pEpLog() / pEpErr() - Add high-res timestamp

Add test_peplog.cc

test/Makefile

@@ -6,7 +6,7 @@ CXXFLAGS+=-I../
 
 .PHONY=all, test_adapter, test_adapter_cxx, test_library
 
-all: test_adapter test_adapter_cxx test_library
+all: test_adapter test_adapter_cxx test_library test_peplog
 
 test_adapter: test_adapter.cc ../libpEpAdapter.a
 
@@ -14,6 +14,9 @@ test_adapter_cxx: test_adapter_cxx.cc ../libpEpAdapter.a
 
 test_library: test_library.cc ../libpEpAdapter.a
 
+test_peplog: test_peplog.cc
+
+
 clean:	
 	rm -vf test_adapter
 	rm -rvf test_adapter.dSYM

test/test_peplog.cc

@@ -0,0 +1,16 @@
+// This file is under GNU General Public License 3.0
+// see LICENSE.txt
+
+#include "utils.hh"
+// Single threaded test of pEpLog() function.
+// check for uniformity of time
+
+int main()
+{
+    pEpLog("Test Starting... observe uniformity of timestamp.");
+    int nr_log_lines = 1000000;
+    for (int i; i < nr_log_lines; i++) {
+        pEpLog("log line nr: " << i);
+    }
+    return 0;
+}

utils.hh

@@ -1,12 +1,42 @@
 #pragma once
-
 #include <iostream>
 #include <thread>
+#include <sstream>
+#include <iomanip>
+
+// Returns a timestamp string featuring microseconds precision
+// Uses system clock, so time might not pass uniformly
+
+inline std::string timestamp_usec() {
+    std::ostringstream buffer;
+    std::chrono::system_clock::duration d = std::chrono::system_clock::now().time_since_epoch();
+
+    std::chrono::microseconds us = std::chrono::duration_cast<std::chrono::microseconds>(d);
+    std::chrono::seconds       s = std::chrono::duration_cast<std::chrono::seconds>     (d);
+
+    std::time_t t = s.count();
+    std::tm tm = *std::localtime(&t);
+
+    std::size_t fractional_seconds = us.count() % 1000000;
+    buffer << std::put_time(&tm, "%H%:%M:%S") << "." << fractional_seconds;
+
+    return buffer.str();
+}
+
+// pEpLog(msg) - logs to STDOUT
+// pEpErr(msg) - logs to STDERR
+//
+// Log format is:
+// TIMESTAMP.usecs THREAD-ID SRC_FILE_NAME::FUNCTION_NAME - msg
+//
+// example:
+// 21:06:04.214884 Thread:0x10f2ce5c0 test_peplog.cc::main - test run nr: 436744
+//
+// if -DNDEBUG=1 (for release builds), all pEpLog() calls will be optimized away.
 
 #ifdef NDEBUG
-    #define pEpLog(msg)  do{}while(0)
+#define pEpLog(msg) do{}while(0)
 #else
-    #define pEpLog(msg) do{std::cout << "Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)
+#define pEpLog(msg) do{ std::cout << timestamp_usec() << " Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)
 #endif
-
-#define pEpErr(msg) do{std::cerr << "Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)
+#define pEpErr(msg) do{ std::cout << timestamp_usec() << " Thread:" << std::this_thread::get_id() << ' ' <<__FILE__ << "::" << __FUNCTION__ << " - " << msg << '\n';} while(0)