From:
Operating system: Linux
PHP version: 5.3SVN-2010-11-26 (snap)
Package: FPM related
Bug Type: Bug
Bug description:php-fpm children constantly exiting (immediately)
Description:
------------
I have installed php-fpm via yesterday's snapshot.
When starting it, the children appear to constantly exit right away.
This is from the logs:
Nov 26 12:15:12.947902 [NOTICE] pid 13248, fpm_children_make(), line 403:
[pool www] child 15605 started
Nov 26 12:15:12.948456 [DEBUG] pid 13248, fpm_got_signal(), line 48:
received SIGCHLD
Nov 26 12:15:12.948473 [WARNING] pid 13248, fpm_children_bury(), line 249:
[pool www] child 15605 exited with code 1 after 0.000595 seconds from
start
Nov 26 12:15:12.948901 [NOTICE] pid 13248, fpm_children_make(), line 403:
[pool www] child 15606 started
Nov 26 12:15:12.949390 [DEBUG] pid 13248, fpm_got_signal(), line 48:
received SIGCHLD
Nov 26 12:15:12.949406 [WARNING] pid 13248, fpm_children_bury(), line 249:
[pool www] child 15606 exited with code 1 after 0.000532 seconds from
start
Nov 26 12:15:12.949737 [NOTICE] pid 13248, fpm_children_make(), line 403:
[pool www] child 15607 started
Nov 26 12:15:12.950274 [DEBUG] pid 13248, fpm_got_signal(), line 48:
received SIGCHLD
Nov 26 12:15:12.950291 [WARNING] pid 13248, fpm_children_bury(), line 249:
[pool www] child 15607 exited with code 1 after 0.000572 seconds from
start
Nov 26 12:15:12.950646 [NOTICE] pid 13248, fpm_children_make(), line 403:
[pool www] child 15608 started
Nov 26 12:15:12.951116 [DEBUG] pid 13248, fpm_got_signal(), line 48:
received SIGCHLD
Nov 26 12:15:12.951132 [WARNING] pid 13248, fpm_children_bury(), line 249:
[pool www] child 15608 exited with code 1 after 0.000503 seconds from
start
I have started it using gdb to get a backtrace (from the master), and this
looks like:
Nov 26 12:15:12.952358 [NOTICE] pid 13248, fpm_children_make(), line 403:
[pool www] child 15610 started
^Z
Program received signal SIGTSTP, Stopped (user).
0xb7a9612c in epoll_wait () from /lib/libc.so.6
(gdb) bt
#0 0xb7a9612c in epoll_wait () from /lib/libc.so.6
#1 0xb7b21c97 in ?? () from /usr/lib/libevent-1.4.so.2
#2 0xb7b14c5a in event_base_loop () from /usr/lib/libevent-1.4.so.2
#3 0xb7b15095 in event_base_dispatch () from /usr/lib/libevent-1.4.so.2
#4 0x083ab9f6 in fpm_event_loop (base=0x8921ef8) at
/build/buildd/php5-5.3.4~snap201011251930/sapi/fpm/fpm/fpm_events.c:112
#5 0x083a7130 in fpm_run (max_requests=0xbfffd580, base=0x8921ef8) at
/build/buildd/php5-5.3.4~snap201011251930/sapi/fpm/fpm/fpm.c:76
#6 0x083ad45e in main (argc=3, argv=0xbffff684) at
/build/buildd/php5-5.3.4~snap201011251930/sapi/fpm/fpm/fpm_main.c:1787
Maybe not really useful, but still..
Here's a "strace -f" of the process:
write(2, "Nov 26 12:22:46.736565 [WARNING]"..., 151Nov 26 12:22:46.736565
[WARNING] pid 23701, fpm_children_bury(), line 249: [pool www] child 25335
exited with code 1 after 0.001438 seconds from start
) = 151
pipe([10, 11]) = 0
pipe([12, 13]) = 0
fcntl64(10, F_GETFL) = 0 (flags O_RDONLY)
fcntl64(10, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
fcntl64(12, F_GETFL) = 0 (flags O_RDONLY)
fcntl64(12, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7019748) = 25336
clock_gettime(CLOCK_MONOTONIC, {1760242, 289405933}) = 0
close(11) = 0
close(13) = 0
epoll_ctl(7, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=10}}) = 0
epoll_ctl(7, EPOLL_CTL_ADD, 12, {EPOLLIN, {u32=12, u64=12}}) = 0
gettimeofday({1290770566, 737322}, NULL) = 0
write(2, "Nov 26 12:22:46.737322 [NOTICE] "..., 105Nov 26 12:22:46.737322
[NOTICE] pid 23701, fpm_children_make(), line 403: [pool www] child 25336
started
) = 105
waitpid(-1, 0xbfaa8c18, WNOHANG|WSTOPPED) = 0
read(4, 0xbfaa8cef, 1) = -1 EAGAIN (Resource temporarily
unavailable)
epoll_wait(7, {{EPOLLHUP, {u32=10, u64=10}}}, 32, 10) = 1
--- SIGCHLD (Child exited) @ 0 (0) ---
write(5, "C", 1) = 1
sigreturn() = ? (mask now [])
clock_gettime(CLOCK_MONOTONIC, {1760242, 290274890}) = 0
read(10, "", 1023) = 0
epoll_ctl(7, EPOLL_CTL_DEL, 10, {EPOLLIN, {u32=10, u64=10}}) = 0
close(10) = 0
epoll_wait(7, {{EPOLLHUP, {u32=12, u64=12}}, {EPOLLIN, {u32=4, u64=4}}},
32, 9) = 2
clock_gettime(CLOCK_MONOTONIC, {1760242, 290435633}) = 0
read(12, "", 1023) = 0
epoll_ctl(7, EPOLL_CTL_DEL, 12, {EPOLLIN, {u32=12, u64=12}}) = 0
close(12) = 0
read(4, "C", 1) = 1
gettimeofday({1290770566, 738251}, NULL) = 0
write(2, "Nov 26 12:22:46.738251 [DEBUG] p"..., 86Nov 26 12:22:46.738251
[DEBUG] pid 23701, fpm_got_signal(), line 48: received SIGCHLD
) = 86
waitpid(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 1}], WNOHANG|WSTOPPED) =
25336
clock_gettime(CLOCK_MONOTONIC, {1760242, 290729116}) = 0
gettimeofday({1290770566, 738426}, NULL) = 0
write(2, "Nov 26 12:22:46.738426 [WARNING]"..., 151Nov 26 12:22:46.738426
[WARNING] pid 23701, fpm_children_bury(), line 249: [pool www] child 25336
exited with code 1 after 0.001324 seconds from start
) = 151
Although using "catch_workers_output = yes" I do not see anything in the
log related to child exiting.
--
Edit bug report at http://bugs.php.net/bug.php?id=53412&edit=1
--
Try a snapshot (PHP 5.2):
http://bugs.php.net/fix.php?id=53412&r=trysnapshot52
Try a snapshot (PHP 5.3):
http://bugs.php.net/fix.php?id=53412&r=trysnapshot53
Try a snapshot (trunk):
http://bugs.php.net/fix.php?id=53412&r=trysnapshottrunk
Fixed in SVN:
http://bugs.php.net/fix.php?id=53412&r=fixed
Fixed in SVN and need be documented:
http://bugs.php.net/fix.php?id=53412&r=needdocs
Fixed in release:
http://bugs.php.net/fix.php?id=53412&r=alreadyfixed
Need backtrace:
http://bugs.php.net/fix.php?id=53412&r=needtrace
Need Reproduce Script:
http://bugs.php.net/fix.php?id=53412&r=needscript
Try newer version:
http://bugs.php.net/fix.php?id=53412&r=oldversion
Not developer issue:
http://bugs.php.net/fix.php?id=53412&r=support
Expected behavior:
http://bugs.php.net/fix.php?id=53412&r=notwrong
Not enough info:
http://bugs.php.net/fix.php?id=53412&r=notenoughinfo
Submitted twice:
http://bugs.php.net/fix.php?id=53412&r=submittedtwice
register_globals:
http://bugs.php.net/fix.php?id=53412&r=globals
PHP 4 support discontinued: http://bugs.php.net/fix.php?id=53412&r=php4
Daylight Savings: http://bugs.php.net/fix.php?id=53412&r=dst
IIS Stability:
http://bugs.php.net/fix.php?id=53412&r=isapi
Install GNU Sed:
http://bugs.php.net/fix.php?id=53412&r=gnused
Floating point limitations:
http://bugs.php.net/fix.php?id=53412&r=float
No Zend Extensions:
http://bugs.php.net/fix.php?id=53412&r=nozend
MySQL Configuration Error:
http://bugs.php.net/fix.php?id=53412&r=mysqlcfg
