From d666a3d92cb5dd9844c29e5472db542de7b5ac9e Mon Sep 17 00:00:00 2001 From: Monty Brandenberg Date: Thu, 18 Nov 2010 08:43:09 -0800 Subject: ESC-154 ESC-155 ESC-156 Asset fetch requests wrapped to allow for measurements. Asset fetch enqueues, dequeues and completion times recorded to asset stats collector. Texture fetch operations (http and udp) recorded to asset stats collector. Stats collector time vallue switched from F32 to U64 which is the more common type in the viewer. Cross-thread mechanism introduced to communicate region changes and generate global statistics messages. Facility to deliver metrics via Capabilities sketched in but needs additional work. Documentation and diagrams added. --- indra/newview/llagent.cpp | 3 + indra/newview/llappviewer.cpp | 114 ++++++ indra/newview/llappviewer.h | 4 + indra/newview/lltexturefetch.cpp | 488 +++++++++++++++++++++++- indra/newview/lltexturefetch.h | 33 +- indra/newview/llviewerassetstats.cpp | 87 ++++- indra/newview/llviewerassetstats.h | 48 ++- indra/newview/llviewerassetstorage.cpp | 124 ++++++ indra/newview/llviewerassetstorage.h | 11 + indra/newview/llviewerregion.cpp | 1 + indra/newview/tests/llviewerassetstats_test.cpp | 2 +- 11 files changed, 893 insertions(+), 22 deletions(-) (limited to 'indra') diff --git a/indra/newview/llagent.cpp b/indra/newview/llagent.cpp index c9bd7851ed..e2b1c89402 100644 --- a/indra/newview/llagent.cpp +++ b/indra/newview/llagent.cpp @@ -637,6 +637,9 @@ void LLAgent::setRegion(LLViewerRegion *regionp) // Update all of the regions. LLWorld::getInstance()->updateAgentOffset(mAgentOriginGlobal); } + + // Pass new region along to metrics components that care about this level of detail. + LLAppViewer::metricsUpdateRegion(regionp->getRegionID()); } mRegionp = regionp; diff --git a/indra/newview/llappviewer.cpp b/indra/newview/llappviewer.cpp index 333c92e50d..2e056238e4 100644 --- a/indra/newview/llappviewer.cpp +++ b/indra/newview/llappviewer.cpp @@ -190,6 +190,7 @@ #include "llparcel.h" #include "llavatariconctrl.h" #include "llgroupiconctrl.h" +#include "llviewerassetstats.h" // Include for security api initialization #include "llsecapi.h" @@ -332,6 +333,14 @@ static std::string gWindowTitle; LLAppViewer::LLUpdaterInfo *LLAppViewer::sUpdaterInfo = NULL ; +//---------------------------------------------------------------------------- +// Metrics logging control constants +//---------------------------------------------------------------------------- +static const F32 METRICS_INTERVAL_MIN = 300.0; +static const F32 METRICS_INTERVAL_MAX = 3600.0; +static const F32 METRICS_INTERVAL_DEFAULT = 600.0; + + void idle_afk_check() { // check idle timers @@ -656,6 +665,8 @@ bool LLAppViewer::init() LLCurl::initClass(); LLMachineID::init(); + LLViewerAssetStatsFF::init(); + initThreads(); writeSystemInfo(); @@ -1670,6 +1681,8 @@ bool LLAppViewer::cleanup() LLWatchdog::getInstance()->cleanup(); + LLViewerAssetStatsFF::cleanup(); + llinfos << "Shutting down message system" << llendflush; end_messaging_system(); @@ -3683,6 +3696,18 @@ void LLAppViewer::idle() gInventory.idleNotifyObservers(); } + // Metrics logging (LLViewerAssetStats, etc.) + { + static LLTimer report_interval; + + // *TODO: Add configuration controls for this + if (report_interval.getElapsedTimeF32() >= METRICS_INTERVAL_DEFAULT) + { + metricsIdle(! gDisconnected); + report_interval.reset(); + } + } + if (gDisconnected) { return; @@ -4525,3 +4550,92 @@ bool LLAppViewer::getMasterSystemAudioMute() { return gSavedSettings.getBOOL("MuteAudio"); } + +//---------------------------------------------------------------------------- +// Metrics-related methods (static and otherwise) +//---------------------------------------------------------------------------- + +/** + * LLViewerAssetStats collects data on a per-region (as defined by the agent's + * location) so we need to tell it about region changes which become a kind of + * hidden variable/global state in the collectors. For collectors not running + * on the main thread, we need to send a message to move the data over safely + * and cheaply (amortized over a run). + */ +void LLAppViewer::metricsUpdateRegion(const LLUUID & region_id) +{ + if (! region_id.isNull()) + { + LLViewerAssetStatsFF::set_region_main(region_id); + if (LLAppViewer::sTextureFetch) + { + // Send a region update message into 'thread1' to get the new region. + LLAppViewer::sTextureFetch->commandSetRegion(region_id); + } + else + { + // No 'thread1', a.k.a. TextureFetch, so update directly + LLViewerAssetStatsFF::set_region_thread1(region_id); + } + } +} + + +/** + * Attempts to start a multi-threaded metrics report to be sent back to + * the grid for consumption. + */ +void LLAppViewer::metricsIdle(bool enable_reporting) +{ + if (! gViewerAssetStatsMain) + return; + + std::string caps_url; + LLViewerRegion * regionp = gAgent.getRegion(); + if (regionp) + { + caps_url = regionp->getCapability("ViewerMetrics"); + caps_url = "http://localhost:80/putz/"; + } + + if (enable_reporting && regionp && ! caps_url.empty()) + { + // *NOTE: Pay attention here. LLSD's are not safe for thread sharing + // and their ownership is difficult to transfer across threads. We do + // it here by having only one reference (the new'd pointer) to the LLSD + // or any subtree of it. This pointer is then transfered to the other + // thread using correct thread logic. + + LLSD * envelope = new LLSD(LLSD::emptyMap()); + { + (*envelope)["session_id"] = gAgentSessionID; + (*envelope)["agent_id"] = gAgentID; + (*envelope)["regions"] = gViewerAssetStatsMain->asLLSD(); + } + + if (LLAppViewer::sTextureFetch) + { + // Send a report request into 'thread1' to get the rest of the data + // and have it sent to the stats collector. LLSD ownership transfers + // with this call. + LLAppViewer::sTextureFetch->commandSendMetrics(caps_url, envelope); + envelope = 0; // transfer noted + } + else + { + // No 'thread1' so transfer doesn't happen and we need to clean up + delete envelope; + envelope = 0; + } + } + else + { + LLAppViewer::sTextureFetch->commandDataBreak(); + } + + // Reset even if we can't report. Rather than gather up a huge chunk of + // data, we'll keep to our sampling interval and retain the data + // resolution in time. + gViewerAssetStatsMain->reset(); +} + diff --git a/indra/newview/llappviewer.h b/indra/newview/llappviewer.h index 56d88f07c8..909f191ab1 100644 --- a/indra/newview/llappviewer.h +++ b/indra/newview/llappviewer.h @@ -167,6 +167,10 @@ public: // mute/unmute the system's master audio virtual void setMasterSystemAudioMute(bool mute); virtual bool getMasterSystemAudioMute(); + + // Metrics policy helper statics. + static void metricsUpdateRegion(const LLUUID & region_id); + static void metricsIdle(bool enable_reporting); protected: virtual bool initWindow(); // Initialize the viewer's window. diff --git a/indra/newview/lltexturefetch.cpp b/indra/newview/lltexturefetch.cpp index fafef84aa2..df99818ee9 100644 --- a/indra/newview/lltexturefetch.cpp +++ b/indra/newview/lltexturefetch.cpp @@ -49,6 +49,7 @@ #include "llviewertexture.h" #include "llviewerregion.h" #include "llviewerstats.h" +#include "llviewerassetstats.h" #include "llworld.h" ////////////////////////////////////////////////////////////////////////////// @@ -143,7 +144,7 @@ public: /*virtual*/ bool deleteOK(); // called from update() (WORK THREAD) ~LLTextureFetchWorker(); - void relese() { --mActiveCount; } + // void relese() { --mActiveCount; } S32 callbackHttpGet(const LLChannelDescriptors& channels, const LLIOPipe::buffer_ptr_t& buffer, @@ -161,9 +162,11 @@ public: mGetReason = reason; } - void setCanUseHTTP(bool can_use_http) {mCanUseHTTP = can_use_http;} - bool getCanUseHTTP()const {return mCanUseHTTP ;} + void setCanUseHTTP(bool can_use_http) { mCanUseHTTP = can_use_http; } + bool getCanUseHTTP() const { return mCanUseHTTP; } + LLTextureFetch & getFetcher() { return *mFetcher; } + protected: LLTextureFetchWorker(LLTextureFetch* fetcher, const std::string& url, const LLUUID& id, const LLHost& host, F32 priority, S32 discard, S32 size); @@ -277,6 +280,8 @@ private: S32 mLastPacket; U16 mTotalPackets; U8 mImageCodec; + + LLViewerAssetStats::duration_t mMetricsStartTime; }; ////////////////////////////////////////////////////////////////////////////// @@ -333,6 +338,18 @@ public: S32 data_size = worker->callbackHttpGet(channels, buffer, partial, success); mFetcher->removeFromHTTPQueue(mID, data_size); + + if (worker->mMetricsStartTime) + { + LLViewerAssetStatsFF::record_response_thread1(LLViewerAssetType::AT_TEXTURE, + true, + LLImageBase::TYPE_AVATAR_BAKE == worker->mType, + LLViewerAssetStatsFF::get_timestamp() - worker->mMetricsStartTime); + worker->mMetricsStartTime = 0; + } + LLViewerAssetStatsFF::record_dequeue_thread1(LLViewerAssetType::AT_TEXTURE, + true, + LLImageBase::TYPE_AVATAR_BAKE == worker->mType); } else { @@ -355,6 +372,201 @@ private: bool mFollowRedir; }; +////////////////////////////////////////////////////////////////////////////// + +// Cross-thread messaging for asset metrics. + +namespace +{ + +/** + * @brief Base class for cross-thread requests made of the fetcher + * + * I believe the intent of the LLQueuedThread class was to + * have these operations derived from LLQueuedThread::QueuedRequest + * but the texture fetcher has elected to manage the queue + * in its own manner. So these are free-standing objects which are + * managed in simple FIFO order on the mCommands queue of the + * LLTextureFetch object. + * + * What each represents is a simple command sent from an + * outside thread into the TextureFetch thread to be processed + * in order and in a timely fashion (though not an absolute + * higher priority than other operations of the thread). + * Each operation derives a new class from the base customizing + * members, constructors and the doWork() method to effect + * the command. + * + * The flow is one-directional. There are two global instances + * of the LLViewerAssetStats collector, one for the main program's + * thread pointed to by gViewerAssetStatsMain and one for the + * TextureFetch thread pointed to by gViewerAssetStatsThread1. + * Common operations has each thread recording metrics events + * into the respective collector unconcerned with locking and + * the state of any other thread. But when the agent moves into + * a different region or the metrics timer expires and a report + * needs to be sent back to the grid, messaging across grids + * is required to distribute data and perform global actions. + * In pseudo-UML, it looks like: + * + * Main Thread1 + * . . + * . . + * +-----+ . + * | AM | . + * +--+--+ . + * +-------+ | . + * | Main | +--+--+ . + * | | | SRE |---. . + * | Stats | +-----+ \ . + * | | | \ (uuid) +-----+ + * | Coll. | +--+--+ `-------->| SR | + * +-------+ | MSC | +--+--+ + * | ^ +-----+ | + * | | (uuid) / . +-----+ (uuid) + * | `--------' . | MSC |---------. + * | . +-----+ | + * | +-----+ . v + * | | TE | . +-------+ + * | +--+--+ . | Thd1 | + * | | . | | + * | (llsd) +-----+ . | Stats | + * `--------->| RSC | . | | + * +--+--+ . | Coll. | + * | . +-------+ + * +--+--+ . | + * | SME |---. . | + * +-----+ \ . | + * . \ (llsd) +-----+ | + * . `-------->| SM | | + * . +--+--+ | + * . | | + * . +-----+ (llsd) | + * . | RSC |<--------' + * . +-----+ + * . | + * . +-----+ + * . | CP |--> HTTP PUT + * . +-----+ + * . . + * . . + * + * + * Key: + * + * SRE - Set Region Enqueued. Enqueue a 'Set Region' command in + * the other thread providing the new UUID of the region. + * TFReqSetRegion carries the data. + * SR - Set Region. New region UUID is sent to the thread-local + * collector. + * SME - Send Metrics Enqueued. Enqueue a 'Send Metrics' command + * including an ownership transfer of an LLSD. + * TFReqSendMetrics carries the data. + * SM - Send Metrics. Global metrics reporting operation. Takes + * the remote LLSD from the command, merges it with and LLSD + * from the local collector and sends it to the grid. + * AM - Agent Moved. Agent has completed some sort of move to a + * new region. + * TE - Timer Expired. Metrics timer has expired (on the order + * of 10 minutes). + * CP - CURL Put + * MSC - Modify Stats Collector. State change in the thread-local + * collector. Typically a region change which affects the + * global pointers used to find the 'current stats'. + * RSC - Read Stats Collector. Extract collector data in LLSD form. + * + */ +class TFRequest // : public LLQueuedThread::QueuedRequest +{ +public: + // Default ctors and assignment operator are correct. + + virtual ~TFRequest() + {} + + virtual bool doWork(LLTextureFetchWorker * worker) = 0; +}; + + +/** + * @brief Implements a 'Set Region' cross-thread command. + * + * When an agent moves to a new region, subsequent metrics need + * to be binned into a new or existing stats collection in 1:1 + * relationship with the region. We communicate this region + * change across the threads involved in the communication with + * this message. + * + * Corresponds to LLTextureFetch::commandSetRegion() + */ +class TFReqSetRegion : public TFRequest +{ +public: + TFReqSetRegion(const LLUUID & region_id) + : TFRequest(), + mRegionID(region_id) + {} + TFReqSetRegion & operator=(const TFReqSetRegion &); // Not defined + + virtual ~TFReqSetRegion() + {} + + virtual bool doWork(LLTextureFetchWorker * worker); + +public: + const LLUUID mRegionID; +}; + + +/** + * @brief Implements a 'Send Metrics' cross-thread command. + * + * This is the big operation. The main thread gathers metrics + * for a period of minutes into LLViewerAssetStats and other + * objects then builds an LLSD to represent the data. It uses + * this command to transfer the LLSD, content *and* ownership, + * to the TextureFetch thread which adds its own metrics and + * kicks of an HTTP POST of the resulting data to the currently + * active metrics collector. + * + * Corresponds to LLTextureFetch::commandSendMetrics() + */ +class TFReqSendMetrics : public TFRequest +{ +public: + /** + * Construct the 'Send Metrics' command to have the TextureFetch + * thread add and log metrics data. + * + * @param caps_url URL of a "ViewerMetrics" Caps target + * to receive the data. Does not have to + * be associated with a particular region. + * + * @param report_main Pointer to LLSD containing main + * thread metrics. Ownership transfers + * to the new thread using very carefully + * constructed code. + */ + TFReqSendMetrics(const std::string & caps_url, + LLSD * report_main) + : TFRequest(), + mCapsURL(caps_url), + mReportMain(report_main) + {} + TFReqSendMetrics & operator=(const TFReqSendMetrics &); // Not defined + + virtual ~TFReqSendMetrics(); + + virtual bool doWork(LLTextureFetchWorker * worker); + +public: + const std::string mCapsURL; + LLSD * mReportMain; +}; + +} // end of anonymous namespace + + ////////////////////////////////////////////////////////////////////////////// //static @@ -374,6 +586,9 @@ const char* LLTextureFetchWorker::sStateDescs[] = { "DONE", }; +// static +volatile bool LLTextureFetch::svMetricsDataBreak(true); // Start with a data break + // called from MAIN THREAD LLTextureFetchWorker::LLTextureFetchWorker(LLTextureFetch* fetcher, @@ -423,7 +638,8 @@ LLTextureFetchWorker::LLTextureFetchWorker(LLTextureFetch* fetcher, mFirstPacket(0), mLastPacket(-1), mTotalPackets(0), - mImageCodec(IMG_CODEC_INVALID) + mImageCodec(IMG_CODEC_INVALID), + mMetricsStartTime(0) { mCanUseNET = mUrl.empty() ; @@ -591,6 +807,10 @@ bool LLTextureFetchWorker::doWork(S32 param) return true; // abort } } + + // Run a cross-thread command, if any. + mFetcher->cmdDoWork(this); + if(mImagePriority < F_ALMOST_ZERO) { if (mState == INIT || mState == LOAD_FROM_NETWORK || mState == LOAD_FROM_SIMULATOR) @@ -800,7 +1020,15 @@ bool LLTextureFetchWorker::doWork(S32 param) mRequestedDiscard = mDesiredDiscard; mSentRequest = QUEUED; mFetcher->addToNetworkQueue(this); + if (! mMetricsStartTime) + { + mMetricsStartTime = LLViewerAssetStatsFF::get_timestamp(); + } + LLViewerAssetStatsFF::record_enqueue_thread1(LLViewerAssetType::AT_TEXTURE, + false, + LLImageBase::TYPE_AVATAR_BAKE == mType); setPriority(LLWorkerThread::PRIORITY_LOW | mWorkPriority); + return false; } else @@ -809,6 +1037,12 @@ bool LLTextureFetchWorker::doWork(S32 param) //llassert_always(mFetcher->mNetworkQueue.find(mID) != mFetcher->mNetworkQueue.end()); // Make certain this is in the network queue //mFetcher->addToNetworkQueue(this); + //if (! mMetricsStartTime) + //{ + // mMetricsStartTime = LLViewerAssetStatsFF::get_timestamp(); + //} + //LLViewerAssetStatsFF::record_enqueue_thread1(LLViewerAssetType::AT_TEXTURE, false, + // LLImageBase::TYPE_AVATAR_BAKE == mType); //setPriority(LLWorkerThread::PRIORITY_LOW | mWorkPriority); return false; } @@ -832,11 +1066,30 @@ bool LLTextureFetchWorker::doWork(S32 param) } setPriority(LLWorkerThread::PRIORITY_HIGH | mWorkPriority); mState = DECODE_IMAGE; - mWriteToCacheState = SHOULD_WRITE ; + mWriteToCacheState = SHOULD_WRITE; + + if (mMetricsStartTime) + { + LLViewerAssetStatsFF::record_response_thread1(LLViewerAssetType::AT_TEXTURE, + false, + LLImageBase::TYPE_AVATAR_BAKE == mType, + LLViewerAssetStatsFF::get_timestamp() - mMetricsStartTime); + mMetricsStartTime = 0; + } + LLViewerAssetStatsFF::record_dequeue_thread1(LLViewerAssetType::AT_TEXTURE, + false, + LLImageBase::TYPE_AVATAR_BAKE == mType); } else { mFetcher->addToNetworkQueue(this); // failsafe + if (! mMetricsStartTime) + { + mMetricsStartTime = LLViewerAssetStatsFF::get_timestamp(); + } + LLViewerAssetStatsFF::record_enqueue_thread1(LLViewerAssetType::AT_TEXTURE, + false, + LLImageBase::TYPE_AVATAR_BAKE == mType); setPriority(LLWorkerThread::PRIORITY_LOW | mWorkPriority); } return false; @@ -898,6 +1151,14 @@ bool LLTextureFetchWorker::doWork(S32 param) mState = WAIT_HTTP_REQ; mFetcher->addToHTTPQueue(mID); + if (! mMetricsStartTime) + { + mMetricsStartTime = LLViewerAssetStatsFF::get_timestamp(); + } + LLViewerAssetStatsFF::record_enqueue_thread1(LLViewerAssetType::AT_TEXTURE, + true, + LLImageBase::TYPE_AVATAR_BAKE == mType); + // Will call callbackHttpGet when curl request completes std::vector headers; headers.push_back("Accept: image/x-j2c"); @@ -1534,6 +1795,12 @@ LLTextureFetch::~LLTextureFetch() { clearDeleteList() ; + while (! mCommands.empty()) + { + delete mCommands.front(); + mCommands.erase(mCommands.begin()); + } + // ~LLQueuedThread() called here } @@ -1815,6 +2082,25 @@ bool LLTextureFetch::updateRequestPriority(const LLUUID& id, F32 priority) return res; } +// virtual +bool LLTextureFetch::runCondition() +{ + // Caller is holding the lock on LLThread's condition variable. + + // LLQueuedThread, unlike its base class LLThread, makes this a + // private method which is unfortunate. I want to use it directly + // but I'm going to have to re-implement the logic here (or change + // declarations, which I don't want to do right now). + + bool have_no_commands(false); + { + LLMutexLock lock(&mQueueMutex); + + have_no_commands = mCommands.empty(); + } + return ! (have_no_commands && mRequestQueue.empty() && mIdleThread); +} + ////////////////////////////////////////////////////////////////////////////// // MAIN THREAD @@ -2357,3 +2643,195 @@ void LLTextureFetch::dump() } } +////////////////////////////////////////////////////////////////////////////// + +// cross-thread command methods + +void LLTextureFetch::commandSetRegion(const LLUUID & region_id) +{ + TFReqSetRegion * req = new TFReqSetRegion(region_id); + + cmdEnqueue(req); +} + +void LLTextureFetch::commandSendMetrics(const std::string & caps_url, + LLSD * report_main) +{ + TFReqSendMetrics * req = new TFReqSendMetrics(caps_url, report_main); + + cmdEnqueue(req); +} + +void LLTextureFetch::commandDataBreak() +{ + // The pedantically correct way to implement this is to create a command + // request object in the above fashion and enqueue it. However, this is + // simple data of an advisorial not operational nature and this case + // of shared-write access is tolerable. + + LLTextureFetch::svMetricsDataBreak = true; +} + +void LLTextureFetch::cmdEnqueue(TFRequest * req) +{ + lockQueue(); + mCommands.push_back(req); + wake(); + unlockQueue(); +} + +TFRequest * LLTextureFetch::cmdDequeue() +{ + TFRequest * ret = 0; + + lockQueue(); + if (! mCommands.empty()) + { + ret = mCommands.front(); + mCommands.erase(mCommands.begin()); + } + unlockQueue(); + + return ret; +} + +void LLTextureFetch::cmdDoWork(LLTextureFetchWorker * worker) +{ + // Queue is expected to be locked here. + + if (mDebugPause) + { + return; // debug: don't do any work + } + + TFRequest * req = cmdDequeue(); + if (req) + { + // One request per pass should really be enough for this. + req->doWork(worker); + delete req; + } +} + + +////////////////////////////////////////////////////////////////////////////// + +// Private (anonymous) class methods implementing the command scheme. + +namespace +{ + +/** + * Implements the 'Set Region' command. + * + * Thread: Thread1 (TextureFetch) + */ +bool +TFReqSetRegion::doWork(LLTextureFetchWorker *) +{ + LLViewerAssetStatsFF::set_region_thread1(mRegionID); + + return true; +} + + +TFReqSendMetrics::~TFReqSendMetrics() +{ + delete mReportMain; + mReportMain = 0; +} + + +/** + * Implements the 'Send Metrics' command. Takes over + * ownership of the passed LLSD pointer. + * + * Thread: Thread1 (TextureFetch) + */ +bool +TFReqSendMetrics::doWork(LLTextureFetchWorker * fetch_worker) +{ + /* + * HTTP POST responder. Doesn't do much but tries to + * detect simple breaks in recording the metrics stream. + * + * The 'volatile' modifiers don't indicate signals, + * mmap'd memory or threads, really. They indicate that + * the referenced data is part of a pseudo-closure for + * this responder rather than being required for correct + * operation. + */ + class lcl_responder : public LLCurl::Responder + { + public: + lcl_responder(volatile bool & post_failed, + volatile bool & post_succeeded) + : LLHTTPClient::Responder(), + mPostFailedStatus(post_failed), + mPostSucceededStatus(post_succeeded) + {} + + // virtual + void error(U32 status_num, const std::string & reason) + { + mPostFailedStatus = true; + } + + // virtual + void result(const LLSD & content) + { + mPostSucceededStatus = true; + } + + private: + volatile bool & mPostFailedStatus; + volatile bool & mPostSucceededStatus; + }; + + if (! gViewerAssetStatsThread1) + return true; + + if (! mCapsURL.empty()) + { + static volatile bool not_initial_report(false); + static S32 report_sequence(0); + + // We've already taken over ownership of the LLSD at this point + // and can do normal LLSD sharing operations at this point. But + // still being careful, regardless. + LLSD & envelope = *mReportMain; + { + envelope["sequence"] = report_sequence; + envelope["regions_alt"] = gViewerAssetStatsThread1->asLLSD(); + envelope["initial"] = ! not_initial_report; // Initial data from viewer + envelope["break"] = LLTextureFetch::svMetricsDataBreak; // Break in data prior to this report + + // *FIXME: Need to merge the two metrics streams here.... + } + + // Update sequence number and other metadata for next attempt. + if (S32_MAX == ++report_sequence) + report_sequence = 0; + LLTextureFetch::svMetricsDataBreak = false; + + LLCurlRequest::headers_t headers; + fetch_worker->getFetcher().getCurlRequest().post(mCapsURL, + headers, + envelope, + new lcl_responder(LLTextureFetch::svMetricsDataBreak, + not_initial_report)); + } + else + { + LLTextureFetch::svMetricsDataBreak = true; + } + + gViewerAssetStatsThread1->reset(); + + return true; +} + +} // end of anonymous namespace + + + diff --git a/indra/newview/lltexturefetch.h b/indra/newview/lltexturefetch.h index 796109df06..220305d881 100644 --- a/indra/newview/lltexturefetch.h +++ b/indra/newview/lltexturefetch.h @@ -40,6 +40,7 @@ class HTTPGetResponder; class LLTextureCache; class LLImageDecodeThread; class LLHost; +namespace { class TFRequest; } // Interface class class LLTextureFetch : public LLWorkerThread @@ -83,6 +84,13 @@ public: LLTextureFetchWorker* getWorkerAfterLock(const LLUUID& id); LLTextureInfo* getTextureInfo() { return &mTextureInfo; } + + // Commands available to other threads. + void commandSetRegion(const LLUUID & region_id); + void commandSendMetrics(const std::string & caps_url, LLSD * report_main); + void commandDataBreak(); + + LLCurlRequest & getCurlRequest() { return *mCurlGetRequest; } protected: void addToNetworkQueue(LLTextureFetchWorker* worker); @@ -91,7 +99,10 @@ protected: void removeFromHTTPQueue(const LLUUID& id, S32 received_size = 0); void removeRequest(LLTextureFetchWorker* worker, bool cancel); // Called from worker thread (during doWork) - void processCurlRequests(); + void processCurlRequests(); + + // Overrides from the LLThread tree + bool runCondition(); private: void sendRequestListToSimulators(); @@ -99,6 +110,11 @@ private: /*virtual*/ void endThread(void); /*virtual*/ void threadedUpdate(void); + // command helpers + void cmdEnqueue(TFRequest *); + TFRequest * cmdDequeue(); + void cmdDoWork(LLTextureFetchWorker* worker); + public: LLUUID mDebugID; S32 mDebugCount; @@ -107,7 +123,7 @@ public: S32 mBadPacketCount; private: - LLMutex mQueueMutex; //to protect mRequestMap only + LLMutex mQueueMutex; //to protect mRequestMap and mCommands only LLMutex mNetworkQueueMutex; //to protect mNetworkQueue, mHTTPTextureQueue and mCancelQueue. LLTextureCache* mTextureCache; @@ -129,6 +145,19 @@ private: LLTextureInfo mTextureInfo; U32 mHTTPTextureBits; + + // Special cross-thread command queue. This command queue + // is logically tied to LLQueuedThread's list of + // QueuedRequest instances and so must be covered by the + // same locks. + typedef std::vector command_queue_t; + command_queue_t mCommands; + +public: + // A probabilistically-correct indicator that the current + // attempt to log metrics follows a break in the metrics stream + // reporting due to either startup or a problem POSTing data. + static volatile bool svMetricsDataBreak; }; #endif // LL_LLTEXTUREFETCH_H diff --git a/indra/newview/llviewerassetstats.cpp b/indra/newview/llviewerassetstats.cpp index 37e7c43f36..09c0364f09 100644 --- a/indra/newview/llviewerassetstats.cpp +++ b/indra/newview/llviewerassetstats.cpp @@ -37,6 +37,35 @@ #include "stdtypes.h" /* + * Classes and utility functions for per-thread and per-region + * asset and experiential metrics to be aggregated grid-wide. + * + * The basic metrics grouping is LLViewerAssetStats::PerRegionStats. + * This provides various counters and simple statistics for asset + * fetches binned into a few categories. One of these is maintained + * for each region encountered and the 'current' region is available + * as a simple reference. Each thread (presently two) interested + * in participating in these stats gets an instance of the + * LLViewerAssetStats class so that threads are completely + * independent. + * + * The idea of a current region is used for simplicity and speed + * of categorization. Each metrics event could have taken a + * region uuid argument resulting in a suitable lookup. Arguments + * against this design include: + * + * - Region uuid not trivially available to caller. + * - Cost (cpu, disruption in real work flow) too high. + * - Additional precision not really meaningful. + * + * By itself, the LLViewerAssetStats class is thread- and + * viewer-agnostic and can be used anywhere without assumptions + * of global pointers and other context. For the viewer, + * a set of free functions are provided in the namespace + * LLViewerAssetStatsFF which *do* implement viewer-native + * policies about per-thread globals and will do correct + * defensive tests of same. + * * References * * Project: @@ -103,7 +132,7 @@ LLViewerAssetStats::reset() mRegionStats.clear(); // If we have a current stats, reset it, otherwise, as at construction, - // create a new one. + // create a new one as we must always have a current stats block. if (mCurRegionStats) { mCurRegionStats->reset(); @@ -130,7 +159,7 @@ LLViewerAssetStats::setRegionID(const LLUUID & region_id) PerRegionContainer::iterator new_stats = mRegionStats.find(region_id); if (mRegionStats.end() == new_stats) { - // Haven't seen this region_id before, create a new block make it current. + // Haven't seen this region_id before, create a new block and make it current. mCurRegionStats = new PerRegionStats(region_id); mRegionStats[region_id] = mCurRegionStats; } @@ -159,7 +188,7 @@ LLViewerAssetStats::recordGetDequeued(LLViewerAssetType::EType at, bool with_htt } void -LLViewerAssetStats::recordGetServiced(LLViewerAssetType::EType at, bool with_http, bool is_temp, F64 duration) +LLViewerAssetStats::recordGetServiced(LLViewerAssetType::EType at, bool with_http, bool is_temp, duration_t duration) { const EViewerAssetCategories eac(asset_type_to_category(at, with_http, is_temp)); @@ -213,9 +242,9 @@ LLViewerAssetStats::asLLSD() const slot[enq_tag] = LLSD(S32(stats.mRequests[i].mEnqueued.getCount())); slot[deq_tag] = LLSD(S32(stats.mRequests[i].mDequeued.getCount())); slot[rcnt_tag] = LLSD(S32(stats.mRequests[i].mResponse.getCount())); - slot[rmin_tag] = LLSD(stats.mRequests[i].mResponse.getMin()); - slot[rmax_tag] = LLSD(stats.mRequests[i].mResponse.getMax()); - slot[rmean_tag] = LLSD(stats.mRequests[i].mResponse.getMean()); + slot[rmin_tag] = LLSD(F64(stats.mRequests[i].mResponse.getMin())); + slot[rmax_tag] = LLSD(F64(stats.mRequests[i].mResponse.getMax())); + slot[rmean_tag] = LLSD(F64(stats.mRequests[i].mResponse.getMean())); } ret[it->first.asString()] = reg_stat; @@ -231,9 +260,24 @@ LLViewerAssetStats::asLLSD() const namespace LLViewerAssetStatsFF { +// // Target thread is elaborated in the function name. This could // have been something 'templatey' like specializations iterated // over a set of constants but with so few, this is clearer I think. +// +// As for the threads themselves... rather than do fine-grained +// locking as we gather statistics, this code creates a collector +// for each thread, allocated and run independently. Logging +// happens at relatively infrequent intervals and at that time +// the data is sent to a single thread to be aggregated into +// a single entity with locks, thread safety and other niceties. +// +// A particularly fussy implementation would distribute the +// per-thread pointers across separate cache lines. But that should +// be beyond current requirements. +// + +// 'main' thread - initial program thread void set_region_main(const LLUUID & region_id) @@ -263,7 +307,7 @@ record_dequeue_main(LLViewerAssetType::EType at, bool with_http, bool is_temp) } void -record_response_main(LLViewerAssetType::EType at, bool with_http, bool is_temp, F64 duration) +record_response_main(LLViewerAssetType::EType at, bool with_http, bool is_temp, LLViewerAssetStats::duration_t duration) { if (! gViewerAssetStatsMain) return; @@ -272,6 +316,8 @@ record_response_main(LLViewerAssetType::EType at, bool with_http, bool is_temp, } +// 'thread1' - should be for TextureFetch thread + void set_region_thread1(const LLUUID & region_id) { @@ -300,7 +346,7 @@ record_dequeue_thread1(LLViewerAssetType::EType at, bool with_http, bool is_temp } void -record_response_thread1(LLViewerAssetType::EType at, bool with_http, bool is_temp, F64 duration) +record_response_thread1(LLViewerAssetType::EType at, bool with_http, bool is_temp, LLViewerAssetStats::duration_t duration) { if (! gViewerAssetStatsThread1) return; @@ -308,6 +354,31 @@ record_response_thread1(LLViewerAssetType::EType at, bool with_http, bool is_tem gViewerAssetStatsThread1->recordGetServiced(at, with_http, is_temp, duration); } + +void +init() +{ + if (! gViewerAssetStatsMain) + { + gViewerAssetStatsMain = new LLViewerAssetStats; + } + if (! gViewerAssetStatsThread1) + { + gViewerAssetStatsThread1 = new LLViewerAssetStats; + } +} + +void +cleanup() +{ + delete gViewerAssetStatsMain; + gViewerAssetStatsMain = 0; + + delete gViewerAssetStatsThread1; + gViewerAssetStatsThread1 = 0; +} + + } // namespace LLViewerAssetStatsFF diff --git a/indra/newview/llviewerassetstats.h b/indra/newview/llviewerassetstats.h index b8356a5ff5..efd0897bb8 100644 --- a/indra/newview/llviewerassetstats.h +++ b/indra/newview/llviewerassetstats.h @@ -95,6 +95,13 @@ public: EVACCount // Must be last }; + /** + * Type for duration and other time values in the metrics. Selected + * for compatibility with the pre-existing timestamp on the texture + * fetcher class, LLTextureFetch. + */ + typedef U64 duration_t; + /** * Collected data for a single region visited by the avatar. */ @@ -107,6 +114,7 @@ public: { reset(); } + // Default assignment and destructor are correct. void reset(); @@ -114,9 +122,9 @@ public: LLUUID mRegionID; struct { - LLSimpleStatCounter mEnqueued; - LLSimpleStatCounter mDequeued; - LLSimpleStatMMM<> mResponse; + LLSimpleStatCounter mEnqueued; + LLSimpleStatCounter mDequeued; + LLSimpleStatMMM mResponse; } mRequests [EVACCount]; }; @@ -137,7 +145,7 @@ public: // Non-Cached GET Requests void recordGetEnqueued(LLViewerAssetType::EType at, bool with_http, bool is_temp); void recordGetDequeued(LLViewerAssetType::EType at, bool with_http, bool is_temp); - void recordGetServiced(LLViewerAssetType::EType at, bool with_http, bool is_temp, F64 duration); + void recordGetServiced(LLViewerAssetType::EType at, bool with_http, bool is_temp, duration_t duration); // Retrieve current metrics for all visited regions. const LLSD asLLSD() const; @@ -180,23 +188,51 @@ extern LLViewerAssetStats * gViewerAssetStatsThread1; namespace LLViewerAssetStatsFF { +/** + * We have many timers, clocks etc. in the runtime. This is the + * canonical timestamp for these metrics which is compatible with + * the pre-existing timestamping in the texture fetcher. + */ +inline LLViewerAssetStats::duration_t get_timestamp() +{ + return LLTimer::getTotalTime(); +} +/** + * Region context, event and duration loggers for the Main thread. + */ void set_region_main(const LLUUID & region_id); void record_enqueue_main(LLViewerAssetType::EType at, bool with_http, bool is_temp); void record_dequeue_main(LLViewerAssetType::EType at, bool with_http, bool is_temp); -void record_response_main(LLViewerAssetType::EType at, bool with_http, bool is_temp, F64 duration); +void record_response_main(LLViewerAssetType::EType at, bool with_http, bool is_temp, + LLViewerAssetStats::duration_t duration); +/** + * Region context, event and duration loggers for Thread 1. + */ void set_region_thread1(const LLUUID & region_id); void record_enqueue_thread1(LLViewerAssetType::EType at, bool with_http, bool is_temp); void record_dequeue_thread1(LLViewerAssetType::EType at, bool with_http, bool is_temp); -void record_response_thread1(LLViewerAssetType::EType at, bool with_http, bool is_temp, F64 duration); +void record_response_thread1(LLViewerAssetType::EType at, bool with_http, bool is_temp, + LLViewerAssetStats::duration_t duration); + +/** + * @brief Allocation and deallocation of globals. + * + * init() should be called before threads are started that will access it though + * you'll likely get away with calling it afterwards. cleanup() should only be + * called after threads are shutdown to prevent races on the global pointers. + */ +void init(); + +void cleanup(); } // namespace LLViewerAssetStatsFF diff --git a/indra/newview/llviewerassetstorage.cpp b/indra/newview/llviewerassetstorage.cpp index 2e7ef0fec3..197cb3468c 100644 --- a/indra/newview/llviewerassetstorage.cpp +++ b/indra/newview/llviewerassetstorage.cpp @@ -33,6 +33,61 @@ #include "message.h" #include "llagent.h" +#include "lltransfersourceasset.h" +#include "lltransfertargetvfile.h" +#include "llviewerassetstats.h" + +///---------------------------------------------------------------------------- +/// LLViewerAssetRequest +///---------------------------------------------------------------------------- + +/** + * @brief Local class to encapsulate asset fetch requests with a timestamp. + * + * Derived from the common LLAssetRequest class, this is currently used + * only for fetch/get operations and its only function is to wrap remote + * asset fetch requests so that they can be timed. + */ +class LLViewerAssetRequest : public LLAssetRequest +{ +public: + LLViewerAssetRequest(const LLUUID &uuid, const LLAssetType::EType type) + : LLAssetRequest(uuid, type), + mMetricsStartTime(0) + { + } + + LLViewerAssetRequest & operator=(const LLViewerAssetRequest &); // Not defined + // Default assignment operator valid + + // virtual + ~LLViewerAssetRequest() + { + recordMetrics(); + } + +protected: + void recordMetrics() + { + if (mMetricsStartTime) + { + // Okay, it appears this request was used for useful things. Record + // the expected dequeue and duration of request processing. + LLViewerAssetStatsFF::record_dequeue_main(mType, false, false); + LLViewerAssetStatsFF::record_response_main(mType, false, false, + (LLViewerAssetStatsFF::get_timestamp() + - mMetricsStartTime)); + mMetricsStartTime = 0; + } + } + +public: + LLViewerAssetStats::duration_t mMetricsStartTime; +}; + +///---------------------------------------------------------------------------- +/// LLViewerAssetStorage +///---------------------------------------------------------------------------- LLViewerAssetStorage::LLViewerAssetStorage(LLMessageSystem *msg, LLXferManager *xfer, LLVFS *vfs, LLVFS *static_vfs, @@ -258,3 +313,72 @@ void LLViewerAssetStorage::storeAssetData( } } } + + +/** + * @brief Allocate and queue an asset fetch request for the viewer + * + * This is a nearly-verbatim copy of the base class's implementation + * with the following changes: + * - Use a locally-derived request class + * - Start timing for metrics when request is queued + * + * This is an unfortunate implementation choice but it's forced by + * current conditions. A refactoring that might clean up the layers + * of responsibility or introduce factories or more virtualization + * of methods would enable a more attractive solution. + * + * If LLAssetStorage::_queueDataRequest changes, this must change + * as well. + */ + +// virtual +void LLViewerAssetStorage::_queueDataRequest( + const LLUUID& uuid, + LLAssetType::EType atype, + LLGetAssetCallback callback, + void *user_data, + BOOL duplicate, + BOOL is_priority) +{ + if (mUpstreamHost.isOk()) + { + // stash the callback info so we can find it after we get the response message + LLViewerAssetRequest *req = new LLViewerAssetRequest(uuid, atype); + req->mDownCallback = callback; + req->mUserData = user_data; + req->mIsPriority = is_priority; + req->mMetricsStartTime = LLViewerAssetStatsFF::get_timestamp(); + + mPendingDownloads.push_back(req); + + if (!duplicate) + { + // send request message to our upstream data provider + // Create a new asset transfer. + LLTransferSourceParamsAsset spa; + spa.setAsset(uuid, atype); + + // Set our destination file, and the completion callback. + LLTransferTargetParamsVFile tpvf; + tpvf.setAsset(uuid, atype); + tpvf.setCallback(downloadCompleteCallback, req); + + llinfos << "Starting transfer for " << uuid << llendl; + LLTransferTargetChannel *ttcp = gTransferManager.getTargetChannel(mUpstreamHost, LLTCT_ASSET); + ttcp->requestTransfer(spa, tpvf, 100.f + (is_priority ? 1.f : 0.f)); + + LLViewerAssetStatsFF::record_enqueue_main(atype, false, false); + } + } + else + { + // uh-oh, we shouldn't have gotten here + llwarns << "Attempt to move asset data request upstream w/o valid upstream provider" << llendl; + if (callback) + { + callback(mVFS, uuid, atype, user_data, LL_ERR_CIRCUIT_GONE, LL_EXSTAT_NO_UPSTREAM); + } + } +} + diff --git a/indra/newview/llviewerassetstorage.h b/indra/newview/llviewerassetstorage.h index 6346b79f03..ca9b9943fa 100644 --- a/indra/newview/llviewerassetstorage.h +++ b/indra/newview/llviewerassetstorage.h @@ -63,6 +63,17 @@ public: bool is_priority = false, bool user_waiting=FALSE, F64 timeout=LL_ASSET_STORAGE_TIMEOUT); + +protected: + using LLAssetStorage::_queueDataRequest; + + // virtual + void _queueDataRequest(const LLUUID& uuid, + LLAssetType::EType type, + void (*callback) (LLVFS *vfs, const LLUUID&, LLAssetType::EType, void *, S32, LLExtStat), + void *user_data, + BOOL duplicate, + BOOL is_priority); }; #endif diff --git a/indra/newview/llviewerregion.cpp b/indra/newview/llviewerregion.cpp index 98f16757b2..79b45a459f 100644 --- a/indra/newview/llviewerregion.cpp +++ b/indra/newview/llviewerregion.cpp @@ -1403,6 +1403,7 @@ void LLViewerRegion::setSeedCapability(const std::string& url) capabilityNames.append("UpdateNotecardTaskInventory"); capabilityNames.append("UpdateScriptTask"); capabilityNames.append("UploadBakedTexture"); + capabilityNames.append("ViewerMetrics"); capabilityNames.append("ViewerStartAuction"); capabilityNames.append("ViewerStats"); capabilityNames.append("WebFetchInventoryDescendents"); diff --git a/indra/newview/tests/llviewerassetstats_test.cpp b/indra/newview/tests/llviewerassetstats_test.cpp index affe16c177..c3c38ef925 100644 --- a/indra/newview/tests/llviewerassetstats_test.cpp +++ b/indra/newview/tests/llviewerassetstats_test.cpp @@ -114,7 +114,7 @@ namespace tut LLViewerAssetStatsFF::record_dequeue_main(LLViewerAssetType::AT_TEXTURE, false, false); - LLViewerAssetStatsFF::record_response_main(LLViewerAssetType::AT_GESTURE, false, false, 12.3); + LLViewerAssetStatsFF::record_response_main(LLViewerAssetType::AT_GESTURE, false, false, 12300000ULL); } // Create a non-global instance and check the structure -- cgit v1.2.3