summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
Diffstat
-rw-r--r--lldb/include/lldb/Utility/Timer.h2
-rw-r--r--lldb/source/Utility/Timer.cpp44
-rw-r--r--lldb/unittests/Utility/TimerTest.cpp39
3 files changed, 72 insertions, 13 deletions
diff --git a/lldb/include/lldb/Utility/Timer.h b/lldb/include/lldb/Utility/Timer.h
index 0d2e8d8c3e5..ad9421a75b1 100644
--- a/lldb/include/lldb/Utility/Timer.h
+++ b/lldb/include/lldb/Utility/Timer.h
@@ -30,6 +30,8 @@ public:
friend class Timer;
const char *m_name;
std::atomic<uint64_t> m_nanos;
+ std::atomic<uint64_t> m_nanos_total;
+ std::atomic<uint64_t> m_count;
std::atomic<Category *> m_next;
DISALLOW_COPY_AND_ASSIGN(Category);
diff --git a/lldb/source/Utility/Timer.cpp b/lldb/source/Utility/Timer.cpp
index 68319244976..7492045bc32 100644
--- a/lldb/source/Utility/Timer.cpp
+++ b/lldb/source/Utility/Timer.cpp
@@ -41,6 +41,8 @@ static TimerStack &GetTimerStackForCurrentThread() {
Timer::Category::Category(const char *cat) : m_name(cat) {
m_nanos.store(0, std::memory_order_release);
+ m_nanos_total.store(0, std::memory_order_release);
+ m_count.store(0, std::memory_order_release);
Category *expected = g_categories;
do {
m_next = expected;
@@ -93,6 +95,8 @@ Timer::~Timer() {
// Keep total results for each category so we can dump results.
m_category.m_nanos += std::chrono::nanoseconds(timer_dur).count();
+ m_category.m_nanos_total += std::chrono::nanoseconds(total_dur).count();
+ m_category.m_count++;
}
void Timer::SetDisplayDepth(uint32_t depth) { g_display_depth = depth; }
@@ -100,25 +104,38 @@ void Timer::SetDisplayDepth(uint32_t depth) { g_display_depth = depth; }
/* binary function predicate:
* - returns whether a person is less than another person
*/
-
-typedef std::pair<const char *, uint64_t> TimerEntry;
-
-static bool CategoryMapIteratorSortCriterion(const TimerEntry &lhs,
- const TimerEntry &rhs) {
- return lhs.second > rhs.second;
+namespace {
+struct Stats {
+ const char *name;
+ uint64_t nanos;
+ uint64_t nanos_total;
+ uint64_t count;
+};
+} // namespace
+
+static bool CategoryMapIteratorSortCriterion(const Stats &lhs,
+ const Stats &rhs) {
+ return lhs.nanos > rhs.nanos;
}
void Timer::ResetCategoryTimes() {
- for (Category *i = g_categories; i; i = i->m_next)
+ for (Category *i = g_categories; i; i = i->m_next) {
i->m_nanos.store(0, std::memory_order_release);
+ i->m_nanos_total.store(0, std::memory_order_release);
+ i->m_count.store(0, std::memory_order_release);
+ }
}
void Timer::DumpCategoryTimes(Stream *s) {
- std::vector<TimerEntry> sorted;
+ std::vector<Stats> sorted;
for (Category *i = g_categories; i; i = i->m_next) {
uint64_t nanos = i->m_nanos.load(std::memory_order_acquire);
- if (nanos)
- sorted.push_back(std::make_pair(i->m_name, nanos));
+ if (nanos) {
+ uint64_t nanos_total = i->m_nanos_total.load(std::memory_order_acquire);
+ uint64_t count = i->m_count.load(std::memory_order_acquire);
+ Stats stats{i->m_name, nanos, nanos_total, count};
+ sorted.push_back(stats);
+ }
}
if (sorted.empty())
return; // Later code will break without any elements.
@@ -126,6 +143,9 @@ void Timer::DumpCategoryTimes(Stream *s) {
// Sort by time
llvm::sort(sorted.begin(), sorted.end(), CategoryMapIteratorSortCriterion);
- for (const auto &timer : sorted)
- s->Printf("%.9f sec for %s\n", timer.second / 1000000000., timer.first);
+ for (const auto &stats : sorted)
+ s->Printf("%.9f sec (total: %.3fs; child: %.3fs; count: %llu) for %s\n",
+ stats.nanos / 1000000000., stats.nanos_total / 1000000000.,
+ (stats.nanos_total - stats.nanos) / 1000000000., stats.count,
+ stats.name);
}
diff --git a/lldb/unittests/Utility/TimerTest.cpp b/lldb/unittests/Utility/TimerTest.cpp
index 28d8d050b3e..53d0ff12d89 100644
--- a/lldb/unittests/Utility/TimerTest.cpp
+++ b/lldb/unittests/Utility/TimerTest.cpp
@@ -61,7 +61,9 @@ TEST(TimerTest, CategoryTimes2) {
StreamString ss;
Timer::DumpCategoryTimes(&ss);
double seconds1, seconds2;
- ASSERT_EQ(2, sscanf(ss.GetData(), "%lf sec for CAT1%*[\n ]%lf sec for CAT2",
+ ASSERT_EQ(2, sscanf(ss.GetData(),
+ "%lf sec (total: %*lfs; child: %*lfs; count: %*d) for "
+ "CAT1%*[\n ]%lf sec for CAT2",
&seconds1, &seconds2))
<< "String: " << ss.GetData();
EXPECT_LT(0.01, seconds1);
@@ -69,3 +71,38 @@ TEST(TimerTest, CategoryTimes2) {
EXPECT_LT(0.001, seconds2);
EXPECT_GT(0.1, seconds2);
}
+
+TEST(TimerTest, CategoryTimesStats) {
+ Timer::ResetCategoryTimes();
+ {
+ static Timer::Category tcat1("CAT1");
+ Timer t1(tcat1, ".");
+ std::this_thread::sleep_for(std::chrono::milliseconds(100));
+ static Timer::Category tcat2("CAT2");
+ {
+ Timer t2(tcat2, ".");
+ std::this_thread::sleep_for(std::chrono::milliseconds(10));
+ }
+ {
+ Timer t3(tcat2, ".");
+ std::this_thread::sleep_for(std::chrono::milliseconds(10));
+ }
+ }
+ // Example output:
+ // 0.105202764 sec (total: 0.132s; child: 0.027s; count: 1) for CAT1
+ // 0.026772798 sec (total: 0.027s; child: 0.000s; count: 2) for CAT2
+ StreamString ss;
+ Timer::DumpCategoryTimes(&ss);
+ double seconds1, total1, child1, seconds2;
+ int count1, count2;
+ ASSERT_EQ(
+ 6, sscanf(ss.GetData(),
+ "%lf sec (total: %lfs; child: %lfs; count: %d) for CAT1%*[\n ]"
+ "%lf sec (total: %*lfs; child: %*lfs; count: %d) for CAT2",
+ &seconds1, &total1, &child1, &count1, &seconds2, &count2))
+ << "String: " << ss.GetData();
+ EXPECT_NEAR(total1 - child1, seconds1, 0.002);
+ EXPECT_EQ(1, count1);
+ EXPECT_NEAR(child1, seconds2, 0.002);
+ EXPECT_EQ(2, count2);
+}
OpenPOWER on IntegriCloud