LLVM 17.0.0git
Timer.cpp
Go to the documentation of this file.
1//===-- Timer.cpp - Interval Timing Support -------------------------------===//
2//
3// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
4// See https://llvm.org/LICENSE.txt for license information.
5// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
6//
7//===----------------------------------------------------------------------===//
8//
9/// \file Interval Timing implementation.
10//
11//===----------------------------------------------------------------------===//
12
13#include "llvm/Support/Timer.h"
14
15#include "DebugOptions.h"
16
17#include "llvm/ADT/Statistic.h"
18#include "llvm/ADT/StringMap.h"
19#include "llvm/Config/config.h"
22#include "llvm/Support/Format.h"
24#include "llvm/Support/Mutex.h"
29#include <limits>
30
31#if HAVE_UNISTD_H
32#include <unistd.h>
33#endif
34
35#ifdef HAVE_PROC_PID_RUSAGE
36#include <libproc.h>
37#endif
38
39using namespace llvm;
40
41// This ugly hack is brought to you courtesy of constructor/destructor ordering
42// being unspecified by C++. Basically the problem is that a Statistic object
43// gets destroyed, which ends up calling 'GetLibSupportInfoOutputFile()'
44// (below), which calls this function. LibSupportInfoOutputFilename used to be
45// a global variable, but sometimes it would get destroyed before the Statistic,
46// causing havoc to ensue. We "fix" this by creating the string the first time
47// it is needed and never destroying it.
49static std::string &getLibSupportInfoOutputFilename() {
51}
52
54
55/// Allows llvm::Timer to emit signposts when supported.
57
58namespace {
59struct CreateTrackSpace {
60 static void *call() {
61 return new cl::opt<bool>("track-memory",
62 cl::desc("Enable -time-passes memory "
63 "tracking (this may be slow)"),
65 }
66};
67static ManagedStatic<cl::opt<bool>, CreateTrackSpace> TrackSpace;
68struct CreateInfoOutputFilename {
69 static void *call() {
71 "info-output-file", cl::value_desc("filename"),
72 cl::desc("File to append -stats and -timer output to"), cl::Hidden,
74 }
75};
76static ManagedStatic<cl::opt<std::string, true>, CreateInfoOutputFilename>
77 InfoOutputFilename;
78struct CreateSortTimers {
79 static void *call() {
80 return new cl::opt<bool>(
81 "sort-timers",
82 cl::desc("In the report, sort the timers in each group "
83 "in wall clock time order"),
84 cl::init(true), cl::Hidden);
85 }
86};
87ManagedStatic<cl::opt<bool>, CreateSortTimers> SortTimers;
88} // namespace
89
91 *TrackSpace;
92 *InfoOutputFilename;
93 *SortTimers;
94}
95
96std::unique_ptr<raw_fd_ostream> llvm::CreateInfoOutputFile() {
98 if (OutputFilename.empty())
99 return std::make_unique<raw_fd_ostream>(2, false); // stderr.
100 if (OutputFilename == "-")
101 return std::make_unique<raw_fd_ostream>(1, false); // stdout.
102
103 // Append mode is used because the info output file is opened and closed
104 // each time -stats or -time-passes wants to print output to it. To
105 // compensate for this, the test-suite Makefiles have code to delete the
106 // info output file before running commands which write to it.
107 std::error_code EC;
108 auto Result = std::make_unique<raw_fd_ostream>(
110 if (!EC)
111 return Result;
112
113 errs() << "Error opening info-output-file '"
114 << OutputFilename << " for appending!\n";
115 return std::make_unique<raw_fd_ostream>(2, false); // stderr.
116}
117
118namespace {
119struct CreateDefaultTimerGroup {
120 static void *call() {
121 return new TimerGroup("misc", "Miscellaneous Ungrouped Timers");
122 }
123};
124} // namespace
127
128//===----------------------------------------------------------------------===//
129// Timer Implementation
130//===----------------------------------------------------------------------===//
131
132void Timer::init(StringRef TimerName, StringRef TimerDescription) {
133 init(TimerName, TimerDescription, *getDefaultTimerGroup());
134}
135
136void Timer::init(StringRef TimerName, StringRef TimerDescription,
137 TimerGroup &tg) {
138 assert(!TG && "Timer already initialized");
139 Name.assign(TimerName.begin(), TimerName.end());
140 Description.assign(TimerDescription.begin(), TimerDescription.end());
141 Running = Triggered = false;
142 TG = &tg;
143 TG->addTimer(*this);
144}
145
147 if (!TG) return; // Never initialized, or already cleared.
148 TG->removeTimer(*this);
149}
150
151static inline size_t getMemUsage() {
152 if (!*TrackSpace)
153 return 0;
155}
156
158#if defined(HAVE_UNISTD_H) && defined(HAVE_PROC_PID_RUSAGE) && \
159 defined(RUSAGE_INFO_V4)
160 struct rusage_info_v4 ru;
161 if (proc_pid_rusage(getpid(), RUSAGE_INFO_V4, (rusage_info_t *)&ru) == 0) {
162 return ru.ri_instructions;
163 }
164#endif
165 return 0;
166}
167
169 using Seconds = std::chrono::duration<double, std::ratio<1>>;
170 TimeRecord Result;
172 std::chrono::nanoseconds user, sys;
173
174 if (Start) {
175 Result.MemUsed = getMemUsage();
176 Result.InstructionsExecuted = getCurInstructionsExecuted();
178 } else {
180 Result.InstructionsExecuted = getCurInstructionsExecuted();
181 Result.MemUsed = getMemUsage();
182 }
183
184 Result.WallTime = Seconds(now.time_since_epoch()).count();
185 Result.UserTime = Seconds(user).count();
186 Result.SystemTime = Seconds(sys).count();
187 return Result;
188}
189
191 assert(!Running && "Cannot start a running timer");
192 Running = Triggered = true;
193 Signposts->startInterval(this, getName());
194 StartTime = TimeRecord::getCurrentTime(true);
195}
196
198 assert(Running && "Cannot stop a paused timer");
199 Running = false;
200 Time += TimeRecord::getCurrentTime(false);
201 Time -= StartTime;
202 Signposts->endInterval(this, getName());
203}
204
206 Running = Triggered = false;
207 Time = StartTime = TimeRecord();
208}
209
210static void printVal(double Val, double Total, raw_ostream &OS) {
211 if (Total < 1e-7) // Avoid dividing by zero.
212 OS << " ----- ";
213 else
214 OS << format(" %7.4f (%5.1f%%)", Val, Val*100/Total);
215}
216
218 if (Total.getUserTime())
219 printVal(getUserTime(), Total.getUserTime(), OS);
220 if (Total.getSystemTime())
221 printVal(getSystemTime(), Total.getSystemTime(), OS);
222 if (Total.getProcessTime())
223 printVal(getProcessTime(), Total.getProcessTime(), OS);
224 printVal(getWallTime(), Total.getWallTime(), OS);
225
226 OS << " ";
227
228 if (Total.getMemUsed())
229 OS << format("%9" PRId64 " ", (int64_t)getMemUsed());
230 if (Total.getInstructionsExecuted())
231 OS << format("%9" PRId64 " ", (int64_t)getInstructionsExecuted());
232}
233
234
235//===----------------------------------------------------------------------===//
236// NamedRegionTimer Implementation
237//===----------------------------------------------------------------------===//
238
239namespace {
240
241typedef StringMap<Timer> Name2TimerMap;
242
243class Name2PairMap {
245public:
246 ~Name2PairMap() {
247 for (StringMap<std::pair<TimerGroup*, Name2TimerMap> >::iterator
248 I = Map.begin(), E = Map.end(); I != E; ++I)
249 delete I->second.first;
250 }
251
252 Timer &get(StringRef Name, StringRef Description, StringRef GroupName,
253 StringRef GroupDescription) {
255
256 std::pair<TimerGroup*, Name2TimerMap> &GroupEntry = Map[GroupName];
257
258 if (!GroupEntry.first)
259 GroupEntry.first = new TimerGroup(GroupName, GroupDescription);
260
261 Timer &T = GroupEntry.second[Name];
262 if (!T.isInitialized())
263 T.init(Name, Description, *GroupEntry.first);
264 return T;
265 }
266};
267
268}
269
271
273 StringRef GroupName,
274 StringRef GroupDescription, bool Enabled)
275 : TimeRegion(!Enabled ? nullptr
276 : &NamedGroupedTimers->get(Name, Description, GroupName,
277 GroupDescription)) {}
278
279//===----------------------------------------------------------------------===//
280// TimerGroup Implementation
281//===----------------------------------------------------------------------===//
282
283/// This is the global list of TimerGroups, maintained by the TimerGroup
284/// ctor/dtor and is protected by the TimerLock lock.
285static TimerGroup *TimerGroupList = nullptr;
286
287TimerGroup::TimerGroup(StringRef Name, StringRef Description)
288 : Name(Name.begin(), Name.end()),
289 Description(Description.begin(), Description.end()) {
290 // Add the group to TimerGroupList.
292 if (TimerGroupList)
293 TimerGroupList->Prev = &Next;
294 Next = TimerGroupList;
295 Prev = &TimerGroupList;
296 TimerGroupList = this;
297}
298
299TimerGroup::TimerGroup(StringRef Name, StringRef Description,
300 const StringMap<TimeRecord> &Records)
301 : TimerGroup(Name, Description) {
302 TimersToPrint.reserve(Records.size());
303 for (const auto &P : Records)
304 TimersToPrint.emplace_back(P.getValue(), std::string(P.getKey()),
305 std::string(P.getKey()));
306 assert(TimersToPrint.size() == Records.size() && "Size mismatch");
307}
308
310 // If the timer group is destroyed before the timers it owns, accumulate and
311 // print the timing data.
312 while (FirstTimer)
313 removeTimer(*FirstTimer);
314
315 // Remove the group from the TimerGroupList.
317 *Prev = Next;
318 if (Next)
319 Next->Prev = Prev;
320}
321
322
323void TimerGroup::removeTimer(Timer &T) {
325
326 // If the timer was started, move its data to TimersToPrint.
327 if (T.hasTriggered())
328 TimersToPrint.emplace_back(T.Time, T.Name, T.Description);
329
330 T.TG = nullptr;
331
332 // Unlink the timer from our list.
333 *T.Prev = T.Next;
334 if (T.Next)
335 T.Next->Prev = T.Prev;
336
337 // Print the report when all timers in this group are destroyed if some of
338 // them were started.
339 if (FirstTimer || TimersToPrint.empty())
340 return;
341
342 std::unique_ptr<raw_ostream> OutStream = CreateInfoOutputFile();
343 PrintQueuedTimers(*OutStream);
344}
345
346void TimerGroup::addTimer(Timer &T) {
348
349 // Add the timer to our list.
350 if (FirstTimer)
351 FirstTimer->Prev = &T.Next;
352 T.Next = FirstTimer;
353 T.Prev = &FirstTimer;
354 FirstTimer = &T;
355}
356
357void TimerGroup::PrintQueuedTimers(raw_ostream &OS) {
358 // Perhaps sort the timers in descending order by amount of time taken.
359 if (*SortTimers)
360 llvm::sort(TimersToPrint);
361
363 for (const PrintRecord &Record : TimersToPrint)
364 Total += Record.Time;
365
366 // Print out timing header.
367 OS << "===" << std::string(73, '-') << "===\n";
368 // Figure out how many spaces to indent TimerGroup name.
369 unsigned Padding = (80-Description.length())/2;
370 if (Padding > 80) Padding = 0; // Don't allow "negative" numbers
371 OS.indent(Padding) << Description << '\n';
372 OS << "===" << std::string(73, '-') << "===\n";
373
374 // If this is not an collection of ungrouped times, print the total time.
375 // Ungrouped timers don't really make sense to add up. We still print the
376 // TOTAL line to make the percentages make sense.
377 if (this != getDefaultTimerGroup())
378 OS << format(" Total Execution Time: %5.4f seconds (%5.4f wall clock)\n",
379 Total.getProcessTime(), Total.getWallTime());
380 OS << '\n';
381
382 if (Total.getUserTime())
383 OS << " ---User Time---";
384 if (Total.getSystemTime())
385 OS << " --System Time--";
386 if (Total.getProcessTime())
387 OS << " --User+System--";
388 OS << " ---Wall Time---";
389 if (Total.getMemUsed())
390 OS << " ---Mem---";
391 if (Total.getInstructionsExecuted())
392 OS << " ---Instr---";
393 OS << " --- Name ---\n";
394
395 // Loop through all of the timing data, printing it out.
396 for (const PrintRecord &Record : llvm::reverse(TimersToPrint)) {
397 Record.Time.print(Total, OS);
398 OS << Record.Description << '\n';
399 }
400
401 Total.print(Total, OS);
402 OS << "Total\n\n";
403 OS.flush();
404
405 TimersToPrint.clear();
406}
407
408void TimerGroup::prepareToPrintList(bool ResetTime) {
409 // See if any of our timers were started, if so add them to TimersToPrint.
410 for (Timer *T = FirstTimer; T; T = T->Next) {
411 if (!T->hasTriggered()) continue;
412 bool WasRunning = T->isRunning();
413 if (WasRunning)
414 T->stopTimer();
415
416 TimersToPrint.emplace_back(T->Time, T->Name, T->Description);
417
418 if (ResetTime)
419 T->clear();
420
421 if (WasRunning)
422 T->startTimer();
423 }
424}
425
426void TimerGroup::print(raw_ostream &OS, bool ResetAfterPrint) {
427 {
428 // After preparing the timers we can free the lock
430 prepareToPrintList(ResetAfterPrint);
431 }
432
433 // If any timers were started, print the group.
434 if (!TimersToPrint.empty())
435 PrintQueuedTimers(OS);
436}
437
440 for (Timer *T = FirstTimer; T; T = T->Next)
441 T->clear();
442}
443
446
447 for (TimerGroup *TG = TimerGroupList; TG; TG = TG->Next)
448 TG->print(OS);
449}
450
453 for (TimerGroup *TG = TimerGroupList; TG; TG = TG->Next)
454 TG->clear();
455}
456
457void TimerGroup::printJSONValue(raw_ostream &OS, const PrintRecord &R,
458 const char *suffix, double Value) {
459 assert(yaml::needsQuotes(Name) == yaml::QuotingType::None &&
460 "TimerGroup name should not need quotes");
461 assert(yaml::needsQuotes(R.Name) == yaml::QuotingType::None &&
462 "Timer name should not need quotes");
463 constexpr auto max_digits10 = std::numeric_limits<double>::max_digits10;
464 OS << "\t\"time." << Name << '.' << R.Name << suffix
465 << "\": " << format("%.*e", max_digits10 - 1, Value);
466}
467
468const char *TimerGroup::printJSONValues(raw_ostream &OS, const char *delim) {
470
471 prepareToPrintList(false);
472 for (const PrintRecord &R : TimersToPrint) {
473 OS << delim;
474 delim = ",\n";
475
476 const TimeRecord &T = R.Time;
477 printJSONValue(OS, R, ".wall", T.getWallTime());
478 OS << delim;
479 printJSONValue(OS, R, ".user", T.getUserTime());
480 OS << delim;
481 printJSONValue(OS, R, ".sys", T.getSystemTime());
482 if (T.getMemUsed()) {
483 OS << delim;
484 printJSONValue(OS, R, ".mem", T.getMemUsed());
485 }
486 if (T.getInstructionsExecuted()) {
487 OS << delim;
488 printJSONValue(OS, R, ".instr", T.getInstructionsExecuted());
489 }
490 }
491 TimersToPrint.clear();
492 return delim;
493}
494
495const char *TimerGroup::printAllJSONValues(raw_ostream &OS, const char *delim) {
497 for (TimerGroup *TG = TimerGroupList; TG; TG = TG->Next)
498 delim = TG->printJSONValues(OS, delim);
499 return delim;
500}
501
504 (void)*NamedGroupedTimers;
505}
506
507std::unique_ptr<TimerGroup> TimerGroup::aquireDefaultGroup() {
508 return std::unique_ptr<TimerGroup>(DefaultTimerGroup.claim());
509}
This file defines the StringMap class.
static sys::TimePoint< std::chrono::seconds > now(bool Deterministic)
static GCRegistry::Add< CoreCLRGC > E("coreclr", "CoreCLR-compatible GC")
std::string Name
#define I(x, y, z)
Definition: MD5.cpp:58
static cl::opt< std::string > OutputFilename("o", cl::desc("Output filename"), cl::value_desc("filename"), cl::init("-"))
#define T
#define P(N)
Provides a library for accessing information about this process and other processes on the operating ...
assert(ImpDefSCC.getReg()==AMDGPU::SCC &&ImpDefSCC.isDef())
static bool Enabled
Definition: Statistic.cpp:46
This file defines the 'Statistic' class, which is designed to be an easy way to expose various metric...
static ManagedStatic< SignpostEmitter > Signposts
Allows llvm::Timer to emit signposts when supported.
Definition: Timer.cpp:56
static ManagedStatic< std::string > LibSupportInfoOutputFilename
Definition: Timer.cpp:48
static ManagedStatic< TimerGroup, CreateDefaultTimerGroup > DefaultTimerGroup
Definition: Timer.cpp:125
static size_t getMemUsage()
Definition: Timer.cpp:151
static void printVal(double Val, double Total, raw_ostream &OS)
Definition: Timer.cpp:210
static ManagedStatic< sys::SmartMutex< true > > TimerLock
Definition: Timer.cpp:53
static TimerGroup * TimerGroupList
This is the global list of TimerGroups, maintained by the TimerGroup ctor/dtor and is protected by th...
Definition: Timer.cpp:285
static TimerGroup * getDefaultTimerGroup()
Definition: Timer.cpp:126
static std::string & getLibSupportInfoOutputFilename()
Definition: Timer.cpp:49
static uint64_t getCurInstructionsExecuted()
Definition: Timer.cpp:157
static ManagedStatic< Name2PairMap > NamedGroupedTimers
Definition: Timer.cpp:270
ManagedStatic - This transparently changes the behavior of global statics to be lazily constructed on...
Definition: ManagedStatic.h:83
unsigned size() const
Definition: StringMap.h:95
StringMap - This is an unconventional map that is specialized for handling keys that are "strings",...
Definition: StringMap.h:111
StringRef - Represent a constant reference to a string, i.e.
Definition: StringRef.h:50
iterator begin() const
Definition: StringRef.h:111
iterator end() const
Definition: StringRef.h:113
double getUserTime() const
Definition: Timer.h:43
double getProcessTime() const
Definition: Timer.h:42
static TimeRecord getCurrentTime(bool Start=true)
Get the current time and memory usage.
Definition: Timer.cpp:168
double getWallTime() const
Definition: Timer.h:45
ssize_t getMemUsed() const
Definition: Timer.h:46
double getSystemTime() const
Definition: Timer.h:44
void print(const TimeRecord &Total, raw_ostream &OS) const
Print the current time record to OS, with a breakdown showing contributions to the Total time record.
Definition: Timer.cpp:217
uint64_t getInstructionsExecuted() const
Definition: Timer.h:47
The TimeRegion class is used as a helper class to call the startTimer() and stopTimer() methods of th...
Definition: Timer.h:145
The TimerGroup class is used to group together related timers into a single report that is printed wh...
Definition: Timer.h:175
static void printAll(raw_ostream &OS)
This static method prints all timers.
Definition: Timer.cpp:444
void print(raw_ostream &OS, bool ResetAfterPrint=false)
Print any started timers in this group, optionally resetting timers after printing them.
Definition: Timer.cpp:426
static void clearAll()
Clear out all timers.
Definition: Timer.cpp:451
void clear()
Clear all timers in this group.
Definition: Timer.cpp:438
static std::unique_ptr< TimerGroup > aquireDefaultGroup()
This makes the default group unmanaged, and lets the user manage the group's lifetime.
Definition: Timer.cpp:507
static const char * printAllJSONValues(raw_ostream &OS, const char *delim)
Prints all timers as JSON key/value pairs.
Definition: Timer.cpp:495
const char * printJSONValues(raw_ostream &OS, const char *delim)
Definition: Timer.cpp:468
static void constructForStatistics()
Ensure global objects required for statistics printing are initialized.
Definition: Timer.cpp:502
This class is used to track the amount of time spent between invocations of its startTimer()/stopTime...
Definition: Timer.h:81
void stopTimer()
Stop the timer.
Definition: Timer.cpp:197
void init(StringRef TimerName, StringRef TimerDescription)
Definition: Timer.cpp:132
void clear()
Clear the timer state.
Definition: Timer.cpp:205
const std::string & getName() const
Definition: Timer.h:113
void startTimer()
Start the timer running.
Definition: Timer.cpp:190
LLVM Value Representation.
Definition: Value.h:74
This class implements an extremely fast bulk output stream that can only output to a stream.
Definition: raw_ostream.h:52
raw_ostream & indent(unsigned NumSpaces)
indent - Insert 'NumSpaces' spaces.
static void GetTimeUsage(TimePoint<> &elapsed, std::chrono::nanoseconds &user_time, std::chrono::nanoseconds &sys_time)
This static function will set user_time to the amount of CPU time spent in user (non-kernel) mode and...
static size_t GetMallocUsage()
Return process memory usage.
initializer< Ty > init(const Ty &Val)
Definition: CommandLine.h:445
LocationClass< Ty > location(Ty &L)
Definition: CommandLine.h:465
@ OF_TextWithCRLF
The file should be opened in text mode and use a carriage linefeed '\r '.
Definition: FileSystem.h:770
@ OF_Append
The file should be opened in append mode.
Definition: FileSystem.h:773
std::chrono::time_point< std::chrono::system_clock, D > TimePoint
A time point on the system clock.
Definition: Chrono.h:34
std::lock_guard< SmartMutex< mt_only > > SmartScopedLock
Definition: Mutex.h:69
This is an optimization pass for GlobalISel generic memory operations.
Definition: AddressRanges.h:18
std::unique_ptr< raw_fd_ostream > CreateInfoOutputFile()
Return a file stream to print our output on.
Definition: Timer.cpp:96
auto reverse(ContainerTy &&C)
Definition: STLExtras.h:484
decltype(auto) get(const PointerIntPair< PointerTy, IntBits, IntType, PtrTraits, Info > &Pair)
void sort(IteratorTy Start, IteratorTy End)
Definition: STLExtras.h:1683
format_object< Ts... > format(const char *Fmt, const Ts &... Vals)
These are helper functions used to produce formatted output.
Definition: Format.h:124
void initTimerOptions()
Definition: Timer.cpp:90
raw_fd_ostream & errs()
This returns a reference to a raw_ostream for standard error.
NamedRegionTimer(StringRef Name, StringRef Description, StringRef GroupName, StringRef GroupDescription, bool Enabled=true)
Definition: Timer.cpp:272