Description
Hello,
This problem spans over these projects:
Symfony\Component\Debug
Symfony\Component\HttpKernel\HttpKernel
- https://github.com/symfony/symfony-standard
Since all of them live under the Symfony umbrella, I decided to report the problem here.
You might want to get a cup of tea/coffee before continuing reading.
Steps to reproduce:
- Get a hold of an nginx + php-fpm7.0 stack.
- Make sure the fpm pool has
catch_workers_output
enabled (on puphpet's Ubuntu, uncomment that option in this file:/etc/php/7.0/fpm/pool.d/www.conf
and restart the php-fpm service) - Create an index.php file with this content:
<?php
echo 'Hi';
fastcgi_finish_request();
throw new \Exception('lorem ipsum');
4.Run this file from your favourite browser.
Result:
Your browser renders the word Hi
and the response was 200. The exception message has been logged to fpm's log file (on puphpet's Ubuntu, the fpm's log file sits in: /var/log/upstart/php7.0-fpm.log
).
5.Install symfony standard edition.
6.Replace DefaultController::indexAction
's body with this:
$eventDispatcher = $this->get('event_dispatcher');
$eventDispatcher->addListener('kernel.terminate', function (PostResponseEvent $event) {
throw new \Exception('exception from kernel.terminate listener');
});
return new Response('foo');
Don't forget to import Response
and PostResponseEvent
classes.
7.Access app_dev.php
from your favourite browser.
Result:
Your browser renders the word foo
and the response was 200. The exception message is not logged anywhere. It's not logged to fpm's log file or symfony's log file. Obviously it's also not logged to nginx' log file, because as far as nginx is concerned, the request was successful.
Expected result:
Great question. I'd say that the exception should at least be logged (both it's message and the stack) to fpm's log file, similar to what happened after step 4.
More details of the problem:
- If you comment this line:
Debug::enable();
inapp_dev.php
, then the expected result happens. - The problem is related with the fact, that
HttpKernel::terminateWithException()
is called after the kernel has already started to terminate. This method is registered as an exception handler bySymfony\Component\HttpKernel\EventListener\DebugHandlersListener::configure()
:
if ($event instanceof KernelEvent) {
if (method_exists($event->getKernel(), 'terminateWithException')) {
$this->exceptionHandler = array($event->getKernel(), 'terminateWithException');
}
}
In that case, HttpKernel::terminateWithException()
throws:
throw new \LogicException('Request stack is empty', 0, $exception);
3.The problem is related with the fact, that Symfony\Component\Debug\ExceptionHandler::handle()
tries to compose and send a response with a pretty error page, but after the kernel.terminate
event, the response has already been sent.
The solution I was thinking about:
Unregister the Symfony\Component\Debug\ExceptionHandler
before the $kernel->terminate($request, $response);
is called in app_dev.php
, because there is no point in sending a pretty error page, when the response is already sent to the client. There is no way to do that currently. To simulate that just to see whether it works, please put these lines at the beginning of the Symfony\Component\Debug\ExceptionHandler::handle()
's body:
if ($this->handler) {
call_user_func($this->handler, $exception);
}
return;
If you rerun the app_dev.php
now, you will see it works. This still leaves us with HttpKernel::terminateWithException()
being called after the kernel.terminate
event to fix. I thought of a private HttpKernel::$terminating = false;
field, that is set to true
in the HttpKernel::terminate()
method. That way, I could do:
public function terminateWithException(\Exception $exception)
{
if ($this->terminating) {
return;
}
If you do this and run the app_dev.php
again, you will see that it's broken again.
I decided to leave the HttpKernel intact and xdebug carefully, what's going on. I discovered, that the change in Symfony\Component\Debug\ExceptionHandler::handle()
is enough, because of some sort of a side effect caused by HttpKernel::terminateWithException()
's throwing an exception. This was the moment, when I decided to give up and ask for an advice.
So yes, could I get some help in resolving this issue, please?
Thanks