All PHP-FPM processes restart every minute, causing 502 errors.

[Utkarsh]

I'm using PHP 5.3.3, php-fpm and nginx on my VPS.

In the php-fpm.log, I'm seeing that fpm restarts every minute

--------------
Sep 12 19:15:01.139646 [NOTICE] Finishing ...
Sep 12 19:15:01.148060 [NOTICE] exiting, bye-bye!
Sep 12 19:15:02.175076 [NOTICE] fpm is running, pid 2360
Sep 12 19:15:02.178138 [NOTICE] ready to handle connections
Sep 12 19:16:01.208322 [NOTICE] Finishing ...
Sep 12 19:16:01.214937 [NOTICE] exiting, bye-bye!
Sep 12 19:16:02.243409 [NOTICE] fpm is running, pid 2401
Sep 12 19:16:02.245982 [NOTICE] ready to handle connections
...
Sep 12 19:19:02.629229 [NOTICE] ready to handle connections
Sep 12 19:20:01.714123 [NOTICE] Finishing ...
Sep 12 19:20:01.725793 [NOTICE] exiting, bye-bye!
Sep 12 19:20:02.751009 [NOTICE] fpm is running, pid 2512
Sep 12 19:20:02.753693 [NOTICE] ready to handle connections
-------------

"ps aux | grep fpm" confirms that all active process are being killed
and restarted every minute

-------------
root@li182-18:~# ps aux | grep fpm
root 2385 0.0 0.0 1796 492 pts/0 S+ 19:15 0:00 tail -f /var/log/php-
fpm.log
root 2618 0.0 0.6 22384 3108 ? Ss 19:24 0:00 /usr/local/php/sbin/php-
fpm --fpm-config /usr/local/php/etc/php-fpm.conf
www-data 2619 0.0 0.5 22384 2728 ? S 19:24 0:00 /usr/local/php/sbin/
php-fpm --fpm-config /usr/local/php/etc/php-fpm.conf
www-data 2620 0.0 0.5 22384 2728 ? S 19:24 0:00 /usr/local/php/sbin/
php-fpm --fpm-config /usr/local/php/etc/php-fpm.conf
root 2636 0.0 0.1 1860 600 pts/1 S+ 19:25 0:00 grep --color=auto fpm
You have new mail in /var/mail/root
root@li182-18:~# ps aux | grep fpm
root 2385 0.0 0.0 1796 492 pts/0 S+ 19:15 0:00 tail -f /var/log/php-
fpm.log
root 2650 0.0 0.6 22384 3108 ? Ss 19:25 0:00 /usr/local/php/sbin/php-
fpm --fpm-config /usr/local/php/etc/php-fpm.conf
www-data 2651 0.0 0.5 22384 2728 ? S 19:25 0:00 /usr/local/php/sbin/
php-fpm --fpm-config /usr/local/php/etc/php-fpm.conf
www-data 2652 0.0 0.5 22384 2728 ? S 19:25 0:00 /usr/local/php/sbin/
php-fpm --fpm-config /usr/local/php/etc/php-fpm.conf
root 2658 0.0 0.1 1860 596 pts/1 S+ 19:25 0:00 grep --color=auto fpm
root@li182-18:~#
-------------

I've tried both dynamic pooling (min 3, max 10, spare 2) and static
pooling.

This restarting of the processes is causing my sites to throw a 502
error to all the requests that are sent in those 1-2 sec every minute.

Is there any setting or anything that might be causing this?

[Michael Shadle]

pastebin your php-fpm config (and anything else relevant)

also turn up your log level to debug

[Utkarsh]

php-fpm.conf and .log (with debug enabled)
https://gist.github.com/d6744c8ec62470992e80

On Sep 13, 1:51 am, Michael Shadle <mike...@gmail.com> wrote:
> pastebin your php-fpm config (and anything else relevant)
>
> also turn up your log level to debug
>

[Michael Shadle]

uncomment this
;catch_workers_output = yes

how many requests are you hitting it with do you think? it ends within
60 seconds roughly and you have it set to 1000 requests. so either
something is crashing or running out of resources for some reason, or
you're hitting your 1000 and it's not recycling.

[Utkarsh]

The load is minimal, max 1-2 requests a minute.

The log output is similar with "catch_workers_output = yes"

On Sep 13, 2:08 am, Michael Shadle <mike...@gmail.com> wrote:
> uncomment this
> ;catch_workers_output = yes
>
> how many requests are you hitting it with do you think? it ends within
> 60 seconds roughly and you have it set to 1000 requests. so either
> something is crashing or running out of resources for some reason, or
> you're hitting your 1000 and it's not recycling.
>

[Jérôme Loyet]

in your log file:

Sep 12 21:01:59.002402 [DEBUG] pid 2432,
fpm_pctl_perform_idle_server_maintenance(), line 357: [pool www]
currently 0 active children, 2 spare children, 2 running children.
Spawning rate 1
Sep 12 21:02:00.003397 [DEBUG] pid 2432,
fpm_pctl_perform_idle_server_maintenance(), line 357: [pool www]
currently 0 active children, 2 spare children, 2 running children.
Spawning rate 1
Sep 12 21:02:01.004449 [DEBUG] pid 2432,
fpm_pctl_perform_idle_server_maintenance(), line 357: [pool www]
currently 0 active children, 2 spare children, 2 running children.
Spawning rate 1
Sep 12 21:02:01.036579 [DEBUG] pid 2432, fpm_got_signal(), line 62:
received SIGQUIT
Sep 12 21:02:01.036594 [NOTICE] pid 2432, fpm_got_signal(), line 63:
Finishing ...

Process 2432 is the master process. it says that it received a QUIT
signal. So it's stopping. It's not a bug.

As you said it happenes every minutes, I think you have a kind of
watchdog software which is not detecting PHP-FPM correctely and
restarts FPM.

2010/9/12 Utkarsh <www.qpro...@gmail.com>

[Utkarsh]

This is a new Ubuntu install. I'm sure I didn't install any such
software, and I don't think any default one comes with Ubuntu 10.04.
Would it be possible to debug/find out what is sending the QUIT signal
to the master process?

On Sep 13, 2:59 am, Jérôme Loyet <m...@fatbsd.com> wrote:
> in your log file:
>
> Sep 12 21:01:59.002402 [DEBUG] pid 2432,
> fpm_pctl_perform_idle_server_maintenance(), line 357: [pool www]
> currently 0 active children, 2 spare children, 2 running children.
> Spawning rate 1
> Sep 12 21:02:00.003397 [DEBUG] pid 2432,
> fpm_pctl_perform_idle_server_maintenance(), line 357: [pool www]
> currently 0 active children, 2 spare children, 2 running children.
> Spawning rate 1
> Sep 12 21:02:01.004449 [DEBUG] pid 2432,
> fpm_pctl_perform_idle_server_maintenance(), line 357: [pool www]
> currently 0 active children, 2 spare children, 2 running children.
> Spawning rate 1
> Sep 12 21:02:01.036579 [DEBUG] pid 2432, fpm_got_signal(), line 62:
> received SIGQUIT
> Sep 12 21:02:01.036594 [NOTICE] pid 2432, fpm_got_signal(), line 63:
> Finishing ...
>
> Process 2432 is the master process. it says that it received a QUIT
> signal. So it's stopping. It's not a bug.
>
> As you said it happenes every minutes, I think you have a kind of
> watchdog software which is not detecting PHP-FPM correctely and
> restarts FPM.
>

> 2010/9/12 Utkarsh <www.qprojects....@gmail.com>

[Michael Shadle]

There is apparmor by default I believe. You could look in other system logs it should report if it was killing something.