Friday, 29 March 2019

How to reliably reproduce curl issue 3602 (curl_multi sometimes timeout while testing public proxies)

About a month ago I opened issue 3602 for curl on GitHub, when I noticed that when I use curl_multi interface for testing public proxies, sometimes I get too many 28(timeout) errors while this never happens if I tested every proxy alone.

The problem is that this issue is unreliably reproducible, no one knows when exactly this happens! it could be a bug in curl or something else, which makes Daniel Stenberg closes the issue and says

Again, I can't rule out that there is a problem somewhere in curl. But without reliable, reproducible behavior I don't know how to determine when a timeout is "real" or not by debugging curl.

Do the TCP handshakes complete within the timeout period or not. Is it curl that doesn't notice the connection or is the connection not happening (fast enough). Those are the questions we want answered. That would probably require that you analyze the network traffic.

Continuing to post times or aggregated data won't help us to get those questions answered. They're just observations that might show a curl issue, but they might also just be problems elsewhere.

Unfortunately, I'm not such a deep networks debugger and I don't know how to debug this issue on a deeper level, however I wrote 2 C programs (one of them is originally written by Daniel Stenberg but I modified it a bit). These 2 C programs do test 407 public proxies

  1. with curl_multi interface (which has the problem)

  2. with curl on many threads, each curl operation on a thread. (which has no problem)

(Those are the 2 C programs(curl-multi and curl-threads) I wrote for testing I'm not a C developer so forgive anything wrong you notice in the 2 programs)

(And this is the tests results you can notice that the tests done with curl_multi make too many timeout, while the timeouts done my curl-threads are stable (about 50 out of 407 of the proxies are working). This is a sample from the tests results. Please note columns 4 and column 6 to see how the curl threads makes about ~170 time outs and ~45 successful connections and curl_multi makes 0 successful connections and about ~300 timeouts out of 407 proxies)

column(1) : #
column(2) : time(UTC)
column(3) : total execution time (seconds)
column(4) : no error 0 (how many requests result in no error CURLE_OK)
column(5) : error 7  (how many requests result in error 7 CURLE_COULDNT_CONNECT)
column(6) : error 28 (how many requests result in error 28 CURLE_OPERATION_TIMEDOUT)
column(7) : error 35 (how many requests result in error 35 CURLE_SSL_CONNECT_ERROR)
column(8) : error 56 (how many requests result in error 56 CURLE_RECV_ERROR)
column(9) : other errors (how many requests result in errors other than the above)
column(10) : program that used the curl
column(11) : cURL version

c(1)    c(2)           c(3)c(4)c(5)c(6)c(7)c(8)c(9) c(10)                  c(11)
267 2019-3-28 01:58:01  40  43  176 183 1   4   0   C (curl - threads) (Linux Fedora)   7.59.0
268 2019-3-28 01:59:01  30  0   286 110 1   10  0   C (curl-multi one thread) (Linux Fedora)    7.59.0
269 2019-3-28 02:00:01  30  46  169 181 1   8   2   C (curl - threads) (Linux Fedora)   7.59.0
270 2019-3-28 02:01:01  31  0   331 74  1   1   0   C (curl-multi one thread) (Linux Fedora)    7.59.0
271 2019-3-28 02:02:01  30  42  173 186 1   4   1   C (curl - threads) (Linux Fedora)   7.59.0
272 2019-3-28 02:03:01  30  0   277 116 1   13  0   C (curl-multi one thread) (Linux Fedora)    7.59.0

I hope this question gets more attention from programmers with more experience than me and more capabilities to dig deeper in this area.

What makes curl_multi sometimes timeouts most of the connections, while curl-threads never do this ?

Note: I can cheat and reproduce the problem by sleeping sleep(30) tell curl timeout, but offcourse this was not what made curl_multi timeouts.


ORIGINAL QUESTION

I'm working on a project that gathers and tests public/free proxies and I noticed sometimes at the later requests in the group a "Connection time-out" error message with a total_time very smaller than the CURLOPT_CONNECTTIMEOUT option while using cURL multi interface for making many requests at the same time which never happens if I made every request alone with cURL only without the multi interface.

Here is a class i made for testing this behavior, I couldn't include it here for post length limit, you can find it at https://github.com/accountantM/CurlMultiTimeoutBugTester

you can use it like

$curlTester = new CurlMultiTimeoutBugTester();
$report = $curlTester->test($url, 2, 1000);
echo $report;
exit;

Sometimes this error can be produced, while some other times it works fine for all requests with normal total_time that is the same as the CURLOPT_CONNECTTIMEOUT , here is a sample output report that shows the problem.

a normal timeout while the CURLOPT_CONNECTTIMEOUT is set to 2 seconds is like this

84.241.19.214:4145 err:"Connection timed out after 2005 milliseconds", total_time:2.364736

a normal connection refused is like this

83.219.1.80:56004 err:"Failed to connect to 83.219.1.80 port 56004: Connection refused", total_time:0.000107

But this is not normal

35.196.70.16:80 err:"Connection time-out", total_time:0.00033  <=================   BUG

If you are connecting to each proxy of them alone with CURLOPT_CONNECTTIMEOUT set to 2 seconds you will never get this error at the later requests, some of them works and some will take it's chance and try to connect for 2 seconds then fail, but this error "total_time very small than timeout" happens only with cURL multi interface.

Please help me I'm new to cURL and it's been 3 days trying to understand what is going on, I tried almost every option that could be related CURLOPT_DNS_USE_GLOBAL_CACHE,CURLOPT_DNS_CACHE_TIMEOUT, CURLOPT_NOSIGNAL, CURLOPT_CONNECTTIMEOUT_MS, CURLOPT_NOSIGNAL, CURLOPT_PIPEWAIT, CURLMOPT_PIPELINING, CURLOPT_TCP_FASTOPEN, CURLOPT_MAXCONNECTS, CURLMOPT_MAXCONNECTS, CURLMOPT_MAX_HOST_CONNECTIONS I also tried to remove the call curl_multi_select($mh) and looping with curl_multi_exec($mh, $active) only, but the same problem shows sometimes :( .

Unfortunately, check this question and it's answers and you will realize that making asynchronous http requests is still a BIG challenge in PHP :(


UPDATE (2019-02-28)

the small TOTAL_TIME problem has been fixed



from How to reliably reproduce curl issue 3602 (curl_multi sometimes timeout while testing public proxies)

No comments:

Post a Comment