Subzero: Enhance the timer dump format.

src/IceTimerTree.cpp

@@ -45,7 +45,8 @@ TimerIdT TimerStack::getTimerID(const IceString &Name) {
 
 // Pushes a new marker onto the timer stack.
 void TimerStack::push(TimerIdT ID) {
-  update();
+  const bool UpdateCounts = false;
+  update(UpdateCounts);
   if (Nodes[StackTop].Children.size() <= ID)
     Nodes[StackTop].Children.resize(ID + 1);
   if (Nodes[StackTop].Children[ID] == 0) {
@@ -61,7 +62,8 @@ void TimerStack::push(TimerIdT ID) {
 // Pop the top marker from the timer stack.  Validates via assert()
 // that the expected marker is popped.
 void TimerStack::pop(TimerIdT ID) {
-  update();
+  const bool UpdateCounts = true;
+  update(UpdateCounts);
   assert(StackTop);
   assert(Nodes[StackTop].Parent < StackTop);
   // Verify that the expected ID is being popped.
@@ -74,7 +76,7 @@ void TimerStack::pop(TimerIdT ID) {
 
 // At a state change (e.g. push or pop), updates the flat and
 // cumulative timings for everything on the timer stack.
-void TimerStack::update() {
+void TimerStack::update(bool UpdateCounts) {
   ++StateChangeCount;
   // Whenever the stack is about to change, we grab the time delta
   // since the last change and add it to all active cumulative
@@ -83,13 +85,20 @@ void TimerStack::update() {
   double Delta = Current - LastTimestamp;
   if (StackTop) {
     TimerIdT Leaf = Nodes[StackTop].Interior;
-    if (Leaf >= LeafTimes.size())
+    if (Leaf >= LeafTimes.size()) {
       LeafTimes.resize(Leaf + 1);
+      LeafCounts.resize(Leaf + 1);
+    }
     LeafTimes[Leaf] += Delta;
+    if (UpdateCounts)
+      ++LeafCounts[Leaf];
   }
   TTindex Prefix = StackTop;
   while (Prefix) {
     Nodes[Prefix].Time += Delta;
+    // Only update a leaf node count, not the internal node counts.
+    if (UpdateCounts && Prefix == StackTop)
+      ++Nodes[Prefix].UpdateCount;
     TTindex Next = Nodes[Prefix].Parent;
     assert(Next < Prefix);
     Prefix = Next;
@@ -105,8 +114,10 @@ void TimerStack::reset() {
   StateChangeCount = 0;
   FirstTimestamp = LastTimestamp = timestamp();
   LeafTimes.assign(LeafTimes.size(), 0);
+  LeafCounts.assign(LeafCounts.size(), 0);
   for (TimerTreeNode &Node : Nodes) {
     Node.Time = 0;
+    Node.UpdateCount = 0;
   }
 }
 
@@ -125,14 +136,36 @@ void dumpHelper(Ostream &Str, const DumpMapType &Map, double TotalTime) {
   }
 }
 
+// Write a printf() format string into Buf[], in the format "[%5lu] ",
+// where "5" is actually the number of digits in MaxVal.  E.g.,
+//   MaxVal=0     ==> "[%1lu] "
+//   MaxVal=5     ==> "[%1lu] "
+//   MaxVal=9876  ==> "[%4lu] "
+void makePrintfFormatString(char *Buf, size_t BufLen, size_t MaxVal) {
+  int NumDigits = 0;
+  do {
+    ++NumDigits;
+    MaxVal /= 10;
+  } while (MaxVal);
+  snprintf(Buf, BufLen, "[%%%dlu] ", NumDigits);
+}
+
 } // end of anonymous namespace
 
 void TimerStack::dump(Ostream &Str, bool DumpCumulative) {
-  update();
+  const bool UpdateCounts = true;
+  update(UpdateCounts);
   double TotalTime = LastTimestamp - FirstTimestamp;
   assert(TotalTime);
+  char FmtString[30], PrefixStr[30];
   if (DumpCumulative) {
     Str << Name << " - Cumulative times:\n";
+    size_t MaxInternalCount = 0;
+    for (TimerTreeNode &Node : Nodes)
+      MaxInternalCount = std::max(MaxInternalCount, Node.UpdateCount);
+    makePrintfFormatString(FmtString, llvm::array_lengthof(FmtString),
+                           MaxInternalCount);
+
     DumpMapType CumulativeMap;
     for (TTindex i = 1; i < Nodes.size(); ++i) {
       TTindex Prefix = i;
@@ -145,14 +178,25 @@ void TimerStack::dump(Ostream &Str, bool DumpCumulative) {
         assert(Nodes[Prefix].Parent < Prefix);
         Prefix = Nodes[Prefix].Parent;
       }
-      CumulativeMap.insert(std::make_pair(Nodes[i].Time, Suffix));
+      snprintf(PrefixStr, llvm::array_lengthof(PrefixStr), FmtString,
+               Nodes[i].UpdateCount);
+      CumulativeMap.insert(std::make_pair(Nodes[i].Time, PrefixStr + Suffix));
     }
     dumpHelper(Str, CumulativeMap, TotalTime);
   }
   Str << Name << " - Flat times:\n";
+  size_t MaxLeafCount = 0;
+  for (size_t Count : LeafCounts)
+    MaxLeafCount = std::max(MaxLeafCount, Count);
+  makePrintfFormatString(FmtString, llvm::array_lengthof(FmtString),
+                         MaxLeafCount);
   DumpMapType FlatMap;
   for (TimerIdT i = 0; i < LeafTimes.size(); ++i) {
-    FlatMap.insert(std::make_pair(LeafTimes[i], IDs[i]));
+    if (LeafCounts[i]) {
+      snprintf(PrefixStr, llvm::array_lengthof(PrefixStr), FmtString,
+               LeafCounts[i]);
+      FlatMap.insert(std::make_pair(LeafTimes[i], PrefixStr + IDs[i]));
+    }
   }
   dumpHelper(Str, FlatMap, TotalTime);
   Str << "Number of timer updates: " << StateChangeCount << "\n";

src/IceTimerTree.h

@@ -32,11 +32,12 @@ typedef std::vector<TimerTreeNode>::size_type TTindex;
 // index.
 class TimerTreeNode {
 public:
-  TimerTreeNode() : Parent(0), Interior(0), Time(0) {}
+  TimerTreeNode() : Parent(0), Interior(0), Time(0), UpdateCount(0) {}
   std::vector<TTindex> Children; // indexed by TimerIdT
   TTindex Parent;
   TimerIdT Interior;
   double Time;
+  size_t UpdateCount;
 };
 
 class TimerStack {
@@ -59,7 +60,7 @@ public:
   void dump(Ostream &Str, bool DumpCumulative);
 
 private:
-  void update();
+  void update(bool UpdateCounts);
   static double timestamp();
   IceString Name;
   double FirstTimestamp;
@@ -70,6 +71,7 @@ private:
   std::vector<IceString> IDs;        // indexed by TimerIdT
   std::vector<TimerTreeNode> Nodes;  // indexed by TTindex
   std::vector<double> LeafTimes;     // indexed by TimerIdT
+  std::vector<size_t> LeafCounts;    // indexed by TimerIdT
   TTindex StackTop;
 };