php / php-src

The PHP Interpreter
https://www.php.net
Other
38.18k stars 7.75k forks source link

Logs wrapped with newlines even when output decoration is disabled #13118

Open siimsoni opened 10 months ago

siimsoni commented 10 months ago

Description

When decorate_workers_output is disabled as a pool directive, and worker output is redirected to the main error log:

decorate_workers_output = no
catch_workers_output = yes

And error log is enabled in global php-fpm.conf:

error_log = /var/log/php8.3-fpm.log

When the following code is executed in an FPM worker:

$err = array_fill(0, 128, "banana");
file_put_contents("php://stderr", json_encode($err));

error_log contains this:

["banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","bana
na","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana"]

But I expected the logged contents to be this instead:

["banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana","banana"]

Links:

PHP Version

PHP 8.3.2

Operating System

No response

siimsoni commented 10 months ago

This may be intentional, as it is possible to set log_limit in global php-fpm.conf, which solves the issue when set to a high enough value. However, I think the common expectation would be that log contents are not modified when decorate_workers_output = no is set. If this cannot be changed, then I propose to add a note about it to decorate_workers_output documentation.

devnexen commented 10 months ago

I ll leave bukka to explain the rationale.

bukka commented 10 months ago

The decorate_workers_output is just about adding message prefix and suffix around the logged data. The log_limit is for setting the line limit so this should not be overwritten. I just double checked and we always do wrapping except external log (logging directly in child to sapi). We could potentially allow disabling of wrapping and just truncate it but not sure if it's really useful. Most of the time it should be just resolved by setting high log_limit. I think we should bump its value in PHP 9 so this problem won't be that visible.

I agree that we can add more explanation to the config for this so I will keep it open as a feature request.