1 //===-- Timer.cpp - Interval Timing Support -------------------------------===//
2 //
3 // Interval Timing implementation.
4 //
5 //===----------------------------------------------------------------------===//
6 
7 #include "Support/Timer.h"
8 #include <sys/resource.h>
9 #include <sys/time.h>
10 #include <sys/unistd.h>
11 #include <unistd.h>
12 #include <malloc.h>
13 #include <stdio.h>
14 #include <iostream>
15 #include <algorithm>
16 #include <functional>
17 
18 // getNumBytesToNotCount - This function is supposed to return the number of
19 // bytes that are to be considered not allocated, even though malloc thinks they
20 // are allocated.
21 //
22 static unsigned getNumBytesToNotCount();
23 
24 static TimerGroup *DefaultTimerGroup = 0;
25 static TimerGroup *getDefaultTimerGroup() {
26   if (DefaultTimerGroup) return DefaultTimerGroup;
27   return DefaultTimerGroup = new TimerGroup("Miscellaneous Ungrouped Timers");
28 }
29 
30 Timer::Timer(const std::string &N)
31   : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
32     Started(false), TG(getDefaultTimerGroup()) {
33   TG->addTimer();
34 }
35 
36 Timer::Timer(const std::string &N, TimerGroup &tg)
37   : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
38     Started(false), TG(&tg) {
39   TG->addTimer();
40 }
41 
42 Timer::Timer(const Timer &T) {
43   TG = T.TG;
44   if (TG) TG->addTimer();
45   operator=(T);
46 }
47 
48 
49 // Copy ctor, initialize with no TG member.
50 Timer::Timer(bool, const Timer &T) {
51   TG = T.TG;     // Avoid assertion in operator=
52   operator=(T);  // Copy contents
53   TG = 0;
54 }
55 
56 
57 Timer::~Timer() {
58   if (TG) {
59     if (Started) {
60       Started = false;
61       TG->addTimerToPrint(*this);
62     }
63     TG->removeTimer();
64   }
65 }
66 
67 static long getMemUsage() {
68   struct mallinfo MI = mallinfo();
69   return MI.uordblks/*+MI.hblkhd-getNumBytesToNotCount()*/;
70 }
71 
72 struct TimeRecord {
73   double Elapsed, UserTime, SystemTime;
74   long MemUsed;
75 };
76 
77 static TimeRecord getTimeRecord(bool Start) {
78   struct rusage RU;
79   struct timeval T;
80   long MemUsed;
81   if (Start) {
82     MemUsed = getMemUsage();
83     if (getrusage(RUSAGE_SELF, &RU))
84       perror("getrusage call failed: -time-passes info incorrect!");
85   }
86   gettimeofday(&T, 0);
87 
88   if (!Start) {
89     MemUsed = getMemUsage();
90     if (getrusage(RUSAGE_SELF, &RU))
91       perror("getrusage call failed: -time-passes info incorrect!");
92   }
93 
94   TimeRecord Result;
95   Result.Elapsed    =           T.tv_sec +           T.tv_usec/1000000.0;
96   Result.UserTime   = RU.ru_utime.tv_sec + RU.ru_utime.tv_usec/1000000.0;
97   Result.SystemTime = RU.ru_stime.tv_sec + RU.ru_stime.tv_usec/1000000.0;
98   Result.MemUsed = MemUsed;
99 
100   return Result;
101 }
102 
103 static std::vector<Timer*> ActiveTimers;
104 
105 void Timer::startTimer() {
106   Started = true;
107   TimeRecord TR = getTimeRecord(true);
108   Elapsed    -= TR.Elapsed;
109   UserTime   -= TR.UserTime;
110   SystemTime -= TR.SystemTime;
111   MemUsed    -= TR.MemUsed;
112   PeakMemBase = TR.MemUsed;
113   ActiveTimers.push_back(this);
114 }
115 
116 void Timer::stopTimer() {
117   TimeRecord TR = getTimeRecord(false);
118   Elapsed    += TR.Elapsed;
119   UserTime   += TR.UserTime;
120   SystemTime += TR.SystemTime;
121   MemUsed    += TR.MemUsed;
122 
123   if (ActiveTimers.back() == this) {
124     ActiveTimers.pop_back();
125   } else {
126     std::vector<Timer*>::iterator I =
127       std::find(ActiveTimers.begin(), ActiveTimers.end(), this);
128     assert(I != ActiveTimers.end() && "stop but no startTimer?");
129     ActiveTimers.erase(I);
130   }
131 }
132 
133 void Timer::sum(const Timer &T) {
134   Elapsed    += T.Elapsed;
135   UserTime   += T.UserTime;
136   SystemTime += T.SystemTime;
137   MemUsed    += T.MemUsed;
138   PeakMem    += T.PeakMem;
139 }
140 
141 /// addPeakMemoryMeasurement - This method should be called whenever memory
142 /// usage needs to be checked.  It adds a peak memory measurement to the
143 /// currently active timers, which will be printed when the timer group prints
144 ///
145 void Timer::addPeakMemoryMeasurement() {
146   long MemUsed = getMemUsage();
147 
148   for (std::vector<Timer*>::iterator I = ActiveTimers.begin(),
149          E = ActiveTimers.end(); I != E; ++I)
150     (*I)->PeakMem = std::max((*I)->PeakMem, MemUsed-(*I)->PeakMemBase);
151 }
152 
153 
154 //===----------------------------------------------------------------------===//
155 //   TimerGroup Implementation
156 //===----------------------------------------------------------------------===//
157 
158 static void printVal(double Val, double Total) {
159   if (Total < 1e-7)   // Avoid dividing by zero...
160     fprintf(stderr, "        -----     ");
161   else
162     fprintf(stderr, "  %7.4f (%5.1f%%)", Val, Val*100/Total);
163 }
164 
165 void Timer::print(const Timer &Total) {
166   if (Total.UserTime)
167     printVal(UserTime, Total.UserTime);
168   if (Total.SystemTime)
169     printVal(SystemTime, Total.SystemTime);
170   if (Total.getProcessTime())
171     printVal(getProcessTime(), Total.getProcessTime());
172   printVal(Elapsed, Total.Elapsed);
173 
174   fprintf(stderr, "  ");
175 
176   if (Total.MemUsed)
177     fprintf(stderr, " %8ld  ", MemUsed);
178   if (Total.PeakMem) {
179     if (PeakMem)
180       fprintf(stderr, " %8ld  ", PeakMem);
181     else
182       fprintf(stderr, "           ");
183   }
184   std::cerr << Name << "\n";
185 
186   Started = false;  // Once printed, don't print again
187 }
188 
189 
190 void TimerGroup::removeTimer() {
191   if (--NumTimers == 0 && !TimersToPrint.empty()) { // Print timing report...
192     // Sort the timers in descending order by amount of time taken...
193     std::sort(TimersToPrint.begin(), TimersToPrint.end(),
194               std::greater<Timer>());
195 
196     // Figure out how many spaces to indent TimerGroup name...
197     unsigned Padding = (80-Name.length())/2;
198     if (Padding > 80) Padding = 0;         // Don't allow "negative" numbers
199 
200     ++NumTimers;
201     {  // Scope to contain Total timer... don't allow total timer to drop us to
202        // zero timers...
203       Timer Total("TOTAL");
204 
205       for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
206         Total.sum(TimersToPrint[i]);
207 
208       // Print out timing header...
209       std::cerr << "===" << std::string(73, '-') << "===\n"
210                 << std::string(Padding, ' ') << Name << "\n"
211                 << "===" << std::string(73, '-')
212                 << "===\n  Total Execution Time: " << Total.getProcessTime()
213                 << " seconds (" << Total.getWallTime()
214                 << " wall clock)\n\n";
215 
216       if (Total.UserTime)
217         std::cerr << "   ---User Time---";
218       if (Total.SystemTime)
219         std::cerr << "   --System Time--";
220       if (Total.getProcessTime())
221         std::cerr << "   --User+System--";
222       std::cerr << "   ---Wall Time---";
223       if (Total.getMemUsed())
224         std::cerr << "  ---Mem---";
225       if (Total.getPeakMem())
226         std::cerr << "  -PeakMem-";
227       std::cerr << "  --- Name ---\n";
228 
229       // Loop through all of the timing data, printing it out...
230       for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
231         TimersToPrint[i].print(Total);
232 
233       Total.print(Total);
234       std::cerr << std::endl;  // Flush output
235     }
236     --NumTimers;
237 
238     TimersToPrint.clear();
239   }
240 
241   // Delete default timer group!
242   if (NumTimers == 0 && this == DefaultTimerGroup) {
243     delete DefaultTimerGroup;
244     DefaultTimerGroup = 0;
245   }
246 }
247 
248 
249 
250 #if (__GNUC__ == 3) && (__GNUC_MINOR__ == 2) && (__GNUC_PATCHLEVEL__ == 0)
251 // If we have GCC 3.2.0, we can calculate pool allocation bookkeeping info
252 #define HAVE_POOL
253 extern "C" {
254   // Taken from GCC 3.2's stl_alloc.h file:
255   enum {_ALIGN = 8, _MAX_BYTES = 128, NFREE = _MAX_BYTES / _ALIGN};
256   struct FreeList { FreeList *Next; };
257 
258   FreeList *_ZNSt24__default_alloc_templateILb1ELi0EE12_S_free_listE[NFREE];
259   char *_ZNSt24__default_alloc_templateILb1ELi0EE13_S_start_freeE;
260   char *_ZNSt24__default_alloc_templateILb1ELi0EE11_S_end_freeE;
261   size_t _ZNSt24__default_alloc_templateILb1ELi0EE12_S_heap_sizeE;
262 
263   // Make the symbols possible to use...
264   FreeList* (&TheFreeList)[NFREE] = _ZNSt24__default_alloc_templateILb1ELi0EE12_S_free_listE;
265   char * &StartFree = _ZNSt24__default_alloc_templateILb1ELi0EE13_S_start_freeE;
266   char * &EndFree   = _ZNSt24__default_alloc_templateILb1ELi0EE11_S_end_freeE;
267   size_t &HeapSize  = _ZNSt24__default_alloc_templateILb1ELi0EE12_S_heap_sizeE;
268 }
269 #endif
270 
271 // getNumBytesToNotCount - This function is supposed to return the number of
272 // bytes that are to be considered not allocated, even though malloc thinks they
273 // are allocated.
274 //
275 static unsigned getNumBytesToNotCount() {
276 #ifdef HAVE_POOL
277   // If we have GCC 3.2.0, we can subtract off pool allocation bookkeeping info
278 
279   // Size of the free slab section...
280   unsigned FreePoolMem = (unsigned)(EndFree-StartFree);
281 
282   // Walk all of the free lists, adding memory to the free counter whenever we
283   // have a free bucket.
284   for (unsigned i = 0; i != NFREE; ++i) {
285     unsigned NumEntries = 0;
286     for (FreeList *FL = TheFreeList[i]; FL; ++NumEntries, FL = FL->Next)
287       /*empty*/ ;
288 
289 #if 0
290     if (NumEntries)
291       std::cerr << "  For Size[" << (i+1)*_ALIGN << "]: " << NumEntries
292                 << " Free entries\n";
293 #endif
294     FreePoolMem += NumEntries*(i+1)*_ALIGN;
295   }
296   return FreePoolMem;
297 
298 #else
299 #warning "Don't know how to avoid pool allocation accounting overhead for this"
300 #warning " compiler: Space usage numbers (with -time-passes) may be off!"
301   return 0;
302 #endif
303 }
304