Add a high precision timestamp to log entry

diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc
index 0b5bc757448d13b9978cdf38ead02d06bd36cce2..b64d416cfb3ff773565fd18794b01c66a31dd5f9 100644 (file)
--- a/pdns/pdns_recursor.cc
+++ b/pdns/pdns_recursor.cc
@@ -5392,7 +5392,20 @@ catch(...) {
    return 0;
 }
 
+//static std::string s_timestampFormat = "%m-%dT%H:%M:%S";
+static std::string s_timestampFormat = "%s";
 
+const char* toTimestampStringMilli(const struct timeval& tv, char *buf, size_t sz)
+{
+  struct tm tm;
+  size_t len = strftime(buf, sz, s_timestampFormat.c_str(), localtime_r(&tv.tv_sec, &tm));
+  if (len == 0) {
+    len = snprintf(buf, sz, "%lld", (long long) tv.tv_sec);
+  }
+
+  snprintf(buf + len, sz - len, ".%03ld", tv.tv_usec / 1000);
+  return buf;
+}
 
 static void loggerBackend(const Logging::Entry& entry) {
   static thread_local std::stringstream buf;
@@ -5406,7 +5419,8 @@ static void loggerBackend(const Logging::Entry& entry) {
   if (entry.name) {
     buf << " subsystem=" << std::quoted(entry.name.get());
   }
-
+  char timebuf[64];
+  buf << " ts=" << std::quoted(toTimestampStringMilli(entry.d_timestamp, timebuf, sizeof(timebuf)));
   for (auto const& v: entry.values) {
     buf << " ";
     buf << v.first << "=" << std::quoted(v.second);

diff --git a/pdns/recursordist/logging.cc b/pdns/recursordist/logging.cc
index f971f5687f7fd5b5e305dcdca15a31bddbf6fe8d..f9b5c58e5aea765617ff0ef8fda9a275937ed7f7 100644 (file)
--- a/pdns/recursordist/logging.cc
+++ b/pdns/recursordist/logging.cc
@@ -22,6 +22,7 @@
 
 #include "logging.hh"
 #include <string>
+#include "utility.hh"
 
 namespace Logging
 {
@@ -48,6 +49,7 @@ namespace Logging
     }
     Entry entry;
     entry.level = _level;
+    Utility::gettimeofday(&entry.d_timestamp);
     entry.name = _name;
     entry.message = msg;
     entry.error = err;

diff --git a/pdns/recursordist/logging.hh b/pdns/recursordist/logging.hh
index 69e5b18bed500ce1906ad904495c885ed02e9f27..3235a54957847319fc71ad99747131d630fdbaa0 100644 (file)
--- a/pdns/recursordist/logging.hh
+++ b/pdns/recursordist/logging.hh
@@ -40,6 +40,7 @@ namespace Logging {
     boost::optional<std::string> name;   // name parts joined with '.'
     std::string message;                 // message as send to log call
     boost::optional<std::string> error;  // error if .Error() was called
+    struct timeval d_timestamp;
     std::map<std::string, std::string> values;
   };