|
|
php.net | support | documentation | report a bug | advanced search | search howto | statistics | random bug | login |
PatchesPull RequestsHistoryAllCommentsChangesGit/SVN commits
[2018-09-17 09:10 UTC] florisjan dot gerrits at gmail dot com
[2018-10-16 11:03 UTC] mnikulin at plesk dot com
[2019-01-23 08:20 UTC] emayoral at arsys dot es
[2019-02-20 04:05 UTC] mnikulin at plesk dot com
[2019-07-23 08:14 UTC] nikic@php.net
[2019-09-02 11:18 UTC] mnikulin at plesk dot com
[2020-01-12 16:45 UTC] bukka@php.net
-Status: Open
+Status: Closed
-Assigned To:
+Assigned To: bukka
[2020-01-12 16:45 UTC] bukka@php.net
|
|||||||||||||||||||||||||||||||||||||
Copyright © 2001-2024 The PHP GroupAll rights reserved. |
Last updated: Thu Apr 18 05:01:28 2024 UTC |
Description: ------------ What you did: Browsed to a website using break/continue outside a loop and afterwards, I reloaded PHP-FPM. What I want to happen: I want PHP-FPM to successfully reload What actually happened: PHP-FPM got stuck in 'Waiting on reload...' and forced me to either restart or manually send a SIGKILL to the child that got stuck. (Force) Moving websites from PHP5.6 to PHP7.x made me to run into this bug. A lot of old websites use 'break' and 'continue' options in if-constructions (outside loops). An example: 2018/09/13 11:25:59 [error] 7861#7861: *8603 FastCGI sent in stderr: "PHP message: PHP Fatal error: 'break' not in the 'loop' or 'switch' context in /home/florisjantest.nl/public_html/index.php on line 5" while reading response header from upstream, client: 0.0.0.0, server: florisjantest.nl, request: "GET / HTTP/1.1", upstream: "fastcgi://unix:/var/run/php-fpm.florisjantest.nl.socket:", host: "florisjantest.nl" This Fatal error triggers the PHP-FPM child to become unresponsive and ignore any and all signals except for SIGKILL. Trying to reload PHP-FPM will cause the master to get stuck in 'waiting on reload' status and will not allow any new connections. Technical: What you did: trigger the error and reload PHP-FPM What I want to happen: [pid 6324] kill(7893, SIGQUIT) = 0 [pid 6324] getpid() = 6324 [pid 6324] getpid() = 6324 [pid 6324] epoll_wait(8, <unfinished ...> [pid 7893] <... accept resumed> 0x7ffd46708d70, [112]) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) [pid 7893] --- SIGQUIT {si_signo=SIGQUIT, si_code=SI_USER, si_pid=6324, si_uid=0} --- [pid 7893] close(0) = 0 [pid 7893] socket(AF_UNIX, SOCK_STREAM, 0) = 0 [pid 7893] rt_sigreturn({mask=[]}) = 43 [pid 7893] accept(0, 0x7ffd46708d70, [112]) = -1 EINVAL (Invalid argument) [pid 7893] munmap(0x7ffab1d13000, 67108864) = 0 [pid 7893] close(3) What actually happened: [pid 22815] kill(8176, SIGQUIT) = 0 [pid 22815] getpid() = 22815 [pid 22815] getpid() = 22815 [pid 22815] epoll_wait(9, <unfinished ...> [pid 8176] <... accept resumed> 0x7ffd81ca33d0, [112]) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) [pid 8176] --- SIGQUIT {si_signo=SIGQUIT, si_code=SI_USER, si_pid=22815, si_uid=0} --- [pid 8176] rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) [pid 8176] accept(10, <unfinished ...> [pid 22815] <... epoll_wait resumed> [], 1, 1000) = 0 [pid 22815] getpid() = 22815 Loaded modules: # php-fpm7.2 -m [PHP Modules] bcmath bz2 calendar cgi-fcgi Core ctype curl date dom exif fileinfo filter ftp gd gettext hash iconv imap intl json ldap libxml mbstring mysqli mysqlnd openssl pcre PDO pdo_mysql pdo_pgsql pdo_sqlite pgsql Phar posix readline Reflection session shmop SimpleXML soap sockets sodium SPL sqlite3 standard sysvmsg sysvsem sysvshm tokenizer wddx xml xmlreader xmlwriter xsl Zend OPcache zip zlib [Zend Modules] Zend OPcache Test script: --------------- <?php $variabele = 'TEST'; if (!empty($variabele)) { break; } Actual result: -------------- After requesting the above mentioned script the following situation will occur: The master process issues a SIGQUIT every 10 seconds: epoll_wait(9, [], 1, 1000) = 0 getpid() = 22080 kill(22106, SIGQUIT) = 0 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 1000) = 0 getpid() = 22080 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 992) = 0 getpid() = 22080 socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 10 getsockopt(10, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0 setsockopt(10, SOL_SOCKET, SO_SNDBUFFORCE, [8388608], 4) = 0 getuid() = 0 geteuid() = 0 getgid() = 0 getegid() = 0 sendmsg(10, {msg_name={sa_family=AF_UNIX, sun_path="/run/systemd/notify"}, msg_namelen=21, msg_iov=[{iov_base="READY=1\nSTATUS=Processes active: 0, idle: 1, Requests: 1, slow: 0, Traffic: 0req/sec", iov_len=84}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 84 An strace on the child process shows the following: accept(10, 0x7fff77012e90, [112]) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) --- SIGQUIT {si_signo=SIGQUIT, si_code=SI_USER, si_pid=22080, si_uid=0} --- rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) accept(10, The situation changes when you initiate a reload of PHP-FPM. The reload will signal SIGUSR2, it sends another SIGQUIT to the child and after 10 seconds it will send a SIGTERM. This is where no further signals are given to the child. No new SIGQUITs no new SIGTERMs and no SIGKILLs (although that's probably okay). The broken child is still active and upholding the master from reloading: # systemctl reload php7.2-fpm.service # ps axuf | grep php root 22697 0.0 0.2 14432 1020 pts/0 S+ 11:40 0:00 \_ grep php root 22080 0.0 6.1 486688 30532 ? Ss 11:25 0:00 php-fpm: master process (/etc/php/7.2/fpm/php-fpm.conf) florisja 22106 0.0 3.8 489292 18984 ? S 11:25 0:00 \_ php-fpm: pool florisjantest.nl Reload in master: epoll_wait(9, 0x55fbc277db10, 1, 1000) = -1 EINTR (Interrupted system call) --- SIGUSR2 {si_signo=SIGUSR2, si_code=SI_USER, si_pid=22692, si_uid=0} --- getpid() = 22080 write(6, "2", 1) = 1 rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) getpid() = 22080 epoll_wait(9, [{EPOLLIN, {u32=3228071840, u64=94539753224096}}], 1, 773) = 1 read(5, "2", 1) = 1 write(4, "[13-Sep-2018 11:40:35] NOTICE: Reloading in progress ...\n", 57) = 57 kill(22106, SIGQUIT) = 0 read(5, 0x7fff77012e77, 1) = -1 EAGAIN (Resource temporarily unavailable) getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 772) = 0 getpid() = 22080 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 1000) = 0 getpid() = 22080 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 1000) = 0 getpid() = 22080 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 795) = 0 getpid() = 22080 socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 10 getsockopt(10, SOL_SOCKET, SO_SNDBUF, [212992], [4]) = 0 setsockopt(10, SOL_SOCKET, SO_SNDBUFFORCE, [8388608], 4) = 0 getuid() = 0 geteuid() = 0 getgid() = 0 getegid() = 0 sendmsg(10, {msg_name={sa_family=AF_UNIX, sun_path="/run/systemd/notify"}, msg_namelen=21, msg_iov=[{iov_base="READY=1\nSTATUS=Processes active: 0, idle: 2, Requests: 1, slow: 0, Traffic: 0req/sec", iov_len=84}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 84 close(10) = 0 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 202) = 0 getpid() = 22080 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 1000) = 0 getpid() = 22080 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 222) = 0 kill(22106, SIGTERM) = 0 getpid() = 22080 getpid() = 22080 epoll_wait(9, [], 1, 777) = 0 Reload in child: --- SIGQUIT {si_signo=SIGQUIT, si_code=SI_USER, si_pid=22080, si_uid=0} --- rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) accept(10, 0x7fff77012e90, [112]) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=22080, si_uid=0} --- rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) accept(10, As mentioned above, no new SIGQUIT signals will follow. The master gets the status 'Waiting on reload...' and doesn't seem to think the child is still there. Initiating a restart of PHP-FPM will show the following: # systemctl restart php7.2-fpm.service # ps axuf root 22815 0.0 6.1 486688 30352 ? Ss 11:47 0:00 php-fpm: master process (/etc/php/7.2/fpm/php-fpm.conf) Master: --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=1, si_uid=0} --- getpid() = 22080 write(6, "T", 1) = 1 rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) --- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=1, si_uid=0} --- getpid() = 22080 epoll_wait(9, [{EPOLLIN, {u32=3228071840, u64=94539753224096}}], 1, 968) = 1 read(5, "T", 1) = 1 write(4, "[13-Sep-2018 11:47:54] NOTICE: Terminating ...\n", 47) = 47 kill(22106, SIGTERM) = 0 read(5, 0x7fff77012e77, 1) = -1 EAGAIN (Resource temporarily unavailable) ...... kill(22106, SIGKILL) = 0 getpid() = 22080 getpid() = 22080 epoll_wait(9, 0x55fbc277db10, 1, 968) = -1 EINTR (Interrupted system call) --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=22106, si_uid=1003, si_status=SIGKILL, si_utime=0, si_stime=1} --- getpid() = 22080 write(6, "C", 1) = 1 rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) getpid() = 22080 epoll_wait(9, [{EPOLLIN, {u32=3228071840, u64=94539753224096}}], 1, 963) = 1 read(5, "C", 1) = 1 wait4(-1, [{WIFSIGNALED(s) && WTERMSIG(s) == SIGKILL}], WNOHANG|WSTOPPED, NULL) = 22106 write(4, "[13-Sep-2018 11:47:59] NOTICE: exiting, bye-bye!\n", 49) = 49 Child: 0x7fff77012e90, [112]) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=1, si_uid=0} --- --- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=1, si_uid=0} --- rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) accept(10, 0x7fff77012e90, [112]) = ? ERESTARTSYS (To be restarted if SA_RESTART is set) --- SIGTERM {si_signo=SIGTERM, si_code=SI_USER, si_pid=22080, si_uid=0} --- rt_sigreturn({mask=[]}) = -1 EINTR (Interrupted system call) accept(10, <unfinished ...>) = ? +++ killed by SIGKILL +++