From 9ba003feeae856c87cb5419b5ed055be9d80daa5 Mon Sep 17 00:00:00 2001
From: Otto <otto.moerbeek@open-xchange.com>
Date: Tue, 11 May 2021 16:35:27 +0200
Subject: [PATCH] Add a high precision timestamp to log entry

---
 pdns/pdns_recursor.cc        | 16 +++++++++++++++-
 pdns/recursordist/logging.cc |  2 ++
 pdns/recursordist/logging.hh |  1 +
 3 files changed, 18 insertions(+), 1 deletion(-)

diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc
index 0b5bc75744..b64d416cfb 100644
--- 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 f971f5687f..f9b5c58e5a 100644
--- 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 69e5b18bed..3235a54957 100644
--- 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;
   };
 
-- 
2.47.2