From 7f1946408dd5ba7258542b1e1637308d7cd1cd69 Mon Sep 17 00:00:00 2001 From: Chandler Carruth Date: Sun, 27 Apr 2014 23:59:25 +0000 Subject: [PATCH] Teach the pass manager's execution dump to print the current time before each line. This is particularly nice for tracking which run of a particular pass over a particular function was slow. This also required making the TimeValue string much more useful. First, there is a standard format for writing out a date and time. Let's use that rather than strings that would have to be parsed. Second, actually output the nanosecond resolution that timevalue claims to have. This is proving useful working on PR19499, so I figured it would be generally useful to commit. git-svn-id: https://llvm.org/svn/llvm-project/llvm/trunk@207385 91177308-0d34-0410-b5e6-96231b3b80d8 --- lib/IR/LegacyPassManager.cpp | 4 +++- lib/Support/Unix/TimeValue.inc | 8 +++++--- 2 files changed, 8 insertions(+), 4 deletions(-) diff --git a/lib/IR/LegacyPassManager.cpp b/lib/IR/LegacyPassManager.cpp index 1ad04982d44..b6d75b483f8 100644 --- a/lib/IR/LegacyPassManager.cpp +++ b/lib/IR/LegacyPassManager.cpp @@ -22,6 +22,7 @@ #include "llvm/Support/ErrorHandling.h" #include "llvm/Support/ManagedStatic.h" #include "llvm/Support/Mutex.h" +#include "llvm/Support/TimeValue.h" #include "llvm/Support/Timer.h" #include "llvm/Support/raw_ostream.h" #include @@ -1158,7 +1159,8 @@ void PMDataManager::dumpPassInfo(Pass *P, enum PassDebuggingString S1, StringRef Msg) { if (PassDebugging < Executions) return; - dbgs() << (void*)this << std::string(getDepth()*2+1, ' '); + dbgs() << "[" << sys::TimeValue::now().str() << "] " << (void *)this + << std::string(getDepth() * 2 + 1, ' '); switch (S1) { case EXECUTION_MSG: dbgs() << "Executing Pass '" << P->getPassName(); diff --git a/lib/Support/Unix/TimeValue.inc b/lib/Support/Unix/TimeValue.inc index 80532b0b952..58c7ba3094d 100644 --- a/lib/Support/Unix/TimeValue.inc +++ b/lib/Support/Unix/TimeValue.inc @@ -26,9 +26,11 @@ std::string TimeValue::str() const { struct tm Storage; struct tm *LT = ::localtime_r(&OurTime, &Storage); assert(LT); - char Buffer[25]; - strftime(Buffer, 25, "%b %e %H:%M %Y", LT); - return std::string(Buffer); + char Buffer1[sizeof("YYYY-MM-DD HH:MM:SS")]; + strftime(Buffer1, sizeof(Buffer1), "%Y-%m-%d %H:%M:%S", LT); + char Buffer2[sizeof("YYYY-MM-DD HH:MM:SS.MMMUUUNNN")]; + snprintf(Buffer2, sizeof(Buffer2), "%s.%.9u", Buffer1, this->nanoseconds()); + return std::string(Buffer2); } TimeValue TimeValue::now() {