Bug #81275 [Opn]: status page, contain bugus value in request duration sometimes
| From: | tsmtgdi at gmail dot com | Date: | Mon, 19 Jul 2021 20:06:49 +0000 |
| Subject: | Bug #81275 [Opn]: status page, contain bugus value in request duration sometimes | ||
| References: | 1 | Groups: | php.bugs |
| Request: | Send a blank email to php-bugs+get-235193@lists.php.net to get a copy of this message | ||
Edit report at https://bugs.php.net/bug.php?id=81275&edit=1
ID: 81275
User updated by: tsmtgdi at gmail dot com
Reported by: tsmtgdi at gmail dot com
Summary: status page, contain bugus value in request duration
sometimes
Status: Open
Type: Bug
Package: FPM related
Operating System: Suse
PHP Version: 8.1Git-2021-07-19 (Git)
Block user comment: N
Private report: N
New Comment:
After reviewing the code, I think the logic is correct, the problem is in some missing mutex or sync
problem, for example I discovered having a single fpm process will never trigger the error.
Also I had case of
[pid] => 0
[state] => (null)
[start time] => 0
[start since] => 1626722020
[requests] => 0
[request duration] => 51276947114
Which is... in theory impossible
What I discovered is that, the proc = *scoreboard_p->procs[i];
Is not doing a correct copy, I have stack trace in which the proc is different from the
scoreboard_p->procs[0]
https://pastebin.com/Hxgwq1c1
I can say that "maybe" the operation is done outside of the mutex (in fact around line 196
you have a
/* copy the scoreboard not to bother other processes */
scoreboard = *scoreboard_p;
fpm_unlock(scoreboard_p->lock);)
I will later try to use this copy.
Previous Comments:
------------------------------------------------------------------------
[2021-07-19 18:24:19] tsmtgdi at gmail dot com
I forget to add, I just compiled the php code (very easy! bravo!), and I will now try with the help
of two coworker to do a patch.
------------------------------------------------------------------------
[2021-07-19 18:23:32] tsmtgdi at gmail dot com
Description:
------------
When accessing the php-fpm status page (pm.status_path), when the process is in status "Reading
headers", "Finishing" and "Starting", we have several cases in which the
value request duration is bogus, we suspect is just reading an uninitialized memory location, we can
even have value of 18446744073709551592 (almost all bit set)...
Test script:
---------------
Is quite easy, you have to poll with very high frequency the status page while doing many small
request to increase the chance to find this bug.
you can use siege or ab2 so simulate traffic on a dummy page (even empty is fine)
and something like
It should take 4/5 second at most on a free running loop...
<?php
while(true){
$json = file_get_contents("http://127.0.0.1/status.php?json&full");
$result = json_decode($json);
$processes = $result->processes;
foreach ($processes as $proc){
//a dummy page should take low time to be gen no ?
if($proc->{"request duration"} > 1000000){
echo "impossible value found!";
print_r($proc);
echo "\n";
die();
}
}
}
------------------------------------------------------------------------
--
Edit this bug report at https://bugs.php.net/bug.php?id=81275&edit=1