Seldaek / monolog

Sends your logs to files, sockets, inboxes, databases and various web services
https://seldaek.github.io/monolog/
MIT License
21.02k stars 1.9k forks source link

Uncaught TypeError: Monolog\Logger::getLevelName() ConsoleHandler given #1783

Open erikbaan opened 1 year ago

erikbaan commented 1 year ago

Monolog version 2 & 3

Since upgrading to Symfony 6.1 (and PHP 8.1), I have been seeing a very rare Symfony container construction issue within the Monolog code. The error is logged by PHP-FPM to nginx:

2022/12/10 07:50:02 [error] 28#28: *273 FastCGI sent in stderr: "PHP message: PHP Fatal error:  Uncaught TypeError: Monolog\Logger::getLevelName(): Argument #1 ($level) must be of type Monolog\Level|int, Symfony\Bridge\Monolog\Handler\ConsoleHandler given, called in /app/vendor/monolog/monolog/src/Monolog/Logger.php on line 196 and defined in /app/vendor/monolog/monolog/src/Monolog/Logger.php:437
Stack trace:
#0 /app/vendor/monolog/monolog/src/Monolog/Logger.php(196): Monolog\Logger::getLevelName()
#1 /app/var/cache/prod/ContainerOqglp2q/App_KernelProdContainer.php(1441): Monolog\Logger->pushHandler()
#2 /app/var/cache/prod/ContainerOqglp2q/App_KernelProdContainer.php(1103): ContainerOqglp2q\App_KernelProdContainer->getMonolog_Logger_RequestService()
#3 /app/vendor/symfony/dependency-injection/Container.php(218): ContainerOqglp2q\App_KernelProdContainer->getHttpKernelService()
#4 /app/vendor/symfony/dependency-injection/Container.php(198): Symfony\Component\DependencyInjection\Container->make()
#5 /app/vendor/symfony/http-kernel/Kernel.php(195): Symfony\Compone" while reading response header from upstream, client: 172.19.0.2, server: _, request: "POST /job-engine-client/execute HTTP/1.0", upstream: "fastcgi://172.31.0.3:9000", host: "x"

This error only gets triggered once every 500 requests. The code is deployed using docker to multiple hosts (ubuntu 22.04 host and container), and the same rare issue happens on multiple hosts.

When looking at the monolog Logger.php code, it seems impossible that a pushHandler will trigger a getLevelName, and even more will cause a ConsoleHandler to be given as level argument. But still this is the only issue I'm seeing, with the exact same trace every time.

Is this a bug within Monolog? Are there any similar issues known?

erikbaan commented 1 year ago

Some extra info: this issue happens with both PHP 8.1.2 and PHP 8.1.13. After disabling opcache, the problem has not occured anymore (so far so good).

So it seems like an opcache related bug..

bravedave commented 1 year ago

Some extra info: this issue happens with both PHP 8.1.2 and PHP 8.1.13. After disabling opcache, the problem has not occured anymore (so far so good).

So it seems like an opcache related bug..

good tip ! that makes sense

dzuelke commented 1 year ago

Has anyone got a reduced reproduce case already for this? It would likely need hammering with ab or siege, but anything that exhibits the problem would help with opening a bug upstream and getting it fixed in PHP. I am happy to do all that coordination work, I just need an initial reproduce case; I'd be happy to even try and further simplify it myself.

Seldaek commented 1 year ago

Could anyone affected try if upgrading symfony/monolog-bundle to 3.x-dev fixes it? I'm wondering if https://github.com/symfony/monolog-bundle/pull/446 might help as it stops doing level resolution in the container build. In theory the old code was fine but who knows. Opcache bugs can be hard to pinpoint.

erikbaan commented 1 year ago

Thanks @Seldaek for pointing to that fix. Unfortunately it's hard to test a dev version in production for us. At least I can confirm that I haven't seen this bug anymore, but I still have opcache disabled.

I will try enabling opcache again when monolog-bundle gets a new release.