[Discussion] Reset FingersCrossedHandler on stateful runtimes

[CViniciusSDias]

While looking into Symfony Runtime, I was thinking about FingersCrossedHandler. I assume it's always going to hit the buffer limit and I thought about writing an event listener for the kernel.terminate event and always reset the logger, but that would not reset only the logger for that request, since the logger is now global.

So with multiple requests, I might have the logger being reset and the next entry would be in the fingers crossed action level for a different request, causing a problem.

But currently, if I'm not mistaken, one request can build up debug logs for one request and if another one triggers the action_level, all the requests logs are going to be sent to the nested handler, not just the ones for that request.

I was wondering if there is a way of scoping the logger for each request and, doing so, we could have FingersCrossedHandler implemented safely in stateful runtimes such as Swoole, ReactPHP, FrankenPHP, etc.

[javaDeveloperKid]

This is the same case as we discussed on Symfony discussions. Monolog as well as Symfony doesn't know your web app is a long running script. You have to jump into request-response cycle and reset given service on your own.

[CViniciusSDias]

This is not the same case.

I was wondering if there is a way of scoping the logger for each request and, doing so, we could have FingersCrossedHandler implemented safely in stateful runtimes such as Swoole, ReactPHP, FrankenPHP, etc.

This is the main point here. As you pointed out in Symfony discussions, the handler is already marked to be reset on terminate. But that doesn't fix the issue of having the same logger for every request.

[CViniciusSDias]

Look at the following code inside an example controller:

    #[Route('/slow', methods: ['GET'], format: 'json')]
    public function slow(): Response
    {
        $this->logger->info('Slow - logger id', ['id' => spl_object_hash($this->logger)]);
        $this->logger->debug('Log de debug antes do sleep');
        sleep(10);

        return $this->json('Ok');
    }

    #[Route('/fast', methods: ['GET'], format: 'json')]
    public function fast(): Response
    {
        $this->logger->info('Fast - logger id', ['id' => spl_object_hash($this->logger)]);
        $this->logger->error('Erro solo que não deve ter mais nada');
        return $this->json('Ok');
    }

If you access the slow route, it's going to add info and debug logs, but if you have fingers crossed configured to only log errors, nothing should be logged. But if, while the slow endpoint is running, you access the fast one, you'll see the logs from the slow request, because the logger is the same.

Hence the following:

I was wondering if there is a way of scoping the logger for each request and, doing so, we could have FingersCrossedHandler implemented safely in stateful runtimes such as Swoole, ReactPHP, FrankenPHP, etc.

[CViniciusSDias]

Same goes for the following:

    #[Route('/slow', methods: ['GET'], format: 'json')]
    public function slow(): Response
    {
        $this->logger->info('Slow - logger id', ['id' => spl_object_hash($this->logger)]);
        $this->logger->debug('Debug log before sleep');
        sleep(10);
        $this->logger->error('Error log that should come after the debug');

        return $this->json('Ok');
    }

    #[Route('/fast', methods: ['GET'], format: 'json')]
    public function fast(): Response
    {
        $this->logger->info('Fast - logger id', ['id' => spl_object_hash($this->logger)]);

        return $this->json('Ok');
    }

The 'Fast - logger id' message should never be sent to the output, but in a stateful runtime it does, because the error log in the slow endpoint makes everything in the logs to be sent.

[javaDeveloperKid]

Does your stateful runtime allow to handle more than 1 concurrent request per process? Or does it share memory between processes (or threads depending on runtime architecture)? If any of these is true then you indeed have a problem (like it is in Java or C# applications I believe).
Along the stateful runtimes out there I have only been working with RoadRunner and it allows only 1 request per worker and doesn't share memory between workers.

[CViniciusSDias]

Does your stateful runtime allow to handle more than 1 concurrent request per process?

It's not mine 😅 but yes, Swoole does allow that.

Or does it share memory between processes (or threads depending on runtime architecture)?

That is also possible in Swoole, yes.

If any of these is true that then you indeed have a problem

Yep, that's why I'm bringing up the discussion so we can figure out a way of having our PHP applications running on those runtimes safely. :-D

[stof]

The only way to avoid issues when running concurrent requests running in a runtime is to have no stateful services being shared between those requests. This would require either having no stateful services at all (but the whole point of a FingersCrossedHandler is to be stateful by buffering log entries until activation happens) or to have separate instances per request being handled (in the case of Symfony, this would end up meaning booting separate kernels for each concurrent request so that they have separate containers).

[Seldaek]

Yeah IMO if you share a single container between multiple concurrent requests in one process you're gonna have bigger issues than the FingersCrossedHandler. Like what happens when an entity is half-modified in one request while another flushes doctrine changes? Doesn't sound very ACID compliant :D

So yes if you run concurrent requests in a single process I would say you need to have at least a fresh container per request, which would instantiate a new fingers crossed handler as well. You can still reset and reuse the container once done with that request so you'd have a pool of containers each running a single request at a time, if that really saves enough cycles to be worth the risks of state pollution between requests.