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