diff --git a/indra/llaudio/llaudiodecodemgr.cpp b/indra/llaudio/llaudiodecodemgr.cpp index 5a4cd236bbeb8959f5e1557b223909599c268309..7e255299c7db541b4773a87195a2310dc4935cc7 100644 --- a/indra/llaudio/llaudiodecodemgr.cpp +++ b/indra/llaudio/llaudiodecodemgr.cpp @@ -615,40 +615,37 @@ void LLAudioDecodeMgr::Impl::startMoreDecodes() // Kick off a decode mDecodes[decode_id] = LLPointer<LLVorbisDecodeState>(NULL); - try - { - main_queue->postTo( - general_queue, - [decode_id]() // Work done on general queue - { - LLPointer<LLVorbisDecodeState> decode_state = beginDecodingAndWritingAudio(decode_id); - - if (!decode_state) - { - // Audio decode has errored - return decode_state; - } + bool posted = main_queue->postTo( + general_queue, + [decode_id]() // Work done on general queue + { + LLPointer<LLVorbisDecodeState> decode_state = beginDecodingAndWritingAudio(decode_id); - // Disk write of decoded audio is now in progress off-thread + if (!decode_state) + { + // Audio decode has errored return decode_state; - }, - [decode_id, this](LLPointer<LLVorbisDecodeState> decode_state) // Callback to main thread - mutable { - if (!gAudiop) - { - // There is no LLAudioEngine anymore. This might happen if - // an audio decode is enqueued just before shutdown. - return; - } - - // At this point, we can be certain that the pointer to "this" - // is valid because the lifetime of "this" is dependent upon - // the lifetime of gAudiop. - - enqueueFinishAudio(decode_id, decode_state); - }); - } - catch (const LLThreadSafeQueueInterrupt&) + } + + // Disk write of decoded audio is now in progress off-thread + return decode_state; + }, + [decode_id, this](LLPointer<LLVorbisDecodeState> decode_state) // Callback to main thread + mutable { + if (!gAudiop) + { + // There is no LLAudioEngine anymore. This might happen if + // an audio decode is enqueued just before shutdown. + return; + } + + // At this point, we can be certain that the pointer to "this" + // is valid because the lifetime of "this" is dependent upon + // the lifetime of gAudiop. + + enqueueFinishAudio(decode_id, decode_state); + }); + if (! posted) { // Shutdown // Consider making processQueue() do a cleanup instead diff --git a/indra/llcommon/llqueuedthread.cpp b/indra/llcommon/llqueuedthread.cpp index a0c5d691b36366b4d3eb9825a7752cb476898a97..2b16ec703eb84b6a6abdf8e8ba6f5bc87c89f663 100644 --- a/indra/llcommon/llqueuedthread.cpp +++ b/indra/llcommon/llqueuedthread.cpp @@ -146,7 +146,7 @@ S32 LLQueuedThread::updateQueue(F32 max_time_ms) // schedule a call to threadedUpdate for every call to updateQueue if (!isQuitting()) { - mRequestQueue.postIfOpen([=]() + mRequestQueue.post([=]() { LL_PROFILE_ZONE_NAMED_CATEGORY_THREAD("qt - update"); mIdleThread = FALSE; diff --git a/indra/llcommon/workqueue.cpp b/indra/llcommon/workqueue.cpp index 83e0216ae72b3bf57a9da5298fccc9cd088e290d..cf80ce0656d5287002f82d20b44cba3e2327d86d 100644 --- a/indra/llcommon/workqueue.cpp +++ b/indra/llcommon/workqueue.cpp @@ -161,12 +161,7 @@ bool LL::WorkQueue::done() return mQueue.done(); } -void LL::WorkQueue::post(const Work& callable) -{ - mQueue.push(callable); -} - -bool LL::WorkQueue::postIfOpen(const Work& callable) +bool LL::WorkQueue::post(const Work& callable) { return mQueue.pushIfOpen(callable); } @@ -215,26 +210,16 @@ bool LL::WorkSchedule::done() return mQueue.done(); } -void LL::WorkSchedule::post(const Work& callable) +bool LL::WorkSchedule::post(const Work& callable) { // Use TimePoint::clock::now() instead of TimePoint's representation of // the epoch because this WorkSchedule may contain a mix of past-due // TimedWork items and TimedWork items scheduled for the future. Sift this // new item into the correct place. - post(callable, TimePoint::clock::now()); -} - -void LL::WorkSchedule::post(const Work& callable, const TimePoint& time) -{ - mQueue.push(TimedWork(time, callable)); -} - -bool LL::WorkSchedule::postIfOpen(const Work& callable) -{ - return postIfOpen(callable, TimePoint::clock::now()); + return post(callable, TimePoint::clock::now()); } -bool LL::WorkSchedule::postIfOpen(const Work& callable, const TimePoint& time) +bool LL::WorkSchedule::post(const Work& callable, const TimePoint& time) { return mQueue.pushIfOpen(TimedWork(time, callable)); } diff --git a/indra/llcommon/workqueue.h b/indra/llcommon/workqueue.h index 5b704e71988594a6282bb172fb6bb659fc4b9c2d..ec0700a718756aa8a09fe0e29cd6b1a64e6c4119 100644 --- a/indra/llcommon/workqueue.h +++ b/indra/llcommon/workqueue.h @@ -83,13 +83,10 @@ namespace LL /*---------------------- fire and forget API -----------------------*/ - /// fire-and-forget - virtual void post(const Work&) = 0; - /** * post work, unless the queue is closed before we can post */ - virtual bool postIfOpen(const Work&) = 0; + virtual bool post(const Work&) = 0; /** * post work, unless the queue is full @@ -247,13 +244,10 @@ namespace LL /*---------------------- fire and forget API -----------------------*/ - /// fire-and-forget - void post(const Work&) override; - /** * post work, unless the queue is closed before we can post */ - bool postIfOpen(const Work&) override; + bool post(const Work&) override; /** * post work, unless the queue is full @@ -320,22 +314,16 @@ namespace LL /*---------------------- fire and forget API -----------------------*/ - /// fire-and-forget - void post(const Work& callable) override; - - /// fire-and-forget, but at a particular (future?) time - void post(const Work& callable, const TimePoint& time); - /** * post work, unless the queue is closed before we can post */ - bool postIfOpen(const Work& callable) override; + bool post(const Work& callable) override; /** * post work for a particular time, unless the queue is closed before * we can post */ - bool postIfOpen(const Work& callable, const TimePoint& time); + bool post(const Work& callable, const TimePoint& time); /** * post work, unless the queue is full @@ -356,7 +344,7 @@ namespace LL * an LLCond variant, e.g. LLOneShotCond or LLBoolCond. */ template <typename Rep, typename Period, typename CALLABLE> - void postEvery(const std::chrono::duration<Rep, Period>& interval, + bool postEvery(const std::chrono::duration<Rep, Period>& interval, CALLABLE&& callable); private: @@ -417,15 +405,10 @@ namespace LL // move-only callable; but naturally this statement must be // the last time we reference this instance, which may become // moved-from. - try - { - auto target{ std::dynamic_pointer_cast<WorkSchedule>(mTarget.lock()) }; - target->post(std::move(*this), mStart); - } - catch (const Closed&) - { - // Once this queue is closed, oh well, just stop - } + auto target{ std::dynamic_pointer_cast<WorkSchedule>(mTarget.lock()) }; + // Discard bool return: once this queue is closed, oh well, + // just stop + target->post(std::move(*this), mStart); } } @@ -437,7 +420,7 @@ namespace LL }; template <typename Rep, typename Period, typename CALLABLE> - void WorkSchedule::postEvery(const std::chrono::duration<Rep, Period>& interval, + bool WorkSchedule::postEvery(const std::chrono::duration<Rep, Period>& interval, CALLABLE&& callable) { if (interval.count() <= 0) @@ -454,7 +437,7 @@ namespace LL // Instantiate and post a suitable BackJack, binding a weak_ptr to // self, the current time, the desired interval and the desired // callable. - post( + return post( BackJack<Rep, Period, CALLABLE>( getWeak(), TimePoint::clock::now(), interval, std::move(callable))); } @@ -516,48 +499,37 @@ namespace LL // Here we believe target WorkQueue still exists. Post to it a // lambda that packages our callable, our callback and a weak_ptr // to this originating WorkQueue. - try - { - tptr->post( - [reply = super::getWeak(), - callable = std::move(callable), - callback = std::move(callback)] - () mutable + return tptr->post( + [reply = super::getWeak(), + callable = std::move(callable), + callback = std::move(callback)] + () mutable + { + // Use postMaybe() below in case this originating WorkQueue + // has been closed or destroyed. Remember, the outer lambda is + // now running on a thread servicing the target WorkQueue, and + // real time has elapsed since postTo()'s tptr->post() call. + try { - // Use postMaybe() below in case this originating WorkQueue - // has been closed or destroyed. Remember, the outer lambda is - // now running on a thread servicing the target WorkQueue, and - // real time has elapsed since postTo()'s tptr->post() call. - try - { - // Make a reply lambda to repost to THIS WorkQueue. - // Delegate to makeReplyLambda() so we can partially - // specialize on void return. - postMaybe(reply, makeReplyLambda(std::move(callable), std::move(callback))); - } - catch (...) - { - // Either variant of makeReplyLambda() is responsible for - // calling the caller's callable. If that throws, return - // the exception to the originating thread. - postMaybe( - reply, - // Bind the current exception to transport back to the - // originating WorkQueue. Once there, rethrow it. - [exc = std::current_exception()](){ std::rethrow_exception(exc); }); - } - }, - // if caller passed a TimePoint, pass it along to post() - std::forward<ARGS>(args)...); - } - catch (const Closed&) - { - // target WorkQueue still exists, but is Closed - return false; - } - - // looks like we were able to post() - return true; + // Make a reply lambda to repost to THIS WorkQueue. + // Delegate to makeReplyLambda() so we can partially + // specialize on void return. + postMaybe(reply, makeReplyLambda(std::move(callable), std::move(callback))); + } + catch (...) + { + // Either variant of makeReplyLambda() is responsible for + // calling the caller's callable. If that throws, return + // the exception to the originating thread. + postMaybe( + reply, + // Bind the current exception to transport back to the + // originating WorkQueue. Once there, rethrow it. + [exc = std::current_exception()](){ std::rethrow_exception(exc); }); + } + }, + // if caller passed a TimePoint, pass it along to post() + std::forward<ARGS>(args)...); } template <typename... ARGS> @@ -568,18 +540,9 @@ namespace LL auto tptr = target.lock(); if (tptr) { - try - { - tptr->post(std::forward<ARGS>(args)...); - // we were able to post() - return true; - } - catch (const Closed&) - { - // target WorkQueue still exists, but is Closed - } + return tptr->post(std::forward<ARGS>(args)...); } - // either target no longer exists, or its WorkQueue is Closed + // target no longer exists return false; } @@ -591,7 +554,7 @@ namespace LL auto operator()(WorkQueueBase* self, CALLABLE&& callable, ARGS&&... args) { LLCoros::Promise<RETURNTYPE> promise; - self->post( + bool posted = self->post( // We dare to bind a reference to Promise because it's // specifically designed for cross-thread communication. [&promise, callable = std::move(callable)]() @@ -608,6 +571,10 @@ namespace LL }, // if caller passed a TimePoint, pass it to post() std::forward<ARGS>(args)...); + if (! posted) + { + LLTHROW(WorkQueueBase::Closed()); + } auto future{ LLCoros::getFuture(promise) }; // now, on the calling thread, wait for that result LLCoros::TempStatus st("waiting for WorkQueue::waitForResult()"); @@ -623,7 +590,7 @@ namespace LL void operator()(WorkQueueBase* self, CALLABLE&& callable, ARGS&&... args) { LLCoros::Promise<void> promise; - self->post( + bool posted = self->post( // &promise is designed for cross-thread access [&promise, callable = std::move(callable)]() mutable { @@ -639,6 +606,10 @@ namespace LL }, // if caller passed a TimePoint, pass it to post() std::forward<ARGS>(args)...); + if (! posted) + { + LLTHROW(WorkQueueBase::Closed()); + } auto future{ LLCoros::getFuture(promise) }; // block until set_value() LLCoros::TempStatus st("waiting for void WorkQueue::waitForResult()"); diff --git a/indra/llimage/llimageworker.cpp b/indra/llimage/llimageworker.cpp index 39d7b1f6621b4c0989a18c4c059f9c8b9eda0baf..b73c7ba44ac8e52a406f3aac16edb568d7d360c3 100644 --- a/indra/llimage/llimageworker.cpp +++ b/indra/llimage/llimageworker.cpp @@ -92,21 +92,19 @@ LLImageDecodeThread::handle_t LLImageDecodeThread::decodeImage( { LL_PROFILE_ZONE_SCOPED_CATEGORY_TEXTURE; - try - { - // Instantiate the ImageRequest right in the lambda, why not? - mThreadPool->getQueue().post( - [req = ImageRequest(image, discard, needs_aux, responder)] - () mutable - { - auto done = req.processRequest(); - req.finishRequest(done); - }); - } - catch (const LLThreadSafeQueueInterrupt&) - { - LL_DEBUGS() << "Tried to start decoding on shutdown" << LL_ENDL; - } + // Instantiate the ImageRequest right in the lambda, why not? + bool posted = mThreadPool->getQueue().post( + [req = ImageRequest(image, discard, needs_aux, responder)] + () mutable + { + auto done = req.processRequest(); + req.finishRequest(done); + }); + if (! posted) + { + LL_DEBUGS() << "Tried to start decoding on shutdown" << LL_ENDL; + // should this return 0? + } // It's important to our consumer (LLTextureFetchWorker) that we return a // nonzero handle. It is NOT important that the nonzero handle be unique: diff --git a/indra/llrender/llimagegl.h b/indra/llrender/llimagegl.h index 65922ad033369e8dc46bbd7bc4c0a5397ed71ba2..21d4280c87f6b3f12254a7337fd09e6115e7bb52 100644 --- a/indra/llrender/llimagegl.h +++ b/indra/llrender/llimagegl.h @@ -344,7 +344,7 @@ class LLImageGLThread : public LLSimpleton<LLImageGLThread>, LL::ThreadPool template <typename CALLABLE> bool post(CALLABLE&& func) { - return getQueue().postIfOpen(std::forward<CALLABLE>(func)); + return getQueue().post(std::forward<CALLABLE>(func)); } void run() override; diff --git a/indra/llwindow/llwindowwin32.cpp b/indra/llwindow/llwindowwin32.cpp index ef3e416089dbe58df06d08443dada466cc2a71bb..af19001aa345f9949bdae44022b6405cee0a3fab 100644 --- a/indra/llwindow/llwindowwin32.cpp +++ b/indra/llwindow/llwindowwin32.cpp @@ -331,15 +331,10 @@ struct LLWindowWin32::LLWindowWin32Thread : public LL::ThreadPool template <typename CALLABLE> void post(CALLABLE&& func) { - try - { - getQueue().post(std::forward<CALLABLE>(func)); - } - catch (const LLThreadSafeQueueInterrupt&) - { - // Shutdown timing is tricky. The main thread can end up trying - // to post a cursor position after having closed the WorkQueue. - } + // Ignore bool return. Shutdown timing is tricky: the main thread can + // end up trying to post a cursor position after having closed the + // WorkQueue. + getQueue().post(std::forward<CALLABLE>(func)); } /** diff --git a/indra/newview/llappviewer.cpp b/indra/newview/llappviewer.cpp index bb2ffc044bedf6eca5b2245a5ab348de05b84993..c03b9bf72601c4cc51d9d78720095c0c319f9c89 100644 --- a/indra/newview/llappviewer.cpp +++ b/indra/newview/llappviewer.cpp @@ -4722,6 +4722,8 @@ void LLAppViewer::idle() LLFrameTimer::updateFrameTime(); LLFrameTimer::updateFrameCount(); LLEventTimer::updateClass(); + LLPerfStats::updateClass(); + // LLApp::stepFrame() performs the above three calls plus mRunner.run(). // Not sure why we don't call stepFrame() here, except that LLRunner seems // completely redundant with LLEventTimer. diff --git a/indra/newview/lldrawpoolalpha.cpp b/indra/newview/lldrawpoolalpha.cpp index e273490e93a8a9dea632be66790cb70c325c541b..7eb7b2f749aa72ec861bdb1de6b2eb3560e2509e 100644 --- a/indra/newview/lldrawpoolalpha.cpp +++ b/indra/newview/lldrawpoolalpha.cpp @@ -157,7 +157,7 @@ void LLDrawPoolAlpha::renderPostDeferred(S32 pass) { LL_PROFILE_ZONE_SCOPED_CATEGORY_DRAWPOOL; - if ((!LLPipeline::sRenderTransparentWater || gCubeSnapshot) && getType() == LLDrawPool::POOL_ALPHA_PRE_WATER) + if (LLPipeline::isWaterClip() && getType() == LLDrawPool::POOL_ALPHA_PRE_WATER) { // don't render alpha objects on the other side of the water plane if water is opaque return; } diff --git a/indra/newview/llfloaterperformance.cpp b/indra/newview/llfloaterperformance.cpp index 8c5745aa4322aceee99cf0b5453dd13dd5f6986d..19fc3e673e41f0a2523291cf7fcb14fa24528ad5 100644 --- a/indra/newview/llfloaterperformance.cpp +++ b/indra/newview/llfloaterperformance.cpp @@ -456,15 +456,8 @@ void LLFloaterPerformance::populateNearbyList() row[1]["column"] = "complex_value"; row[1]["type"] = "text"; - if (is_slow && !showTunedART) - { - row[1]["value"] = llformat( "%.f", LLPerfStats::raw_to_us( avatar->getLastART() ) ); - } - else - { - // use GPU time in us - row[1]["value"] = llformat( "%.f", render_av_gpu_ms * 1000.f); - } + // use GPU time in us + row[1]["value"] = llformat( "%.f", render_av_gpu_ms * 1000.f); row[1]["font"]["name"] = "SANSSERIF"; row[3]["column"] = "name"; diff --git a/indra/newview/llperfstats.cpp b/indra/newview/llperfstats.cpp index b680d8761b2ed9d1357c5348c76779d7a5a98911..395ac0e788eedc202a49b238e6cba4157f28034f 100644 --- a/indra/newview/llperfstats.cpp +++ b/indra/newview/llperfstats.cpp @@ -39,6 +39,11 @@ extern LLControlGroup gSavedSettings; namespace LLPerfStats { + // avatar timing metrics in ms (updated once per mainloop iteration) + std::atomic<F32> sTotalAvatarTime = 0.f; + std::atomic<F32> sAverageAvatarTime = 0.f; + std::atomic<F32> sMaxAvatarTime = 0.f; + std::atomic<int64_t> tunedAvatars{0}; std::atomic<U64> renderAvatarMaxART_ns{(U64)(ART_UNLIMITED_NANOS)}; // highest render time we'll allow without culling features bool belowTargetFPS{false}; @@ -141,14 +146,12 @@ namespace LLPerfStats resetChanges(); } - StatsRecorder::StatsRecorder():q(1024*16),t(&StatsRecorder::run) + StatsRecorder::StatsRecorder():q(1024*16) { // create a queue - // create a thread to consume from the queue tunables.initialiseFromSettings(); LLPerfStats::cpu_hertz = (F64)LLTrace::BlockTimer::countsPerSecond(); LLPerfStats::vsync_max_fps = gViewerWindow->getWindow()->getRefreshRate(); - t.detach(); } // static @@ -172,11 +175,13 @@ namespace LLPerfStats // RENDER_MESHREPO, StatType_t::RENDER_IDLE }; +#if 0 static constexpr std::initializer_list<StatType_t> avatarStatsToAvg = { StatType_t::RENDER_GEOMETRY, StatType_t::RENDER_SHADOWS, StatType_t::RENDER_COMBINED, StatType_t::RENDER_IDLE }; +#endif if( /*sceneStats[static_cast<size_t>(StatType_t::RENDER_FPSLIMIT)] != 0 ||*/ sceneStats[static_cast<size_t>(StatType_t::RENDER_SLEEP)] != 0 ) @@ -200,20 +205,6 @@ namespace LLPerfStats } } - auto& statsMapAv = statsDoubleBuffer[writeBuffer][static_cast<size_t>(ObjType_t::OT_AVATAR)]; - for(auto& stat_entry : statsMapAv) - { - for(auto& stat : avatarStatsToAvg) - { - auto val = stat_entry.second[static_cast<size_t>(stat)]; - if(val > SMOOTHING_PERIODS) - { - auto avg = statsDoubleBuffer[writeBuffer ^ 1][static_cast<size_t>(ObjType_t::OT_AVATAR)][stat_entry.first][static_cast<size_t>(stat)]; - stat_entry.second[static_cast<size_t>(stat)] = avg + (val / SMOOTHING_PERIODS) - (avg / SMOOTHING_PERIODS); - } - } - } - // swap the buffers if(enabled()) { @@ -293,6 +284,36 @@ namespace LLPerfStats } } + // called once per main loop iteration on main thread + void updateClass() + { + LL_PROFILE_ZONE_SCOPED_CATEGORY_STATS; + + sTotalAvatarTime = LLVOAvatar::getTotalGPURenderTime(); + sAverageAvatarTime = LLVOAvatar::getAverageGPURenderTime(); + sMaxAvatarTime = LLVOAvatar::getMaxGPURenderTime(); + + auto general = LL::WorkQueue::getInstance("General"); + + if (general) + { + general->post([] { StatsRecorder::update(); }); + } + } + + // called once per main loop iteration on General thread + void StatsRecorder::update() + { + LL_PROFILE_ZONE_SCOPED_CATEGORY_STATS; + StatsRecord upd; + auto& instance{ StatsRecorder::getInstance() }; + + while (enabled() && !LLApp::isQuitting() && instance.q.tryPop(upd)) + { + instance.processUpdate(upd); + } + } + //static int StatsRecorder::countNearbyAvatars(S32 distance) { @@ -327,6 +348,8 @@ namespace LLPerfStats // static void StatsRecorder::updateAvatarParams() { + LL_PROFILE_ZONE_SCOPED_CATEGORY_STATS; + if(tunables.autoTuneTimeout) { LLPerfStats::lastSleepedFrame = gFrameCount; @@ -380,10 +403,10 @@ namespace LLPerfStats } } - auto av_render_max_raw = LLPerfStats::StatsRecorder::getMax(ObjType_t::OT_AVATAR, LLPerfStats::StatType_t::RENDER_COMBINED); + auto av_render_max_raw = ms_to_raw(sMaxAvatarTime); // Is our target frame time lower than current? If so we need to take action to reduce draw overheads. // cumulative avatar time (includes idle processing, attachments and base av) - auto tot_avatar_time_raw = LLPerfStats::StatsRecorder::getSum(ObjType_t::OT_AVATAR, LLPerfStats::StatType_t::RENDER_COMBINED); + auto tot_avatar_time_raw = ms_to_raw(sTotalAvatarTime); // The frametime budget we have based on the target FPS selected auto target_frame_time_raw = (U64)llround(LLPerfStats::cpu_hertz / (target_fps == 0 ? 1 : target_fps)); @@ -417,7 +440,7 @@ namespace LLPerfStats // if so we've got work to do // how much of the frame was spent on non avatar related work? - U64 non_avatar_time_raw = tot_frame_time_raw - tot_avatar_time_raw; + U64 non_avatar_time_raw = tot_frame_time_raw > tot_avatar_time_raw ? tot_frame_time_raw - tot_avatar_time_raw : 0; // If the target frame time < scene time (estimated as non_avatar time) U64 target_avatar_time_raw; @@ -475,7 +498,11 @@ namespace LLPerfStats { new_render_limit_ns = renderAvatarMaxART_ns; } - new_render_limit_ns -= LLPerfStats::ART_MIN_ADJUST_DOWN_NANOS; + + if (new_render_limit_ns > LLPerfStats::ART_MIN_ADJUST_DOWN_NANOS) + { + new_render_limit_ns -= LLPerfStats::ART_MIN_ADJUST_DOWN_NANOS; + } // bounce at the bottom to prevent "no limit" new_render_limit_ns = std::max((U64)new_render_limit_ns, (U64)LLPerfStats::ART_MINIMUM_NANOS); diff --git a/indra/newview/llperfstats.h b/indra/newview/llperfstats.h index a4768272b9dc979c8c6675361ddb088f1a019538..bb5677f237e8b57c031af7213eaa42bb5e2e0d9f 100644 --- a/indra/newview/llperfstats.h +++ b/indra/newview/llperfstats.h @@ -42,6 +42,10 @@ extern U32 gFrameCount; extern LLUUID gAgentID; namespace LLPerfStats { + + // called once per main loop iteration + void updateClass(); + // Note if changing these, they should correspond with the log range of the correpsonding sliders static constexpr U64 ART_UNLIMITED_NANOS{50000000}; static constexpr U64 ART_MINIMUM_NANOS{100000}; @@ -68,7 +72,6 @@ namespace LLPerfStats enum class ObjType_t{ OT_GENERAL=0, // Also Unknown. Used for n/a type stats such as scenery - OT_AVATAR, OT_COUNT }; enum class StatType_t{ @@ -162,6 +165,9 @@ namespace LLPerfStats using Queue = LLThreadSafeQueue<StatsRecord>; public: + // called once per main loop iteration on General thread + static void update(); + static inline StatsRecorder& getInstance() { static StatsRecorder instance; @@ -241,7 +247,6 @@ namespace LLPerfStats auto ot{upd.objType}; auto& key{upd.objID}; - auto& avKey{upd.avID}; auto type {upd.statType}; auto val {upd.time}; @@ -251,13 +256,6 @@ namespace LLPerfStats doUpd(key, ot, type,val); return; } - - if (ot == ObjType_t::OT_AVATAR) - { - // LL_INFOS("perfstats") << "Avatar update:" << LL_ENDL; - doUpd(avKey, ot, type, val); - return; - } } static inline void doUpd(const LLUUID& key, ObjType_t ot, StatType_t type, uint64_t val) @@ -286,42 +284,7 @@ namespace LLPerfStats static void toggleBuffer(); static void clearStatsBuffers(); - // thread entry - static void run() - { - StatsRecord upd[10]; - auto & instance {StatsRecorder::getInstance()}; - LL_PROFILER_SET_THREAD_NAME("PerfStats"); - - while( enabled() && !LLApp::isExiting() ) - { - auto count = 0; - while (count < 10) - { - if (instance.q.tryPopFor(std::chrono::milliseconds(10), upd[count])) - { - count++; - } - else - { - break; - } - } - //LL_PROFILER_THREAD_BEGIN("PerfStats"); - if(count) - { - // LL_INFOS("perfstats") << "processing " << count << " updates." << LL_ENDL; - for(auto i =0; i < count; i++) - { - instance.processUpdate(upd[i]); - } - } - //LL_PROFILER_THREAD_END("PerfStats"); - } - } - Queue q; - std::thread t; ~StatsRecorder() = default; StatsRecorder(const StatsRecorder&) = delete; @@ -354,13 +317,6 @@ namespace LLPerfStats LL_PROFILE_ZONE_SCOPED_CATEGORY_STATS; }; - template < ObjType_t OD = ObjTypeDiscriminator, - std::enable_if_t<OD == ObjType_t::OT_AVATAR> * = nullptr> - RecordTime( const LLUUID & av, StatType_t type ):RecordTime<ObjTypeDiscriminator>(std::move(av), LLUUID::null, type) - { - //LL_PROFILE_ZONE_COLOR(tracy::Color::Purple); - }; - ~RecordTime() { if(!LLPerfStats::StatsRecorder::enabled()) @@ -375,13 +331,19 @@ namespace LLPerfStats }; }; - + inline double raw_to_ns(U64 raw) { return (static_cast<double>(raw) * 1000000000.0) / LLPerfStats::cpu_hertz; }; inline double raw_to_us(U64 raw) { return (static_cast<double>(raw) * 1000000.0) / LLPerfStats::cpu_hertz; }; inline double raw_to_ms(U64 raw) { return (static_cast<double>(raw) * 1000.0) / LLPerfStats::cpu_hertz; }; + inline U64 ns_to_raw(double ns) { return (U64)(LLPerfStats::cpu_hertz * (ns / 1000000000.0)); } + inline U64 us_to_raw(double us) { return (U64)(LLPerfStats::cpu_hertz * (us / 1000000.0)); } + inline U64 ms_to_raw(double ms) { return (U64)(LLPerfStats::cpu_hertz * (ms / 1000.0)); + + } + + using RecordSceneTime = RecordTime<ObjType_t::OT_GENERAL>; - using RecordAvatarTime = RecordTime<ObjType_t::OT_AVATAR>; };// namespace LLPerfStats diff --git a/indra/newview/llviewerstats.cpp b/indra/newview/llviewerstats.cpp index 22f583e912842f52a4258a4df4715e448085cbde..12c8d32fa4fca925353db45869752ed1e9458560 100644 --- a/indra/newview/llviewerstats.cpp +++ b/indra/newview/llviewerstats.cpp @@ -473,7 +473,7 @@ void update_statistics() auto tot_frame_time_raw = LLPerfStats::StatsRecorder::getSceneStat(LLPerfStats::StatType_t::RENDER_FRAME); // cumulative avatar time (includes idle processing, attachments and base av) - auto tot_avatar_time_raw = LLPerfStats::StatsRecorder::getSum(LLPerfStats::ObjType_t::OT_AVATAR, LLPerfStats::StatType_t::RENDER_COMBINED); + auto tot_avatar_time_raw = LLPerfStats::us_to_raw(LLVOAvatar::getTotalGPURenderTime()); // cumulative avatar render specific time (a bit arbitrary as the processing is too.) // auto tot_av_idle_time_raw = LLPerfStats::StatsRecorder::getSum(AvType, LLPerfStats::StatType_t::RENDER_IDLE); // auto tot_avatar_render_time_raw = tot_avatar_time_raw - tot_av_idle_time_raw; diff --git a/indra/newview/llvoavatar.cpp b/indra/newview/llvoavatar.cpp index 93246b99b275788e682fff486d7269cf3d569071..7ce4ddd1d53e9fd9f76d07f0f8afefdad44f2026 100644 --- a/indra/newview/llvoavatar.cpp +++ b/indra/newview/llvoavatar.cpp @@ -2597,7 +2597,6 @@ void LLVOAvatar::idleUpdate(LLAgent &agent, const F64 &time) return; } // record time and refresh "tooSlow" status - LLPerfStats::RecordAvatarTime T(getID(), LLPerfStats::StatType_t::RENDER_IDLE); // per avatar "idle" time. updateTooSlow(); static LLCachedControl<bool> disable_all_render_types(gSavedSettings, "DisableAllRenderTypes"); @@ -8675,14 +8674,6 @@ bool LLVOAvatar::isTooSlow() const return mTooSlow; } -// use Avatar Render Time as complexity metric -// markARTStale - Mark stale and set the frameupdate to now so that we can wait at least one frame to get a revised number. -void LLVOAvatar::markARTStale() -{ - mARTStale=true; - mLastARTUpdateFrame = LLFrameTimer::getFrameCount(); -} - // Udpate Avatar state based on render time void LLVOAvatar::updateTooSlow() { @@ -8693,41 +8684,9 @@ void LLVOAvatar::updateTooSlow() // mTooSlow - Is the avatar flagged as being slow (includes shadow time) // mTooSlowWithoutShadows - Is the avatar flagged as being slow even with shadows removed. - // mARTStale - the rendertime we have is stale because of an update. We need to force a re-render to re-assess slowness - - if( mARTStale ) - { - if ( LLFrameTimer::getFrameCount() - mLastARTUpdateFrame < 5 ) - { - // LL_INFOS() << this->getFullname() << " marked stale " << LL_ENDL; - // we've not had a chance to update yet (allow a few to be certain a full frame has passed) - return; - } - - mARTStale = false; - mTooSlow = false; - mTooSlowWithoutShadows = false; - // LL_INFOS() << this->getFullname() << " refreshed ART combined = " << mRenderTime << " @ " << mLastARTUpdateFrame << LL_ENDL; - } - - // Either we're not stale or we've updated. - - U64 render_time_raw; - U64 render_geom_time_raw; - - if( !mTooSlow ) - { - // we are fully rendered, so we use the live values - std::lock_guard<std::mutex> lock{LLPerfStats::bufferToggleLock}; - render_time_raw = LLPerfStats::StatsRecorder::get(LLPerfStats::ObjType_t::OT_AVATAR, id, LLPerfStats::StatType_t::RENDER_COMBINED); - render_geom_time_raw = LLPerfStats::StatsRecorder::get(LLPerfStats::ObjType_t::OT_AVATAR, id, LLPerfStats::StatType_t::RENDER_GEOMETRY); - } - else - { - // use the cached values. - render_time_raw = mRenderTime; - render_geom_time_raw = mGeomTime; - } + + // get max render time in ms + F32 max_art_ms = (F32) (LLPerfStats::renderAvatarMaxART_ns / 1000000.0); bool autotune = LLPerfStats::tunables.userAutoTuneEnabled && !mIsControlAvatar && !isSelf(); @@ -8743,19 +8702,13 @@ void LLVOAvatar::updateTooSlow() } bool exceeds_max_ART = - ((LLPerfStats::renderAvatarMaxART_ns > 0) && (LLPerfStats::raw_to_ns(render_time_raw) >= LLPerfStats::renderAvatarMaxART_ns)); + ((LLPerfStats::renderAvatarMaxART_ns > 0) && + (mGPURenderTime >= max_art_ms)); // NOTE: don't use getGPURenderTime accessor here to avoid "isTooSlow" feedback loop if (exceeds_max_ART && !ignore_tune) { - if( !mTooSlow ) // if we were previously not slow (with or without shadows.) - { - // if we weren't capped, we are now - mLastARTUpdateFrame = LLFrameTimer::getFrameCount(); - mRenderTime = render_time_raw; - mGeomTime = render_geom_time_raw; - mARTStale = false; - mTooSlow = true; - } + mTooSlow = true; + if(!mTooSlowWithoutShadows) // if we were not previously above the full impostor cap { bool render_friend_or_exception = ( alwaysRenderFriends && LLAvatarTracker::instance().isBuddy( id ) ) || @@ -8763,13 +8716,12 @@ void LLVOAvatar::updateTooSlow() if( (!isSelf() || allowSelfImpostor) && !render_friend_or_exception ) { // Note: slow rendering Friends still get their shadows zapped. - mTooSlowWithoutShadows = (LLPerfStats::raw_to_ns(render_geom_time_raw) >= LLPerfStats::renderAvatarMaxART_ns); + mTooSlowWithoutShadows = getGPURenderTime()*2.f >= max_art_ms; // NOTE: assumes shadow rendering doubles render time } } } else { - // LL_INFOS() << this->getFullname() << " ("<< (combined?"combined":"geometry") << ") good render time = " << LLPerfStats::raw_to_ns(render_time_raw) << " vs ("<< LLVOAvatar::sRenderTimeCap_ns << " set @ " << mLastARTUpdateFrame << LL_ENDL; mTooSlow = false; mTooSlowWithoutShadows = false; @@ -11554,6 +11506,21 @@ void LLVOAvatar::calculateUpdateRenderComplexity() { LLSidepanelAppearance::updateAvatarComplexity(mVisualComplexity, item_complexity, temp_item_complexity, body_parts_complexity); } + + //schedule an update to ART next frame if needed + if (LLPerfStats::tunables.userAutoTuneEnabled && + LLPerfStats::tunables.userFPSTuningStrategy != LLPerfStats::TUNE_SCENE_ONLY && + !isVisuallyMuted()) + { + LLUUID id = getID(); // <== use id to make sure this avatar didn't get deleted between frames + LL::WorkQueue::getInstance("mainloop")->post([this, id]() + { + if (gObjectList.findObject(id) != nullptr) + { + gPipeline.profileAvatar(this); + } + }); + } } } @@ -11931,6 +11898,9 @@ void LLVOAvatar::readProfileQuery(S32 retries) glGetQueryObjectui64v(mGPUTimerQuery, GL_QUERY_RESULT, &time_elapsed); mGPURenderTime = time_elapsed / 1000000.f; mGPUProfilePending = false; + + setDebugText(llformat("%d", (S32)(mGPURenderTime * 1000.f))); + } else { // wait until next frame @@ -11943,3 +11913,67 @@ void LLVOAvatar::readProfileQuery(S32 retries) } } + +F32 LLVOAvatar::getGPURenderTime() +{ + return isVisuallyMuted() ? 0.f : mGPURenderTime; +} + +// static +F32 LLVOAvatar::getTotalGPURenderTime() +{ + LL_PROFILE_ZONE_SCOPED_CATEGORY_AVATAR; + + F32 ret = 0.f; + + for (LLCharacter* iter : LLCharacter::sInstances) + { + LLVOAvatar* inst = (LLVOAvatar*) iter; + ret += inst->getGPURenderTime(); + } + + return ret; +} + +F32 LLVOAvatar::getMaxGPURenderTime() +{ + LL_PROFILE_ZONE_SCOPED_CATEGORY_AVATAR; + + F32 ret = 0.f; + + for (LLCharacter* iter : LLCharacter::sInstances) + { + LLVOAvatar* inst = (LLVOAvatar*)iter; + ret = llmax(inst->getGPURenderTime(), ret); + } + + return ret; +} + +F32 LLVOAvatar::getAverageGPURenderTime() +{ + LL_PROFILE_ZONE_SCOPED_CATEGORY_AVATAR; + + F32 ret = 0.f; + + S32 count = 0; + + for (LLCharacter* iter : LLCharacter::sInstances) + { + LLVOAvatar* inst = (LLVOAvatar*)iter; + if (!inst->isTooSlow()) + { + ret += inst->getGPURenderTime(); + ++count; + } + } + + if (count > 0) + { + ret /= count; + } + + return ret; +} + + diff --git a/indra/newview/llvoavatar.h b/indra/newview/llvoavatar.h index bdf275308d8d9b144174670f36ed63726ecd4a7f..ddf0ab37e3e6b319c0b8e29c0c0e8cb9829024a8 100644 --- a/indra/newview/llvoavatar.h +++ b/indra/newview/llvoavatar.h @@ -318,11 +318,21 @@ class LLVOAvatar : void readProfileQuery(S32 retries); // get the GPU time in ms of rendering this avatar including all attachments - // returns -1 if this avatar has not been profiled using gPipeline.profileAvatar - F32 getGPURenderTime() { return mGPURenderTime; } + // returns 0.f if this avatar has not been profiled using gPipeline.profileAvatar + // or the avatar is visually muted + F32 getGPURenderTime(); + + // get the total GPU render time in ms of all avatars that have been benched + static F32 getTotalGPURenderTime(); + + // get the max GPU render time in ms of all avatars that have been benched + static F32 getMaxGPURenderTime(); + + // get the average GPU render time in ms of all avatars that have been benched + static F32 getAverageGPURenderTime(); // get the CPU time in ms of rendering this avatar including all attachments - // return -1 if this avatar has not been profiled using gPipeline.mProfileAvatar + // return 0.f if this avatar has not been profiled using gPipeline.mProfileAvatar F32 getCPURenderTime() { return mCPURenderTime; } @@ -411,8 +421,7 @@ class LLVOAvatar : void logMetricsTimerRecord(const std::string& phase_name, F32 elapsed, bool completed); void calcMutedAVColor(); - void markARTStale(); - + protected: LLViewerStats::PhaseMap& getPhases() { return mPhases; } BOOL updateIsFullyLoaded(); @@ -433,11 +442,6 @@ class LLVOAvatar : LLFrameTimer mFullyLoadedTimer; LLFrameTimer mRuthTimer; - U32 mLastARTUpdateFrame{0}; - U64 mRenderTime{0}; - U64 mGeomTime{0}; - bool mARTStale{true}; - bool mARTCapped{false}; // variables to hold "slowness" status bool mTooSlow{false}; bool mTooSlowWithoutShadows{false}; @@ -571,11 +575,11 @@ class LLVOAvatar : // profile results // GPU render time in ms - F32 mGPURenderTime = -1.f; + F32 mGPURenderTime = 0.f; bool mGPUProfilePending = false; // CPU render time in ms - F32 mCPURenderTime = -1.f; + F32 mCPURenderTime = 0.f; // the isTooComplex method uses these mutable values to avoid recalculating too frequently // DEPRECATED -- obsolete avatar render cost values @@ -1226,8 +1230,6 @@ class LLVOAvatar : // COF version of last appearance message received for this av. S32 mLastUpdateReceivedCOFVersion; - U64 getLastART() const { return mRenderTime; } - /** Diagnostics ** ** *******************************************************************************/ diff --git a/indra/newview/llworld.cpp b/indra/newview/llworld.cpp index 7f95ba74d1eae35b692a5957a0a85424fa43788b..ae6280529c1e62b12d0cb26f2af4d43395f1ea6f 100644 --- a/indra/newview/llworld.cpp +++ b/indra/newview/llworld.cpp @@ -1651,7 +1651,11 @@ F32 LLWorld::getNearbyAvatarsAndMaxGPUTime(std::vector<LLCharacter*> &valid_near char_iter++; continue; } - gPipeline.profileAvatar(avatar); + + if (!avatar->isTooSlow()) + { + gPipeline.profileAvatar(avatar); + } nearby_max_complexity = llmax(nearby_max_complexity, avatar->getGPURenderTime()); valid_nearby_avs.push_back(*char_iter); } diff --git a/indra/newview/pipeline.cpp b/indra/newview/pipeline.cpp index 25af75884a9c601e6b81d083bd4c924fe5d260d1..e5a92a57e3c242f5fbdbc5db9a11a8782a34edd1 100644 --- a/indra/newview/pipeline.cpp +++ b/indra/newview/pipeline.cpp @@ -2396,12 +2396,18 @@ bool LLPipeline::getVisibleExtents(LLCamera& camera, LLVector3& min, LLVector3& static LLTrace::BlockTimerStatHandle FTM_CULL("Object Culling"); +// static +bool LLPipeline::isWaterClip() +{ + return (!sRenderTransparentWater || gCubeSnapshot) && !sRenderingHUDs; +} + void LLPipeline::updateCull(LLCamera& camera, LLCullResult& result) { LL_PROFILE_ZONE_SCOPED_CATEGORY_PIPELINE; //LL_RECORD_BLOCK_TIME(FTM_CULL); LL_PROFILE_GPU_ZONE("updateCull"); // should always be zero GPU time, but drop a timer to flush stuff out - bool water_clip = !sRenderTransparentWater && !sRenderingHUDs; + bool water_clip = isWaterClip(); if (water_clip) { @@ -10132,6 +10138,9 @@ void LLPipeline::profileAvatar(LLVOAvatar* avatar, bool profile_attachments) LL_PROFILE_ZONE_SCOPED_CATEGORY_PIPELINE; + // don't continue to profile an avatar that is known to be too slow + llassert(!avatar->isTooSlow()); + LLGLSLShader* cur_shader = LLGLSLShader::sCurBoundShaderPtr; mRT->deferredScreen.bindTarget(); @@ -10404,25 +10413,28 @@ void LLPipeline::generateImpostor(LLVOAvatar* avatar, bool preview_avatar, bool resY = llmin(nhpo2((U32) (fov*pa)), (U32) 512); resX = llmin(nhpo2((U32) (atanf(tdim.mV[0]/distance)*2.f*RAD_TO_DEG*pa)), (U32) 512); - if (!avatar->mImpostor.isComplete()) - { - avatar->mImpostor.allocate(resX, resY, GL_RGBA, true); + if (!for_profile) + { + if (!avatar->mImpostor.isComplete()) + { + avatar->mImpostor.allocate(resX, resY, GL_RGBA, true); - if (LLPipeline::sRenderDeferred) - { - addDeferredAttachments(avatar->mImpostor, true); - } - - gGL.getTexUnit(0)->bind(&avatar->mImpostor); - gGL.getTexUnit(0)->setTextureFilteringOption(LLTexUnit::TFO_POINT); - gGL.getTexUnit(0)->unbind(LLTexUnit::TT_TEXTURE); - } - else if(resX != avatar->mImpostor.getWidth() || resY != avatar->mImpostor.getHeight()) - { - avatar->mImpostor.resize(resX,resY); - } + if (LLPipeline::sRenderDeferred) + { + addDeferredAttachments(avatar->mImpostor, true); + } + + gGL.getTexUnit(0)->bind(&avatar->mImpostor); + gGL.getTexUnit(0)->setTextureFilteringOption(LLTexUnit::TFO_POINT); + gGL.getTexUnit(0)->unbind(LLTexUnit::TT_TEXTURE); + } + else if (resX != avatar->mImpostor.getWidth() || resY != avatar->mImpostor.getHeight()) + { + avatar->mImpostor.resize(resX, resY); + } - avatar->mImpostor.bindTarget(); + avatar->mImpostor.bindTarget(); + } } F32 old_alpha = LLDrawPoolAvatar::sMinimumAlpha; @@ -10525,7 +10537,7 @@ void LLPipeline::generateImpostor(LLVOAvatar* avatar, bool preview_avatar, bool gGL.popMatrix(); } - if (!preview_avatar) + if (!preview_avatar && !for_profile) { avatar->mImpostor.flush(); avatar->setImpostorDim(tdim); diff --git a/indra/newview/pipeline.h b/indra/newview/pipeline.h index fe372a53dda20d3009c6b3aebacacba0ed849c40..b2a36ae79662c07fc42f83f67525a3cda51e8f59 100644 --- a/indra/newview/pipeline.h +++ b/indra/newview/pipeline.h @@ -355,6 +355,8 @@ class LLPipeline bool hasRenderType(const U32 type) const; bool hasAnyRenderType(const U32 type, ...) const; + static bool isWaterClip(); + void setRenderTypeMask(U32 type, ...); // This is equivalent to 'setRenderTypeMask' //void orRenderTypeMask(U32 type, ...);