Immediate timeout on reused curl handle with low speed limit set

[Coderlane]

I did this

I have a curl easy handle that is used with curl_easy_perform to periodically POST data. The easy handle is reused between requests to take advantage of the cached connection. Data is attached to the upload via CURLOPT_READFUNCTION. However, a CURLOPT_SEEKFUNCTION is not configured.

To avoid stalled connections, CURLOPT_LOW_SPEED_LIMIT is set:

curl_easy_setopt(easy, CURLOPT_LOW_SPEED_LIMIT, 1L);
curl_easy_setopt(easy, CURLOPT_LOW_SPEED_TIME, 60L);

Occasionally, I'll see the following behavior:

1. (OK) A request succeeds and the connection is cached
2. (OK) A request fails, as the cached connection is actually closed and the request can't be rewound
3. (NOT OK) All subsequent requests successfully upload all data, but hit CURLOPT_LOW_SPEED_LIMIT before receiving the response

See annotated_log.txt for annotated logs from CURLOPT_DEBUGFUNCTION.

Suspicion:

I think the behavior in part 3 above occurs because the rewind bit is still set on the request from the previous (failed) request. When Curl_init_do is called at the start of the request in part 3, it calls Curl_req_start -> Curl_req_soft_reset -> Curl_client_start which will attempt to perform a rewind. This rewind is guaranteed to fail, because I'm using a read function and don't have a seek function.

Popping back to Curl_init_do, if Curl_req_start fails Curl_speedinit will not be called:

curl/lib/url.c

Lines 3853 to 3858 in 657aae7

	result = Curl_req_start(&data->req, data);
	if(!result) {
	Curl_speedinit(data);
	Curl_pgrsSetUploadCounter(data, 0);
	Curl_pgrsSetDownloadCounter(data, 0);
	}

None of the call sites of Curl_init_do check the result of the function:

curl/lib/url.c

Lines 3555 to 3558 in 657aae7

	/* since we skip do_init() */
	Curl_init_do(data, conn);
	goto out;

curl/lib/url.c

Lines 3706 to 3714 in 657aae7

	/* Setup and init stuff before DO starts, in preparing for the transfer. */
	Curl_init_do(data, conn);
	/*
	* Setup whatever necessary for a resumed transfer
	*/
	result = setup_range(data);
	if(result)
	goto out;

This is ultimately what triggers the CURLOPT_LOW_SPEED_LIMIT failure on an otherwise successful request. The speed data on request 3 is still the speed data from request 2. Thus, it looks like request 3 has stalled.

I expected the following

I'd expect curl_easy_perform to fail if a required seek fails. IE: The result of Curl_init_do should be checked.

I'd expect the rewind bit to be reset after the request, but I'm not sure this is a reasonable expectation. For my use, each call to curl_easy_perform is a request and rewinding before sending any data has no meaning. I'm not sure if this holds for all use cases.

curl/libcurl version

libcurl 8.12.1 w/ boringssl

operating system

macOS 15.4.1 (24E263)

Darwin <REDACTED> 24.4.0 Darwin Kernel Version 24.4.0: Fri Apr 11 18:33:47 PDT 2025; root:xnu-11417.101.15~117/RELEASE_ARM64_T6000 arm64

[icing]

@Coderlane thanks for your detailed report. I believe your analysis is correct and the failed rewind should lead to an early error, not a transfer failed unreliably later. Will work on a fix...

[icing]

I made the fix in #17150 (and found a bug in a test case that way). Could you test that in your setup? Thanks!

[Coderlane]

Thank you! I'll give it a try and get back to you.

[Coderlane]

177f7b3 seems correct to me. The request now fails with CURLE_SEND_FAIL_REWIND when I don't have a CURLOPT_SEEKFUNCTION registered. Thank you!

Here are the logs:

2025-04-23T19:25:14.470ZI LogCurlInfo == Info: upload completely sent off: 39 bytes
2025-04-23T19:25:18.167ZI LogCurlInfo == Info: Recv failure: No route to host
2025-04-23T19:25:18.167ZI LogCurlInfo == Info: BoringSSL SSL_read: No route to host, errno 65
2025-04-23T19:25:18.167ZI LogCurlInfo == Info: Connection died, retrying a fresh connect (retry count: 1)
2025-04-23T19:25:18.168ZI LogCurlInfo == Info: shutting down connection 0
2025-04-23T19:25:18.168ZI LogCurlInfo == Info: Send failure: Broken pipe
2025-04-23T19:25:18.169ZI LogCurlInfo == Info: seek callback returned error 2
2025-04-23T19:25:18.169ZI LogCurlInfo == Info: rewind of client reader 'cr-in' failed: 65
2025-04-23T19:25:18.169ZI LogCurlInfo == Info: Issue another request to this URL: '<REDACTED>'
2025-04-23T19:25:18.169ZI LogCurlInfo == Info: seek callback returned error 2
2025-04-23T19:25:18.169ZI LogCurlInfo == Info: rewind of client reader 'cr-in' failed: 65
2025-04-23T19:25:18.169ZI LogCurlInfo == Info: closing connection 3