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 <unistd.h>
  12 #ifndef __FreeBSD__
  13 #include <malloc.h>
  14 #endif // __FreeBSD__
  15 #include <stdio.h>
  16 #include <iostream>
  17 #include <algorithm>
  18 #include <functional>
  19 #include <fstream>
  20
  21 std::string LibSupportInfoOutputFilename;
  22
  23 namespace {
  24   cl::opt<bool>
  25   TrackSpace("track-memory", cl::desc("Enable -time-passes memory "
  26                                       "tracking (this may be slow)"),
  27              cl::Hidden);
  28
  29   cl::opt<std::string, true>
  30   InfoOutputFilename("info-output-file",
  31                      cl::desc("File to append -stats and -timer output to"),
  32                      cl::Hidden, cl::location(LibSupportInfoOutputFilename));
  33 }
  34
  35 static TimerGroup *DefaultTimerGroup = 0;
  36 static TimerGroup *getDefaultTimerGroup() {
  37   if (DefaultTimerGroup) return DefaultTimerGroup;
  38   return DefaultTimerGroup = new TimerGroup("Miscellaneous Ungrouped Timers");
  39 }
  40
  41 Timer::Timer(const std::string &N)
  42   : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
  43     Started(false), TG(getDefaultTimerGroup()) {
  44   TG->addTimer();
  45 }
  46
  47 Timer::Timer(const std::string &N, TimerGroup &tg)
  48   : Elapsed(0), UserTime(0), SystemTime(0), MemUsed(0), PeakMem(0), Name(N),
  49     Started(false), TG(&tg) {
  50   TG->addTimer();
  51 }
  52
  53 Timer::Timer(const Timer &T) {
  54   TG = T.TG;
  55   if (TG) TG->addTimer();
  56   operator=(T);
  57 }
  58
  59
  60 // Copy ctor, initialize with no TG member.
  61 Timer::Timer(bool, const Timer &T) {
  62   TG = T.TG;     // Avoid assertion in operator=
  63   operator=(T);  // Copy contents
  64   TG = 0;
  65 }
  66
  67
  68 Timer::~Timer() {
  69   if (TG) {
  70     if (Started) {
  71       Started = false;
  72       TG->addTimerToPrint(*this);
  73     }
  74     TG->removeTimer();
  75   }
  76 }
  77
  78 static long getMemUsage() {
  79 #ifndef __FreeBSD__
  80   if (TrackSpace) {
  81     struct mallinfo MI = mallinfo();
  82     return MI.uordblks/*+MI.hblkhd*/;
  83   }
  84 #endif // __FreeBSD__
  85   return 0;
  86 }
  87
  88 struct TimeRecord {
  89   double Elapsed, UserTime, SystemTime;
  90   long MemUsed;
  91 };
  92
  93 static TimeRecord getTimeRecord(bool Start) {
  94   struct rusage RU;
  95   struct timeval T;
  96   long MemUsed = 0;
  97   if (Start) {
  98     MemUsed = getMemUsage();
  99     if (getrusage(RUSAGE_SELF, &RU))
 100       perror("getrusage call failed: -time-passes info incorrect!");
 101   }
 102   gettimeofday(&T, 0);
 103
 104   if (!Start) {
 105     MemUsed = getMemUsage();
 106     if (getrusage(RUSAGE_SELF, &RU))
 107       perror("getrusage call failed: -time-passes info incorrect!");
 108   }
 109
 110   TimeRecord Result;
 111   Result.Elapsed    =           T.tv_sec +           T.tv_usec/1000000.0;
 112   Result.UserTime   = RU.ru_utime.tv_sec + RU.ru_utime.tv_usec/1000000.0;
 113   Result.SystemTime = RU.ru_stime.tv_sec + RU.ru_stime.tv_usec/1000000.0;
 114   Result.MemUsed = MemUsed;
 115
 116   return Result;
 117 }
 118
 119 static std::vector<Timer*> ActiveTimers;
 120
 121 void Timer::startTimer() {
 122   Started = true;
 123   TimeRecord TR = getTimeRecord(true);
 124   Elapsed    -= TR.Elapsed;
 125   UserTime   -= TR.UserTime;
 126   SystemTime -= TR.SystemTime;
 127   MemUsed    -= TR.MemUsed;
 128   PeakMemBase = TR.MemUsed;
 129   ActiveTimers.push_back(this);
 130 }
 131
 132 void Timer::stopTimer() {
 133   TimeRecord TR = getTimeRecord(false);
 134   Elapsed    += TR.Elapsed;
 135   UserTime   += TR.UserTime;
 136   SystemTime += TR.SystemTime;
 137   MemUsed    += TR.MemUsed;
 138
 139   if (ActiveTimers.back() == this) {
 140     ActiveTimers.pop_back();
 141   } else {
 142     std::vector<Timer*>::iterator I =
 143       std::find(ActiveTimers.begin(), ActiveTimers.end(), this);
 144     assert(I != ActiveTimers.end() && "stop but no startTimer?");
 145     ActiveTimers.erase(I);
 146   }
 147 }
 148
 149 void Timer::sum(const Timer &T) {
 150   Elapsed    += T.Elapsed;
 151   UserTime   += T.UserTime;
 152   SystemTime += T.SystemTime;
 153   MemUsed    += T.MemUsed;
 154   PeakMem    += T.PeakMem;
 155 }
 156
 157 /// addPeakMemoryMeasurement - This method should be called whenever memory
 158 /// usage needs to be checked.  It adds a peak memory measurement to the
 159 /// currently active timers, which will be printed when the timer group prints
 160 ///
 161 void Timer::addPeakMemoryMeasurement() {
 162   long MemUsed = getMemUsage();
 163
 164   for (std::vector<Timer*>::iterator I = ActiveTimers.begin(),
 165          E = ActiveTimers.end(); I != E; ++I)
 166     (*I)->PeakMem = std::max((*I)->PeakMem, MemUsed-(*I)->PeakMemBase);
 167 }
 168
 169
 170 //===----------------------------------------------------------------------===//
 171 //   TimerGroup Implementation
 172 //===----------------------------------------------------------------------===//
 173
 174 // printAlignedFP - Simulate the printf "%A.Bf" format, where A is the
 175 // TotalWidth size, and B is the AfterDec size.
 176 //
 177 static void printAlignedFP(double Val, unsigned AfterDec, unsigned TotalWidth,
 178                            std::ostream &OS) {
 179   assert(TotalWidth >= AfterDec+1 && "Bad FP Format!");
 180   OS.width(TotalWidth-AfterDec-1);
 181   char OldFill = OS.fill();
 182   OS.fill(' ');
 183   OS << (int)Val;  // Integer part;
 184   OS << ".";
 185   OS.width(AfterDec);
 186   OS.fill('0');
 187   unsigned ResultFieldSize = 1;
 188   while (AfterDec--) ResultFieldSize *= 10;
 189   OS << (int)(Val*ResultFieldSize) % ResultFieldSize;
 190   OS.fill(OldFill);
 191 }
 192
 193 static void printVal(double Val, double Total, std::ostream &OS) {
 194   if (Total < 1e-7)   // Avoid dividing by zero...
 195     OS << "        -----     ";
 196   else {
 197     OS << "  ";
 198     printAlignedFP(Val, 4, 7, OS);
 199     OS << " (";
 200     printAlignedFP(Val*100/Total, 1, 5, OS);
 201     OS << "%)";
 202   }
 203 }
 204
 205 void Timer::print(const Timer &Total, std::ostream &OS) {
 206   if (Total.UserTime)
 207     printVal(UserTime, Total.UserTime, OS);
 208   if (Total.SystemTime)
 209     printVal(SystemTime, Total.SystemTime, OS);
 210   if (Total.getProcessTime())
 211     printVal(getProcessTime(), Total.getProcessTime(), OS);
 212   printVal(Elapsed, Total.Elapsed, OS);
 213
 214   OS << "  ";
 215
 216   if (Total.MemUsed) {
 217     OS.width(9);
 218     OS << MemUsed << "  ";
 219   }
 220   if (Total.PeakMem) {
 221     if (PeakMem) {
 222       OS.width(9);
 223       OS << PeakMem << "  ";
 224     } else
 225       OS << "           ";
 226   }
 227   OS << Name << "\n";
 228
 229   Started = false;  // Once printed, don't print again
 230 }
 231
 232 // GetLibSupportInfoOutputFile - Return a file stream to print our output on...
 233 std::ostream *GetLibSupportInfoOutputFile() {
 234   if (LibSupportInfoOutputFilename.empty())
 235     return &std::cerr;
 236   if (LibSupportInfoOutputFilename == "-")
 237     return &std::cout;
 238
 239   std::ostream *Result = new std::ofstream(LibSupportInfoOutputFilename.c_str(),
 240                                            std::ios::app);
 241   if (!Result->good()) {
 242     std::cerr << "Error opening info-output-file '"
 243               << LibSupportInfoOutputFilename << " for appending!\n";
 244     delete Result;
 245     return &std::cerr;
 246   }
 247   return Result;
 248 }
 249
 250
 251 void TimerGroup::removeTimer() {
 252   if (--NumTimers == 0 && !TimersToPrint.empty()) { // Print timing report...
 253     // Sort the timers in descending order by amount of time taken...
 254     std::sort(TimersToPrint.begin(), TimersToPrint.end(),
 255               std::greater<Timer>());
 256
 257     // Figure out how many spaces to indent TimerGroup name...
 258     unsigned Padding = (80-Name.length())/2;
 259     if (Padding > 80) Padding = 0;         // Don't allow "negative" numbers
 260
 261     std::ostream *OutStream = GetLibSupportInfoOutputFile();
 262
 263     ++NumTimers;
 264     {  // Scope to contain Total timer... don't allow total timer to drop us to
 265        // zero timers...
 266       Timer Total("TOTAL");
 267
 268       for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
 269         Total.sum(TimersToPrint[i]);
 270
 271       // Print out timing header...
 272       *OutStream << "===" << std::string(73, '-') << "===\n"
 273                  << std::string(Padding, ' ') << Name << "\n"
 274                  << "===" << std::string(73, '-')
 275                  << "===\n  Total Execution Time: ";
 276
 277       printAlignedFP(Total.getProcessTime(), 4, 5, *OutStream);
 278       *OutStream << " seconds (";
 279       printAlignedFP(Total.getWallTime(), 4, 5, *OutStream);
 280       *OutStream << " wall clock)\n\n";
 281
 282       if (Total.UserTime)
 283         *OutStream << "   ---User Time---";
 284       if (Total.SystemTime)
 285         *OutStream << "   --System Time--";
 286       if (Total.getProcessTime())
 287         *OutStream << "   --User+System--";
 288       *OutStream << "   ---Wall Time---";
 289       if (Total.getMemUsed())
 290         *OutStream << "  ---Mem---";
 291       if (Total.getPeakMem())
 292         *OutStream << "  -PeakMem-";
 293       *OutStream << "  --- Name ---\n";
 294
 295       // Loop through all of the timing data, printing it out...
 296       for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i)
 297         TimersToPrint[i].print(Total, *OutStream);
 298
 299       Total.print(Total, *OutStream);
 300       *OutStream << std::endl;  // Flush output
 301     }
 302     --NumTimers;
 303
 304     TimersToPrint.clear();
 305
 306     if (OutStream != &std::cerr && OutStream != &std::cout)
 307       delete OutStream;   // Close the file...
 308   }
 309
 310   // Delete default timer group!
 311   if (NumTimers == 0 && this == DefaultTimerGroup) {
 312     delete DefaultTimerGroup;
 313     DefaultTimerGroup = 0;
 314   }
 315 }