PHP 5.3.x with php-fpm kills the socket but children are still alive

[Kiril Angov]

Hello,

I compiled php 5.3.1RC3 and then php 5.3.0 with the old php-fpm and also with the new one but I suffer from the same problem. I run php-fpm with a socket /tmp/php-5.3.x.sock and that setup was working fine on ubuntu 9.04 but as I updated recently to ubuntu 9.10 I am getting the following problem:

I have monit monitor the php-fpm process and until now I had it monitor only the PID file. Today I was surprised to find that nginc was giving me 502 errors when the monit service did not complain that php-fpm was down. When I checked, yes, php-fpm was running as the children were alive but the socket file was not there and obvious not able to server requests. Upon php-fpm restart, everything works as expected until upto an hour later when this happens again. So for the moment I updated monit to also check the socket and restart php-fpm if the socket becomes unavailable.

So how can I go about debugging this problem and what to information to privide? Should I just switch to TCP? Thanks.

P.S.
No errors in the log of php-fpm and nginx only reports the bad gateway (502) error and nothing pertaining to why the PHP process destroyed the socket file.

[omega13a (omega13a)]

This doesn't just effect Ubuntu. I'm having the same problem on CentOS...

[mindmorass (curtis-downing)]

Running Ubuntu 8.04
PHP 5.3.1
PHP-FPM

Had the same problem - running php-fpm on TCP 127.0.0.1:9900

It usually begins with some warning
(snippet)
Jan 07 10:47:11.704787 [WARNING] fpm_stdio_child_said(), line 167: child 14061 (pool default) said into stderr: "01 0:00:01 --:--:-- 500"
Jan 07 10:47:11.704805 [WARNING] fpm_stdio_child_said(), line 167: child 14061 (pool default) said into stderr: ""

These warnings begin to fill up the logs then eventually become
(snippet)
Jan 07 10:54:14.515903 [NOTICE] fpm_pctl_kill_all(), line 172: sending signal 9 SIGKILL to child 13779 (pool default)
Jan 07 10:54:14.515922 [NOTICE] fpm_pctl_kill_all(), line 172: sending signal 9 SIGKILL to child 13728 (pool default)
Jan 07 10:54:14.515941 [NOTICE] fpm_pctl_kill_all(), line 181: 5 children are still alive
Jan 07 10:54:14.516903 [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
Jan 07 10:54:14.516946 [WARNING] fpm_children_bury(), line 217: child 14061 (pool default) exited on signal 9 SIGKILL after 1267.634537 seconds from start
Jan 07 10:54:14.518230 [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
Jan 07 10:54:14.518264 [WARNING] fpm_children_bury(), line 217: child 13779 (pool default) exited on signal 9 SIGKILL after 5975.821306 seconds from start

Things work for a while on restart....

[Michael Shadle (mshadle)]

Personally I am still wary on 5.3.x + fpm.

I will say that it is expected behavior in the logfile to show the child being send SIGCHLD as that occurs when it has hit max_requests and is recycling the PHP process.

This is what I show when a child is being restarted (5.2.11 w/ patch)

Jan 07 11:46:44.247761 [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
Jan 07 11:46:44.247843 [NOTICE] fpm_children_bury(), line 215: child 18159 (pool default) exited with code 0 after 1447.637682 seconds from start
Jan 07 11:46:44.248313 [NOTICE] fpm_children_make(), line 352: child 20218 (pool default) started

[Nabeel (nabeel)]

I'm also having this issue on Ubuntu 9.10. I'm downgrading to 5.2.10 for now. I was using the dotdeb package. My logs:

Apr 05 20:11:23.440573 [NOTICE] fpm_children_make(), line 354: child 3514 (pool default) started
Apr 05 20:11:23.441259 [WARNING] fpm_stdio_child_said(), line 167: child 3514 (pool default) said into stderr: "Apr 05 20:11:23. 441035 [ERROR] fpm_unix_init_child(), line 168: setrlimit(RLIMIT_NOFILE) failed: Invalid argument (22)"
Apr 05 20:16:24.662567 [NOTICE] fpm_got_signal(), line 48: received SIGCHLD
Apr 05 20:16:24.662643 [NOTICE] fpm_children_bury(), line 217: child 6246 (pool default) exited with code 0 after 799.478670 sec onds from start
Apr 05 20:16:24.664310 [NOTICE] fpm_children_make(), line 354: child 16164 (pool default) started
Apr 05 20:16:24.664786 [WARNING] fpm_stdio_child_said(), line 167: child 16164 (pool default) said into stderr: "Apr 05 20:16:24 .664627 [ERROR] fpm_unix_init_child(), line 168: setrlimit(RLIMIT_NOFILE) failed: Invalid argument (22)"
Apr 05 20:17:01.492911 [NOTICE] fpm_got_signal(), line 60: received SIGQUIT
Apr 05 20:17:01.492951 [NOTICE] fpm_pctl(), line 256: switching to 'finishing' state
Apr 05 20:17:01.497969 [NOTICE] fpm_pctl_kill_all(), line 172: sending signal 3 SIGQUIT to child 16164 (pool default)
Apr 05 20:17:01.497993 [NOTICE] fpm_pctl_kill_all(), line 172: sending signal 3 SIGQUIT to child 3514 (pool default)
Apr 05 20:17:01.498005 [NOTICE] fpm_pctl_kill_all(), line 172: sending signal 3 SIGQUIT to child 10598 (pool default)
Apr 05 20:17:01.498015 [NOTICE] fpm_pctl_kill_all(), line 172: sending signal 3 SIGQUIT to child 8737 (pool default)
Apr 05 20:17:01.498025 [NOTICE] fpm_pctl_kill_all(), line 172: sending signal 3 SIGQUIT to child 6247 (pool default)
Apr 05 20:17:01.498031 [NOTICE] fpm_pctl_kill_all(), line 181: 5 children are still alive

I've tried increasing the rlimit parameter, but no dice. I'm not using it as a socket, but a tcp listener.