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/Timer.h"
15 #include "llvm/Support/CommandLine.h"
16 #include "llvm/Support/Debug.h"
17 #include "llvm/Support/ManagedStatic.h"
18 #include "llvm/Support/raw_ostream.h"
19 #include "llvm/Support/Format.h"
20 #include "llvm/System/Mutex.h"
21 #include "llvm/System/Process.h"
25 // GetLibSupportInfoOutputFile - Return a file stream to print our output on.
26 namespace llvm { extern raw_ostream *GetLibSupportInfoOutputFile(); }
28 // getLibSupportInfoOutputFilename - This ugly hack is brought to you courtesy
29 // of constructor/destructor ordering being unspecified by C++. Basically the
30 // problem is that a Statistic object gets destroyed, which ends up calling
31 // 'GetLibSupportInfoOutputFile()' (below), which calls this function.
32 // LibSupportInfoOutputFilename used to be a global variable, but sometimes it
33 // would get destroyed before the Statistic, causing havoc to ensue. We "fix"
34 // this by creating the string the first time it is needed and never destroying
36 static ManagedStatic<std::string> LibSupportInfoOutputFilename;
37 static std::string &getLibSupportInfoOutputFilename() {
38 return *LibSupportInfoOutputFilename;
41 static ManagedStatic<sys::SmartMutex<true> > TimerLock;
45 TrackSpace("track-memory", cl::desc("Enable -time-passes memory "
46 "tracking (this may be slow)"),
49 static cl::opt<std::string, true>
50 InfoOutputFilename("info-output-file", cl::value_desc("filename"),
51 cl::desc("File to append -stats and -timer output to"),
52 cl::Hidden, cl::location(getLibSupportInfoOutputFilename()));
55 // GetLibSupportInfoOutputFile - Return a file stream to print our output on.
56 raw_ostream *llvm::GetLibSupportInfoOutputFile() {
57 std::string &LibSupportInfoOutputFilename = getLibSupportInfoOutputFilename();
58 if (LibSupportInfoOutputFilename.empty())
60 if (LibSupportInfoOutputFilename == "-")
64 raw_ostream *Result = new raw_fd_ostream(LibSupportInfoOutputFilename.c_str(),
65 Error, raw_fd_ostream::F_Append);
69 errs() << "Error opening info-output-file '"
70 << LibSupportInfoOutputFilename << " for appending!\n";
76 static TimerGroup *DefaultTimerGroup = 0;
77 static TimerGroup *getDefaultTimerGroup() {
78 TimerGroup *tmp = DefaultTimerGroup;
82 llvm_acquire_global_lock();
83 tmp = DefaultTimerGroup;
85 tmp = new TimerGroup("Miscellaneous Ungrouped Timers");
87 DefaultTimerGroup = tmp;
89 llvm_release_global_lock();
94 //===----------------------------------------------------------------------===//
95 // Timer Implementation
96 //===----------------------------------------------------------------------===//
98 Timer::Timer(const std::string &N)
99 : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), Name(N),
100 Started(false), TG(getDefaultTimerGroup()) {
104 Timer::Timer(const std::string &N, TimerGroup &tg)
105 : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), Name(N),
106 Started(false), TG(&tg) {
110 Timer::Timer(const Timer &T) {
112 if (TG) TG->addTimer();
116 // Copy ctor, initialize with no TG member.
117 Timer::Timer(bool, const Timer &T) {
118 TG = T.TG; // Avoid assertion in operator=
119 operator=(T); // Copy contents
128 TG->addTimerToPrint(*this);
133 static inline size_t getMemUsage() {
135 return sys::Process::GetMallocUsage();
140 double Elapsed, UserTime, SystemTime;
144 static TimeRecord getTimeRecord(bool Start) {
147 sys::TimeValue now(0,0);
148 sys::TimeValue user(0,0);
149 sys::TimeValue sys(0,0);
153 MemUsed = getMemUsage();
154 sys::Process::GetTimeUsage(now, user, sys);
156 sys::Process::GetTimeUsage(now, user, sys);
157 MemUsed = getMemUsage();
160 Result.Elapsed = now.seconds() + now.microseconds() / 1000000.0;
161 Result.UserTime = user.seconds() + user.microseconds() / 1000000.0;
162 Result.SystemTime = sys.seconds() + sys.microseconds() / 1000000.0;
163 Result.MemUsed = MemUsed;
167 static ManagedStatic<std::vector<Timer*> > ActiveTimers;
169 void Timer::startTimer() {
171 ActiveTimers->push_back(this);
172 TimeRecord TR = getTimeRecord(true);
173 Elapsed -= TR.Elapsed;
174 UserTime -= TR.UserTime;
175 SystemTime -= TR.SystemTime;
176 MemUsed -= TR.MemUsed;
179 void Timer::stopTimer() {
180 TimeRecord TR = getTimeRecord(false);
181 Elapsed += TR.Elapsed;
182 UserTime += TR.UserTime;
183 SystemTime += TR.SystemTime;
184 MemUsed += TR.MemUsed;
186 if (ActiveTimers->back() == this) {
187 ActiveTimers->pop_back();
189 std::vector<Timer*>::iterator I =
190 std::find(ActiveTimers->begin(), ActiveTimers->end(), this);
191 assert(I != ActiveTimers->end() && "stop but no startTimer?");
192 ActiveTimers->erase(I);
196 void Timer::sum(const Timer &T) {
197 Elapsed += T.Elapsed;
198 UserTime += T.UserTime;
199 SystemTime += T.SystemTime;
200 MemUsed += T.MemUsed;
203 const Timer &Timer::operator=(const Timer &T) {
205 UserTime = T.UserTime;
206 SystemTime = T.SystemTime;
210 assert(TG == T.TG && "Can only assign timers in the same TimerGroup!");
215 static void printVal(double Val, double Total, raw_ostream &OS) {
216 if (Total < 1e-7) // Avoid dividing by zero.
219 OS << " " << format("%7.4f", Val) << " (";
220 OS << format("%5.1f", Val*100/Total) << "%)";
224 void Timer::print(const Timer &Total, raw_ostream &OS) {
226 printVal(UserTime, Total.UserTime, OS);
227 if (Total.SystemTime)
228 printVal(SystemTime, Total.SystemTime, OS);
229 if (Total.getProcessTime())
230 printVal(getProcessTime(), Total.getProcessTime(), OS);
231 printVal(Elapsed, Total.Elapsed, OS);
236 OS << format("%9lld", (long long)MemUsed) << " ";
240 Started = false; // Once printed, don't print again
244 //===----------------------------------------------------------------------===//
245 // NamedRegionTimer Implementation
246 //===----------------------------------------------------------------------===//
248 typedef std::map<std::string, Timer> Name2Timer;
249 typedef std::map<std::string, std::pair<TimerGroup, Name2Timer> > Name2Pair;
251 static ManagedStatic<Name2Timer> NamedTimers;
252 static ManagedStatic<Name2Pair> NamedGroupedTimers;
254 static Timer &getNamedRegionTimer(const std::string &Name) {
255 sys::SmartScopedLock<true> L(*TimerLock);
256 Name2Timer::iterator I = NamedTimers->find(Name);
257 if (I != NamedTimers->end())
260 return NamedTimers->insert(I, std::make_pair(Name, Timer(Name)))->second;
263 static Timer &getNamedRegionTimer(const std::string &Name,
264 const std::string &GroupName) {
265 sys::SmartScopedLock<true> L(*TimerLock);
267 Name2Pair::iterator I = NamedGroupedTimers->find(GroupName);
268 if (I == NamedGroupedTimers->end()) {
269 TimerGroup TG(GroupName);
270 std::pair<TimerGroup, Name2Timer> Pair(TG, Name2Timer());
271 I = NamedGroupedTimers->insert(I, std::make_pair(GroupName, Pair));
274 Name2Timer::iterator J = I->second.second.find(Name);
275 if (J == I->second.second.end())
276 J = I->second.second.insert(J,
284 NamedRegionTimer::NamedRegionTimer(const std::string &Name)
285 : TimeRegion(getNamedRegionTimer(Name)) {}
287 NamedRegionTimer::NamedRegionTimer(const std::string &Name,
288 const std::string &GroupName)
289 : TimeRegion(getNamedRegionTimer(Name, GroupName)) {}
291 //===----------------------------------------------------------------------===//
292 // TimerGroup Implementation
293 //===----------------------------------------------------------------------===//
295 void TimerGroup::removeTimer() {
296 sys::SmartScopedLock<true> L(*TimerLock);
297 if (--NumTimers != 0 || TimersToPrint.empty())
298 return; // Don't print timing report.
300 // Sort the timers in descending order by amount of time taken.
301 std::sort(TimersToPrint.begin(), TimersToPrint.end(),
302 std::greater<Timer>());
304 // Figure out how many spaces to indent TimerGroup name.
305 unsigned Padding = (80-Name.length())/2;
306 if (Padding > 80) Padding = 0; // Don't allow "negative" numbers
308 raw_ostream *OutStream = GetLibSupportInfoOutputFile();
311 { // Scope to contain Total timer: don't allow total timer to drop us to
313 Timer Total("TOTAL");
315 for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
316 Total.sum(TimersToPrint[i]);
318 // Print out timing header.
319 *OutStream << "===" << std::string(73, '-') << "===\n"
320 << std::string(Padding, ' ') << Name << "\n"
321 << "===" << std::string(73, '-')
324 // If this is not an collection of ungrouped times, print the total time.
325 // Ungrouped timers don't really make sense to add up. We still print the
326 // TOTAL line to make the percentages make sense.
327 if (this != DefaultTimerGroup) {
328 *OutStream << " Total Execution Time: ";
329 *OutStream << format("%5.4f", Total.getProcessTime()) << " seconds (";
330 *OutStream << format("%5.4f", Total.getWallTime()) << " wall clock)\n";
335 *OutStream << " ---User Time---";
336 if (Total.SystemTime)
337 *OutStream << " --System Time--";
338 if (Total.getProcessTime())
339 *OutStream << " --User+System--";
340 *OutStream << " ---Wall Time---";
341 if (Total.getMemUsed())
342 *OutStream << " ---Mem---";
343 *OutStream << " --- Name ---\n";
345 // Loop through all of the timing data, printing it out.
346 for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
347 TimersToPrint[i].print(Total, *OutStream);
349 Total.print(Total, *OutStream);
355 TimersToPrint.clear();
357 if (OutStream != &errs() && OutStream != &outs())
358 delete OutStream; // Close the file.
361 void TimerGroup::addTimer() {
362 sys::SmartScopedLock<true> L(*TimerLock);
366 void TimerGroup::addTimerToPrint(const Timer &T) {
367 sys::SmartScopedLock<true> L(*TimerLock);
368 TimersToPrint.push_back(Timer(true, T));