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