From 188221a90c7a054d390ddaa534d391f6370ac6bc Mon Sep 17 00:00:00 2001 From: Monty Brandenberg Date: Tue, 9 Apr 2013 23:44:59 +0000 Subject: SH-4088 Deadman timer switch started in llcommon. Unit test started. Will be used for mesh, inventory, etc., operation markers. --- indra/llcommon/lldeadmantimer.cpp | 141 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 141 insertions(+) create mode 100644 indra/llcommon/lldeadmantimer.cpp (limited to 'indra/llcommon/lldeadmantimer.cpp') diff --git a/indra/llcommon/lldeadmantimer.cpp b/indra/llcommon/lldeadmantimer.cpp new file mode 100644 index 0000000000..2f48d13c2d --- /dev/null +++ b/indra/llcommon/lldeadmantimer.cpp @@ -0,0 +1,141 @@ +/** +* @file lldeadmantimer.cpp +* @brief Simple deadman-switch timer. +* @author monty@lindenlab.com +* +* $LicenseInfo:firstyear=2013&license=viewerlgpl$ +* Second Life Viewer Source Code +* Copyright (C) 2013, Linden Research, Inc. +* +* This library is free software; you can redistribute it and/or +* modify it under the terms of the GNU Lesser General Public +* License as published by the Free Software Foundation; +* version 2.1 of the License only. +* +* This library 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 +* Lesser General Public License for more details. +* +* You should have received a copy of the GNU Lesser General Public +* License along with this library; if not, write to the Free Software +* Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA +* +* Linden Research, Inc., 945 Battery Street, San Francisco, CA 94111 USA +* $/LicenseInfo$ +*/ + + +#include "lldeadmantimer.h" + + +LLDeadmanTimer::LLDeadmanTimer(F64 horizon) + : mHorizon(U64(horizon * gClockFrequency)), + mActive(false), // If true, a timer is running. + mDone(false), // If true, timer has completed and can be read (once) + mStarted(U64L(0)), + mExpires(U64L(0)), + mStopped(U64L(0)), + mCount(U64L(0)) +{} + + +void LLDeadmanTimer::start(U64 now) +{ + // *TODO: If active, let's complete an existing timer and save + // the result to the side. I think this will be useful later. + // For now, wipe out anything in progress, start fresh. + + if (! now) + { + now = LLTimer::getCurrentClockCount(); + } + mActive = true; + mDone = false; + mStarted = now; + mExpires = now + mHorizon; + mStopped = now; + mCount = U64L(0); +} + + +void LLDeadmanTimer::stop(U64 now) +{ + if (! mActive) + { + return; + } + + if (! now) + { + now = LLTimer::getCurrentClockCount(); + } + mStopped = now; + mActive = false; + mDone = true; +} + + +bool LLDeadmanTimer::isExpired(F64 & started, F64 & stopped, U64 & count, U64 now) +{ + if (! mActive) + { + return false; + } + + if (! mDone) + { + if (! now) + { + now = LLTimer::getCurrentClockCount(); + } + + if (now > mExpires) + { + // mStopped from ringBell() is the value we want + mActive = false; + mDone = true; + } + } + + if (! mDone) + { + return false; + } + + started = mStarted * gClockFrequencyInv; + stopped = mStopped * gClockFrequencyInv; + count = mCount; + mDone = false; + + return true; +} + + +void LLDeadmanTimer::ringBell(U64 now) +{ + if (! mActive) + { + return; + } + + if (! now) + { + now = LLTimer::getCurrentClockCount(); + } + + if (now > mExpires) + { + mActive = false; + mDone = true; + } + else + { + mStopped = now; + mExpires = now + mHorizon; + ++mCount; + } + + return; +} + -- cgit v1.3 From aabda8f3073928980b26530eac9b05eeb85a2207 Mon Sep 17 00:00:00 2001 From: Monty Brandenberg Date: Wed, 10 Apr 2013 16:30:26 +0000 Subject: SH-4089 Unit test work for timer. Knocked off some tests for the deadman's timer. Found some bugs, dig some cleanup and documented a few things. Definitely want to get rid of the U64/F64 interfaces at sometime but this is a good start. --- indra/llcommon/lldeadmantimer.cpp | 26 ++- indra/llcommon/tests/lldeadmantimer_test.cpp | 259 ++++++++++++++++++++++++++- 2 files changed, 272 insertions(+), 13 deletions(-) (limited to 'indra/llcommon/lldeadmantimer.cpp') diff --git a/indra/llcommon/lldeadmantimer.cpp b/indra/llcommon/lldeadmantimer.cpp index 2f48d13c2d..3d3f738c06 100644 --- a/indra/llcommon/lldeadmantimer.cpp +++ b/indra/llcommon/lldeadmantimer.cpp @@ -29,8 +29,21 @@ #include "lldeadmantimer.h" +// *TODO: Currently, this uses lltimer functions for its time +// aspects and this leaks into the apis in the U64s/F64s. Would +// like to perhaps switch this over to TSC register-based timers +// sometime and drop the overhead some more. + + +// Flag states and their meaning: +// mActive mDone Meaning +// false false Nothing running, no result available +// true false Timer running, no result available +// false true Timer finished, result can be read once +// true true Not allowed +// LLDeadmanTimer::LLDeadmanTimer(F64 horizon) - : mHorizon(U64(horizon * gClockFrequency)), + : mHorizon(U64(llmax(horizon, F64(0.0)) * gClockFrequency)), mActive(false), // If true, a timer is running. mDone(false), // If true, timer has completed and can be read (once) mStarted(U64L(0)), @@ -78,19 +91,14 @@ void LLDeadmanTimer::stop(U64 now) bool LLDeadmanTimer::isExpired(F64 & started, F64 & stopped, U64 & count, U64 now) { - if (! mActive) - { - return false; - } - - if (! mDone) + if (mActive && ! mDone) { if (! now) { now = LLTimer::getCurrentClockCount(); } - if (now > mExpires) + if (now >= mExpires) { // mStopped from ringBell() is the value we want mActive = false; @@ -124,7 +132,7 @@ void LLDeadmanTimer::ringBell(U64 now) now = LLTimer::getCurrentClockCount(); } - if (now > mExpires) + if (now >= mExpires) { mActive = false; mDone = true; diff --git a/indra/llcommon/tests/lldeadmantimer_test.cpp b/indra/llcommon/tests/lldeadmantimer_test.cpp index 52a27b9c0a..571d43825f 100644 --- a/indra/llcommon/tests/lldeadmantimer_test.cpp +++ b/indra/llcommon/tests/lldeadmantimer_test.cpp @@ -31,6 +31,20 @@ #include "../test/lltut.h" +// Convert between floating point time deltas and U64 time deltas. +// Reflects an implementation detail inside lldeadmantimer.cpp + +static U64 float_time_to_u64(F64 delta) +{ + return U64(delta * gClockFrequency); +} + +static F64 u64_time_to_float(U64 delta) +{ + return delta * gClockFrequencyInv; +} + + namespace tut { @@ -47,17 +61,254 @@ typedef test_group deadmantimer_group_t; typedef deadmantimer_group_t::object deadmantimer_object_t; tut::deadmantimer_group_t deadmantimer_instance("LLDeadmanTimer"); +// Basic construction test and isExpired() call template<> template<> void deadmantimer_object_t::test<1>() { F64 started(42.0), stopped(97.0); U64 count(U64L(8)); - LLDeadmanTimer timer(1.0); + LLDeadmanTimer timer(10.0); ensure_equals("isExpired() returns false after ctor()", timer.isExpired(started, stopped, count), false); - ensure_approximately_equals("isExpired() does not modify started", started, F64(42.0), 2); - ensure_approximately_equals("isExpired() does not modify stopped", stopped, F64(97.0), 2); - ensure_equals("isExpired() does not modified count", count, U64L(8)); + ensure_approximately_equals("t1 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("t1 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("t1 - isExpired() does not modify count", count, U64L(8)); +} + + +// Construct with negative horizon - not useful generally but will be useful in testing +template<> template<> +void deadmantimer_object_t::test<2>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(0.0); // Zero is pre-expired + + ensure_equals("isExpired() still returns false with 0.0 time ctor()", timer.isExpired(started, stopped, count), false); +} + + +// "pre-expired" timer - starting a timer with a 0.0 horizon will result in +// expiration on first test. +template<> template<> +void deadmantimer_object_t::test<3>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(0.0); + + timer.start(); + ensure_equals("isExpired() returns true with 0.0 horizon time", timer.isExpired(started, stopped, count), true); + ensure_approximately_equals("expired timer with no bell ringing has stopped == started", started, stopped, 8); +} + + +// "pre-expired" timer - bell rings are ignored as we're already expired. +template<> template<> +void deadmantimer_object_t::test<4>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(0.0); + + timer.start(); + timer.ringBell(LLTimer::getCurrentClockCount() + float_time_to_u64(1000.0)); + ensure_equals("isExpired() returns true with 0.0 horizon time after bell ring", timer.isExpired(started, stopped, count), true); + ensure_approximately_equals("ringBell has no impact on expired timer leaving stopped == started", started, stopped, 8); +} + + +// start() test - unexpired timer reports unexpired +template<> template<> +void deadmantimer_object_t::test<5>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0); + + timer.start(); + ensure_equals("isExpired() returns false after starting with 10.0 horizon time", timer.isExpired(started, stopped, count), false); + ensure_approximately_equals("t5 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("t5 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("t5 - isExpired() does not modify count", count, U64L(8)); } + +// start() test - start in the past but not beyond 1 horizon +template<> template<> +void deadmantimer_object_t::test<6>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0); + + U64 the_past(LLTimer::getCurrentClockCount() - float_time_to_u64(5.0)); + timer.start(the_past); + ensure_equals("isExpired() returns false with 10.0 horizon time starting 5.0 in past", timer.isExpired(started, stopped, count), false); + ensure_approximately_equals("t6 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("t6 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("t6 - isExpired() does not modify count", count, U64L(8)); +} + + +// start() test - start in the past but well beyond 1 horizon +template<> template<> +void deadmantimer_object_t::test<7>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0); + + U64 the_past(LLTimer::getCurrentClockCount() - float_time_to_u64(20.0)); + timer.start(the_past); + ensure_equals("isExpired() returns true with 10.0 horizon time starting 20.0 in past", timer.isExpired(started, stopped, count), true); + ensure_approximately_equals("starting before horizon still gives equal started / stopped", started, stopped, 8); +} + + +// isExpired() test - results are read-once. Probes after first true are false. +template<> template<> +void deadmantimer_object_t::test<8>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0); + + U64 the_past(LLTimer::getCurrentClockCount() - float_time_to_u64(20.0)); + timer.start(the_past); + ensure_equals("t8 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", timer.isExpired(started, stopped, count), true); + + started = 42.0; + stopped = 97.0; + count = U64L(8); + ensure_equals("t8 - second isExpired() returns false after true", timer.isExpired(started, stopped, count), false); + ensure_approximately_equals("t8 - 2nd isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("t8 - 2nd isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("t8 - 2nd isExpired() does not modify count", count, U64L(8)); +} + + +// ringBell() test - see that we can keep a timer from expiring +template<> template<> +void deadmantimer_object_t::test<9>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(5.0); + + U64 now(LLTimer::getCurrentClockCount()); + F64 real_start(u64_time_to_float(now)); + timer.start(); + + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + ensure_equals("t9 - 5.0 horizon timer has not timed out after 10 1-second bell rings", timer.isExpired(started, stopped, count, now), false); + F64 last_good_ring(u64_time_to_float(now)); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("t9 - 5.0 horizon timer expires on 10-second jump", timer.isExpired(started, stopped, count, now), true); + ensure_approximately_equals("t9 - started matches start() time", started, real_start, 4); + ensure_approximately_equals("t9 - stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("t9 - 10 good ringBell()s", count, U64L(10)); + ensure_equals("t9 - single read only", timer.isExpired(started, stopped, count, now), false); +} + + +// restart after expiration test - verify that restarts behave well +template<> template<> +void deadmantimer_object_t::test<10>() +{ + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(5.0); + + U64 now(LLTimer::getCurrentClockCount()); + F64 real_start(u64_time_to_float(now)); + timer.start(); + + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + ensure_equals("t10 - 5.0 horizon timer has not timed out after 10 1-second bell rings", timer.isExpired(started, stopped, count, now), false); + F64 last_good_ring(u64_time_to_float(now)); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("t10 - 5.0 horizon timer expires on 10-second jump", timer.isExpired(started, stopped, count, now), true); + ensure_approximately_equals("t10 - started matches start() time", started, real_start, 4); + ensure_approximately_equals("t10 - stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("t10 - 10 good ringBell()s", count, U64L(10)); + ensure_equals("t10 - single read only", timer.isExpired(started, stopped, count, now), false); + + // Jump forward and restart + now += float_time_to_u64(1.0); + real_start = u64_time_to_float(now); + timer.start(now); + + // Run a modified bell ring sequence + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + now += float_time_to_u64(1.0); + timer.ringBell(now); + ensure_equals("t10 - 5.0 horizon timer has not timed out after 8 1-second bell rings", timer.isExpired(started, stopped, count, now), false); + last_good_ring = u64_time_to_float(now); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("t10 - 5.0 horizon timer expires on 8-second jump", timer.isExpired(started, stopped, count, now), true); + ensure_approximately_equals("t10 - 2nd started matches start() time", started, real_start, 4); + ensure_approximately_equals("t10 - 2nd stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("t10 - 8 good ringBell()s", count, U64L(8)); + ensure_equals("t10 - single read only - 2nd start", timer.isExpired(started, stopped, count, now), false); +} + + } // end namespace tut -- cgit v1.3 From e59d59878200d25dc6e94753026d986d2704ab8d Mon Sep 17 00:00:00 2001 From: Monty Brandenberg Date: Wed, 17 Apr 2013 18:30:46 -0400 Subject: SH-4090 Integrating deadman timer with mesh repo downloads. Timer interface violated my design rules and I paid for it with clumsiness and silent errors. Cleaned it up mainly removing the evil default values. Found better integration points in the mesh downloader and it's producing fairly consistent numbers on the MeshTest2 test region (about 5500 downloads, ~90 seconds, +/- 10 seconds). Will review with davep and do an early timer stop on teleport which invalidates a timing sequence. --- indra/llcommon/lldeadmantimer.cpp | 25 +++-- indra/llcommon/lldeadmantimer.h | 59 +++++++---- indra/llcommon/tests/lldeadmantimer_test.cpp | 143 +++++++++++++++------------ indra/newview/llmeshrepository.cpp | 48 ++++++--- indra/newview/llmeshrepository.h | 3 +- 5 files changed, 174 insertions(+), 104 deletions(-) (limited to 'indra/llcommon/lldeadmantimer.cpp') diff --git a/indra/llcommon/lldeadmantimer.cpp b/indra/llcommon/lldeadmantimer.cpp index 3d3f738c06..2a356d857a 100644 --- a/indra/llcommon/lldeadmantimer.cpp +++ b/indra/llcommon/lldeadmantimer.cpp @@ -43,7 +43,7 @@ // true true Not allowed // LLDeadmanTimer::LLDeadmanTimer(F64 horizon) - : mHorizon(U64(llmax(horizon, F64(0.0)) * gClockFrequency)), + : mHorizon(time_type(llmax(horizon, F64(0.0)) * gClockFrequency)), mActive(false), // If true, a timer is running. mDone(false), // If true, timer has completed and can be read (once) mStarted(U64L(0)), @@ -53,7 +53,14 @@ LLDeadmanTimer::LLDeadmanTimer(F64 horizon) {} -void LLDeadmanTimer::start(U64 now) +// static +LLDeadmanTimer::time_type LLDeadmanTimer::getNow() +{ + return LLTimer::getCurrentClockCount(); +} + + +void LLDeadmanTimer::start(time_type now) { // *TODO: If active, let's complete an existing timer and save // the result to the side. I think this will be useful later. @@ -72,7 +79,7 @@ void LLDeadmanTimer::start(U64 now) } -void LLDeadmanTimer::stop(U64 now) +void LLDeadmanTimer::stop(time_type now) { if (! mActive) { @@ -81,7 +88,7 @@ void LLDeadmanTimer::stop(U64 now) if (! now) { - now = LLTimer::getCurrentClockCount(); + now = getNow(); } mStopped = now; mActive = false; @@ -89,13 +96,13 @@ void LLDeadmanTimer::stop(U64 now) } -bool LLDeadmanTimer::isExpired(F64 & started, F64 & stopped, U64 & count, U64 now) +bool LLDeadmanTimer::isExpired(time_type now, F64 & started, F64 & stopped, U64 & count) { if (mActive && ! mDone) { if (! now) { - now = LLTimer::getCurrentClockCount(); + now = getNow(); } if (now >= mExpires) @@ -120,7 +127,7 @@ bool LLDeadmanTimer::isExpired(F64 & started, F64 & stopped, U64 & count, U64 no } -void LLDeadmanTimer::ringBell(U64 now) +void LLDeadmanTimer::ringBell(time_type now, unsigned int count) { if (! mActive) { @@ -129,7 +136,7 @@ void LLDeadmanTimer::ringBell(U64 now) if (! now) { - now = LLTimer::getCurrentClockCount(); + now = getNow(); } if (now >= mExpires) @@ -141,7 +148,7 @@ void LLDeadmanTimer::ringBell(U64 now) { mStopped = now; mExpires = now + mHorizon; - ++mCount; + mCount += count; } return; diff --git a/indra/llcommon/lldeadmantimer.h b/indra/llcommon/lldeadmantimer.h index 84023723ab..8643b8cad8 100644 --- a/indra/llcommon/lldeadmantimer.h +++ b/indra/llcommon/lldeadmantimer.h @@ -76,6 +76,16 @@ class LL_COMMON_API LLDeadmanTimer { +public: + /// Public types + + /// Low-level time type chosen for compatibility with + /// LLTimer::getCurrentClockCount() which is the basis + /// of time operations in this class. This is likely + /// to change in a future version in a move to TSC-based + /// timing. + typedef U64 time_type; + public: /// Construct and initialize an LLDeadmanTimer /// @@ -93,6 +103,18 @@ private: void operator=(const LLDeadmanTimer &); // Not defined public: + /// Get the current time. Zero-basis for this time + /// representation is not defined and is different on + /// different platforms. Do not attempt to compute + /// negative times relative to the first value returned, + /// there may not be enough 'front porch' on the range + /// to prevent wraparound. + /// + /// Note: Implementation is expected to change in a + /// future release as well. + /// + static time_type getNow(); + /// Begin timing. If the timer is already active, it is reset /// and timing begins now. /// @@ -100,8 +122,7 @@ public: /// LLTimer::getCurrentClockCount(). If zero, /// method will lookup current time. /// - void start(U64 now = U64L(0)); - + void start(time_type now); /// End timing. Actively declare the end of the event independent /// of the deadman's switch operation. @see isExpired() will return @@ -111,28 +132,34 @@ public: /// LLTimer::getCurrentClockCount(). If zero, /// method will lookup current time. /// - void stop(U64 now = U64L(0)); - + void stop(time_type now); /// Declare that something interesting happened. This has two /// effects on an unexpired-timer. 1) The expiration time /// is extended for 'horizon' seconds after the 'now' value. - /// 2) An internal counter associated with the event is incremented. - /// This count is returned via the @see isExpired() method. + /// 2) An internal counter associated with the event is incremented + /// by the @ref count parameter. This count is returned via the + /// @see isExpired() method. /// /// @param now Current time as returned by @see /// LLTimer::getCurrentClockCount(). If zero, /// method will lookup current time. /// - void ringBell(U64 now = U64L(0)); + /// @param count Count of events to be associated with + /// this bell ringing. + /// + void ringBell(time_type now, unsigned int count); - /// Checks on the status of the timer Declare that something interesting happened. This has two /// effects on an unexpired-timer. 1) The expiration time /// is extended for 'horizon' seconds after the 'now' value. /// 2) An internal counter associated with the event is incremented. /// This count is returned via the @see isExpired() method. /// + /// @param now Current time as returned by @see + /// LLTimer::getCurrentClockCount(). If zero, + /// method will lookup current time. + /// /// @param started If expired, the starting time of the event is /// returned to the caller via this reference. /// @@ -146,25 +173,21 @@ public: /// @param count If expired, the number of ringBell() calls /// made prior to expiration. /// - /// @param now Current time as returned by @see - /// LLTimer::getCurrentClockCount(). If zero, - /// method will lookup current time. - /// /// @return true if the timer has expired, false otherwise. /// If true, it also returns the started, /// stopped and count values otherwise these are /// left unchanged. /// - bool isExpired(F64 & started, F64 & stopped, U64 & count, U64 now = U64L(0)); + bool isExpired(time_type now, F64 & started, F64 & stopped, U64 & count); protected: - U64 mHorizon; + time_type mHorizon; bool mActive; bool mDone; - U64 mStarted; - U64 mExpires; - U64 mStopped; - U64 mCount; + time_type mStarted; + time_type mExpires; + time_type mStopped; + time_type mCount; }; diff --git a/indra/llcommon/tests/lldeadmantimer_test.cpp b/indra/llcommon/tests/lldeadmantimer_test.cpp index 40e354115b..63cab29e04 100644 --- a/indra/llcommon/tests/lldeadmantimer_test.cpp +++ b/indra/llcommon/tests/lldeadmantimer_test.cpp @@ -34,12 +34,12 @@ // Convert between floating point time deltas and U64 time deltas. // Reflects an implementation detail inside lldeadmantimer.cpp -static U64 float_time_to_u64(F64 delta) +static LLDeadmanTimer::time_type float_time_to_u64(F64 delta) { - return U64(delta * gClockFrequency); + return LLDeadmanTimer::time_type(delta * gClockFrequency); } -static F64 u64_time_to_float(U64 delta) +static F64 u64_time_to_float(LLDeadmanTimer::time_type delta) { return delta * gClockFrequencyInv; } @@ -69,7 +69,7 @@ void deadmantimer_object_t::test<1>() U64 count(U64L(8)); LLDeadmanTimer timer(10.0); - ensure_equals("isExpired() returns false after ctor()", timer.isExpired(started, stopped, count), false); + ensure_equals("isExpired() returns false after ctor()", timer.isExpired(0, started, stopped, count), false); ensure_approximately_equals("t1 - isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("t1 - isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("t1 - isExpired() does not modify count", count, U64L(8)); @@ -84,7 +84,8 @@ void deadmantimer_object_t::test<2>() U64 count(U64L(8)); LLDeadmanTimer timer(0.0); // Zero is pre-expired - ensure_equals("isExpired() still returns false with 0.0 time ctor()", timer.isExpired(started, stopped, count), false); + ensure_equals("isExpired() still returns false with 0.0 time ctor()", + timer.isExpired(0, started, stopped, count), false); } @@ -97,8 +98,9 @@ void deadmantimer_object_t::test<3>() U64 count(U64L(8)); LLDeadmanTimer timer(0.0); - timer.start(); - ensure_equals("isExpired() returns true with 0.0 horizon time", timer.isExpired(started, stopped, count), true); + timer.start(0); + ensure_equals("isExpired() returns true with 0.0 horizon time", + timer.isExpired(0, started, stopped, count), true); ensure_approximately_equals("expired timer with no bell ringing has stopped == started", started, stopped, 8); } @@ -111,14 +113,15 @@ void deadmantimer_object_t::test<4>() U64 count(U64L(8)); LLDeadmanTimer timer(0.0); - timer.start(); - timer.ringBell(LLTimer::getCurrentClockCount() + float_time_to_u64(1000.0)); - ensure_equals("isExpired() returns true with 0.0 horizon time after bell ring", timer.isExpired(started, stopped, count), true); + timer.start(0); + timer.ringBell(LLDeadmanTimer::getNow() + float_time_to_u64(1000.0), 1); + ensure_equals("isExpired() returns true with 0.0 horizon time after bell ring", + timer.isExpired(0, started, stopped, count), true); ensure_approximately_equals("ringBell has no impact on expired timer leaving stopped == started", started, stopped, 8); } -// start() test - unexpired timer reports unexpired +// start(0) test - unexpired timer reports unexpired template<> template<> void deadmantimer_object_t::test<5>() { @@ -126,8 +129,9 @@ void deadmantimer_object_t::test<5>() U64 count(U64L(8)); LLDeadmanTimer timer(10.0); - timer.start(); - ensure_equals("isExpired() returns false after starting with 10.0 horizon time", timer.isExpired(started, stopped, count), false); + timer.start(0); + ensure_equals("isExpired() returns false after starting with 10.0 horizon time", + timer.isExpired(0, started, stopped, count), false); ensure_approximately_equals("t5 - isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("t5 - isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("t5 - isExpired() does not modify count", count, U64L(8)); @@ -146,10 +150,11 @@ void deadmantimer_object_t::test<6>() // the implementation on Windows is zero-based. We wrap around // the backside resulting in a large U64 number. - U64 the_past(LLTimer::getCurrentClockCount()); - U64 now(the_past + float_time_to_u64(5.0)); + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(5.0)); timer.start(the_past); - ensure_equals("isExpired() returns false with 10.0 horizon time starting 5.0 in past", timer.isExpired(started, stopped, count, now), false); + ensure_equals("isExpired() returns false with 10.0 horizon time starting 5.0 in past", + timer.isExpired(now, started, stopped, count), false); ensure_approximately_equals("t6 - isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("t6 - isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("t6 - isExpired() does not modify count", count, U64L(8)); @@ -168,10 +173,11 @@ void deadmantimer_object_t::test<7>() // the implementation on Windows is zero-based. We wrap around // the backside resulting in a large U64 number. - U64 the_past(LLTimer::getCurrentClockCount()); - U64 now(the_past + float_time_to_u64(20.0)); + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); timer.start(the_past); - ensure_equals("isExpired() returns true with 10.0 horizon time starting 20.0 in past", timer.isExpired(started, stopped, count, now), true); + ensure_equals("isExpired() returns true with 10.0 horizon time starting 20.0 in past", + timer.isExpired(now,started, stopped, count), true); ensure_approximately_equals("starting before horizon still gives equal started / stopped", started, stopped, 8); } @@ -188,15 +194,17 @@ void deadmantimer_object_t::test<8>() // the implementation on Windows is zero-based. We wrap around // the backside resulting in a large U64 number. - U64 the_past(LLTimer::getCurrentClockCount()); - U64 now(the_past + float_time_to_u64(20.0)); + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); timer.start(the_past); - ensure_equals("t8 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", timer.isExpired(started, stopped, count, now), true); + ensure_equals("t8 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", + timer.isExpired(now, started, stopped, count), true); started = 42.0; stopped = 97.0; count = U64L(8); - ensure_equals("t8 - second isExpired() returns false after true", timer.isExpired(started, stopped, count, now), false); + ensure_equals("t8 - second isExpired() returns false after true", + timer.isExpired(now, started, stopped, count), false); ensure_approximately_equals("t8 - 2nd isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("t8 - 2nd isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("t8 - 2nd isExpired() does not modify count", count, U64L(8)); @@ -211,40 +219,42 @@ void deadmantimer_object_t::test<9>() U64 count(U64L(8)); LLDeadmanTimer timer(5.0); - U64 now(LLTimer::getCurrentClockCount()); + LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); F64 real_start(u64_time_to_float(now)); - timer.start(); + timer.start(0); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); - ensure_equals("t9 - 5.0 horizon timer has not timed out after 10 1-second bell rings", timer.isExpired(started, stopped, count, now), false); + timer.ringBell(now, 1); + ensure_equals("t9 - 5.0 horizon timer has not timed out after 10 1-second bell rings", + timer.isExpired(now, started, stopped, count), false); F64 last_good_ring(u64_time_to_float(now)); // Jump forward and expire now += float_time_to_u64(10.0); - ensure_equals("t9 - 5.0 horizon timer expires on 10-second jump", timer.isExpired(started, stopped, count, now), true); + ensure_equals("t9 - 5.0 horizon timer expires on 10-second jump", + timer.isExpired(now, started, stopped, count), true); ensure_approximately_equals("t9 - started matches start() time", started, real_start, 4); ensure_approximately_equals("t9 - stopped matches last ringBell() time", stopped, last_good_ring, 4); ensure_equals("t9 - 10 good ringBell()s", count, U64L(10)); - ensure_equals("t9 - single read only", timer.isExpired(started, stopped, count, now), false); + ensure_equals("t9 - single read only", timer.isExpired(now, started, stopped, count), false); } @@ -256,40 +266,42 @@ void deadmantimer_object_t::test<10>() U64 count(U64L(8)); LLDeadmanTimer timer(5.0); - U64 now(LLTimer::getCurrentClockCount()); + LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); F64 real_start(u64_time_to_float(now)); - timer.start(); + timer.start(0); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); - ensure_equals("t10 - 5.0 horizon timer has not timed out after 10 1-second bell rings", timer.isExpired(started, stopped, count, now), false); + timer.ringBell(now, 1); + ensure_equals("t10 - 5.0 horizon timer has not timed out after 10 1-second bell rings", + timer.isExpired(now, started, stopped, count), false); F64 last_good_ring(u64_time_to_float(now)); // Jump forward and expire now += float_time_to_u64(10.0); - ensure_equals("t10 - 5.0 horizon timer expires on 10-second jump", timer.isExpired(started, stopped, count, now), true); + ensure_equals("t10 - 5.0 horizon timer expires on 10-second jump", + timer.isExpired(now, started, stopped, count), true); ensure_approximately_equals("t10 - started matches start() time", started, real_start, 4); ensure_approximately_equals("t10 - stopped matches last ringBell() time", stopped, last_good_ring, 4); ensure_equals("t10 - 10 good ringBell()s", count, U64L(10)); - ensure_equals("t10 - single read only", timer.isExpired(started, stopped, count, now), false); + ensure_equals("t10 - single read only", timer.isExpired(now, started, stopped, count), false); // Jump forward and restart now += float_time_to_u64(1.0); @@ -298,31 +310,34 @@ void deadmantimer_object_t::test<10>() // Run a modified bell ring sequence now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); + timer.ringBell(now, 1); now += float_time_to_u64(1.0); - timer.ringBell(now); - ensure_equals("t10 - 5.0 horizon timer has not timed out after 8 1-second bell rings", timer.isExpired(started, stopped, count, now), false); + timer.ringBell(now, 1); + ensure_equals("t10 - 5.0 horizon timer has not timed out after 8 1-second bell rings", + timer.isExpired(now, started, stopped, count), false); last_good_ring = u64_time_to_float(now); // Jump forward and expire now += float_time_to_u64(10.0); - ensure_equals("t10 - 5.0 horizon timer expires on 8-second jump", timer.isExpired(started, stopped, count, now), true); + ensure_equals("t10 - 5.0 horizon timer expires on 8-second jump", + timer.isExpired(now, started, stopped, count), true); ensure_approximately_equals("t10 - 2nd started matches start() time", started, real_start, 4); ensure_approximately_equals("t10 - 2nd stopped matches last ringBell() time", stopped, last_good_ring, 4); ensure_equals("t10 - 8 good ringBell()s", count, U64L(8)); - ensure_equals("t10 - single read only - 2nd start", timer.isExpired(started, stopped, count, now), false); + ensure_equals("t10 - single read only - 2nd start", + timer.isExpired(now, started, stopped, count), false); } diff --git a/indra/newview/llmeshrepository.cpp b/indra/newview/llmeshrepository.cpp index 11c5780a30..8f97f3e71a 100755 --- a/indra/newview/llmeshrepository.cpp +++ b/indra/newview/llmeshrepository.cpp @@ -2168,6 +2168,9 @@ void LLMeshHeaderResponder::completedRaw(U32 status, const std::string& reason, if (status < 200 || status > 400) { + // Manage time-to-load metrics for mesh download operations. + LLMeshRepository::metricsProgress(0); + //llwarns // << "Header responder failed with status: " // << status << ": " << reason << llendl; @@ -2358,6 +2361,9 @@ void LLMeshRepository::shutdown() //called in the main thread. S32 LLMeshRepository::update() { + // Conditionally log a mesh metrics event + metricsUpdate(); + if(mUploadWaitList.empty()) { return 0 ; @@ -2377,6 +2383,9 @@ S32 LLMeshRepository::update() S32 LLMeshRepository::loadMesh(LLVOVolume* vobj, const LLVolumeParams& mesh_params, S32 detail, S32 last_lod) { + // Manage time-to-load metrics for mesh download operations. + metricsProgress(1); + if (detail < 0 || detail > 4) { return detail; @@ -2680,7 +2689,7 @@ void LLMeshRepository::notifyDecompositionReceived(LLModel::Decomposition* decom void LLMeshRepository::notifyMeshLoaded(const LLVolumeParams& mesh_params, LLVolume* volume) { //called from main thread // Manage time-to-load metrics for mesh download operations. - metricsCheck(); + metricsProgress(0); S32 detail = LLVolumeLODGroup::getVolumeDetailFromScale(volume->getDetail()); @@ -2725,6 +2734,9 @@ void LLMeshRepository::notifyMeshLoaded(const LLVolumeParams& mesh_params, LLVol void LLMeshRepository::notifyMeshUnavailable(const LLVolumeParams& mesh_params, S32 lod) { //called from main thread + // Manage time-to-load metrics for mesh download operations. + metricsProgress(0); + //get list of objects waiting to be notified this mesh is loaded mesh_load_map::iterator obj_iter = mLoadingMeshes[lod].find(mesh_params); @@ -3704,39 +3716,51 @@ bool LLMeshRepository::meshRezEnabled() return false; } +// Threading: main thread only +// static void LLMeshRepository::metricsStart() { - sQuiescentTimer.start(); + sQuiescentTimer.start(0); } +// Threading: main thread only +// static void LLMeshRepository::metricsStop() { - sQuiescentTimer.stop(); + sQuiescentTimer.stop(0); } -void LLMeshRepository::metricsCheck() +// Threading: main thread only +// static +void LLMeshRepository::metricsProgress(unsigned int this_count) { static bool first_start(true); - F64 started, stopped; - U64 count; - if (first_start) { // Let the first request start the timing cycle for login. metricsStart(); first_start = false; } - sQuiescentTimer.ringBell(); - if (sQuiescentTimer.isExpired(started, stopped, count)) + sQuiescentTimer.ringBell(0, this_count); +} + +// Threading: main thread only +// static +void LLMeshRepository::metricsUpdate() +{ + F64 started, stopped; + U64 total_count; + + if (sQuiescentTimer.isExpired(0, started, stopped, total_count)) { LLSD metrics; - metrics["reason"] = "Mesh download quiescent"; + metrics["reason"] = "Mesh Download Quiescent"; metrics["scope"] = "Login"; metrics["start"] = started; metrics["stop"] = stopped; - metrics["downloads"] = LLSD::Integer(count); - llinfos << "MetricsMarker" << metrics << llendl; + metrics["downloads"] = LLSD::Integer(total_count); + llinfos << "EventMarker " << metrics << llendl; } } diff --git a/indra/newview/llmeshrepository.h b/indra/newview/llmeshrepository.h index f08feedf81..3cdc66e1f0 100644 --- a/indra/newview/llmeshrepository.h +++ b/indra/newview/llmeshrepository.h @@ -500,7 +500,8 @@ public: // Quiescent timer management, main thread only. static void metricsStart(); static void metricsStop(); - static void metricsCheck(); + static void metricsProgress(unsigned int count); + static void metricsUpdate(); typedef std::map > mesh_load_map; mesh_load_map mLoadingMeshes[4]; -- cgit v1.3 From 11cca95187f01f594172ca950315dcd8d99dc2c3 Mon Sep 17 00:00:00 2001 From: Monty Brandenberg Date: Thu, 2 May 2013 21:59:53 +0000 Subject: SH-4161 Integrate cpu metrics into LLDeadmanTimer and then metrics viewer Integrated as a ctor-time option to LLDeadmanTimer and have mesh use this mode for the stats I'm gathering. --- indra/llcommon/lldeadmantimer.cpp | 36 +- indra/llcommon/lldeadmantimer.h | 38 +- indra/llcommon/tests/lldeadmantimer_test.cpp | 701 +++++++++++++++++++-------- indra/newview/llmeshrepository.cpp | 2 +- 4 files changed, 562 insertions(+), 215 deletions(-) (limited to 'indra/llcommon/lldeadmantimer.cpp') diff --git a/indra/llcommon/lldeadmantimer.cpp b/indra/llcommon/lldeadmantimer.cpp index 2a356d857a..2ba757d2af 100644 --- a/indra/llcommon/lldeadmantimer.cpp +++ b/indra/llcommon/lldeadmantimer.cpp @@ -42,14 +42,19 @@ // false true Timer finished, result can be read once // true true Not allowed // -LLDeadmanTimer::LLDeadmanTimer(F64 horizon) +LLDeadmanTimer::LLDeadmanTimer(F64 horizon, bool inc_cpu) : mHorizon(time_type(llmax(horizon, F64(0.0)) * gClockFrequency)), mActive(false), // If true, a timer is running. mDone(false), // If true, timer has completed and can be read (once) mStarted(U64L(0)), mExpires(U64L(0)), mStopped(U64L(0)), - mCount(U64L(0)) + mCount(U64L(0)), + mIncCPU(inc_cpu), + mUStartCPU(LLProcInfo::time_type(U64L(0))), + mUEndCPU(LLProcInfo::time_type(U64L(0))), + mSStartCPU(LLProcInfo::time_type(U64L(0))), + mSEndCPU(LLProcInfo::time_type(U64L(0))) {} @@ -76,6 +81,10 @@ void LLDeadmanTimer::start(time_type now) mExpires = now + mHorizon; mStopped = now; mCount = U64L(0); + if (mIncCPU) + { + LLProcInfo::getCPUUsage(mUStartCPU, mSStartCPU); + } } @@ -93,9 +102,26 @@ void LLDeadmanTimer::stop(time_type now) mStopped = now; mActive = false; mDone = true; + if (mIncCPU) + { + LLProcInfo::getCPUUsage(mUEndCPU, mSEndCPU); + } } +bool LLDeadmanTimer::isExpired(time_type now, F64 & started, F64 & stopped, U64 & count, + LLProcInfo::time_type & user_cpu, LLProcInfo::time_type & sys_cpu) +{ + const bool status(isExpired(now, started, stopped, count)); + if (status) + { + user_cpu = mUEndCPU - mUStartCPU; + sys_cpu = mSEndCPU - mSStartCPU; + } + return status; +} + + bool LLDeadmanTimer::isExpired(time_type now, F64 & started, F64 & stopped, U64 & count) { if (mActive && ! mDone) @@ -141,14 +167,20 @@ void LLDeadmanTimer::ringBell(time_type now, unsigned int count) if (now >= mExpires) { + // Timer has expired, this event will be dropped mActive = false; mDone = true; } else { + // Timer renewed, keep going mStopped = now; mExpires = now + mHorizon; mCount += count; + if (mIncCPU) + { + LLProcInfo::getCPUUsage(mUEndCPU, mSEndCPU); + } } return; diff --git a/indra/llcommon/lldeadmantimer.h b/indra/llcommon/lldeadmantimer.h index 8643b8cad8..a6022852b9 100644 --- a/indra/llcommon/lldeadmantimer.h +++ b/indra/llcommon/lldeadmantimer.h @@ -32,6 +32,7 @@ #include "linden_common.h" #include "lltimer.h" +#include "llprocinfo.h" /// @file lldeadmantimer.h @@ -93,7 +94,11 @@ public: /// call at which point the timer will consider itself /// expired. /// - LLDeadmanTimer(F64 horizon); + /// @param inc_cpu If true, gather system and user cpu stats while + /// running the timer. This does require more syscalls + /// during updates. If false, cpu usage data isn't + /// collected and will be zero if queried. + LLDeadmanTimer(F64 horizon, bool inc_cpu); ~LLDeadmanTimer() {} @@ -173,21 +178,38 @@ public: /// @param count If expired, the number of ringBell() calls /// made prior to expiration. /// + /// @param user_cpu Amount of CPU spent in user mode by the process + /// during the event. Value in microseconds and will + /// read zero if not enabled by the constructor. + /// + /// @param sys_cpu Amount of CPU spent in system mode by the process. + /// /// @return true if the timer has expired, false otherwise. /// If true, it also returns the started, /// stopped and count values otherwise these are /// left unchanged. /// + bool isExpired(time_type now, F64 & started, F64 & stopped, U64 & count, + LLProcInfo::time_type & user_cpu, LLProcInfo::time_type & sys_cpu); + + /// Identical to the six-arugment form except is does without the + /// CPU time return if the caller isn't interested in it. bool isExpired(time_type now, F64 & started, F64 & stopped, U64 & count); protected: - time_type mHorizon; - bool mActive; - bool mDone; - time_type mStarted; - time_type mExpires; - time_type mStopped; - time_type mCount; + time_type mHorizon; + bool mActive; + bool mDone; + time_type mStarted; + time_type mExpires; + time_type mStopped; + time_type mCount; + + const bool mIncCPU; // Include CPU metrics in timer + LLProcInfo::time_type mUStartCPU; + LLProcInfo::time_type mUEndCPU; + LLProcInfo::time_type mSStartCPU; + LLProcInfo::time_type mSEndCPU; }; diff --git a/indra/llcommon/tests/lldeadmantimer_test.cpp b/indra/llcommon/tests/lldeadmantimer_test.cpp index 63cab29e04..a4ec76a016 100644 --- a/indra/llcommon/tests/lldeadmantimer_test.cpp +++ b/indra/llcommon/tests/lldeadmantimer_test.cpp @@ -28,6 +28,7 @@ #include "../lldeadmantimer.h" #include "../llsd.h" +#include "../lltimer.h" #include "../test/lltut.h" @@ -65,14 +66,32 @@ tut::deadmantimer_group_t deadmantimer_instance("LLDeadmanTimer"); template<> template<> void deadmantimer_object_t::test<1>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(10.0); - - ensure_equals("isExpired() returns false after ctor()", timer.isExpired(0, started, stopped, count), false); - ensure_approximately_equals("t1 - isExpired() does not modify started", started, F64(42.0), 2); - ensure_approximately_equals("t1 - isExpired() does not modify stopped", stopped, F64(97.0), 2); - ensure_equals("t1 - isExpired() does not modify count", count, U64L(8)); + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0, false); + + ensure_equals("WOCM isExpired() returns false after ctor()", timer.isExpired(0, started, stopped, count), false); + ensure_approximately_equals("WOCM t1 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WOCM t1 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("WOCM t1 - isExpired() does not modify count", count, U64L(8)); + } + + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + LLDeadmanTimer timer(10.0, true); + + ensure_equals("WCM isExpired() returns false after ctor()", timer.isExpired(0, started, stopped, count, user_cpu, sys_cpu), false); + ensure_approximately_equals("WCM t1 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WCM t1 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("WCM t1 - isExpired() does not modify count", count, U64L(8)); + ensure_equals("WCM t1 - isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); + ensure_equals("WCM t1 - isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + } } @@ -80,12 +99,26 @@ void deadmantimer_object_t::test<1>() template<> template<> void deadmantimer_object_t::test<2>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(0.0); // Zero is pre-expired - - ensure_equals("isExpired() still returns false with 0.0 time ctor()", - timer.isExpired(0, started, stopped, count), false); + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(0.0, false); // Zero is pre-expired + + ensure_equals("WOCM isExpired() still returns false with 0.0 time ctor()", + timer.isExpired(0, started, stopped, count), false); + } + + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + LLDeadmanTimer timer(0.0, true); // Zero is pre-expired + + ensure_equals("WCM isExpired() still returns false with 0.0 time ctor()", + timer.isExpired(0, started, stopped, count, user_cpu, sys_cpu), false); + } } @@ -94,14 +127,29 @@ void deadmantimer_object_t::test<2>() template<> template<> void deadmantimer_object_t::test<3>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(0.0); - - timer.start(0); - ensure_equals("isExpired() returns true with 0.0 horizon time", - timer.isExpired(0, started, stopped, count), true); - ensure_approximately_equals("expired timer with no bell ringing has stopped == started", started, stopped, 8); + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(0.0, false); + + timer.start(0); + ensure_equals("WOCM isExpired() returns true with 0.0 horizon time", + timer.isExpired(0, started, stopped, count), true); + ensure_approximately_equals("WOCM expired timer with no bell ringing has stopped == started", started, stopped, 8); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + LLDeadmanTimer timer(0.0, true); + + timer.start(0); + ensure_equals("WCM isExpired() returns true with 0.0 horizon time", + timer.isExpired(0, started, stopped, count, user_cpu, sys_cpu), true); + ensure_approximately_equals("WCM expired timer with no bell ringing has stopped == started", started, stopped, 8); + } } @@ -109,15 +157,31 @@ void deadmantimer_object_t::test<3>() template<> template<> void deadmantimer_object_t::test<4>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(0.0); + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(0.0, false); + + timer.start(0); + timer.ringBell(LLDeadmanTimer::getNow() + float_time_to_u64(1000.0), 1); + ensure_equals("WOCM isExpired() returns true with 0.0 horizon time after bell ring", + timer.isExpired(0, started, stopped, count), true); + ensure_approximately_equals("WOCM ringBell has no impact on expired timer leaving stopped == started", started, stopped, 8); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + LLDeadmanTimer timer(0.0, true); - timer.start(0); - timer.ringBell(LLDeadmanTimer::getNow() + float_time_to_u64(1000.0), 1); - ensure_equals("isExpired() returns true with 0.0 horizon time after bell ring", - timer.isExpired(0, started, stopped, count), true); - ensure_approximately_equals("ringBell has no impact on expired timer leaving stopped == started", started, stopped, 8); + timer.start(0); + timer.ringBell(LLDeadmanTimer::getNow() + float_time_to_u64(1000.0), 1); + ensure_equals("WCM isExpired() returns true with 0.0 horizon time after bell ring", + timer.isExpired(0, started, stopped, count, user_cpu, sys_cpu), true); + ensure_approximately_equals("WCM ringBell has no impact on expired timer leaving stopped == started", started, stopped, 8); + } } @@ -125,16 +189,35 @@ void deadmantimer_object_t::test<4>() template<> template<> void deadmantimer_object_t::test<5>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(10.0); + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0, false); + + timer.start(0); + ensure_equals("WOCM isExpired() returns false after starting with 10.0 horizon time", + timer.isExpired(0, started, stopped, count), false); + ensure_approximately_equals("WOCM t5 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WOCM t5 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("WOCM t5 - isExpired() does not modify count", count, U64L(8)); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + LLDeadmanTimer timer(10.0, true); - timer.start(0); - ensure_equals("isExpired() returns false after starting with 10.0 horizon time", - timer.isExpired(0, started, stopped, count), false); - ensure_approximately_equals("t5 - isExpired() does not modify started", started, F64(42.0), 2); - ensure_approximately_equals("t5 - isExpired() does not modify stopped", stopped, F64(97.0), 2); - ensure_equals("t5 - isExpired() does not modify count", count, U64L(8)); + timer.start(0); + ensure_equals("WCM isExpired() returns false after starting with 10.0 horizon time", + timer.isExpired(0, started, stopped, count, user_cpu, sys_cpu), false); + ensure_approximately_equals("WCM t5 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WCM t5 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("WCM t5 - isExpired() does not modify count", count, U64L(8)); + ensure_equals("WCM t5 - isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); + ensure_equals("WCM t5 - isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + } } @@ -142,22 +225,47 @@ void deadmantimer_object_t::test<5>() template<> template<> void deadmantimer_object_t::test<6>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(10.0); - - // Would like to do subtraction on current time but can't because - // the implementation on Windows is zero-based. We wrap around - // the backside resulting in a large U64 number. + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0, false); + + // Would like to do subtraction on current time but can't because + // the implementation on Windows is zero-based. We wrap around + // the backside resulting in a large U64 number. + + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(5.0)); + timer.start(the_past); + ensure_equals("WOCM t6 - isExpired() returns false with 10.0 horizon time starting 5.0 in past", + timer.isExpired(now, started, stopped, count), false); + ensure_approximately_equals("WOCM t6 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WOCM t6 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("WOCM t6 - isExpired() does not modify count", count, U64L(8)); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + LLDeadmanTimer timer(10.0, true); + + // Would like to do subtraction on current time but can't because + // the implementation on Windows is zero-based. We wrap around + // the backside resulting in a large U64 number. - LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); - LLDeadmanTimer::time_type now(the_past + float_time_to_u64(5.0)); - timer.start(the_past); - ensure_equals("isExpired() returns false with 10.0 horizon time starting 5.0 in past", - timer.isExpired(now, started, stopped, count), false); - ensure_approximately_equals("t6 - isExpired() does not modify started", started, F64(42.0), 2); - ensure_approximately_equals("t6 - isExpired() does not modify stopped", stopped, F64(97.0), 2); - ensure_equals("t6 - isExpired() does not modify count", count, U64L(8)); + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(5.0)); + timer.start(the_past); + ensure_equals("WCM t6 - isExpired() returns false with 10.0 horizon time starting 5.0 in past", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), false); + ensure_approximately_equals("WCM t6 - isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WCM t6 - isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("t6 - isExpired() does not modify count", count, U64L(8)); + ensure_equals("WCM t6 - isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); + ensure_equals("WCM t6 - isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + } } @@ -165,20 +273,41 @@ void deadmantimer_object_t::test<6>() template<> template<> void deadmantimer_object_t::test<7>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(10.0); - - // Would like to do subtraction on current time but can't because - // the implementation on Windows is zero-based. We wrap around - // the backside resulting in a large U64 number. + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0, false); + + // Would like to do subtraction on current time but can't because + // the implementation on Windows is zero-based. We wrap around + // the backside resulting in a large U64 number. + + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); + timer.start(the_past); + ensure_equals("WOCM t7 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", + timer.isExpired(now,started, stopped, count), true); + ensure_approximately_equals("WOCM t7 - starting before horizon still gives equal started / stopped", started, stopped, 8); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0, true); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + + // Would like to do subtraction on current time but can't because + // the implementation on Windows is zero-based. We wrap around + // the backside resulting in a large U64 number. - LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); - LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); - timer.start(the_past); - ensure_equals("isExpired() returns true with 10.0 horizon time starting 20.0 in past", - timer.isExpired(now,started, stopped, count), true); - ensure_approximately_equals("starting before horizon still gives equal started / stopped", started, stopped, 8); + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); + timer.start(the_past); + ensure_equals("WCM t7 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", + timer.isExpired(now,started, stopped, count, user_cpu, sys_cpu), true); + ensure_approximately_equals("WOCM t7 - starting before horizon still gives equal started / stopped", started, stopped, 8); + } } @@ -186,28 +315,61 @@ void deadmantimer_object_t::test<7>() template<> template<> void deadmantimer_object_t::test<8>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(10.0); - - // Would like to do subtraction on current time but can't because - // the implementation on Windows is zero-based. We wrap around - // the backside resulting in a large U64 number. + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0, false); + + // Would like to do subtraction on current time but can't because + // the implementation on Windows is zero-based. We wrap around + // the backside resulting in a large U64 number. - LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); - LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); - timer.start(the_past); - ensure_equals("t8 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", - timer.isExpired(now, started, stopped, count), true); - - started = 42.0; - stopped = 97.0; - count = U64L(8); - ensure_equals("t8 - second isExpired() returns false after true", - timer.isExpired(now, started, stopped, count), false); - ensure_approximately_equals("t8 - 2nd isExpired() does not modify started", started, F64(42.0), 2); - ensure_approximately_equals("t8 - 2nd isExpired() does not modify stopped", stopped, F64(97.0), 2); - ensure_equals("t8 - 2nd isExpired() does not modify count", count, U64L(8)); + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); + timer.start(the_past); + ensure_equals("WOCM t8 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", + timer.isExpired(now, started, stopped, count), true); + + started = 42.0; + stopped = 97.0; + count = U64L(8); + ensure_equals("WOCM t8 - second isExpired() returns false after true", + timer.isExpired(now, started, stopped, count), false); + ensure_approximately_equals("WOCM t8 - 2nd isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WOCM t8 - 2nd isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("WOCM t8 - 2nd isExpired() does not modify count", count, U64L(8)); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(10.0, true); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + + // Would like to do subtraction on current time but can't because + // the implementation on Windows is zero-based. We wrap around + // the backside resulting in a large U64 number. + + LLDeadmanTimer::time_type the_past(LLDeadmanTimer::getNow()); + LLDeadmanTimer::time_type now(the_past + float_time_to_u64(20.0)); + timer.start(the_past); + ensure_equals("WCM t8 - isExpired() returns true with 10.0 horizon time starting 20.0 in past", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), true); + + started = 42.0; + stopped = 97.0; + count = U64L(8); + user_cpu = 29000; + sys_cpu = 57000; + ensure_equals("WCM t8 - second isExpired() returns false after true", + timer.isExpired(now, started, stopped, count), false); + ensure_approximately_equals("WCM t8 - 2nd isExpired() does not modify started", started, F64(42.0), 2); + ensure_approximately_equals("WCM t8 - 2nd isExpired() does not modify stopped", stopped, F64(97.0), 2); + ensure_equals("WCM t8 - 2nd isExpired() does not modify count", count, U64L(8)); + ensure_equals("WCM t8 - 2nd isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); + ensure_equals("WCM t8 - 2nd isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + } } @@ -215,46 +377,93 @@ void deadmantimer_object_t::test<8>() template<> template<> void deadmantimer_object_t::test<9>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(5.0); - - LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); - F64 real_start(u64_time_to_float(now)); - timer.start(0); - - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - ensure_equals("t9 - 5.0 horizon timer has not timed out after 10 1-second bell rings", - timer.isExpired(now, started, stopped, count), false); - F64 last_good_ring(u64_time_to_float(now)); - - // Jump forward and expire - now += float_time_to_u64(10.0); - ensure_equals("t9 - 5.0 horizon timer expires on 10-second jump", - timer.isExpired(now, started, stopped, count), true); - ensure_approximately_equals("t9 - started matches start() time", started, real_start, 4); - ensure_approximately_equals("t9 - stopped matches last ringBell() time", stopped, last_good_ring, 4); - ensure_equals("t9 - 10 good ringBell()s", count, U64L(10)); - ensure_equals("t9 - single read only", timer.isExpired(now, started, stopped, count), false); + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(5.0, false); + + LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); + F64 real_start(u64_time_to_float(now)); + timer.start(0); + + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + ensure_equals("WOCM t9 - 5.0 horizon timer has not timed out after 10 1-second bell rings", + timer.isExpired(now, started, stopped, count), false); + F64 last_good_ring(u64_time_to_float(now)); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("WOCM t9 - 5.0 horizon timer expires on 10-second jump", + timer.isExpired(now, started, stopped, count), true); + ensure_approximately_equals("WOCM t9 - started matches start() time", started, real_start, 4); + ensure_approximately_equals("WOCM t9 - stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("WOCM t9 - 10 good ringBell()s", count, U64L(10)); + ensure_equals("WOCM t9 - single read only", timer.isExpired(now, started, stopped, count), false); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(5.0, true); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + + LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); + F64 real_start(u64_time_to_float(now)); + timer.start(0); + + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + ensure_equals("WCM t9 - 5.0 horizon timer has not timed out after 10 1-second bell rings", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), false); + F64 last_good_ring(u64_time_to_float(now)); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("WCM t9 - 5.0 horizon timer expires on 10-second jump", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), true); + ensure_approximately_equals("WCM t9 - started matches start() time", started, real_start, 4); + ensure_approximately_equals("WCM t9 - stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("WCM t9 - 10 good ringBell()s", count, U64L(10)); + ensure_equals("WCM t9 - single read only", timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), false); + } } @@ -262,83 +471,167 @@ void deadmantimer_object_t::test<9>() template<> template<> void deadmantimer_object_t::test<10>() { - F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLDeadmanTimer timer(5.0); - - LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); - F64 real_start(u64_time_to_float(now)); - timer.start(0); - - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - ensure_equals("t10 - 5.0 horizon timer has not timed out after 10 1-second bell rings", - timer.isExpired(now, started, stopped, count), false); - F64 last_good_ring(u64_time_to_float(now)); - - // Jump forward and expire - now += float_time_to_u64(10.0); - ensure_equals("t10 - 5.0 horizon timer expires on 10-second jump", - timer.isExpired(now, started, stopped, count), true); - ensure_approximately_equals("t10 - started matches start() time", started, real_start, 4); - ensure_approximately_equals("t10 - stopped matches last ringBell() time", stopped, last_good_ring, 4); - ensure_equals("t10 - 10 good ringBell()s", count, U64L(10)); - ensure_equals("t10 - single read only", timer.isExpired(now, started, stopped, count), false); - - // Jump forward and restart - now += float_time_to_u64(1.0); - real_start = u64_time_to_float(now); - timer.start(now); - - // Run a modified bell ring sequence - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - now += float_time_to_u64(1.0); - timer.ringBell(now, 1); - ensure_equals("t10 - 5.0 horizon timer has not timed out after 8 1-second bell rings", - timer.isExpired(now, started, stopped, count), false); - last_good_ring = u64_time_to_float(now); - - // Jump forward and expire - now += float_time_to_u64(10.0); - ensure_equals("t10 - 5.0 horizon timer expires on 8-second jump", - timer.isExpired(now, started, stopped, count), true); - ensure_approximately_equals("t10 - 2nd started matches start() time", started, real_start, 4); - ensure_approximately_equals("t10 - 2nd stopped matches last ringBell() time", stopped, last_good_ring, 4); - ensure_equals("t10 - 8 good ringBell()s", count, U64L(8)); - ensure_equals("t10 - single read only - 2nd start", - timer.isExpired(now, started, stopped, count), false); + { + // Without cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(5.0, false); + + LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); + F64 real_start(u64_time_to_float(now)); + timer.start(0); + + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + ensure_equals("WOCM t10 - 5.0 horizon timer has not timed out after 10 1-second bell rings", + timer.isExpired(now, started, stopped, count), false); + F64 last_good_ring(u64_time_to_float(now)); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("WOCM t10 - 5.0 horizon timer expires on 10-second jump", + timer.isExpired(now, started, stopped, count), true); + ensure_approximately_equals("WOCM t10 - started matches start() time", started, real_start, 4); + ensure_approximately_equals("WOCM t10 - stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("WOCM t10 - 10 good ringBell()s", count, U64L(10)); + ensure_equals("WOCM t10 - single read only", timer.isExpired(now, started, stopped, count), false); + + // Jump forward and restart + now += float_time_to_u64(1.0); + real_start = u64_time_to_float(now); + timer.start(now); + + // Run a modified bell ring sequence + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + ensure_equals("WOCM t10 - 5.0 horizon timer has not timed out after 8 1-second bell rings", + timer.isExpired(now, started, stopped, count), false); + last_good_ring = u64_time_to_float(now); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("WOCM t10 - 5.0 horizon timer expires on 8-second jump", + timer.isExpired(now, started, stopped, count), true); + ensure_approximately_equals("WOCM t10 - 2nd started matches start() time", started, real_start, 4); + ensure_approximately_equals("WOCM t10 - 2nd stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("WOCM t10 - 8 good ringBell()s", count, U64L(8)); + ensure_equals("WOCM t10 - single read only - 2nd start", + timer.isExpired(now, started, stopped, count), false); + } + { + // With cpu metrics + F64 started(42.0), stopped(97.0); + U64 count(U64L(8)); + LLDeadmanTimer timer(5.0, true); + LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + + LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); + F64 real_start(u64_time_to_float(now)); + timer.start(0); + + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + ensure_equals("WCM t10 - 5.0 horizon timer has not timed out after 10 1-second bell rings", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), false); + F64 last_good_ring(u64_time_to_float(now)); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("WCM t10 - 5.0 horizon timer expires on 10-second jump", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), true); + ensure_approximately_equals("WCM t10 - started matches start() time", started, real_start, 4); + ensure_approximately_equals("WCM t10 - stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("WCM t10 - 10 good ringBell()s", count, U64L(10)); + ensure_equals("WCM t10 - single read only", timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), false); + + // Jump forward and restart + now += float_time_to_u64(1.0); + real_start = u64_time_to_float(now); + timer.start(now); + + // Run a modified bell ring sequence + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + now += float_time_to_u64(1.0); + timer.ringBell(now, 1); + ensure_equals("WCM t10 - 5.0 horizon timer has not timed out after 8 1-second bell rings", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), false); + last_good_ring = u64_time_to_float(now); + + // Jump forward and expire + now += float_time_to_u64(10.0); + ensure_equals("WCM t10 - 5.0 horizon timer expires on 8-second jump", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), true); + ensure_approximately_equals("WCM t10 - 2nd started matches start() time", started, real_start, 4); + ensure_approximately_equals("WCM t10 - 2nd stopped matches last ringBell() time", stopped, last_good_ring, 4); + ensure_equals("WCM t10 - 8 good ringBell()s", count, U64L(8)); + ensure_equals("WCM t10 - single read only - 2nd start", + timer.isExpired(now, started, stopped, count, user_cpu, sys_cpu), false); + } } + } // end namespace tut diff --git a/indra/newview/llmeshrepository.cpp b/indra/newview/llmeshrepository.cpp index 0f33128057..2a863a3103 100755 --- a/indra/newview/llmeshrepository.cpp +++ b/indra/newview/llmeshrepository.cpp @@ -96,7 +96,7 @@ U32 LLMeshRepository::sLODPending = 0; U32 LLMeshRepository::sCacheBytesRead = 0; U32 LLMeshRepository::sCacheBytesWritten = 0; U32 LLMeshRepository::sPeakKbps = 0; -LLDeadmanTimer LLMeshRepository::sQuiescentTimer(15.0); +LLDeadmanTimer LLMeshRepository::sQuiescentTimer(15.0, true); const U32 MAX_TEXTURE_UPLOAD_RETRIES = 5; -- cgit v1.3 From 960139aa6f02f90c6102d3c5d5c38b5ebe689f9c Mon Sep 17 00:00:00 2001 From: Monty Brandenberg Date: Thu, 2 May 2013 19:12:59 -0400 Subject: SH-4161 Integrate cpu metrics into LLDeadmanTimer and then metrics viewer Normalize deadman timer's args on U64/F64. Internals remain the same. Modify mesh to collect and output enhanced CPU metrics. --- indra/llcommon/lldeadmantimer.cpp | 6 ++-- indra/llcommon/lldeadmantimer.h | 2 +- indra/llcommon/tests/lldeadmantimer_test.cpp | 47 +++++++++++----------------- indra/newview/llmeshrepository.cpp | 10 +++--- 4 files changed, 29 insertions(+), 36 deletions(-) (limited to 'indra/llcommon/lldeadmantimer.cpp') diff --git a/indra/llcommon/lldeadmantimer.cpp b/indra/llcommon/lldeadmantimer.cpp index 2ba757d2af..7d9097e344 100644 --- a/indra/llcommon/lldeadmantimer.cpp +++ b/indra/llcommon/lldeadmantimer.cpp @@ -110,13 +110,13 @@ void LLDeadmanTimer::stop(time_type now) bool LLDeadmanTimer::isExpired(time_type now, F64 & started, F64 & stopped, U64 & count, - LLProcInfo::time_type & user_cpu, LLProcInfo::time_type & sys_cpu) + U64 & user_cpu, U64 & sys_cpu) { const bool status(isExpired(now, started, stopped, count)); if (status) { - user_cpu = mUEndCPU - mUStartCPU; - sys_cpu = mSEndCPU - mSStartCPU; + user_cpu = U64(mUEndCPU - mUStartCPU); + sys_cpu = U64(mSEndCPU - mSStartCPU); } return status; } diff --git a/indra/llcommon/lldeadmantimer.h b/indra/llcommon/lldeadmantimer.h index a6022852b9..0dde16b717 100644 --- a/indra/llcommon/lldeadmantimer.h +++ b/indra/llcommon/lldeadmantimer.h @@ -190,7 +190,7 @@ public: /// left unchanged. /// bool isExpired(time_type now, F64 & started, F64 & stopped, U64 & count, - LLProcInfo::time_type & user_cpu, LLProcInfo::time_type & sys_cpu); + U64 & user_cpu, U64 & sys_cpu); /// Identical to the six-arugment form except is does without the /// CPU time return if the caller isn't interested in it. diff --git a/indra/llcommon/tests/lldeadmantimer_test.cpp b/indra/llcommon/tests/lldeadmantimer_test.cpp index a4ec76a016..7fd2dde6e0 100644 --- a/indra/llcommon/tests/lldeadmantimer_test.cpp +++ b/indra/llcommon/tests/lldeadmantimer_test.cpp @@ -81,16 +81,15 @@ void deadmantimer_object_t::test<1>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(10.0, true); ensure_equals("WCM isExpired() returns false after ctor()", timer.isExpired(0, started, stopped, count, user_cpu, sys_cpu), false); ensure_approximately_equals("WCM t1 - isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("WCM t1 - isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("WCM t1 - isExpired() does not modify count", count, U64L(8)); - ensure_equals("WCM t1 - isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); - ensure_equals("WCM t1 - isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + ensure_equals("WCM t1 - isExpired() does not modify user_cpu", user_cpu, U64L(29000)); + ensure_equals("WCM t1 - isExpired() does not modify sys_cpu", sys_cpu, U64L(57000)); } } @@ -112,8 +111,7 @@ void deadmantimer_object_t::test<2>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(0.0, true); // Zero is pre-expired ensure_equals("WCM isExpired() still returns false with 0.0 time ctor()", @@ -141,8 +139,7 @@ void deadmantimer_object_t::test<3>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(0.0, true); timer.start(0); @@ -172,8 +169,7 @@ void deadmantimer_object_t::test<4>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(0.0, true); timer.start(0); @@ -205,8 +201,7 @@ void deadmantimer_object_t::test<5>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(10.0, true); timer.start(0); @@ -215,8 +210,8 @@ void deadmantimer_object_t::test<5>() ensure_approximately_equals("WCM t5 - isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("WCM t5 - isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("WCM t5 - isExpired() does not modify count", count, U64L(8)); - ensure_equals("WCM t5 - isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); - ensure_equals("WCM t5 - isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + ensure_equals("WCM t5 - isExpired() does not modify user_cpu", user_cpu, U64L(29000)); + ensure_equals("WCM t5 - isExpired() does not modify sys_cpu", sys_cpu, U64L(57000)); } } @@ -247,8 +242,7 @@ void deadmantimer_object_t::test<6>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(10.0, true); // Would like to do subtraction on current time but can't because @@ -263,8 +257,8 @@ void deadmantimer_object_t::test<6>() ensure_approximately_equals("WCM t6 - isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("WCM t6 - isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("t6 - isExpired() does not modify count", count, U64L(8)); - ensure_equals("WCM t6 - isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); - ensure_equals("WCM t6 - isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + ensure_equals("WCM t6 - isExpired() does not modify user_cpu", user_cpu, U64L(29000)); + ensure_equals("WCM t6 - isExpired() does not modify sys_cpu", sys_cpu, U64L(57000)); } } @@ -293,9 +287,8 @@ void deadmantimer_object_t::test<7>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(10.0, true); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); // Would like to do subtraction on current time but can't because // the implementation on Windows is zero-based. We wrap around @@ -343,9 +336,8 @@ void deadmantimer_object_t::test<8>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(10.0, true); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); // Would like to do subtraction on current time but can't because // the implementation on Windows is zero-based. We wrap around @@ -367,8 +359,8 @@ void deadmantimer_object_t::test<8>() ensure_approximately_equals("WCM t8 - 2nd isExpired() does not modify started", started, F64(42.0), 2); ensure_approximately_equals("WCM t8 - 2nd isExpired() does not modify stopped", stopped, F64(97.0), 2); ensure_equals("WCM t8 - 2nd isExpired() does not modify count", count, U64L(8)); - ensure_equals("WCM t8 - 2nd isExpired() does not modify user_cpu", user_cpu, LLProcInfo::time_type(29000)); - ensure_equals("WCM t8 - 2nd isExpired() does not modify sys_cpu", sys_cpu, LLProcInfo::time_type(57000)); + ensure_equals("WCM t8 - 2nd isExpired() does not modify user_cpu", user_cpu, U64L(29000)); + ensure_equals("WCM t8 - 2nd isExpired() does not modify sys_cpu", sys_cpu, U64L(57000)); } } @@ -423,9 +415,8 @@ void deadmantimer_object_t::test<9>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); LLDeadmanTimer timer(5.0, true); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); F64 real_start(u64_time_to_float(now)); @@ -553,9 +544,9 @@ void deadmantimer_object_t::test<10>() { // With cpu metrics F64 started(42.0), stopped(97.0); - U64 count(U64L(8)); + U64 count(U64L(8)), user_cpu(29000), sys_cpu(57000); + LLDeadmanTimer timer(5.0, true); - LLProcInfo::time_type user_cpu(29000), sys_cpu(57000); LLDeadmanTimer::time_type now(LLDeadmanTimer::getNow()); F64 real_start(u64_time_to_float(now)); diff --git a/indra/newview/llmeshrepository.cpp b/indra/newview/llmeshrepository.cpp index 2a863a3103..4d3937ded1 100755 --- a/indra/newview/llmeshrepository.cpp +++ b/indra/newview/llmeshrepository.cpp @@ -96,7 +96,7 @@ U32 LLMeshRepository::sLODPending = 0; U32 LLMeshRepository::sCacheBytesRead = 0; U32 LLMeshRepository::sCacheBytesWritten = 0; U32 LLMeshRepository::sPeakKbps = 0; -LLDeadmanTimer LLMeshRepository::sQuiescentTimer(15.0, true); +LLDeadmanTimer LLMeshRepository::sQuiescentTimer(15.0, true); // true -> gather cpu metrics const U32 MAX_TEXTURE_UPLOAD_RETRIES = 5; @@ -3769,9 +3769,9 @@ void LLMeshRepository::metricsProgress(unsigned int this_count) void LLMeshRepository::metricsUpdate() { F64 started, stopped; - U64 total_count; - - if (sQuiescentTimer.isExpired(0, started, stopped, total_count)) + U64 total_count(U64L(0)), user_cpu(U64L(0)), sys_cpu(U64L(0)); + + if (sQuiescentTimer.isExpired(0, started, stopped, total_count, user_cpu, sys_cpu)) { LLSD metrics; @@ -3781,6 +3781,8 @@ void LLMeshRepository::metricsUpdate() metrics["stop"] = stopped; metrics["downloads"] = LLSD::Integer(total_count); metrics["teleports"] = LLSD::Integer(metrics_teleport_start_count); + metrics["user_cpu"] = double(user_cpu) / 1.0e6; + metrics["sys_cpu"] = double(sys_cpu) / 1.0e6; llinfos << "EventMarker " << metrics << llendl; } } -- cgit v1.3