Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(669)

Issues Search
    My Issues | Starred     Open | Closed | All

Unified Diff: test/unittests/counters-unittest.cc

Issue 2511093002: [counters] RuntimeStats: fix wrong bookkeeping when dynamically changing counters. (Closed)
Patch Set: merge with master Created 4 years, 1 month ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View side-by-side diff with in-line comments
Download patch
« no previous file with comments | « src/profiler/profile-generator.cc ('k') | no next file » | no next file with comments »
Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
Index: test/unittests/counters-unittest.cc
diff --git a/test/unittests/counters-unittest.cc b/test/unittests/counters-unittest.cc
index 822a5c552ecb0b94addf11abb21878157693c85c..79678d5a08a6c9beec3a9d7219843f591a0fb708 100644
--- a/test/unittests/counters-unittest.cc
+++ b/test/unittests/counters-unittest.cc
@@ -4,9 +4,11 @@
#include <vector>
+#include "src/counters-inl.h"
#include "src/counters.h"
#include "src/handles-inl.h"
#include "src/objects-inl.h"
+#include "src/tracing/tracing-category-observer.h"
#include "testing/gtest/include/gtest/gtest.h"
namespace v8 {
@@ -42,6 +44,42 @@ class AggregatedMemoryHistogramTest : public ::testing::Test {
MockHistogram mock_;
};
+class RuntimeCallStatsTest : public ::testing::Test {
+ public:
+ RuntimeCallStatsTest() {
+ FLAG_runtime_stats =
+ v8::tracing::TracingCategoryObserver::ENABLED_BY_NATIVE;
+ }
+ virtual ~RuntimeCallStatsTest() {}
+
+ RuntimeCallStats* stats() { return &stats_; }
+ RuntimeCallStats::CounterId counter_id() {
+ return &RuntimeCallStats::TestCounter1;
+ }
+ RuntimeCallStats::CounterId counter_id2() {
+ return &RuntimeCallStats::TestCounter2;
+ }
+ RuntimeCallStats::CounterId counter_id3() {
+ return &RuntimeCallStats::TestCounter3;
+ }
+ RuntimeCallCounter* counter() { return &(stats()->*counter_id()); }
+ RuntimeCallCounter* counter2() { return &(stats()->*counter_id2()); }
+ RuntimeCallCounter* counter3() { return &(stats()->*counter_id3()); }
+ void Sleep(int32_t milliseconds) {
+ base::ElapsedTimer timer;
+ base::TimeDelta delta = base::TimeDelta::FromMilliseconds(milliseconds);
+ timer.Start();
+ while (!timer.HasExpired(delta)) {
+ base::OS::Sleep(base::TimeDelta::FromMicroseconds(0));
+ }
+ }
+
+ const uint32_t kEpsilonMs = 20;
Michael Achenbach 2016/11/24 09:48:46 Hmm, is that rock solid?
+
+ private:
+ RuntimeCallStats stats_;
+};
+
} // namespace
@@ -195,6 +233,278 @@ TEST_F(AggregatedMemoryHistogramTest, ManySamples2) {
}
}
+#define EXPECT_IN_RANGE(start, value, end) \
+ EXPECT_LE(start, value); \
+ EXPECT_GE(end, value)
+
+TEST_F(RuntimeCallStatsTest, RuntimeCallTimer) {
+ RuntimeCallTimer timer;
+
+ Sleep(50);
+ RuntimeCallStats::Enter(stats(), &timer, counter_id());
+ EXPECT_EQ(counter(), timer.counter());
+ EXPECT_EQ(nullptr, timer.parent());
+ EXPECT_TRUE(timer.IsStarted());
+ EXPECT_EQ(&timer, stats()->current_timer());
+
+ Sleep(100);
+
+ RuntimeCallStats::Leave(stats(), &timer);
+ Sleep(50);
+ EXPECT_FALSE(timer.IsStarted());
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
+}
+
+TEST_F(RuntimeCallStatsTest, RuntimeCallTimerSubTimer) {
+ RuntimeCallTimer timer;
+ RuntimeCallTimer timer2;
+
+ RuntimeCallStats::Enter(stats(), &timer, counter_id());
+ EXPECT_TRUE(timer.IsStarted());
+ EXPECT_FALSE(timer2.IsStarted());
+ EXPECT_EQ(counter(), timer.counter());
+ EXPECT_EQ(nullptr, timer.parent());
+ EXPECT_EQ(&timer, stats()->current_timer());
+
+ Sleep(50);
+
+ RuntimeCallStats::Enter(stats(), &timer2, counter_id2());
+ // timer 1 is paused, while timer 2 is active.
+ EXPECT_TRUE(timer2.IsStarted());
+ EXPECT_EQ(counter(), timer.counter());
+ EXPECT_EQ(counter2(), timer2.counter());
+ EXPECT_EQ(nullptr, timer.parent());
+ EXPECT_EQ(&timer, timer2.parent());
+ EXPECT_EQ(&timer2, stats()->current_timer());
+
+ Sleep(100);
+ RuntimeCallStats::Leave(stats(), &timer2);
+
+ // The subtimer subtracts its time from the parent timer.
+ EXPECT_TRUE(timer.IsStarted());
+ EXPECT_FALSE(timer2.IsStarted());
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(1, counter2()->count());
+ EXPECT_EQ(0, counter()->time().InMilliseconds());
+ EXPECT_IN_RANGE(100, counter2()->time().InMilliseconds(), 100 + kEpsilonMs);
+ EXPECT_EQ(&timer, stats()->current_timer());
+
+ Sleep(100);
+
+ RuntimeCallStats::Leave(stats(), &timer);
+ EXPECT_FALSE(timer.IsStarted());
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_EQ(1, counter2()->count());
+ EXPECT_IN_RANGE(150, counter()->time().InMilliseconds(), 150 + kEpsilonMs);
+ EXPECT_IN_RANGE(100, counter2()->time().InMilliseconds(), 100 + kEpsilonMs);
+ EXPECT_EQ(nullptr, stats()->current_timer());
+}
+
+TEST_F(RuntimeCallStatsTest, RuntimeCallTimerRecursive) {
+ RuntimeCallTimer timer;
+ RuntimeCallTimer timer2;
+
+ RuntimeCallStats::Enter(stats(), &timer, counter_id());
+ EXPECT_EQ(counter(), timer.counter());
+ EXPECT_EQ(nullptr, timer.parent());
+ EXPECT_TRUE(timer.IsStarted());
+ EXPECT_EQ(&timer, stats()->current_timer());
+
+ RuntimeCallStats::Enter(stats(), &timer2, counter_id());
+ EXPECT_EQ(counter(), timer2.counter());
+ EXPECT_EQ(nullptr, timer.parent());
+ EXPECT_EQ(&timer, timer2.parent());
+ EXPECT_TRUE(timer2.IsStarted());
+ EXPECT_EQ(&timer2, stats()->current_timer());
+
+ Sleep(50);
+
+ RuntimeCallStats::Leave(stats(), &timer2);
+ EXPECT_EQ(nullptr, timer.parent());
+ EXPECT_FALSE(timer2.IsStarted());
+ EXPECT_TRUE(timer.IsStarted());
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
+
+ Sleep(100);
+
+ RuntimeCallStats::Leave(stats(), &timer);
+ EXPECT_FALSE(timer.IsStarted());
+ EXPECT_EQ(2, counter()->count());
+ EXPECT_IN_RANGE(150, counter()->time().InMilliseconds(),
+ 150 + 2 * kEpsilonMs);
+}
+
+TEST_F(RuntimeCallStatsTest, RuntimeCallTimerScope) {
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(50);
+ }
+ Sleep(100);
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(50);
+ }
+ EXPECT_EQ(2, counter()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
+ 100 + 2 * kEpsilonMs);
+}
+
+TEST_F(RuntimeCallStatsTest, RuntimeCallTimerScopeRecursive) {
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(50);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(0, counter()->time().InMilliseconds());
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(50);
+ }
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
+ }
+ EXPECT_EQ(2, counter()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
+ 100 + 2 * kEpsilonMs);
+}
+
+TEST_F(RuntimeCallStatsTest, RenameTimer) {
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(50);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_EQ(0, counter()->time().InMilliseconds());
+ EXPECT_EQ(0, counter2()->time().InMilliseconds());
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(100);
+ }
+ CHANGE_CURRENT_RUNTIME_COUNTER(stats(), TestCounter2);
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
+ EXPECT_IN_RANGE(0, counter2()->time().InMilliseconds(), 0);
+ }
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_EQ(1, counter2()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
+ EXPECT_IN_RANGE(50, counter2()->time().InMilliseconds(), 50 + kEpsilonMs);
+}
+
+TEST_F(RuntimeCallStatsTest, BasicPrintAndSnapshot) {
+ std::ostringstream out;
+ stats()->Print(out);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_EQ(0, counter3()->count());
+ EXPECT_EQ(0, counter()->time().InMilliseconds());
+ EXPECT_EQ(0, counter2()->time().InMilliseconds());
+ EXPECT_EQ(0, counter3()->time().InMilliseconds());
+
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(50);
+ stats()->Print(out);
+ }
+ stats()->Print(out);
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_EQ(0, counter3()->count());
+ EXPECT_IN_RANGE(50, counter()->time().InMilliseconds(), 50 + kEpsilonMs);
+ EXPECT_EQ(0, counter2()->time().InMilliseconds());
+ EXPECT_EQ(0, counter3()->time().InMilliseconds());
+}
+
+TEST_F(RuntimeCallStatsTest, PrintAndSnapshot) {
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(100);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(0, counter()->time().InMilliseconds());
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id2());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_EQ(0, counter2()->time().InMilliseconds());
+ Sleep(50);
+
+ // This calls Snapshot on the current active timer and sychronizes and
+ // commits the whole timer stack.
+ std::ostringstream out;
+ stats()->Print(out);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
+ 100 + kEpsilonMs);
+ EXPECT_IN_RANGE(50, counter2()->time().InMilliseconds(), 50 + kEpsilonMs);
+ // Calling Print several times shouldn't have a (big) impact on the
+ // measured times.
+ stats()->Print(out);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
+ 100 + kEpsilonMs);
+ EXPECT_IN_RANGE(50, counter2()->time().InMilliseconds(), 50 + kEpsilonMs);
+
+ Sleep(50);
+ stats()->Print(out);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(0, counter2()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(),
+ 100 + kEpsilonMs);
+ EXPECT_IN_RANGE(100, counter2()->time().InMilliseconds(),
+ 100 + kEpsilonMs);
+ Sleep(50);
+ }
+ Sleep(50);
+ EXPECT_EQ(0, counter()->count());
+ EXPECT_EQ(1, counter2()->count());
+ EXPECT_IN_RANGE(100, counter()->time().InMilliseconds(), 100 + kEpsilonMs);
+ EXPECT_IN_RANGE(150, counter2()->time().InMilliseconds(), 150 + kEpsilonMs);
+ Sleep(50);
+ }
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_EQ(1, counter2()->count());
+ EXPECT_IN_RANGE(200, counter()->time().InMilliseconds(), 200 + kEpsilonMs);
+ EXPECT_IN_RANGE(150, counter2()->time().InMilliseconds(),
+ 150 + 2 * kEpsilonMs);
+}
+
+TEST_F(RuntimeCallStatsTest, NestedScopes) {
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id());
+ Sleep(100);
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id2());
+ Sleep(100);
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id3());
+ Sleep(50);
+ }
+ Sleep(50);
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id3());
+ Sleep(50);
+ }
+ Sleep(50);
+ }
+ Sleep(100);
+ {
+ RuntimeCallTimerScope scope(stats(), counter_id2());
+ Sleep(100);
+ }
+ Sleep(50);
+ }
+ EXPECT_EQ(1, counter()->count());
+ EXPECT_EQ(2, counter2()->count());
+ EXPECT_EQ(2, counter3()->count());
+ EXPECT_IN_RANGE(250, counter()->time().InMilliseconds(), 250 + kEpsilonMs);
+ EXPECT_IN_RANGE(300, counter2()->time().InMilliseconds(), 300 + kEpsilonMs);
+ EXPECT_IN_RANGE(100, counter3()->time().InMilliseconds(), 100 + kEpsilonMs);
+}
} // namespace internal
} // namespace v8
« no previous file with comments | « src/profiler/profile-generator.cc ('k') | no next file » | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698