Edit report at http://bugs.php.net/bug.php?id=52796&edit=1
ID: 52796
User updated by: momchil at xaxo dot eu
Reported by: momchil at xaxo dot eu
Summary: Sep 08 15:22:32.861368 [WARNING] [pool www0] child
25271 said into stderr: "php
-Status: Feedback
+Status: Assigned
Type: Bug
Package: FPM related
Operating System: linux
PHP Version: 5.3SVN-2010-09-08 (SVN)
Assigned To: fat
Block user comment: N
New Comment:
1,2,4,5 are known.
about forking: I thought you mean forking inside php code and did not
thought about system(), there is some code using the system() function.
reloading: I did not reload fpm at the moment when the crash happened,
we are reloading it on fpm.conf/php.ini changes
about what I wrote just before on 2010-09-09 21:38 UTC: I was told that
the mail() function has been used about 1500 times in a script for
sending newsletter, which might be related as you pointed out.
I will try without the emergency restart as you suggest, thank you for
the pointers and your time investigating this :)
Previous Comments:
------------------------------------------------------------------------
[2010-09-09 23:47:47] fat@php.net
You have a lots of error in your LOG file:
1- Sep 08 14:10:10.251071 [WARNING] [pool www0] child 13097 said into
stderr: "Connection from
disallowed IP address '10.13.20.24' is dropped."
you should allow those IP address
2- you have a lots of PHP errors which are written to stdout. Search for
"said into stderr" in
you LOG file.
3- You have calls from external command (rm, convert). when run, php
forks for running those
command. The problem seem to be similar to bug
http://bugs.php.net/52501
4- you have a lot of requests which are executing too slow after 15s and
which are ptraced to
slowlog.
5- you have a lot of requests which are timeouted after 30s.
6- you have a lot of warning saying your server "seems busy". you should
review your
configuration file to increase min/max_spare_server.
4- I asked if you did reload FPM. You said no and your LOG file says you
had:
Sep 08 03:10:07.634996 [NOTICE] using inherited socket fd=6,
"10.13.20.26:9910"
5- I asked if your PHP scripts forks somehow. It appears so
finaly, the problem occurs when:
- some PHP scripts are forking some process (via system() or mail())
- FPM is reloading via emergency_restart_threshold
It's a bug related to libevent and forking. I'm on it. You should try
disabling
emergency_restart_threshold temporarily.
------------------------------------------------------------------------
[2010-09-09 23:43:14] momchil at xaxo dot eu
fpm.conf of the above one:
[global]
pid = /var/run/php-fpm.pid
error_log = /var/log/php/php-fpm.log
log_level = notice
emergency_restart_threshold = 10
emergency_restart_interval = 1m
process_control_timeout = 5s
daemonize = yes
[www0]
listen = 127.0.0.1:9910
listen.backlog = -1
listen.allowed_clients = 127.0.0.1
user = php
group = php
pm = dynamic
pm.max_children = 100
pm.start_servers = 10
pm.min_spare_servers = 5
pm.max_spare_servers = 20
pm.max_requests = 500
pm.status_path = /status
ping.path = /ping
ping.response = pong
request_terminate_timeout = 30s
request_slowlog_timeout = 15s
slowlog = /var/log/php/php-fpm-0.log.slow
rlimit_files = 20000
rlimit_core = 0
catch_workers_output = yes
env[HOSTNAME] = $HOSTNAME
env[PATH] = /usr/local/bin:/usr/bin:/bin
env[TMP] = /tmp
env[TMPDIR] = /tmp
env[TEMP] = /tmp
------------------------------------------------------------------------
[2010-09-09 23:38:24] momchil at xaxo dot eu
umf... got it on another server with another website running r301234
Sep 10 00:08:15.534321 [WARNING] [pool www0] child 25119, script
'/www/grabo.bg/www/root/index.php' execution timed out (30.126267 sec),
terminating
Sep 10 00:08:15.537840 [WARNING] [pool www0] child 25119 exited on
signal 15 SIGTERM after 124.330987 seconds from start
Sep 10 00:08:15.538251 [NOTICE] [pool www0] child 27012 started
Sep 10 00:08:15.539222 [WARNING] [pool www0] child 27012 exited on
signal 11 SIGSEGV after 0.000991 seconds from start
Sep 10 00:08:15.539538 [NOTICE] [pool www0] child 27013 started
Sep 10 00:08:15.544915 [WARNING] [pool www0] child 27013 exited on
signal 11 SIGSEGV after 0.005390 seconds from start
Sep 10 00:08:15.545278 [NOTICE] [pool www0] child 27015 started
Sep 10 00:08:15.554279 [WARNING] [pool www0] child 27015 exited on
signal 11 SIGSEGV after 0.009020 seconds from start
Sep 10 00:08:15.554629 [NOTICE] [pool www0] child 27016 started
Sep 10 00:08:15.555623 [WARNING] [pool www0] child 27016 exited on
signal 11 SIGSEGV after 0.001011 seconds from start
Sep 10 00:08:15.555929 [NOTICE] [pool www0] child 27017 started
Sep 10 00:08:15.556648 [WARNING] [pool www0] child 27017 exited on
signal 11 SIGSEGV after 0.000739 seconds from start
Sep 10 00:08:15.556904 [NOTICE] [pool www0] child 27018 started
Sep 10 00:08:15.557602 [WARNING] [pool www0] child 27018 exited on
signal 11 SIGSEGV after 0.000720 seconds from start
Sep 10 00:08:15.557848 [NOTICE] [pool www0] child 27019 started
Sep 10 00:08:15.558532 [WARNING] [pool www0] child 27019 exited on
signal 11 SIGSEGV after 0.000705 seconds from start
Sep 10 00:08:15.558774 [NOTICE] [pool www0] child 27020 started
Sep 10 00:08:15.559492 [WARNING] [pool www0] child 27020 exited on
signal 11 SIGSEGV after 0.000738 seconds from start
Sep 10 00:08:15.559747 [NOTICE] [pool www0] child 27021 started
Sep 10 00:08:15.560549 [WARNING] [pool www0] child 27021 exited on
signal 11 SIGSEGV after 0.000822 seconds from start
Sep 10 00:08:15.560911 [NOTICE] [pool www0] child 27022 started
Sep 10 00:08:15.561798 [WARNING] [pool www0] child 27022 exited on
signal 11 SIGSEGV after 0.000905 seconds from start
Sep 10 00:08:15.561850 [WARNING] failed processes threshold (10 in 60
sec) is reached, initiating reload
Sep 10 00:08:15.650499 [NOTICE] reloading:
execvp("/usr/local/php/sbin/php-fpm", {"/usr/local/php/sbin/php-fpm"})
php-fpm: event.c:261: event_base_free: Assertion
`(((&base->eventqueue)->tqh_first) == ((void *)0))' failed.
------------------------------------------------------------------------
[2010-09-08 15:11:02] momchil at xaxo dot eu
http://img01.gepime.com/php-fpm.confhttp://img01.gepime.com/php-fpm.log
btw the log is 334MB (it's a busy server)
------------------------------------------------------------------------
[2010-09-08 14:56:51] fat@php.net
can you pastbin the full php-fpm.log and your config please ?
------------------------------------------------------------------------
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=52796--
Edit this bug report at http://bugs.php.net/bug.php?id=52796&edit=1