PHP-FPM breaks up stack trace log into separate events

Question

I have a problem with PHP-FPM registering a single event as multiple events. Take for example the stack trace below:

[30-Jul-2014 05:38:50] WARNING: [pool www] child 11606 said into stderr: "NOTICE: PHP message: PHP Fatal error:  Uncaught exception 'Zend_View_Exception' with message 'script 'new-layout.mobile.phtml' not found...."
[30-Jul-2014 05:38:50] WARNING: [pool www] child 11606 said into stderr: "Stack trace:"
[30-Jul-2014 05:38:50] WARNING: [pool www] child 11606 said into stderr: "#0 /usr/share/nginx/html/site.com/142-webapp/library/Zend/View/Abstract.php(884): Zend_View_Abstract->_script('new-layout.mobi...')"
[30-Jul-2014 05:38:50] WARNING: [pool www] child 11606 said into stderr: "#1 /usr/share/nginx/html/site.com/142-webapp/library/Zend/Layout.php(796): Zend_View_Abstract->render('new-layout.mobi...')"
[30-Jul-2014 05:38:50] WARNING: [pool www] child 11606 said into stderr: "#2 /usr/share/nginx/html/site.com/142-webapp/library/Zend/Layout/Controller/Plugin/Layout.php(143): Zend_Layout->render()"
[30-Jul-2014 05:38:50] WARNING: [pool www] child 11606 said into stderr: "#3 /usr/share/nginx/html/site.com/142-webapp/library/Zend/Controller/Plugin/Broker...."

As you can see, each line of the stack trace is effectively a separate event with its own timestamp. This is problematic when forwarding logs to another service for analysis because then each stack trace will be broken up when it should be considered as one event. At the moment I am using Kibana 3 and it is a nightmare viewing and managing stack traces since each line is a separate event and the individual events are not always in chronological order.

How do I make php-fpm register each stack trace as one event ?

Answer 1

Unfortunately not

PHP-FPM simply logs each line of PHP output as a separate event. There's nothing you can do in/with PHP-FPM to change this.

PHP Code

You'll need to "fix" this in your application (PHP code). There are 3 ways you can influence the way PHP reports errors, and you'll probably want to use all 3:

• Register a custom error handler with set_error_handler(). This handler is called on all errors except E_ERROR, E_PARSE, E_CORE_ERROR, E_CORE_WARNING, E_COMPILE_ERROR, E_COMPILE_WARNING, and most of E_STRICT raised in the file where set_error_handler() is called.

• Register a custom exception handler with set_exception_handler(). This handler is called when an uncaught exception occurs.

• Register a custom shutdown function with register_shutdown_function(). This function is called after script execution finishes or exit() is called. This one is useful for detecting errors that are not handled with the error handler.

Log library

I can advise you to have a look at Monolog. It's a PSR-3 complaint logging library which also facilitates what I described above.

In addition it has an impressive list of "handlers" which can write the logs to all sorts of services. Chances are the service you're using now is among them!

Alternative

Another option is to create a proxy script that will read the PHP-FPM log files and buffers lines until a "full event" is gathered. Then writing that as a single entry to the service you're using.

I would advise you not to go this way. Writing such a script can be tricky and is very error-prone. Logging from your application itself is much more stable and reliable.