]> git.ipfire.org Git - thirdparty/pdns.git/commitdiff
Convert startup and some of config to use structured logging
authorOtto Moerbeek <otto.moerbeek@open-xchange.com>
Tue, 17 May 2022 08:13:57 +0000 (10:13 +0200)
committerOtto Moerbeek <otto.moerbeek@open-xchange.com>
Wed, 18 May 2022 09:57:39 +0000 (11:57 +0200)
pdns/logging.hh
pdns/pdns_recursor.cc
pdns/recursordist/logging.cc
pdns/recursordist/rec-main.cc
pdns/recursordist/rec-main.hh
pdns/recursordist/rec-tcp.cc
pdns/reczones.cc
pdns/syncres.hh

index e95535b8c51ac652d9d7a32dcf5acfbc67f2360a..d2ab31ca58ede2a6f3265a8ca152b7b65b140aa8 100644 (file)
@@ -71,6 +71,8 @@ template <>
 std::string Loggable<ComboAddress>::to_string() const;
 template <>
 std::string Loggable<std::string>::to_string() const;
+template <>
+std::string Loggable<std::vector<std::string>>::to_string() const;
 
 // Loggable<std::string>::Loggable(const std::string& v): _t(v) {}
 
index 189e908f04d1eef919dc5fcc2e7eab41e4dac1a2..2e3b840d548c4455ee79c4324345e89c5d3a6532 100644 (file)
@@ -2289,7 +2289,7 @@ static void handleNewUDPQuestion(int fd, FDMultiplexer::funcparam_t& var)
   }
 }
 
-void makeUDPServerSockets(deferredAdd_t& deferredAdds)
+void makeUDPServerSockets(deferredAdd_t& deferredAdds, std::shared_ptr<Logr::Logger>& log)
 {
   int one = 1;
   vector<string> locals;
@@ -2317,9 +2317,10 @@ void makeUDPServerSockets(deferredAdd_t& deferredAdds)
     if (fd < 0) {
       throw PDNSException("Making a UDP server socket for resolver: " + stringerror());
     }
-    if (!setSocketTimestamps(fd))
-      g_log << Logger::Warning << "Unable to enable timestamp reporting for socket" << endl;
-
+    if (!setSocketTimestamps(fd)) {
+      SLOG(g_log << Logger::Warning << "Unable to enable timestamp reporting for socket" << endl,
+           log->info(Logr::Warning,  "Unable to enable timestamp reporting for socket"));
+    }
     if (IsAnyAddress(sin)) {
       if (sin.sin4.sin_family == AF_INET)
         if (!setsockopt(fd, IPPROTO_IP, GEN_IP_PKTINFO, &one, sizeof(one))) // linux supports this, so why not - might fail on other systems
@@ -2331,7 +2332,8 @@ void makeUDPServerSockets(deferredAdd_t& deferredAdds)
 #endif
       if (sin.sin6.sin6_family == AF_INET6 && setsockopt(fd, IPPROTO_IPV6, IPV6_V6ONLY, &one, sizeof(one)) < 0) {
         int err = errno;
-        g_log << Logger::Error << "Failed to set IPv6 socket to IPv6 only, continuing anyhow: " << strerror(err) << endl;
+        SLOG(g_log << Logger::Error << "Failed to set IPv6 socket to IPv6 only, continuing anyhow: " << strerror(err) << endl,
+             log->error(Logr::Error, "Failed to set IPv6 socket to IPv6 only, continuing anyhow"));
       }
     }
     if (::arg().mustDo("non-local-bind"))
@@ -2369,7 +2371,8 @@ void makeUDPServerSockets(deferredAdd_t& deferredAdds)
       setSocketIgnorePMTU(fd, sin.sin4.sin_family);
     }
     catch (const std::exception& e) {
-      g_log << Logger::Warning << "Failed to set IP_MTU_DISCOVER on UDP server socket: " << e.what() << endl;
+      SLOG(g_log << Logger::Warning << "Failed to set IP_MTU_DISCOVER on UDP server socket: " << e.what() << endl,
+           log->error(Logr::Warning, e.what(), "Failed to set IP_MTU_DISCOVER on UDP server socket"));
     }
 
     socklen_t socklen = sin.getSocklen();
@@ -2380,10 +2383,8 @@ void makeUDPServerSockets(deferredAdd_t& deferredAdds)
 
     deferredAdds.emplace_back(fd, handleNewUDPQuestion);
     g_listenSocketsAddresses[fd] = sin; // this is written to only from the startup thread, not from the workers
-    if (sin.sin4.sin_family == AF_INET)
-      g_log << Logger::Info << "Listening for UDP queries on " << sin.toString() << ":" << st.port << endl;
-    else
-      g_log << Logger::Info << "Listening for UDP queries on [" << sin.toString() << "]:" << st.port << endl;
+    SLOG(g_log << Logger::Info << "Listening for UDP queries on " << sin.toStringWithPort() << endl,
+         log->info(Logr::Info, "Listening forqueries", "protocol", Logging::Loggable("UDP"), "address", Logging::Loggable(sin.toStringWithPort())));
   }
 }
 
index 6196ba3b8f7a8aa572a0668c00c3bd2b15ea492c..5b49d2a61e1c83625db636a09228bf1188d248c0 100644 (file)
@@ -126,6 +126,21 @@ std::string Loggable<std::string>::to_string() const
 {
   return _t;
 }
+template <>
+std::string Loggable<std::vector<std::string>>::to_string() const
+{
+  std::ostringstream oss;
+  bool first = true;
+  for (const auto& e : _t) {
+    if (!first) {
+      oss << ' ';
+    } else {
+      first = false;
+    }
+    oss << e;
+  }
+  return oss.str();
+}
 
 std::shared_ptr<Logr::Logger> Logger::withName(const std::string& name) const
 {
index 9c6b6f2447d406304d74cdfc815b8fefbc05f73c..28aeefdffd9e41042f9484accaa4c1d5cc12f113 100644 (file)
@@ -191,14 +191,15 @@ void RecThreadInfo::start(unsigned int id, const string& tname, const std::map<u
   setCPUMap(cpusMap, id, thread.native_handle());
 }
 
-int RecThreadInfo::runThreads()
+int RecThreadInfo::runThreads(std::shared_ptr<Logr::Logger>& log)
 {
   int ret = EXIT_SUCCESS;
   unsigned int currentThreadId = 1;
   const auto cpusMap = parseCPUMap();
 
   if (RecThreadInfo::numDistributors() + RecThreadInfo::numWorkers() == 1) {
-    g_log << Logger::Warning << "Operating with single distributor/worker thread" << endl;
+    SLOG(g_log << Logger::Warning << "Operating with single distributor/worker thread" << endl,
+         log->info(Logr::Warning, "Operating with single distributor/worker thread"));
 
     /* This thread handles the web server, carbon, statistics and the control channel */
     auto& handlerInfo = RecThreadInfo::info(0);
@@ -243,14 +244,15 @@ int RecThreadInfo::runThreads()
 
     // And now start the actual threads
     if (RecThreadInfo::weDistributeQueries()) {
-      g_log << Logger::Warning << "Launching " << RecThreadInfo::numDistributors() << " distributor threads" << endl;
+      SLOG(g_log << Logger::Warning << "Launching " << RecThreadInfo::numDistributors() << " distributor threads" << endl,
+           log->info(Logr::Warning, "Launching distributor threads", "count", Logging::Loggable(RecThreadInfo::numDistributors())));
       for (unsigned int n = 0; n < RecThreadInfo::numDistributors(); ++n) {
         auto& info = RecThreadInfo::info(currentThreadId);
         info.start(currentThreadId++, "distr", cpusMap);
       }
     }
-
-    g_log << Logger::Warning << "Launching " << RecThreadInfo::numWorkers() << " worker threads" << endl;
+    SLOG(g_log << Logger::Warning << "Launching " << RecThreadInfo::numWorkers() << " worker threads" << endl,
+         log->info(Logr::Warning, "Launching worker threads", "count", Logging::Loggable(RecThreadInfo::numWorkers())));
 
     for (unsigned int n = 0; n < RecThreadInfo::numWorkers(); ++n) {
       auto& info = RecThreadInfo::info(currentThreadId);
@@ -858,7 +860,6 @@ 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;
 }
@@ -928,7 +929,7 @@ static void doStats(void)
   statsWanted = false;
 }
 
-static std::shared_ptr<NetmaskGroup> parseACL(const std::string& aclFile, const std::string& aclSetting)
+static std::shared_ptr<NetmaskGroup> parseACL(const std::string& aclFile, const std::string& aclSetting, std::shared_ptr<Logr::Logger>& log)
 {
   auto result = std::make_shared<NetmaskGroup>();
 
@@ -950,20 +951,29 @@ static std::shared_ptr<NetmaskGroup> parseACL(const std::string& aclFile, const
 
       result->addMask(line);
     }
-    g_log << Logger::Info << "Done parsing " << result->size() << " " << aclSetting << " ranges from file '" << ::arg()[aclFile] << "' - overriding '" << aclSetting << "' setting" << endl;
-  }
+    SLOG(g_log << Logger::Info << "Done parsing " << result->size() << " " << aclSetting << " ranges from file '" << ::arg()[aclFile] << "' - overriding '" << aclSetting << "' setting" << endl,
+         log->info(Logr::Info, "Done parsing ranges from file, will override setting", "setting", Logging::Loggable(aclSetting),
+                   "number",  Logging::Loggable(result->size()), "file", Logging::Loggable(::arg()[aclFile])));
+    }
   else if (!::arg()[aclSetting].empty()) {
     vector<string> ips;
     stringtok(ips, ::arg()[aclSetting], ", ");
 
-    g_log << Logger::Info << aclSetting << ": ";
-    for (vector<string>::const_iterator i = ips.begin(); i != ips.end(); ++i) {
-      result->addMask(*i);
-      if (i != ips.begin())
-        g_log << Logger::Info << ", ";
-      g_log << Logger::Info << *i;
+    for (const auto& i : ips) {
+      result->addMask(i);
+    }
+    if (!g_slogStructured) {
+      g_log << Logger::Info << aclSetting << ": ";
+      for (vector<string>::const_iterator i = ips.begin(); i != ips.end(); ++i) {
+        if (i != ips.begin())
+          g_log << Logger::Info << ", ";
+        g_log << Logger::Info << *i;
+      }
+      g_log << Logger::Info << endl;
+    }
+    else {
+      log->info(Logr::Info, "Setting access control", "acl", Logging::Loggable(aclSetting), "addresses", Logging::Loggable(ips));
     }
-    g_log << Logger::Info << endl;
   }
 
   return result;
@@ -989,6 +999,8 @@ void* pleaseSupplantAllowNotifyFor(std::shared_ptr<notifyset_t> ns)
 
 void parseACLs()
 {
+  auto log = g_slog->withName("config");
+
   static bool l_initialized;
 
   if (l_initialized) { // only reload configuration file on second call
@@ -1032,18 +1044,20 @@ void parseACLs()
     ::arg().preParse(g_argc, g_argv, "allow-notify-from");
   }
 
-  auto allowFrom = parseACL("allow-from-file", "allow-from");
+  auto allowFrom = parseACL("allow-from-file", "allow-from", log);
 
   if (allowFrom->size() == 0) {
-    if (::arg()["local-address"] != "127.0.0.1" && ::arg().asNum("local-port") == 53)
-      g_log << Logger::Warning << "WARNING: Allowing queries from all IP addresses - this can be a security risk!" << endl;
+    if (::arg()["local-address"] != "127.0.0.1" && ::arg().asNum("local-port") == 53) {
+      SLOG(g_log << Logger::Warning << "WARNING: Allowing queries from all IP addresses - this can be a security risk!" << endl,
+           log->info(Logr::Warning, "WARNING: Allowing queries from all IP addresses - this can be a security risk!"));
+    }
     allowFrom = nullptr;
   }
 
   g_initialAllowFrom = allowFrom;
   broadcastFunction([=] { return pleaseSupplantAllowFrom(allowFrom); });
 
-  auto allowNotifyFrom = parseACL("allow-notify-from-file", "allow-notify-from");
+  auto allowNotifyFrom = parseACL("allow-notify-from-file", "allow-notify-from", log);
 
   g_initialAllowNotifyFrom = allowNotifyFrom;
   broadcastFunction([=] { return pleaseSupplantAllowNotifyFrom(allowNotifyFrom); });
@@ -1163,7 +1177,7 @@ template vector<ComboAddress> broadcastAccFunction(const std::function<vector<Co
 template vector<pair<DNSName, uint16_t>> broadcastAccFunction(const std::function<vector<pair<DNSName, uint16_t>>*()>& fun); // explicit instantiation
 template ThreadTimes broadcastAccFunction(const std::function<ThreadTimes*()>& fun);
 
-static int serviceMain(int argc, char* argv[])
+static int serviceMain(int argc, char* argv[], std::shared_ptr<Logr::Logger>& log)
 {
   g_log.setName(g_programname);
   g_log.disableSyslog(::arg().mustDo("disable-syslog"));
@@ -1173,8 +1187,10 @@ static int serviceMain(int argc, char* argv[])
     int val = logFacilityToLOG(::arg().asNum("logging-facility"));
     if (val >= 0)
       g_log.setFacility(val);
-    else
-      g_log << Logger::Error << "Unknown logging facility " << ::arg().asNum("logging-facility") << endl;
+    else {
+      SLOG(g_log << Logger::Error << "Unknown logging facility " << ::arg().asNum("logging-facility") << endl,
+           log->info(Logr::Error, "Unknown logging facility", "facility", Logging::Loggable(::arg().asNum("logging-facility"))));
+    }
   }
 
   showProductVersion();
@@ -1186,28 +1202,34 @@ static int serviceMain(int argc, char* argv[])
     pdns::parseQueryLocalAddress(::arg()["query-local-address"]);
   }
   catch (std::exception& e) {
-    g_log << Logger::Error << "Assigning local query addresses: " << e.what();
+    SLOG(g_log << Logger::Error << "Assigning local query addresses: " << e.what(),
+         log->error(Logr::Error, e.what(), "Assigning local query address"));
     exit(99);
   }
 
   if (pdns::isQueryLocalAddressFamilyEnabled(AF_INET)) {
     SyncRes::s_doIPv4 = true;
-    g_log << Logger::Warning << "Enabling IPv4 transport for outgoing queries" << endl;
+    SLOG(g_log << Logger::Warning << "Enabling IPv4 transport for outgoing queries" << endl,
+         log->info(Logr::Warning, "Enabling IPv4 transport for outgoing queries"));
   }
   else {
-    g_log << Logger::Warning << "NOT using IPv4 for outgoing queries - add an IPv4 address (like '0.0.0.0') to query-local-address to enable" << endl;
+    SLOG(g_log << Logger::Warning << "NOT using IPv4 for outgoing queries - add an IPv4 address (like '0.0.0.0') to query-local-address to enable" << endl,
+         log->info(Logr::Warning, "NOT using IPv4 for outgoing queries - add an IPv4 address (like '0.0.0.0') to query-local-address to enable"));
   }
 
   if (pdns::isQueryLocalAddressFamilyEnabled(AF_INET6)) {
     SyncRes::s_doIPv6 = true;
-    g_log << Logger::Warning << "Enabling IPv6 transport for outgoing queries" << endl;
+    SLOG(g_log << Logger::Warning << "Enabling IPv6 transport for outgoing queries" << endl,
+         log->info(Logr::Warning, "Enabling IPv6 transport for outgoing queries"));
   }
   else {
-    g_log << Logger::Warning << "NOT using IPv6 for outgoing queries - add an IPv6 address (like '::') to query-local-address to enable" << endl;
+    SLOG(g_log << Logger::Warning << "NOT using IPv6 for outgoing queries - add an IPv6 address (like '::') to query-local-address to enable" << endl,
+         log->info(Logr::Warning, "NOT using IPv6 for outgoing queries - add an IPv6 address (like '::') to query-local-address to enable"));
   }
 
   if (!SyncRes::s_doIPv6 && !SyncRes::s_doIPv4) {
-    g_log << Logger::Error << "No outgoing addresses configured! Can not continue" << endl;
+    SLOG(g_log << Logger::Error << "No outgoing addresses configured! Can not continue" << endl,
+         log->info(Logr::Error, "No outgoing addresses configured! Can not continue"));
     exit(99);
   }
 
@@ -1223,13 +1245,15 @@ static int serviceMain(int argc, char* argv[])
   else if (::arg()["dnssec"] == "log-fail")
     g_dnssecmode = DNSSECMode::ValidateForLog;
   else {
-    g_log << Logger::Error << "Unknown DNSSEC mode " << ::arg()["dnssec"] << endl;
+    SLOG(g_log << Logger::Error << "Unknown DNSSEC mode " << ::arg()["dnssec"] << endl,
+         log->info(Logr::Error, "Unknown DNSSEC mode", "dnssec", Logging::Loggable(::arg()["dnssec"])));
     exit(1);
   }
 
   g_signatureInceptionSkew = ::arg().asNum("signature-inception-skew");
   if (g_signatureInceptionSkew < 0) {
-    g_log << Logger::Error << "A negative value for 'signature-inception-skew' is not allowed" << endl;
+    SLOG(g_log << Logger::Error << "A negative value for 'signature-inception-skew' is not allowed" << endl,
+         log->info(Logr::Error, "A negative value for 'signature-inception-skew' is not allowed"));
     exit(1);
   }
 
@@ -1247,7 +1271,8 @@ static int serviceMain(int argc, char* argv[])
     g_proxyMapping = proxyMapping.empty() ? nullptr : std::make_shared<ProxyMapping>(proxyMapping);
   }
   catch (PDNSException& e) {
-    g_log << Logger::Error << "Cannot load Lua configuration: " << e.reason << endl;
+    SLOG(g_log << Logger::Error << "Cannot load Lua configuration: " << e.reason << endl,
+         log->error(Logr::Error, e.reason, "Cannot load Lua configuration"));
     exit(1);
   }
 
@@ -1260,20 +1285,28 @@ static int serviceMain(int argc, char* argv[])
     ips.push_back("0.0.0.0");
     ips.push_back("::");
 
-    g_log << Logger::Warning << "Will not send queries to: ";
-    for (vector<string>::const_iterator i = ips.begin(); i != ips.end(); ++i) {
-      SyncRes::addDontQuery(*i);
-      if (i != ips.begin())
-        g_log << Logger::Warning << ", ";
-      g_log << Logger::Warning << *i;
+    for (const auto& ip : ips) {
+      SyncRes::addDontQuery(ip);
+    }
+    if (!g_slogStructured) {
+      g_log << Logger::Warning << "Will not send queries to: ";
+      for (vector<string>::const_iterator i = ips.begin(); i != ips.end(); ++i) {
+        if (i != ips.begin())
+          g_log << Logger::Warning << ", ";
+        g_log << Logger::Warning << *i;
+      }
+      g_log << Logger::Warning << endl;
+    }
+    else {
+      log->info(Logr::Warning, "Will not send queries to", "addresses", Logging::Loggable(ips));
     }
-    g_log << Logger::Warning << endl;
   }
 
   /* this needs to be done before parseACLs(), which call broadcastFunction() */
   RecThreadInfo::setWeDistributeQueries(::arg().mustDo("pdns-distributes-queries"));
   if (RecThreadInfo::weDistributeQueries()) {
-    g_log << Logger::Warning << "PowerDNS Recursor itself will distribute queries over threads" << endl;
+    SLOG(g_log << Logger::Warning << "PowerDNS Recursor itself will distribute queries over threads" << endl,
+         log->info(Logr::Warning, "PowerDNS Recursor itself will distribute queries over threads"));
   }
 
   g_outgoingEDNSBufsize = ::arg().asNum("edns-outgoing-bufsize");
@@ -1289,7 +1322,8 @@ static int serviceMain(int argc, char* argv[])
   }
   string myHostname = getHostname();
   if (myHostname == "UNKNOWN") {
-    g_log << Logger::Warning << "Unable to get the hostname, NSID and id.server values will be empty" << endl;
+    SLOG(g_log << Logger::Warning << "Unable to get the hostname, NSID and id.server values will be empty" << endl,
+         log->info(Logr::Warning, "Unable to get the hostname, NSID and id.server values will be empty"));
     myHostname = "";
   }
 
@@ -1357,7 +1391,8 @@ static int serviceMain(int argc, char* argv[])
     SyncRes::s_hardenNXD = SyncRes::HardenNXD::No;
   }
   else if (value != "dnssec") {
-    g_log << Logger::Error << "Unknown nothing-below-nxdomain mode: " << value << endl;
+    SLOG(g_log << Logger::Error << "Unknown nothing-below-nxdomain mode: " << value << endl,
+         log->info(Logr::Error, "Unknown nothing-below-nxdomain mode", "mode", Logging::Loggable(value)));
     exit(1);
   }
 
@@ -1402,7 +1437,8 @@ static int serviceMain(int argc, char* argv[])
     try {
       auto dns64Prefix = Netmask(::arg()["dns64-prefix"]);
       if (dns64Prefix.getBits() != 96) {
-        g_log << Logger::Error << "Invalid prefix for 'dns64-prefix', the current implementation only supports /96 prefixes: " << ::arg()["dns64-prefix"] << endl;
+        SLOG(g_log << Logger::Error << "Invalid prefix for 'dns64-prefix', the current implementation only supports /96 prefixes: " << ::arg()["dns64-prefix"] << endl,
+             log->info(Logr::Error, "Invalid prefix for 'dns64-prefix', the current implementation only supports /96 prefixes", "prefix", Logging::Loggable(::arg()["dns64-prefix"])));
         exit(1);
       }
       g_dns64Prefix = dns64Prefix.getNetwork();
@@ -1413,7 +1449,8 @@ static int serviceMain(int argc, char* argv[])
       }
     }
     catch (const NetmaskException& ne) {
-      g_log << Logger::Error << "Invalid prefix '" << ::arg()["dns64-prefix"] << "' for 'dns64-prefix': " << ne.reason << endl;
+      SLOG(g_log << Logger::Error << "Invalid prefix '" << ::arg()["dns64-prefix"] << "' for 'dns64-prefix': " << ne.reason << endl,
+           log->info(Logr::Error, "Invalid prefix", "dns64-prefix", Logging::Loggable(::arg()["dns64-prefix"])));
       exit(1);
     }
   }
@@ -1440,7 +1477,8 @@ static int serviceMain(int argc, char* argv[])
     g_paddingMode = PaddingMode::PaddedQueries;
   }
   else {
-    g_log << Logger::Error << "Unknown edns-padding-mode: " << ::arg()["edns-padding-mode"] << endl;
+    SLOG(g_log << Logger::Error << "Unknown edns-padding-mode: " << ::arg()["edns-padding-mode"] << endl,
+         log->info(Logr::Error, "Unknown edns-padding-mode", "edns-padding-mode", Logging::Loggable(::arg()["edns-padding-mode"])));
     exit(1);
   }
   g_paddingTag = ::arg().asNum("edns-padding-tag");
@@ -1448,7 +1486,8 @@ static int serviceMain(int argc, char* argv[])
   RecThreadInfo::setNumDistributorThreads(::arg().asNum("distributor-threads"));
   RecThreadInfo::setNumWorkerThreads(::arg().asNum("threads"));
   if (RecThreadInfo::numWorkers() < 1) {
-    g_log << Logger::Warning << "Asked to run with 0 threads, raising to 1 instead" << endl;
+    SLOG(g_log << Logger::Warning << "Asked to run with 0 threads, raising to 1 instead" << endl,
+         log->info(Logr::Warning, "Asked to run with 0 threads, raising to 1 instead"));
     RecThreadInfo::setNumWorkerThreads(1);
   }
 
@@ -1456,7 +1495,8 @@ static int serviceMain(int argc, char* argv[])
 
   int64_t maxInFlight = ::arg().asNum("max-concurrent-requests-per-tcp-connection");
   if (maxInFlight < 1 || maxInFlight > USHRT_MAX || maxInFlight >= g_maxMThreads) {
-    g_log << Logger::Warning << "Asked to run with illegal max-concurrent-requests-per-tcp-connection, setting to default (10)" << endl;
+    SLOG(g_log << Logger::Warning << "Asked to run with illegal max-concurrent-requests-per-tcp-connection, setting to default (10)" << endl,
+         log->info(Logr::Warning, "Asked to run with illegal max-concurrent-requests-per-tcp-connection, setting to default (10)"));
     TCPConnection::s_maxInFlight = 10;
   }
   else {
@@ -1480,7 +1520,8 @@ static int serviceMain(int argc, char* argv[])
       g_aggressiveNSECCache = make_unique<AggressiveNSECCache>(::arg().asNum("aggressive-nsec-cache-size"));
     }
     else {
-      g_log << Logger::Warning << "Aggressive NSEC/NSEC3 caching is enabled but DNSSEC validation is not set to 'validate', 'log-fail' or 'process', ignoring" << endl;
+      SLOG(g_log << Logger::Warning << "Aggressive NSEC/NSEC3 caching is enabled but DNSSEC validation is not set to 'validate', 'log-fail' or 'process', ignoring" << endl,
+           log->info(Logr::Warning, "Aggressive NSEC/NSEC3 caching is enabled but DNSSEC validation is not set to 'validate', 'log-fail' or 'process', ignoring"));
     }
   }
 
@@ -1518,7 +1559,8 @@ static int serviceMain(int argc, char* argv[])
     stringtok(parts, ::arg()["dot-to-auth-names"], " ,");
 #ifndef HAVE_DNS_OVER_TLS
     if (parts.size()) {
-      g_log << Logger::Error << "dot-to-auth-names setting contains names, but Recursor was built without DNS over TLS support. Setting will be ignored." << endl;
+      SLOG(g_log << Logger::Error << "dot-to-auth-names setting contains names, but Recursor was built without DNS over TLS support. Setting will be ignored." << endl,
+           log->info(Logr::Error,  "dot-to-auth-names setting contains names, but Recursor was built without DNS over TLS support. Setting will be ignored"));
     }
 #endif
     for (const auto& p : parts) {
@@ -1539,7 +1581,8 @@ static int serviceMain(int argc, char* argv[])
   g_balancingFactor = ::arg().asDouble("distribution-load-factor");
   if (g_balancingFactor != 0.0 && g_balancingFactor < 1.0) {
     g_balancingFactor = 0.0;
-    g_log << Logger::Warning << "Asked to run with a distribution-load-factor below 1.0, disabling it instead" << endl;
+    SLOG(g_log << Logger::Warning << "Asked to run with a distribution-load-factor below 1.0, disabling it instead" << endl,
+         log->info(Logr::Warning, "Asked to run with a distribution-load-factor below 1.0, disabling it instead"));
   }
 
 #ifdef SO_REUSEPORT
@@ -1555,8 +1598,8 @@ static int serviceMain(int argc, char* argv[])
         auto& info = RecThreadInfo::info(threadId);
         auto& deferredAdds = info.deferredAdds;
         auto& tcpSockets = info.tcpSockets;
-        makeUDPServerSockets(deferredAdds);
-        makeTCPServerSockets(deferredAdds, tcpSockets);
+        makeUDPServerSockets(deferredAdds, log);
+        makeTCPServerSockets(deferredAdds, tcpSockets, log);
       }
     }
     else {
@@ -1565,8 +1608,8 @@ static int serviceMain(int argc, char* argv[])
         auto& info = RecThreadInfo::info(threadId);
         auto& deferredAdds = info.deferredAdds;
         auto& tcpSockets = info.tcpSockets;
-        makeUDPServerSockets(deferredAdds);
-        makeTCPServerSockets(deferredAdds, tcpSockets);
+        makeUDPServerSockets(deferredAdds, log);
+        makeTCPServerSockets(deferredAdds, tcpSockets, log);
       }
     }
   }
@@ -1574,8 +1617,8 @@ static int serviceMain(int argc, char* argv[])
     std::set<int> tcpSockets;
     /* we don't have reuseport so we can only open one socket per
        listening addr:port and everyone will listen on it */
-    makeUDPServerSockets(g_deferredAdds);
-    makeTCPServerSockets(g_deferredAdds, tcpSockets);
+    makeUDPServerSockets(g_deferredAdds, log);
+    makeTCPServerSockets(g_deferredAdds, tcpSockets, log);
 
     /* every listener (so distributor if g_weDistributeQueries, workers otherwise)
        needs to listen to the shared sockets */
@@ -1605,7 +1648,8 @@ static int serviceMain(int argc, char* argv[])
   }
 
   if (::arg().mustDo("daemon")) {
-    g_log << Logger::Warning << "Calling daemonize, going to background" << endl;
+    SLOG(g_log << Logger::Warning << "Calling daemonize, going to background" << endl,
+         log->info(Logr::Warning, "Calling daemonize, going to background"));
     g_log.toConsole(Logger::Critical);
     daemonize();
   }
@@ -1635,7 +1679,8 @@ static int serviceMain(int argc, char* argv[])
 
 #ifdef HAVE_LIBSODIUM
   if (sodium_init() == -1) {
-    g_log << Logger::Error << "Unable to initialize sodium crypto library" << endl;
+    SLOG(g_log << Logger::Error << "Unable to initialize sodium crypto library" << endl,
+         log->info(Logr::Error, "Unable to initialize sodium crypto library"));
     exit(99);
   }
 #endif
@@ -1663,17 +1708,21 @@ static int serviceMain(int argc, char* argv[])
     char* ns;
     ns = getenv("NOTIFY_SOCKET");
     if (ns != nullptr) {
-      g_log << Logger::Error << "Unable to chroot when running from systemd. Please disable chroot= or set the 'Type' for this service to 'simple'" << endl;
+      SLOG(g_log << Logger::Error << "Unable to chroot when running from systemd. Please disable chroot= or set the 'Type' for this service to 'simple'" << endl,
+           log->info(Logr::Error, "Unable to chroot when running from systemd. Please disable chroot= or set the 'Type' for this service to 'simple'"));
       exit(1);
     }
 #endif
     if (chroot(::arg()["chroot"].c_str()) < 0 || chdir("/") < 0) {
       int err = errno;
-      g_log << Logger::Error << "Unable to chroot to '" + ::arg()["chroot"] + "': " << strerror(err) << ", exiting" << endl;
+      SLOG(g_log << Logger::Error << "Unable to chroot to '" + ::arg()["chroot"] + "': " << strerror(err) << ", exiting" << endl,
+           log->error(Logr::Error, err,  "Unable to chroot", "chroot", Logging::Loggable(::arg()["chroot"])));
       exit(1);
     }
-    else
-      g_log << Logger::Info << "Chrooted to '" << ::arg()["chroot"] << "'" << endl;
+    else {
+      SLOG(g_log << Logger::Info << "Chrooted to '" << ::arg()["chroot"] << "'" << endl,
+           log->info(Logr::Info, "Chrooted", "chroot",  Logging::Loggable(::arg()["chroot"])));
+    }
   }
 
   checkSocketDir();
@@ -1694,7 +1743,8 @@ static int serviceMain(int argc, char* argv[])
     dropCapabilities();
   }
   catch (const std::exception& e) {
-    g_log << Logger::Warning << e.what() << endl;
+    SLOG(g_log << Logger::Warning << e.what() << endl,
+         log->error(Logr::Warning, e.what(), "Could not drop capabilities"));
   }
 
   startLuaConfigDelayedThreads(delayedLuaThreads, g_luaconfs.getCopy().generation);
@@ -1730,13 +1780,15 @@ static int serviceMain(int argc, char* argv[])
 
   int port = ::arg().asNum("udp-source-port-min");
   if (port < 1024 || port > 65535) {
-    g_log << Logger::Error << "Unable to launch, udp-source-port-min is not a valid port number" << endl;
+    SLOG(g_log << Logger::Error << "Unable to launch, udp-source-port-min is not a valid port number" << endl,
+         log->info(Logr::Error, "Unable to launch, udp-source-port-min is not a valid port number"));
     exit(99); // this isn't going to fix itself either
   }
   g_minUdpSourcePort = port;
   port = ::arg().asNum("udp-source-port-max");
   if (port < 1024 || port > 65535 || port < g_minUdpSourcePort) {
-    g_log << Logger::Error << "Unable to launch, udp-source-port-max is not a valid port number or is smaller than udp-source-port-min" << endl;
+    SLOG(g_log << Logger::Error << "Unable to launch, udp-source-port-max is not a valid port number or is smaller than udp-source-port-min" << endl,
+         log->info(Logr::Error, "Unable to launch, udp-source-port-max is not a valid port number or is smaller than udp-source-port-min"));
     exit(99); // this isn't going to fix itself either
   }
   g_maxUdpSourcePort = port;
@@ -1745,13 +1797,14 @@ static int serviceMain(int argc, char* argv[])
   for (const auto& part : parts) {
     port = std::stoi(part);
     if (port < 1024 || port > 65535) {
-      g_log << Logger::Error << "Unable to launch, udp-source-port-avoid contains an invalid port number: " << part << endl;
+      SLOG(g_log << Logger::Error << "Unable to launch, udp-source-port-avoid contains an invalid port number: " << part << endl,
+           log->info(Logr::Error,  "Unable to launch, udp-source-port-avoid contains an invalid port number", "port", Logging::Loggable(part)));
       exit(99); // this isn't going to fix itself either
     }
     g_avoidUdpSourcePorts.insert(port);
   }
 
-  return RecThreadInfo::runThreads();
+  return RecThreadInfo::runThreads(log);
 }
 
 static void handlePipeRequest(int fd, FDMultiplexer::funcparam_t& var)
@@ -2670,21 +2723,21 @@ int main(int argc, char** argv)
     g_recCache = std::make_unique<MemRecursorCache>(::arg().asNum("record-cache-shards"));
     g_negCache = std::make_unique<NegCache>(::arg().asNum("record-cache-shards"));
 
-    ret = serviceMain(argc, argv);
+    ret = serviceMain(argc, argv, startupLog);
   }
   catch (const PDNSException& ae) {
     SLOG(g_log << Logger::Error << "Exception: " << ae.reason << endl,
-         g_slog->withName("startup")->error(Logr::Error, "Exception", ae.reason));
+         g_slog->withName("startup")->error(Logr::Error, ae.reason, "Exception"));
     ret = EXIT_FAILURE;
   }
   catch (const std::exception& e) {
     SLOG(g_log << Logger::Error << "STL Exception: " << e.what() << endl,
-         g_slog->withName("startup")->error(Logr::Error, "STL Exception", e.what()));
+         g_slog->withName("startup")->error(Logr::Error, e.what(), "STL Exception"));
     ret = EXIT_FAILURE;
   }
   catch (...) {
     SLOG(g_log << Logger::Error << "any other exception in main: " << endl,
-         g_slog->withName("startup")->error(Logr::Error, "Exception", "Unexpected"));
+         g_slog->withName("startup")->error(Logr::Error, "Unknown", "Exception"));
     ret = EXIT_FAILURE;
   }
 
index 8a29e825d7b8f20696c527d45d2cc405736f7954..7ee40a64e06eee682fd61a101f642f51cefebeb4 100644 (file)
@@ -27,6 +27,7 @@
 #endif
 
 #include "logger.hh"
+#include "logr.hh"
 #include "lua-recursor4.hh"
 #include "mplexer.hh"
 #include "namespaces.hh"
@@ -445,7 +446,7 @@ public:
     return numHandlers() + numDistributors() + numWorkers() + numTaskThreads();
   }
 
-  static int runThreads();
+  static int runThreads(std::shared_ptr<Logr::Logger>&);
   static void makeThreadPipes();
 
   void setExitCode(int e)
@@ -495,6 +496,7 @@ struct ThreadMSG
   bool wantAnswer;
 };
 
+void parseACLs();
 PacketBuffer GenUDPQueryResponse(const ComboAddress& dest, const string& query);
 bool checkProtobufExport(LocalStateHolder<LuaConfigItems>& luaconfsLocal);
 bool checkOutgoingProtobufExport(LocalStateHolder<LuaConfigItems>& luaconfsLocal);
@@ -523,10 +525,10 @@ bool expectProxyProtocol(const ComboAddress& from);
 void finishTCPReply(std::unique_ptr<DNSComboWriter>& dc, bool hadError, bool updateInFlight);
 void checkFastOpenSysctl(bool active);
 void checkTFOconnect();
-void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets);
+void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets, std::shared_ptr<Logr::Logger>&);
 void handleNewTCPQuestion(int fd, FDMultiplexer::funcparam_t&);
 
-void makeUDPServerSockets(deferredAdd_t& deferredAdds);
+void makeUDPServerSockets(deferredAdd_t& deferredAdds, std::shared_ptr<Logr::Logger>&);
 
 #define LOCAL_NETS "127.0.0.0/8, 10.0.0.0/8, 100.64.0.0/10, 169.254.0.0/16, 192.168.0.0/16, 172.16.0.0/12, ::1/128, fc00::/7, fe80::/10"
 #define LOCAL_NETS_INVERSE "!127.0.0.0/8, !10.0.0.0/8, !100.64.0.0/10, !169.254.0.0/16, !192.168.0.0/16, !172.16.0.0/12, !::1/128, !fc00::/7, !fe80::/10"
index c4723653063ea72ff02f1e7d38db6f00e3921160..96ad1325863ff2c7336c446d10b051340c312831 100644 (file)
@@ -994,7 +994,7 @@ LWResult::Result arecvtcp(PacketBuffer& data, const size_t len, shared_ptr<TCPIO
   return LWResult::Result::Success;
 }
 
-void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets)
+void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets, std::shared_ptr<Logr::Logger>& log)
 {
   int fd;
   vector<string> locals;
@@ -1031,13 +1031,15 @@ void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets
     }
     if (sin.sin6.sin6_family == AF_INET6 && setsockopt(fd, IPPROTO_IPV6, IPV6_V6ONLY, &tmp, sizeof(tmp)) < 0) {
       int err = errno;
-      g_log << Logger::Error << "Failed to set IPv6 socket to IPv6 only, continuing anyhow: " << strerror(err) << endl;
+      SLOG(g_log << Logger::Error << "Failed to set IPv6 socket to IPv6 only, continuing anyhow: " << strerror(err) << endl,
+           log->error(Logr::Error, err, "Failed to set IPv6 socket to IPv6 only, continuing anyhow"));
     }
 
 #ifdef TCP_DEFER_ACCEPT
     if (setsockopt(fd, IPPROTO_TCP, TCP_DEFER_ACCEPT, &tmp, sizeof tmp) >= 0) {
-      if (i == locals.begin())
-        g_log << Logger::Info << "Enabled TCP data-ready filter for (slight) DoS protection" << endl;
+      if (i == locals.begin()) {
+        SLOG(g_log << Logger::Info << "Enabled TCP data-ready filter for (slight) DoS protection" << endl,
+             log->info(Logr::Info, "Enabled TCP data-ready filter for (slight) DoS protection"));
     }
 #endif
 
@@ -1067,10 +1069,12 @@ void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets
 #ifdef TCP_FASTOPEN
       if (setsockopt(fd, IPPROTO_TCP, TCP_FASTOPEN, &SyncRes::s_tcp_fast_open, sizeof SyncRes::s_tcp_fast_open) < 0) {
         int err = errno;
-        g_log << Logger::Error << "Failed to enable TCP Fast Open for listening socket: " << strerror(err) << endl;
+        SLOG(g_log << Logger::Error << "Failed to enable TCP Fast Open for listening socket: " << strerror(err) << endl,
+             log->error(Logr::Error, err, "Failed to enable TCP Fast Open for listening socket"));
       }
 #else
-      g_log << Logger::Warning << "TCP Fast Open configured but not supported for listening socket" << endl;
+      SLOG(g_log << Logger::Warning << "TCP Fast Open configured but not supported for listening socket" << endl,
+           log->info(Logr::Warning, "TCP Fast Open configured but not supported for listening socket"));
 #endif
     }
 
@@ -1084,7 +1088,8 @@ void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets
       setSocketSendBuffer(fd, 65000);
     }
     catch (const std::exception& e) {
-      g_log << Logger::Error << e.what() << endl;
+      SLOG(g_log << Logger::Error << e.what() << endl,
+           log->error(Logr::Error, e.what(), "Exception while setting socket send buffer"));
     }
 
     listen(fd, 128);
@@ -1093,9 +1098,7 @@ void makeTCPServerSockets(deferredAdd_t& deferredAdds, std::set<int>& tcpSockets
 
     // we don't need to update g_listenSocketsAddresses since it doesn't work for TCP/IP:
     //  - fd is not that which we know here, but returned from accept()
-    if (sin.sin4.sin_family == AF_INET)
-      g_log << Logger::Info << "Listening for TCP queries on " << sin.toString() << ":" << st.port << endl;
-    else
-      g_log << Logger::Info << "Listening for TCP queries on [" << sin.toString() << "]:" << st.port << endl;
+    SLOG(g_log << Logger::Info << "Listening for TCP queries on " << sin.toStringWithPort() << endl,
+         log->info(Logr::Info, "Listening for queries", "protocol", Logging::Loggable("TCP"), "address", Logging::Loggable(sin.toStringWithPort())));
   }
 }
index c0770bfdb785698816e0f3ca2660cad6fee55004..f50cec976eb72c78a5dffd3e4dd9afad029e2612 100644 (file)
@@ -146,16 +146,20 @@ bool primeHints(time_t ignored)
         break;
       }
     }
+    auto log = g_slog->withName("config");
     if (SyncRes::s_doIPv4 && !SyncRes::s_doIPv6 && !reachableA) {
-      g_log << Logger::Error << "Running IPv4 only but no IPv4 root hints" << endl;
+      SLOG(g_log << Logger::Error << "Running IPv4 only but no IPv4 root hints" << endl,
+           log->info(Logr::Error, "Running IPv4 only but no IPv4 root hints"));
       return false;
     }
     if (!SyncRes::s_doIPv4 && SyncRes::s_doIPv6 && !reachableAAAA) {
-      g_log << Logger::Error << "Running IPv6 only but no IPv6 root hints" << endl;
+      SLOG(g_log << Logger::Error << "Running IPv6 only but no IPv6 root hints" << endl,
+           log->info(Logr::Error, "Running IPv6 only but no IPv6 root hints"));
       return false;
     }
     if (SyncRes::s_doIPv4 && SyncRes::s_doIPv6 && !reachableA && !reachableAAAA) {
-      g_log << Logger::Error << "No valid root hints" << endl;
+      SLOG(g_log << Logger::Error << "No valid root hints" << endl,
+           log->info(Logr::Error,  "No valid root hints"));
       return false;
     }
   }
@@ -192,7 +196,7 @@ void primeRootNSZones(DNSSECMode mode, unsigned int depth)
   }
 }
 
-static void makeNameToIPZone(std::shared_ptr<SyncRes::domainmap_t> newMap, const DNSName& hostname, const string& ip)
+static void makeNameToIPZone(std::shared_ptr<SyncRes::domainmap_t> newMap, const DNSName& hostname, const string& ip, std::shared_ptr<Logr::Logger>& log)
 {
   SyncRes::AuthDomain ad;
   ad.d_rdForward = false;
@@ -217,17 +221,19 @@ static void makeNameToIPZone(std::shared_ptr<SyncRes::domainmap_t> newMap, const
   ad.d_records.insert(dr);
 
   if (newMap->count(dr.d_name)) {
-    g_log << Logger::Warning << "Hosts file will not overwrite zone '" << dr.d_name << "' already loaded" << endl;
+    SLOG(g_log << Logger::Warning << "Hosts file will not overwrite zone '" << dr.d_name << "' already loaded" << endl,
+         log->info(Logr::Warning, "Hosts file will not overwrite already loaded zone", "zone", Logging::Loggable( dr.d_name)));
   }
   else {
-    g_log << Logger::Warning << "Inserting forward zone '" << dr.d_name << "' based on hosts file" << endl;
+    SLOG(g_log << Logger::Warning << "Inserting forward zone '" << dr.d_name << "' based on hosts file" << endl,
+         log->info(Logr::Warning,  "Inserting forward zone based on hosts file", "zone", Logging::Loggable(dr.d_name)));
     ad.d_name = dr.d_name;
     (*newMap)[ad.d_name] = ad;
   }
 }
 
 //! parts[0] must be an IP address, the rest must be host names
-static void makeIPToNamesZone(std::shared_ptr<SyncRes::domainmap_t> newMap, const vector<string>& parts)
+static void makeIPToNamesZone(std::shared_ptr<SyncRes::domainmap_t> newMap, const vector<string>& parts, std::shared_ptr<Logr::Logger>& log)
 {
   string address = parts[0];
   vector<string> ipparts;
@@ -263,33 +269,55 @@ static void makeIPToNamesZone(std::shared_ptr<SyncRes::domainmap_t> newMap, cons
     }
 
   if (newMap->count(dr.d_name)) {
-    g_log << Logger::Warning << "Will not overwrite zone '" << dr.d_name << "' already loaded" << endl;
+    SLOG(g_log << Logger::Warning << "Will not overwrite zone '" << dr.d_name << "' already loaded" << endl,
+         log->info(Logr::Warning, "Will not overwrite already loaded zone", "zone", Logging::Loggable(dr.d_name)));
   }
   else {
-    if (ipparts.size() == 4)
-      g_log << Logger::Warning << "Inserting reverse zone '" << dr.d_name << "' based on hosts file" << endl;
+    if (ipparts.size() == 4) {
+      SLOG(g_log << Logger::Warning << "Inserting reverse zone '" << dr.d_name << "' based on hosts file" << endl,
+           log->info(Logr::Warning, "Inserting reverse zone based on hosts file", "zone", Logging::Loggable(dr.d_name)));
+    }
     ad.d_name = dr.d_name;
     (*newMap)[ad.d_name] = ad;
   }
 }
 
-static void convertServersForAD(const std::string& input, SyncRes::AuthDomain& ad, const char* sepa, bool verbose = true)
+static void convertServersForAD(const std::string& zone, const std::string& input, SyncRes::AuthDomain& ad, const char* sepa, std::shared_ptr<Logr::Logger>& log, bool verbose = true)
 {
   vector<string> servers;
   stringtok(servers, input, sepa);
   ad.d_servers.clear();
 
+  vector<string> addresses;
   for (vector<string>::const_iterator iter = servers.begin(); iter != servers.end(); ++iter) {
-    if (verbose && iter != servers.begin())
-      g_log << ", ";
-
     ComboAddress addr = parseIPAndPort(*iter, 53);
-    if (verbose)
-      g_log << addr.toStringWithPort();
     ad.d_servers.push_back(addr);
+    if (verbose) {
+      addresses.push_back(addr.toStringWithPort());
+    }
+  }
+  if (verbose) {
+    if (!g_slogStructured) {
+      g_log << Logger::Info << "Redirecting queries for zone '" << zone << "' ";
+      if (ad.d_rdForward) {
+        g_log << "with recursion ";
+      }
+      g_log << "to: ";
+      bool first = true;
+      for (const auto& a : addresses) {
+        if (!first ) {
+          g_log << ", ";
+        } else {
+          first = false;
+        }
+        g_log << a;
+      }
+      g_log << endl;
+    }
+    else {
+      log->info(Logr::Info, "Redirecting queries", "zone", Logging::Loggable(zone), "recursion", Logging::Loggable(ad.d_rdForward), "addresses", Logging::Loggable(addresses));
+    }
   }
-  if (verbose)
-    g_log << endl;
 }
 
 static void* pleaseUseNewSDomainsMap(std::shared_ptr<SyncRes::domainmap_t> newmap)
@@ -301,9 +329,11 @@ static void* pleaseUseNewSDomainsMap(std::shared_ptr<SyncRes::domainmap_t> newma
 string reloadZoneConfiguration()
 {
   std::shared_ptr<SyncRes::domainmap_t> original = SyncRes::getDomainMap();
-
+  auto log = g_slog->withName("config");
+  
   try {
-    g_log << Logger::Warning << "Reloading zones, purging data from cache" << endl;
+    SLOG(g_log << Logger::Warning << "Reloading zones, purging data from cache" << endl,
+         log->info(Logr::Warning, "Reloading zones, purging data from cache"));
 
     string configname = ::arg()["config-dir"] + "/recursor.conf";
     if (::arg()["config-name"] != "") {
@@ -373,20 +403,25 @@ string reloadZoneConfiguration()
     broadcastFunction([ns = newNotifySet] { return pleaseSupplantAllowNotifyFor(ns); });
     return "ok\n";
   }
-  catch (std::exception& e) {
-    g_log << Logger::Error << "Encountered error reloading zones, keeping original data: " << e.what() << endl;
+  catch (const std::exception& e) {
+    SLOG(g_log << Logger::Error << "Encountered error reloading zones, keeping original data: " << e.what() << endl,
+         log->error(Logr::Error, e.what(), "Encountered error reloading zones, keeping original data"));
   }
-  catch (PDNSException& ae) {
-    g_log << Logger::Error << "Encountered error reloading zones, keeping original data: " << ae.reason << endl;
+  catch (const PDNSException& ae) {
+    SLOG(g_log << Logger::Error << "Encountered error reloading zones, keeping original data: " << ae.reason << endl,
+         log->error(Logr::Error, ae.reason, "Encountered error reloading zones, keeping original data"));
   }
   catch (...) {
-    g_log << Logger::Error << "Encountered unknown error reloading zones, keeping original data" << endl;
+    SLOG(g_log << Logger::Error << "Encountered unknown error reloading zones, keeping original data" << endl,
+          log->error(Logr::Error, "Exception", "Encountered error reloading zones, keeping original data"));
   }
   return "reloading failed, see log\n";
 }
 
 std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>> parseZoneConfiguration()
 {
+  auto log = g_slog->withName("config");
+
   TXTRecordContent::report();
   OPTRecordContent::report();
 
@@ -409,7 +444,8 @@ std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>>
       // headers.first=toCanonic("", headers.first);
       if (n == 0) {
         ad.d_rdForward = false;
-        g_log << Logger::Error << "Parsing authoritative data for zone '" << headers.first << "' from file '" << headers.second << "'" << endl;
+        SLOG(g_log << Logger::Error << "Parsing authoritative data for zone '" << headers.first << "' from file '" << headers.second << "'" << endl,
+             log->info(Logr::Error, "Parsing authoritative data from file", "zone", Logging::Loggable(headers.first), "file",  Logging::Loggable(headers.second)));
         ZoneParserTNG zpt(headers.second, DNSName(headers.first));
         zpt.setMaxGenerateSteps(::arg().asNum("max-generate-steps"));
         zpt.setMaxIncludes(::arg().asNum("max-include-depth"));
@@ -431,19 +467,8 @@ std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>>
         }
       }
       else {
-        g_log << Logger::Error << "Redirecting queries for zone '" << headers.first << "' ";
-        if (n == 2) {
-          g_log << "with recursion ";
-          ad.d_rdForward = true;
-        }
-        else
-          ad.d_rdForward = false;
-        g_log << "to: ";
-
-        convertServersForAD(headers.second, ad, ";");
-        if (n == 2) {
-          ad.d_rdForward = true;
-        }
+        ad.d_rdForward = (n == 2);
+        convertServersForAD(headers.first, headers.second, ad, ";", log);
       }
 
       ad.d_name = DNSName(headers.first);
@@ -452,7 +477,8 @@ std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>>
   }
 
   if (!::arg()["forward-zones-file"].empty()) {
-    g_log << Logger::Warning << "Reading zone forwarding information from '" << ::arg()["forward-zones-file"] << "'" << endl;
+    SLOG(g_log << Logger::Warning << "Reading zone forwarding information from '" << ::arg()["forward-zones-file"] << "'" << endl,
+         log->info(Logr::Warning, "Reading zone forwarding information", "file", Logging::Loggable( ::arg()["forward-zones-file"])));
     auto fp = std::unique_ptr<FILE, int (*)(FILE*)>(fopen(::arg()["forward-zones-file"].c_str(), "r"), fclose);
     if (!fp) {
       throw PDNSException("Error opening forward-zones-file '" + ::arg()["forward-zones-file"] + "': " + stringerror());
@@ -497,7 +523,7 @@ std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>>
       }
 
       try {
-        convertServersForAD(instructions, ad, ",; ", false);
+        convertServersForAD(domain, instructions, ad, ",; ", log, false);
       }
       catch (...) {
         throw PDNSException("Conversion error parsing line " + std::to_string(linenum) + " of " + ::arg()["forward-zones-file"]);
@@ -509,7 +535,8 @@ std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>>
         newSet->insert(ad.d_name);
       }
     }
-    g_log << Logger::Warning << "Done parsing " << newMap->size() - before << " forwarding instructions from file '" << ::arg()["forward-zones-file"] << "'" << endl;
+    SLOG(g_log << Logger::Warning << "Done parsing " << newMap->size() - before << " forwarding instructions from file '" << ::arg()["forward-zones-file"] << "'" << endl,
+         log->info(Logr::Warning, "Done parsing forwarding instructions from file", "file", Logging::Loggable(::arg()["forward-zones-file"]), "count",  Logging::Loggable( newMap->size() - before)));
   }
 
   if (::arg().mustDo("export-etc-hosts")) {
@@ -537,32 +564,33 @@ std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>>
 
         for (unsigned int n = 1; n < parts.size(); ++n) {
           if (searchSuffix.empty() || parts[n].find('.') != string::npos)
-            makeNameToIPZone(newMap, DNSName(parts[n]), parts[0]);
+            makeNameToIPZone(newMap, DNSName(parts[n]), parts[0], log);
           else {
             DNSName canonic = toCanonic(DNSName(searchSuffix), parts[n]); /// XXXX DNSName pain
             if (canonic != DNSName(parts[n])) { // XXX further DNSName pain
-              makeNameToIPZone(newMap, canonic, parts[0]);
+              makeNameToIPZone(newMap, canonic, parts[0], log);
             }
           }
         }
-        makeIPToNamesZone(newMap, parts);
+        makeIPToNamesZone(newMap, parts, log);
       }
     }
   }
 
   if (::arg().mustDo("serve-rfc1918")) {
-    g_log << Logger::Warning << "Inserting rfc 1918 private space zones" << endl;
+    SLOG(g_log << Logger::Warning << "Inserting rfc 1918 private space zones" << endl,
+         log->info(Logr::Warning, "Inserting rfc 1918 private space zones"));
     parts.clear();
     parts.push_back("127");
-    makeIPToNamesZone(newMap, parts);
+    makeIPToNamesZone(newMap, parts, log);
     parts[0] = "10";
-    makeIPToNamesZone(newMap, parts);
+    makeIPToNamesZone(newMap, parts, log);
 
     parts[0] = "192.168";
-    makeIPToNamesZone(newMap, parts);
+    makeIPToNamesZone(newMap, parts, log);
     for (int n = 16; n < 32; n++) {
       parts[0] = "172." + std::to_string(n);
-      makeIPToNamesZone(newMap, parts);
+      makeIPToNamesZone(newMap, parts, log);
     }
   }
 
@@ -587,7 +615,8 @@ std::tuple<std::shared_ptr<SyncRes::domainmap_t>, std::shared_ptr<notifyset_t>>
         continue;
       newSet->insert(DNSName(line));
     }
-    g_log << Logger::Warning << "Done parsing " << newSet->size() - before << " NOTIFY-allowed zones from file '" << anff << "'" << endl;
+    SLOG(g_log << Logger::Warning << "Done parsing " << newSet->size() - before << " NOTIFY-allowed zones from file '" << anff << "'" << endl,
+         log->info(Logr::Warning, "Done parsing NOTIFY-allowed zones from file", "file", Logging::Loggable(anff), "count", Logging::Loggable(newSet->size() - before)));
   }
 
   return {newMap, newSet};
index dd54b46ecbdc5496da312e89e3e010dc44ecb62c..b77457d6a7176ffc9bc777612042ee7ca30b4833 100644 (file)
@@ -896,7 +896,6 @@ extern thread_local std::unique_ptr<boost::circular_buffer<pair<DNSName,uint16_t
 extern thread_local std::shared_ptr<NetmaskGroup> t_allowFrom;
 extern thread_local std::shared_ptr<NetmaskGroup> t_allowNotifyFrom;
 string doTraceRegex(vector<string>::const_iterator begin, vector<string>::const_iterator end);
-void parseACLs();
 extern RecursorStats g_stats;
 extern unsigned int g_networkTimeoutMsec;
 extern uint16_t g_outgoingEDNSBufsize;