[php-src] Issue #10031: [Stream] STREAM_NOTIFY_PROGRESS over HTTP emitted irregularly for last chunk of data

Issue: https://github.com/php/php-src/issues/10031 Author: aetonsi ### Description ### Problem #### Files ##### file echo.php ```php <?php $fsize = 1000; $chunksize = 99; $chunks = floor($fsize / $chunksize); // 10 chunks * 99 bytes $lastchunksize = $fsize - $chunksize * $chunks; // 1 chunk * 10 bytes header("Content-length: " . $fsize); flush(); for ($chunk = 1; $chunk <= $chunks; $chunk++) { echo str_repeat('x', $chunksize); @ob_flush(); usleep(50 * 1000); } echo str_repeat('x', $lastchunksize); ``` ##### file test.php ```php <?php $context = stream_context_create(['http' => ['ignore_errors' => true,]]); $lastBytesTransferred = 0; stream_context_set_params($context, ['notification' => function ($code, $s, $m, $mc, $bytes_transferred, $bytes_max) use (&$lastBytesTransferred) { $progress = $bytes_max ? $bytes_transferred / $bytes_max * 100 : 0; $chunksize = $bytes_transferred - $lastBytesTransferred; if ($code === STREAM_NOTIFY_PROGRESS) echo "\nprogress: $progress% ($bytes_transferred/$bytes_max b) (chunksize=$chunksize)"; if ($code === STREAM_NOTIFY_FILE_SIZE_IS) echo "\nexpected filesize= $bytes_max"; if ($code === STREAM_NOTIFY_COMPLETED) echo "\nSTREAM_NOTIFY_COMPLETED"; $lastBytesTransferred = $bytes_transferred; @ob_flush(); }]); $get = file_get_contents('http://localhost:8000/echo.php', false, $context); if (!$get) die("\nERROR during file_get_contents. is the local server running? ( php -\"dxdebug.mode\"=off -S localhost:8000 )\n"); echo "\ngot filesize=" . strlen($get) . PHP_EOL; ``` #### CLI commands: ```bash # to start local server php -S localhost:8000 # to run the test php test.php ``` #### Wrong output (happens irregularly): ``` > php .\src\test.php expected filesize= 1000 progress: 0% (0/1000 b) (chunksize=0) progress: 9.9% (99/1000 b) (chunksize=99) progress: 19.8% (198/1000 b) (chunksize=99) progress: 29.7% (297/1000 b) (chunksize=99) progress: 39.6% (396/1000 b) (chunksize=99) progress: 49.5% (495/1000 b) (chunksize=99) progress: 59.4% (594/1000 b) (chunksize=99) progress: 69.3% (693/1000 b) (chunksize=99) progress: 79.2% (792/1000 b) (chunksize=99) progress: 89.1% (891/1000 b) (chunksize=99) progress: 90.1% (901/1000 b) (chunksize=10) got filesize=1000 ``` #### Correct output: ``` > php .\src\test.php expected filesize= 1000 progress: 0% (0/1000 b) (chunksize=0) progress: 9.9% (99/1000 b) (chunksize=99) progress: 19.8% (198/1000 b) (chunksize=99) progress: 29.7% (297/1000 b) (chunksize=99) progress: 39.6% (396/1000 b) (chunksize=99) progress: 49.5% (495/1000 b) (chunksize=99) progress: 59.4% (594/1000 b) (chunksize=99) progress: 69.3% (693/1000 b) (chunksize=99) progress: 79.2% (792/1000 b) (chunksize=99) progress: 89.1% (891/1000 b) (chunksize=99) progress: 99% (990/1000 b) (chunksize=99) progress: 100% (1000/1000 b) (chunksize=10) got filesize=1000 ``` ### Description The file echo.php generates a series of 1000 consecutive "x"s. The data is emitted with intervals of 50ms (usleep(50 * 1000)), in 10 chunks sized 99bytes, plus one final chunk of 10bytes (99*10 + 10 = 1000). The script test.php fetches the data from the url /echo.php of the local web server. file_get_contents is passed a context with a notification callback. This callback prints the download progress: percentage, bytes transferred, total bytes, current chunk size. The chunk size is calculated by subtracting the **previous** $bytes_transferred from the current $bytes_transferred. If you run php test.php multiple times, you will see that **sometimes** the event last 1/2 STREAM_NOTIFY_PROGRESS events are not emitted correctly. The last events should **always** be: - progress: 89.1% (891/1000 b) (chunksize=99) = chunk 9 - progress: 99% (**990**/1000 b) (chunksize=**99**) = chunk 10 - progress: 100% (**1000**/1000 b) (chunksize=**10**) = chunk 11 Instead, sometimes the last chunks are messed up: - progress: 89.1% (891/1000 b) (chunksize=99) = chunk 9 - progress: 90.1% (**901**/1000 b) (chunksize=**10**) = chunk 10. This line here is the culprit. This chunk has the correct size of the last chunk (10 bytes), but it's reported as being the 10th! In reality, the 10th chunk is still 99bytes large, and the 11th is the 10bytes one. When this problem occurs, 100% progress is never emitted (as the 10th chunk is mistaken for the 11th). --- I don't think this is a problem in the communication between php and the web server. Any possible delay in the communication shouldn't interfere with how the chunks are passed to the notification callback. I tried running curl -#O multiple times to see how curl receives the data. This is the command line i used (powershell): `1..10 | % { curl -#LO http://localhost:8000/echo.php *>&1 | php -r "preg_match_all('/[0-9\.]+/m', stream_get_contents(STDIN), $m);echo implode(', ', $m[0]).PHP_EOL;" ;}. For each iteration (1..10), this prints every progress percentage reported by curl`. It prints something like this: ```log 19.8, 39.6, 49.5, 59.4, 69.3, 79.2, 99.0, 100.0 19.8, 29.7, 39.6, 49.5, 59.4, 69.3, 79.2, 89.1, 99.0, 100.0 19.8, 29.7, 39.6, 49.5, 59.4, 69.3, 89.1, 99.0, 100.0 19.8, 39.6, 49.5, 59.4, 69.3, 79.2, 89.1, 99.0, 100.0 19.8, 29.7, 39.6, 49.5, 59.4, 69.3, 79.2, 99.0, 100.0 19.8, 29.7, 39.6, 59.4, 69.3, 79.2, 89.1, 99.0, 100.0 19.8, 29.7, 39.6, 49.5, 59.4, 79.2, 89.1, 99.0, 100.0 19.8, 29.7, 39.6, 49.5, 59.4, 69.3, 79.2, 89.1, 99.0, 100.0 19.8, 39.6, 49.5, 59.4, 69.3, 79.2, 89.1, 99.0, 100.0 19.8, 29.7, 39.6, 49.5, 59.4, 69.3, 79.2, 89.1, 99.0, 100.0 ``` As you can see, curl doesn't always report its progress, but even though it skips some reporting, it always has the correct progress percentages. It always ends with 89.1, 99.0, 100.0, which is the correct sequence. php on the other hand sometimes ends with 89.1, 90.1. --- In conclusion, at the moment the STREAM_NOTIFY_PROGRESS event is not reliable. I cannot determine **why** this problem occures only sometimes. I really can't. This appears **extremely** frequently when the chunks are transferred with varying sizes (eg if the php script on the server calls readfile(), and/or if the connection to the server is not stable). ### PHP Version PHP 8.1.12 ### Operating System Windows 11 (10.0.22621.819)