Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HTTP/2 transfer timeout causes all future transfers using the Curl_easy to time-out #3966

Closed
Josie-H opened this issue May 29, 2019 · 1 comment

Comments

@Josie-H
Copy link
Contributor

commented May 29, 2019

I did this

Our project uses libcurl (7.61.1, on Centos6, via the Rust crate) for (OpenSSL) HTTP/2 transfers, and we reuse the same Curl_easy session for multiple transfers. Importantly, we reuse the session even if a transfer fails.

At several customers, we started to see transfers repeatedly timing out on one Curl_easy session, and continuing to do this until we restarted the application. Strangely, logs proved that the transfer stalled at the point after they'd sent headers but before sending the body.

I expected the following

That we shouldn't generally timeout during a send, especially if we've already sent some headers!

I debugged the bug :-)

After many repros with a lot of extra logs added to the Curl code, I discovered that the transfers were failing because the Curl_easy's state.drain was permanently nonzero. (If this is set but there's nothing to drain, Curl just spins looking for something to drain until timeout.)

Many more temporary logs later, I discovered that the drain field can remain set on the Curl_easy when a transfer has failed, because the last time it's unset is at the beginning of Curl_http2_done(), but the nghttp2 functions called within that function can set it again.

I fixed the bug

Moving the call to drained_transfer() to a point later in Curl_http2_done() stopped our customers from getting into this permanent timeout state - further monitoring with another few logs confirmed that they were occasionally seeing regular timeouts such that the accused nghttp2 functions were indeed setting drain on after the last time it would previously have been switched off.

I'll attach a pull request of what I did in our codebase, but do feel free to point out edge-cases where this won't work for the wider Curl userbase!

@bagder bagder added the HTTP/2 label May 29, 2019
@bagder

This comment has been minimized.

Copy link
Member

commented May 29, 2019

Thanks! If you provide a pull-request I'll understand better exactly the change you propose and I can also test and check it out. Then I'll make sure to comment or merge it accordingly!

Josie-H added a commit to Josie-H/curl that referenced this issue May 29, 2019
Various functions called within Curl_http2_done() can have the
side-effect of setting the Easy connection into drain mode (by calling
drain_this()).  However, the last time we unset this for a transfer (by
calling drained_transfer()) is at the beginning of Curl_http2_done().
If the Curl_easy is reused for another transfer, it is then stuck in
drain mode permanently, which in practice makes it unable to write any
data in the new transfer.

This fix moves the last call to drained_transfer() to later in
Curl_http2_done(), after the functions that could potentially call for a
drain.

Fixes curl#3966
Reported-by: Josie-H
@bagder bagder closed this in 1c0e952 May 29, 2019
@lock lock bot locked as resolved and limited conversation to collaborators Aug 27, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
2 participants
You can’t perform that action at this time.