lib/Support/Timer.cpp

   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 }