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 "Support/CommandLine.h"
   9 #include <sys/resource.h>
  10 #include <sys/time.h>
  11 #include <sys/unistd.h>
  12 #include <unistd.h>
  13 #include <malloc.h>
  14 #include <stdio.h>
  15 #include <iostream>
  16 #include <algorithm>
  17 #include <functional>
  18
  19 namespace {
  20   cl::opt<bool>
  21   TrackSpace("track-memory", cl::desc("Enable -time-passes memory "
  22                                       "tracking (this may be slow)"),
  23              cl::Hidden);
  24 }
  25
  26 static TimerGroup *DefaultTimerGroup = 0;
  27 static TimerGroup *getDefaultTimerGroup() {
  28   if (DefaultTimerGroup) return DefaultTimerGroup;
  29   return DefaultTimerGroup = new TimerGroup("Miscellaneous Ungrouped Timers");
  30 }
  31
  32 Timer::Timer(const std::string &N)
  33   : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
  34     Started(false), TG(getDefaultTimerGroup()) {
  35   TG->addTimer();
  36 }
  37
  38 Timer::Timer(const std::string &N, TimerGroup &tg)
  39   : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
  40     Started(false), TG(&tg) {
  41   TG->addTimer();
  42 }
  43
  44 Timer::Timer(const Timer &T) {
  45   TG = T.TG;
  46   if (TG) TG->addTimer();
  47   operator=(T);
  48 }
  49
  50
  51 // Copy ctor, initialize with no TG member.
  52 Timer::Timer(bool, const Timer &T) {
  53   TG = T.TG;     // Avoid assertion in operator=
  54   operator=(T);  // Copy contents
  55   TG = 0;
  56 }
  57
  58
  59 Timer::~Timer() {
  60   if (TG) {
  61     if (Started) {
  62       Started = false;
  63       TG->addTimerToPrint(*this);
  64     }
  65     TG->removeTimer();
  66   }
  67 }
  68
  69 static long getMemUsage() {
  70   if (TrackSpace) {
  71     struct mallinfo MI = mallinfo();
  72     return MI.uordblks/*+MI.hblkhd*/;
  73   } else {
  74     return 0;
  75   }
  76 }
  77
  78 struct TimeRecord {
  79   double Elapsed, UserTime, SystemTime;
  80   long MemUsed;
  81 };
  82
  83 static TimeRecord getTimeRecord(bool Start) {
  84   struct rusage RU;
  85   struct timeval T;
  86   long MemUsed = 0;
  87   if (Start) {
  88     MemUsed = getMemUsage();
  89     if (getrusage(RUSAGE_SELF, &RU))
  90       perror("getrusage call failed: -time-passes info incorrect!");
  91   }
  92   gettimeofday(&T, 0);
  93
  94   if (!Start) {
  95     MemUsed = getMemUsage();
  96     if (getrusage(RUSAGE_SELF, &RU))
  97       perror("getrusage call failed: -time-passes info incorrect!");
  98   }
  99
 100   TimeRecord Result;
 101   Result.Elapsed    =           T.tv_sec +           T.tv_usec/1000000.0;
 102   Result.UserTime   = RU.ru_utime.tv_sec + RU.ru_utime.tv_usec/1000000.0;
 103   Result.SystemTime = RU.ru_stime.tv_sec + RU.ru_stime.tv_usec/1000000.0;
 104   Result.MemUsed = MemUsed;
 105
 106   return Result;
 107 }
 108
 109 static std::vector<Timer*> ActiveTimers;
 110
 111 void Timer::startTimer() {
 112   Started = true;
 113   TimeRecord TR = getTimeRecord(true);
 114   Elapsed    -= TR.Elapsed;
 115   UserTime   -= TR.UserTime;
 116   SystemTime -= TR.SystemTime;
 117   MemUsed    -= TR.MemUsed;
 118   PeakMemBase = TR.MemUsed;
 119   ActiveTimers.push_back(this);
 120 }
 121
 122 void Timer::stopTimer() {
 123   TimeRecord TR = getTimeRecord(false);
 124   Elapsed    += TR.Elapsed;
 125   UserTime   += TR.UserTime;
 126   SystemTime += TR.SystemTime;
 127   MemUsed    += TR.MemUsed;
 128
 129   if (ActiveTimers.back() == this) {
 130     ActiveTimers.pop_back();
 131   } else {
 132     std::vector<Timer*>::iterator I =
 133       std::find(ActiveTimers.begin(), ActiveTimers.end(), this);
 134     assert(I != ActiveTimers.end() && "stop but no startTimer?");
 135     ActiveTimers.erase(I);
 136   }
 137 }
 138
 139 void Timer::sum(const Timer &T) {
 140   Elapsed    += T.Elapsed;
 141   UserTime   += T.UserTime;
 142   SystemTime += T.SystemTime;
 143   MemUsed    += T.MemUsed;
 144   PeakMem    += T.PeakMem;
 145 }
 146
 147 /// addPeakMemoryMeasurement - This method should be called whenever memory
 148 /// usage needs to be checked.  It adds a peak memory measurement to the
 149 /// currently active timers, which will be printed when the timer group prints
 150 ///
 151 void Timer::addPeakMemoryMeasurement() {
 152   long MemUsed = getMemUsage();
 153
 154   for (std::vector<Timer*>::iterator I = ActiveTimers.begin(),
 155          E = ActiveTimers.end(); I != E; ++I)
 156     (*I)->PeakMem = std::max((*I)->PeakMem, MemUsed-(*I)->PeakMemBase);
 157 }
 158
 159
 160 //===----------------------------------------------------------------------===//
 161 //   TimerGroup Implementation
 162 //===----------------------------------------------------------------------===//
 163
 164 static void printVal(double Val, double Total) {
 165   if (Total < 1e-7)   // Avoid dividing by zero...
 166     fprintf(stderr, "        -----     ");
 167   else
 168     fprintf(stderr, "  %7.4f (%5.1f%%)", Val, Val*100/Total);
 169 }
 170
 171 void Timer::print(const Timer &Total) {
 172   if (Total.UserTime)
 173     printVal(UserTime, Total.UserTime);
 174   if (Total.SystemTime)
 175     printVal(SystemTime, Total.SystemTime);
 176   if (Total.getProcessTime())
 177     printVal(getProcessTime(), Total.getProcessTime());
 178   printVal(Elapsed, Total.Elapsed);
 179
 180   fprintf(stderr, "  ");
 181
 182   if (Total.MemUsed)
 183     fprintf(stderr, " %8ld  ", MemUsed);
 184   if (Total.PeakMem) {
 185     if (PeakMem)
 186       fprintf(stderr, " %8ld  ", PeakMem);
 187     else
 188       fprintf(stderr, "           ");
 189   }
 190   std::cerr << Name << "\n";
 191
 192   Started = false;  // Once printed, don't print again
 193 }
 194
 195
 196 void TimerGroup::removeTimer() {
 197   if (--NumTimers == 0 && !TimersToPrint.empty()) { // Print timing report...
 198     // Sort the timers in descending order by amount of time taken...
 199     std::sort(TimersToPrint.begin(), TimersToPrint.end(),
 200               std::greater<Timer>());
 201
 202     // Figure out how many spaces to indent TimerGroup name...
 203     unsigned Padding = (80-Name.length())/2;
 204     if (Padding > 80) Padding = 0;         // Don't allow "negative" numbers
 205
 206     ++NumTimers;
 207     {  // Scope to contain Total timer... don't allow total timer to drop us to
 208        // zero timers...
 209       Timer Total("TOTAL");
 210
 211       for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
 212         Total.sum(TimersToPrint[i]);
 213
 214       // Print out timing header...
 215       std::cerr << "===" << std::string(73, '-') << "===\n"
 216                 << std::string(Padding, ' ') << Name << "\n"
 217                 << "===" << std::string(73, '-')
 218                 << "===\n  Total Execution Time: " << std::fixed
 219                 << Total.getProcessTime()
 220                 << " seconds (" << Total.getWallTime() << std::scientific
 221                 << " wall clock)\n\n";
 222
 223       if (Total.UserTime)
 224         std::cerr << "   ---User Time---";
 225       if (Total.SystemTime)
 226         std::cerr << "   --System Time--";
 227       if (Total.getProcessTime())
 228         std::cerr << "   --User+System--";
 229       std::cerr << "   ---Wall Time---";
 230       if (Total.getMemUsed())
 231         std::cerr << "  ---Mem---";
 232       if (Total.getPeakMem())
 233         std::cerr << "  -PeakMem-";
 234       std::cerr << "  --- Name ---\n";
 235
 236       // Loop through all of the timing data, printing it out...
 237       for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
 238         TimersToPrint[i].print(Total);
 239
 240       Total.print(Total);
 241       std::cerr << std::endl;  // Flush output
 242     }
 243     --NumTimers;
 244
 245     TimersToPrint.clear();
 246   }
 247
 248   // Delete default timer group!
 249   if (NumTimers == 0 && this == DefaultTimerGroup) {
 250     delete DefaultTimerGroup;
 251     DefaultTimerGroup = 0;
 252   }
 253 }