]> git.ipfire.org Git - thirdparty/pdns.git/commitdiff
Rate limit logging for a few cases (there could be more)
authorOtto Moerbeek <otto.moerbeek@open-xchange.com>
Fri, 17 May 2024 09:19:14 +0000 (11:19 +0200)
committerOtto Moerbeek <otto.moerbeek@open-xchange.com>
Tue, 21 May 2024 13:47:33 +0000 (15:47 +0200)
pdns/recursordist/Makefile.am
pdns/recursordist/pdns_recursor.cc
pdns/recursordist/ratelimitedlog.hh [new file with mode: 0644]
pdns/recursordist/rec-main.cc

index 63b821d4eb253e1004805726cbbbf3e9f6fd1d7f..a1a3ffc0b0d871aa6af4e0ee3d89ea809fb4e447 100644 (file)
@@ -169,6 +169,7 @@ pdns_recursor_SOURCES = \
        pubsuffixloader.cc \
        qtype.hh qtype.cc \
        query-local-address.hh query-local-address.cc \
+       ratelimitedlog.hh \
        rcpgenerator.cc rcpgenerator.hh \
        rec-carbon.cc \
        rec-eventtrace.cc rec-eventtrace.hh \
@@ -307,6 +308,7 @@ testrunner_SOURCES = \
        pollmplexer.cc \
        qtype.cc qtype.hh \
        query-local-address.hh query-local-address.cc \
+       ratelimitedlog.hh \
        rcpgenerator.cc \
        rec-eventtrace.cc rec-eventtrace.hh \
        rec-responsestats.hh rec-responsestats.cc \
index 756ec5d0463e031d894830990069b689fef42fb5..ad3ad7ac61430264c788a46fd3d0d441c3a691ba 100644 (file)
@@ -31,6 +31,8 @@
 #include "shuffle.hh"
 #include "validate-recursor.hh"
 
+#include "ratelimitedlog.hh"
+
 #ifdef HAVE_SYSTEMD
 #include <systemd/sd-daemon.h>
 #endif
@@ -98,6 +100,8 @@ GlobalStateHolder<NetmaskGroup> g_dontThrottleNetmasks;
 GlobalStateHolder<SuffixMatchNode> g_DoTToAuthNames;
 uint64_t g_latencyStatSize;
 
+static pdns::RateLimitedLog s_rateLimitedLogger;
+
 LWResult::Result UDPClientSocks::getSocket(const ComboAddress& toaddr, int* fileDesc)
 {
   *fileDesc = makeClientSocket(toaddr.sin4.sin_family);
@@ -2229,19 +2233,13 @@ static string* doProcessUDPQuestion(const std::string& question, const ComboAddr
               eventTrace.add(RecEventTrace::LuaGetTag, ctag, false);
             }
           }
-          catch (const std::exception& e) {
-            if (g_logCommonErrors) {
-              SLOG(g_log << Logger::Warning << "Error parsing a query packet qname='" << qname << "' for tag determination, setting tag=0: " << e.what() << endl,
-                   g_slogudpin->error(Logr::Warning, e.what(), "Error parsing a query packet for tag determination, setting tag=0", "qname", Logging::Loggable(qname), "remote", Logging::Loggable(fromaddr), "exception", Logging::Loggable("std;:exception")));
-            }
+          catch (const std::exception& stdException) {
+            s_rateLimitedLogger.log(g_slogudpin, "Error parsing a query packet for tag determination", stdException, "qname", Logging::Loggable(qname), "remote", Logging::Loggable(fromaddr));
           }
         }
       }
-      catch (const std::exception& e) {
-        if (g_logCommonErrors) {
-          SLOG(g_log << Logger::Warning << "Error parsing a query packet for tag determination, setting tag=0: " << e.what() << endl,
-               g_slogudpin->error(Logr::Warning, e.what(), "Error parsing a query packet for tag determination, setting tag=0", "remote", Logging::Loggable(fromaddr), "exception", Logging::Loggable("std;:exception")));
-        }
+      catch (const std::exception& stdException) {
+        s_rateLimitedLogger.log(g_slogudpin, "Error parsing a query packet for tag determination, setting tag=0", stdException);
       }
     }
 
diff --git a/pdns/recursordist/ratelimitedlog.hh b/pdns/recursordist/ratelimitedlog.hh
new file mode 100644 (file)
index 0000000..1200585
--- /dev/null
@@ -0,0 +1,95 @@
+/*
+ * This file is part of PowerDNS or dnsdist.
+ * Copyright -- PowerDNS.COM B.V. and its contributors
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of version 2 of the GNU General Public License as
+ * published by the Free Software Foundation.
+ *
+ * In addition, for the avoidance of any doubt, permission is granted to
+ * link this program with OpenSSL and to (re)distribute the binaries
+ * produced as the result of such linking.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software
+ * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
+ */
+#pragma once
+
+#include "logger.hh"
+#include "logging.hh"
+
+namespace pdns
+{
+class RateLimitedLog
+{
+public:
+  RateLimitedLog(time_t arg = 60) :
+    d_period(arg) {}
+
+  [[nodiscard]] uint32_t getCount() const
+  {
+    return d_count;
+  }
+
+  template <typename... Args>
+  void log(Logr::log_t slog, const string& msg, const Args&... args)
+  {
+    uint32_t count{};
+    if (doLog(count)) {
+      SLOG(g_log << Logger::Error << msg << " created an exception" << endl,
+           slog->info(Logr::Error, msg + " created an exception",
+                      "ratelimitingSkipped", Logging::Loggable(count),
+                      "exception", Logging::Loggable("other"), args...));
+    };
+  }
+  template <typename... Args>
+  void log(Logr::log_t slog, const string& msg, const std::exception& stdException, const Args&... args)
+  {
+    uint32_t count{};
+    if (doLog(count)) {
+      SLOG(g_log << Logger::Error << msg << " created an exception: " << except.what() << endl,
+           slog->error(Logr::Error, stdException.what(), msg + " created an exception",
+                       "ratelimitingSkipped", Logging::Loggable(count),
+                       "exception", Logging::Loggable("std::exception"), args...));
+    }
+  }
+
+  template <typename... Args>
+  void log(Logr::log_t slog, const string& msg, const PDNSException& pdnsException, const Args&... args)
+  {
+    uint32_t count{};
+    if (doLog(count)) {
+      SLOG(g_log << Logger::Error << msg << " created an PDNSException: " << except.reason << endl,
+           slog->error(Logr::Error, pdnsException.reason, msg + " created an exception",
+                       "ratelimitingSkipped", Logging::Loggable(count),
+                       "exception", Logging::Loggable("PDNSException"), args...));
+    }
+  }
+
+private:
+  [[nodiscard]] bool doLog(uint32_t& count)
+  {
+    std::lock_guard lock(d_mutex);
+    time_t now = time(nullptr);
+    if (d_last + d_period < now) {
+      d_last = now;
+      count = d_count;
+      d_count = 0;
+      return true;
+    }
+    count = d_count;
+    d_count++;
+    return false;
+  }
+  std::mutex d_mutex;
+  time_t d_last{0};
+  const time_t d_period;
+  uint32_t d_count{0};
+};
+}
index a3cc3f71f314597d52ba37961bd357b01d34492f..69306aa6c823ce097b467642a1611b8378575f8a 100644 (file)
@@ -43,6 +43,7 @@
 #include "json.hh"
 #include "rec-system-resolve.hh"
 #include "root-dnssec.hh"
+#include "ratelimitedlog.hh"
 
 #ifdef NOD_ENABLED
 #include "nod.hh"
@@ -141,6 +142,8 @@ unsigned int RecThreadInfo::s_numUDPWorkerThreads;
 unsigned int RecThreadInfo::s_numTCPWorkerThreads;
 thread_local unsigned int RecThreadInfo::t_id;
 
+static pdns::RateLimitedLog s_rateLimitedLogger;
+
 static std::map<unsigned int, std::set<int>> parseCPUMap(Logr::log_t log)
 {
   std::map<unsigned int, std::set<int>> result;
@@ -942,8 +945,8 @@ static void checkLinuxMapCountLimits([[maybe_unused]] Logr::log_t log)
     // Also add 2 for handler and task threads.
     auto mapsNeeded = 4ULL * g_maxMThreads * (RecThreadInfo::numTCPWorkers() + RecThreadInfo::numUDPWorkers() + 2);
     if (lim < mapsNeeded) {
-      SLOG(g_log << Logger::Error << "sysctl kern.max_map_count= <" << mapsNeeded << ", this may cause 'bad_alloc' exceptions" << endl,
-           log->info(Logr::Error, "sysctl kern.max_map_count < mapsNeeded, this may cause 'bad_alloc' exceptions",
+      SLOG(g_log << Logger::Error << "sysctl vm.max_map_count= <" << mapsNeeded << ", this may cause 'bad_alloc' exceptions" << endl,
+           log->info(Logr::Error, "sysctl vm.max_map_count < mapsNeeded, this may cause 'bad_alloc' exceptions",
                      "kern.max_map_count", Logging::Loggable(lim), "mapsNeeded", Logging::Loggable(mapsNeeded)));
     }
   }
@@ -2343,17 +2346,14 @@ static void handlePipeRequest(int fileDesc, FDMultiplexer::funcparam_t& /* var *
   try {
     resp = tmsg->func();
   }
-  catch (const PDNSException& e) {
-    SLOG(g_log << Logger::Error << "PIPE function we executed created PDNS exception: " << e.reason << endl, // but what if they wanted an answer.. we send 0
-         g_slog->withName("runtime")->error(Logr::Error, e.reason, "PIPE function we executed created exception", "exception", Logging::Loggable("PDNSException")));
+  catch (const PDNSException& pdnsException) {
+    s_rateLimitedLogger.log(g_slog->withName("runtime"), "PIPE function", pdnsException);
   }
-  catch (const std::exception& e) {
-    SLOG(g_log << Logger::Error << "PIPE function we executed created exception: " << e.what() << endl, // but what if they wanted an answer.. we send 0
-         g_slog->withName("runtime")->error(Logr::Error, e.what(), "PIPE function we executed created exception", "exception", Logging::Loggable("std::exception")));
+  catch (const std::exception& stdException) {
+    s_rateLimitedLogger.log(g_slog->withName("runtime"), "PIPE function", stdException);
   }
   catch (...) {
-    SLOG(g_log << Logger::Error << "PIPE function we executed created another exception" << endl, // but what if they wanted an answer.. we send 0
-         g_slog->withName("runtime")->info(Logr::Error, "PIPE function we executed created another exception"));
+    s_rateLimitedLogger.log(g_slog->withName("runtime"), "PIPE function");
   }
   if (tmsg->wantAnswer) {
     if (write(RecThreadInfo::self().getPipes().writeFromThread, &resp, sizeof(resp)) != sizeof(resp)) {
@@ -2766,17 +2766,14 @@ static void recLoop()
 
       runTCPMaintenance(threadInfo, listenOnTCP, maxTcpClients);
     }
-    catch (const PDNSException& ae) {
-      SLOG(g_log << Logger::Error << "PDNSException in recLoop: " << ae.reason << endl,
-           g_slog->withName("runtime")->error(Logr::Error, ae.reason, "Exception in recLoop", "exception", Logging::Loggable("PDNSException")));
+    catch (const PDNSException& pdnsException) {
+      s_rateLimitedLogger.log(g_slog->withName("runtime"), "recLoop", pdnsException);
     }
-    catch (const std::exception& e) {
-      SLOG(g_log << Logger::Error << "Exception in recLoop: " << e.what() << endl,
-           g_slog->withName("runtime")->error(Logr::Error, e.what(), "Exception in recLoop", "exception", Logging::Loggable("std::exception")));
+    catch (const std::exception& stdException) {
+      s_rateLimitedLogger.log(g_slog->withName("runtime"), "recLoop", stdException);
     }
     catch (...) {
-      SLOG(g_log << Logger::Error << "Any other exception in recLoop: " << endl,
-           g_slog->withName("runtime")->info(Logr::Error, "Exception in recLoop"));
+      s_rateLimitedLogger.log(g_slog->withName("runtime"), "recLoop");
     }
   }
 }