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.

llvm-svn: 207385

2 files changed, 8 insertions, 4 deletions

diff --git a/llvm/lib/IR/LegacyPassManager.cpp b/llvm/lib/IR/LegacyPassManager.cpp
index 1ad04982d44..b6d75b483f8 100644
--- a/llvm/lib/IR/LegacyPassManager.cpp
+++ b/llvm/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 <algorithm>
@@ -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/llvm/lib/Support/Unix/TimeValue.inc b/llvm/lib/Support/Unix/TimeValue.inc
index 80532b0b952..58c7ba3094d 100644
--- a/llvm/lib/Support/Unix/TimeValue.inc
+++ b/llvm/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() {