1
//===-- Timer.cpp - Interval Timing Support -------------------------------===//
3
// The LLVM Compiler Infrastructure
5
// This file is distributed under the University of Illinois Open Source
6
// License. See LICENSE.TXT for details.
8
//===----------------------------------------------------------------------===//
10
// Interval Timing implementation.
12
//===----------------------------------------------------------------------===//
14
#include "llvm/Support/Debug.h"
15
#include "llvm/Support/Timer.h"
16
#include "llvm/Support/CommandLine.h"
17
#include "llvm/Support/ManagedStatic.h"
18
#include "llvm/Support/raw_ostream.h"
19
#include "llvm/Support/Format.h"
20
#include "llvm/System/Process.h"
26
// GetLibSupportInfoOutputFile - Return a file stream to print our output on.
27
namespace llvm { extern raw_ostream *GetLibSupportInfoOutputFile(); }
29
// getLibSupportInfoOutputFilename - This ugly hack is brought to you courtesy
30
// of constructor/destructor ordering being unspecified by C++. Basically the
31
// problem is that a Statistic object gets destroyed, which ends up calling
32
// 'GetLibSupportInfoOutputFile()' (below), which calls this function.
33
// LibSupportInfoOutputFilename used to be a global variable, but sometimes it
34
// would get destroyed before the Statistic, causing havoc to ensue. We "fix"
35
// this by creating the string the first time it is needed and never destroying
37
static ManagedStatic<std::string> LibSupportInfoOutputFilename;
38
static std::string &getLibSupportInfoOutputFilename() {
39
return *LibSupportInfoOutputFilename;
42
static ManagedStatic<sys::SmartMutex<true> > TimerLock;
46
TrackSpace("track-memory", cl::desc("Enable -time-passes memory "
47
"tracking (this may be slow)"),
50
static cl::opt<std::string, true>
51
InfoOutputFilename("info-output-file", cl::value_desc("filename"),
52
cl::desc("File to append -stats and -timer output to"),
53
cl::Hidden, cl::location(getLibSupportInfoOutputFilename()));
56
static TimerGroup *DefaultTimerGroup = 0;
57
static TimerGroup *getDefaultTimerGroup() {
58
TimerGroup* tmp = DefaultTimerGroup;
61
llvm_acquire_global_lock();
62
tmp = DefaultTimerGroup;
64
tmp = new TimerGroup("Miscellaneous Ungrouped Timers");
66
DefaultTimerGroup = tmp;
68
llvm_release_global_lock();
74
Timer::Timer(const std::string &N)
75
: Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
76
Started(false), TG(getDefaultTimerGroup()) {
80
Timer::Timer(const std::string &N, TimerGroup &tg)
81
: Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
82
Started(false), TG(&tg) {
86
Timer::Timer(const Timer &T) {
88
if (TG) TG->addTimer();
93
// Copy ctor, initialize with no TG member.
94
Timer::Timer(bool, const Timer &T) {
95
TG = T.TG; // Avoid assertion in operator=
96
operator=(T); // Copy contents
105
TG->addTimerToPrint(*this);
111
static inline size_t getMemUsage() {
113
return sys::Process::GetMallocUsage();
118
double Elapsed, UserTime, SystemTime;
122
static TimeRecord getTimeRecord(bool Start) {
125
sys::TimeValue now(0,0);
126
sys::TimeValue user(0,0);
127
sys::TimeValue sys(0,0);
131
MemUsed = getMemUsage();
132
sys::Process::GetTimeUsage(now,user,sys);
134
sys::Process::GetTimeUsage(now,user,sys);
135
MemUsed = getMemUsage();
138
Result.Elapsed = now.seconds() + now.microseconds() / 1000000.0;
139
Result.UserTime = user.seconds() + user.microseconds() / 1000000.0;
140
Result.SystemTime = sys.seconds() + sys.microseconds() / 1000000.0;
141
Result.MemUsed = MemUsed;
146
static ManagedStatic<std::vector<Timer*> > ActiveTimers;
148
void Timer::startTimer() {
149
sys::SmartScopedLock<true> L(*TimerLock);
151
ActiveTimers->push_back(this);
152
TimeRecord TR = getTimeRecord(true);
153
Elapsed -= TR.Elapsed;
154
UserTime -= TR.UserTime;
155
SystemTime -= TR.SystemTime;
156
MemUsed -= TR.MemUsed;
157
PeakMemBase = TR.MemUsed;
160
void Timer::stopTimer() {
161
sys::SmartScopedLock<true> L(*TimerLock);
162
TimeRecord TR = getTimeRecord(false);
163
Elapsed += TR.Elapsed;
164
UserTime += TR.UserTime;
165
SystemTime += TR.SystemTime;
166
MemUsed += TR.MemUsed;
168
if (ActiveTimers->back() == this) {
169
ActiveTimers->pop_back();
171
std::vector<Timer*>::iterator I =
172
std::find(ActiveTimers->begin(), ActiveTimers->end(), this);
173
assert(I != ActiveTimers->end() && "stop but no startTimer?");
174
ActiveTimers->erase(I);
178
void Timer::sum(const Timer &T) {
179
Elapsed += T.Elapsed;
180
UserTime += T.UserTime;
181
SystemTime += T.SystemTime;
182
MemUsed += T.MemUsed;
183
PeakMem += T.PeakMem;
186
/// addPeakMemoryMeasurement - This method should be called whenever memory
187
/// usage needs to be checked. It adds a peak memory measurement to the
188
/// currently active timers, which will be printed when the timer group prints
190
void Timer::addPeakMemoryMeasurement() {
191
sys::SmartScopedLock<true> L(*TimerLock);
192
size_t MemUsed = getMemUsage();
194
for (std::vector<Timer*>::iterator I = ActiveTimers->begin(),
195
E = ActiveTimers->end(); I != E; ++I)
196
(*I)->PeakMem = std::max((*I)->PeakMem, MemUsed-(*I)->PeakMemBase);
199
//===----------------------------------------------------------------------===//
200
// NamedRegionTimer Implementation
201
//===----------------------------------------------------------------------===//
205
typedef std::map<std::string, Timer> Name2Timer;
206
typedef std::map<std::string, std::pair<TimerGroup, Name2Timer> > Name2Pair;
210
static ManagedStatic<Name2Timer> NamedTimers;
212
static ManagedStatic<Name2Pair> NamedGroupedTimers;
214
static Timer &getNamedRegionTimer(const std::string &Name) {
215
sys::SmartScopedLock<true> L(*TimerLock);
216
Name2Timer::iterator I = NamedTimers->find(Name);
217
if (I != NamedTimers->end())
220
return NamedTimers->insert(I, std::make_pair(Name, Timer(Name)))->second;
223
static Timer &getNamedRegionTimer(const std::string &Name,
224
const std::string &GroupName) {
225
sys::SmartScopedLock<true> L(*TimerLock);
227
Name2Pair::iterator I = NamedGroupedTimers->find(GroupName);
228
if (I == NamedGroupedTimers->end()) {
229
TimerGroup TG(GroupName);
230
std::pair<TimerGroup, Name2Timer> Pair(TG, Name2Timer());
231
I = NamedGroupedTimers->insert(I, std::make_pair(GroupName, Pair));
234
Name2Timer::iterator J = I->second.second.find(Name);
235
if (J == I->second.second.end())
236
J = I->second.second.insert(J,
244
NamedRegionTimer::NamedRegionTimer(const std::string &Name)
245
: TimeRegion(getNamedRegionTimer(Name)) {}
247
NamedRegionTimer::NamedRegionTimer(const std::string &Name,
248
const std::string &GroupName)
249
: TimeRegion(getNamedRegionTimer(Name, GroupName)) {}
251
//===----------------------------------------------------------------------===//
252
// TimerGroup Implementation
253
//===----------------------------------------------------------------------===//
256
static void printVal(double Val, double Total, raw_ostream &OS) {
257
if (Total < 1e-7) // Avoid dividing by zero...
260
OS << " " << format("%7.4f", Val) << " (";
261
OS << format("%5.1f", Val*100/Total) << "%)";
265
void Timer::print(const Timer &Total, raw_ostream &OS) {
266
sys::SmartScopedLock<true> L(*TimerLock);
268
printVal(UserTime, Total.UserTime, OS);
269
if (Total.SystemTime)
270
printVal(SystemTime, Total.SystemTime, OS);
271
if (Total.getProcessTime())
272
printVal(getProcessTime(), Total.getProcessTime(), OS);
273
printVal(Elapsed, Total.Elapsed, OS);
278
OS << format("%9lld", (long long)MemUsed) << " ";
282
OS << format("%9lld", (long long)PeakMem) << " ";
288
Started = false; // Once printed, don't print again
291
// GetLibSupportInfoOutputFile - Return a file stream to print our output on...
293
llvm::GetLibSupportInfoOutputFile() {
294
std::string &LibSupportInfoOutputFilename = getLibSupportInfoOutputFilename();
295
if (LibSupportInfoOutputFilename.empty())
297
if (LibSupportInfoOutputFilename == "-")
302
raw_ostream *Result = new raw_fd_ostream(LibSupportInfoOutputFilename.c_str(),
303
Error, raw_fd_ostream::F_Append);
307
errs() << "Error opening info-output-file '"
308
<< LibSupportInfoOutputFilename << " for appending!\n";
314
void TimerGroup::removeTimer() {
315
sys::SmartScopedLock<true> L(*TimerLock);
316
if (--NumTimers == 0 && !TimersToPrint.empty()) { // Print timing report...
317
// Sort the timers in descending order by amount of time taken...
318
std::sort(TimersToPrint.begin(), TimersToPrint.end(),
319
std::greater<Timer>());
321
// Figure out how many spaces to indent TimerGroup name...
322
unsigned Padding = (80-Name.length())/2;
323
if (Padding > 80) Padding = 0; // Don't allow "negative" numbers
325
raw_ostream *OutStream = GetLibSupportInfoOutputFile();
328
{ // Scope to contain Total timer... don't allow total timer to drop us to
330
Timer Total("TOTAL");
332
for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
333
Total.sum(TimersToPrint[i]);
335
// Print out timing header...
336
*OutStream << "===" << std::string(73, '-') << "===\n"
337
<< std::string(Padding, ' ') << Name << "\n"
338
<< "===" << std::string(73, '-')
341
// If this is not an collection of ungrouped times, print the total time.
342
// Ungrouped timers don't really make sense to add up. We still print the
343
// TOTAL line to make the percentages make sense.
344
if (this != DefaultTimerGroup) {
345
*OutStream << " Total Execution Time: ";
347
*OutStream << format("%5.4f", Total.getProcessTime()) << " seconds (";
348
*OutStream << format("%5.4f", Total.getWallTime()) << " wall clock)\n";
353
*OutStream << " ---User Time---";
354
if (Total.SystemTime)
355
*OutStream << " --System Time--";
356
if (Total.getProcessTime())
357
*OutStream << " --User+System--";
358
*OutStream << " ---Wall Time---";
359
if (Total.getMemUsed())
360
*OutStream << " ---Mem---";
361
if (Total.getPeakMem())
362
*OutStream << " -PeakMem-";
363
*OutStream << " --- Name ---\n";
365
// Loop through all of the timing data, printing it out...
366
for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
367
TimersToPrint[i].print(Total, *OutStream);
369
Total.print(Total, *OutStream);
375
TimersToPrint.clear();
377
if (OutStream != &errs() && OutStream != &outs() && OutStream != &dbgs())
378
delete OutStream; // Close the file...
382
void TimerGroup::addTimer() {
383
sys::SmartScopedLock<true> L(*TimerLock);
387
void TimerGroup::addTimerToPrint(const Timer &T) {
388
sys::SmartScopedLock<true> L(*TimerLock);
389
TimersToPrint.push_back(Timer(true, T));