Edit report at http://bugs.php.net/bug.php?id=53412&edit=1
ID: 53412
User updated by: php-bugs at thequod dot de
Reported by: php-bugs at thequod dot de
Summary: php-fpm children constantly exiting (immediately)
-Status: Feedback
+Status: Assigned
Type: Bug
Package: FPM related
Operating System: Linux
PHP Version: 5.3SVN-2010-11-26 (snap)
Assigned To: fat
Block user comment: N
Private report: N
New Comment:
Unfortunately this does not work: "exit" is not undefined in my case,
and when running the program (using "-y main.conf" it starts looping
right away).
However, I have something more/new:
(gdb) set follow-fork-mode child
(gdb) catch fork
Catchpoint 1 (fork)
(gdb) break exit
Breakpoint 2 at 0x806a2f0
(gdb) run -y main.conf
Starting program: /usr/sbin/php5-fpm -y main.conf
[Thread debugging using libthread_db enabled]
[New Thread 0xb7591b70 (LWP 24013)]
[Thread 0xb7591b70 (LWP 24013) exited]
Nov 30 17:20:22.583597 [DEBUG] pid 24010, fpm_event_init_main(), line
229: 1 fds have been reserved
Nov 30 17:20:22.583701 [NOTICE] pid 24010, fpm_init(), line 52: fpm is
running, pid 24010
Catchpoint 1 (forked process 24014), 0xb7a77f32 in __libc_fork ()
at ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c:130
130 ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c: No such file or
directory.
in ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c
(gdb) n
[New process 24014]
[Thread debugging using libthread_db enabled]
Nov 30 17:20:33.356489 [DEBUG] pid 24010, fpm_children_make(), line 377:
pid after fork=24014
Nov 30 17:20:33.356517 [DEBUG] pid 24010, fpm_children_make(), line 400:
[pool www] child 24014 started
Nov 30 17:20:33.356527 [NOTICE] pid 24010, fpm_event_loop(), line 254:
ready to handle connections
137 in ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c
[...]
216 in ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c
fpm_children_make (wp=0x8924b30, in_event_loop=0, nb_to_spawn=0,
is_debug=1)
at
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c:377
377
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c:
No such file or directory.
in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
376 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
377 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
Nov 30 17:22:45.638098 [DEBUG] pid 24014, fpm_children_make(), line 377:
pid after fork=0
379 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
337 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
338 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
59 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
383 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
146 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
383 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
146 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
148 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
149 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
148 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
150 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
148 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
151 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
148 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
152 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
148 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
153 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
148 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
406 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
fpm_children_create_initial (wp=0x8924b30)
at
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c:412
412 in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
fpm_run (max_requests=0xbfffd590) at
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm.c:70
70 /build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm.c: No
such file or directory.
in /build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm.c
80 in /build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm.c
Using "next"/"n" the next time causes the infinite loop. I cannot see
what is going on there really, because the scrollback buffer is spammed
fast and I need to switch to another screen window to "pkill -9 -f
php-fpm".
Apparently the child/fork I've followed in gdb exits here?!
Debugging this further, it looks like the child itselfs calls fork
again?
(gdb) set follow-fork-mode child
(gdb) catch fork
Catchpoint 1 (fork)
(gdb) break exit
Breakpoint 2 at 0x806a2f0
(gdb) break fpm_children_create_initial
Breakpoint 3 at 0x83a73b6: file
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c,
line 411.
(gdb) run -y main.conf
Starting program: /usr/sbin/php5-fpm -y main.conf
[Thread debugging using libthread_db enabled]
[New Thread 0xb7591b70 (LWP 26154)]
[Thread 0xb7591b70 (LWP 26154) exited]
Nov 30 17:37:05.574273 [DEBUG] pid 26151, fpm_event_init_main(), line
229: 1 fds have been reserved
Nov 30 17:37:05.574381 [NOTICE] pid 26151, fpm_init(), line 52: fpm is
running, pid 26151
Breakpoint 3, fpm_children_create_initial (wp=0x8924b30)
at
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c:411
411
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c:
No such file or directory.
in
/build/buildd/php5-5.3.4~snap201011290730/sapi/fpm/fpm/fpm_children.c
(gdb) n
Catchpoint 1 (forked process 26155), 0xb7a77f32 in __libc_fork ()
at ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c:130
130 ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c: No such file or
directory.
in ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c
(gdb) n
[New process 26155]
Nov 30 17:37:13.200755 [DEBUG] pid 26151, fpm_children_make(), line 377:
pid after fork=26155
Nov 30 17:37:13.200784 [DEBUG] pid 26151, fpm_children_make(), line 400:
[pool www] child 26155 started
Nov 30 17:37:13.200799 [NOTICE] pid 26151, fpm_event_loop(), line 254:
ready to handle connections
[Thread debugging using libthread_db enabled]
137 in ../nptl/sysdeps/unix/sysv/linux/i386/../fork.c
When coming to the last line (80 in fpm.c), I can do "ni" once, before
the second one triggers the loop again.
I could setup a remote box for you, if this would help you debugging
this. However, my fear grows that this is related to some Debian/Ubuntu
patch (and I should check vanilla PHP), but this also means that you
could try the Ubuntu build as well as a remote box.
Previous Comments:
------------------------------------------------------------------------
[2010-11-30 00:39:14] [email protected]
You can :
# gdb ./sapi/fpm/php-fpm
(gdb) set follow-fork-mode child
(gdb) break exit
Function "exit" not defined.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (exit) pending.
(gdb) run
...
(gdb) bt
------------------------------------------------------------------------
[2010-11-29 23:17:21] php-bugs at thequod dot de
Don't you see a possibility to attach gdb to the child process to see
where it is exiting?
What does exit code 1 refer to? Generic error?
Does it make sense to use specific exit codes for reference?
Where should I to start with adding debug output?
FWIW, this happens both with the Ubuntu package (available at
https://launchpad.net/ubuntu/+source/php5/5.3.3-1ubuntu9.1/+build/2003382
if you like to try reproducing it from there) and the package updated
using the source from the snapshot(s); I have not tried it unpatched.
However, there does not appear to be a fpm specific patch (apart from
config handling).
My packages are available from here:
https://launchpad.net/~blueyed/+archive/ppa/+packages
------------------------------------------------------------------------
[2010-11-29 23:17:08] php-bugs at thequod dot de
Don't you see a possibility to attach gdb to the child process to see
where it is exiting?
What does exit code 1 refer to? Generic error?
Does it make sense to use specific exit codes for reference?
Where should I to start with adding debug output?
FWIW, this happens both with the Ubuntu package (available at
https://launchpad.net/ubuntu/+source/php5/5.3.3-1ubuntu9.1/+build/2003382
if you like to try reproducing it from there) and the package updated
using the source from the snapshot(s); I have not tried it unpatched.
However, there does not appear to be a fpm specific patch (apart from
config handling).
My packages are available from here:
https://launchpad.net/~blueyed/+archive/ppa/+packages
------------------------------------------------------------------------
[2010-11-29 22:08:56] [email protected]
OK, children forks correctely. There is a problem somewhere after
fork().
What you can do (as I can't reproduice the problem and I don't have
access to a
server which has the same problem):
set only one pool with :
log_level = debug
pm = static
pm.max_children = 1
insert a log trace in the source code step by step to determine where
the bug
comes from.
I'm sorry not to be able to help you more.
------------------------------------------------------------------------
[2010-11-29 21:50:23] php-bugs at thequod dot de
It looks like this:
Nov 29 21:47:59.518416 [DEBUG] pid 29191, fpm_children_make(), line 377:
pid after fork=30301
Nov 29 21:47:59.518440 [NOTICE] pid 29191, fpm_children_make(), line
400: [pool www] child 30301 started
Nov 29 21:47:59.518451 [DEBUG] pid 30301, fpm_children_make(), line 377:
pid after fork=0
Nov 29 21:47:59.518981 [DEBUG] pid 29191, fpm_got_signal(), line 75:
received SIGCHLD
Nov 29 21:47:59.518995 [WARNING] pid 29191, fpm_children_bury(), line
249: [pool www] child 30301 exited with code 1 after 0.000562 seconds
from start
------------------------------------------------------------------------
The remainder of the comments for this report are too long. To view
the rest of the comments, please view the bug report online at
http://bugs.php.net/bug.php?id=53412
--
Edit this bug report at http://bugs.php.net/bug.php?id=53412&edit=1
