php-fpm: hundreds of seconds in the log

Lari13 asked:

I have nginx+php-fpm web server

So I’ve noticed in php5-fpm.log many strange lines:

[03-Sep-2013 09:25:23] NOTICE: [pool www] child 23999 exited with code 0 after 321.832329 seconds from start
[03-Sep-2013 09:25:23] NOTICE: [pool www] child 24082 started
[03-Sep-2013 09:25:41] NOTICE: [pool www] child 24032 exited with code 0 after 259.247887 seconds from start
[03-Sep-2013 09:25:41] NOTICE: [pool www] child 24083 started
[03-Sep-2013 09:25:47] NOTICE: [pool www] child 24033 exited with code 0 after 255.954602 seconds from start
[03-Sep-2013 09:25:47] NOTICE: [pool www] child 24084 started
[03-Sep-2013 09:25:50] NOTICE: [pool www] child 24014 exited with code 0 after 327.620462 seconds from start
[03-Sep-2013 09:25:50] NOTICE: [pool www] child 24085 started
[03-Sep-2013 09:25:55] NOTICE: [pool www] child 24034 exited with code 0 after 254.974653 seconds from start
[03-Sep-2013 09:25:55] NOTICE: [pool www] child 24086 started
[03-Sep-2013 09:26:01] NOTICE: [pool www] child 24035 exited with code 0 after 253.388234 seconds from start
[03-Sep-2013 09:26:01] NOTICE: [pool www] child 24087 started
[03-Sep-2013 09:26:02] NOTICE: [pool www] child 24036 exited with code 0 after 251.374430 seconds from start
[03-Sep-2013 09:26:02] NOTICE: [pool www] child 24088 started
[03-Sep-2013 09:26:05] NOTICE: [pool www] child 24019 exited with code 0 after 325.601766 seconds from start
[03-Sep-2013 09:26:05] NOTICE: [pool www] child 24089 started
[03-Sep-2013 09:26:09] NOTICE: [pool www] child 24037 exited with code 0 after 255.871955 seconds from start
[03-Sep-2013 09:26:09] NOTICE: [pool www] child 24090 started
[03-Sep-2013 09:26:09] NOTICE: [pool www] child 24038 exited with code 0 after 255.884311 seconds from start
[03-Sep-2013 09:26:09] NOTICE: [pool www] child 24091 started
[03-Sep-2013 09:26:09] NOTICE: [pool www] child 24039 exited with code 0 after 254.826181 seconds from start
[03-Sep-2013 09:26:09] NOTICE: [pool www] child 24092 started
[03-Sep-2013 09:26:12] NOTICE: [pool www] child 24040 exited with code 0 after 256.232759 seconds from start
[03-Sep-2013 09:26:12] NOTICE: [pool www] child 24093 started
[03-Sep-2013 09:26:14] NOTICE: [pool www] child 24027 exited with code 0 after 321.722533 seconds from start

Can anyone tell me, what are these seconds like after 321.722533 seconds from start and what does it mean?

UPD

My config is:

pm = dynamic
pm.max_children = 50
pm.start_servers = 20
pm.min_spare_servers = 5
pm.max_spare_servers = 35
pm.max_requests = 100

My answer:


“Seconds” is a unit of time; 321 of them is a little over five minutes.

The reason your processes are exiting and respawning is that you have set the pm.max_requests option in your php-fpm pool configuration file.

For example, taken from the default configuration:

; The number of requests each child process should execute before respawning.
; This can be useful to work around memory leaks in 3rd party libraries. For
; endless request processing specify '0'. Equivalent to PHP_FCGI_MAX_REQUESTS.
; Default Value: 0
pm.max_requests = 500

We can see in your configuration that it is set to 100, thus php-fpm recycles the process after it has processed 100 requests.


View the full question and answer on Server Fault.

Creative Commons License
This work is licensed under a Creative Commons Attribution-ShareAlike 3.0 Unported License.