From 982921e495b4f2f86a656139d0ab7bcd28742067 Mon Sep 17 00:00:00 2001 From: Aleric Inglewood Date: Mon, 1 Jul 2013 15:41:44 +0200 Subject: [PATCH 1/5] Add AICurlTimer - timer support for the curl thread. Not used yet. Deliberately not threadsafe. Usage the same as AIFrameTimer, upon which is was based. --- indra/llmessage/CMakeLists.txt | 2 + indra/llmessage/aicurlthread.cpp | 55 +++++++++--- indra/llmessage/aicurlthread.h | 3 + indra/llmessage/aicurltimer.cpp | 110 +++++++++++++++++++++++ indra/llmessage/aicurltimer.h | 144 +++++++++++++++++++++++++++++++ 5 files changed, 302 insertions(+), 12 deletions(-) create mode 100644 indra/llmessage/aicurltimer.cpp create mode 100644 indra/llmessage/aicurltimer.h diff --git a/indra/llmessage/CMakeLists.txt b/indra/llmessage/CMakeLists.txt index 53e890040..2f9963706 100644 --- a/indra/llmessage/CMakeLists.txt +++ b/indra/llmessage/CMakeLists.txt @@ -27,6 +27,7 @@ set(llmessage_SOURCE_FILES aicurleasyrequeststatemachine.cpp aicurlperservice.cpp aicurlthread.cpp + aicurltimer.cpp aihttpheaders.cpp aihttptimeout.cpp aihttptimeoutpolicy.cpp @@ -116,6 +117,7 @@ set(llmessage_HEADER_FILES aicurlperservice.h aicurlprivate.h aicurlthread.h + aicurltimer.h aihttpheaders.h aihttptimeout.h aihttptimeoutpolicy.h diff --git a/indra/llmessage/aicurlthread.cpp b/indra/llmessage/aicurlthread.cpp index a29859048..70c4d5a37 100644 --- a/indra/llmessage/aicurlthread.cpp +++ b/indra/llmessage/aicurlthread.cpp @@ -34,6 +34,7 @@ #include "aihttptimeout.h" #include "aicurlperservice.h" #include "aiaverage.h" +#include "aicurltimer.h" #include "lltimer.h" // ms_sleep, get_clock_count #include "llhttpstatuscodes.h" #include "llbuffer.h" @@ -1433,21 +1434,35 @@ void AICurlThread::run(void) #endif int ready = 0; struct timeval timeout; + // Update AICurlTimer::sTime_1ms. + AICurlTimer::sTime_1ms = get_clock_count() * AICurlTimer::sClockWidth_1ms; + Dout(dc::curl, "AICurlTimer::sTime_1ms = " << AICurlTimer::sTime_1ms); + // Get the time in ms that libcurl wants us to wait for socket actions - at most - before proceeding. long timeout_ms = multi_handle_w->getTimeout(); - // If no timeout is set, sleep 1 second. + // Set libcurl_timeout iff the shortest timeout is that of libcurl. + bool libcurl_timeout = timeout_ms == 0 || (timeout_ms > 0 && !AICurlTimer::expiresBefore(timeout_ms)); + // If no curl timeout is set, sleep at most 4 seconds. if (LL_UNLIKELY(timeout_ms < 0)) - timeout_ms = 1000; - if (LL_UNLIKELY(timeout_ms == 0)) + timeout_ms = 4000; + // Check if some AICurlTimer expires first. + if (AICurlTimer::expiresBefore(timeout_ms)) { - if (mZeroTimeout >= 10000) + timeout_ms = AICurlTimer::nextExpiration(); + } + // If we have to continue immediately, then just set a zero timeout, but only for 100 calls on a row; + // after that start sleeping 1ms and later even 10ms (this should never happen). + if (LL_UNLIKELY(timeout_ms <= 0)) + { + if (mZeroTimeout >= 1000) { - if (mZeroTimeout == 10000) - llwarns << "Detected more than 10000 zero-timeout calls of select() by curl thread (more than 101 seconds)!" << llendl; - } - else if (mZeroTimeout >= 1000) + if (mZeroTimeout % 10000 == 0) + llwarns << "Detected " << mZeroTimeout << " zero-timeout calls of select() by curl thread (more than 101 seconds)!" << llendl; timeout_ms = 10; + } else if (mZeroTimeout >= 100) timeout_ms = 1; + else + timeout_ms = 0; } else { @@ -1554,12 +1569,28 @@ void AICurlThread::run(void) } continue; } - // Clock count used for timeouts. - HTTPTimeout::sTime_10ms = get_clock_count() * HTTPTimeout::sClockWidth_10ms; - Dout(dc::curl, "HTTPTimeout::sTime_10ms = " << HTTPTimeout::sTime_10ms); + // Update the clocks. + AICurlTimer::sTime_1ms = get_clock_count() * AICurlTimer::sClockWidth_1ms; + Dout(dc::curl, "AICurlTimer::sTime_1ms = " << AICurlTimer::sTime_1ms); + HTTPTimeout::sTime_10ms = AICurlTimer::sTime_1ms / 10; if (ready == 0) { - multi_handle_w->socket_action(CURL_SOCKET_TIMEOUT, 0); + if (libcurl_timeout) + { + multi_handle_w->socket_action(CURL_SOCKET_TIMEOUT, 0); + } + else + { + // Update MultiHandle::mTimeout because next loop we need to sleep timeout_ms shorter. + multi_handle_w->update_timeout(timeout_ms); + Dout(dc::curl, "MultiHandle::mTimeout set to " << multi_handle_w->getTimeout() << " ms."); + } + // Handle timers. + if (AICurlTimer::expiresBefore(1)) + { + AICurlTimer::handleExpiration(); + } + // Handle stalling transactions. multi_handle_w->handle_stalls(); } else diff --git a/indra/llmessage/aicurlthread.h b/indra/llmessage/aicurlthread.h index 080456652..908456b13 100644 --- a/indra/llmessage/aicurlthread.h +++ b/indra/llmessage/aicurlthread.h @@ -93,6 +93,9 @@ class MultiHandle : public CurlMultiHandle // Returns how long to wait for socket action before calling socket_action(CURL_SOCKET_TIMEOUT, 0), in ms. int getTimeout(void) const { return mTimeout; } + // We slept delta_ms instead of mTimeout ms. Update mTimeout to be the remaining time. + void update_timeout(long delta_ms) { mTimeout -= delta_ms; } + // This is called before sleeping, after calling (one or more times) socket_action. void check_msg_queue(void); diff --git a/indra/llmessage/aicurltimer.cpp b/indra/llmessage/aicurltimer.cpp new file mode 100644 index 000000000..7c2e3dc51 --- /dev/null +++ b/indra/llmessage/aicurltimer.cpp @@ -0,0 +1,110 @@ +/** + * @file aicurltimer.cpp + * + * Copyright (c) 2013, Aleric Inglewood. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + * + * There are special exceptions to the terms and conditions of the GPL as + * it is applied to this Source Code. View the full text of the exception + * in the file doc/FLOSS-exception.txt in this software distribution. + * + * CHANGELOG + * and additional copyright holders. + * + * 29/06/2013 + * - Initial version, written by Aleric Inglewood @ SL + */ + +// An AICurlTimer object provides a callback API for timer events +// by and from the curl thread. It is NOT threadsafe. Everything +// has to be called from the curl thread. +// +// Typical usage: +// +// AICurlTimer timer; +// ... +// // In curl thread (after successful construction is guaranteed). +// timer.create(5.5, boost::bind(&the_callback, )); // Call the_callback() in 5.5 seconds. +// +// The callback function is always called by the curl thread. +// +// If timer.cancel() is called before the timer expires, then the callback +// function isn't called. Calling cancel() multiple times is not a problem. +// Note: It is not allowed to call cancel() is from the callback function +// (and rather pointless). +// +// The timer object can be reused (by calling create() again), but +// only after either the callback function was called, or after cancel() +// returned. Most notably, you can call create() again from inside the +// callback function to "restart" the timer. +// + +#include "aicurltimer.h" +#include "lltimer.h" + +static U64 const NEVER = ((U64)1) << 60; // The year 36,560,871. + +//static +F64 const AICurlTimer::sClockWidth_1ms = 1000.0 / calc_clock_frequency(); // Time between two clock ticks, in 1ms units. +U64 AICurlTimer::sTime_1ms; // Time in 1ms units, set once per select() entry. +U64 AICurlTimer::sNextExpiration; +AICurlTimer::timer_list_type AICurlTimer::sTimerList; + +void AICurlTimer::create(deltams_type expiration, signal_type::slot_type const& slot) +{ + AIRunningCurlTimer new_timer(expiration, this); + llassert(mHandle.mRunningTimer == sTimerList.end()); // Create may only be called when the timer isn't already running. + mHandle.init(sTimerList.insert(new_timer), slot); + sNextExpiration = sTimerList.begin()->expiration(); +} + +void AICurlTimer::cancel(void) +{ + if (mHandle.mRunningTimer != sTimerList.end()) + { + sTimerList.erase(mHandle.mRunningTimer); + mHandle.mRunningTimer = sTimerList.end(); + sNextExpiration = sTimerList.empty() ? NEVER : sTimerList.begin()->expiration(); + } +} + +void AICurlTimer::handleExpiration(void) +{ + for(;;) + { + if (sTimerList.empty()) + { + // No running timers left. + sNextExpiration = NEVER; + break; + } + timer_list_type::iterator running_timer = sTimerList.begin(); + sNextExpiration = running_timer->expiration(); + if (sNextExpiration > sTime_1ms) + { + // Didn't expire yet. + break; + } + + Handle& handle(running_timer->getTimer()->mHandle); + llassert_always(running_timer == handle.mRunningTimer); + handle.mRunningTimer = sTimerList.end(); + running_timer->do_callback(); // May not throw exceptions. + + // Erase the timer from the running list. + sTimerList.erase(running_timer); + } +} + diff --git a/indra/llmessage/aicurltimer.h b/indra/llmessage/aicurltimer.h new file mode 100644 index 000000000..8b30a9ac6 --- /dev/null +++ b/indra/llmessage/aicurltimer.h @@ -0,0 +1,144 @@ +/** + * @file aicurltimer.h + * @brief Implementation of AICurlTimer. + * + * Copyright (c) 2013, Aleric Inglewood. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + * + * There are special exceptions to the terms and conditions of the GPL as + * it is applied to this Source Code. View the full text of the exception + * in the file doc/FLOSS-exception.txt in this software distribution. + * + * CHANGELOG + * and additional copyright holders. + * + * 29/06/2013 + * Initial version, written by Aleric Inglewood @ SL + */ + +#ifndef AICURLTIMER_H +#define AICURLTIMER_H + +#include "llerror.h" // llassert +#include "stdtypes.h" // U64, F64 +#include +#include + +class AICurlTimer +{ + protected: + typedef boost::signals2::signal signal_type; + typedef long deltams_type; + + private: + // Use separate struct for this object because it is non-copyable. + struct Signal { + signal_type mSignal; + }; + + class AIRunningCurlTimer { + private: + U64 mExpire; // Time at which the timer expires, in miliseconds since the epoch (compared to LLCurlTimer::sTime_1ms). + AICurlTimer* mTimer; // The actual timer. + // Can be mutable, since only the mExpire is used for ordering this object in the multiset AICurlTimer::sTimerList. + mutable Signal* mCallback; // Pointer to callback struct, or NULL when the object wasn't added to sTimerList yet. + + public: + AIRunningCurlTimer(deltams_type expiration, AICurlTimer* timer) : mExpire(AICurlTimer::sTime_1ms + expiration), mTimer(timer), mCallback(NULL) { } + ~AIRunningCurlTimer() { delete mCallback; } + + // This function is called after the final object was added to sTimerList (where it is initialized in-place). + void init(signal_type::slot_type const& slot) const + { + // We may only call init() once. + llassert(!mCallback); + mCallback = new Signal; + mCallback->mSignal.connect(slot); + } + + // Order AICurlTimer::sTimerList so that the timer that expires first is up front. + friend bool operator<(AIRunningCurlTimer const& ft1, AIRunningCurlTimer const& ft2) { return ft1.mExpire < ft2.mExpire; } + + void do_callback(void) const { mCallback->mSignal(); } + U64 expiration(void) const { return mExpire; } + AICurlTimer* getTimer(void) const { return mTimer; } + +#if LL_DEBUG + // May not copy this object after it was initialized. + AIRunningCurlTimer(AIRunningCurlTimer const& running_curl_timer) : + mExpire(running_curl_timer.mExpire), mTimer(running_curl_timer.mTimer), mCallback(running_curl_timer.mCallback) + { llassert(!mCallback); } +#endif + }; + + typedef std::multiset timer_list_type; + static timer_list_type sTimerList; // List with all running timers. + static U64 sNextExpiration; // Cache of smallest value in sTimerList. + + public: + static F64 const sClockWidth_1ms; // Time between two clock ticks in 1 ms units. + static U64 sTime_1ms; // Time since the epoch in 1 ms units. Set by AICurlThread::run(). + + static deltams_type nextExpiration(void) { return static_cast(sNextExpiration - sTime_1ms); } + static bool expiresBefore(deltams_type timeout_ms) { return sNextExpiration < sTime_1ms + timeout_ms; } + + private: + class Handle { + public: + timer_list_type::iterator mRunningTimer; // Points to the running timer, or to sTimerList.end() when not running. + // Access to this iterator is protected by the AICurlTimer::sMutex! + + // Constructor for a not-running timer. + Handle(void) : mRunningTimer(sTimerList.end()) { } + + // Actual initialization used by AICurlTimer::create. + void init(timer_list_type::iterator const& running_timer, signal_type::slot_type const& slot) + { + mRunningTimer = running_timer; + mRunningTimer->init(slot); + } + + private: + // No assignment operator. + Handle& operator=(Handle const&) { return *this; } + }; + + Handle mHandle; + + public: + // Construct an AICurlTimer that is not running. + AICurlTimer(void) { } + + // Construction of a running AICurlTimer with expiration time expiration in miliseconds, and callback slot. + AICurlTimer(deltams_type expiration, signal_type::slot_type const& slot) { create(expiration, slot); } + + // Destructing the AICurlTimer object terminates the running timer (if still running). + // Note that cancel() must have returned BEFORE anything is destructed that would disallow the callback function to be called. + // So, if the AICurlTimer is a member of an object whose callback function is called then cancel() has + // to be called manually (or from the destructor of THAT object), before that object is destructed. + // Cancel may be called multiple times. + ~AICurlTimer() { cancel(); } + + void create(deltams_type expiration, signal_type::slot_type const& slot); + void cancel(void); + + bool isRunning(void) const { return mHandle.mRunningTimer != sTimerList.end(); } + + public: + static void handleExpiration(void); +}; + +#endif + From 0353498b9ccf214926ee8358c293823e9ae0a9db Mon Sep 17 00:00:00 2001 From: Aleric Inglewood Date: Mon, 1 Jul 2013 15:44:47 +0200 Subject: [PATCH 2/5] Set CURLOPT_FORBID_REUSE for XMLRPCResponder XMLRPCResponder is used to login, which is a HTTP 1.0 server that doesn't support reuse of connections. It's cleaner to close connections from our side too. This changes, 0x7fffdcf93700 CURLIO 0x7fffcd86db40 * Connection #0 to host login.agni.lindenlab.com left intact into 0x7fffdcf93700 CURLIO 0x7fffcd8b0bd0 * Closing connection #0 --- indra/llmessage/aicurl.cpp | 4 ++++ indra/llmessage/llhttpclient.h | 4 ++++ indra/newview/llxmlrpcresponder.h | 1 + 3 files changed, 9 insertions(+) diff --git a/indra/llmessage/aicurl.cpp b/indra/llmessage/aicurl.cpp index e5dcb6ae8..7e6fc9236 100644 --- a/indra/llmessage/aicurl.cpp +++ b/indra/llmessage/aicurl.cpp @@ -1392,6 +1392,10 @@ void BufferedCurlEasyRequest::prepRequest(AICurlEasyRequest_wat& curl_easy_reque // to id.secondlife.com for marketplace.secondlife.com. allow_cookies = true; } + if (responder->forbidReuse()) + { + curl_easy_request_w->setopt(CURLOPT_FORBID_REUSE, 1); + } if (allow_cookies) { // Given an empty or non-existing file or by passing the empty string (""), diff --git a/indra/llmessage/llhttpclient.h b/indra/llmessage/llhttpclient.h index af11a6687..b4ce6facc 100644 --- a/indra/llmessage/llhttpclient.h +++ b/indra/llmessage/llhttpclient.h @@ -217,6 +217,10 @@ public: // Derived classes that implement completed_headers()/completedHeaders() should return true here. virtual bool needsHeaders(void) const { return false; } + // A derived class should return true if curl should close the connection when done. + // The default is to keep connections open for possible reuse. + virtual bool forbidReuse(void) const { return false; } + // A derived class should return true if curl should follow redirections. // The default is not to follow redirections. virtual bool followRedir(void) const { return false; } diff --git a/indra/newview/llxmlrpcresponder.h b/indra/newview/llxmlrpcresponder.h index 3c32cd2a6..4a5f29077 100644 --- a/indra/newview/llxmlrpcresponder.h +++ b/indra/newview/llxmlrpcresponder.h @@ -107,6 +107,7 @@ public: LLXMLRPCValue responseValue(void) const; /*virtual*/ bool needsHeaders(void) const { return true; } + /*virtual*/ bool forbidReuse(void) const { return true; } /*virtual*/ void received_HTTP_header(void) { mReceivedHTTPHeader = true; LLHTTPClient::ResponderBase::received_HTTP_header(); } /*virtual*/ void completed_headers(U32 status, std::string const& reason, AITransferInfo* info); /*virtual*/ void completedRaw(U32 status, std::string const& reason, LLChannelDescriptors const& channels, buffer_ptr_t const& buffer); From 59716ba86b880009357190d456cd22c213ee36e1 Mon Sep 17 00:00:00 2001 From: Aleric Inglewood Date: Tue, 2 Jul 2013 02:07:07 +0200 Subject: [PATCH 3/5] Added progress meter in HTTP debug console. --- indra/llmessage/aicurl.cpp | 1 - indra/llmessage/aicurlperservice.cpp | 6 +++- indra/llmessage/aicurlperservice.h | 8 ++++- indra/llmessage/aicurlthread.cpp | 10 +++--- indra/newview/aihttpview.cpp | 48 +++++++++++++++++++++++----- 5 files changed, 58 insertions(+), 15 deletions(-) diff --git a/indra/llmessage/aicurl.cpp b/indra/llmessage/aicurl.cpp index 7e6fc9236..6b8ac5064 100644 --- a/indra/llmessage/aicurl.cpp +++ b/indra/llmessage/aicurl.cpp @@ -977,7 +977,6 @@ void CurlEasyRequest::resetState(void) mTimeoutPolicy = NULL; mTimeout = NULL; mHandleEventsTarget = NULL; - mResult = CURLE_FAILED_INIT; applyDefaultOptions(); } diff --git a/indra/llmessage/aicurlperservice.cpp b/indra/llmessage/aicurlperservice.cpp index a0493f1a3..c99264db8 100644 --- a/indra/llmessage/aicurlperservice.cpp +++ b/indra/llmessage/aicurlperservice.cpp @@ -339,7 +339,7 @@ void AIPerService::added_to_multi_handle(AICapabilityType capability_type) ++mTotalAdded; } -void AIPerService::removed_from_multi_handle(AICapabilityType capability_type, bool downloaded_something) +void AIPerService::removed_from_multi_handle(AICapabilityType capability_type, bool downloaded_something, bool success) { CapabilityType& ct(mCapabilityType[capability_type]); llassert(mTotalAdded > 0 && ct.mAdded > 0); @@ -354,6 +354,10 @@ void AIPerService::removed_from_multi_handle(AICapabilityType capability_type, b { mark_unused(capability_type); } + if (success) + { + ct.mFlags |= ctf_success; + } } // Returns true if the request was queued. diff --git a/indra/llmessage/aicurlperservice.h b/indra/llmessage/aicurlperservice.h index 0509dfd95..f81236997 100644 --- a/indra/llmessage/aicurlperservice.h +++ b/indra/llmessage/aicurlperservice.h @@ -134,6 +134,11 @@ class AIPerService { static U16 const ctf_empty = 1; static U16 const ctf_full = 2; static U16 const ctf_starvation = 4; + // Flags used by the HTTP debug console. + static U16 const ctf_success = 8; + static U16 const ctf_progress_mask = 0x70; + static U16 const ctf_progress_shift = 4; + static U16 const ctf_grey = 0x80; struct CapabilityType { typedef std::deque queued_request_type; @@ -145,6 +150,7 @@ class AIPerService { U16 mFlags; // ctf_empty: Set to true when the queue becomes precisely empty. // ctf_full : Set to true when the queue is popped and then still isn't empty; // ctf_starvation: Set to true when the queue was about to be popped but was already empty. + // ctf_success: Set to true when a curl request finished successfully. U32 mDownloading; // The number of active easy handles with this service for which data was received. U16 mMaxPipelinedRequests; // The maximum number of accepted requests for this service and (approved) capability type, that didn't finish yet. U16 mConcurrentConnections; // The maximum number of allowed concurrent connections to the service of this capability type. @@ -259,7 +265,7 @@ class AIPerService { void added_to_command_queue(AICapabilityType capability_type) { ++mCapabilityType[capability_type].mQueuedCommands; mark_inuse(capability_type); } void removed_from_command_queue(AICapabilityType capability_type) { --mCapabilityType[capability_type].mQueuedCommands; llassert(mCapabilityType[capability_type].mQueuedCommands >= 0); } void added_to_multi_handle(AICapabilityType capability_type); // Called when an easy handle for this service has been added to the multi handle. - void removed_from_multi_handle(AICapabilityType capability_type, bool downloaded_something); // Called when an easy handle for this service is removed again from the multi handle. + void removed_from_multi_handle(AICapabilityType capability_type, bool downloaded_something, bool success); // Called when an easy handle for this service is removed again from the multi handle. void download_started(AICapabilityType capability_type) { ++mCapabilityType[capability_type].mDownloading; } bool throttled(AICapabilityType capability_type) const; // Returns true if the maximum number of allowed requests for this service/capability type have been added to the multi handle. bool nothing_added(AICapabilityType capability_type) const { return mCapabilityType[capability_type].mAdded == 0; } diff --git a/indra/llmessage/aicurlthread.cpp b/indra/llmessage/aicurlthread.cpp index 70c4d5a37..f6f971516 100644 --- a/indra/llmessage/aicurlthread.cpp +++ b/indra/llmessage/aicurlthread.cpp @@ -1647,7 +1647,7 @@ MultiHandle::~MultiHandle() // Curl demands that all handles are removed from the multi session handle before calling curl_multi_cleanup. for(addedEasyRequests_type::iterator iter = mAddedEasyRequests.begin(); iter != mAddedEasyRequests.end(); iter = mAddedEasyRequests.begin()) { - finish_easy_request(*iter, CURLE_OK); // Error code is not used anyway. + finish_easy_request(*iter, CURLE_GOT_NOTHING); // Error code is not used anyway. remove_easy_request(*iter); } delete mWritePollSet; @@ -1848,7 +1848,9 @@ CURLMcode MultiHandle::remove_easy_request(addedEasyRequests_type::iterator cons res = curl_easy_request_w->remove_handle_from_multi(curl_easy_request_w, mMultiHandle); capability_type = curl_easy_request_w->capability_type(); per_service = curl_easy_request_w->getPerServicePtr(); - PerService_wat(*per_service)->removed_from_multi_handle(capability_type, downloaded_something); // (About to be) removed from mAddedEasyRequests. + CURLcode code; + curl_easy_request_w->getResult(&code, NULL); + PerService_wat(*per_service)->removed_from_multi_handle(capability_type, downloaded_something, code == CURLE_OK); // (About to be) removed from mAddedEasyRequests. #ifdef SHOW_ASSERT curl_easy_request_w->mRemovedPerCommand = as_per_command; #endif @@ -2200,7 +2202,7 @@ void BufferedCurlEasyRequest::update_body_bandwidth(void) mTotalRawBytes = total_raw_bytes; // Note that in some cases (like HTTP_PARTIAL_CONTENT), the output of CURLINFO_SIZE_DOWNLOAD lags // behind and will return 0 the first time, and the value of the previous chunk the next time. - // The last call from MultiHandle::finish_easy_request recorrects this, in that case. + // The last call from MultiHandle::finish_easy_request corrects this, in that case. if (raw_bytes > 0) { U64 const sTime_40ms = curlthread::HTTPTimeout::sTime_10ms >> 2; @@ -2800,7 +2802,7 @@ AIPerService::Approvement* AIPerService::approveHTTPRequestFor(AIPerServicePtr c equal = pipelined_requests_per_capability_type == ct.mMaxPipelinedRequests; increment_threshold = ct.mFlags & ctf_starvation; decrement_threshold = (ct.mFlags & (ctf_empty | ctf_full)) == ctf_full; - ct.mFlags = 0; + ct.mFlags &= ~(ctf_empty|ctf_full|ctf_starvation); if (decrement_threshold) { if ((int)ct.mMaxPipelinedRequests > ct.mConcurrentConnections) diff --git a/indra/newview/aihttpview.cpp b/indra/newview/aihttpview.cpp index 86849575f..60e9fc4e6 100644 --- a/indra/newview/aihttpview.cpp +++ b/indra/newview/aihttpview.cpp @@ -76,7 +76,7 @@ void AIServiceBar::draw() LLFontGL::getFontMonospace()->renderUTF8(mName, 0, start, height, text_color, LLFontGL::LEFT, LLFontGL::TOP); start += LLFontGL::getFontMonospace()->getWidth(mName); std::string text; - AIPerService::CapabilityType const* cts; + AIPerService::CapabilityType* cts; U32 is_used; U32 is_inuse; int total_added; @@ -94,20 +94,52 @@ void AIServiceBar::draw() for (int col = 0; col < number_of_capability_types; ++col) { AICapabilityType capability_type = static_cast(col); - AIPerService::CapabilityType const& ct(cts[capability_type]); + AIPerService::CapabilityType& ct(cts[capability_type]); start = mHTTPView->updateColumn(col, start); U32 mask = AIPerService::CT2mask(capability_type); if (!(is_used & mask)) { text = " | "; } - else if (col < 2) - { - text = llformat(" | %hu-%hu-%lu,{%hu/%hu,%u}/%u", ct.mApprovedRequests, ct.mQueuedCommands, ct.mQueuedRequests.size(), ct.mAdded, ct.mConcurrentConnections, ct.mDownloading, ct.mMaxPipelinedRequests); - } else { - text = llformat(" | --%hu-%lu,{%hu/%hu,%u}", ct.mQueuedCommands, ct.mQueuedRequests.size(), ct.mAdded, ct.mConcurrentConnections, ct.mDownloading); + if (col < 2) + { + text = llformat(" | %hu-%hu-%lu,{%hu/%hu,%u}/%u", + ct.mApprovedRequests, ct.mQueuedCommands, ct.mQueuedRequests.size(), + ct.mAdded, ct.mConcurrentConnections, ct.mDownloading, + ct.mMaxPipelinedRequests); + } + else + { + text = llformat(" | --%hu-%lu,{%hu/%hu,%u}", + ct.mQueuedCommands, ct.mQueuedRequests.size(), + ct.mAdded, ct.mConcurrentConnections, ct.mDownloading); + } + if (capability_type == cap_texture || capability_type == cap_mesh) + { + if (!(is_inuse & mask)) + { + ct.mFlags |= AIPerService::ctf_grey; + } + else + { + bool show = true; + int progress_counter = (ct.mFlags & AIPerService::ctf_progress_mask) >> AIPerService::ctf_progress_shift; + if ((ct.mFlags & AIPerService::ctf_success)) + { + show = !(ct.mFlags & AIPerService::ctf_grey); + ct.mFlags &= ~(AIPerService::ctf_success|AIPerService::ctf_grey|AIPerService::ctf_progress_mask); + progress_counter = (progress_counter + 1) % 8; + ct.mFlags |= progress_counter << AIPerService::ctf_progress_shift; + } + if (show) + { + static char const* progress_utf8[8] = { " \xe2\xac\x93", " \xe2\xac\x95", " \xe2\x97\xa7", " \xe2\x97\xa9", " \xe2\xac\x92", " \xe2\xac\x94", " \xe2\x97\xa8", " \xe2\x97\xaa" }; + text += progress_utf8[progress_counter]; + } + } + } } LLFontGL::getFontMonospace()->renderUTF8(text, 0, start, height, ((is_inuse & mask) == 0) ? LLColor4::grey2 : text_color, LLFontGL::LEFT, LLFontGL::TOP); start += LLFontGL::getFontMonospace()->getWidth(text); @@ -174,7 +206,7 @@ void AIGLHTTPHeaderBar::draw(void) // First header line. F32 height = v_offset + sLineHeight * number_of_header_lines; - text = "HTTP console -- [approved]-commandQ-curlQ,{added/max,downloading}[/max]"; + text = "HTTP console -- [approved]-commandQ-curlQ,{added/max,downloading}[/max][ completed]"; LLFontGL::getFontMonospace()->renderUTF8(text, 0, h_offset, height, text_color, LLFontGL::LEFT, LLFontGL::TOP); text = " | Added/Max"; U32 start = mHTTPView->updateColumn(mc_col, 100); From e0c66138c79184c08c5fb216736dd54256c52e6d Mon Sep 17 00:00:00 2001 From: Aleric Inglewood Date: Wed, 3 Jul 2013 23:48:56 +0200 Subject: [PATCH 4/5] Increase connect timeouts for capabilities that demand short transfer times. The automatic adjustment sets the connect time to 3 seconds, which might be a bit on the short side sometimes. Also remove the HACK and use CurlTimeoutConnect again. The default is still 10 seconds, but is overridden to be 30 for mesh now (which needs a reconnect for every mesh, since LL does not support connection reuse for mesh). Note that I never saw any successful connect under 8 seconds while I had the connect time out at 30: Over 8 seconds is a sure fail (except for mesh, where in rare cases there were connect times of 15 seconds (never 14 or 16). On quiet servers, the connect time is normally sub-second. This is the bulk of connections for my own SL use. --- indra/llmessage/aihttptimeoutpolicy.cpp | 65 +++++++++++++++++-------- indra/newview/llappviewer.cpp | 2 +- 2 files changed, 46 insertions(+), 21 deletions(-) diff --git a/indra/llmessage/aihttptimeoutpolicy.cpp b/indra/llmessage/aihttptimeoutpolicy.cpp index 502cabf37..65451b34a 100644 --- a/indra/llmessage/aihttptimeoutpolicy.cpp +++ b/indra/llmessage/aihttptimeoutpolicy.cpp @@ -677,21 +677,46 @@ AIHTTPTimeoutPolicyBase AIHTTPTimeoutPolicy::sDebugSettingsCurlTimeout( // Note: All operator objects (Transaction, Connect, etc) must be globals (not temporaries)! // To enforce this they are passes as reference to non-const (but will never be changed). -// This used to be '5 seconds'. -Transaction transactionOp5s(5); -AIHTTPTimeoutPolicyBase transfer_5s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), - transactionOp5s +// Used for baseCapabilitiesComplete - which is retried many times, and needs to be rather "fast". +// Most connection succeed under 5 seconds. +Connect connectOp5s(5); +AIHTTPTimeoutPolicyBase connect_5s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), + connectOp5s ); -// This used to be '18 seconds'. -Transaction transactionOp18s(18); -AIHTTPTimeoutPolicyBase transfer_18s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), +// Some services connects rather slow. We need to enforce that connect timeouts never drop below 10 seconds for the policies that shorten the transaction time. +Connect connectOp10s(10); +AIHTTPTimeoutPolicyBase connect_10s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), + connectOp10s + ); + +// The texture/mesh service suffers often from timeouts, give them a much longer connect timeout than normal. +Connect connectOp30s(30); +AIHTTPTimeoutPolicyBase connect_30s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), + connectOp30s + ); + +// Extreme measures. +Connect connectOp60s(60); +AIHTTPTimeoutPolicyBase connect_60s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), + connectOp60s + ); + +// This used to be '18 seconds'. Pass connectOp5s or it would become 3 seconds (which is working already pretty good actually). +Transaction transactionOp18s(18, connectOp5s); +AIHTTPTimeoutPolicyBase transfer_18s_connect_5s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), transactionOp18s ); -// This used to be '30 seconds'. -Transaction transactionOp30s(30); -AIHTTPTimeoutPolicyBase transfer_30s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), +// This used to be '18 seconds'. Pass connectOp10s or it would become 3 seconds. +Transaction transactionOp22s(22, connectOp10s); +AIHTTPTimeoutPolicyBase transfer_22s_connect_10s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), + transactionOp22s + ); + +// This used to be '30 seconds'. Pass connectOp10s or it would become 3 seconds. +Transaction transactionOp30s(30, connectOp10s); +AIHTTPTimeoutPolicyBase transfer_30s_connect_10s(AIHTTPTimeoutPolicyBase::getDebugSettingsCurlTimeout(), transactionOp30s ); @@ -881,7 +906,7 @@ P(asyncConsoleResponder); P(avatarPickerResponder); P(authHandler); P(avatarNameResponder); -P2(baseCapabilitiesComplete, transfer_18s); +P2(baseCapabilitiesComplete, transfer_18s_connect_5s); P(blockingLLSDPost); P(blockingLLSDGet); P(blockingRawGet); @@ -889,7 +914,7 @@ P(charactersResponder); P(checkAgentAppearanceServiceResponder); P(classifiedStatsResponder); P(consoleResponder); -P2(crashLoggerResponder, transfer_5s); +P2(crashLoggerResponder, transfer_22s_connect_10s); P(createInventoryCategoryResponder); P(emeraldDicDownloader); P(environmentApplyResponder); @@ -902,7 +927,7 @@ P(fetchScriptLimitsRegionDetailsResponder); P(fetchScriptLimitsRegionInfoResponder); P(fetchScriptLimitsRegionSummaryResponder); P(fnPtrResponder); -P2(gamingDataReceived, transfer_18s); +P2(gamingDataReceived, transfer_22s_connect_10s); P2(groupMemberDataResponder, transfer_300s); P2(groupProposalBallotResponder, transfer_300s); P(homeLocationResponder); @@ -916,14 +941,14 @@ P(lcl_responder); P(MPImportGetResponder); P(MPImportPostResponder); P(mapLayerResponder); -P2(maturityPreferences, transfer_30s); +P2(maturityPreferences, transfer_30s_connect_10s); P(mediaDataClientResponder); P(mediaTypeResponder); -P(meshDecompositionResponder); -P(meshHeaderResponder); -P(meshLODResponder); -P(meshPhysicsShapeResponder); -P(meshSkinInfoResponder); +P2(meshDecompositionResponder, connect_30s); +P2(meshHeaderResponder, connect_30s); +P2(meshLODResponder, connect_30s); +P2(meshPhysicsShapeResponder, connect_30s); +P2(meshSkinInfoResponder, connect_30s); P(mimeDiscoveryResponder); P(moderationResponder); P(navMeshRebakeResponder); @@ -941,7 +966,7 @@ P(requestAgentUpdateAppearance); P(responderIgnore); P(sessionInviteResponder); P(setDisplayNameResponder); -P2(simulatorFeaturesReceived, transfer_18s); +P2(simulatorFeaturesReceived, transfer_22s_connect_10s); P(startConferenceChatResponder); P2(startGroupVoteResponder, transfer_300s); P(terrainLinksetsResponder); diff --git a/indra/newview/llappviewer.cpp b/indra/newview/llappviewer.cpp index 29a339eca..5cb16e6d9 100644 --- a/indra/newview/llappviewer.cpp +++ b/indra/newview/llappviewer.cpp @@ -644,7 +644,7 @@ bool LLAppViewer::init() AIHTTPTimeoutPolicy policy_tmp( "CurlTimeout* Debug Settings", gSavedSettings.getU32("CurlTimeoutDNSLookup"), - /*gSavedSettings.getU32("CurlTimeoutConnect") Temporary HACK: 30 is the current max*/ 30, + gSavedSettings.getU32("CurlTimeoutConnect"), gSavedSettings.getU32("CurlTimeoutReplyDelay"), gSavedSettings.getU32("CurlTimeoutLowSpeedTime"), gSavedSettings.getU32("CurlTimeoutLowSpeedLimit"), From 4b0b83797c9b35e813176590a97c0ceab0b4fd41 Mon Sep 17 00:00:00 2001 From: Aleric Inglewood Date: Wed, 3 Jul 2013 23:54:07 +0200 Subject: [PATCH 5/5] CURLIO (and libcwd): add number of established connections to http console. I need to parse the debug output of libcurl for this, and choose to not do that for a Release build - at which point it makes little sense to even do it for a Debug build, since also the Alpha release are 'Release'. Even though it would probably have no impact on FPS, there would be like two persons looking at that number and understanding it. --- indra/llmessage/aicurl.cpp | 29 ++++++++++++++ indra/llmessage/aicurlperservice.cpp | 2 + indra/llmessage/aicurlperservice.h | 4 ++ indra/llmessage/aicurlprivate.h | 9 +++++ indra/llmessage/aicurlthread.cpp | 57 ++++++++++++++++++++++++++-- indra/newview/aihttpview.cpp | 6 +++ 6 files changed, 104 insertions(+), 3 deletions(-) diff --git a/indra/llmessage/aicurl.cpp b/indra/llmessage/aicurl.cpp index 6b8ac5064..04b9c5a16 100644 --- a/indra/llmessage/aicurl.cpp +++ b/indra/llmessage/aicurl.cpp @@ -977,6 +977,7 @@ void CurlEasyRequest::resetState(void) mTimeoutPolicy = NULL; mTimeout = NULL; mHandleEventsTarget = NULL; + mResult = CURLE_FAILED_INIT; applyDefaultOptions(); } @@ -1322,6 +1323,34 @@ void BufferedCurlEasyRequest::bad_socket(void) mResponder = NULL; } +#if defined(CWDEBUG) || defined(DEBUG_CURLIO) +static AIPerServicePtr sConnections[64]; + +void BufferedCurlEasyRequest::connection_established(int connectionnr) +{ + PerService_rat per_service_r(*mPerServicePtr); + int n = per_service_r->connection_established(); + llassert(sConnections[connectionnr] == NULL); // Only one service can use a connection at a time. + llassert_always(connectionnr < 64); + sConnections[connectionnr] = mPerServicePtr; + Dout(dc::curlio, (void*)get_lockobj() << " Connection established (#" << connectionnr << "). Now " << n << " connections [" << (void*)&*per_service_r << "]."); + llassert(sConnections[connectionnr] != NULL); +} + +void BufferedCurlEasyRequest::connection_closed(int connectionnr) +{ + if (sConnections[connectionnr] == NULL) + { + Dout(dc::curlio, "Closing connection that never connected (#" << connectionnr << ")."); + return; + } + PerService_rat per_service_r(*sConnections[connectionnr]); + int n = per_service_r->connection_closed(); + sConnections[connectionnr] = NULL; + Dout(dc::curlio, (void*)get_lockobj() << " Connection closed (#" << connectionnr << "); " << n << " connections remaining [" << (void*)&*per_service_r << "]."); +} +#endif + void BufferedCurlEasyRequest::resetState(void) { llassert(!mResponder); diff --git a/indra/llmessage/aicurlperservice.cpp b/indra/llmessage/aicurlperservice.cpp index c99264db8..8a58e2c98 100644 --- a/indra/llmessage/aicurlperservice.cpp +++ b/indra/llmessage/aicurlperservice.cpp @@ -75,6 +75,7 @@ AIPerService::AIPerService(void) : mConcurrentConnections(CurlConcurrentConnectionsPerService), mApprovedRequests(0), mTotalAdded(0), + mEstablishedConnections(0), mUsedCT(0), mCTInUse(0) { @@ -230,6 +231,7 @@ AIPerServicePtr AIPerService::instance(std::string const& servicename) if (iter == instance_map_w->end()) { iter = instance_map_w->insert(instance_map_type::value_type(servicename, new RefCountedThreadSafePerService)).first; + Dout(dc::curlio, "Created new service \"" << servicename << "\" [" << (void*)&*PerService_rat(*iter->second) << "]"); } // Note: the creation of AIPerServicePtr MUST be protected by the lock on sInstanceMap (see release()). return iter->second; diff --git a/indra/llmessage/aicurlperservice.h b/indra/llmessage/aicurlperservice.h index f81236997..188d383bf 100644 --- a/indra/llmessage/aicurlperservice.h +++ b/indra/llmessage/aicurlperservice.h @@ -169,6 +169,7 @@ class AIPerService { int mConcurrentConnections; // The maximum number of allowed concurrent connections to this service. int mApprovedRequests; // The number of approved requests for this service by approveHTTPRequestFor that were not added to the command queue yet. int mTotalAdded; // Number of active easy handles with this service. + int mEstablishedConnections; // Number of connected sockets to this service. U32 mUsedCT; // Bit mask with one bit per capability type. A '1' means the capability was in use since the last resetUsedCT(). U32 mCTInUse; // Bit mask with one bit per capability type. A '1' means the capability is in use right now. @@ -203,6 +204,9 @@ class AIPerService { } } public: + int connection_established(void) { mEstablishedConnections++; return mEstablishedConnections; } + int connection_closed(void) { mEstablishedConnections--; return mEstablishedConnections; } + static bool is_approved(AICapabilityType capability_type) { return (((U32)1 << capability_type) & approved_mask); } static U32 CT2mask(AICapabilityType capability_type) { return (U32)1 << capability_type; } void resetUsedCt(void) { mUsedCT = mCTInUse; } diff --git a/indra/llmessage/aicurlprivate.h b/indra/llmessage/aicurlprivate.h index af8b6b267..cbb9a293d 100644 --- a/indra/llmessage/aicurlprivate.h +++ b/indra/llmessage/aicurlprivate.h @@ -457,6 +457,9 @@ class BufferedCurlEasyRequest : public CurlEasyRequest { // So far the only such error I've seen is HTTP_BAD_REQUEST. bool upload_error_status(void) const { return mStatus == HTTP_BAD_REQUEST; } + // Returns true if the request was a success. + bool success(void) const { return mResult == CURLE_OK && mStatus >= 200 && mStatus < 400; } + // Return true when prepRequest was already called and the object has not been // invalidated as a result of calling timed_out(). bool isValid(void) const { return mResponder; } @@ -466,6 +469,12 @@ class BufferedCurlEasyRequest : public CurlEasyRequest { // Return true if any data was received. bool received_data(void) const { return mTotalRawBytes > 0; } + +#if defined(CWDEBUG) || defined(DEBUG_CURLIO) + // Connection accounting for debug purposes. + void connection_established(int connectionnr); + void connection_closed(int connectionnr); +#endif }; inline ThreadSafeBufferedCurlEasyRequest* CurlEasyRequest::get_lockobj(void) diff --git a/indra/llmessage/aicurlthread.cpp b/indra/llmessage/aicurlthread.cpp index f6f971516..64a6b69fe 100644 --- a/indra/llmessage/aicurlthread.cpp +++ b/indra/llmessage/aicurlthread.cpp @@ -1845,12 +1845,11 @@ CURLMcode MultiHandle::remove_easy_request(addedEasyRequests_type::iterator cons { AICurlEasyRequest_wat curl_easy_request_w(**iter); bool downloaded_something = curl_easy_request_w->received_data(); + bool success = curl_easy_request_w->success(); res = curl_easy_request_w->remove_handle_from_multi(curl_easy_request_w, mMultiHandle); capability_type = curl_easy_request_w->capability_type(); per_service = curl_easy_request_w->getPerServicePtr(); - CURLcode code; - curl_easy_request_w->getResult(&code, NULL); - PerService_wat(*per_service)->removed_from_multi_handle(capability_type, downloaded_something, code == CURLE_OK); // (About to be) removed from mAddedEasyRequests. + PerService_wat(*per_service)->removed_from_multi_handle(capability_type, downloaded_something, success); // (About to be) removed from mAddedEasyRequests. #ifdef SHOW_ASSERT curl_easy_request_w->mRemovedPerCommand = as_per_command; #endif @@ -2356,6 +2355,58 @@ int debug_callback(CURL* handle, curl_infotype infotype, char* buf, size_t size, { request->mDebugIsHeadOrGetMethod = true; } + if (infotype == CURLINFO_TEXT) + { + if (!strncmp(buf, "STATE: WAITCONNECT => ", 22)) + { + if (buf[22] == 'P' || buf[22] == 'D') // PROTOCONNECT or DO. + { + int n = size - 1; + while (buf[n] != ')') + { + llassert(n > 56); + --n; + } + int connectionnr = 0; + int factor = 1; + do + { + llassert(n > 56); + --n; + connectionnr += factor * (buf[n] - '0'); + factor *= 10; + } + while(buf[n - 1] != '#'); + // A new connection was established. + request->connection_established(connectionnr); + } + else + { + llassert(buf[22] == 'C'); // COMPLETED (connection failure). + } + } + else if (!strncmp(buf, "Closing connection", 18)) + { + int n = size - 1; + while (!std::isdigit(buf[n])) + { + llassert(n > 20); + --n; + } + int connectionnr = 0; + int factor = 1; + do + { + llassert(n > 19); + connectionnr += factor * (buf[n] - '0'); + factor *= 10; + --n; + } + while(buf[n] != '#'); + // A connection was closed. + request->connection_closed(connectionnr); + } + } #ifdef DEBUG_CURLIO if (!debug_curl_print_debug(handle)) diff --git a/indra/newview/aihttpview.cpp b/indra/newview/aihttpview.cpp index 60e9fc4e6..58bc2f689 100644 --- a/indra/newview/aihttpview.cpp +++ b/indra/newview/aihttpview.cpp @@ -80,6 +80,7 @@ void AIServiceBar::draw() U32 is_used; U32 is_inuse; int total_added; + int established_connections; int concurrent_connections; size_t bandwidth; { @@ -87,6 +88,7 @@ void AIServiceBar::draw() is_used = per_service_r->is_used(); is_inuse = per_service_r->is_inuse(); total_added = per_service_r->mTotalAdded; + established_connections = per_service_r->mEstablishedConnections; concurrent_connections = per_service_r->mConcurrentConnections; bandwidth = per_service_r->bandwidth().truncateData(AIHTTPView::getTime_40ms()); cts = per_service_r->mCapabilityType; // Not thread-safe, but we're only reading from it and only using the results to show in a debug console. @@ -145,7 +147,11 @@ void AIServiceBar::draw() start += LLFontGL::getFontMonospace()->getWidth(text); } start = mHTTPView->updateColumn(mc_col, start); +#if defined(CWDEBUG) || defined(DEBUG_CURLIO) + text = llformat(" | %d,%d/%d", total_added, established_connections, concurrent_connections); +#else text = llformat(" | %d/%d", total_added, concurrent_connections); +#endif LLFontGL::getFontMonospace()->renderUTF8(text, 0, start, height, text_color, LLFontGL::LEFT, LLFontGL::TOP); start += LLFontGL::getFontMonospace()->getWidth(text); start = mHTTPView->updateColumn(bw_col, start);