| //===- subzero/src/IceTimerTree.cpp - Pass timer defs ---------------------===// | |
| // | |
| // The Subzero Code Generator | |
| // | |
| // This file is distributed under the University of Illinois Open Source | |
| // License. See LICENSE.TXT for details. | |
| // | |
| //===----------------------------------------------------------------------===// | |
| /// | |
| /// \file | |
| /// \brief Defines the TimerTree class, which tracks flat and cumulative | |
| /// execution time collection of call chains. | |
| /// | |
| //===----------------------------------------------------------------------===// | |
| #include "IceTimerTree.h" | |
| #include "IceDefs.h" | |
| #ifdef __clang__ | |
| #pragma clang diagnostic push | |
| #pragma clang diagnostic ignored "-Wunused-parameter" | |
| #endif // __clang__ | |
| #include "llvm/Support/Format.h" | |
| #include "llvm/Support/Timer.h" | |
| #ifdef __clang__ | |
| #pragma clang diagnostic pop | |
| #endif // __clang__ | |
| namespace Ice { | |
| TimerStack::TimerStack(const std::string &Name) | |
| : Name(Name), FirstTimestamp(timestamp()), LastTimestamp(FirstTimestamp) { | |
| if (!BuildDefs::timers()) | |
| return; | |
| Nodes.resize(1); // Reserve Nodes[0] for the root node (sentinel). | |
| IDs.resize(TT__num); | |
| LeafTimes.resize(TT__num); | |
| LeafCounts.resize(TT__num); | |
| #define STR(s) #s | |
| #define X(tag) \ | |
| IDs[TT_##tag] = STR(tag); \ | |
| IDsIndex[STR(tag)] = TT_##tag; | |
| TIMERTREE_TABLE; | |
| #undef X | |
| #undef STR | |
| } | |
| // Returns the unique timer ID for the given Name, creating a new ID if needed. | |
| TimerIdT TimerStack::getTimerID(const std::string &Name) { | |
| if (!BuildDefs::timers()) | |
| return 0; | |
| if (IDsIndex.find(Name) == IDsIndex.end()) { | |
| IDsIndex[Name] = IDs.size(); | |
| IDs.push_back(Name); | |
| LeafTimes.push_back(decltype(LeafTimes)::value_type()); | |
| LeafCounts.push_back(decltype(LeafCounts)::value_type()); | |
| } | |
| return IDsIndex[Name]; | |
| } | |
| // Creates a mapping from TimerIdT (leaf) values in the Src timer stack into | |
| // TimerIdT values in this timer stack. Creates new entries in this timer stack | |
| // as needed. | |
| TimerStack::TranslationType | |
| TimerStack::translateIDsFrom(const TimerStack &Src) { | |
| size_t Size = Src.IDs.size(); | |
| TranslationType Mapping(Size); | |
| for (TimerIdT i = 0; i < Size; ++i) { | |
| Mapping[i] = getTimerID(Src.IDs[i]); | |
| } | |
| return Mapping; | |
| } | |
| // Merges two timer stacks, by combining and summing corresponding entries. | |
| // This timer stack is updated from Src. | |
| void TimerStack::mergeFrom(const TimerStack &Src) { | |
| if (!BuildDefs::timers()) | |
| return; | |
| TranslationType Mapping = translateIDsFrom(Src); | |
| TTindex SrcIndex = 0; | |
| for (const TimerTreeNode &SrcNode : Src.Nodes) { | |
| // The first node is reserved as a sentinel, so avoid it. | |
| if (SrcIndex > 0) { | |
| // Find the full path to the Src node, translated to path components | |
| // corresponding to this timer stack. | |
| PathType MyPath = Src.getPath(SrcIndex, Mapping); | |
| // Find a node in this timer stack corresponding to the given path, | |
| // creating new interior nodes as necessary. | |
| TTindex MyIndex = findPath(MyPath); | |
| Nodes[MyIndex].Time += SrcNode.Time; | |
| Nodes[MyIndex].UpdateCount += SrcNode.UpdateCount; | |
| } | |
| ++SrcIndex; | |
| } | |
| for (TimerIdT i = 0; i < Src.LeafTimes.size(); ++i) { | |
| LeafTimes[Mapping[i]] += Src.LeafTimes[i]; | |
| LeafCounts[Mapping[i]] += Src.LeafCounts[i]; | |
| } | |
| StateChangeCount += Src.StateChangeCount; | |
| } | |
| // Constructs a path consisting of the sequence of leaf values leading to a | |
| // given node, with the Mapping translation applied to the leaf values. The | |
| // path ends up being in "reverse" order, i.e. from leaf to root. | |
| TimerStack::PathType TimerStack::getPath(TTindex Index, | |
| const TranslationType &Mapping) const { | |
| PathType Path; | |
| while (Index) { | |
| Path.push_back(Mapping[Nodes[Index].Interior]); | |
| assert(Nodes[Index].Parent < Index); | |
| Index = Nodes[Index].Parent; | |
| } | |
| return Path; | |
| } | |
| // Given a parent node and a leaf ID, returns the index of the parent's child | |
| // ID, creating a new node for the child as necessary. | |
| TimerStack::TTindex TimerStack::getChildIndex(TimerStack::TTindex Parent, | |
| TimerIdT ID) { | |
| if (Nodes[Parent].Children.size() <= ID) | |
| Nodes[Parent].Children.resize(ID + 1); | |
| if (Nodes[Parent].Children[ID] == 0) { | |
| TTindex Size = Nodes.size(); | |
| Nodes[Parent].Children[ID] = Size; | |
| Nodes.resize(Size + 1); | |
| Nodes[Size].Parent = Parent; | |
| Nodes[Size].Interior = ID; | |
| } | |
| return Nodes[Parent].Children[ID]; | |
| } | |
| // Finds a node in the timer stack corresponding to the given path, creating | |
| // new interior nodes as necessary. | |
| TimerStack::TTindex TimerStack::findPath(const PathType &Path) { | |
| TTindex CurIndex = 0; | |
| // The path is in reverse order (leaf to root), so it needs to be followed in | |
| // reverse. | |
| for (TTindex Index : reverse_range(Path)) { | |
| CurIndex = getChildIndex(CurIndex, Index); | |
| } | |
| assert(CurIndex); // shouldn't be the sentinel node | |
| return CurIndex; | |
| } | |
| // Pushes a new marker onto the timer stack. | |
| void TimerStack::push(TimerIdT ID) { | |
| if (!BuildDefs::timers()) | |
| return; | |
| constexpr bool UpdateCounts = false; | |
| update(UpdateCounts); | |
| StackTop = getChildIndex(StackTop, ID); | |
| assert(StackTop); | |
| } | |
| // Pops the top marker from the timer stack. Validates via assert() that the | |
| // expected marker is popped. | |
| void TimerStack::pop(TimerIdT ID) { | |
| if (!BuildDefs::timers()) | |
| return; | |
| constexpr bool UpdateCounts = true; | |
| update(UpdateCounts); | |
| assert(StackTop); | |
| assert(Nodes[StackTop].Parent < StackTop); | |
| // Verify that the expected ID is being popped. | |
| assert(Nodes[StackTop].Interior == ID); | |
| (void)ID; | |
| // Verify that the parent's child points to the current stack top. | |
| assert(Nodes[Nodes[StackTop].Parent].Children[ID] == StackTop); | |
| StackTop = Nodes[StackTop].Parent; | |
| } | |
| // At a state change (e.g. push or pop), updates the flat and cumulative | |
| // timings for everything on the timer stack. | |
| void TimerStack::update(bool UpdateCounts) { | |
| if (!BuildDefs::timers()) | |
| return; | |
| ++StateChangeCount; | |
| // Whenever the stack is about to change, we grab the time delta since the | |
| // last change and add it to all active cumulative elements and to the flat | |
| // element for the top of the stack. | |
| double Current = timestamp(); | |
| double Delta = Current - LastTimestamp; | |
| if (StackTop) { | |
| TimerIdT Leaf = Nodes[StackTop].Interior; | |
| 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; | |
| } | |
| // Capture the next timestamp *after* the updates are finished. This | |
| // minimizes how much the timer can perturb the reported timing. The numbers | |
| // may not sum to 100%, and the missing amount is indicative of the overhead | |
| // of timing. | |
| LastTimestamp = timestamp(); | |
| } | |
| void TimerStack::reset() { | |
| if (!BuildDefs::timers()) | |
| return; | |
| 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; | |
| } | |
| } | |
| namespace { | |
| using DumpMapType = std::multimap<double, std::string>; | |
| // Dump the Map items in reverse order of their time contribution. If | |
| // AddPercents is true (i.e. for printing "flat times"), it also prints a | |
| // cumulative percentage column, and recalculates TotalTime as the sum of all | |
| // the individual times so that cumulative percentage adds up to 100%. | |
| void dumpHelper(Ostream &Str, const DumpMapType &Map, double TotalTime, | |
| bool AddPercents) { | |
| if (!BuildDefs::timers()) | |
| return; | |
| if (AddPercents) { | |
| // Recalculate TotalTime as the sum of the individual times. This is | |
| // because the individual times generally add up to less than 100% because | |
| // of timer overhead. | |
| TotalTime = 0; | |
| for (const auto &I : Map) { | |
| TotalTime += I.first; | |
| } | |
| } | |
| double Sum = 0; | |
| for (const auto &I : reverse_range(Map)) { | |
| Sum += I.first; | |
| if (AddPercents) { | |
| Str << llvm::format(" %10.6f %4.1f%% %5.1f%% ", I.first, | |
| I.first * 100 / TotalTime, Sum * 100 / TotalTime) | |
| << I.second << "\n"; | |
| } else { | |
| Str << llvm::format(" %10.6f %4.1f%% ", I.first, | |
| I.first * 100 / TotalTime) | |
| << I.second << "\n"; | |
| } | |
| } | |
| } | |
| } // end of anonymous namespace | |
| void TimerStack::dump(Ostream &Str, bool DumpCumulative) { | |
| if (!BuildDefs::timers()) | |
| return; | |
| constexpr bool UpdateCounts = true; | |
| update(UpdateCounts); | |
| double TotalTime = LastTimestamp - FirstTimestamp; | |
| assert(TotalTime); | |
| char PrefixStr[30]; | |
| if (DumpCumulative) { | |
| Str << Name | |
| << " - Cumulative times:\n" | |
| " Seconds Pct EventCnt TimerPath\n"; | |
| DumpMapType CumulativeMap; | |
| for (TTindex i = 1; i < Nodes.size(); ++i) { | |
| TTindex Prefix = i; | |
| std::string Suffix = ""; | |
| while (Prefix) { | |
| if (Suffix.empty()) | |
| Suffix = IDs[Nodes[Prefix].Interior]; | |
| else | |
| Suffix = IDs[Nodes[Prefix].Interior] + "." + Suffix; | |
| assert(Nodes[Prefix].Parent < Prefix); | |
| Prefix = Nodes[Prefix].Parent; | |
| } | |
| snprintf(PrefixStr, llvm::array_lengthof(PrefixStr), "%9zu ", | |
| Nodes[i].UpdateCount); | |
| CumulativeMap.insert(std::make_pair(Nodes[i].Time, PrefixStr + Suffix)); | |
| } | |
| constexpr bool NoAddPercents = false; | |
| dumpHelper(Str, CumulativeMap, TotalTime, NoAddPercents); | |
| } | |
| Str << Name | |
| << " - Flat times:\n" | |
| " Seconds Pct CumPct EventCnt TimerName\n"; | |
| DumpMapType FlatMap; | |
| for (TimerIdT i = 0; i < LeafTimes.size(); ++i) { | |
| if (LeafCounts[i]) { | |
| snprintf(PrefixStr, llvm::array_lengthof(PrefixStr), "%9zu ", | |
| LeafCounts[i]); | |
| FlatMap.insert(std::make_pair(LeafTimes[i], PrefixStr + IDs[i])); | |
| } | |
| } | |
| constexpr bool AddPercents = true; | |
| dumpHelper(Str, FlatMap, TotalTime, AddPercents); | |
| Str << "Number of timer updates: " << StateChangeCount << "\n"; | |
| } | |
| double TimerStack::timestamp() { | |
| // TODO: Implement in terms of std::chrono for C++11. | |
| return llvm::TimeRecord::getCurrentTime(false).getWallTime(); | |
| } | |
| } // end of namespace Ice |