php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login

go to bug id or search bugs for

Bug #81275 status page, contain bugus value in request duration sometimes
Submitted: 2021-07-19 18:23 UTC Modified: 2024-09-04 12:16 UTC
Votes:1
Avg. Score:3.0 ± 0.0
Reproduced:0 of 0 (0.0%)
From: tsmtgdi at gmail dot com Assigned: bukka (profile)
Status: Closed Package: FPM related
PHP Version: 8.1Git-2021-07-19 (Git) OS: Suse
Private report: No CVE-ID: None
View Developer Edit
Welcome! If you don't have a Git account, you can't do anything here.
If you reported this bug, you can edit this bug over here.
(description)
Block user comment
Status: Assign to:
Package:
Bug Type:
Summary:
From: tsmtgdi at gmail dot com
New email:
PHP Version: OS:

 

 [2021-07-19 18:23 UTC] 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();
        }
    }
}

Patches

Pull Requests

Pull requests:

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2021-07-19 18:24 UTC] 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 20:06 UTC] tsmtgdi at gmail dot com 
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.
 [2021-07-20 01:20 UTC] tsmtgdi at gmail dot com 
I tried doing

		int   scoreboard_size        = sizeof(struct fpm_scoreboard_s) + (scoreboard_p->nprocs) * sizeof(struct fpm_scoreboard_proc_s*);
		int   scoreboard_nprocs_size = sizeof(struct fpm_scoreboard_proc_s) * scoreboard_p->nprocs;
		scoreboardCopy                = (struct fpm_scoreboard_s*)emalloc(scoreboard_size + scoreboard_nprocs_size);
		
		memcpy(scoreboardCopy, scoreboard_p, scoreboard_size + scoreboard_nprocs_size);

To have a full copy, both of the fpm_scoreboard_s and the array of fpm_scoreboard_proc_s, but the problem is still present.
 [2021-08-03 13:05 UTC] ramsey@php.net
-Assigned To: +Assigned To: bukka
 [2021-08-03 13:05 UTC] ramsey@php.net 
bukka, can you take a look? nikic thinks there might already be a PR for this, but I can't find it.
 [2021-08-03 13:10 UTC] nikic@php.net 
This is the PR I had in mind: https://github.com/php/php-src/pull/3188
 [2021-09-05 19:23 UTC] bukka@php.net 
Ah so it's not maybe such a theoretical issue that I thought initially. That PR looks like a potential fix indeed. I will need to test it to confirm though. Will also think about creating some test for this (most likely the slow one if possible).
 [2022-02-08 22:42 UTC] bukka@php.net 
Thanks for the reproducing script which worked perfectly for me in this setup https://github.com/bukka/php-util/tree/7ac45d4e51465f60ad69589f9e06a8ef5b5cec16/tests/fpm/scoreboard-race . I was able to recreate the issue with PHP-8.0 and after applying https://github.com/php/php-src/pull/8049 , the issue is no longer present. I will merge it tomorrow.
 [2022-02-08 22:43 UTC] bukka@php.net 
The following pull request has been associated:

Patch Name: Fix #76109: Implement fpm_scoreboard_copy
On GitHub:  https://github.com/php/php-src/pull/8049
Patch:      https://github.com/php/php-src/pull/8049.patch
 [2022-02-10 22:37 UTC] bukka@php.net
-Status: Assigned +Status: Closed
 [2022-02-10 22:37 UTC] bukka@php.net 
The PR mentioned above has been merged and the fix should be released as part of PHP 8.0.17 and 8.1.4.
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved. 		Last updated: Sat Dec 21 13:01:31 2024 UTC