return !resolvers.empty();
}
-static bool handleSVCResult(const PacketBuffer& answer, const ComboAddress& existingAddr, uint16_t dohSVCKey, ServiceDiscovery::DiscoveredResolverConfig& config)
+static bool handleSVCResult(const Logr::Logger& logger, const PacketBuffer& answer, const ComboAddress& existingAddr, uint16_t dohSVCKey, ServiceDiscovery::DiscoveredResolverConfig& config)
{
std::map<uint16_t, DesignatedResolvers> resolvers;
if (!parseSVCParams(answer, resolvers)) {
- vinfolog("No configuration found in response for backend %s", existingAddr.toStringWithPort());
+ VERBOSESLOG(infolog("No configuration found in response for backend %s", existingAddr.toStringWithPort()),
+ logger.info(Logr::Info, "No configuration found in response"));
return false;
}
continue;
#endif
if (tempConfig.d_dohPath.empty()) {
- vinfolog("Got a DoH upgrade offered for %s but no path, skipping", existingAddr.toStringWithPort());
+ VERBOSESLOG(infolog("Got a DoH upgrade offered for %s but no path, skipping", existingAddr.toStringWithPort()),
+ logger.info(Logr::Info, "Got a DoH upgrade offer but no path, skipping"));
continue;
}
}
return false;
}
-bool ServiceDiscovery::getDiscoveredConfig(const UpgradeableBackend& upgradeableBackend, ServiceDiscovery::DiscoveredResolverConfig& config)
+bool ServiceDiscovery::getDiscoveredConfig(const Logr::Logger& topLogger, const UpgradeableBackend& upgradeableBackend, ServiceDiscovery::DiscoveredResolverConfig& config)
{
const auto verbose = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verbose;
const auto& backend = upgradeableBackend.d_ds;
pw.addOpt(4096, 0, 0);
pw.commit();
+ auto logger = topLogger.withValues("dns.query.id", Logging::Loggable(id), "dns.query.name", Logging::Loggable(s_discoveryDomain), "dns.query.type", Logging::Loggable(QType(s_discoveryType)));
+
uint16_t querySize = static_cast<uint16_t>(packet.size());
const uint8_t sizeBytes[] = {static_cast<uint8_t>(querySize / 256), static_cast<uint8_t>(querySize % 256)};
packet.insert(packet.begin(), sizeBytes, sizeBytes + 2);
auto got = readn2WithTimeout(sock.getHandle(), &responseSize, sizeof(responseSize), remainingTime);
if (got != sizeof(responseSize)) {
if (verbose) {
- warnlog("Error while waiting for the ADD upgrade response size from backend %s: %d", addr.toStringWithPort(), got);
+ SLOG(warnlog("Error while waiting for the ADD upgrade response size from backend %s: %d", addr.toStringWithPort(), got),
+ logger->info(Logr::Warning, "Error while waiting for the ADD upgrade response size from backend", "value", Logging::Loggable(got), "expected", Logging::Loggable(sizeof(responseSize))));
}
return false;
}
got = readn2WithTimeout(sock.getHandle(), packet.data(), packet.size(), remainingTime);
if (got != packet.size()) {
if (verbose) {
- warnlog("Error while waiting for the ADD upgrade response from backend %s: %d", addr.toStringWithPort(), got);
+ SLOG(warnlog("Error while waiting for the ADD upgrade response from backend %s: %d", addr.toStringWithPort(), got),
+ logger->info(Logr::Warning, "Error while waiting for the ADD upgrade response from backend", "value", Logging::Loggable(got), "expected", Logging::Loggable(packet.size())));
}
return false;
}
if (packet.size() <= sizeof(struct dnsheader)) {
if (verbose) {
- warnlog("Too short answer of size %d received from the backend %s", packet.size(), addr.toStringWithPort());
+ SLOG(warnlog("Too short answer of size %d received from the backend %s", packet.size(), addr.toStringWithPort()),
+ logger->info(Logr::Warning, "Too short answer received from the backend", "dns.response.size", Logging::Loggable(packet.size())));
}
return false;
}
memcpy(&d, packet.data(), sizeof(d));
if (d.id != id) {
if (verbose) {
- warnlog("Invalid ID (%d / %d) received from the backend %s", d.id, id, addr.toStringWithPort());
+ SLOG(warnlog("Invalid ID (%d / %d) received from the backend %s", d.id, id, addr.toStringWithPort()),
+ logger->info(Logr::Warning, "Invalid ID received from the backend", "dns.response.id", Logging::Loggable(d.id)));
}
return false;
}
if (d.rcode != RCode::NoError) {
if (verbose) {
- warnlog("Response code '%s' received from the backend %s for '%s'", RCode::to_s(d.rcode), addr.toStringWithPort(), s_discoveryDomain);
+ SLOG(warnlog("Response code '%s' received from the backend %s for '%s'", RCode::to_s(d.rcode), addr.toStringWithPort(), s_discoveryDomain),
+ logger->info(Logr::Warning, "Unexpected response code received from backend", "dns.response.code", Logging::Loggable(RCode::to_s(d.rcode))));
}
return false;
if (ntohs(d.qdcount) != 1) {
if (verbose) {
- warnlog("Invalid answer (qdcount %d) received from the backend %s", ntohs(d.qdcount), addr.toStringWithPort());
+ SLOG(warnlog("Invalid answer (qdcount %d) received from the backend %s", ntohs(d.qdcount), addr.toStringWithPort()),
+ logger->info(Logr::Warning, "Invalid qdcount in answer received from the backend", "dns.response.qdcount", Logging::Loggable(ntohs(d.qdcount))));
}
return false;
}
if (receivedName != s_discoveryDomain || receivedType != s_discoveryType || receivedClass != QClass::IN) {
if (verbose) {
- warnlog("Invalid answer, either the qname (%s / %s), qtype (%s / %s) or qclass (%s / %s) does not match, received from the backend %s", receivedName, s_discoveryDomain, QType(receivedType).toString(), s_discoveryType.toString(), QClass(receivedClass).toString(), QClass::IN.toString(), addr.toStringWithPort());
+ SLOG(warnlog("Invalid answer, either the qname (%s / %s), qtype (%s / %s) or qclass (%s / %s) does not match, received from the backend %s", receivedName, s_discoveryDomain, QType(receivedType).toString(), s_discoveryType.toString(), QClass(receivedClass).toString(), QClass::IN.toString(), addr.toStringWithPort()),
+ logger->info(Logr::Warning, "Response received from the backend doesn't match query", "dns.response.name", Logging::Loggable(receivedName), "dns.response.type", Logging::Loggable(QType(receivedType)), "dns.response.class", Logging::Loggable(receivedClass)));
}
return false;
}
- return handleSVCResult(packet, addr, upgradeableBackend.d_dohKey, config);
+ return handleSVCResult(*logger, packet, addr, upgradeableBackend.d_dohKey, config);
}
catch (const std::exception& e) {
- warnlog("Error while trying to discover backend upgrade for %s: %s", addr.toStringWithPort(), e.what());
+ SLOG(warnlog("Error while trying to discover backend upgrade for %s: %s", addr.toStringWithPort(), e.what()),
+ topLogger.error(Logr::Warning, e.what(), "Error while trying to discover backend upgrade"));
}
catch (...) {
- warnlog("Error while trying to discover backend upgrade for %s", addr.toStringWithPort());
+ SLOG(warnlog("Error while trying to discover backend upgrade for %s", addr.toStringWithPort()),
+ topLogger.info(Logr::Error, "Error while trying to discover backend upgrade"));
}
return false;
}
-static bool checkBackendUsability(std::shared_ptr<DownstreamState>& ds)
+static bool checkBackendUsability(const Logr::Logger& logger, std::shared_ptr<DownstreamState>& ds)
{
try {
Socket sock(ds->d_config.remote.sin4.sin_family, SOCK_STREAM);
return true;
}
catch (const std::exception& e) {
- vinfolog("Exception when trying to use a newly upgraded backend %s (subject %s): %s", ds->getNameWithAddr(), ds->d_config.d_tlsSubjectName, e.what());
+ VERBOSESLOG(infolog("Exception when trying to use a newly upgraded backend %s (subject %s): %s", ds->getNameWithAddr(), ds->d_config.d_tlsSubjectName, e.what()),
+ logger.error(Logr::Info, e.what(), "Exception when trying to use a newly upgraded backend", "tls-subject-name", Logging::Loggable(ds->d_config.d_tlsSubjectName)));
}
catch (...) {
- vinfolog("Exception when trying to use a newly upgraded backend %s (subject %s)", ds->getNameWithAddr(), ds->d_config.d_tlsSubjectName);
+ VERBOSESLOG(infolog("Exception when trying to use a newly upgraded backend %s (subject %s)", ds->getNameWithAddr(), ds->d_config.d_tlsSubjectName),
+ logger.info(Logr::Info, "Exception when trying to use a newly upgraded backend", "tls-subject-name", Logging::Loggable(ds->d_config.d_tlsSubjectName)));
}
return false;
}
-bool ServiceDiscovery::tryToUpgradeBackend(const UpgradeableBackend& backend)
+bool ServiceDiscovery::tryToUpgradeBackend(const Logr::Logger& logger, const UpgradeableBackend& backend)
{
ServiceDiscovery::DiscoveredResolverConfig discoveredConfig;
- vinfolog("Trying to discover configuration for backend %s", backend.d_ds->getNameWithAddr());
- if (!ServiceDiscovery::getDiscoveredConfig(backend, discoveredConfig)) {
+ VERBOSESLOG(infolog("Trying to discover configuration for backend %s", backend.d_ds->getNameWithAddr()),
+ logger.info(Logr::Info, "Trying to discover upgrade configuration for backend"));
+
+ if (!ServiceDiscovery::getDiscoveredConfig(logger, backend, discoveredConfig)) {
return false;
}
auto newServer = std::make_shared<DownstreamState>(std::move(config), std::move(tlsCtx), true);
/* check that we can connect to the backend (including certificate validation */
- if (!checkBackendUsability(newServer)) {
- vinfolog("Failed to use the automatically upgraded server %s, skipping for now", newServer->getNameWithAddr());
+ if (!checkBackendUsability(logger, newServer)) {
+ VERBOSESLOG(infolog("Failed to use the automatically upgraded server %s, skipping for now", newServer->getNameWithAddr()),
+ logger.info(Logr::Info, "Failed to use the automatically upgraded server, skipping for now"));
return false;
}
- infolog("Added automatically upgraded server %s", newServer->getNameWithAddr());
+ SLOG(infolog("Added automatically upgraded server %s", newServer->getNameWithAddr()),
+ logger.info(Logr::Info, "Added automatically upgraded server"));
if (!newServer->d_config.pools.empty()) {
for (const auto& poolName : newServer->d_config.pools) {
return true;
}
catch (const std::exception& e) {
- warnlog("Error when trying to upgrade a discovered backend: %s", e.what());
+ SLOG(warnlog("Error when trying to upgrade a discovered backend: %s", e.what()),
+ logger.error(Logr::Warning, e.what(), "Error when trying to upgrade a discovered backend"));
}
return false;
void ServiceDiscovery::worker()
{
setThreadName("dnsdist/discove");
+ auto logger = dnsdist::logging::getTopLogger()->withName("service-discovery");
+
while (true) {
dnsdist::configuration::refreshLocalRuntimeConfiguration();
time_t now = time(nullptr);
for (auto backendIt = upgradeables.begin(); backendIt != upgradeables.end();) {
auto& backend = *backendIt;
+ auto backendLogger = logger->withValues("backend.name", Logging::Loggable(backend->d_ds->getName()), "backend.address", Logging::Loggable(backend->d_ds->d_config.remote));
+
try {
if (backend->d_nextCheck > now) {
++backendIt;
continue;
}
- auto upgraded = tryToUpgradeBackend(*backend);
+ auto upgraded = tryToUpgradeBackend(*backendLogger, *backend);
if (upgraded) {
upgradedBackends.insert(backend->d_ds);
backendIt = upgradeables.erase(backendIt);
}
}
catch (const std::exception& e) {
- vinfolog("Exception in the Service Discovery thread: %s", e.what());
+ VERBOSESLOG(infolog("Exception in the Service Discovery thread: %s", e.what()),
+ backendLogger->error(Logr::Info, e.what(), "Exception in the Service Discovery thread"));
}
catch (...) {
- vinfolog("Exception in the Service Discovery thread");
+ VERBOSESLOG(infolog("Exception in the Service Discovery thread"),
+ backendLogger->info(Logr::Info, "Exception in the Service Discovery thread"));
}
backend->d_nextCheck = now + backend->d_interval;
#include "lock.hh"
struct DownstreamState;
+namespace Logr
+{
+class Logger;
+}
namespace dnsdist
{
bool keepAfterUpgrade;
};
- static bool getDiscoveredConfig(const UpgradeableBackend& backend, DiscoveredResolverConfig& config);
- static bool tryToUpgradeBackend(const UpgradeableBackend& backend);
+ static bool getDiscoveredConfig(const Logr::Logger& logger, const UpgradeableBackend& backend, DiscoveredResolverConfig& config);
+ static bool tryToUpgradeBackend(const Logr::Logger& logger, const UpgradeableBackend& backend);
static void worker();
query.parsePacket(packet, tcp, now);
if (!query.isValid()) {
- vinfolog("Dropping DNSCrypt invalid query");
+ VERBOSESLOG(infolog("Dropping DNSCrypt invalid query"),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "Dropping DNSCrypt invalid query"));
return false;
}
}
}
catch (const std::exception& e) {
- vinfolog("Unable to insert eBPF dynamic block for %s, falling back to regular dynamic block: %s", requestor.toString(), e.what());
+ VERBOSESLOG(infolog("Unable to insert eBPF dynamic block for %s, falling back to regular dynamic block: %s", requestor.toString(), e.what()),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->error(Logr::Info, e.what(), "Unable to insert eBPF dynamic block, falling back to regular dynamic block", "client.address", Logging::Loggable(requestor)));
}
}
if (!beQuiet) {
- warnlog("Inserting %s%sdynamic block for %s for %d seconds: %s", dblock.warning ? "(warning) " : "", bpf ? "eBPF " : "", requestor.toString(), dblock.until.tv_sec - now.tv_sec, dblock.reason);
+ SLOG(warnlog("Inserting %s%sdynamic block for %s for %d seconds: %s", dblock.warning ? "(warning) " : "", bpf ? "eBPF " : "", requestor.toString(), dblock.until.tv_sec - now.tv_sec, dblock.reason),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->info(Logr::Warning, "Inserting dynamic rule", "dynamic_rule.warning_rule", Logging::Loggable(dblock.warning), "client.address", Logging::Loggable(requestor), "dynamic_rule.use_bpf", Logging::Loggable(bpf), "dyanmic_rule.reason", Logging::Loggable(dblock.reason), "dynamic_rule.duration", Logging::Loggable(dblock.until.tv_sec - now.tv_sec)));
}
}
dblock.blocks = count;
if (!beQuiet && (got == nullptr || expired)) {
- warnlog("Inserting dynamic block for %s for %d seconds: %s", dblock.domain, dblock.until.tv_sec - now.tv_sec, dblock.reason);
+ SLOG(warnlog("Inserting dynamic block for %s for %d seconds: %s", dblock.domain, dblock.until.tv_sec - now.tv_sec, dblock.reason),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->info(Logr::Warning, "Inserting dynamic rule", "dynamic_rule.warning_rule", Logging::Loggable(false), "dns.query.name", Logging::Loggable(dblock.domain), "dynamic_rule.use_bpf", Logging::Loggable(false), "dyanmic_rule.reason", Logging::Loggable(dblock.reason), "dynamic_rule.duration", Logging::Loggable(dblock.until.tv_sec - now.tv_sec)));
}
+
auto domain = dblock.domain;
blocks.add(domain, std::move(dblock));
return true;
d_newBlockHook(dnsdist_ffi_dynamic_block_type_nmt, requestor.toString().c_str(), rule.d_blockReason.c_str(), static_cast<uint8_t>(rule.d_action), rule.d_blockDuration, warning);
}
catch (const std::exception& exp) {
- warnlog("Error calling the Lua hook after a dynamic block insertion: %s", exp.what());
+ SLOG(warnlog("Error calling the Lua hook after a dynamic block insertion: %s", exp.what()),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->error(Logr::Warning, exp.what(), "Error calling the Lua hook after a dynamic rule insertion"));
}
}
}
d_newBlockHook(dnsdist_ffi_dynamic_block_type_smt, name.toString().c_str(), rule.d_blockReason.c_str(), static_cast<uint8_t>(rule.d_action), rule.d_blockDuration, false);
}
catch (const std::exception& exp) {
- warnlog("Error calling the Lua hook after a dynamic block insertion: %s", exp.what());
+ SLOG(warnlog("Error calling the Lua hook after a dynamic block insertion: %s", exp.what()),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->error(Logr::Warning, exp.what(), "Error calling the Lua hook after a suffix-based dynamic rule insertion"));
}
}
}
bpfBlocked += g_defaultBPFFilter->getHits(network);
}
catch (const std::exception& e) {
- vinfolog("Error while getting block count before removing eBPF dynamic block for %s: %s", entry.first.toString(), e.what());
+ VERBOSESLOG(infolog("Error while getting block count before removing eBPF dynamic block for %s: %s", entry.first.toString(), e.what()),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->error(Logr::Info, e.what(), "Error while getting block count before removing eBPF dynamic block", "dynamic_rule.key", Logging::Loggable(entry.first)));
}
+
try {
g_defaultBPFFilter->unblock(network);
}
catch (const std::exception& e) {
- vinfolog("Error while removing eBPF dynamic block for %s: %s", entry.first.toString(), e.what());
+ VERBOSESLOG(infolog("Error while removing eBPF dynamic block for %s: %s", entry.first.toString(), e.what()),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->error(Logr::Info, e.what(), "Error while removing eBPF dynamic block", "dynamic_rule.key", Logging::Loggable(entry.first)));
}
}
}
}
}
catch (const std::exception& e) {
- warnlog("Error in the dynamic block maintenance thread: %s", e.what());
+ SLOG(warnlog("Error in the dynamic block maintenance thread: %s", e.what()),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->error(Logr::Warning, e.what(), "Error in the dynamic block maintenance thread"));
}
catch (...) {
- vinfolog("Unhandled error in the dynamic block maintenance thread");
+ VERBOSESLOG(infolog("Unhandled error in the dynamic block maintenance thread"),
+ dnsdist::logging::getTopLogger()->withName("dynamic-rules")->info(Logr::Info, "Unhandled error in the dynamic block maintenance thread"));
}
}
}
}
}
+
+static std::shared_ptr<Logr::Logger> getLoggerFromData(const std::shared_ptr<const HealthCheckData>& data)
+{
+ const auto& downstream = data->d_ds;
+ return dnsdist::logging::getTopLogger()->withName("backend-health-check")->withValues("health_check.proto", Logging::Loggable(downstream->doHealthcheckOverTCP() ? (data->d_tcpHandler->isTLS() ? "DoT" : "tcp") : "udp"), "backend.name", Logging::Loggable(downstream->getName()), "backend.address", Logging::Loggable(downstream->d_config.remote), "dns.query.id", Logging::Loggable(data->d_queryID), "dns.query.name", Logging::Loggable(data->d_checkName), "dns.query.type", Logging::Loggable(QType(data->d_checkType)), "dns.query.class", Logging::Loggable(data->d_checkClass));
+}
+
static bool handleResponse(std::shared_ptr<HealthCheckData>& data)
{
- const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
const auto& downstream = data->d_ds;
+ std::shared_ptr<Logr::Logger> logger;
+ const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
+ if (verboseHealthChecks) {
+ logger = getLoggerFromData(data);
+ }
+
try {
if (data->d_buffer.size() < sizeof(dnsheader)) {
++data->d_ds->d_healthCheckMetrics.d_parseErrors;
if (verboseHealthChecks) {
- infolog("Invalid health check response of size %d from backend %s, expecting at least %d", data->d_buffer.size(), downstream->getNameWithAddr(), sizeof(dnsheader));
+ SLOG(infolog("Invalid health check response of size %d from backend %s, expecting at least %d", data->d_buffer.size(), downstream->getNameWithAddr(), sizeof(dnsheader)),
+ logger->info(Logr::Info, "Invalid health check response", "dns.response.size", Logging::Loggable(data->d_buffer.size())));
}
return false;
}
if (responseHeader.get()->id != data->d_queryID) {
++data->d_ds->d_healthCheckMetrics.d_mismatchErrors;
if (verboseHealthChecks) {
- infolog("Invalid health check response id %d from backend %s, expecting %d", responseHeader.get()->id, downstream->getNameWithAddr(), data->d_queryID);
+ SLOG(infolog("Invalid health check response id %d from backend %s, expecting %d", responseHeader.get()->id, downstream->getNameWithAddr(), data->d_queryID),
+ logger->info(Logr::Info, "Invalid health check response id", "dns.response.id", Logging::Loggable(responseHeader.get()->id)));
}
return false;
}
if (!responseHeader.get()->qr) {
++data->d_ds->d_healthCheckMetrics.d_invalidResponseErrors;
if (verboseHealthChecks) {
- infolog("Invalid health check response from backend %s, expecting QR to be set", downstream->getNameWithAddr());
+ SLOG(infolog("Invalid health check response from backend %s, expecting QR to be set", downstream->getNameWithAddr()),
+ logger->info(Logr::Info, "Invalid health check response, expecting the QR bit to be set"));
}
return false;
}
if (responseHeader.get()->rcode == RCode::ServFail) {
++data->d_ds->d_healthCheckMetrics.d_invalidResponseErrors;
if (verboseHealthChecks) {
- infolog("Backend %s responded to health check with ServFail", downstream->getNameWithAddr());
+ SLOG(infolog("Backend %s responded to health check with ServFail", downstream->getNameWithAddr()),
+ logger->info(Logr::Info, "Backend responded to health check with ServFail", "dns.response.rcode", Logging::Loggable(RCode::to_s(responseHeader.get()->rcode))));
}
return false;
}
if (downstream->d_config.mustResolve && (responseHeader.get()->rcode == RCode::NXDomain || responseHeader.get()->rcode == RCode::Refused)) {
++data->d_ds->d_healthCheckMetrics.d_invalidResponseErrors;
if (verboseHealthChecks) {
- infolog("Backend %s responded to health check with %s while mustResolve is set", downstream->getNameWithAddr(), responseHeader.get()->rcode == RCode::NXDomain ? "NXDomain" : "Refused");
+ SLOG(infolog("Backend %s responded to health check with %s while mustResolve is set", downstream->getNameWithAddr(), responseHeader.get()->rcode == RCode::NXDomain ? "NXDomain" : "Refused"),
+ logger->info(Logr::Info, "Backend responded to health check with an invalid code while mustResolve is set", "dns.response.rcode", Logging::Loggable(RCode::to_s(responseHeader.get()->rcode))));
}
return false;
}
if (receivedName != data->d_checkName || receivedType != data->d_checkType || receivedClass != data->d_checkClass) {
++data->d_ds->d_healthCheckMetrics.d_mismatchErrors;
if (verboseHealthChecks) {
- infolog("Backend %s responded to health check with an invalid qname (%s vs %s), qtype (%s vs %s) or qclass (%d vs %d)", downstream->getNameWithAddr(), receivedName.toLogString(), data->d_checkName.toLogString(), QType(receivedType).toString(), QType(data->d_checkType).toString(), receivedClass, data->d_checkClass);
+ SLOG(infolog("Backend %s responded to health check with an invalid qname (%s vs %s), qtype (%s vs %s) or qclass (%d vs %d)", downstream->getNameWithAddr(), receivedName.toLogString(), data->d_checkName.toLogString(), QType(receivedType).toString(), QType(data->d_checkType).toString(), receivedClass, data->d_checkClass),
+ logger->info(Logr::Info, "Backend responded to health check with an invalid qname, qtype or qclass", "dns.response.name", Logging::Loggable(receivedName), "dns.response.qtype", Logging::Loggable(QType(receivedType)), "dns.response.class", Logging::Loggable(QClass(receivedClass))));
}
return false;
}
catch (const std::exception& e) {
++data->d_ds->d_healthCheckMetrics.d_parseErrors;
if (verboseHealthChecks) {
- infolog("Error checking the health of backend %s: %s", downstream->getNameWithAddr(), e.what());
+ SLOG(infolog("Error checking the health of backend %s: %s", downstream->getNameWithAddr(), e.what()),
+ logger->error(Logr::Info, e.what(), "Error checking the health of backend"));
}
return false;
}
catch (...) {
if (verboseHealthChecks) {
- infolog("Unknown exception while checking the health of backend %s", downstream->getNameWithAddr());
+ SLOG(infolog("Unknown exception while checking the health of backend %s", downstream->getNameWithAddr()),
+ logger->info(Logr::Info, "Unknown exception while checking the health of backend"));
}
return false;
}
static void healthCheckUDPCallback(int descriptor, FDMultiplexer::funcparam_t& param)
{
auto data = boost::any_cast<std::shared_ptr<HealthCheckData>>(param);
+ std::shared_ptr<Logr::Logger> logger;
const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
+ if (verboseHealthChecks) {
+ logger = getLoggerFromData(data);
+ }
ssize_t got = 0;
ComboAddress from;
}
if (verboseHealthChecks) {
- infolog("Error receiving health check response from %s: %s", data->d_ds->d_config.remote.toStringWithPort(), stringerror(savederrno));
+ SLOG(infolog("Error receiving health check response from %s: %s", data->d_ds->d_config.remote.toStringWithPort(), stringerror(savederrno)),
+ logger->error(Logr::Info, savederrno, "Error receiving health check response"));
}
++data->d_ds->d_healthCheckMetrics.d_networkErrors;
data->d_ds->submitHealthCheckResult(data->d_initial, false);
/* we are using a connected socket but hey.. */
if (from != data->d_ds->d_config.remote) {
if (verboseHealthChecks) {
- infolog("Invalid health check response received from %s, expecting one from %s", from.toStringWithPort(), data->d_ds->d_config.remote.toStringWithPort());
+ SLOG(infolog("Invalid health check response received from %s, expecting one from %s", from.toStringWithPort(), data->d_ds->d_config.remote.toStringWithPort()),
+ logger->info(Logr::Info, "Invalid health check response received from the wrong address", "network.peer.address", Logging::Loggable(from)));
}
++data->d_ds->d_healthCheckMetrics.d_networkErrors;
data->d_ds->submitHealthCheckResult(data->d_initial, false);
{
(void)descriptor;
auto data = boost::any_cast<std::shared_ptr<HealthCheckData>>(param);
+ std::shared_ptr<Logr::Logger> logger;
+ const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
+ if (verboseHealthChecks) {
+ logger = getLoggerFromData(data);
+ }
IOStateGuard ioGuard(data->d_ioState);
try {
}
}
catch (const std::exception& e) {
- vinfolog("Unable to get a TLS session from the DoT healthcheck: %s", e.what());
+ VERBOSESLOG(infolog("Unable to get a TLS session from the DoT healthcheck: %s", e.what()),
+ logger->error(Logr::Info, e.what(), "Unable to get a TLS session from the DoT healthcheck"));
}
}
}
catch (const std::exception& e) {
++data->d_ds->d_healthCheckMetrics.d_networkErrors;
data->d_ds->submitHealthCheckResult(data->d_initial, false);
- const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
if (verboseHealthChecks) {
- infolog("Error checking the health of backend %s: %s", data->d_ds->getNameWithAddr(), e.what());
+ SLOG(infolog("Error checking the health of backend %s: %s", data->d_ds->getNameWithAddr(), e.what()),
+ logger->error(Logr::Info, e.what(), "Error checking the health of backend"));
}
}
catch (...) {
data->d_ds->submitHealthCheckResult(data->d_initial, false);
- const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
if (verboseHealthChecks) {
- infolog("Unknown exception while checking the health of backend %s", data->d_ds->getNameWithAddr());
+ SLOG(infolog("Unknown exception while checking the health of backend %s", data->d_ds->getNameWithAddr()),
+ logger->info(Logr::Info, "Unknown exception while checking the health of backend"));
}
}
}
bool queueHealthCheck(std::unique_ptr<FDMultiplexer>& mplexer, const std::shared_ptr<DownstreamState>& downstream, bool initialCheck)
{
const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
+ std::shared_ptr<Logr::Logger> logger;
+ if (verboseHealthChecks) {
+ logger = dnsdist::logging::getTopLogger()->withName("backend-health-check")->withValues("backend.name", Logging::Loggable(downstream->getName()), "backend.address", Logging::Loggable(downstream->d_config.remote));
+ }
+
try {
uint16_t queryID = dnsdist::getRandomDNSID();
DNSName checkName = downstream->d_config.checkName;
if (!downstream->d_config.sourceItfName.empty()) {
int res = setsockopt(sock.getHandle(), SOL_SOCKET, SO_BINDTODEVICE, downstream->d_config.sourceItfName.c_str(), downstream->d_config.sourceItfName.length());
if (res != 0 && verboseHealthChecks) {
- infolog("Error setting SO_BINDTODEVICE on the health check socket for backend '%s': %s", downstream->getNameWithAddr(), stringerror());
+ int savederror = errno;
+ SLOG(infolog("Error setting SO_BINDTODEVICE on the health check socket for backend '%s': %s", downstream->getNameWithAddr(), stringerror(savederror)),
+ logger->error(Logr::Info, savederror, "Error setting SO_BINDTODEVICE on the health check socket for backend"));
}
}
#endif
if (sent < 0) {
int ret = errno;
if (verboseHealthChecks) {
- infolog("Error while sending a health check query (ID %d) to backend %s: %d", queryID, downstream->getNameWithAddr(), ret);
+ SLOG(infolog("Error while sending a health check query (ID %d) to backend %s: %d", queryID, downstream->getNameWithAddr(), ret),
+ logger->error(Logr::Info, ret, "Error while sending a health check query to backend", "dns.query.id", Logging::Loggable(queryID)));
}
return false;
}
}
}
catch (const std::exception& e) {
- vinfolog("Unable to restore a TLS session for the DoT healthcheck for backend %s: %s", downstream->getNameWithAddr(), e.what());
+ VERBOSESLOG(infolog("Unable to restore a TLS session for the DoT healthcheck for backend %s: %s", downstream->getNameWithAddr(), e.what()),
+ logger->error(Logr::Info, e.what(), "Unable to restore a TLS session for the DoT healthcheck"));
}
}
data->d_tcpHandler->tryConnect(downstream->d_config.tcpFastOpen, downstream->d_config.remote);
}
catch (const std::exception& e) {
if (verboseHealthChecks) {
- infolog("Error checking the health of backend %s: %s", downstream->getNameWithAddr(), e.what());
+ SLOG(infolog("Error checking the health of backend %s: %s", downstream->getNameWithAddr(), e.what()),
+ logger->error(Logr::Info, e.what(), "Error checking the health of backend"));
}
return false;
}
catch (...) {
if (verboseHealthChecks) {
- infolog("Unknown exception while checking the health of backend %s", downstream->getNameWithAddr());
+ SLOG(infolog("Unknown exception while checking the health of backend %s", downstream->getNameWithAddr()),
+ logger->info(Logr::Info, "Unknown exception while checking the health of backend"));
}
return false;
}
void handleQueuedHealthChecks(FDMultiplexer& mplexer, bool initial)
{
const auto verboseHealthChecks = dnsdist::configuration::getCurrentRuntimeConfiguration().d_verboseHealthChecks;
+ std::shared_ptr<Logr::Logger> logger;
+ if (verboseHealthChecks) {
+ logger = dnsdist::logging::getTopLogger()->withName("backend-health-check");
+ }
+
while (mplexer.getWatchedFDCount(false) > 0 || mplexer.getWatchedFDCount(true) > 0) {
struct timeval now{};
int ret = mplexer.run(&now, 100);
if (ret == -1) {
if (verboseHealthChecks) {
- infolog("Error while waiting for the health check response from backends: %d", ret);
+ SLOG(infolog("Error while waiting for the health check response from backends: %d", ret),
+ logger->error(Logr::Info, ret, "Error while waiting for the health check response from backends"));
}
break;
}
}
auto data = boost::any_cast<std::shared_ptr<HealthCheckData>>(timeout.second);
+ std::shared_ptr<Logr::Logger> queryLogger;
+ if (verboseHealthChecks) {
+ queryLogger = getLoggerFromData(data);
+ }
+
try {
/* UDP does not have an IO state, H2 is handled separately */
if (data->d_ioState) {
else {
mplexer.removeReadFD(timeout.first);
}
+
if (verboseHealthChecks) {
- infolog("Timeout while waiting for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
+ SLOG(infolog("Timeout while waiting for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr()),
+ queryLogger->info(Logr::Info, "Timeout while waiting for the health check response from backend"));
}
++data->d_ds->d_healthCheckMetrics.d_timeOuts;
there for us to reach that code, and the submission code should not throw,
but let's provide a nice error message if it ever does. */
if (verboseHealthChecks) {
- infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s: %s", data->d_queryID, data->d_ds->getNameWithAddr(), e.what());
+ SLOG(infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s: %s", data->d_queryID, data->d_ds->getNameWithAddr(), e.what()),
+ queryLogger->error(Logr::Info, e.what(), "Error while dealing with a timeout for the health check response from backend"));
}
}
catch (...) {
/* this is even less likely to happen */
if (verboseHealthChecks) {
- infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
+ SLOG(infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr()),
+ queryLogger->info(Logr::Info, "Error while dealing with a timeout for the health check response from backend"));
}
}
}
continue;
}
auto data = boost::any_cast<std::shared_ptr<HealthCheckData>>(timeout.second);
+ std::shared_ptr<Logr::Logger> queryLogger;
+ if (verboseHealthChecks) {
+ queryLogger = getLoggerFromData(data);
+ }
try {
/* UDP does not block while writing, H2 is handled separately */
data->d_ioState.reset();
if (verboseHealthChecks) {
- infolog("Timeout while waiting for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
+ SLOG(infolog("Timeout while waiting for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr()),
+ queryLogger->info(Logr::Info, "Timeout while waiting for the health check response from backend"));
}
++data->d_ds->d_healthCheckMetrics.d_timeOuts;
/* this is not supposed to happen as the submission code should not throw,
but let's provide a nice error message if it ever does. */
if (verboseHealthChecks) {
- infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s: %s", data->d_queryID, data->d_ds->getNameWithAddr(), e.what());
+ SLOG(infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s: %s", data->d_queryID, data->d_ds->getNameWithAddr(), e.what()),
+ queryLogger->error(Logr::Info, e.what(), "Error while dealing with a timeout for the health check response for backend"));
}
}
catch (...) {
/* this is even less likely to happen */
if (verboseHealthChecks) {
- infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
+ SLOG(infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr()),
+ queryLogger->info(Logr::Info, "Error while dealing with a timeout for the health check response from backend"));
}
}
}
projects / thirdparty / pdns.git / commitdiff
