[Lldb-commits] [PATCH] D61235: Add more information to the log timer dump

[Pavel Labath via Phabricator via lldb-commits]

labath added inline comments.


================
Comment at: lldb/source/Utility/Timer.cpp:98-101
   m_category.m_nanos += std::chrono::nanoseconds(timer_dur).count();
+  m_category.m_nanos_total += std::chrono::nanoseconds(total_dur).count();
+  m_category.m_nanos_child +=
+      std::chrono::nanoseconds(m_child_duration).count();
----------------
IIUC, one of these is redundant, as it can be recomputed from the other two, so we should remove it.


================
Comment at: lldb/source/Utility/Timer.cpp:110-123
+namespace {
+struct Stats {
+  uint64_t nanos;
+  uint64_t nanos_total;
+  uint64_t nanos_child;
+  uint64_t count;
+};
----------------
You can just move the `const char *` into the `Stats` struct and get rid of the std::pair. Then the `CategoryMapIteratorSortCriterion` thingy can also become a regular operator<.


================
Comment at: lldb/unittests/Utility/TimerTest.cpp:89
+  // 0.102982273 sec (total: 0.126s; child: 0.023s; count: 1) for CAT1
+  // 0.023058228 sec (total: 0.036s; child: 0.012s; count: 2) for CAT2
+  StreamString ss;
----------------
I'm not sure this second line is really helpful here. Looking at this output, I would have never guessed that these numbers mean we were running two recursive timers belonging to the same category, and the entire thing finished in 20ms.

Maybe this isn't a real usage problem, as normally we don't have recursive timers (I believe), but in that case, we probably shouldn't have them in this test either (as right now it is the only documentation about how these times are supposed to work). 

What's the reason for using recursive timers here? If you just wanted to check that the invocation count is 2, then you can wrap the two timers in `{}` blocks, so that they execute "sequentially" instead of recursively. (Which I guess would match the typical scenario where a timer-enabled function calls another timer-enabled function two times in a loop.)


================
Comment at: lldb/unittests/Utility/TimerTest.cpp:96-97
+      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))
----------------
Could you help clang-format split this string more reasonably (e.g., by manually splitting the string after the `]`)?


================
Comment at: lldb/unittests/Utility/TimerTest.cpp:100-101
+      << "String: " << ss.GetData();
+  EXPECT_GT(total1 - child1, seconds1 - 0.001);
+  EXPECT_LT(total1 - child1, seconds1 + 0.001);
+  EXPECT_EQ(1, count1);
----------------
aadsm wrote:
> davide wrote:
> > this seems ... very fragile.
> that's a good point. I'm not that familiar with the ieee754 to know what's a safe interval here, do you know?
I think you want to use `EXPECT_DOUBLE_EQ` here.


Repository:
  rG LLVM Github Monorepo

CHANGES SINCE LAST ACTION
  https://reviews.llvm.org/D61235/new/

https://reviews.llvm.org/D61235