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 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. 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 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. 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. 108 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. 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. 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. 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. 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. 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 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%. 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 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 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