PHP-FPM on 8.2 seems to spawn many children without any corresponding requests

[blackwolf12333]

Description

Since we switched our production backend to php 8.2 on 22-06-2023 we've observed a consistently higher load on our tasks. We run on AWS fargate with a slightly modified docker image based on the official php:8.2-fpm-bullseye image. The php-fpm processes sit behind an nginx server.

We observe that every day before traffic really gets busy one or two of our tasks starts using up 100% CPU. The logs for those tasks indicate that they are starting and stopping new children continuously even if there doesn't seem to be a request associated with it (we use a canonical log line so each request should have at least one application log line but we don't see those next to the children starting).

Here is an excerpt of our logs logs-insights-results-13.csv
And here is our current php-fpm configuration: www_pool.txt

We've only observed this behavior in production so far. If there is anything we can do to debug this further please let us know.

PHP Version

PHP 8.2

Operating System

debian bullseye

[bukka]

Why do you have pm.max_requests = 500 in your config? This means that child restarts after 500 requests. That's a very small number obviously and might explain what you see in logs. I would suggest to comment it completely unless you are aware of some other problem (e.g. continuous increasing of memory)?

[blackwolf12333]

This configuration has not changed in months or even years at this point. But we'll give your suggestion a go next week.

However the behaviour we see in our logs has drastically changed recently so I'm not super hopeful this is the culprit.

[bukka]

It might also depend on traffic but hard to say from the provided logs. If you do not see it disappear, please enable debug log level in master fpm config and provide data from it.

[blackwolf12333]

@bukka we've only enabled the debug logging at the moment, the attached partial log file is from a task running at >50% CPU (which for us is unusual, all our other tasks run at around 30%). And this will go up to 100% over the day.

I personally don't see anything obviously wrong here, except that the children are spawning and exiting.
log-events-viewer-result-1.csv
Let me know if you want to get more logs, this is just a small excerpt.

We'll experiment with the the max_requests variable next, and we might also try disabling jit because chatgpt suggested it (I don't really expect this to be the issue but we'll see).

[maaarghk]

Might be worth turning on catch_workers_output to see if the child processes say anything to the logs before exiting

[blackwolf12333]

This excerpt seems to be where the issue starts appearing, there is a clear pattern at the start of the file (which is consistent all the way to the start of the full log) that's broken later on in the file (around line 80).
logs-insights-results-14.csv

[blackwolf12333]

@bukka This #11736 sounds superficially similar to what I'm seeing, we'll definitely try disabling JIT as well.

After looking at it closer it's not like this at all. For us it takes a while to reach 100%.

[blackwolf12333]

We've removed the max_requests now, I think we should be able to tell tomorrow if that improves the situation.

[blackwolf12333]

@bukka we haven't observed the issue since we set max_requests to 0.

[bukka]

Yeah I thought that it will be the reason. Did you have this config before switching for such low value of max_requests? Usually you should not be using this options unless you see some memory leak (e.g. some 3rd party extension or core bug) or some other problem.

[blackwolf12333]

I honestly don't know why it was set to such a low value (git history is also not helpful unfortunately), but we've had this config for years and haven't really had any issues with it.

[bukka]

You should be able to see it from access logs if you log pid (%p) and count the requests based on that value. Then you should see if the child restarts after the correct number of requests based on time.

Currently I don't see any issue here so I will close this but if you notice anything specific that does not look right, please report it here with all the details and if it's an issue, I will be happy to re-open this and investigate further.