diff --git a/lib/connect.c b/lib/connect.c index d9317f378..18d3d84f5 100644 --- a/lib/connect.c +++ b/lib/connect.c @@ -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); @@ -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); @@ -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)) { @@ -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); diff --git a/lib/multi.c b/lib/multi.c index 322f14377..2237ca69b 100644 --- a/lib/multi.c +++ b/lib/multi.c @@ -1543,6 +1543,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 @@ -1674,7 +1726,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; @@ -1704,47 +1755,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; } @@ -2422,6 +2442,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); + } + statemachine_end: if(data->mstate < MSTATE_COMPLETED) { diff --git a/lib/url.c b/lib/url.c index 9a96e6a93..28594e87b 100644 --- a/lib/url.c +++ b/lib/url.c @@ -3374,9 +3374,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;