Add timestamps to logger

Author: hq6

src/Logger.cc

@@ -15,23 +15,60 @@
 
 #include "Logger.h"
 #include <execinfo.h>
+#include "PerfUtils/Cycles.h"
+
+using PerfUtils::Cycles;
 
 namespace Arachne {
 
 extern FILE* errorStream;
-LogLevel Logger::displayMinLevel = WARNING;
+LogLevel Logger::displayMinLevel = DEBUG;
 std::mutex Logger::mutex;
+PerfUtils::Initialize Logger::_(Logger::init);
+uint64_t Logger::startingTsc;
+
+/**
+  * Friendly names for each #LogLevel value.
+  * Keep this in sync with the LogLevel enum.
+  */
+static const char* logLevelNames[] = {"VERBOSE", "DEBUG", "NOTICE", "WARNING",
+                                      "ERROR", "SILENT"};
+
 
+void
+Logger::init()
+{
+startingTsc = Cycles::rdtsc();	
+}
 void
 Logger::log(LogLevel level, const char* fmt, ...) {
     if (level < displayMinLevel) {
         return;
     }
 
-    Lock lock(mutex);
+    // First format the message; timestamps are in seconds since the first log
+#define MAX_MESSAGE_CHARS 2000
+    // Construct a message on the stack and then print it out with the lock
+    char buffer[MAX_MESSAGE_CHARS];
+    int spaceLeft = MAX_MESSAGE_CHARS;
+    int charsWritten = 0;
+    int actual;
+    double time = Cycles::toSeconds(Cycles::rdtsc() - startingTsc);
+
+    // Add a header including rdtsc time and location in the file.
+    actual = snprintf(buffer + charsWritten, spaceLeft,
+                      "%.10lf: %s: ", time, logLevelNames[level]);
+    charsWritten += actual;
+    spaceLeft -= actual;
+
+    // Add the intended message
     va_list args;
     va_start(args, fmt);
-    vfprintf(errorStream, fmt, args);
+    actual = vsnprintf(buffer + charsWritten, spaceLeft, fmt, args);
+    va_end(args);
+
+    Lock lock(mutex);
+    fprintf(errorStream, "%s\n", buffer);
     fflush(errorStream);
     va_end(args);
 }

src/Logger.h

@@ -19,6 +19,7 @@
 #include <stdarg.h>
 #include <stdint.h>
 #include <mutex>
+#include <PerfUtils/Initialize.h>
 
 #define ARACHNE_LOG Logger::log
 #define ARACHNE_BACKTRACE Logger::logBacktrace
@@ -52,12 +53,17 @@ class Logger {
     static void logBacktrace(LogLevel level);
 
   private:
+    static void init(); 
     // The minimum severity level to print.
     static LogLevel displayMinLevel;
 
     // Lock around printing since Arachne is multithreaded.
     typedef std::unique_lock<std::mutex> Lock;
     static std::mutex mutex;
+
+    // Initialize
+    static PerfUtils::Initialize _;
+    static uint64_t startingTsc;
 };
 
 }  // namespace Arachne