More Log Options for catch_workers_output?

[Joshua Chamberlain]

Hello,

I've run into some issues lately trying to log from PHP-FPM inside a Docker container and I'm curious what's the best way to handle the situation, and if this is an area where PHP-FPM might be improved. If there's someone or somewhere else I should ask, please let me know.

Question: Is there any way to format the error log, particularly to allow stdout of child workers to pass through unaltered?

In a single a container, I have to run PHP-FPM and my PHP app, both of which have logs. The normal Docker way, and in my opinion the easiest way for standardized log collection, is to send all logging to stdout. That's not a problem for PHP-FPM--I can easily send its error and access logs to stdout and stderr, which are then collected by docker log or any other collector.

However, the only way to output my app's logs is to enable "catch_workers_output", which presents two difficulties: 1) My app's stdout is wrapped in quotes and prefixed with "WARNING: [pool www] child 11606 said into stdout:". 2) Each line of output is presented as a separate log entry, making stack traces difficult to follow.

I realize I could have my app log directly to some outside collector, but that breaks the encapsulation and portability of my container, and would increase the complexity of a development environment.

Ideally, I'd have my app output JSON log entries that could be captured by PHP-FPM and entered into its log without any alteration, thus enabling me to pass them in their original form to whatever log aggregation service I use. Is there any way to do that? If not, is that something that could be added to PHP-FPM?

Thanks,

Joshua Chamberlain

[Bryan Latten]

Joshua,

I'm facing the *exact* same issue, and definitely frustrated with the lack of options here. Services like heroku are parsing it after it is landing on disk (not viable for me) https://github.com/dzuelke/heroku-buildpack-php/commit/207e26180cc63e096b65344dedc6cb2706f6e713. 

I've been experimenting with a janky POC: 

`php5-fpm --nodaemonize 2>/dev/stdout &`

This allows me to capture and redirect the output of that process to stdout, even after its then backgrounded. If we can then shove that through another pipe instead of /dev/stdout directly, with something like  

`mkfifo stdout_filter; && sed -u 's/WARNING: \[pool www\] child [0-9]* said into stdout: \"\(.*\)\"$/\1/' < stdout_filter > /dev/stdout &; && php5-fpm --nodaemonize  2> stdout_filter &` 

We could have a shot. But I haven't yet succeeded in making this work, nor keeping that pipe filter alive. Any ideas?

Bryan

[Bryan Latten]

I've gotten this one working solution that cleanses the garbage from FPM children:

php5-fpm -F -O 2>&1 | sed -u 's/WARNING: \[pool www\] child [0-9]* said into std[a-z]*: \"\(.*\)\"$/\1/'

Bryan

[Peter Ullah]

I found this thread after searching for the *exact* problem as you guys.

Bryan, I can confirm that your solution, worked for me. The only additional issue that I faced was that, in using Supervisord to manage php-fpm, the command would not work verbatim.

The stumbling block was the stderr redirection; supervisord just didn't like it. 

In the end, I wrapped the command in a shell script and just called that from supervisord. e.g

[program:php-fpm]

command=php-fpm-wrapper.sh

stdout_logfile=/dev/stdout

stderr_logfile=/dev/stdout

autostart=true

autorestart=true

stdout_logfile_maxbytes=0

stderr_logfile_maxbytes=0

php-fpm-wrapper.sh:

#!/bin/bash

php-fpm -F -O 2>&1 | sed -u 's/WARNING: \[pool www\] child [0-9]* said into std[a-z]*: \"\(.*\)\"$/\1/'

P.S remember to make the shell script executable!

[Bryan Latten]

Peter - thanks for the script, looks pretty good! Just to update you on my implementation, I've switched to this in production, which is a little more maintainable (and doesn't fail on truncated messages from PHP): 

php5-fpm -F -O 2>&1 | sed -u 's,.*: \"\(.*\)$,\1,'| sed -u 's,"$,,' 1>&1 &

[Luis Pabón]

Thank you Bryan, that works nicely.

[Marcel Hernandez Bertran]

As of PHP 7.3 there's a new "decorate_workers_output" directive for FPM pools that solves that problem neatly:

https://www.php.net/manual/en/install.fpm.configuration.php#decorate-workers-output