rec: add structured logging backend that uses JSON representation

diff --git a/.github/actions/spell-check/expect.txt b/.github/actions/spell-check/expect.txt
index addd80d075d1b4e3f9075765ca3c4eefa8f1c479..0b27c6a3cddc7482aea4275a9e839b052bd88335 100644 (file)
--- a/.github/actions/spell-check/expect.txt
+++ b/.github/actions/spell-check/expect.txt
@@ -1319,6 +1319,7 @@ Storesund
 stou
 strcasestr
 stringmatch
+structuredlogging
 stubquery
 stubresolver
 Stussy

diff --git a/pdns/recursordist/docs/appendices/structuredlogging.rst b/pdns/recursordist/docs/appendices/structuredlogging.rst
index d48366330bc6c0d9418653c94bd0d776b598179a..020ecf6eca3331f3fccc316de39626659cd71edc 100644 (file)
--- a/pdns/recursordist/docs/appendices/structuredlogging.rst
+++ b/pdns/recursordist/docs/appendices/structuredlogging.rst
@@ -2,10 +2,11 @@ Structured Logging Dictionary
 =============================
 
 This page describes the common entries of the Structured Logging component.
-Currently there are two possible values for :ref:`setting-structured-logging-backend`:
+Currently :ref:`setting-structured-logging-backend` can have these values:
 
 - The ``default`` text based backend
 - The ``systemd-journal`` backend
+- The ``json`` backend (added in version 5.1.0).
 
 The ``default`` backend
 -----------------------
@@ -100,3 +101,13 @@ To query the log, use a command similar to::
 
   # journalctl -r -n 1 -o json-pretty -u pdns-recursor.service
 
+The ``json`` backend
+--------------------
+The ``json`` structured logging backend has been added in version 5.1.0 and uses the same keys and values as the default backend.
+And example of a a log object::
+
+    {"level": "0", "limit": "10765", "msg": "Raised soft limit on number of filedescriptors to match max-mthreads and threads settings", "priority": "4", "subsystem": "config", "tid": "0", "ts": "1709285994.851"}
+
+All values are represented as strings.
+
+The JSON log objects are written to the standard error stream.

diff --git a/pdns/recursordist/rec-main.cc b/pdns/recursordist/rec-main.cc
index e652ddb0cc7ff970cffd51adf6712ec711fe39cf..7b334f01010d7e601af6067936ab9af1458630a5 100644 (file)
--- a/pdns/recursordist/rec-main.cc
+++ b/pdns/recursordist/rec-main.cc
@@ -40,6 +40,7 @@
 #include "logging.hh"
 #include "dnsseckeeper.hh"
 #include "settings/cxxsettings.hh"
+#include "json.hh"
 
 #ifdef NOD_ENABLED
 #include "nod.hh"
@@ -1022,6 +1023,49 @@ static void loggerSDBackend(const Logging::Entry& entry)
 }
 #endif
 
+static void loggerJSONBackend(const Logging::Entry& entry)
+{
+  // First map SL priority to syslog's Urgency
+  Logger::Urgency urg = entry.d_priority != 0 ? Logger::Urgency(entry.d_priority) : Logger::Info;
+  if (urg > s_logUrgency) {
+    // We do not log anything if the Urgency of the message is lower than the requested loglevel.
+    // Not that lower Urgency means higher number.
+    return;
+  }
+
+  std::array<char, 64> timebuf{};
+  json11::Json::object json = {
+    {"msg", entry.message},
+    {"level", std::to_string(entry.level)},
+    // 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)},
+  };
+
+  if (entry.error) {
+    json.emplace("error", entry.error.get());
+  }
+
+  if (entry.name) {
+    json.emplace("subsystem", entry.name.get());
+  }
+
+  if (entry.d_priority != 0) {
+    json.emplace("priority", std::to_string(entry.d_priority));
+  }
+
+  for (auto const& value : entry.values) {
+    json.emplace(value.first, value.second);
+  }
+
+  static thread_local std::string out;
+  out.clear();
+  json11::Json doc(std::move(json));
+  doc.dump(out);
+  cerr << out << endl;
+}
+
 static void loggerBackend(const Logging::Entry& entry)
 {
   static thread_local std::stringstream buf;
@@ -2986,6 +3030,31 @@ static void handleRuntimeDefaults(Logr::log_t log)
   }
 }
 
+static void setupLogging(const string& logname)
+{
+  if (logname == "systemd-journal") {
+#ifdef HAVE_SYSTEMD
+    if (int fileDesc = sd_journal_stream_fd("pdns-recusor", LOG_DEBUG, 0); fileDesc >= 0) {
+      g_slog = Logging::Logger::create(loggerSDBackend);
+      close(fileDesc);
+    }
+#endif
+    if (g_slog == nullptr) {
+      cerr << "Structured logging to systemd-journal requested but it is not available" << endl;
+    }
+  }
+  else if (logname == "json") {
+    g_slog = Logging::Logger::create(loggerJSONBackend);
+    if (g_slog == nullptr) {
+      cerr << "JSON logging to requested but it is not available" << endl;
+    }
+  }
+
+  if (g_slog == nullptr) {
+    g_slog = Logging::Logger::create(loggerBackend);
+  }
+}
+
 int main(int argc, char** argv)
 {
   g_argc = argc;
@@ -3056,21 +3125,7 @@ int main(int argc, char** argv)
       return 99;
     }
 
-    if (s_structured_logger_backend == "systemd-journal") {
-#ifdef HAVE_SYSTEMD
-      if (int fd = sd_journal_stream_fd("pdns-recusor", LOG_DEBUG, 0); fd >= 0) {
-        g_slog = Logging::Logger::create(loggerSDBackend);
-        close(fd);
-      }
-#endif
-      if (g_slog == nullptr) {
-        cerr << "Structured logging to systemd-journal requested but it is not available" << endl;
-      }
-    }
-
-    if (g_slog == nullptr) {
-      g_slog = Logging::Logger::create(loggerBackend);
-    }
+    setupLogging(s_structured_logger_backend);
 
     // Missing: a mechanism to call setVerbosity(x)
     auto startupLog = g_slog->withName("config");

diff --git a/pdns/recursordist/settings/table.py b/pdns/recursordist/settings/table.py
index 5028b4c5f482f9754a851c51b5bda3a6f0d580a3..8f92f630ad7d13532a3cf84b54e8273e890f3aa8 100644 (file)
--- a/pdns/recursordist/settings/table.py
+++ b/pdns/recursordist/settings/table.py
@@ -2670,8 +2670,12 @@ Available backends are:
 - ``default``: use the traditional logging system to output structured logging information.
 - ``systemd-journal``: use systemd-journal.
   When using this backend, provide ``-o verbose`` or simular output option to ``journalctl`` to view the full information.
+- ``json``: JSON objects are written to the standard error stream
+
+See :doc:`appendices/structuredlogging` for more details.
  ''',
-    'versionadded': '4.8.0'
+        'versionadded': '4.8.0',
+        'versionchanged': ('5.1.0', 'The JSON backend was added')
     },
     {
         'name' : 'tcp_fast_open',