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

Alter timeout ordering with connections #7178

Closed
Closed
Show file tree
Hide file tree
Changes from 3 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
32 changes: 20 additions & 12 deletions lib/connect.c
Expand Up @@ -872,15 +872,6 @@ CURLcode Curl_is_connected(struct Curl_easy *data,

now = Curl_now();

/* figure out how long time we have left to connect */
allow = Curl_timeleft(data, &now, TRUE);

if(allow < 0) {
/* time-out, bail out, go home */
failf(data, "Connection time-out");
return CURLE_OPERATION_TIMEDOUT;
}

if(SOCKS_STATE(conn->cnnct.state)) {
/* still doing SOCKS */
result = connect_SOCKS(data, sockindex, connected);
Expand Down Expand Up @@ -994,6 +985,7 @@ CURLcode Curl_is_connected(struct Curl_easy *data,
Curl_strerror(error, buffer, sizeof(buffer)));
#endif

allow = Curl_timeleft(data, &now, TRUE);
conn->timeoutms_per_addr[i] = conn->tempaddr[i]->ai_next == NULL ?
allow : allow / 2;
ainext(conn, i, TRUE);
Expand All @@ -1006,6 +998,21 @@ CURLcode Curl_is_connected(struct Curl_easy *data,
}
}

/*
* Now that we've checked whether we are connected, check whether we've
* already timed out.
*
* First figure out how long time we have left to connect */

allow = Curl_timeleft(data, &now, TRUE);

if(allow < 0) {
/* time-out, bail out, go home */
failf(data, "Connection timeout after %ld ms",
Curl_timediff(now, data->progress.t_startsingle));
return CURLE_OPERATION_TIMEDOUT;
}

if(result &&
(conn->tempsock[0] == CURL_SOCKET_BAD) &&
(conn->tempsock[1] == CURL_SOCKET_BAD)) {
Expand All @@ -1031,9 +1038,10 @@ CURLcode Curl_is_connected(struct Curl_easy *data,
else
hostname = conn->host.name;

failf(data, "Failed to connect to %s port %ld: %s",
hostname, conn->port,
Curl_strerror(error, buffer, sizeof(buffer)));
failf(data, "Failed to connect to %s port %ld after %ld ms: %s",
hostname, conn->port,
Curl_timediff(now, data->progress.t_startsingle),
Curl_strerror(error, buffer, sizeof(buffer)));

Curl_quic_disconnect(data, conn, 0);
Curl_quic_disconnect(data, conn, 1);
Expand Down
115 changes: 75 additions & 40 deletions lib/multi.c
Expand Up @@ -1539,6 +1539,58 @@ static CURLcode multi_do_more(struct Curl_easy *data, int *complete)
return result;
}

/*
* Check whether a timeout occurred, and handle it if it did
*/
static bool multi_handle_timeout(struct Curl_easy *data,
struct curltime *now,
bool *stream_error,
CURLcode *result,
bool connect_timeout)
{
timediff_t timeout_ms;
timeout_ms = Curl_timeleft(data, now, connect_timeout);

if(timeout_ms < 0) {
/* Handle timed out */
if(data->mstate == MSTATE_RESOLVING)
failf(data, "Resolving timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds",
Curl_timediff(*now, data->progress.t_startsingle));
else if(data->mstate == MSTATE_CONNECTING)
failf(data, "Connection timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds",
Curl_timediff(*now, data->progress.t_startsingle));
else {
struct SingleRequest *k = &data->req;
if(k->size != -1) {
failf(data, "Operation timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds with %" CURL_FORMAT_CURL_OFF_T " out of %"
CURL_FORMAT_CURL_OFF_T " bytes received",
Curl_timediff(*now, data->progress.t_startsingle),
k->bytecount, k->size);
}
else {
failf(data, "Operation timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds with %" CURL_FORMAT_CURL_OFF_T
" bytes received",
Curl_timediff(*now, data->progress.t_startsingle),
k->bytecount);
}
}

/* Force connection closed if the connection has indeed been used */
if(data->mstate > MSTATE_DO) {
streamclose(data->conn, "Disconnected with pending data");
*stream_error = TRUE;
}
*result = CURLE_OPERATION_TIMEDOUT;
(void)multi_done(data, *result, TRUE);
}

return (timeout_ms < 0);
}

/*
* We are doing protocol-specific connecting and this is being called over and
* over from the multi interface until the connection phase is done on
Expand Down Expand Up @@ -1670,7 +1722,6 @@ static CURLMcode multi_runsingle(struct Curl_multi *multi,
bool done = FALSE;
CURLMcode rc;
CURLcode result = CURLE_OK;
timediff_t timeout_ms;
timediff_t recv_timeout_ms;
timediff_t send_timeout_ms;
int control;
Expand Down Expand Up @@ -1700,47 +1751,16 @@ static CURLMcode multi_runsingle(struct Curl_multi *multi,
if(data->conn &&
(data->mstate >= MSTATE_CONNECT) &&
(data->mstate < MSTATE_COMPLETED)) {
/* Check for overall operation timeout here but defer handling the
* connection timeout to later, to allow for a connection to be set up
* in the window since we last checked timeout. This prevents us
* tearing down a completed connection in the case where we were slow
* to check the timeout (e.g. process descheduled during this loop).
* We set connect_timeout=FALSE to do this.*/

/* we need to wait for the connect state as only then is the start time
stored, but we must not check already completed handles */
timeout_ms = Curl_timeleft(data, nowp,
(data->mstate <= MSTATE_DO)?
TRUE:FALSE);

if(timeout_ms < 0) {
/* Handle timed out */
if(data->mstate == MSTATE_RESOLVING)
failf(data, "Resolving timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds",
Curl_timediff(*nowp, data->progress.t_startsingle));
else if(data->mstate == MSTATE_CONNECTING)
failf(data, "Connection timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds",
Curl_timediff(*nowp, data->progress.t_startsingle));
else {
struct SingleRequest *k = &data->req;
if(k->size != -1) {
failf(data, "Operation timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds with %" CURL_FORMAT_CURL_OFF_T " out of %"
CURL_FORMAT_CURL_OFF_T " bytes received",
Curl_timediff(*nowp, data->progress.t_startsingle),
k->bytecount, k->size);
}
else {
failf(data, "Operation timed out after %" CURL_FORMAT_TIMEDIFF_T
" milliseconds with %" CURL_FORMAT_CURL_OFF_T
" bytes received",
Curl_timediff(*nowp, data->progress.t_startsingle),
k->bytecount);
}
}

/* Force connection closed if the connection has indeed been used */
if(data->mstate > MSTATE_DO) {
streamclose(data->conn, "Disconnected with pending data");
stream_error = TRUE;
}
result = CURLE_OPERATION_TIMEDOUT;
(void)multi_done(data, result, TRUE);
if(multi_handle_timeout(data, nowp, &stream_error, &result, FALSE)) {
/* Skip the statemachine and go directly to error handling section. */
goto statemachine_end;
}
Expand Down Expand Up @@ -2418,6 +2438,21 @@ static CURLMcode multi_runsingle(struct Curl_multi *multi,
default:
return CURLM_INTERNAL_ERROR;
}

if(data->conn &&
data->mstate >= MSTATE_CONNECT &&
data->mstate <= MSTATE_DO &&
rc != CURLM_CALL_MULTI_PERFORM &&
!multi_ischanged(multi, false)) {
/* We now handle stream timeouts if and only if this will be the last
* loop iteration. We only check this on the last iteration to ensure
* that if we know we have additional work to do immediately
* (i.e. CURLM_CALL_MULTI_PERFORM == TRUE) then we should do that before
* declaring the connection timed out as we may almost have a completed
* connection. */
multi_handle_timeout(data, nowp, &stream_error, &result, TRUE);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The TRUE in there will make the function check the timeout for the connection phase, and yet you call this function also in the MSTATE_DO state which then already has connected. Surely that makes this too trigger-happy?

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is preserving the existing behaviour. The previous check at line 1706 included checking the connect timeout in the MSTATE_DO.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah yes I see. That's certainly a bug that surely in itself could've contributed to you having the problems you've had! The DO state is passed the connect so it is just wrong to check the connect timeout in that state.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks - I've changed the check to data->mstate < MSTATE_DO to exclude the DO state

}

statemachine_end:

if(data->mstate < MSTATE_COMPLETED) {
Expand Down
7 changes: 5 additions & 2 deletions lib/url.c
Expand Up @@ -3355,9 +3355,12 @@ static CURLcode resolve_server(struct Curl_easy *data,
if(rc == CURLRESOLV_PENDING)
*async = TRUE;

else if(rc == CURLRESOLV_TIMEDOUT)
else if(rc == CURLRESOLV_TIMEDOUT) {
failf(data, "Failed to resolve host '%s' with timeout after %ld ms",
connhost->dispname,
Curl_timediff(Curl_now(), data->progress.t_startsingle));
result = CURLE_OPERATION_TIMEDOUT;

}
else if(!hostaddr) {
failf(data, "Could not resolve host: %s", connhost->dispname);
result = CURLE_COULDNT_RESOLVE_HOST;
Expand Down