Subzero: Enhance the timer dump format.
This adds update counts to the output, e.g.:
Total across all functions - Flat times:
0.262297 (13.0%): [ 1287] linearScan
0.243965 (12.1%): [ 1287] emit
...
This is useful to know when some passes are called once per function and others are called several times per function.
BUG= none
R=jvoung@chromium.org
Review URL: https://codereview.chromium.org/655563005
diff --git a/src/IceTimerTree.cpp b/src/IceTimerTree.cpp
index cfe3ca5..1fb098d 100644
--- a/src/IceTimerTree.cpp
+++ b/src/IceTimerTree.cpp
@@ -45,7 +45,8 @@
// 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 @@
// 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 @@
// 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 @@
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 @@
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 @@
}
}
+// 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 @@
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";
