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/ADT/StringMap.h"
16 #include "llvm/Support/CommandLine.h"
17 #include "llvm/Support/Debug.h"
18 #include "llvm/Support/FileSystem.h"
19 #include "llvm/Support/Format.h"
20 #include "llvm/Support/ManagedStatic.h"
21 #include "llvm/Support/Mutex.h"
22 #include "llvm/Support/MutexGuard.h"
23 #include "llvm/Support/Process.h"
24 #include "llvm/Support/raw_ostream.h"
27 // CreateInfoOutputFile - Return a file stream to print our output on.
28 namespace llvm
{ extern raw_ostream
*CreateInfoOutputFile(); }
30 // getLibSupportInfoOutputFilename - This ugly hack is brought to you courtesy
31 // of constructor/destructor ordering being unspecified by C++. Basically the
32 // problem is that a Statistic object gets destroyed, which ends up calling
33 // 'GetLibSupportInfoOutputFile()' (below), which calls this function.
34 // LibSupportInfoOutputFilename used to be a global variable, but sometimes it
35 // would get destroyed before the Statistic, causing havoc to ensue. We "fix"
36 // this by creating the string the first time it is needed and never destroying
38 static ManagedStatic
<std::string
> LibSupportInfoOutputFilename
;
39 static std::string
&getLibSupportInfoOutputFilename() {
40 return *LibSupportInfoOutputFilename
;
43 static ManagedStatic
<sys::SmartMutex
<true> > TimerLock
;
47 TrackSpace("track-memory", cl::desc("Enable -time-passes memory "
48 "tracking (this may be slow)"),
51 static cl::opt
<std::string
, true>
52 InfoOutputFilename("info-output-file", cl::value_desc("filename"),
53 cl::desc("File to append -stats and -timer output to"),
54 cl::Hidden
, cl::location(getLibSupportInfoOutputFilename()));
57 // CreateInfoOutputFile - Return a file stream to print our output on.
58 raw_ostream
*llvm::CreateInfoOutputFile() {
59 const std::string
&OutputFilename
= getLibSupportInfoOutputFilename();
60 if (OutputFilename
.empty())
61 return new raw_fd_ostream(2, false); // stderr.
62 if (OutputFilename
== "-")
63 return new raw_fd_ostream(1, false); // stdout.
65 // Append mode is used because the info output file is opened and closed
66 // each time -stats or -time-passes wants to print output to it. To
67 // compensate for this, the test-suite Makefiles have code to delete the
68 // info output file before running commands which write to it.
70 raw_ostream
*Result
= new raw_fd_ostream(OutputFilename
, EC
,
71 sys::fs::F_Append
| sys::fs::F_Text
);
75 errs() << "Error opening info-output-file '"
76 << OutputFilename
<< " for appending!\n";
78 return new raw_fd_ostream(2, false); // stderr.
82 static TimerGroup
*DefaultTimerGroup
= nullptr;
83 static TimerGroup
*getDefaultTimerGroup() {
84 TimerGroup
*tmp
= DefaultTimerGroup
;
88 sys::SmartScopedLock
<true> Lock(*TimerLock
);
89 tmp
= DefaultTimerGroup
;
91 tmp
= new TimerGroup("Miscellaneous Ungrouped Timers");
93 DefaultTimerGroup
= tmp
;
99 //===----------------------------------------------------------------------===//
100 // Timer Implementation
101 //===----------------------------------------------------------------------===//
103 void Timer::init(StringRef N
) {
104 assert(!TG
&& "Timer already initialized");
105 Name
.assign(N
.begin(), N
.end());
107 TG
= getDefaultTimerGroup();
111 void Timer::init(StringRef N
, TimerGroup
&tg
) {
112 assert(!TG
&& "Timer already initialized");
113 Name
.assign(N
.begin(), N
.end());
120 if (!TG
) return; // Never initialized, or already cleared.
121 TG
->removeTimer(*this);
124 static inline size_t getMemUsage() {
125 if (!TrackSpace
) return 0;
126 return sys::Process::GetMallocUsage();
129 TimeRecord
TimeRecord::getCurrentTime(bool Start
) {
131 sys::TimeValue
now(0,0), user(0,0), sys(0,0);
134 Result
.MemUsed
= getMemUsage();
135 sys::Process::GetTimeUsage(now
, user
, sys
);
137 sys::Process::GetTimeUsage(now
, user
, sys
);
138 Result
.MemUsed
= getMemUsage();
141 Result
.WallTime
= now
.seconds() + now
.microseconds() / 1000000.0;
142 Result
.UserTime
= user
.seconds() + user
.microseconds() / 1000000.0;
143 Result
.SystemTime
= sys
.seconds() + sys
.microseconds() / 1000000.0;
147 static ManagedStatic
<std::vector
<Timer
*> > ActiveTimers
;
149 void Timer::startTimer() {
151 ActiveTimers
->push_back(this);
152 Time
-= TimeRecord::getCurrentTime(true);
155 void Timer::stopTimer() {
156 Time
+= TimeRecord::getCurrentTime(false);
158 if (ActiveTimers
->back() == this) {
159 ActiveTimers
->pop_back();
161 std::vector
<Timer
*>::iterator I
=
162 std::find(ActiveTimers
->begin(), ActiveTimers
->end(), this);
163 assert(I
!= ActiveTimers
->end() && "stop but no startTimer?");
164 ActiveTimers
->erase(I
);
168 static void printVal(double Val
, double Total
, raw_ostream
&OS
) {
169 if (Total
< 1e-7) // Avoid dividing by zero.
172 OS
<< format(" %7.4f (%5.1f%%)", Val
, Val
*100/Total
);
175 void TimeRecord::print(const TimeRecord
&Total
, raw_ostream
&OS
) const {
176 if (Total
.getUserTime())
177 printVal(getUserTime(), Total
.getUserTime(), OS
);
178 if (Total
.getSystemTime())
179 printVal(getSystemTime(), Total
.getSystemTime(), OS
);
180 if (Total
.getProcessTime())
181 printVal(getProcessTime(), Total
.getProcessTime(), OS
);
182 printVal(getWallTime(), Total
.getWallTime(), OS
);
186 if (Total
.getMemUsed())
187 OS
<< format("%9" PRId64
" ", (int64_t)getMemUsed());
191 //===----------------------------------------------------------------------===//
192 // NamedRegionTimer Implementation
193 //===----------------------------------------------------------------------===//
197 typedef StringMap
<Timer
> Name2TimerMap
;
200 StringMap
<std::pair
<TimerGroup
*, Name2TimerMap
> > Map
;
203 for (StringMap
<std::pair
<TimerGroup
*, Name2TimerMap
> >::iterator
204 I
= Map
.begin(), E
= Map
.end(); I
!= E
; ++I
)
205 delete I
->second
.first
;
208 Timer
&get(StringRef Name
, StringRef GroupName
) {
209 sys::SmartScopedLock
<true> L(*TimerLock
);
211 std::pair
<TimerGroup
*, Name2TimerMap
> &GroupEntry
= Map
[GroupName
];
213 if (!GroupEntry
.first
)
214 GroupEntry
.first
= new TimerGroup(GroupName
);
216 Timer
&T
= GroupEntry
.second
[Name
];
217 if (!T
.isInitialized())
218 T
.init(Name
, *GroupEntry
.first
);
225 static ManagedStatic
<Name2TimerMap
> NamedTimers
;
226 static ManagedStatic
<Name2PairMap
> NamedGroupedTimers
;
228 static Timer
&getNamedRegionTimer(StringRef Name
) {
229 sys::SmartScopedLock
<true> L(*TimerLock
);
231 Timer
&T
= (*NamedTimers
)[Name
];
232 if (!T
.isInitialized())
237 NamedRegionTimer::NamedRegionTimer(StringRef Name
,
239 : TimeRegion(!Enabled
? nullptr : &getNamedRegionTimer(Name
)) {}
241 NamedRegionTimer::NamedRegionTimer(StringRef Name
, StringRef GroupName
,
243 : TimeRegion(!Enabled
? nullptr : &NamedGroupedTimers
->get(Name
, GroupName
)){}
245 //===----------------------------------------------------------------------===//
246 // TimerGroup Implementation
247 //===----------------------------------------------------------------------===//
249 /// TimerGroupList - This is the global list of TimerGroups, maintained by the
250 /// TimerGroup ctor/dtor and is protected by the TimerLock lock.
251 static TimerGroup
*TimerGroupList
= nullptr;
253 TimerGroup::TimerGroup(StringRef name
)
254 : Name(name
.begin(), name
.end()), FirstTimer(nullptr) {
256 // Add the group to TimerGroupList.
257 sys::SmartScopedLock
<true> L(*TimerLock
);
259 TimerGroupList
->Prev
= &Next
;
260 Next
= TimerGroupList
;
261 Prev
= &TimerGroupList
;
262 TimerGroupList
= this;
265 TimerGroup::~TimerGroup() {
266 // If the timer group is destroyed before the timers it owns, accumulate and
267 // print the timing data.
269 removeTimer(*FirstTimer
);
271 // Remove the group from the TimerGroupList.
272 sys::SmartScopedLock
<true> L(*TimerLock
);
279 void TimerGroup::removeTimer(Timer
&T
) {
280 sys::SmartScopedLock
<true> L(*TimerLock
);
282 // If the timer was started, move its data to TimersToPrint.
284 TimersToPrint
.push_back(std::make_pair(T
.Time
, T
.Name
));
288 // Unlink the timer from our list.
291 T
.Next
->Prev
= T
.Prev
;
293 // Print the report when all timers in this group are destroyed if some of
294 // them were started.
295 if (FirstTimer
|| TimersToPrint
.empty())
298 raw_ostream
*OutStream
= CreateInfoOutputFile();
299 PrintQueuedTimers(*OutStream
);
300 delete OutStream
; // Close the file.
303 void TimerGroup::addTimer(Timer
&T
) {
304 sys::SmartScopedLock
<true> L(*TimerLock
);
306 // Add the timer to our list.
308 FirstTimer
->Prev
= &T
.Next
;
310 T
.Prev
= &FirstTimer
;
314 void TimerGroup::PrintQueuedTimers(raw_ostream
&OS
) {
315 // Sort the timers in descending order by amount of time taken.
316 std::sort(TimersToPrint
.begin(), TimersToPrint
.end());
319 for (unsigned i
= 0, e
= TimersToPrint
.size(); i
!= e
; ++i
)
320 Total
+= TimersToPrint
[i
].first
;
322 // Print out timing header.
323 OS
<< "===" << std::string(73, '-') << "===\n";
324 // Figure out how many spaces to indent TimerGroup name.
325 unsigned Padding
= (80-Name
.length())/2;
326 if (Padding
> 80) Padding
= 0; // Don't allow "negative" numbers
327 OS
.indent(Padding
) << Name
<< '\n';
328 OS
<< "===" << std::string(73, '-') << "===\n";
330 // If this is not an collection of ungrouped times, print the total time.
331 // Ungrouped timers don't really make sense to add up. We still print the
332 // TOTAL line to make the percentages make sense.
333 if (this != DefaultTimerGroup
)
334 OS
<< format(" Total Execution Time: %5.4f seconds (%5.4f wall clock)\n",
335 Total
.getProcessTime(), Total
.getWallTime());
338 if (Total
.getUserTime())
339 OS
<< " ---User Time---";
340 if (Total
.getSystemTime())
341 OS
<< " --System Time--";
342 if (Total
.getProcessTime())
343 OS
<< " --User+System--";
344 OS
<< " ---Wall Time---";
345 if (Total
.getMemUsed())
347 OS
<< " --- Name ---\n";
349 // Loop through all of the timing data, printing it out.
350 for (unsigned i
= 0, e
= TimersToPrint
.size(); i
!= e
; ++i
) {
351 const std::pair
<TimeRecord
, std::string
> &Entry
= TimersToPrint
[e
-i
-1];
352 Entry
.first
.print(Total
, OS
);
353 OS
<< Entry
.second
<< '\n';
356 Total
.print(Total
, OS
);
360 TimersToPrint
.clear();
363 /// print - Print any started timers in this group and zero them.
364 void TimerGroup::print(raw_ostream
&OS
) {
365 sys::SmartScopedLock
<true> L(*TimerLock
);
367 // See if any of our timers were started, if so add them to TimersToPrint and
369 for (Timer
*T
= FirstTimer
; T
; T
= T
->Next
) {
370 if (!T
->Started
) continue;
371 TimersToPrint
.push_back(std::make_pair(T
->Time
, T
->Name
));
373 // Clear out the time.
375 T
->Time
= TimeRecord();
378 // If any timers were started, print the group.
379 if (!TimersToPrint
.empty())
380 PrintQueuedTimers(OS
);
383 /// printAll - This static method prints all timers and clears them all out.
384 void TimerGroup::printAll(raw_ostream
&OS
) {
385 sys::SmartScopedLock
<true> L(*TimerLock
);
387 for (TimerGroup
*TG
= TimerGroupList
; TG
; TG
= TG
->Next
)