From: Otto Moerbeek Date: Fri, 17 May 2024 09:19:14 +0000 (+0200) Subject: Rate limit logging for a few cases (there could be more) X-Git-Tag: rec-5.1.0-beta1~31^2~7 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=f6fd9d7dcf657009c18b523228c0f8fddcdca157;p=thirdparty%2Fpdns.git Rate limit logging for a few cases (there could be more) --- diff --git a/pdns/recursordist/Makefile.am b/pdns/recursordist/Makefile.am index 63b821d4eb..a1a3ffc0b0 100644 --- a/pdns/recursordist/Makefile.am +++ b/pdns/recursordist/Makefile.am @@ -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 \ diff --git a/pdns/recursordist/pdns_recursor.cc b/pdns/recursordist/pdns_recursor.cc index 756ec5d046..ad3ad7ac61 100644 --- a/pdns/recursordist/pdns_recursor.cc +++ b/pdns/recursordist/pdns_recursor.cc @@ -31,6 +31,8 @@ #include "shuffle.hh" #include "validate-recursor.hh" +#include "ratelimitedlog.hh" + #ifdef HAVE_SYSTEMD #include #endif @@ -98,6 +100,8 @@ GlobalStateHolder g_dontThrottleNetmasks; GlobalStateHolder 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 index 0000000000..12005859aa --- /dev/null +++ b/pdns/recursordist/ratelimitedlog.hh @@ -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 + 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 + 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 + 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}; +}; +} diff --git a/pdns/recursordist/rec-main.cc b/pdns/recursordist/rec-main.cc index a3cc3f71f3..69306aa6c8 100644 --- a/pdns/recursordist/rec-main.cc +++ b/pdns/recursordist/rec-main.cc @@ -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> parseCPUMap(Logr::log_t log) { std::map> 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"); } } }