Logging to stderr has some kind of limit in the PHP-FPM runtime

[curlysanders]

Description:
It seems that logging to stderr with monolog (using Symfony 6.3) has some kind of limit in the web function, with php-fpm runtime.
Whenever some threshold in amount (and size) of log entries is reached the lambda seems to hang until it times out after 28 seconds.

For instance we have an import endpoint which reads an uploaded Excel sheet. With logging enabled we can process about 260 rows before it hangs. The same command for processing but then run via a console command has no issue whatsoever, it handles 13.000+ rows easily. Also worker lambdas do not show this behavior

This behavior is also observed locally with the same runtime.

Debgging steps tried:
When minimum log level is raised to notice, the logging is reduced to next to nothing (only when an unhandled exception or a PHP notice/warning/error occurs it will be logged). In this case importing via web request works even for 13.000 rows, with only 1 or 2 seconds to spare before the 28 second timeout.
I've also tried increasing memorySize to no effect. No difference noticed comparing 1792M, 10240M and the default 1024M (which we normally use).

How to reproduce:
Attached a Symfony controller and a console command to test amount of log entries (on top of entries generated by frameork and dependencies).
source.zip

• Create a simple Symfony (6.3) project with monolog and add the controller and command.
• Add and setup Bref (2.1.3)
• Setup serverless.yml with the runtimes (web: php-82-fpm, console: php-82-console, worker: php-82)
• Use a local docker setup with web php image bref/php-82-fpm-dev:2

See also Slack: https://brefworkspace.slack.com/archives/C057S6G4Z9N/p1704917185595609

[kevincerro]

I was having this issue with symfony deprecation logs
When lot of deprecations are triggered, lambda hangs until timeout (28 seconds) is reached.

[curlysanders]

@kevincerro I assume you 'solved' it by disabling deprecation logging.

[kevincerro]

@kevincerro I assume you 'solved' it by disabling deprecation logging.

I fixed the deprecation (was being triggered multiple times inside a for loop)

But yes, disabling deprecation logger was my alternative hotfix.

[mnapoli]

Pasting my comment from Slack here for reference:

FYI FPM logs are forwarded to CloudWatch via this: https://github.com/brefphp/bref/blob/master/src/FpmRuntime/FpmHandler.php#L82-L85

Something could be "overwhelming" the PHP code here?

Or maybe it could be this config option for the FPM configuration: https://github.com/brefphp/aws-lambda-layers/blob/main/layers/fpm/php-fpm.conf#L9-L10

[curlysanders]

I've tried with different FPM config values, to no effect.

• log_limit to ten times 8192
• log_buffering = no

Also tested with php-fpm-83. No luck 🤷🏻‍♂️

[mnapoli]

I managed to reproduce and I have a fix in #1852, would love if you could test it and confirm if it works.

I'll be closing this issue as a duplicate of #1369 btw