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;
62 llvm_acquire_global_lock();
63 tmp = DefaultTimerGroup;
65 tmp = new TimerGroup("Miscellaneous Ungrouped Timers");
67 DefaultTimerGroup = tmp;
69 llvm_release_global_lock();
74 //===----------------------------------------------------------------------===//
75 // Timer Implementation
76 //===----------------------------------------------------------------------===//
78 Timer::Timer(const std::string &N)
79 : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
80 Started(false), TG(getDefaultTimerGroup()) {
84 Timer::Timer(const std::string &N, TimerGroup &tg)
85 : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
86 Started(false), TG(&tg) {
90 Timer::Timer(const Timer &T) {
92 if (TG) TG->addTimer();
96 // Copy ctor, initialize with no TG member.
97 Timer::Timer(bool, const Timer &T) {
98 TG = T.TG; // Avoid assertion in operator=
99 operator=(T); // Copy contents
108 TG->addTimerToPrint(*this);
113 static inline size_t getMemUsage() {
115 return sys::Process::GetMallocUsage();
120 double Elapsed, UserTime, SystemTime;
124 static TimeRecord getTimeRecord(bool Start) {
127 sys::TimeValue now(0,0);
128 sys::TimeValue user(0,0);
129 sys::TimeValue sys(0,0);
133 MemUsed = getMemUsage();
134 sys::Process::GetTimeUsage(now, user, sys);
136 sys::Process::GetTimeUsage(now, user, sys);
137 MemUsed = getMemUsage();
140 Result.Elapsed = now.seconds() + now.microseconds() / 1000000.0;
141 Result.UserTime = user.seconds() + user.microseconds() / 1000000.0;
142 Result.SystemTime = sys.seconds() + sys.microseconds() / 1000000.0;
143 Result.MemUsed = MemUsed;
147 static ManagedStatic<std::vector<Timer*> > ActiveTimers;
149 void Timer::startTimer() {
150 sys::SmartScopedLock<true> L(*TimerLock);
152 ActiveTimers->push_back(this);
153 TimeRecord TR = getTimeRecord(true);
154 Elapsed -= TR.Elapsed;
155 UserTime -= TR.UserTime;
156 SystemTime -= TR.SystemTime;
157 MemUsed -= TR.MemUsed;
158 PeakMemBase = TR.MemUsed;
161 void Timer::stopTimer() {
162 sys::SmartScopedLock<true> L(*TimerLock);
163 TimeRecord TR = getTimeRecord(false);
164 Elapsed += TR.Elapsed;
165 UserTime += TR.UserTime;
166 SystemTime += TR.SystemTime;
167 MemUsed += TR.MemUsed;
169 if (ActiveTimers->back() == this) {
170 ActiveTimers->pop_back();
172 std::vector<Timer*>::iterator I =
173 std::find(ActiveTimers->begin(), ActiveTimers->end(), this);
174 assert(I != ActiveTimers->end() && "stop but no startTimer?");
175 ActiveTimers->erase(I);
179 void Timer::sum(const Timer &T) {
180 Elapsed += T.Elapsed;
181 UserTime += T.UserTime;
182 SystemTime += T.SystemTime;
183 MemUsed += T.MemUsed;
184 PeakMem += T.PeakMem;
187 /// addPeakMemoryMeasurement - This method should be called whenever memory
188 /// usage needs to be checked. It adds a peak memory measurement to the
189 /// currently active timers, which will be printed when the timer group prints
191 void Timer::addPeakMemoryMeasurement() {
192 sys::SmartScopedLock<true> L(*TimerLock);
193 size_t MemUsed = getMemUsage();
195 for (std::vector<Timer*>::iterator I = ActiveTimers->begin(),
196 E = ActiveTimers->end(); I != E; ++I)
197 (*I)->PeakMem = std::max((*I)->PeakMem, MemUsed-(*I)->PeakMemBase);
201 static void printVal(double Val, double Total, raw_ostream &OS) {
202 if (Total < 1e-7) // Avoid dividing by zero.
205 OS << " " << format("%7.4f", Val) << " (";
206 OS << format("%5.1f", Val*100/Total) << "%)";
210 void Timer::print(const Timer &Total, raw_ostream &OS) {
211 sys::SmartScopedLock<true> L(*TimerLock);
213 printVal(UserTime, Total.UserTime, OS);
214 if (Total.SystemTime)
215 printVal(SystemTime, Total.SystemTime, OS);
216 if (Total.getProcessTime())
217 printVal(getProcessTime(), Total.getProcessTime(), OS);
218 printVal(Elapsed, Total.Elapsed, OS);
223 OS << format("%9lld", (long long)MemUsed) << " ";
227 OS << format("%9lld", (long long)PeakMem) << " ";
233 Started = false; // Once printed, don't print again
237 //===----------------------------------------------------------------------===//
238 // NamedRegionTimer Implementation
239 //===----------------------------------------------------------------------===//
241 typedef std::map<std::string, Timer> Name2Timer;
242 typedef std::map<std::string, std::pair<TimerGroup, Name2Timer> > Name2Pair;
244 static ManagedStatic<Name2Timer> NamedTimers;
245 static ManagedStatic<Name2Pair> NamedGroupedTimers;
247 static Timer &getNamedRegionTimer(const std::string &Name) {
248 sys::SmartScopedLock<true> L(*TimerLock);
249 Name2Timer::iterator I = NamedTimers->find(Name);
250 if (I != NamedTimers->end())
253 return NamedTimers->insert(I, std::make_pair(Name, Timer(Name)))->second;
256 static Timer &getNamedRegionTimer(const std::string &Name,
257 const std::string &GroupName) {
258 sys::SmartScopedLock<true> L(*TimerLock);
260 Name2Pair::iterator I = NamedGroupedTimers->find(GroupName);
261 if (I == NamedGroupedTimers->end()) {
262 TimerGroup TG(GroupName);
263 std::pair<TimerGroup, Name2Timer> Pair(TG, Name2Timer());
264 I = NamedGroupedTimers->insert(I, std::make_pair(GroupName, Pair));
267 Name2Timer::iterator J = I->second.second.find(Name);
268 if (J == I->second.second.end())
269 J = I->second.second.insert(J,
277 NamedRegionTimer::NamedRegionTimer(const std::string &Name)
278 : TimeRegion(getNamedRegionTimer(Name)) {}
280 NamedRegionTimer::NamedRegionTimer(const std::string &Name,
281 const std::string &GroupName)
282 : TimeRegion(getNamedRegionTimer(Name, GroupName)) {}
284 //===----------------------------------------------------------------------===//
285 // TimerGroup Implementation
286 //===----------------------------------------------------------------------===//
288 // GetLibSupportInfoOutputFile - Return a file stream to print our output on.
290 llvm::GetLibSupportInfoOutputFile() {
291 std::string &LibSupportInfoOutputFilename = getLibSupportInfoOutputFilename();
292 if (LibSupportInfoOutputFilename.empty())
294 if (LibSupportInfoOutputFilename == "-")
299 raw_ostream *Result = new raw_fd_ostream(LibSupportInfoOutputFilename.c_str(),
300 Error, raw_fd_ostream::F_Append);
304 errs() << "Error opening info-output-file '"
305 << LibSupportInfoOutputFilename << " for appending!\n";
311 void TimerGroup::removeTimer() {
312 sys::SmartScopedLock<true> L(*TimerLock);
313 if (--NumTimers != 0 || TimersToPrint.empty())
314 return; // Don't print timing report.
316 // Sort the timers in descending order by amount of time taken.
317 std::sort(TimersToPrint.begin(), TimersToPrint.end(),
318 std::greater<Timer>());
320 // Figure out how many spaces to indent TimerGroup name.
321 unsigned Padding = (80-Name.length())/2;
322 if (Padding > 80) Padding = 0; // Don't allow "negative" numbers
324 raw_ostream *OutStream = GetLibSupportInfoOutputFile();
327 { // Scope to contain Total timer: don't allow total timer to drop us to
329 Timer Total("TOTAL");
331 for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
332 Total.sum(TimersToPrint[i]);
334 // Print out timing header.
335 *OutStream << "===" << std::string(73, '-') << "===\n"
336 << std::string(Padding, ' ') << Name << "\n"
337 << "===" << std::string(73, '-')
340 // If this is not an collection of ungrouped times, print the total time.
341 // Ungrouped timers don't really make sense to add up. We still print the
342 // TOTAL line to make the percentages make sense.
343 if (this != DefaultTimerGroup) {
344 *OutStream << " Total Execution Time: ";
346 *OutStream << format("%5.4f", Total.getProcessTime()) << " seconds (";
347 *OutStream << format("%5.4f", Total.getWallTime()) << " wall clock)\n";
352 *OutStream << " ---User Time---";
353 if (Total.SystemTime)
354 *OutStream << " --System Time--";
355 if (Total.getProcessTime())
356 *OutStream << " --User+System--";
357 *OutStream << " ---Wall Time---";
358 if (Total.getMemUsed())
359 *OutStream << " ---Mem---";
360 if (Total.getPeakMem())
361 *OutStream << " -PeakMem-";
362 *OutStream << " --- Name ---\n";
364 // Loop through all of the timing data, printing it out.
365 for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
366 TimersToPrint[i].print(Total, *OutStream);
368 Total.print(Total, *OutStream);
374 TimersToPrint.clear();
376 if (OutStream != &errs() && OutStream != &outs() && OutStream != &dbgs())
377 delete OutStream; // Close the file.
380 void TimerGroup::addTimer() {
381 sys::SmartScopedLock<true> L(*TimerLock);
385 void TimerGroup::addTimerToPrint(const Timer &T) {
386 sys::SmartScopedLock<true> L(*TimerLock);
387 TimersToPrint.push_back(Timer(true, T));