`ext\curl\tests\bug45161.phpt` test is absurdly slow on Windows #10753

mvorisek · 2023-03-02T21:30:28Z

Description

I report this as a performance bug.

(209.652 s) Bug #45161 (Reusing a curl handle leaks memory) [D:\a\php-src\php-src\ext\curl\tests\bug45161.phpt]

CI: https://github.com/php/php-src/actions/runs/4308375002/jobs/7514584871#step:8:113

on Windows 1024 iterations - https://github.com/php/php-src/blob/master/ext/curl/tests/bug45161.phpt - takes > 200 seconds, on linux/MacOS it takes <1 second

there is probably something wrong with Windows code

maybe related with #10119

PHP Version

8.2 and master, x86 and x64

Operating System

Windows

The text was updated successfully, but these errors were encountered:

Jan-E · 2023-03-04T02:05:51Z

PHP Version
8.2 and master, x86 and x64

The same happens on PHP 8.0.28 NTS x64

mvorisek · 2023-04-03T22:26:38Z

Can someone please look into this issue?

iluuu1994 · 2023-04-04T11:11:51Z

I don't have a Windows machine to test this. Is running it locally equally slow?

Jan-E · 2023-04-04T11:31:55Z

Yes. Running the tests for curl takes on my machine 250 seconds, almost entirely due to this single test.

iluuu1994 · 2023-04-04T11:33:32Z

@Jan-E Are the requests that slow? Can you debug the script to check which part causes it?

Jan-E · 2023-04-05T11:28:02Z

I debugged the script by adding milliseconds to the output. All tests were done with Curl 8.0.1.

$start = memory_get_usage() + 1024;
for($i = 0; $i < 1024; $i++) {                                                                                             
    curl_setopt($ch, CURLOPT_URL, "{$host}/get.inc");
    curl_setopt($ch, CURLOPT_FILE, $fp);
    $stime = date_create()->format('Uv');
    echo $stime."\n";
    curl_exec($ch);
    $stime = date_create()->format('Uv');
    echo $stime."\n";
}

Of course the test failed with the extra output, but it told me that on my machine every curl_exec($ch) took about 210 milliseconds. Multiply this by 1024 and you end up with a test duration of 215 seconds.

Which raises the question: is the curl request slow or the server that the test script launches? The server listens on localhost on a random port, but as long as the script was running I could detect on which port and launch the same request from a DOS-prompt. Detecting the port:

$ netstat -anb | grep TIME_WAIT
....
  TCP    [::1]:60323            [::1]:60543            TIME_WAIT
  TCP    [::1]:60323            [::1]:60545            TIME_WAIT
  TCP    [::1]:60323            [::1]:60548            TIME_WAIT
  TCP    [::1]:60323            [::1]:60550            TIME_WAIT
  TCP    [::1]:60323            [::1]:60552            TIME_WAIT
  TCP    [::1]:60323            [::1]:60554            TIME_WAIT
  TCP    [::1]:60324            [::1]:60323            TIME_WAIT

Doing the same request with curl.exe:

$ ptime curl -o nul http://localhost:60323/get.inc

ptime 1.0 for Win32, Freeware - http://www.pc-tools.net/
Copyright(C) 2002, Jem Berkes <[email protected]>

===  curl -o nul http://localhost:60323/get.inc ===
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100    25    0    25    0     0    113      0 --:--:-- --:--:-- --:--:--   113

Execution time: 0.281 s. A bit longer than the same request from within PHP.
wget.exe was quicker:

$ ptime wget http://localhost:60323/get.inc

ptime 1.0 for Win32, Freeware - http://www.pc-tools.net/
Copyright(C) 2002, Jem Berkes <[email protected]>

===  wget http://localhost:60323/get.inc ===
--2023-04-04 18:37:30--  http://localhost:60323/get.inc
Resolving localhost (localhost)... ::1, 127.0.0.1
Connecting to localhost (localhost)|::1|:60323... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/html]
Saving to: 'get.inc'

get.inc                    [ <=>                        ]      25  --.-KB/s    in 0s

2023-04-04 18:37:30 (394 KB/s) - 'get.inc' saved [25]

Execution time: 0.076 s, which amounts to about 27% of the time curl.exe took for it.

Conclusions: the test server on Windows is slow. but it seems that requesting http://localhost:60323/get.inc by means of Curl is causing a greater delay.

As a BTW: I am getting the same results for this test from PHP 7.3 onwards. The test in PHP 7.2 was skipped as 'Not for Windows'.

iluuu1994 · 2023-04-05T12:26:07Z

@Jan-E Thank you for your fantastic analysis! I'll compare the results to Linux. @adoy I reckon you don't have an explanation on why Curl on Windows is so slow?

iluuu1994 · 2023-04-05T14:56:39Z

On Linux the entire test with all 1024 iterations finishes in 0.15 seconds. I'm not sure what's going on here on Windows. This could also be an issue with cli-server itself on Windows.

adoy · 2023-04-06T17:01:18Z

@Jan-E Thank you for your fantastic analysis! I'll compare the results to Linux. @adoy I reckon you don't have an explanation on why Curl on Windows is so slow?

@iluuu1994 No. And I don't have a windows machine do test it. It looks like it's really a curl issue, we should probably report this upstream.

See GH-10753 The test is insanely slow on Windows and it's unclear why. It might be a curl issue.

M1ke · 2023-12-12T16:03:39Z

I can confirm this issue happens on Linux too; we built a PHP8.1 server on the latest build of Ubuntu 22.04 LTS which has openssl 3; web response times were 25-50% slower across thousands of endpoints (most of which are database-backed so we generally assume any slowness comes from the database). Tracked it down to our use of AWS DDB for session storage, and within that the curl prerequest time was double or triple the length of time on the same server with Ubuntu 20.04 LTS (using openssl 1.1)

dark blue - server running 22.04, php8.1, openssl 3
other lines - 20.04, php7.4, openssl 1.1

light blue - server running 20.04, php8.1, openssl 1.1
other lines - 20.04, php7.4, openssl 1.1

So we can see here that the same build, code running php8.1 looked bad compared to 7.4, until we downgraded openssl where we see performance of 8.1 on the lower end of the average 7.4 performance, and definitely no distinct increase. Openssl 3 definitely causing these issues (I imagine other people may report curl issues as they migrate php versions and in the process accidentally bump their openssl version)

GrahamCampbell · 2023-12-12T16:54:56Z

OpenSSL 3.2 has some changes which may improve things. Is anyone able to compare 3.0 vs 3.2?

cmb69 · 2024-07-17T18:47:25Z

I faintly remember a super slow test on Windows after some cURL update; I don't remember exactly which test it has been, but the issue might have been related to curl/curl#9296 (so that would have been cURL 7.85.0).

Anyhow, bug45161.phpt (without that SKIPIF section) runs pretty fast for me (PHP-8.2, cURL 8.7.1), but is somewhat slower (~7s) on PHP-8.1, cURL 7.77.0. When I replace the $host assignment line at the top of the --FILE-- section with
$host = str_replace('localhost', curl_cli_server_start(), '127.0.0.1');, the test is as fast as on PHP-8.2 (~2s).

mvorisek · 2024-07-17T18:57:02Z

This issue is easily verifyable using linux/Windows Github Actions CI based on the description:

on Windows 1024 iterations - https://github.com/php/php-src/blob/master/ext/curl/tests/bug45161.phpt - takes > 200 seconds, on linux/MacOS it takes <1 second

of course, with 4b22c3e reverted

cmb69 · 2024-07-17T20:44:15Z

@mvorisek, it is not listed in the slow tests section for a recent test build. Either the test has not been executed, or it isn't that slow anymore.

mvorisek · 2024-07-17T22:50:22Z

So let's land cmb69@1bd111e and close this issue.

cmb69 · 2024-07-17T23:20:53Z

Let's wait a bit, please. I want to see how long the test took.

Jan-E · 2024-07-18T09:44:11Z

On my system with PHP 8.4.0 Alpha 2 NTS x64:

=====================================================================
PHP         : N:\php-sdk\php84dev\x64\Release\php-8.4.0alpha2\php.exe
PHP_SAPI    : cli
PHP_VERSION : 8.4.0alpha2
ZEND_VERSION: 4.4.0-dev
PHP_OS      : WINNT - Windows NT X220I7 10.0 build 19045 (Windows 10) AMD64
INI actual  : N:\php-sdk\php84dev\x64\Release\php-8.4.0alpha2\php.ini
More .INIs  :
---------------------------------------------------------------------
PHP         : N:\php-sdk\php84dev\x64\Release\php-8.4.0alpha2\php-cgi.exe
PHP_SAPI    : cgi-fcgi
PHP_VERSION : 8.4.0alpha2
ZEND_VERSION: 4.4.0-dev
PHP_OS      : WINNT - Windows NT X220I7 10.0 build 19045 (Windows 10) AMD64
INI actual  : N:\php-sdk\php84dev\x64\Release\php-8.4.0alpha2\php.ini
More .INIs  :
---------------------------------------------------------------------
---------------------------------------------------------------------
PHP         : N:\php-sdk\php84dev\x64\Release\php-8.4.0alpha2\phpdbg.exe
PHP_SAPI    : phpdbg
PHP_VERSION : 8.4.0alpha2
ZEND_VERSION: 4.4.0-dev
PHP_OS      : WINNT - Windows NT X220I7 10.0 build 19045 (Windows 10) AMD64
INI actual  : N:\php-sdk\php84dev\x64\Release\php-8.4.0alpha2\php.ini
More .INIs  :
---------------------------------------------------------------------
CWD         : N:\php-sdk\php84dev\x64\Release\php-8.4.0alpha2
Extra dirs  :
VALGRIND    : Not used
=====================================================================
Running selected tests.
PASS Bug #45161 (Reusing a curl handle leaks memory) [N:\php-sdk\php84dev\ext\curl\tests\bug45161.phpt]
=====================================================================
Number of tests :     1                 1
Tests skipped   :     0 (  0.0%) --------
Tests warned    :     0 (  0.0%) (  0.0%)
Tests failed    :     0 (  0.0%) (  0.0%)
Tests passed    :     1 (100.0%) (100.0%)
---------------------------------------------------------------------
Time taken      : 1.486 seconds
=====================================================================

1.5 seconds is not insanely long, given that all curl tests take 29 seconds on the same system.

Jan-E · 2024-07-18T09:48:01Z

That is with this build:
https://phpdev.toolsforresearch.com/php-8.4.0alpha2-nts-Win32-vs17-x64.htm
https://phpdev.toolsforresearch.com/php-8.4.0alpha2-nts-Win32-vs17-x64.zip

Curl 8.8.0, OpenSSL 3.0.14

cmb69 · 2024-07-18T09:59:42Z

So we might assume that this has been "fixed in third party library" (unless someone is willing to verify this exactly).

Jan-E · 2024-07-18T10:13:06Z

I am not going to do the analysis in #10753 (comment) once again, so I guess that would be right. Building PHP 8.2.22RC1 TS x64 right now to verify that the test takes about 1 second on my system as well. I will edit the test time into this comment once it has been done.

Edit No fractions of seconds when running the 8.2 tests. 1 or 2 seconds for bug45161 out of a total of 34/35 for all curl tests.

mvorisek added Bug Status: Needs Triage labels Mar 2, 2023

iluuu1994 added a commit that referenced this issue Apr 13, 2023

[skip ci] Skip bug45161.phpt on Windows

4b22c3e

See GH-10753 The test is insanely slow on Windows and it's unclear why. It might be a curl issue.

mvorisek mentioned this issue Sep 24, 2023

Massive performance degradation in OpenSsl 3.0 if used in a heavy multi threaded server application openssl/openssl#17064

Open

Girgias added the Extension: curl label Dec 5, 2023

This was referenced Dec 12, 2023

CURL - massive Performance issue #10119

Closed

Performance issues on Bref PHP 8.1 and Later brefphp/bref#1528

Open

cmb69 mentioned this issue Jul 18, 2024

Revert "[skip ci] Skip bug45161.phpt on Windows" #14998

Closed

cmb69 closed this as completed in 355baf9 Jul 18, 2024

cmb69 added Status: Fixed in Third Party Library and removed Status: Needs Triage labels Jul 18, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`ext\curl\tests\bug45161.phpt` test is absurdly slow on Windows #10753

`ext\curl\tests\bug45161.phpt` test is absurdly slow on Windows #10753

mvorisek commented Mar 2, 2023 •

edited

Loading

Jan-E commented Mar 4, 2023

mvorisek commented Apr 3, 2023

iluuu1994 commented Apr 4, 2023

Jan-E commented Apr 4, 2023 •

edited

Loading

iluuu1994 commented Apr 4, 2023

Jan-E commented Apr 5, 2023 •

edited

Loading

iluuu1994 commented Apr 5, 2023

iluuu1994 commented Apr 5, 2023

adoy commented Apr 6, 2023

M1ke commented Dec 12, 2023 •

edited

Loading

GrahamCampbell commented Dec 12, 2023

cmb69 commented Jul 17, 2024

mvorisek commented Jul 17, 2024

cmb69 commented Jul 17, 2024

mvorisek commented Jul 17, 2024

cmb69 commented Jul 17, 2024

Jan-E commented Jul 18, 2024

Jan-E commented Jul 18, 2024

cmb69 commented Jul 18, 2024

Jan-E commented Jul 18, 2024 •

edited

Loading

ext\curl\tests\bug45161.phpt test is absurdly slow on Windows #10753

ext\curl\tests\bug45161.phpt test is absurdly slow on Windows #10753

Comments

mvorisek commented Mar 2, 2023 • edited Loading

Description

PHP Version

Operating System

Jan-E commented Mar 4, 2023

mvorisek commented Apr 3, 2023

iluuu1994 commented Apr 4, 2023

Jan-E commented Apr 4, 2023 • edited Loading

iluuu1994 commented Apr 4, 2023

Jan-E commented Apr 5, 2023 • edited Loading

iluuu1994 commented Apr 5, 2023

iluuu1994 commented Apr 5, 2023

adoy commented Apr 6, 2023

M1ke commented Dec 12, 2023 • edited Loading

GrahamCampbell commented Dec 12, 2023

cmb69 commented Jul 17, 2024

mvorisek commented Jul 17, 2024

cmb69 commented Jul 17, 2024

mvorisek commented Jul 17, 2024

cmb69 commented Jul 17, 2024

Jan-E commented Jul 18, 2024

Jan-E commented Jul 18, 2024

cmb69 commented Jul 18, 2024

Jan-E commented Jul 18, 2024 • edited Loading

`ext\curl\tests\bug45161.phpt` test is absurdly slow on Windows #10753

`ext\curl\tests\bug45161.phpt` test is absurdly slow on Windows #10753

mvorisek commented Mar 2, 2023 •

edited

Loading

Jan-E commented Apr 4, 2023 •

edited

Loading

Jan-E commented Apr 5, 2023 •

edited

Loading

M1ke commented Dec 12, 2023 •

edited

Loading

Jan-E commented Jul 18, 2024 •

edited

Loading