Curl not timing out properly

Question

I have CURLOPT_CONNECTTIMEOUT_MS = 200 and CURLOPT_TIMEOUT_MS = 70 ms set. But my I am seeing CURLINFO_TOTAL_TIME to be around 220 ms.

As per the libcurl doc, CURLOPT_TIMEOUT_MS includes connect timeout also. So basically my curl call total time should not take more than 70 ms. But why is it taking more return back the control?

Can someone please explain this behavior.

I am using curl 7.19_02 C++ library.

Here is my code

CURL * curl;
curl = curl_easy_init();
curl_easy_setopt(curl, CURLOPT_URL, url);
curl_easy_setopt(curl,CURLOPT_CONNECTTIMEOUT_MS,200);
curl_easy_setopt(curl,CURLOPT_TIMEOUT_MS,70);
curl_easy_setopt(curl, CURLOPT_HEADER, 0);
curl_easy_setopt(curl, CURLOPT_WRITEFUNCTION, writer);
curl_easy_setopt(curl, CURLOPT_WRITEDATA, &response);
curl_easy_setopt(curl, CURLOPT_VERBOSE, 1L); 

double tt = 0.0;
double ns = 0.0;
double ct = 0.0;
double pt = 0.0;
double st = 0.0;

curl_easy_perform(curl);

int curlRC = curl_easy_getinfo(curl, CURLINFO_TOTAL_TIME, &tt);
curlRC = curl_easy_getinfo(curl, CURLINFO_NAMELOOKUP_TIME, &ns);
curlRC = curl_easy_getinfo(curl, CURLINFO_CONNECT_TIME, &ct);
curlRC = curl_easy_getinfo(curl, CURLINFO_PRETRANSFER_TIME, &pt);
curlRC = curl_easy_getinfo(curl, CURLINFO_STARTTRANSFER_TIME, &st);

cout << "Curl timing info: Total: " << tt << endl << " Lookup: "<< ns << endl << "    Connect: " << ct << "\n" << "pre transfer: " << pt << endl << "start transfer: " << st <<endl;

The timing info I got is as below. Please check this out

Curl timing info: Total: 0.216793

Lookup: 0.000999

Connect: 0.023199

pre transfer: 0.023213

start transfer: 0.216667

So the point is, what is happening between pre transfer and start transfer?

Answer 1

It's a bug in libcurl up to version 7.20.0. With 7.20.1 the output is like expected:

Curl timing info: Total: 0.071098
Lookup: 0.000116
Connect: 0.000303
pre transfer: 0.000327
start transfer: 0

I couldn't find the changeset fixing the bug. But could be in "sub-second timeouts improvements" in cURL Changes