process review comments; move toTimestampStringMilli() to Logging nam…

…espace

pdns/logging.hh

@@ -100,6 +100,8 @@ struct is_toString_available<T, std::void_t<decltype(std::declval<T>().toString(
 {
 };
 
+const char* toTimestampStringMilli(const struct timeval& tval, std::array<char, 64>& buf, const std::string& format = "%s");
+
 template <typename T>
 struct Loggable : public Logr::Loggable
 {
@@ -206,9 +208,9 @@ private:
 
 extern std::shared_ptr<Logging::Logger> g_slog;
 
-// Prefer structured logging? Since 5.1.0, we always do. We keep a const, to allow for step-by-step
-// removal of old style logging code (for recursor-only code). Note that code shared with auth still uses
-// old-style, so the SLOG calls should remain for shared code.
+// Prefer structured logging? Since Recursor 5.1.0, we always do. We keep a const, to allow for
+// step-by-step removal of old style logging code (for recursor-only code). Note that code shared
+// with auth still uses old-style, so the SLOG calls should remain for shared code.
 constexpr bool g_slogStructured = true;
 
 // A helper macro to switch between old-style logging and new-style (structured logging)

pdns/recursordist/logging.cc

@@ -22,6 +22,7 @@
 
 #include "logging.hh"
 #include <string>
+#include <mutex>
 #include "utility.hh"
 
 namespace Logging
@@ -156,3 +157,23 @@ Logger::~Logger()
 };
 
 std::shared_ptr<Logging::Logger> g_slog{nullptr};
+
+const char* Logging::toTimestampStringMilli(const struct timeval& tval, std::array<char, 64>& buf, const std::string& format)
+{
+  size_t len = 0;
+  if (format != "%s") {
+    // strftime is not thread safe, it can access locale information
+    static std::mutex mutex;
+    auto lock = std::lock_guard(mutex);
+    struct tm theTime // clang-format insists on formatting it like this
+    {
+    };
+    len = strftime(buf.data(), buf.size(), format.c_str(), localtime_r(&tval.tv_sec, &theTime));
+  }
+  if (len == 0) {
+    len = snprintf(buf.data(), buf.size(), "%lld", static_cast<long long>(tval.tv_sec));
+  }
+
+  snprintf(&buf.at(len), buf.size() - len, ".%03ld", static_cast<long>(tval.tv_usec) / 1000);
+  return buf.data();
+}

pdns/recursordist/rec-main.cc

@@ -929,29 +929,6 @@ static void checkOrFixFDS(Logr::log_t log)
   }
 }
 
-// static std::string s_timestampFormat = "%m-%dT%H:%M:%S";
-static std::string s_timestampFormat = "%s";
-
-static const char* toTimestampStringMilli(const struct timeval& tval, std::array<char, 64>& buf)
-{
-  size_t len = 0;
-  if (s_timestampFormat != "%s") {
-    // strftime is not thread safe, it can access locale information
-    static std::mutex mutex;
-    auto lock = std::lock_guard(mutex);
-    struct tm theTime // clang-format insists on formatting it like this
-    {
-    };
-    len = strftime(buf.data(), buf.size(), s_timestampFormat.c_str(), localtime_r(&tval.tv_sec, &theTime));
-  }
-  if (len == 0) {
-    len = snprintf(buf.data(), buf.size(), "%lld", static_cast<long long>(tval.tv_sec));
-  }
-
-  snprintf(&buf.at(len), buf.size() - len, ".%03ld", static_cast<long>(tval.tv_usec) / 1000);
-  return buf.data();
-}
-
 #ifdef HAVE_SYSTEMD
 static void loggerSDBackend(const Logging::Entry& entry)
 {
@@ -998,7 +975,7 @@ static void loggerSDBackend(const Logging::Entry& entry)
     appendKeyAndVal("SUBSYSTEM", entry.name.get());
   }
   std::array<char, 64> timebuf{};
-  appendKeyAndVal("TIMESTAMP", toTimestampStringMilli(entry.d_timestamp, timebuf));
+  appendKeyAndVal("TIMESTAMP", Logging::toTimestampStringMilli(entry.d_timestamp, timebuf));
   for (const auto& value : entry.values) {
     if (value.first.at(0) == '_' || special.count(value.first) != 0) {
       string key{"PDNS"};
@@ -1040,7 +1017,7 @@ static void loggerJSONBackend(const Logging::Entry& entry)
     // Thread id filled in by backend, since the SL code does not know about RecursorThreads
     // We use the Recursor thread, other threads get id 0. May need to revisit.
     {"tid", std::to_string(RecThreadInfo::id())},
-    {"ts", toTimestampStringMilli(entry.d_timestamp, timebuf)},
+    {"ts", Logging::toTimestampStringMilli(entry.d_timestamp, timebuf)},
   };
 
   if (entry.error) {
@@ -1094,7 +1071,7 @@ static void loggerBackend(const Logging::Entry& entry)
   // We use the Recursor thread, other threads get id 0. May need to revisit.
   buf << " tid=" << std::quoted(std::to_string(RecThreadInfo::id()));
   std::array<char, 64> timebuf{};
-  buf << " ts=" << std::quoted(toTimestampStringMilli(entry.d_timestamp, timebuf));
+  buf << " ts=" << std::quoted(Logging::toTimestampStringMilli(entry.d_timestamp, timebuf));
   for (auto const& value : entry.values) {
     buf << " ";
     buf << value.first << "=" << std::quoted(value.second);

pdns/recursordist/rec_control.cc

@@ -262,13 +262,10 @@ static void recControlLoggerBackend(const Logging::Entry& entry)
   if (entry.d_priority != 0) {
     buf << " prio=" << std::quoted(Logr::Logger::toString(entry.d_priority));
   }
-#if 0
-  // Thread id filled in by backend, since the SL code does not know about RecursorThreads
-  // We use the Recursor thread, other threads get id 0. May need to revisit.
-  buf << " tid=" << std::quoted(std::to_string(RecThreadInfo::id()));
+
   std::array<char, 64> timebuf{};
-  buf << " ts=" << std::quoted(toTimestampStringMilli(entry.d_timestamp, timebuf));
-#endif
+  buf << " ts=" << std::quoted(Logging::toTimestampStringMilli(entry.d_timestamp, timebuf));
+
   for (auto const& value : entry.values) {
     buf << " ";
     buf << value.first << "=" << std::quoted(value.second);