From 3ac46f5fa7b04d6cca57eeaed24c7351382cf72d Mon Sep 17 00:00:00 2001 From: Aleric Inglewood Date: Fri, 12 Oct 2012 19:39:11 +0200 Subject: [PATCH] HTTP timeout work in progress. --- indra/aistatemachine/aicurl.cpp | 40 +++++++++++++++------------ indra/aistatemachine/aicurlthread.cpp | 37 ++++++++++++++++++++++++- indra/newview/llxmlrpctransaction.cpp | 17 +++++++----- 3 files changed, 69 insertions(+), 25 deletions(-) diff --git a/indra/aistatemachine/aicurl.cpp b/indra/aistatemachine/aicurl.cpp index 5f53a8685..fae7c3633 100644 --- a/indra/aistatemachine/aicurl.cpp +++ b/indra/aistatemachine/aicurl.cpp @@ -1573,26 +1573,32 @@ bool CurlEasyRequest::timeout_lowspeed(size_t bytes) // | void CurlEasyRequest::timeout_done(CURLcode code) { - timeout_timings(); llassert(mTimeoutUploadFinished || mTimeoutNothingReceivedYet); // If this is false then the 'upload finished' detection failed. - if (code == CURLE_OPERATION_TIMEDOUT) + if (code == CURLE_OPERATION_TIMEDOUT || code == CURLE_COULDNT_RESOLVE_HOST) { - if (mTimeoutNothingReceivedYet) + bool dns_problem = false; + if (code == CURLE_COULDNT_RESOLVE_HOST) { - // Only consider this to possibly be related to a DNS lookup if we didn't connect - // to the remote host yet. Note that CURLINFO_CONNECT_TIME gives the time needed - // to connect to the proxy, or first host-- and fails to take redirects into account. - // Also note that CURLINFO_APPCONNECT_TIME gives the time of the FIRST actual - // connect, so for any transfers on the same pipeline that come after this we - // also correctly determine that there was not a problem with a DNS lookup. - double appconnect_time; - getinfo(CURLINFO_APPCONNECT_TIME, &appconnect_time); - if (appconnect_time == 0) - { - // Inform policy object that there might be problems with resolving this host. - AIHTTPTimeoutPolicy::connect_timed_out(mTimeoutLowercaseHostname); - // AIFIXME: use return value to change priority - } + // Note that CURLINFO_OS_ERRNO returns 0; we don't know any more than this. + llwarns << "Failed to resolve hostname " << mTimeoutLowercaseHostname << llendl; + dns_problem = true; + } + else if (mTimeoutNothingReceivedYet) + { + // Only consider this to possibly be related to a DNS lookup if we didn't + // resolved the host yet, which can be detected by asking for + // CURLINFO_NAMELOOKUP_TIME which is set when libcurl initiates the + // actual connect and thus knows the IP# (possibly from it's DNS cache). + double namelookup_time; + getinfo(CURLINFO_NAMELOOKUP_TIME, &namelookup_time); + dns_problem = (namelookup_time == 0); + } + if (dns_problem) + { + // Inform policy object that there might be problems with resolving this host. + // This will increase the connect timeout the next time we try to connect to this host. + AIHTTPTimeoutPolicy::connect_timed_out(mTimeoutLowercaseHostname); + // AIFIXME: use return value to change priority } } // Make sure no timeout will happen anymore. diff --git a/indra/aistatemachine/aicurlthread.cpp b/indra/aistatemachine/aicurlthread.cpp index ee345ac47..0abb4bc82 100644 --- a/indra/aistatemachine/aicurlthread.cpp +++ b/indra/aistatemachine/aicurlthread.cpp @@ -1654,7 +1654,42 @@ void MultiHandle::finish_easy_request(AICurlEasyRequest const& easy_request, CUR #ifdef CWDEBUG char* eff_url; curl_easy_request_w->getinfo(CURLINFO_EFFECTIVE_URL, &eff_url); - Dout(dc::curl, "Finished: " << eff_url << " (" << curl_easy_strerror(result) << ") [CURLINFO_PRIVATE = " << (void*)easy_request.get_ptr().get() << "]"); + double namelookup_time, connect_time, appconnect_time, pretransfer_time, starttransfer_time; + curl_easy_request_w->getinfo(CURLINFO_NAMELOOKUP_TIME, &namelookup_time); + curl_easy_request_w->getinfo(CURLINFO_CONNECT_TIME, &connect_time); + curl_easy_request_w->getinfo(CURLINFO_APPCONNECT_TIME, &appconnect_time); + curl_easy_request_w->getinfo(CURLINFO_PRETRANSFER_TIME, &pretransfer_time); + curl_easy_request_w->getinfo(CURLINFO_STARTTRANSFER_TIME, &starttransfer_time); + // If appconnect_time is almost equal to connect_time, then it was just set because this is a connection re-use. + if (appconnect_time - connect_time <= 1e-6) + { + appconnect_time = 0; + } + // If connect_time is almost equal to namelookup_time, then it was just set because it was already connected. + if (connect_time - namelookup_time <= 1e-6) + { + connect_time = 0; + } + // If namelookup_time is less than 500 microseconds, then it's very likely just a DNS cache lookup. + if (namelookup_time < 500e-6) + { + namelookup_time = 0; + } + Dout(dc::curl|continued_cf, "Finished: " << eff_url << " (" << curl_easy_strerror(result) << "); "); + if (namelookup_time) + { + Dout(dc::continued, "namelookup time: " << namelookup_time << ", "); + } + if (connect_time) + { + Dout(dc::continued, "connect_time: " << connect_time << ", "); + } + if (appconnect_time) + { + Dout(dc::continued, "appconnect_time: " << appconnect_time << ", "); + } + Dout(dc::finish, "pretransfer_time: " << pretransfer_time << ", starttransfer_time: " << starttransfer_time << + ". [CURLINFO_PRIVATE = " << (void*)easy_request.get_ptr().get() << "]"); #endif // Update timeout administration. curl_easy_request_w->timeout_done(result); diff --git a/indra/newview/llxmlrpctransaction.cpp b/indra/newview/llxmlrpctransaction.cpp index f4cd188fe..e96dc1f2f 100644 --- a/indra/newview/llxmlrpctransaction.cpp +++ b/indra/newview/llxmlrpctransaction.cpp @@ -322,15 +322,18 @@ void LLXMLRPCTransaction::Impl::curlEasyRequestCallback(bool success) if (!success) { // AICurlEasyRequestStateMachine did abort. - // This currently only happens when libcurl didn't finish before the timer expired. - std::ostringstream msg; - F32 timeout_value = gSavedSettings.getF32("CurlRequestTimeOut"); - msg << "Connection to " << mURI << " timed out (" << timeout_value << " s)!"; - if (timeout_value < 40) + // This currently only happens when libcurl didn't finish before the timer expired, or when the viewer was quit. + if (LLApp::isRunning()) { - msg << "\nTry increasing CurlRequestTimeOut in Debug Settings."; + std::ostringstream msg; + F32 timeout_value = gSavedSettings.getF32("CurlRequestTimeOut"); + msg << "Connection to " << mURI << " timed out (" << timeout_value << " s)!"; + if (timeout_value < 40) + { + msg << "\nTry increasing CurlRequestTimeOut in Debug Settings."; + } + setStatus(LLXMLRPCTransaction::StatusOtherError, msg.str()); } - setStatus(LLXMLRPCTransaction::StatusOtherError, msg.str()); return; }