Block signals during fpm master initialization #4471

plmnikulin · 2019-07-24T10:05:56Z

Fix PHP-FPM failure in the case of concurrent reload attempts.

Postpone signal delivery to the fpm master process till proper signal
handlers are set. Prevent the following case:

Running master process receives SIGUSR2 and performs execvp().
Another SIGUSR2 is arrived before signal handlers are set.
Master process dies.
Requests to the HTTP server handled by PHP-fpm can not be served
any more.

Block some signals using sigprocmask() before execvp() and early
in the main() function. Unblock signals as soon as proper
handlers are set.

Fixes bug #74083

Fix PHP-FPM failure in the case of concurrent reload attempts. Postpone signal delivery to the fpm master process till proper signal handlers are set. Prevent the following case: - Running master process receives `SIGUSR2` and performs `execvp()`. - Another `SIGUSR2` is arrived before signal handlers are set. - Master process dies. - Requests to the HTTP server handled by PHP-fpm can not be served any more. Block some signals using `sigprocmask()` before `execvp()` and early in the `main()` function. Unblock signals as soon as proper handlers are set. Fixes bug #74083

plmnikulin · 2019-07-24T10:14:09Z

I have a patch for Bug #76601 but it adds more code to same places so independent pull request will conflict with this one. That is why I am expecting review of this change at first.

bukka · 2019-07-24T16:55:54Z

As I said in the bug report, this one needs a test.

I have got actually some changes in fpmi (sort of my testing version of fpm) for that so it's possible to enable automatically opcache in FPMi tests. Essentially these are the changes in the tester (might be missing some later changes maybe):

bukka/fpmi@9baff5d

and this is the test:

https://github.com/bukka/fpmi/blob/e0c2e8ec725ce5ee7749407f4b404d190cc37829/tests/bug76895-reload-after-error.phpt

I will need to port it to FPM and do a bit more testing.

I think it looks good in general but need to think about it a bit more. In the worst case we might just merge it to 7.4 and see what happens... :)

plmnikulin · 2019-07-25T06:10:56Z

This particular issue #74083 has nothing common with opcache.

The full story is the following. We were receiving complains concerning PHP-FPM crashes during reload and so web-sites downtime but the root cause was unclear. Concurrent reload #74083 was the most obvious problem. Before this patch was ready, I faced #76601 that is even more weird (the state could be unnoticed by watchdogs) and has no common with opcache as well. The latter is currently hidden by the bug #74083, and it is easier to reproduce bug #76601 when this patch is applied. I believe that #76601 is quite rare in real life scenarios. I prepared a patch currently submitted as the pull request #4460 that is enough to make php bug #76601 invisible (the pull request #4465 by @nikic is likely even better). Later we accidentally realized that #76895 may be the most probable origin of reload "hangs" and the pull request #4460 surprisingly fixes it. It is not a crash however. You know, people tell you that it was PHP-FPM crash even actually their site was unavailable due to "scoreboard is full" in apache.

In #76601 thread on bugs.php.net I posted my unsuccessful attempts to write a test for the bug #76895. I could not figure out that syntax error problem is tightly bound to opcache before. Now @nikic is trying to fix bug #76895 in #4461 so I believe that tests involving opcache should be discussed there.

I have tried to add a test, but race condition tests usually require some non-negligible time to achieve high enough probability of failure and depend on performance of an executor. People usually complain that they already have enough slow tests.

From my point of view this pull request should be merged after #4465 or #4460. Additional patch against #76601 is preferable but not strictly required.

plmnikulin · 2019-07-25T06:11:54Z

Look e.g. at fpm_events.c#L440 I suspect that such workarounds are required due to lack of proper signal blocking during some operations. This patch is the first part to fix such cases.

Have not expected side effects of `include`.

plmnikulin · 2019-07-29T04:59:52Z

sapi/fpm/tests/bug74083-concurrent-reload.phpt

+echo "Reached interval $interval us with $step us steps\n";
+$tester->expectLogNotice('Reloading in progress ...');
+/* Consume mix of 'Reloading in progress ...' and 'reloading: .*' */
+$tester->getLogLines(2000);


Test spends 2 seconds here due to timeout. Test will be unreliable with exact number of lines since number of actual reloads may vary. Reload may be interrupted issued only a part of logs. More careful analysis of output requires reimplementation of functions like expectLogStartNotices(). That is why extra delay could hardly be avoided.

Yeah I will try to find some time to take a look on this so we can remove the slow test flag...

krakjoe · 2019-09-30T09:06:32Z

@bukka could you take care of this and the related requests please ?

plmnikulin · 2019-10-03T04:15:37Z

sapi/fpm/fpm/fpm_main.c

@@ -109,6 +109,10 @@ int __riscosify_control = __RISCOSIFY_STRICT_UNIX_SPECS;
 #include "fpm_log.h"
 #include "zlog.h"

+#if HAVE_SIGNAL_H


Notice that HAVE_SIGNAL_H has been removed in 7.4 5f89157

Fixed in the rebase...

plmnikulin · 2019-10-03T04:26:21Z

This pull request requires #4465 (merged to 7.4 only yet) or additional changes in children spawning that use functions introduced here.

bukka · 2019-10-06T18:48:41Z

I tried to run the test in FPMi: bukka/fpmi@9d02a13

But getting this:

sh: line 1: 13619 User defined signal 2   /home/jakub/prog/php/74/sapi/fpmi/php-fpmi -F -O -y /home/jakub/prog/php/74/sapi/fpmi/tests/bug74083-concurrent-reload.ini 2>&1
sh: line 0: kill: (13619) - No such process
ERROR: master process is dead
Reached interval 4000 us with 1000 us steps
sh: line 0: kill: (13619) - No such process
ERROR: The NOTICE does not match expected message:
- PATTERN: /^\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d\] NOTICE: Reloading in progress ...$/
- MESSAGE: 
- EXPECT: 'Reloading in progress ...'
- ACTUAL: ''
Done

This fix should be in it but might be because I'm missing some other fixes. Will probably need to look a bit more and port other stuff as well or will just try it in FPM.

bukka · 2019-10-06T18:50:18Z

@plmnikulin just to double check if the test is working fine for you in 7.4?

plmnikulin · 2019-10-10T11:18:28Z

Sorry, I am quite busy these days.

I rebased 3 commits of this pull request to 5b44560,
tried a minimal variant in Ubuntu-18.04 lxc container ../php-src/configure --prefix /opt/issue-74083-7.4 --disable-fpmi --enable-fpm --enable-pcntl --enable-opcache, however opcache and fpmi are irrelevant here
make test VERBOSE=1 TESTS='sapi/fpm/tests/bug74083-concurrent-reload.phpt' passed
To check that test works I tried 5b44560 and sapi/fpm/tests/bug74083-concurrent-reload.phpt taken from the rebased branch. The test fails.

---- EXPECTED OUTPUT
Reached interval 25000 us with 1000 us steps
Done
---- ACTUAL OUTPUT
Reached interval 25000 us with 1000 us steps
ERROR: The NOTICE does not match expected message:
- PATTERN: /^\[\d\d-\w\w\w-\d{4} \d\d:\d\d:\d\d\] NOTICE: Reloading in progress ...$/
- MESSAGE: 
- EXPECT: 'Reloading in progress ...'
- ACTUAL: ''
Done
---- FAILED

Please, provide more details on your environment (maybe backtrace from coredump could be useful) if you suspect that the problem is not completely fixed. I have not checked if you have a patch fixing SIGKILL for children in the fpmi project.

bukka · 2019-10-20T16:05:55Z

@plmnikulin I made it work and the tests passes when patch is applied and fails when it's not which is good.

I merged to PHP 7.4 only for now so it gets in at least. If it's all good after 7.4 gets some usage, we might consider back port to 7.3

plmnikulin · 2019-10-21T08:34:47Z

Promised patch against Bug #76601: #4836

nikic added the Bug label Jul 24, 2019

nikic requested a review from bukka July 24, 2019 10:30

Add (slow) test for fpm concurrent reloads #74083

1cbea19

Skip fpm bug #74083 test on Windows

8948a33

Have not expected side effects of `include`.

plmnikulin commented Jul 29, 2019

View reviewed changes

plmnikulin mentioned this pull request Jul 30, 2019

Fix bug #76895 #4461

Closed

krakjoe assigned bukka Sep 30, 2019

krakjoe added the Waiting on Review label Sep 30, 2019

plmnikulin commented Oct 3, 2019

View reviewed changes

bukka closed this Oct 20, 2019

plmnikulin mentioned this pull request Oct 21, 2019

Do not let PHP-FPM children miss SIGTERM, SIGQUIT #4836

Closed

plmnikulin deleted the issue-74083 branch February 18, 2020 07:43

kocsismate removed the Waiting on Review label May 29, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Block signals during fpm master initialization #4471

Block signals during fpm master initialization #4471

Uh oh!

plmnikulin commented Jul 24, 2019

Uh oh!

plmnikulin commented Jul 24, 2019

Uh oh!

bukka commented Jul 24, 2019 •

edited

Loading

Uh oh!

plmnikulin commented Jul 25, 2019

Uh oh!

plmnikulin commented Jul 25, 2019

Uh oh!

plmnikulin Jul 29, 2019

Uh oh!

bukka Oct 20, 2019

Uh oh!

krakjoe commented Sep 30, 2019

Uh oh!

plmnikulin Oct 3, 2019

Uh oh!

bukka Oct 20, 2019

Uh oh!

plmnikulin commented Oct 3, 2019

Uh oh!

bukka commented Oct 6, 2019

Uh oh!

bukka commented Oct 6, 2019

Uh oh!

plmnikulin commented Oct 10, 2019

Uh oh!

bukka commented Oct 20, 2019

Uh oh!

plmnikulin commented Oct 21, 2019

Uh oh!

Uh oh!

Block signals during fpm master initialization #4471

Block signals during fpm master initialization #4471

Uh oh!

Conversation

plmnikulin commented Jul 24, 2019

Uh oh!

plmnikulin commented Jul 24, 2019

Uh oh!

bukka commented Jul 24, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

plmnikulin commented Jul 25, 2019

Uh oh!

plmnikulin commented Jul 25, 2019

Uh oh!

plmnikulin Jul 29, 2019

Choose a reason for hiding this comment

Uh oh!

bukka Oct 20, 2019

Choose a reason for hiding this comment

Uh oh!

krakjoe commented Sep 30, 2019

Uh oh!

plmnikulin Oct 3, 2019

Choose a reason for hiding this comment

Uh oh!

bukka Oct 20, 2019

Choose a reason for hiding this comment

Uh oh!

plmnikulin commented Oct 3, 2019

Uh oh!

bukka commented Oct 6, 2019

Uh oh!

bukka commented Oct 6, 2019

Uh oh!

plmnikulin commented Oct 10, 2019

Uh oh!

bukka commented Oct 20, 2019

Uh oh!

plmnikulin commented Oct 21, 2019

Uh oh!

Uh oh!

bukka commented Jul 24, 2019 •

edited

Loading