X-Git-Url: http://demsky.eecs.uci.edu/git/?a=blobdiff_plain;f=lib%2FSupport%2FTimer.cpp;h=077995d9fb8993a21d4a07120d20e1c366b0854a;hb=3daae2701b76293c31c1cbdafc9782352321e1f0;hp=3a81fc4b53f30213ca9fd430c680f7e26efb6ccf;hpb=bbe5ac1458f3719fd51785f086e9166ccbb0c464;p=oota-llvm.git diff --git a/lib/Support/Timer.cpp b/lib/Support/Timer.cpp index 3a81fc4b53f..077995d9fb8 100644 --- a/lib/Support/Timer.cpp +++ b/lib/Support/Timer.cpp @@ -1,33 +1,54 @@ //===-- Timer.cpp - Interval Timing Support -------------------------------===// // +// The LLVM Compiler Infrastructure +// +// This file was developed by the LLVM research group and is distributed under +// the University of Illinois Open Source License. See LICENSE.TXT for details. +// +//===----------------------------------------------------------------------===// +// // Interval Timing implementation. // //===----------------------------------------------------------------------===// -#include "Support/Timer.h" -#include "Support/CommandLine.h" -#include -#include -#include -#include -#include -#include -#include +#include "llvm/Support/Timer.h" +#include "llvm/Support/CommandLine.h" +#include "llvm/Support/ManagedStatic.h" +#include "llvm/Support/Streams.h" +#include "llvm/System/Process.h" #include +#include #include +#include +using namespace llvm; + +// GetLibSupportInfoOutputFile - Return a file stream to print our output on. +namespace llvm { extern std::ostream *GetLibSupportInfoOutputFile(); } + +// getLibSupportInfoOutputFilename - This ugly hack is brought to you courtesy +// of constructor/destructor ordering being unspecified by C++. Basically the +// problem is that a Statistic object gets destroyed, which ends up calling +// 'GetLibSupportInfoOutputFile()' (below), which calls this function. +// LibSupportInfoOutputFilename used to be a global variable, but sometimes it +// would get destroyed before the Statistic, causing havoc to ensue. We "fix" +// this by creating the string the first time it is needed and never destroying +// it. +static ManagedStatic LibSupportInfoOutputFilename; +static std::string &getLibSupportInfoOutputFilename() { + return *LibSupportInfoOutputFilename; +} namespace { cl::opt TrackSpace("track-memory", cl::desc("Enable -time-passes memory " "tracking (this may be slow)"), cl::Hidden); -} -// getNumBytesToNotCount - This function is supposed to return the number of -// bytes that are to be considered not allocated, even though malloc thinks they -// are allocated. -// -static unsigned getNumBytesToNotCount(); + cl::opt + InfoOutputFilename("info-output-file", cl::value_desc("filename"), + cl::desc("File to append -stats and -timer output to"), + cl::Hidden, cl::location(getLibSupportInfoOutputFilename())); +} static TimerGroup *DefaultTimerGroup = 0; static TimerGroup *getDefaultTimerGroup() { @@ -72,47 +93,42 @@ Timer::~Timer() { } } -static long getMemUsage() { - if (TrackSpace) { - struct mallinfo MI = mallinfo(); - return MI.uordblks/*+MI.hblkhd-getNumBytesToNotCount()*/; - } else { - return 0; - } +static inline size_t getMemUsage() { + if (TrackSpace) + return sys::Process::GetMallocUsage(); + return 0; } struct TimeRecord { double Elapsed, UserTime, SystemTime; - long MemUsed; + ssize_t MemUsed; }; static TimeRecord getTimeRecord(bool Start) { - struct rusage RU; - struct timeval T; - long MemUsed = 0; + TimeRecord Result; + + sys::TimeValue now(0,0); + sys::TimeValue user(0,0); + sys::TimeValue sys(0,0); + + ssize_t MemUsed = 0; if (Start) { MemUsed = getMemUsage(); - if (getrusage(RUSAGE_SELF, &RU)) - perror("getrusage call failed: -time-passes info incorrect!"); - } - gettimeofday(&T, 0); - - if (!Start) { + sys::Process::GetTimeUsage(now,user,sys); + } else { + sys::Process::GetTimeUsage(now,user,sys); MemUsed = getMemUsage(); - if (getrusage(RUSAGE_SELF, &RU)) - perror("getrusage call failed: -time-passes info incorrect!"); } - TimeRecord Result; - Result.Elapsed = T.tv_sec + T.tv_usec/1000000.0; - Result.UserTime = RU.ru_utime.tv_sec + RU.ru_utime.tv_usec/1000000.0; - Result.SystemTime = RU.ru_stime.tv_sec + RU.ru_stime.tv_usec/1000000.0; - Result.MemUsed = MemUsed; + Result.Elapsed = now.seconds() + now.microseconds() / 1000000.0; + Result.UserTime = user.seconds() + user.microseconds() / 1000000.0; + Result.SystemTime = sys.seconds() + sys.microseconds() / 1000000.0; + Result.MemUsed = MemUsed; return Result; } -static std::vector ActiveTimers; +static ManagedStatic > ActiveTimers; void Timer::startTimer() { Started = true; @@ -122,7 +138,7 @@ void Timer::startTimer() { SystemTime -= TR.SystemTime; MemUsed -= TR.MemUsed; PeakMemBase = TR.MemUsed; - ActiveTimers.push_back(this); + ActiveTimers->push_back(this); } void Timer::stopTimer() { @@ -132,13 +148,13 @@ void Timer::stopTimer() { SystemTime += TR.SystemTime; MemUsed += TR.MemUsed; - if (ActiveTimers.back() == this) { - ActiveTimers.pop_back(); + if (ActiveTimers->back() == this) { + ActiveTimers->pop_back(); } else { std::vector::iterator I = - std::find(ActiveTimers.begin(), ActiveTimers.end(), this); - assert(I != ActiveTimers.end() && "stop but no startTimer?"); - ActiveTimers.erase(I); + std::find(ActiveTimers->begin(), ActiveTimers->end(), this); + assert(I != ActiveTimers->end() && "stop but no startTimer?"); + ActiveTimers->erase(I); } } @@ -155,49 +171,113 @@ void Timer::sum(const Timer &T) { /// currently active timers, which will be printed when the timer group prints /// void Timer::addPeakMemoryMeasurement() { - long MemUsed = getMemUsage(); + size_t MemUsed = getMemUsage(); - for (std::vector::iterator I = ActiveTimers.begin(), - E = ActiveTimers.end(); I != E; ++I) + for (std::vector::iterator I = ActiveTimers->begin(), + E = ActiveTimers->end(); I != E; ++I) (*I)->PeakMem = std::max((*I)->PeakMem, MemUsed-(*I)->PeakMemBase); } +//===----------------------------------------------------------------------===// +// NamedRegionTimer Implementation +//===----------------------------------------------------------------------===// + +static ManagedStatic > NamedTimers; + +static Timer &getNamedRegionTimer(const std::string &Name) { + std::map::iterator I = NamedTimers->lower_bound(Name); + if (I != NamedTimers->end() && I->first == Name) + return I->second; + + return NamedTimers->insert(I, std::make_pair(Name, Timer(Name)))->second; +} + +NamedRegionTimer::NamedRegionTimer(const std::string &Name) + : TimeRegion(getNamedRegionTimer(Name)) {} + //===----------------------------------------------------------------------===// // TimerGroup Implementation //===----------------------------------------------------------------------===// -static void printVal(double Val, double Total) { +// printAlignedFP - Simulate the printf "%A.Bf" format, where A is the +// TotalWidth size, and B is the AfterDec size. +// +static void printAlignedFP(double Val, unsigned AfterDec, unsigned TotalWidth, + std::ostream &OS) { + assert(TotalWidth >= AfterDec+1 && "Bad FP Format!"); + OS.width(TotalWidth-AfterDec-1); + char OldFill = OS.fill(); + OS.fill(' '); + OS << (int)Val; // Integer part; + OS << "."; + OS.width(AfterDec); + OS.fill('0'); + unsigned ResultFieldSize = 1; + while (AfterDec--) ResultFieldSize *= 10; + OS << (int)(Val*ResultFieldSize) % ResultFieldSize; + OS.fill(OldFill); +} + +static void printVal(double Val, double Total, std::ostream &OS) { if (Total < 1e-7) // Avoid dividing by zero... - fprintf(stderr, " ----- "); - else - fprintf(stderr, " %7.4f (%5.1f%%)", Val, Val*100/Total); + OS << " ----- "; + else { + OS << " "; + printAlignedFP(Val, 4, 7, OS); + OS << " ("; + printAlignedFP(Val*100/Total, 1, 5, OS); + OS << "%)"; + } } -void Timer::print(const Timer &Total) { +void Timer::print(const Timer &Total, std::ostream &OS) { if (Total.UserTime) - printVal(UserTime, Total.UserTime); + printVal(UserTime, Total.UserTime, OS); if (Total.SystemTime) - printVal(SystemTime, Total.SystemTime); + printVal(SystemTime, Total.SystemTime, OS); if (Total.getProcessTime()) - printVal(getProcessTime(), Total.getProcessTime()); - printVal(Elapsed, Total.Elapsed); - - fprintf(stderr, " "); + printVal(getProcessTime(), Total.getProcessTime(), OS); + printVal(Elapsed, Total.Elapsed, OS); + + OS << " "; - if (Total.MemUsed) - fprintf(stderr, " %8ld ", MemUsed); + if (Total.MemUsed) { + OS.width(9); + OS << MemUsed << " "; + } if (Total.PeakMem) { - if (PeakMem) - fprintf(stderr, " %8ld ", PeakMem); - else - fprintf(stderr, " "); + if (PeakMem) { + OS.width(9); + OS << PeakMem << " "; + } else + OS << " "; } - std::cerr << Name << "\n"; + OS << Name << "\n"; Started = false; // Once printed, don't print again } +// GetLibSupportInfoOutputFile - Return a file stream to print our output on... +std::ostream * +llvm::GetLibSupportInfoOutputFile() { + std::string &LibSupportInfoOutputFilename = getLibSupportInfoOutputFilename(); + if (LibSupportInfoOutputFilename.empty()) + return cerr.stream(); + if (LibSupportInfoOutputFilename == "-") + return cout.stream(); + + std::ostream *Result = new std::ofstream(LibSupportInfoOutputFilename.c_str(), + std::ios::app); + if (!Result->good()) { + cerr << "Error opening info-output-file '" + << LibSupportInfoOutputFilename << " for appending!\n"; + delete Result; + return cerr.stream(); + } + return Result; +} + void TimerGroup::removeTimer() { if (--NumTimers == 0 && !TimersToPrint.empty()) { // Print timing report... @@ -209,45 +289,61 @@ void TimerGroup::removeTimer() { unsigned Padding = (80-Name.length())/2; if (Padding > 80) Padding = 0; // Don't allow "negative" numbers + std::ostream *OutStream = GetLibSupportInfoOutputFile(); + ++NumTimers; { // Scope to contain Total timer... don't allow total timer to drop us to // zero timers... Timer Total("TOTAL"); - + for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i) Total.sum(TimersToPrint[i]); - + // Print out timing header... - std::cerr << "===" << std::string(73, '-') << "===\n" - << std::string(Padding, ' ') << Name << "\n" - << "===" << std::string(73, '-') - << "===\n Total Execution Time: " << Total.getProcessTime() - << " seconds (" << Total.getWallTime() - << " wall clock)\n\n"; + *OutStream << "===" << std::string(73, '-') << "===\n" + << std::string(Padding, ' ') << Name << "\n" + << "===" << std::string(73, '-') + << "===\n"; + + // If this is not an collection of ungrouped times, print the total time. + // Ungrouped timers don't really make sense to add up. We still print the + // TOTAL line to make the percentages make sense. + if (this != DefaultTimerGroup) { + *OutStream << " Total Execution Time: "; + + printAlignedFP(Total.getProcessTime(), 4, 5, *OutStream); + *OutStream << " seconds ("; + printAlignedFP(Total.getWallTime(), 4, 5, *OutStream); + *OutStream << " wall clock)\n"; + } + *OutStream << "\n"; if (Total.UserTime) - std::cerr << " ---User Time---"; + *OutStream << " ---User Time---"; if (Total.SystemTime) - std::cerr << " --System Time--"; + *OutStream << " --System Time--"; if (Total.getProcessTime()) - std::cerr << " --User+System--"; - std::cerr << " ---Wall Time---"; + *OutStream << " --User+System--"; + *OutStream << " ---Wall Time---"; if (Total.getMemUsed()) - std::cerr << " ---Mem---"; + *OutStream << " ---Mem---"; if (Total.getPeakMem()) - std::cerr << " -PeakMem-"; - std::cerr << " --- Name ---\n"; - + *OutStream << " -PeakMem-"; + *OutStream << " --- Name ---\n"; + // Loop through all of the timing data, printing it out... for (unsigned i = 0, e = TimersToPrint.size(); i != e; ++i) - TimersToPrint[i].print(Total); - - Total.print(Total); - std::cerr << std::endl; // Flush output + TimersToPrint[i].print(Total, *OutStream); + + Total.print(Total, *OutStream); + *OutStream << std::endl; // Flush output } --NumTimers; TimersToPrint.clear(); + + if (OutStream != cerr.stream() && OutStream != cout.stream()) + delete OutStream; // Close the file... } // Delete default timer group! @@ -257,59 +353,3 @@ void TimerGroup::removeTimer() { } } - - -#if (__GNUC__ == 3) && (__GNUC_MINOR__ == 2) && (__GNUC_PATCHLEVEL__ == 0) -// If we have GCC 3.2.0, we can calculate pool allocation bookkeeping info -#define HAVE_POOL -extern "C" { - // Taken from GCC 3.2's stl_alloc.h file: - enum {_ALIGN = 8, _MAX_BYTES = 128, NFREE = _MAX_BYTES / _ALIGN}; - struct FreeList { FreeList *Next; }; - - FreeList *_ZNSt24__default_alloc_templateILb1ELi0EE12_S_free_listE[NFREE]; - char *_ZNSt24__default_alloc_templateILb1ELi0EE13_S_start_freeE; - char *_ZNSt24__default_alloc_templateILb1ELi0EE11_S_end_freeE; - size_t _ZNSt24__default_alloc_templateILb1ELi0EE12_S_heap_sizeE; - - // Make the symbols possible to use... - FreeList* (&TheFreeList)[NFREE] = _ZNSt24__default_alloc_templateILb1ELi0EE12_S_free_listE; - char * &StartFree = _ZNSt24__default_alloc_templateILb1ELi0EE13_S_start_freeE; - char * &EndFree = _ZNSt24__default_alloc_templateILb1ELi0EE11_S_end_freeE; - size_t &HeapSize = _ZNSt24__default_alloc_templateILb1ELi0EE12_S_heap_sizeE; -} -#endif - -// getNumBytesToNotCount - This function is supposed to return the number of -// bytes that are to be considered not allocated, even though malloc thinks they -// are allocated. -// -static unsigned getNumBytesToNotCount() { -#ifdef HAVE_POOL - // If we have GCC 3.2.0, we can subtract off pool allocation bookkeeping info - - // Size of the free slab section... - unsigned FreePoolMem = (unsigned)(EndFree-StartFree); - - // Walk all of the free lists, adding memory to the free counter whenever we - // have a free bucket. - for (unsigned i = 0; i != NFREE; ++i) { - unsigned NumEntries = 0; - for (FreeList *FL = TheFreeList[i]; FL; ++NumEntries, FL = FL->Next) - /*empty*/ ; - -#if 0 - if (NumEntries) - std::cerr << " For Size[" << (i+1)*_ALIGN << "]: " << NumEntries - << " Free entries\n"; -#endif - FreePoolMem += NumEntries*(i+1)*_ALIGN; - } - return FreePoolMem; - -#else -#warning "Don't know how to avoid pool allocation accounting overhead for this" -#warning " compiler: Space usage numbers (with -time-passes) may be off!" - return 0; -#endif -}