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

[mvorisek]

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

[Jan-E]

PHP Version
8.2 and master, x86 and x64

The same happens on PHP 8.0.28 NTS x64

[mvorisek]

Can someone please look into this issue?

[iluuu1994]

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

[Jan-E]

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

[iluuu1994]

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

[Jan-E]

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 <jberkes@pc-tools.net>

===  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 <jberkes@pc-tools.net>

===  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]

@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]

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]

@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.

[M1ke]

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)