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 10 #include "Config/sys/resource.h" 11 #include "Config/sys/time.h" 12 #include "Config/unistd.h" 13 #include "Config/malloc.h" 14 #include "Config/stdio.h" 15 #include <iostream> 16 #include <algorithm> 17 #include <functional> 18 #include <fstream> 19 20 static std::string LibSupportInfoOutputFilename; 21 22 namespace { 23 #ifdef HAVE_MALLINFO 24 cl::opt<bool> 25 TrackSpace("track-memory", cl::desc("Enable -time-passes memory " 26 "tracking (this may be slow)"), 27 cl::Hidden); 28 #endif 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 #ifdef HAVE_MALLINFO 81 if (TrackSpace) { 82 struct mallinfo MI = mallinfo(); 83 return MI.uordblks/*+MI.hblkhd*/; 84 } 85 #endif 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 } 317