From: Otto Moerbeek Date: Wed, 4 May 2022 08:25:49 +0000 (+0200) Subject: Reorg to be able to use structured logging in shared files. X-Git-Tag: auth-4.8.0-alpha0~95^2~10 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=ebaffe64bf9ba0b57f7f93b43801125f5ec4b47b;p=thirdparty%2Fpdns.git Reorg to be able to use structured logging in shared files. Using arguments.cc as a test-case. --- diff --git a/pdns/Makefile.am b/pdns/Makefile.am index 3bb3bf077f..3cda451347 100644 --- a/pdns/Makefile.am +++ b/pdns/Makefile.am @@ -234,6 +234,7 @@ pdns_server_SOURCES = \ json.cc json.hh \ lock.hh \ logger.cc logger.hh \ + logging.hh \ lua-auth4.cc lua-auth4.hh \ lua-base4.cc lua-base4.hh \ mastercommunicator.cc \ diff --git a/pdns/arguments.cc b/pdns/arguments.cc index 4ece63184d..b6769ed046 100644 --- a/pdns/arguments.cc +++ b/pdns/arguments.cc @@ -358,11 +358,12 @@ static const map deprecateList = { { "snmp-master-socket", "snmp-daemon-socket" } }; -static void warnIfDeprecated(const string& var) +void ArgvMap::warnIfDeprecated(const string& var) { const auto msg = deprecateList.find(var); if (msg != deprecateList.end()) { - g_log << Logger::Warning << "'" << var << "' is deprecated and will be removed in a future release, use '" << msg->second << "' instead" << endl; + SLOG(g_log << Logger::Warning << "'" << var << "' is deprecated and will be removed in a future release, use '" << msg->second << "' instead" << endl, + d_log->info(Logr::Warning, "Option is deprecated and will be removed in a future release", "deprecatedName", Logging::Loggable(var), "name", Logging::Loggable(msg->second))); } } @@ -399,7 +400,9 @@ void ArgvMap::parseOne(const string &arg, const string &parseOnly, bool lax) boost::trim(var); if(var!="" && (parseOnly.empty() || var==parseOnly)) { - warnIfDeprecated(var); + if (!lax) { + warnIfDeprecated(var); + } pos=val.find_first_not_of(" \t"); // strip leading whitespace if(pos && pos!=string::npos) val=val.substr(pos); @@ -429,7 +432,8 @@ void ArgvMap::parseOne(const string &arg, const string &parseOnly, bool lax) stringtok(parts, d_params["ignore-unknown-settings"], " ,\t\n\r"); if (find(parts.begin(), parts.end(), var) != parts.end()) { d_unknownParams[var] = val; - g_log<info(Logr::Warning, "Ignoring unknown setting as requested", "name", Logging::Loggable(var))); return; } @@ -525,7 +529,8 @@ bool ArgvMap::file(const char *fname, bool lax, bool included) set("include-dir","Directory to include configuration files from"); if(!parseFile(fname, "", lax)) { - g_log << Logger::Warning << "Unable to open " << fname << std::endl; + SLOG(g_log << Logger::Warning << "Unable to open " << fname << std::endl, + d_log->error(Logr::Warning, "Unable to open", "name", Logging::Loggable(fname))); return false; } @@ -535,7 +540,8 @@ bool ArgvMap::file(const char *fname, bool lax, bool included) gatherIncludes(extraConfigs); for(const std::string& fn : extraConfigs) { if (!file(fn.c_str(), lax, true)) { - g_log << Logger::Error << fn << " could not be parsed" << std::endl; + SLOG(g_log << Logger::Error << fn << " could not be parsed" << std::endl, + d_log->info(Logr::Error, "Could not be parsed", "name", Logging::Loggable(fn))); throw ArgException(fn + " could not be parsed"); } } @@ -553,7 +559,8 @@ void ArgvMap::gatherIncludes(std::vector &extraConfigs) { if (!(dir = opendir(d_params["include-dir"].c_str()))) { int err = errno; string msg = d_params["include-dir"] + " is not accessible: " + strerror(err); - g_log << Logger::Error << msg << std::endl; + SLOG(g_log << Logger::Error << msg << std::endl, + d_log->error(Logr::Error, err, "Directory is not accessible", "name", Logging::Loggable(d_params["include-dir"]))); throw ArgException(msg); } @@ -568,7 +575,8 @@ void ArgvMap::gatherIncludes(std::vector &extraConfigs) { struct stat st; if (stat(name.c_str(), &st) || !S_ISREG(st.st_mode)) { string msg = name + " is not a regular file"; - g_log << Logger::Error << msg << std::endl; + SLOG(g_log << Logger::Error << msg << std::endl, + d_log->info(Logr::Error, "Is not a regular file", "name", Logging::Loggable(name))); closedir(dir); throw ArgException(msg); } diff --git a/pdns/arguments.hh b/pdns/arguments.hh index 696f3ffa92..96b562580c 100644 --- a/pdns/arguments.hh +++ b/pdns/arguments.hh @@ -33,6 +33,7 @@ #include #include "namespaces.hh" +#include "logging.hh" typedef PDNSException ArgException; @@ -76,6 +77,9 @@ class ArgvMap { public: ArgvMap(); +#ifdef RECURSOR + std::shared_ptr d_log; +#endif void parse(int &argc, char **argv, bool lax=false); //!< use this to parse from argc and argv void laxParse(int &argc, char **argv) //!< use this to parse from argc and argv { @@ -119,6 +123,7 @@ public: const vector&getCommands(); void gatherIncludes(std::vector &extraConfigs); private: + void warnIfDeprecated(const string& var); void parseOne(const string &unparsed, const string &parseOnly="", bool lax=false); const string formatOne(bool running, bool full, const string &var, const string &help, const string& theDefault, const string& value); map d_params; diff --git a/pdns/logging.hh b/pdns/logging.hh new file mode 100644 index 0000000000..e95535b8c5 --- /dev/null +++ b/pdns/logging.hh @@ -0,0 +1,148 @@ +/* + * 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 "config.h" + +#ifdef RECURSOR + +#include +#include +#include +#include +#include + +#include "logr.hh" +#include "dnsname.hh" +#include "iputils.hh" + +namespace Logging +{ + +struct Entry +{ + boost::optional name; // name parts joined with '.' + std::string message; // message as send to log call + boost::optional error; // error if .Error() was called + struct timeval d_timestamp; // time of entry generation + std::map values; // key-value pairs + size_t level; // level at which this was logged + Logr::Priority d_priority; // (syslog) priority) +}; + +template +struct Loggable : public Logr::Loggable +{ + const T& _t; + Loggable(const T& v) : + _t(v) + { + } + std::string to_string() const + { + std::ostringstream oss; + oss << _t; + return oss.str(); + } +}; +template <> +std::string Loggable::to_string() const; +template <> +std::string Loggable::to_string() const; +template <> +std::string Loggable::to_string() const; + +// Loggable::Loggable(const std::string& v): _t(v) {} + +typedef void (*EntryLogger)(const Entry&); + +class Logger : public Logr::Logger, public std::enable_shared_from_this +{ +public: + bool enabled(Logr::Priority) const override; + + void info(const std::string& msg) const override; + void info(Logr::Priority, const std::string& msg) const override; + void error(int err, const std::string& msg) const override; + void error(const std::string& err, const std::string& msg) const override; + void error(Logr::Priority, int err, const std::string& msg) const override; + void error(Logr::Priority, const std::string& err, const std::string& msg) const override; + + std::shared_ptr v(size_t level) const override; + std::shared_ptr withValues(const std::map& values) const override; + virtual std::shared_ptr withName(const std::string& name) const override; + + static std::shared_ptr create(EntryLogger callback); + static std::shared_ptr create(EntryLogger callback, const std::string& name); + + Logger(EntryLogger callback); + Logger(EntryLogger callback, boost::optional name); + Logger(std::shared_ptr parent, boost::optional name, size_t verbosity, size_t lvl, EntryLogger callback); + virtual ~Logger(); + + size_t getVerbosity() const; + void setVerbosity(size_t verbosity); + +private: + void logMessage(const std::string& msg, boost::optional err) const; + void logMessage(const std::string& msg, Logr::Priority p, boost::optional err) const; + std::shared_ptr getptr() const; + + std::shared_ptr _parent{nullptr}; + EntryLogger _callback; + boost::optional _name; + std::map _values; + // current Logger's level. the higher the more verbose. + size_t _level{0}; + // verbosity settings. messages with level higher's than verbosity won't appear + size_t _verbosity{0}; +}; +} + +extern std::shared_ptr g_slog; + +// Prefer structured logging? +extern bool g_slogStructured; + +// A helper macro to switch between old-style logging and new-style (structured logging) +// A typical use: +// +// SLOG(g_log<error("No such file", "Unable to parse configuration file", "config_file", Logging::Loggable(configname)); +// +#define SLOG(oldStyle, slogCall) \ + do { \ + if (g_slogStructured) { \ + slogCall; \ + } \ + else { \ + oldStyle; \ + } \ + } while (0); + +#else // No structured logging (e.g. auth) +#define SLOG(oldStyle, slogCall) \ + do { \ + oldStyle; \ + } while (0); +#endif diff --git a/pdns/rec_control.cc b/pdns/rec_control.cc index 2cbd70bc5a..386a695898 100644 --- a/pdns/rec_control.cc +++ b/pdns/rec_control.cc @@ -85,8 +85,10 @@ static void initArguments(int argc, char** argv) } } + int main(int argc, char** argv) { + g_slogStructured = false; const set fileCommands = { "dump-cache", "dump-edns", diff --git a/pdns/recursordist/Makefile.am b/pdns/recursordist/Makefile.am index ee57d9c9ef..dcf4fb5563 100644 --- a/pdns/recursordist/Makefile.am +++ b/pdns/recursordist/Makefile.am @@ -478,6 +478,7 @@ rec_control_SOURCES = \ dnslabeltext.cc \ dnsname.hh dnsname.cc \ logger.cc \ + logging.cc \ misc.cc \ qtype.cc \ rec_channel.cc rec_channel.hh \ diff --git a/pdns/recursordist/logging.hh b/pdns/recursordist/logging.hh deleted file mode 100644 index fb03332d3a..0000000000 --- a/pdns/recursordist/logging.hh +++ /dev/null @@ -1,137 +0,0 @@ -/* - * 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 -#include -#include -#include -#include - -#include "logr.hh" -#include "dnsname.hh" -#include "iputils.hh" - -namespace Logging -{ - -struct Entry -{ - boost::optional name; // name parts joined with '.' - std::string message; // message as send to log call - boost::optional error; // error if .Error() was called - struct timeval d_timestamp; // time of entry generation - std::map values; // key-value pairs - size_t level; // level at which this was logged - Logr::Priority d_priority; // (syslog) priority) -}; - -template -struct Loggable : public Logr::Loggable -{ - const T& _t; - Loggable(const T& v) : - _t(v) - { - } - std::string to_string() const - { - std::ostringstream oss; - oss << _t; - return oss.str(); - } -}; -template <> -std::string Loggable::to_string() const; -template <> -std::string Loggable::to_string() const; -template <> -std::string Loggable::to_string() const; - -// Loggable::Loggable(const std::string& v): _t(v) {} - -typedef void (*EntryLogger)(const Entry&); - -class Logger : public Logr::Logger, public std::enable_shared_from_this -{ -public: - bool enabled(Logr::Priority) const override; - - void info(const std::string& msg) const override; - void info(Logr::Priority, const std::string& msg) const override; - void error(int err, const std::string& msg) const override; - void error(const std::string& err, const std::string& msg) const override; - void error(Logr::Priority, int err, const std::string& msg) const override; - void error(Logr::Priority, const std::string& err, const std::string& msg) const override; - - std::shared_ptr v(size_t level) const override; - std::shared_ptr withValues(const std::map& values) const override; - virtual std::shared_ptr withName(const std::string& name) const override; - - static std::shared_ptr create(EntryLogger callback); - static std::shared_ptr create(EntryLogger callback, const std::string& name); - - Logger(EntryLogger callback); - Logger(EntryLogger callback, boost::optional name); - Logger(std::shared_ptr parent, boost::optional name, size_t verbosity, size_t lvl, EntryLogger callback); - virtual ~Logger(); - - size_t getVerbosity() const; - void setVerbosity(size_t verbosity); - -private: - void logMessage(const std::string& msg, boost::optional err) const; - void logMessage(const std::string& msg, Logr::Priority p, boost::optional err) const; - std::shared_ptr getptr() const; - - std::shared_ptr _parent{nullptr}; - EntryLogger _callback; - boost::optional _name; - std::map _values; - // current Logger's level. the higher the more verbose. - size_t _level{0}; - // verbosity settings. messages with level higher's than verbosity won't appear - size_t _verbosity{0}; -}; -} - -extern std::shared_ptr g_slog; - -// Prefer structured logging? -extern bool g_slogStructured; - -// A helper macro to switch between old-style logging and new-style (structured logging) -// A typical use: -// -// SLOG(g_log<error("No such file", "Unable to parse configuration file", "config_file", Logging::Loggable(configname)); -// -#define SLOG(oldStyle, slogCall) \ - do { \ - if (g_slogStructured) { \ - slogCall; \ - } \ - else { \ - oldStyle; \ - } \ - } while (0); diff --git a/pdns/recursordist/logging.hh b/pdns/recursordist/logging.hh new file mode 120000 index 0000000000..020d82c1ef --- /dev/null +++ b/pdns/recursordist/logging.hh @@ -0,0 +1 @@ +../logging.hh \ No newline at end of file diff --git a/pdns/recursordist/logr.hh b/pdns/recursordist/logr.hh index 22a0a6f37f..f1ad0931c9 100644 --- a/pdns/recursordist/logr.hh +++ b/pdns/recursordist/logr.hh @@ -24,6 +24,7 @@ #include #include +#include // Minimal logging API based on https://github.com/go-logr/logr diff --git a/pdns/recursordist/rec-main.cc b/pdns/recursordist/rec-main.cc index 3b7805774c..6a0228eca2 100644 --- a/pdns/recursordist/rec-main.cc +++ b/pdns/recursordist/rec-main.cc @@ -858,6 +858,7 @@ static void loggerBackend(const Logging::Entry& entry) buf << " "; buf << v.first << "=" << std::quoted(v.second); } + cerr << entry.d_priority << endl; Logger::Urgency u = entry.d_priority ? Logger::Urgency(entry.d_priority) : Logger::Info; g_log << u << buf.str() << endl; } @@ -1164,8 +1165,6 @@ template ThreadTimes broadcastAccFunction(const std::function& f static int serviceMain(int argc, char* argv[]) { - g_slogStructured = ::arg().mustDo("structured-logging"); - g_log.setName(g_programname); g_log.disableSyslog(::arg().mustDo("disable-syslog")); g_log.setTimestamps(::arg().mustDo("log-timestamp")); @@ -2561,6 +2560,25 @@ int main(int argc, char** argv) showBuildConfiguration(); exit(0); } + if (::arg().mustDo("help")) { + cout << "syntax:" << endl + << endl; + cout << ::arg().helpstring(::arg()["help"]) << endl; + exit(0); + } + + // Pick up options given on command line to setup logging asap. + g_quiet = ::arg().mustDo("quiet"); + Logger::Urgency logUrgency = (Logger::Urgency)::arg().asNum("loglevel"); + g_slogStructured = ::arg().mustDo("structured-logging"); + + if (logUrgency < Logger::Error) + logUrgency = Logger::Error; + if (!g_quiet && logUrgency < Logger::Info) { // Logger::Info=6, Logger::Debug=7 + logUrgency = Logger::Info; // if you do --quiet=no, you need Info to also see the query log + } + g_log.setLoglevel(logUrgency); + g_log.toConsole(logUrgency); string configname = ::arg()["config-dir"] + "/recursor.conf"; if (::arg()["config-name"] != "") { @@ -2593,15 +2611,31 @@ int main(int argc, char** argv) } g_slog = Logging::Logger::create(loggerBackend); + // Missing: a mechanism to call setVerbosity(x) auto startupLog = g_slog->withName("startup"); + ::arg().d_log = startupLog; if (!::arg().file(configname.c_str())) { SLOG(g_log << Logger::Warning << "Unable to parse configuration file '" << configname << "'" << endl, startupLog->error("No such file", "Unable to parse configuration file", "config_file", Logging::Loggable(configname))); } + // Reparse, now with config file as well ::arg().parse(argc, argv); + g_quiet = ::arg().mustDo("quiet"); + logUrgency = (Logger::Urgency)::arg().asNum("loglevel"); + g_slogStructured = ::arg().mustDo("structured-logging"); + + + if (logUrgency < Logger::Error) + logUrgency = Logger::Error; + if (!g_quiet && logUrgency < Logger::Info) { // Logger::Info=6, Logger::Debug=7 + logUrgency = Logger::Info; // if you do --quiet=no, you need Info to also see the query log + } + g_log.setLoglevel(logUrgency); + g_log.toConsole(logUrgency); + if (!::arg()["chroot"].empty() && !::arg()["api-config-dir"].empty()) { SLOG(g_log << Logger::Error << "Using chroot and enabling the API is not possible" << endl, startupLog->info("Cannot use chroot and enable the API at the same time")); @@ -2633,26 +2667,9 @@ int main(int argc, char** argv) ::arg().set("distributor-threads") = "0"; } - if (::arg().mustDo("help")) { - cout << "syntax:" << endl - << endl; - cout << ::arg().helpstring(::arg()["help"]) << endl; - exit(0); - } g_recCache = std::make_unique(::arg().asNum("record-cache-shards")); g_negCache = std::make_unique(::arg().asNum("record-cache-shards")); - g_quiet = ::arg().mustDo("quiet"); - Logger::Urgency logUrgency = (Logger::Urgency)::arg().asNum("loglevel"); - - if (logUrgency < Logger::Error) - logUrgency = Logger::Error; - if (!g_quiet && logUrgency < Logger::Info) { // Logger::Info=6, Logger::Debug=7 - logUrgency = Logger::Info; // if you do --quiet=no, you need Info to also see the query log - } - g_log.setLoglevel(logUrgency); - g_log.toConsole(logUrgency); - ret = serviceMain(argc, argv); } catch (PDNSException& ae) {