• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 //===- subzero/src/IceTimerTree.cpp - Pass timer defs ---------------------===//
2 //
3 //                        The Subzero Code Generator
4 //
5 // This file is distributed under the University of Illinois Open Source
6 // License. See LICENSE.TXT for details.
7 //
8 //===----------------------------------------------------------------------===//
9 ///
10 /// \file
11 /// \brief Defines the TimerTree class, which tracks flat and cumulative
12 /// execution time collection of call chains.
13 ///
14 //===----------------------------------------------------------------------===//
15 
16 #include "IceTimerTree.h"
17 
18 #include "IceDefs.h"
19 
20 #ifdef __clang__
21 #pragma clang diagnostic push
22 #pragma clang diagnostic ignored "-Wunused-parameter"
23 #endif // __clang__
24 
25 #include "llvm/Support/Format.h"
26 #include "llvm/Support/Timer.h"
27 
28 #ifdef __clang__
29 #pragma clang diagnostic pop
30 #endif // __clang__
31 
32 namespace Ice {
33 
TimerStack(const std::string & Name)34 TimerStack::TimerStack(const std::string &Name)
35     : Name(Name), FirstTimestamp(timestamp()), LastTimestamp(FirstTimestamp) {
36   if (!BuildDefs::timers())
37     return;
38   Nodes.resize(1); // Reserve Nodes[0] for the root node (sentinel).
39   IDs.resize(TT__num);
40   LeafTimes.resize(TT__num);
41   LeafCounts.resize(TT__num);
42 #define STR(s) #s
43 #define X(tag)                                                                 \
44   IDs[TT_##tag] = STR(tag);                                                    \
45   IDsIndex[STR(tag)] = TT_##tag;
46   TIMERTREE_TABLE;
47 #undef X
48 #undef STR
49 }
50 
51 // Returns the unique timer ID for the given Name, creating a new ID if needed.
getTimerID(const std::string & Name)52 TimerIdT TimerStack::getTimerID(const std::string &Name) {
53   if (!BuildDefs::timers())
54     return 0;
55   if (IDsIndex.find(Name) == IDsIndex.end()) {
56     IDsIndex[Name] = IDs.size();
57     IDs.push_back(Name);
58     LeafTimes.push_back(decltype(LeafTimes)::value_type());
59     LeafCounts.push_back(decltype(LeafCounts)::value_type());
60   }
61   return IDsIndex[Name];
62 }
63 
64 // Creates a mapping from TimerIdT (leaf) values in the Src timer stack into
65 // TimerIdT values in this timer stack. Creates new entries in this timer stack
66 // as needed.
67 TimerStack::TranslationType
translateIDsFrom(const TimerStack & Src)68 TimerStack::translateIDsFrom(const TimerStack &Src) {
69   size_t Size = Src.IDs.size();
70   TranslationType Mapping(Size);
71   for (TimerIdT i = 0; i < Size; ++i) {
72     Mapping[i] = getTimerID(Src.IDs[i]);
73   }
74   return Mapping;
75 }
76 
77 // Merges two timer stacks, by combining and summing corresponding entries.
78 // This timer stack is updated from Src.
mergeFrom(const TimerStack & Src)79 void TimerStack::mergeFrom(const TimerStack &Src) {
80   if (!BuildDefs::timers())
81     return;
82   TranslationType Mapping = translateIDsFrom(Src);
83   TTindex SrcIndex = 0;
84   for (const TimerTreeNode &SrcNode : Src.Nodes) {
85     // The first node is reserved as a sentinel, so avoid it.
86     if (SrcIndex > 0) {
87       // Find the full path to the Src node, translated to path components
88       // corresponding to this timer stack.
89       PathType MyPath = Src.getPath(SrcIndex, Mapping);
90       // Find a node in this timer stack corresponding to the given path,
91       // creating new interior nodes as necessary.
92       TTindex MyIndex = findPath(MyPath);
93       Nodes[MyIndex].Time += SrcNode.Time;
94       Nodes[MyIndex].UpdateCount += SrcNode.UpdateCount;
95     }
96     ++SrcIndex;
97   }
98   for (TimerIdT i = 0; i < Src.LeafTimes.size(); ++i) {
99     LeafTimes[Mapping[i]] += Src.LeafTimes[i];
100     LeafCounts[Mapping[i]] += Src.LeafCounts[i];
101   }
102   StateChangeCount += Src.StateChangeCount;
103 }
104 
105 // Constructs a path consisting of the sequence of leaf values leading to a
106 // given node, with the Mapping translation applied to the leaf values. The
107 // path ends up being in "reverse" order, i.e. from leaf to root.
getPath(TTindex Index,const TranslationType & Mapping) const108 TimerStack::PathType TimerStack::getPath(TTindex Index,
109                                          const TranslationType &Mapping) const {
110   PathType Path;
111   while (Index) {
112     Path.push_back(Mapping[Nodes[Index].Interior]);
113     assert(Nodes[Index].Parent < Index);
114     Index = Nodes[Index].Parent;
115   }
116   return Path;
117 }
118 
119 // Given a parent node and a leaf ID, returns the index of the parent's child
120 // ID, creating a new node for the child as necessary.
getChildIndex(TimerStack::TTindex Parent,TimerIdT ID)121 TimerStack::TTindex TimerStack::getChildIndex(TimerStack::TTindex Parent,
122                                               TimerIdT ID) {
123   if (Nodes[Parent].Children.size() <= ID)
124     Nodes[Parent].Children.resize(ID + 1);
125   if (Nodes[Parent].Children[ID] == 0) {
126     TTindex Size = Nodes.size();
127     Nodes[Parent].Children[ID] = Size;
128     Nodes.resize(Size + 1);
129     Nodes[Size].Parent = Parent;
130     Nodes[Size].Interior = ID;
131   }
132   return Nodes[Parent].Children[ID];
133 }
134 
135 // Finds a node in the timer stack corresponding to the given path, creating
136 // new interior nodes as necessary.
findPath(const PathType & Path)137 TimerStack::TTindex TimerStack::findPath(const PathType &Path) {
138   TTindex CurIndex = 0;
139   // The path is in reverse order (leaf to root), so it needs to be followed in
140   // reverse.
141   for (TTindex Index : reverse_range(Path)) {
142     CurIndex = getChildIndex(CurIndex, Index);
143   }
144   assert(CurIndex); // shouldn't be the sentinel node
145   return CurIndex;
146 }
147 
148 // Pushes a new marker onto the timer stack.
push(TimerIdT ID)149 void TimerStack::push(TimerIdT ID) {
150   if (!BuildDefs::timers())
151     return;
152   constexpr bool UpdateCounts = false;
153   update(UpdateCounts);
154   StackTop = getChildIndex(StackTop, ID);
155   assert(StackTop);
156 }
157 
158 // Pops the top marker from the timer stack. Validates via assert() that the
159 // expected marker is popped.
pop(TimerIdT ID)160 void TimerStack::pop(TimerIdT ID) {
161   if (!BuildDefs::timers())
162     return;
163   constexpr bool UpdateCounts = true;
164   update(UpdateCounts);
165   assert(StackTop);
166   assert(Nodes[StackTop].Parent < StackTop);
167   // Verify that the expected ID is being popped.
168   assert(Nodes[StackTop].Interior == ID);
169   (void)ID;
170   // Verify that the parent's child points to the current stack top.
171   assert(Nodes[Nodes[StackTop].Parent].Children[ID] == StackTop);
172   StackTop = Nodes[StackTop].Parent;
173 }
174 
175 // At a state change (e.g. push or pop), updates the flat and cumulative
176 // timings for everything on the timer stack.
update(bool UpdateCounts)177 void TimerStack::update(bool UpdateCounts) {
178   if (!BuildDefs::timers())
179     return;
180   ++StateChangeCount;
181   // Whenever the stack is about to change, we grab the time delta since the
182   // last change and add it to all active cumulative elements and to the flat
183   // element for the top of the stack.
184   double Current = timestamp();
185   double Delta = Current - LastTimestamp;
186   if (StackTop) {
187     TimerIdT Leaf = Nodes[StackTop].Interior;
188     if (Leaf >= LeafTimes.size()) {
189       LeafTimes.resize(Leaf + 1);
190       LeafCounts.resize(Leaf + 1);
191     }
192     LeafTimes[Leaf] += Delta;
193     if (UpdateCounts)
194       ++LeafCounts[Leaf];
195   }
196   TTindex Prefix = StackTop;
197   while (Prefix) {
198     Nodes[Prefix].Time += Delta;
199     // Only update a leaf node count, not the internal node counts.
200     if (UpdateCounts && Prefix == StackTop)
201       ++Nodes[Prefix].UpdateCount;
202     TTindex Next = Nodes[Prefix].Parent;
203     assert(Next < Prefix);
204     Prefix = Next;
205   }
206   // Capture the next timestamp *after* the updates are finished. This
207   // minimizes how much the timer can perturb the reported timing. The numbers
208   // may not sum to 100%, and the missing amount is indicative of the overhead
209   // of timing.
210   LastTimestamp = timestamp();
211 }
212 
reset()213 void TimerStack::reset() {
214   if (!BuildDefs::timers())
215     return;
216   StateChangeCount = 0;
217   FirstTimestamp = LastTimestamp = timestamp();
218   LeafTimes.assign(LeafTimes.size(), 0);
219   LeafCounts.assign(LeafCounts.size(), 0);
220   for (TimerTreeNode &Node : Nodes) {
221     Node.Time = 0;
222     Node.UpdateCount = 0;
223   }
224 }
225 
226 namespace {
227 
228 using DumpMapType = std::multimap<double, std::string>;
229 
230 // Dump the Map items in reverse order of their time contribution.  If
231 // AddPercents is true (i.e. for printing "flat times"), it also prints a
232 // cumulative percentage column, and recalculates TotalTime as the sum of all
233 // the individual times so that cumulative percentage adds up to 100%.
dumpHelper(Ostream & Str,const DumpMapType & Map,double TotalTime,bool AddPercents)234 void dumpHelper(Ostream &Str, const DumpMapType &Map, double TotalTime,
235                 bool AddPercents) {
236   if (!BuildDefs::timers())
237     return;
238   if (AddPercents) {
239     // Recalculate TotalTime as the sum of the individual times.  This is
240     // because the individual times generally add up to less than 100% because
241     // of timer overhead.
242     TotalTime = 0;
243     for (const auto &I : Map) {
244       TotalTime += I.first;
245     }
246   }
247   double Sum = 0;
248   for (const auto &I : reverse_range(Map)) {
249     Sum += I.first;
250     if (AddPercents) {
251       Str << llvm::format("  %10.6f %4.1f%% %5.1f%% ", I.first,
252                           I.first * 100 / TotalTime, Sum * 100 / TotalTime)
253           << I.second << "\n";
254     } else {
255       Str << llvm::format("  %10.6f %4.1f%% ", I.first,
256                           I.first * 100 / TotalTime) << I.second << "\n";
257     }
258   }
259 }
260 
261 } // end of anonymous namespace
262 
dump(Ostream & Str,bool DumpCumulative)263 void TimerStack::dump(Ostream &Str, bool DumpCumulative) {
264   if (!BuildDefs::timers())
265     return;
266   constexpr bool UpdateCounts = true;
267   update(UpdateCounts);
268   double TotalTime = LastTimestamp - FirstTimestamp;
269   assert(TotalTime);
270   char PrefixStr[30];
271   if (DumpCumulative) {
272     Str << Name << " - Cumulative times:\n"
273                    "     Seconds   Pct  EventCnt TimerPath\n";
274     DumpMapType CumulativeMap;
275     for (TTindex i = 1; i < Nodes.size(); ++i) {
276       TTindex Prefix = i;
277       std::string Suffix = "";
278       while (Prefix) {
279         if (Suffix.empty())
280           Suffix = IDs[Nodes[Prefix].Interior];
281         else
282           Suffix = IDs[Nodes[Prefix].Interior] + "." + Suffix;
283         assert(Nodes[Prefix].Parent < Prefix);
284         Prefix = Nodes[Prefix].Parent;
285       }
286       snprintf(PrefixStr, llvm::array_lengthof(PrefixStr), "%9zu ",
287                Nodes[i].UpdateCount);
288       CumulativeMap.insert(std::make_pair(Nodes[i].Time, PrefixStr + Suffix));
289     }
290     constexpr bool NoAddPercents = false;
291     dumpHelper(Str, CumulativeMap, TotalTime, NoAddPercents);
292   }
293   Str << Name << " - Flat times:\n"
294                  "     Seconds   Pct CumPct  EventCnt TimerName\n";
295   DumpMapType FlatMap;
296   for (TimerIdT i = 0; i < LeafTimes.size(); ++i) {
297     if (LeafCounts[i]) {
298       snprintf(PrefixStr, llvm::array_lengthof(PrefixStr), "%9zu ",
299                LeafCounts[i]);
300       FlatMap.insert(std::make_pair(LeafTimes[i], PrefixStr + IDs[i]));
301     }
302   }
303   constexpr bool AddPercents = true;
304   dumpHelper(Str, FlatMap, TotalTime, AddPercents);
305   Str << "Number of timer updates: " << StateChangeCount << "\n";
306 }
307 
timestamp()308 double TimerStack::timestamp() {
309   // TODO: Implement in terms of std::chrono for C++11.
310   return llvm::TimeRecord::getCurrentTime(false).getWallTime();
311 }
312 
313 } // end of namespace Ice
314