From: Charles-Henri Bruyand Date: Wed, 10 Mar 2021 08:49:37 +0000 (+0100) Subject: rec: structured-logging draft X-Git-Tag: dnsdist-1.7.0-alpha1~122^2~12 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=f3cba0342f4905c5d48d719e993394175a1f559f;p=thirdparty%2Fpdns.git rec: structured-logging draft --- diff --git a/pdns/pdns_recursor.cc b/pdns/pdns_recursor.cc index 2ee539cfb6..b1fda8118f 100644 --- a/pdns/pdns_recursor.cc +++ b/pdns/pdns_recursor.cc @@ -76,6 +76,7 @@ #include "zoneparser-tng.hh" #include "rec_channel.hh" #include "logger.hh" +#include "logging.hh" #include "iputils.hh" #include "mplexer.hh" #include "config.h" @@ -5674,13 +5675,34 @@ int main(int argc, char **argv) exit(0); } - if(!::arg().file(configname.c_str())) - g_log< entry) { + if (entry->error) { + std::cout << "ERR "; + } else { + std::cout << "INFO"; + } + if (entry->name) { + std::cout << entry->name.get() << ": "; + } + std::cout << entry->message; + for (auto const& v: entry->values) { + std::cout << " "; + std::cout << v.first << "=" << v.second; + } + std::cout << std::endl; + }); + auto startupLog = g_slog->withName("startup"); + + if(!::arg().file(configname.c_str())) { + startupLog + ->withValues("config_file", Logging::Loggable(configname)) + ->error("No such file", "Unable to parse configuration file"); + } ::arg().parse(argc,argv); if( !::arg()["chroot"].empty() && !::arg()["api-config-dir"].empty() ) { - g_log<info("Cannot use chroot and enable the API at the same time"); exit(EXIT_FAILURE); } @@ -5693,13 +5715,13 @@ int main(int argc, char **argv) if(::arg().asNum("threads")==1) { if (::arg().mustDo("pdns-distributes-queries")) { - g_log<v(1)->info("Only one thread, no need to distribute queries ourselves"); ::arg().set("pdns-distributes-queries")="no"; } } if(::arg().mustDo("pdns-distributes-queries") && ::arg().asNum("distributor-threads") <= 0) { - g_log<v(1)->info("Asked to run with pdns-distributes-queries set but no distributor threads, raising to 1"); ::arg().set("distributor-threads")="1"; } diff --git a/pdns/recursordist/Makefile.am b/pdns/recursordist/Makefile.am index bd39f48fe5..5175204b60 100644 --- a/pdns/recursordist/Makefile.am +++ b/pdns/recursordist/Makefile.am @@ -130,6 +130,7 @@ pdns_recursor_SOURCES = \ lazy_allocator.hh \ lock.hh \ logger.hh logger.cc \ + logging.hh logging.cc logr.hh \ lua-base4.cc lua-base4.hh \ lua-recursor4-ffi.hh \ lua-recursor4.cc lua-recursor4.hh \ @@ -255,6 +256,7 @@ testrunner_SOURCES = \ iputils.cc iputils.hh \ ixfr.cc ixfr.hh \ logger.cc logger.hh \ + logging.hh logging.cc logr.hh \ misc.cc misc.hh \ mtasker_context.cc \ namespaces.hh \ diff --git a/pdns/recursordist/logging.cc b/pdns/recursordist/logging.cc new file mode 100644 index 0000000000..b5da367fe4 --- /dev/null +++ b/pdns/recursordist/logging.cc @@ -0,0 +1,140 @@ +/** + * 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. + */ + +#include "logging.hh" + +namespace Logging +{ + + std::shared_ptr Logger::getptr() + { + return shared_from_this(); + } + + bool Logger::enabled() + { + return true; + } + + void Logger::info(const std::string& msg) + { + logMessage(msg, boost::none); + } + + void Logger::logMessage(const std::string& msg, boost::optional err) + { + if (_level > _verbosity) { + return ; + } + auto entry = std::unique_ptr(new Entry()); + entry->level = _level; + entry->name = _name; + entry->message = msg; + entry->error = err; + auto parent = _parent; + entry->values.insert(_values.begin(), _values.end()); + while (parent) { + entry->values.insert(parent->_values.begin(), parent->_values.end()); + parent = parent->_parent; + } + _callback(std::move(entry)); + } + + void Logger::error(const std::string& err, const std::string& msg) + { + logMessage(msg, err); + } + + std::shared_ptr Logger::v(size_t level) + { + auto res = std::make_shared(getptr(), boost::none, level + _level, _callback); + res->setVerbosity(getVerbosity()); + return res; + } + + std::shared_ptr Logger::withValues(const std::string& key, const Logr::Loggable& value) + { + auto res = std::make_shared(getptr(), _name.get(), _level, _callback); + res->_values.insert({key, value.to_string()}); + res->setVerbosity(getVerbosity()); + return res; + } + + template struct Loggable; + template struct Loggable; + template struct Loggable; + + template <> + std::string Loggable::to_string() const { + return _t.toLogString(); + } + template <> + std::string Loggable::to_string() const { + return _t.toLogString(); + } + template <> + std::string Loggable::to_string() const { + return _t; + } + + std::shared_ptr Logger::withName(const std::string& name) + { + std::shared_ptr res; + if (_name) { + res = std::make_shared(getptr(), _name.get() + "." + name, _level, _callback); + } else { + res = std::make_shared(getptr(), name, _level, _callback); + } + res->setVerbosity(getVerbosity()); + return res; + } + std::shared_ptr Logger::create(EntryLogger callback) + { + return std::make_shared(callback); + } + std::shared_ptr Logger::create(EntryLogger callback, const std::string& name) + { + return std::make_shared(callback, name); + } + + size_t Logger::getVerbosity() const + { + return _verbosity; + } + + void Logger::setVerbosity(size_t verbosity) + { + _verbosity = verbosity; + } + + Logger::Logger(EntryLogger callback) : _callback(callback) + { + } + Logger::Logger(EntryLogger callback, boost::optional name) : _callback(callback), _name(name) + { + } + Logger::Logger(std::shared_ptr parent, boost::optional name, size_t lvl, EntryLogger callback) : _parent(parent), _callback(callback), _name(name), _level(lvl) + { + } +}; + +std::shared_ptr g_slog{nullptr}; diff --git a/pdns/recursordist/logging.hh b/pdns/recursordist/logging.hh new file mode 100644 index 0000000000..b8517284a0 --- /dev/null +++ b/pdns/recursordist/logging.hh @@ -0,0 +1,102 @@ +/* + * 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 + { + size_t level; // level at which this was logged + boost::optional name; // name parts joined with '.' + std::string message; // message as send to log call + boost::optional error; // error if .Error() was called + std::map values; + }; + + 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; +// template <> +// Loggable::Loggable(const std::string& v): _t(v) {} + + typedef void(*EntryLogger)(std::unique_ptr); + + class Logger: public Logr::Logger, public std::enable_shared_from_this + { + public: + virtual bool enabled(); + virtual void info(const std::string& msg); + virtual void error(const std::string& err, const std::string& msg); + virtual std::shared_ptr v(size_t level); + + std::shared_ptr withValues(const std::string& key, const Logr::Loggable& value); + virtual std::shared_ptr withName(const std::string& name); + + 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 lvl, EntryLogger callback); + + size_t getVerbosity() const; + void setVerbosity(size_t verbosity); + private: + void logMessage(const std::string& msg, boost::optional err); + std::shared_ptr getptr(); + + std::shared_ptr _parent{nullptr}; + EntryLogger _callback; + boost::optional _name; + std::map _values; + size_t _verbosity{0}; + size_t _level{0}; + }; +} + +extern std::shared_ptr g_slog; diff --git a/pdns/recursordist/logr.hh b/pdns/recursordist/logr.hh new file mode 100644 index 0000000000..2345c3f1fd --- /dev/null +++ b/pdns/recursordist/logr.hh @@ -0,0 +1,77 @@ +/* + * 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 + +// Minimal logging API based on https://github.com/go-logr/logr + +namespace Logr { + struct Loggable { + virtual std::string to_string() const = 0; + }; + + class Logger { + public: + // Enabled tests whether this Logger is enabled. For example, commandline + // flags might be used to set the logging verbosity and disable some info + // logs. + virtual bool enabled() = 0; + + // Info logs a non-error message with the given key/value pairs as context. + // + // The msg argument should be used to add some constant description to + // the log line. The key/value pairs can then be used to add additional + // variable information. The key/value pairs should alternate string + // keys and arbitrary values. + virtual void info(const std::string& msg) = 0; + + // Error logs an error, with the given message and key/value pairs as context. + // It functions similarly to calling Info with the "error" named value, but may + // have unique behavior, and should be preferred for logging errors (see the + // package documentations for more information). + // + // The msg field should be used to add context to any underlying error, + // while the err field should be used to attach the actual error that + // triggered this log line, if present. + virtual void error(const std::string& err, const std::string& msg) = 0; + + // V returns an Logger value for a specific verbosity level, relative to + // this Logger. In other words, V values are additive. V higher verbosity + // level means a log message is less important. It's illegal to pass a log + // level less than zero. + virtual std::shared_ptr v(size_t level) = 0; + + // WithValues adds some key-value pairs of context to a logger. + // See Info for documentation on how key/value pairs work. + virtual std::shared_ptr withValues(const std::string& key, const Loggable& value) = 0; + + // WithName adds a new element to the logger's name. + // Successive calls with WithName continue to append + // suffixes to the logger's name. It's strongly recommended + // that name segments contain only letters, digits, and hyphens + // (see the package documentation for more information). + virtual std::shared_ptr withName(const std::string& name) = 0; + }; +} diff --git a/pdns/rpzloader.cc b/pdns/rpzloader.cc index 7d521ca6a0..3c27c1cd96 100644 --- a/pdns/rpzloader.cc +++ b/pdns/rpzloader.cc @@ -5,6 +5,7 @@ #include "syncres.hh" #include "axfr-retriever.hh" #include "logger.hh" +#include "logging.hh" #include "rec-lua-conf.hh" #include "rpzloader.hh" #include "zoneparser-tng.hh" @@ -188,9 +189,12 @@ static void RPZRecordToPolicy(const DNSRecord& dr, std::shared_ptr loadRPZFromServer(const ComboAddress& primary, const DNSName& zoneName, std::shared_ptr zone, boost::optional defpol, bool defpolOverrideLocal, uint32_t maxTTL, const TSIGTriplet& tt, size_t maxReceivedBytes, const ComboAddress& localAddress, uint16_t axfrTimeout) { - g_log<withName("rpz")->withValues("zone", Logging::Loggable(zoneName))->withValues("primary", Logging::Loggable(primary)); + logger->info("Loading RPZ from nameserver"); + if(!tt.name.empty()) { + logger->withValues("tsig_key_name", Logging::Loggable(tt.name))->withValues("tsig_key_algorithm", Logging::Loggable(tt.algo))->info("Using TSIG key for authentication"); + } ComboAddress local(localAddress); if (local == ComboAddress()) @@ -224,11 +228,11 @@ static shared_ptr loadRPZFromServer(const ComboAddress& primar throw PDNSException("Total AXFR time exceeded!"); } if(last != time(0)) { - g_log<withValues("nrecords", Logging::Loggable(nrecords))->info("RPZ load in progress"); last=time(0); } } - g_log<getZoneRepresentation()<withValues("nrecords", Logging::Loggable(nrecords))->withValues("soa", Logging::Loggable(sr->getZoneRepresentation()))->info("RPZ load completed"); return sr; } @@ -304,17 +308,20 @@ static void setRPZZoneNewState(const std::string& zone, uint32_t serial, uint64_ static bool dumpZoneToDisk(const DNSName& zoneName, const std::shared_ptr& newZone, const std::string& dumpZoneFileName) { + auto logger = g_slog->withName("rpz")->withValues("zone", Logging::Loggable(zoneName)); + logger->v(1)->withValues("destination_file", Logging::Loggable(dumpZoneFileName))->info("Dumping zone to disk"); std::string temp = dumpZoneFileName + "XXXXXX"; int fd = mkstemp(&temp.at(0)); if (fd < 0) { - g_log<error(strerror(errno), "Unable to create temporary file"); return false; } auto fp = std::unique_ptr(fdopen(fd, "w+"), fclose); if (!fp) { + int err = errno; close(fd); - g_log<error(stringerror(err), "Unable to open file pointer"); return false; } fd = -1; @@ -323,27 +330,29 @@ static bool dumpZoneToDisk(const DNSName& zoneName, const std::shared_ptrdump(fp.get()); } catch(const std::exception& e) { - g_log<error(e.what(), "Error while dumping the content of the RPZ"); return false; } if (fflush(fp.get()) != 0) { - g_log<error(stringerror(), "Error while flushing the content of the RPZ"); return false; } if (fsync(fileno(fp.get())) != 0) { - g_log<error(stringerror(), "Error while syncing the content of the RPZ"); return false; } if (fclose(fp.release()) != 0) { - g_log<error(stringerror(), "Error while writing the content of the RPZ"); return false; } if (rename(temp.c_str(), dumpZoneFileName.c_str()) != 0) { - g_log<withValues("destination_file", Logging::Loggable(dumpZoneFileName)) + ->error(stringerror(), "Error while moving the content of the RPZ"); return false; }