HTTP timeout work in progress.

This commit is contained in:
Aleric Inglewood
2012-10-12 19:39:11 +02:00
parent faee255730
commit 3ac46f5fa7
3 changed files with 69 additions and 25 deletions

View File

@@ -1573,26 +1573,32 @@ bool CurlEasyRequest::timeout_lowspeed(size_t bytes)
// | // |
void CurlEasyRequest::timeout_done(CURLcode code) void CurlEasyRequest::timeout_done(CURLcode code)
{ {
timeout_timings();
llassert(mTimeoutUploadFinished || mTimeoutNothingReceivedYet); // If this is false then the 'upload finished' detection failed. 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 // Note that CURLINFO_OS_ERRNO returns 0; we don't know any more than this.
// to the remote host yet. Note that CURLINFO_CONNECT_TIME gives the time needed llwarns << "Failed to resolve hostname " << mTimeoutLowercaseHostname << llendl;
// to connect to the proxy, or first host-- and fails to take redirects into account. dns_problem = true;
// 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 else if (mTimeoutNothingReceivedYet)
// also correctly determine that there was not a problem with a DNS lookup. {
double appconnect_time; // Only consider this to possibly be related to a DNS lookup if we didn't
getinfo(CURLINFO_APPCONNECT_TIME, &appconnect_time); // resolved the host yet, which can be detected by asking for
if (appconnect_time == 0) // CURLINFO_NAMELOOKUP_TIME which is set when libcurl initiates the
{ // actual connect and thus knows the IP# (possibly from it's DNS cache).
// Inform policy object that there might be problems with resolving this host. double namelookup_time;
AIHTTPTimeoutPolicy::connect_timed_out(mTimeoutLowercaseHostname); getinfo(CURLINFO_NAMELOOKUP_TIME, &namelookup_time);
// AIFIXME: use return value to change priority 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. // Make sure no timeout will happen anymore.

View File

@@ -1654,7 +1654,42 @@ void MultiHandle::finish_easy_request(AICurlEasyRequest const& easy_request, CUR
#ifdef CWDEBUG #ifdef CWDEBUG
char* eff_url; char* eff_url;
curl_easy_request_w->getinfo(CURLINFO_EFFECTIVE_URL, &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 #endif
// Update timeout administration. // Update timeout administration.
curl_easy_request_w->timeout_done(result); curl_easy_request_w->timeout_done(result);

View File

@@ -322,15 +322,18 @@ void LLXMLRPCTransaction::Impl::curlEasyRequestCallback(bool success)
if (!success) if (!success)
{ {
// AICurlEasyRequestStateMachine did abort. // AICurlEasyRequestStateMachine did abort.
// This currently only happens when libcurl didn't finish before the timer expired. // This currently only happens when libcurl didn't finish before the timer expired, or when the viewer was quit.
std::ostringstream msg; if (LLApp::isRunning())
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."; 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; return;
} }