ext/json11/json11.cpp \
ext/json11/json11.hpp \
fuzz_dnsdistcache.cc \
+ gettime.cc gettime.hh \
iputils.cc iputils.hh \
logging.cc logging.hh \
misc.cc misc.hh \
return result;
}
catch (const std::exception& e) {
- warnlog("LuaAction failed inside Lua, returning ServFail: %s", e.what());
+ SLOG(warnlog("LuaAction failed inside Lua, returning ServFail: %s", e.what()),
+ dnsquestion->getLogger()->error(Logr::Warning, e.what(), "LuaAction failed inside Lua, returning ServFail"));
}
catch (...) {
- warnlog("LuaAction failed inside Lua, returning ServFail: [unknown exception]");
+ SLOG(warnlog("LuaAction failed inside Lua, returning ServFail: [unknown exception]"),
+ dnsquestion->getLogger()->error(Logr::Warning, "[unknown exception]", "LuaAction failed inside Lua, returning ServFail"));
}
return DNSAction::Action::ServFail;
}
return result;
}
catch (const std::exception& e) {
- warnlog("LuaResponseAction failed inside Lua, returning ServFail: %s", e.what());
+ SLOG(warnlog("LuaResponseAction failed inside Lua, returning ServFail: %s", e.what()),
+ response->getLogger()->error(Logr::Warning, e.what(), "LuaResponseAction failed inside Lua, returning ServFail"));
}
catch (...) {
- warnlog("LuaResponseAction failed inside Lua, returning ServFail: [unknown exception]");
+ SLOG(warnlog("LuaResponseAction failed inside Lua, returning ServFail: [unknown exception]"),
+ response->getLogger()->error(Logr::Warning, "[unknown exception]", "LuaResponseAction failed inside Lua, returning ServFail"));
}
return DNSResponseAction::Action::ServFail;
}
return result;
}
catch (const std::exception& e) {
- warnlog("LuaFFIAction failed inside Lua, returning ServFail: %s", e.what());
+ SLOG(warnlog("LuaFFIAction failed inside Lua, returning ServFail: %s", e.what()),
+ dnsquestion->getLogger()->error(Logr::Warning, e.what(), "LuaFFIAction failed inside Lua, returning ServFail"));
}
catch (...) {
- warnlog("LuaFFIAction failed inside Lua, returning ServFail: [unknown exception]");
+ SLOG(warnlog("LuaFFIAction failed inside Lua, returning ServFail: [unknown exception]"),
+ dnsquestion->getLogger()->error(Logr::Warning, "[unknown exception]", "LuaFFIAction failed inside Lua, returning ServFail"));
}
return DNSAction::Action::ServFail;
}
return static_cast<DNSAction::Action>(ret);
}
catch (const std::exception& e) {
- warnlog("LuaFFIPerThreadAction failed inside Lua, returning ServFail: %s", e.what());
+ SLOG(warnlog("LuaFFIPerthreadAction failed inside Lua, returning ServFail: %s", e.what()),
+ dnsquestion->getLogger()->error(Logr::Warning, e.what(), "LuaFFIPerthreadAction failed inside Lua, returning ServFail"));
}
catch (...) {
- warnlog("LuaFFIPerthreadAction failed inside Lua, returning ServFail: [unknown exception]");
+ SLOG(warnlog("LuaFFIPerthreadAction failed inside Lua, returning ServFail: [unknown exception]"),
+ dnsquestion->getLogger()->error(Logr::Warning, "[unknown exception]", "LuaFFIPerthreadAction failed inside Lua, returning ServFail"));
}
return DNSAction::Action::ServFail;
}
return result;
}
catch (const std::exception& e) {
- warnlog("LuaFFIResponseAction failed inside Lua, returning ServFail: %s", e.what());
+ SLOG(warnlog("LuaFFIResponseAction failed inside Lua, returning ServFail: %s", e.what()),
+ response->getLogger()->error(Logr::Warning, e.what(), "LuaFFIResponseAction failed inside Lua, returning ServFail"));
}
catch (...) {
- warnlog("LuaFFIResponseAction failed inside Lua, returning ServFail: [unknown exception]");
+ SLOG(warnlog("LuaFFIResponseAction failed inside Lua, returning ServFail: [unknown exception]"),
+ response->getLogger()->error(Logr::Warning, "[unknown exception]", "LuaFFIResponseAction failed inside Lua, returning ServFail"));
}
return DNSResponseAction::Action::ServFail;
}
return static_cast<DNSResponseAction::Action>(ret);
}
catch (const std::exception& e) {
- warnlog("LuaFFIPerThreadResponseAction failed inside Lua, returning ServFail: %s", e.what());
+ SLOG(warnlog("LuaFFIPerThreadResponseAction failed inside Lua, returning ServFail: %s", e.what()),
+ response->getLogger()->error(Logr::Warning, e.what(), "LuaFFIPerThreadResponseAction failed inside Lua, returning ServFail"));
}
catch (...) {
- warnlog("LuaFFIPerthreadResponseAction failed inside Lua, returning ServFail: [unknown exception]");
+ SLOG(warnlog("LuaFFIPerThreadResponseAction failed inside Lua, returning ServFail: [unknown exception]"),
+ response->getLogger()->error(Logr::Warning, "[unknown exception]", "LuaFFIPerThreadResponseAction failed inside Lua, returning ServFail"));
}
return DNSResponseAction::Action::ServFail;
}
if (!filepointer) {
if (!d_verboseOnly || dnsdist::configuration::getCurrentRuntimeConfiguration().d_verbose) {
if (d_includeTimestamp) {
- infolog("[%u.%u] Packet from %s for %s %s with id %d", static_cast<unsigned long long>(dnsquestion->getQueryRealTime().tv_sec), static_cast<unsigned long>(dnsquestion->getQueryRealTime().tv_nsec), dnsquestion->ids.origRemote.toStringWithPort(), dnsquestion->ids.qname.toString(), QType(dnsquestion->ids.qtype).toString(), dnsquestion->getHeader()->id);
+ SLOG(infolog("[%u.%u] Packet from %s for %s %s with id %d", static_cast<unsigned long long>(dnsquestion->getQueryRealTime().tv_sec), static_cast<unsigned long>(dnsquestion->getQueryRealTime().tv_nsec), dnsquestion->ids.origRemote.toStringWithPort(), dnsquestion->ids.qname.toString(), QType(dnsquestion->ids.qtype).toString(), dnsquestion->getHeader()->id),
+ dnsquestion->getLogger()->info(Logr::Info, "Logging packet", "query-real-time-sec", Logging::Loggable(dnsquestion->getQueryRealTime().tv_sec), "query-real-time-nsec", Logging::Loggable(dnsquestion->getQueryRealTime().tv_nsec)));
}
else {
- infolog("Packet from %s for %s %s with id %d", dnsquestion->ids.origRemote.toStringWithPort(), dnsquestion->ids.qname.toString(), QType(dnsquestion->ids.qtype).toString(), dnsquestion->getHeader()->id);
+ SLOG(infolog("Packet from %s for %s %s with id %d", dnsquestion->ids.origRemote.toStringWithPort(), dnsquestion->ids.qname.toString(), QType(dnsquestion->ids.qtype).toString(), dnsquestion->getHeader()->id),
+ dnsquestion->getLogger()->info(Logr::Info, "Logging packet"));
}
}
}
void reload() override
{
if (!reopenLogFile()) {
- warnlog("Unable to open file '%s' for logging: %s", d_fname, stringerror());
+ int savederrno = errno;
+ SLOG(warnlog("Unable to open file '%s' for logging: %s", d_fname, stringerror(savederrno)),
+ dnsdist::logging::getTopLogger()->error(Logr::Warning, savederrno, "Unable to open file for logging", "file-name", Logging::Loggable(d_fname)));
}
}
if (!filepointer) {
if (!d_verboseOnly || dnsdist::configuration::getCurrentRuntimeConfiguration().d_verbose) {
if (d_includeTimestamp) {
- infolog("[%u.%u] Answer to %s for %s %s (%s) with id %u", static_cast<unsigned long long>(response->getQueryRealTime().tv_sec), static_cast<unsigned long>(response->getQueryRealTime().tv_nsec), response->ids.origRemote.toStringWithPort(), response->ids.qname.toString(), QType(response->ids.qtype).toString(), RCode::to_s(response->getHeader()->rcode), response->getHeader()->id);
+ SLOG(infolog("[%u.%u] Answer to %s for %s %s (%s) with id %u", static_cast<unsigned long long>(response->getQueryRealTime().tv_sec), static_cast<unsigned long>(response->getQueryRealTime().tv_nsec), response->ids.origRemote.toStringWithPort(), response->ids.qname.toString(), QType(response->ids.qtype).toString(), RCode::to_s(response->getHeader()->rcode), response->getHeader()->id),
+ response->getLogger()->info(Logr::Info, "Logging response packet", "query-real-time-sec", Logging::Loggable(response->getQueryRealTime().tv_sec), "query-real-time-nsec", Logging::Loggable(response->getQueryRealTime().tv_nsec)));
}
else {
- infolog("Answer to %s for %s %s (%s) with id %u", response->ids.origRemote.toStringWithPort(), response->ids.qname.toString(), QType(response->ids.qtype).toString(), RCode::to_s(response->getHeader()->rcode), response->getHeader()->id);
+ SLOG(infolog("Answer to %s for %s %s (%s) with id %u", response->ids.origRemote.toStringWithPort(), response->ids.qname.toString(), QType(response->ids.qtype).toString(), RCode::to_s(response->getHeader()->rcode), response->getHeader()->id),
+ response->getLogger()->info("Logging response packet"));
}
}
}
void reload() override
{
if (!reopenLogFile()) {
- warnlog("Unable to open file '%s' for logging: %s", d_fname, stringerror());
+ int savederrno = errno;
+ SLOG(warnlog("Unable to open file '%s' for logging: %s", d_fname, stringerror(savederrno)),
+ dnsdist::logging::getTopLogger()->error(Logr::Warning, savederrno, "Unable to open file for logging", "file-name", Logging::Loggable(d_fname)));
}
}
case RemoteLoggerInterface::Result::Queued:
break;
case RemoteLoggerInterface::Result::PipeFull: {
- vinfolog("%s: %s", remoteLogger.name(), RemoteLoggerInterface::toErrorString(ret));
+ VERBOSESLOG(infolog("%s: %s", remoteLogger.name(), RemoteLoggerInterface::toErrorString(ret)),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, RemoteLoggerInterface::toErrorString(ret), "Remote logger pipe full event", "remote-logger-name", Logging::Loggable(remoteLogger.name())));
break;
}
case RemoteLoggerInterface::Result::TooLarge: {
- warnlog("%s: %s", remoteLogger.name(), RemoteLoggerInterface::toErrorString(ret));
+ SLOG(warnlog("%s: %s", remoteLogger.name(), RemoteLoggerInterface::toErrorString(ret)),
+ dnsdist::logging::getTopLogger()->error(Logr::Warning, RemoteLoggerInterface::toErrorString(ret), "Remote logger too large event", "remote-logger-name", Logging::Loggable(remoteLogger.name())));
break;
}
case RemoteLoggerInterface::Result::OtherError:
- warnlog("%s: %s", remoteLogger.name(), RemoteLoggerInterface::toErrorString(ret));
+ SLOG(warnlog("%s: %s", remoteLogger.name(), RemoteLoggerInterface::toErrorString(ret)),
+ dnsdist::logging::getTopLogger()->error(Logr::Warning, RemoteLoggerInterface::toErrorString(ret), "Remote logger error event", "remote-logger-name", Logging::Loggable(remoteLogger.name())));
}
}
{
auto tracer = dnsquestion->ids.getTracer();
if (tracer == nullptr) {
- vinfolog("SetTraceAction called, but OpenTelemetry tracing is globally disabled. Did you forget to call setOpenTelemetryTracing?");
+ VERBOSESLOG(infolog("SetTraceAction called, but OpenTelemetry tracing is globally disabled. Did you forget to call setOpenTelemetryTracing?"),
+ dnsquestion->getLogger()->info(Logr::Info, "SetTraceAction called, but OpenTelemetry tracing is globally disabled. Did you forget to call setOpenTelemetryTracing?"));
return Action::None;
}
}
if (dnsquestion->ednsOptions == nullptr) {
// Parsing failed, log a warning and return
- vinfolog("parsing EDNS options failed while looking for OpenTelemetry Trace ID");
+ VERBOSESLOG(infolog("parsing EDNS options failed while looking for OpenTelemetry Trace ID"),
+ dnsquestion->getLogger()->info(Logr::Info, "Parsing EDNS options failed while looking for OpenTelemetry Trace ID"));
return Action::None;
}
}
if (!last) {
- vinfolog("SetTraceAction: EDNS options is not the last RR in the packet, not removing TRACEPARENT");
+ VERBOSESLOG(infolog("SetTraceAction: EDNS options is not the last RR in the packet, not removing TRACEPARENT"),
+ dnsquestion->getLogger()->info(Logr::Info, "SetTraceAction: EDNS options is not the last RR in the packet, not removing TRACEPARENT"));
return Action::None;
}
auto [queryID, query] = std::move(expiredEvents.front());
expiredEvents.pop_front();
if (!data->d_failOpen) {
- vinfolog("Asynchronous query %d has expired at %d.%d, notifying the sender", queryID, now.tv_sec, now.tv_usec);
+ VERBOSESLOG(infolog("Asynchronous query %d has expired at %d.%d, notifying the sender", queryID, now.tv_sec, now.tv_usec),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "Asynchronous query has expired, notifying the sender", "query-id", Logging::Loggable(queryID)));
auto sender = query->getTCPQuerySender();
if (sender) {
TCPResponse tresponse(std::move(query->query));
}
}
else {
- vinfolog("Asynchronous query %d has expired at %d.%d, resuming", queryID, now.tv_sec, now.tv_usec);
+ VERBOSESLOG(infolog("Asynchronous query %d has expired at %d.%d, resuming", queryID, now.tv_sec, now.tv_usec),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "Asynchronous query has expired, resuming", "query-id", Logging::Loggable(queryID)));
resumeQuery(std::move(query));
}
}
auto content = d_data->d_content.lock();
auto contentIt = content->find(std::tie(queryID, asyncID));
if (contentIt == content->end()) {
- struct timeval now{};
+ timeval now{};
gettimeofday(&now, nullptr);
- vinfolog("Asynchronous object %d not found at %d.%d", queryID, now.tv_sec, now.tv_usec);
+ VERBOSESLOG(infolog("Asynchronous object %d not found at %d.%d", queryID, now.tv_sec, now.tv_usec),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "Asynchronous object not found", "async-id", Logging::Loggable(asyncID), "query-id", Logging::Loggable(queryID)));
return nullptr;
}
}
}
catch (const std::exception& e) {
- vinfolog("Got exception while resuming cross-protocol response: %s", e.what());
+ VERBOSESLOG(infolog("Got exception while resuming cross-protocol response: %s", e.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, e.what(), "Got exception while resuming cross-protocol response"));
return false;
}
queue->pop_front();
}
if (query && !resumeQuery(std::move(query))) {
- vinfolog("Unable to resume asynchronous query event");
+ VERBOSESLOG(infolog("Unable to resume asynchronous query event"),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "Unable to resume asynchronous query event"));
}
}
}
return true;
}
catch (const std::exception& e) {
- vinfolog("Got exception while resuming cross-protocol self-answered query: %s", e.what());
+ VERBOSESLOG(infolog("Got exception while resuming cross-protocol self-answered query: %s", e.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, e.what(), "Got exception while resuming cross-protocol self-answered query"));
return false;
}
}
if (result == ProcessQueryResult::Asynchronous) {
/* nope */
- errlog("processQueryAfterRules returned 'asynchronous' while trying to resume an already asynchronous query");
+ SLOG(errlog("processQueryAfterRules returned 'asynchronous' while trying to resume an already asynchronous query"),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "processQueryAfterRules returned 'asynchronous' while trying to resume an already asynchronous query"));
return false;
}
ttd.tv_usec += static_cast<decltype(ttd.tv_usec)>((timeoutMs % 1000) * 1000);
normalizeTV(ttd);
- vinfolog("Suspending asynchronous query %d at %d.%d until %d.%d", queryID, now.tv_sec, now.tv_usec, ttd.tv_sec, ttd.tv_usec);
+ VERBOSESLOG(infolog("Suspending asynchronous query %d at %d.%d until %d.%d", queryID, now.tv_sec, now.tv_usec, ttd.tv_sec, ttd.tv_usec),
+ dnsQuestion.getLogger()->info(Logr::Info, "Suspending asynchronous query", "until-sec", Logging::Loggable(ttd.tv_sec), "until-usec", Logging::Loggable(ttd.tv_usec)));
auto query = getInternalQueryFromDQ(dnsQuestion, false);
g_asyncHolder->push(asyncID, queryID, ttd, std::move(query));
ttd.tv_usec += static_cast<decltype(ttd.tv_usec)>((timeoutMs % 1000) * 1000);
normalizeTV(ttd);
- vinfolog("Suspending asynchronous response %d at %d.%d until %d.%d", queryID, now.tv_sec, now.tv_usec, ttd.tv_sec, ttd.tv_usec);
+ VERBOSESLOG(infolog("Suspending asynchronous response %d at %d.%d until %d.%d", queryID, now.tv_sec, now.tv_usec, ttd.tv_sec, ttd.tv_usec),
+ dnsResponse.getLogger()->info(Logr::Info, "Suspending asynchronous response", "until-sec", Logging::Loggable(ttd.tv_sec), "until-usec", Logging::Loggable(ttd.tv_usec)));
auto query = getInternalQueryFromDQ(dnsResponse, true);
query->d_isResponse = true;
query->downstream = dnsResponse.d_downstream;
if (!d_config.sourceItfName.empty()) {
int res = setsockopt(fd, SOL_SOCKET, SO_BINDTODEVICE, d_config.sourceItfName.c_str(), d_config.sourceItfName.length());
if (res != 0) {
- infolog("Error setting up the interface on backend socket '%s': %s", d_config.remote.toStringWithPort(), stringerror());
+ int saved = errno;
+ SLOG(infolog("Error setting up the interface on backend socket '%s': %s", d_config.remote.toStringWithPort(), stringerror(saved)),
+ getLogger()->error(Logr::Info, saved, "Error setting up the interface on backend socket", "source-interface", Logging::Loggable(d_config.sourceItfName)));
}
}
#endif
catch (const std::runtime_error& error) {
if (initialAttempt || dnsdist::configuration::getCurrentRuntimeConfiguration().d_verbose) {
if (!IsAnyAddress(d_config.sourceAddr) || !d_config.sourceItfName.empty()) {
- infolog("Error connecting to new server with address %s (source address: %s, source interface: %s): %s", d_config.remote.toStringWithPort(), IsAnyAddress(d_config.sourceAddr) ? "not set" : d_config.sourceAddr.toString(), d_config.sourceItfName.empty() ? "not set" : d_config.sourceItfName, error.what());
+ SLOG(infolog("Error connecting to new server with address %s (source address: %s, source interface: %s): %s", d_config.remote.toStringWithPort(), IsAnyAddress(d_config.sourceAddr) ? "not set" : d_config.sourceAddr.toString(), d_config.sourceItfName.empty() ? "not set" : d_config.sourceItfName, error.what()),
+ getLogger()->error(Logr::Info, error.what(), "Error connecting to server", "source-address", Logging::Loggable(d_config.sourceAddr), "source-interface", Logging::Loggable(d_config.sourceItfName)));
+
}
else {
- infolog("Error connecting to new server with address %s: %s", d_config.remote.toStringWithPort(), error.what());
+ SLOG(infolog("Error connecting to new server with address %s: %s", d_config.remote.toStringWithPort(), error.what()),
+ getLogger()->error(Logr::Info, error.what(), "Error connecting to server"));
}
}
connected = false;
void DownstreamState::hash()
{
const auto hashPerturbation = dnsdist::configuration::getImmutableConfiguration().d_hashPerturbation;
- vinfolog("Computing hashes for id=%s and weight=%d, hash_perturbation=%d", *d_config.id, d_config.d_weight, hashPerturbation);
+ VERBOSESLOG(infolog("Computing hashes for id=%s and weight=%d, hash_perturbation=%d", *d_config.id, d_config.d_weight, hashPerturbation),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "Computing hashes for backend", "id", Logging::Loggable(*d_config.id), "weight", Logging::Loggable(d_config.d_weight), "hash-perturbation", Logging::Loggable(hashPerturbation)));
+
auto weight = d_config.d_weight;
auto idStr = boost::str(boost::format("%s") % *d_config.id);
auto lockedHashes = hashes.write_lock();
void DownstreamState::setWeight(int newWeight)
{
if (newWeight < 1) {
- errlog("Error setting server's weight: downstream weight value must be greater than 0.");
+ SLOG(errlog("Error setting server's weight: downstream weight value must be greater than 0."),
+ getLogger()->info(Logr::Error, "Error setting server's weight: downstream weight value must be greater than 0", "weight", Logging::Loggable(newWeight)));
return ;
}
++reuseds;
--outstanding;
++dnsdist::metrics::g_stats.downstreamTimeouts; // this is an 'actively' discovered timeout
- vinfolog("Had a downstream timeout from %s (%s) for query for %s|%s from %s",
- d_config.remote.toStringWithPort(), getName(),
- ids.internal.qname.toLogString(), QType(ids.internal.qtype).toString(), ids.internal.origRemote.toStringWithPort());
+ SLOG(infolog("Had a downstream timeout from %s (%s) for query for %s|%s from %s",
+ d_config.remote.toStringWithPort(), getName(),
+ ids.internal.qname.toLogString(), QType(ids.internal.qtype).toString(), ids.internal.origRemote.toStringWithPort()),
+ getLogger()->info(Logr::Info, "Had a downstream timeout", "qname", Logging::Loggable(ids.internal.qname), "qtype", Logging::Loggable(QType(ids.internal.qtype)), "query-id", Logging::Loggable(ids.internal.origID), "address", Logging::Loggable(ids.internal.origRemote)));
const auto& chains = dnsdist::configuration::getCurrentRuntimeConfiguration().d_ruleChains;
const auto& timeoutRespRules = dnsdist::rules::getResponseRuleChain(chains, dnsdist::rules::ResponseRuleChain::TimeoutResponseRules);
if (d_config.d_healthCheckMode == DownstreamState::HealthCheckMode::Lazy) {
auto stats = d_lazyHealthCheckStats.lock();
if (stats->d_status == LazyHealthCheckStats::LazyStatus::PotentialFailure) {
- vinfolog("Sending health-check query for %s which is still in the Potential Failure state", getNameWithAddr());
+ VERBOSESLOG(infolog("Sending health-check query for %s which is still in the Potential Failure state", getNameWithAddr()),
+ getLogger()->info(Logr::Info, "Sending health-check query for a backend which is still in the Potential Failure state"));
return true;
}
if (stats->d_status == LazyHealthCheckStats::LazyStatus::Failed) {
/* we update the next check time here because the check might time out,
and we do not want to send a second check during that time unless
the timer is actually very short */
- vinfolog("Sending health-check query for %s which is still in the Failed state", getNameWithAddr());
+ VERBOSESLOG(infolog("Sending health-check query for %s which is still in the Failed state", getNameWithAddr()),
+ getLogger()->info(Logr::Info, "Sending health-check query for backend which is still in the Failed state"));
updateNextLazyHealthCheck(*stats, true, now);
return true;
}
auto current = (100.0 * failures) / totalCount;
if (current >= maxFailureRate) {
lastResults.clear();
- vinfolog("Backend %s reached the lazy health-check threshold (%f%% out of %f%%, looking at sample of %d items with %d failures), moving to Potential Failure state", getNameWithAddr(), current, maxFailureRate, totalCount, failures);
+ VERBOSESLOG(infolog("Backend %s reached the lazy health-check threshold (%f%% out of %f%%, looking at sample of %d items with %d failures), moving to Potential Failure state", getNameWithAddr(), current, maxFailureRate, totalCount, failures),
+ getLogger()->info(Logr::Info, "Backend reached the lazy health-check threshold, moving to Potential failure state", "current-failure-rate", Logging::Loggable(current), "max-failure-rate", Logging::Loggable(maxFailureRate), "samples", Logging::Loggable(totalCount), "failures-count", Logging::Loggable(failures)));
stats->d_status = LazyHealthCheckStats::LazyStatus::PotentialFailure;
consecutiveSuccessfulChecks = 0;
/* we update the next check time here because the check might time out,
/* we are still in the "up" state, we need to send the next query quickly to
determine if the backend is really down */
stats.d_nextCheck = now + d_config.checkInterval;
- vinfolog("Backend %s is in potential failure state, next check in %d seconds", getNameWithAddr(), d_config.checkInterval.load());
+ VERBOSESLOG(infolog("Backend %s is in potential failure state, next check in %d seconds", getNameWithAddr(), d_config.checkInterval.load()),
+ getLogger()->info(Logr::Info, "Backend is in potential failure state", "next-check", Logging::Loggable(d_config.checkInterval.load())));
}
else if (consecutiveSuccessfulChecks > 0) {
/* we are in 'Failed' state, but just had one (or more) successful check,
be available again. */
stats.d_nextCheck = now + d_config.d_lazyHealthCheckFailedInterval;
if (!checkScheduled) {
- vinfolog("Backend %s is in failed state but had %d consecutive successful checks, next check in %d seconds", getNameWithAddr(), std::to_string(consecutiveSuccessfulChecks), d_config.d_lazyHealthCheckFailedInterval);
+ VERBOSESLOG(infolog("Backend %s is in failed state but had %d consecutive successful checks, next check in %d seconds", getNameWithAddr(), std::to_string(consecutiveSuccessfulChecks), d_config.d_lazyHealthCheckFailedInterval),
+ getLogger()->info(Logr::Info, "Backend is in failed state but had a successful check", "consecutive-successful-checks", Logging::Loggable(std::to_string(consecutiveSuccessfulChecks)), "next-check", Logging::Loggable(d_config.d_lazyHealthCheckFailedInterval)));
}
}
else {
}
stats.d_nextCheck = now + backOff;
- vinfolog("Backend %s is in failed state and has failed %d consecutive checks, next check in %d seconds", getNameWithAddr(), failedTests, backOff);
+ VERBOSESLOG(infolog("Backend %s is in failed state and has failed %d consecutive checks, next check in %d seconds", getNameWithAddr(), failedTests, backOff),
+ getLogger()->info(Logr::Info, "Backend is in failed state and has failed its last check", "consecutive-failed-checks", Logging::Loggable(failedTests), "next-check", Logging::Loggable(backOff)));
}
}
else {
stats.d_nextCheck = now + d_config.d_lazyHealthCheckFailedInterval;
- vinfolog("Backend %s is in %s state, next check in %d seconds", getNameWithAddr(), (stats.d_status == DownstreamState::LazyHealthCheckStats::LazyStatus::PotentialFailure ? "potential failure" : "failed"), d_config.d_lazyHealthCheckFailedInterval);
+ VERBOSESLOG(infolog("Backend %s is in %s state, next check in %d seconds", getNameWithAddr(), (stats.d_status == DownstreamState::LazyHealthCheckStats::LazyStatus::PotentialFailure ? "potential failure" : "failed"), d_config.d_lazyHealthCheckFailedInterval),
+ getLogger()->info(Logr::Info, "Scheduling the next lazy check for this backend", "state", Logging::Loggable(stats.d_status == DownstreamState::LazyHealthCheckStats::LazyStatus::PotentialFailure ? "potential failure" : "failed"), "next-check", Logging::Loggable(d_config.d_lazyHealthCheckFailedInterval)));
}
}
/* if this is the initial health-check, at startup, we do not care
about the minimum number of failed/successful health-checks */
if (!IsAnyAddress(d_config.remote)) {
- infolog("Marking downstream %s as '%s'", getNameWithAddr(), newResult ? "up" : "down");
+ SLOG(infolog("Marking downstream %s as '%s'", getNameWithAddr(), newResult ? "up" : "down"),
+ getLogger()->info(Logr::Info, "Setting initial status for backend", "status", Logging::Loggable(newResult ? "up" : "down")));
}
setUpStatus(newResult);
if (newResult == false) {
if (newState) {
if (d_config.d_healthCheckMode == DownstreamState::HealthCheckMode::Lazy) {
auto stats = d_lazyHealthCheckStats.lock();
- vinfolog("Backend %s had %d successful checks, moving to Healthy", getNameWithAddr(), std::to_string(consecutiveSuccessfulChecks));
+ VERBOSESLOG(infolog("Backend %s had %d successful checks, moving to Healthy", getNameWithAddr(), std::to_string(consecutiveSuccessfulChecks)),
+ getLogger()->info(Logr::Info, "Backend had a successful check, moving to Healthy", "consecutive-successful-checks", Logging::Loggable(std::to_string(consecutiveSuccessfulChecks))));
stats->d_status = LazyHealthCheckStats::LazyStatus::Healthy;
stats->d_lastResults.clear();
}
}
else if (d_config.d_healthCheckMode == DownstreamState::HealthCheckMode::Lazy) {
auto stats = d_lazyHealthCheckStats.lock();
- vinfolog("Backend %s failed its health-check, moving from Potential failure to Failed", getNameWithAddr());
+ VERBOSESLOG(infolog("Backend %s failed its health-check, moving from Potential failure to Failed", getNameWithAddr()),
+ getLogger()->info(Logr::Info, "Backend failed its health-check, moving from Potential failure to Failed"));
stats->d_status = LazyHealthCheckStats::LazyStatus::Failed;
currentCheckFailures = 1;
updateNextLazyHealthCheck(*stats, false);
if (newState != upStatus.load(std::memory_order_relaxed)) {
/* we are actually moving to a new state */
if (!IsAnyAddress(d_config.remote)) {
- infolog("Marking downstream %s as '%s'", getNameWithAddr(), newState ? "up" : "down");
+ SLOG(infolog("Marking downstream %s as '%s'", getNameWithAddr(), newState ? "up" : "down"),
+ getLogger()->info(Logr::Info, "Updating status for backend", "status", Logging::Loggable(newState ? "up" : "down")));
}
if (newState && !isTCPOnly() && (!connected || d_config.reconnectOnUp)) {
}
if (addresses.size() > 1) {
- warnlog("More than one address configured on interface %s, picking the first one (%s) for XSK. Set the 'source' parameter on 'newServer' if you want to use a different address.", ifName, addresses.at(0).toString());
+ SLOG(warnlog("More than one address configured on interface %s, picking the first one (%s) for XSK. Set the 'source' parameter on 'newServer' if you want to use a different address.", ifName, addresses.at(0).toString()),
+ getLogger()->info(Logr::Warning, "More than one address configured on this interface, picking the first one for XSK. Set the 'source' parameter on 'newServer' if you want to use a different address.", "interface", Logging::Loggable(ifName), "address", Logging::Loggable(addresses.at(0).toString())));
}
d_config.sourceAddr = addresses.at(0);
}
return true;
}
- warnlog("Dismissing source %s because '%s' is not a valid interface name", source, config.sourceItfName);
+ SLOG(warnlog("Dismissing source %s because '%s' is not a valid interface name", source, config.sourceItfName),
+ dnsdist::logging::getTopLogger()->info(Logr::Warning, "Dismissing source because the interface name is not valid", "backend-name", Logging::Loggable(config.name), "backend-address", Logging::Loggable(config.remote), "source", Logging::Loggable(source), "source-interface", Logging::Loggable(config.sourceItfName)));
+
return false;
}
return d_qpsLimiter ? d_qpsLimiter->getRate() : 0U;
}
+[[nodiscard]] std::shared_ptr<const Logr::Logger> DownstreamState::getLogger() const
+{
+ return dnsdist::logging::getTopLogger()->withName("backend")->withValues("backend-name", Logging::Loggable(getName()), "backend-address", Logging::Loggable(d_config.remote), "backend-proto", Logging::Loggable(getProtocol()));
+}
+
size_t ServerPool::countServers(bool upOnly) const
{
size_t count = 0;
return d_logger;
}
auto logger = dnsdist::logging::getTopLogger();
- logger = logger->withValues("qname", Logging::Loggable(ids.qname), "qtype", Logging::Loggable(QType(ids.qtype)), "qclass", Logging::Loggable(QClass(ids.qclass)), "source", Logging::Loggable(ids.origRemote), "destination", Logging::Loggable(ids.origDest), "proto", Logging::Loggable(ids.protocol));
+ logger = logger->withValues("qname", Logging::Loggable(ids.qname), "qtype", Logging::Loggable(QType(ids.qtype)), "qclass", Logging::Loggable(QClass(ids.qclass)), "source", Logging::Loggable(ids.origRemote), "destination", Logging::Loggable(ids.origDest), "proto", Logging::Loggable(ids.protocol), "id", Logging::Loggable(ids.origID), "flags", Logging::Loggable(ids.origFlags));
+ return logger;
+}
+
+std::shared_ptr<const Logr::Logger> DNSResponse::getThisLogger() const
+{
+ if (d_logger) {
+ return d_logger;
+ }
+ auto logger = DNSQuestion::getThisLogger();
+ if (data.size() >= sizeof(dnsheader)) {
+ const auto header = getHeader();
+ logger = logger->withValues("rcode", Logging::Loggable(RCode::to_s(header->rcode)));
+ }
+ if (d_downstream) {
+ logger = logger->withValues("backend-protocol", Logging::Loggable(d_downstream->getProtocol()), "backend-name", Logging::Loggable(d_downstream->getName()), "backend-address", Logging::Loggable(d_downstream->d_config.remote));
+ }
+ const double udiff = ids.queryRealTime.udiff();
+ logger = logger->withValues("latency-us", Logging::Loggable(udiff), "response-size", Logging::Loggable(data.size()));
return logger;
}
#include <string_view>
#include "config.h"
+#include "dolog.hh"
#include "iputils.hh"
#include "libssl.hh"
#include "noinitvector.hh"
std::shared_ptr<DOHServerConfig> d_dsc{nullptr};
std::shared_ptr<std::vector<std::shared_ptr<DOHResponseMapEntry>>> d_responsesMap;
std::shared_ptr<TLSFrontend> d_tlsContext;
+ std::shared_ptr<const Logr::Logger> d_logger;
std::string d_serverTokens{"dnsdist"};
std::unordered_map<std::string, std::string> d_customResponseHeaders;
std::string d_library;
return !d_tlsContext->d_tlsConfig.d_certKeyPairs.empty();
}
+ const Logr::Logger& getLogger() const
+ {
+ return *d_logger;
+ }
+
#ifndef HAVE_DNS_OVER_HTTPS
virtual void setup()
{
namespace dnsdist::webserver
{
-void registerWebHandler(const std::string& endpoint, std::function<void(const YaHTTP::Request&, YaHTTP::Response&)> handler, bool isLua);
+void registerWebHandler(const std::string& endpoint, std::function<void(const YaHTTP::Request&, YaHTTP::Response&)> handler);
}
void setupLuaWeb([[maybe_unused]] LuaContext& luaCtx)
#ifndef DISABLE_LUA_WEB_HANDLERS
luaCtx.writeFunction("registerWebHandler", [](const std::string& path, std::function<void(const YaHTTP::Request*, YaHTTP::Response*)> handler) {
/* LuaWrapper does a copy for objects passed by reference, so we pass a pointer */
- dnsdist::webserver::registerWebHandler(path, [handler](const YaHTTP::Request& req, YaHTTP::Response& resp) { handler(&req, &resp); }, true);
+ dnsdist::webserver::registerWebHandler(path, [handler](const YaHTTP::Request& req, YaHTTP::Response& resp) { handler(&req, &resp); });
});
luaCtx.registerMember<std::string(YaHTTP::Request::*)>("path", [](const YaHTTP::Request& req) -> std::string { return req.url.path; }, [](YaHTTP::Request& req, const std::string& path) { (void)req; (void) path; });
#include <sys/time.h>
#include <sys/resource.h>
#include <thread>
+#include <variant>
#include "ext/json11/json11.hpp"
#include <yahttp/yahttp.hpp>
class WebClientConnection
{
public:
- WebClientConnection(const ComboAddress& client, int socketDesc) :
+ WebClientConnection(const ComboAddress& client, int socketDesc, const Logr::Logger& logger) :
d_client(client), d_socket(socketDesc)
{
if (!s_connManager.registerConnection()) {
throw std::runtime_error("Too many concurrent web client connections");
}
+ d_logger = logger.withValues("address", Logging::Loggable(client));
}
WebClientConnection(WebClientConnection&& rhs) noexcept :
- d_client(rhs.d_client), d_socket(std::move(rhs.d_socket))
+ d_logger(std::move(rhs.d_logger)), d_client(rhs.d_client), d_socket(std::move(rhs.d_socket))
{
}
WebClientConnection(const WebClientConnection&) = delete;
{
d_client = rhs.d_client;
d_socket = std::move(rhs.d_socket);
+ d_logger = std::move(rhs.d_logger);
return *this;
}
return d_client;
}
+ [[nodiscard]] const Logr::Logger& getLogger() const
+ {
+ return *d_logger;
+ }
+
private:
+ std::shared_ptr<Logr::Logger> d_logger;
ComboAddress d_client;
Socket d_socket;
};
}
#ifndef DISABLE_WEB_CONFIG
-static bool apiWriteConfigFile(const string& filebasename, const string& content)
+static bool apiWriteConfigFile(const string& filebasename, const string& content, const Logr::Logger& logger)
{
const auto& runtimeConfig = dnsdist::configuration::getCurrentRuntimeConfiguration();
if (!runtimeConfig.d_apiReadWrite) {
- warnlog("Not writing content to %s since the API is read-only", filebasename);
+ SLOG(warnlog("Not writing content to %s since the API is read-only", filebasename),
+ logger.info(Logr::Warning, "Not writing content to file since the API is read-only", "file", Logging::Loggable(filebasename)));
return false;
}
if (runtimeConfig.d_apiConfigDirectory.empty()) {
- vinfolog("Not writing content to %s since the API configuration directory is not set", filebasename);
+ VERBOSESLOG(infolog("Not writing content to %s since the API configuration directory is not set", filebasename),
+ logger.info(Logr::Info, "Not writing content to file since the API configuration directory is not set", "file", Logging::Loggable(filebasename)));
+
return false;
}
string filename = runtimeConfig.d_apiConfigDirectory + "/" + filebasename + ".conf";
ofstream ofconf(filename.c_str());
if (!ofconf) {
- errlog("Could not open configuration fragment file '%s' for writing: %s", filename, stringerror());
+ int saved = errno;
+ SLOG(errlog("Could not open configuration fragment file '%s' for writing: %s", filename, stringerror(saved)),
+ logger.error(Logr::Error, saved, "Could not open configuration fragment file for writing", "file", Logging::Loggable(filebasename)));
+
return false;
}
ofconf << "-- Generated by the REST API, DO NOT EDIT" << endl;
return true;
}
-static void apiSaveACL(const NetmaskGroup& nmg)
+static void apiSaveACL(const NetmaskGroup& nmg, const Logr::Logger& logger)
{
auto aclEntries = nmg.toStringVector();
}
string content = "setACL({" + acl + "})";
- apiWriteConfigFile("acl", content);
+ apiWriteConfigFile("acl", content, logger);
}
#endif /* DISABLE_WEB_CONFIG */
output << metricName << "_count" << label << " " << container.latencyCount << "\n";
}
-static void handlePrometheus(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handlePrometheus(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
handleCORS(req, resp);
resp.status = 200;
MetricDefinition metricDetails;
if (!s_metricDefinitions.getMetricDetails(metricName, metricDetails)) {
- vinfolog("Do not have metric details for %s", metricName);
+ VERBOSESLOG(infolog("Do not have metric details for %s", metricName),
+ logger.info(Logr::Info, "Missing details for this metric", "metric-name", Logging::Loggable(metricName)));
continue;
}
const std::string prometheusTypeName = s_metricDefinitions.getPrometheusStringMetricType(metricDetails.prometheusType);
if (prometheusTypeName.empty()) {
- vinfolog("Unknown Prometheus type for %s", metricName);
+ VERBOSESLOG(infolog("Unknown Prometheus type for %s", metricName),
+ logger.info(Logr::Info, "Unknown Prometheus type", "metric-name", Logging::Loggable(metricName)));
continue;
}
}
#ifndef DISABLE_BUILTIN_HTML
-static void handleJSONStats(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleJSONStats(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
handleCORS(req, resp);
resp.status = 200;
servers.emplace_back(std::move(server));
}
-static void handleStats(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleStats(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
handleCORS(req, resp);
resp.status = 200;
resp.body = Json(responseObject).dump();
}
-static void handlePoolStats(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handlePoolStats(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
handleCORS(req, resp);
const auto poolName = req.getvars.find("name");
if (poolName == req.getvars.end()) {
resp.body = my_json.dump();
}
-static void handleStatsOnly(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleStatsOnly(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
handleCORS(req, resp);
resp.status = 200;
}
#ifndef DISABLE_WEB_CONFIG
-static void handleConfigDump(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleConfigDump(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
handleCORS(req, resp);
resp.status = 200;
resp.headers["Content-Type"] = "application/json";
}
-static void handleAllowFrom(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleAllowFrom(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
handleCORS(req, resp);
}
if (resp.status == 200) {
- infolog("Updating the ACL via the API to %s", nmg.toString());
+ SLOG(infolog("Updating the ACL via the API to %s", nmg.toString()),
+ logger.info(Logr::Info, "Updating the ACL via the API", "acl", Logging::Loggable(nmg)));
+
dnsdist::configuration::updateRuntimeConfiguration([&nmg](dnsdist::configuration::RuntimeConfiguration& config) {
config.d_ACL = nmg;
});
- apiSaveACL(nmg);
+ apiSaveACL(nmg, logger);
}
}
else {
#endif /* DISABLE_WEB_CONFIG */
#ifndef DISABLE_WEB_CACHE_MANAGEMENT
-static void handleCacheManagement(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleCacheManagement(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
handleCORS(req, resp);
resp.headers["Content-Type"] = "application/json";
list.emplace_back(std::move(tmp));
}
-static void handleRings(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleRings(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
handleCORS(req, resp);
maxNumberOfQueries = pdns::checked_stoi<size_t>(maxQueries->second);
}
catch (const std::exception& exp) {
- vinfolog("Error parsing the 'maxQueries' value from rings HTTP GET query: %s", exp.what());
+ VERBOSESLOG(infolog("Error parsing the 'maxQueries' value from rings HTTP GET query: %s", exp.what()),
+ logger.error(Logr::Info, exp.what(), "Error parsing the 'maxQueries' value from rings HTTP GET query"));
}
}
maxNumberOfResponses = pdns::checked_stoi<size_t>(maxResponses->second);
}
catch (const std::exception& exp) {
- vinfolog("Error parsing the 'maxResponses' value from rings HTTP GET query: %s", exp.what());
+ VERBOSESLOG(infolog("Error parsing the 'maxResponses' value from rings HTTP GET query: %s", exp.what()),
+ logger.error(Logr::Info, exp.what(), "Error parsing the 'maxResponses' value from rings HTTP GET query"));
}
}
resp.headers["Content-Type"] = "application/json";
}
-using WebHandler = std::function<void(const YaHTTP::Request&, YaHTTP::Response&)>;
-struct WebHandlerContext
-{
- WebHandler d_handler;
- bool d_isLua{false};
-};
+using BuiltinWebHandler = std::function<void(const YaHTTP::Request&, YaHTTP::Response&, const Logr::Logger& logger)>;
+using LuaWebHandler = std::function<void(const YaHTTP::Request&, YaHTTP::Response&)>;
+using WebHandler = std::variant<BuiltinWebHandler, LuaWebHandler>;
+
+static SharedLockGuarded<std::unordered_map<std::string, WebHandler>> s_webHandlers;
-static SharedLockGuarded<std::unordered_map<std::string, WebHandlerContext>> s_webHandlers;
+void registerWebHandler(const std::string& endpoint, LuaWebHandler handler);
-void registerWebHandler(const std::string& endpoint, WebHandler handler, bool isLua = false);
+void registerWebHandler(const std::string& endpoint, LuaWebHandler handler)
+{
+ auto handlers = s_webHandlers.write_lock();
+ (*handlers)[endpoint] = WebHandler{std::move(handler)};
+}
-void registerWebHandler(const std::string& endpoint, WebHandler handler, bool isLua)
+static void registerWebHandler(const std::string& endpoint, BuiltinWebHandler handler)
{
auto handlers = s_webHandlers.write_lock();
- (*handlers)[endpoint] = WebHandlerContext{std::move(handler), isLua};
+ (*handlers)[endpoint] = WebHandler{std::move(handler)};
}
void clearWebHandlers()
#ifndef DISABLE_BUILTIN_HTML
#include "htmlfiles.h"
-static void redirectToIndex([[maybe_unused]] const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void redirectToIndex([[maybe_unused]] const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
const string charset = "; charset=utf-8";
resp.body.assign(s_urlmap.at("index.html"));
resp.headers["Content-Type"] = "text/html" + charset;
resp.status = 200;
}
-static void handleBuiltInFiles(const YaHTTP::Request& req, YaHTTP::Response& resp)
+static void handleBuiltInFiles(const YaHTTP::Request& req, YaHTTP::Response& resp, const Logr::Logger& logger)
{
+ (void)logger;
if (req.url.path.empty()) {
resp.status = 404;
return;
{
setThreadName("dnsdist/webConn");
- vinfolog("Webserver handling connection from %s", conn.getClient().toStringWithPort());
+ VERBOSESLOG(infolog("Webserver handling connection from %s", conn.getClient().toStringWithPort()),
+ conn.getLogger().info(Logr::Info, "Webserver handling connection"));
try {
YaHTTP::AsyncRequestLoader yarl;
else if (!handleAuthorization(req)) {
auto header = req.headers.find("authorization");
if (header != req.headers.end()) {
- vinfolog("HTTP Request \"%s\" from %s: Web Authentication failed", req.url.path, conn.getClient().toStringWithPort());
+ VERBOSESLOG(infolog("HTTP Request \"%s\" from %s: Web Authentication failed", req.url.path, conn.getClient().toStringWithPort()),
+ conn.getLogger().info(Logr::Info, "Web authentication failed for HTTP Request", "url", Logging::Loggable( req.url.path)));
}
resp.status = 401;
resp.body = "<h1>Unauthorized</h1>";
resp.status = 405;
}
else {
- std::optional<WebHandlerContext> handlerCtx{std::nullopt};
+ std::optional<WebHandler> handler{std::nullopt};
{
auto handlers = s_webHandlers.read_lock();
const auto webHandlersIt = handlers->find(req.url.path);
if (webHandlersIt != handlers->end()) {
- handlerCtx = webHandlersIt->second;
+ handler = webHandlersIt->second;
}
}
- if (handlerCtx) {
- if (handlerCtx->d_isLua) {
+ if (handler) {
+ if (const auto* luaHandler = std::get_if<LuaWebHandler>(&*handler)) {
auto lua = g_lua.lock();
- handlerCtx->d_handler(req, resp);
+ (*luaHandler)(req, resp);
}
- else {
- handlerCtx->d_handler(req, resp);
+ else if (const auto* builtinHandler = std::get_if<BuiltinWebHandler>(&*handler)) {
+ (*builtinHandler)(req, resp, conn.getLogger());
}
}
else {
writen2(conn.getSocket().getHandle(), done.c_str(), done.size());
}
catch (const YaHTTP::ParseError& e) {
- vinfolog("Webserver thread died with parse error exception while processing a request from %s: %s", conn.getClient().toStringWithPort(), e.what());
+ VERBOSESLOG(infolog("Webserver thread died with parse error exception while processing a request from %s: %s", conn.getClient().toStringWithPort(), e.what()),
+ conn.getLogger().error(Logr::Info, e.what(), "Webserver thread died with parse error exception while processing a request"));
}
catch (const std::exception& e) {
- vinfolog("Webserver thread died with exception while processing a request from %s: %s", conn.getClient().toStringWithPort(), e.what());
+ VERBOSESLOG(infolog("Webserver thread died with exception while processing a request from %s: %s", conn.getClient().toStringWithPort(), e.what()),
+ conn.getLogger().error(Logr::Info, e.what(), "Webserver thread died with exception while processing a request"));
}
catch (...) {
- vinfolog("Webserver thread died with exception while processing a request from %s", conn.getClient().toStringWithPort());
+ VERBOSESLOG(infolog("Webserver thread died with exception while processing a request from %s", conn.getClient().toStringWithPort()),
+ conn.getLogger().info(Logr::Info, "Webserver thread died with exception while processing a request"));
}
}
void WebserverThread(ComboAddress listeningAddress, Socket sock)
{
setThreadName("dnsdist/webserv");
- // coverity[auto_causes_copy]
- infolog("Webserver launched on %s", listeningAddress.toStringWithPort());
+ auto serverLogger = dnsdist::logging::getTopLogger()->withName("webserver")->withValues("listening-address", Logging::Loggable(listeningAddress));
+ SLOG(infolog("Webserver launched on %s", listeningAddress.toStringWithPort()),
+ serverLogger->info(Logr::Info, "Webserver launched"));
{
const auto& config = dnsdist::configuration::getCurrentRuntimeConfiguration();
if (!config.d_webPassword && config.d_dashboardRequiresAuthentication) {
- warnlog("Webserver launched on %s without a password set!", listeningAddress.toStringWithPort());
+ SLOG(warnlog("Webserver launched on %s without a password set!", listeningAddress.toStringWithPort()),
+ serverLogger->info(Logr::Info, "Webserver launched without a password set!"));
}
}
dnsdist::configuration::refreshLocalRuntimeConfiguration();
if (!isClientAllowedByACL(remote)) {
- vinfolog("Connection to webserver from client %s is not allowed, closing", remote.toStringWithPort());
+ VERBOSESLOG(infolog("Connection to webserver from client %s is not allowed, closing", remote.toStringWithPort()),
+ serverLogger->info(Logr::Info, "Connection to webserver is not allowed by ACL, closing", "address", Logging::Loggable(remote)));
close(fileDesc);
continue;
}
- WebClientConnection conn(remote, fileDesc);
- vinfolog("Got a connection to the webserver from %s", remote.toStringWithPort());
+ WebClientConnection conn(remote, fileDesc, *serverLogger);
+ VERBOSESLOG(infolog("Got a connection to the webserver from %s", remote.toStringWithPort()),
+ conn.getLogger().info(Logr::Info, "Got a connection to the webserver"));
std::thread connThr(connectionThread, std::move(conn));
connThr.detach();
}
catch (const std::exception& e) {
- vinfolog("Had an error accepting new webserver connection: %s", e.what());
+ VERBOSESLOG(infolog("Had an error accepting new webserver connection: %s", e.what()),
+ serverLogger->error(Logr::Info, e.what(), "Had an error accepting new webserver connection"));
}
}
}
{
try {
setThreadName("dnsdist/XskResp");
+ auto logger = dnsdist::logging::getTopLogger()->withName("xsk-response-worker")->withValues("backend-name", Logging::Loggable(dss->getName()), "backend-address", Logging::Loggable(dss->d_config.remote));
+
auto pollfds = getPollFdsForWorker(*xskInfo);
while (!dss->isStopped()) {
poll(pollfds.data(), pollfds.size(), -1);
}
if (!processResponderPacket(dss, response, std::move(*ids))) {
xskInfo->markAsFree(packet);
- vinfolog("XSK packet dropped because processResponderPacket failed");
+ VERBOSESLOG(infolog("XSK packet dropped because processResponderPacket failed"),
+ logger->info(Logr::Info, "XSK packet dropped because processResponderPacket failed"));
return;
}
if (response.size() > packet.getCapacity()) {
/* fallback to sending the packet via normal socket */
sendUDPResponse(ids->cs->udpFD, response, ids->delayMsec, ids->hopLocal, ids->hopRemote);
- infolog("XSK packet falling back because packet is too large");
+ VERBOSESLOG(infolog("XSK packet falling back because packet is too large"),
+ logger->info(Logr::Info, "XSK packet falling back because packet is too large"));
xskInfo->markAsFree(packet);
return;
}
packet.setHeader(ids->xskPacketHeader);
if (!packet.setPayload(response)) {
- infolog("Unable to set XSK payload !");
+ VERBOSESLOG(infolog("Unable to set XSK payload!"),
+ logger->info(Logr::Info, "Unable to set XSK payload!"));
}
if (ids->delayMsec > 0) {
packet.addDelay(ids->delayMsec);
}
}
catch (const std::exception& e) {
- errlog("XSK responder thread died because of exception: %s", e.what());
+ SLOG(errlog("XSK responder thread died because of exception: %s", e.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Error, e.what(), "XSK responder thread died because of exception"));
}
catch (const PDNSException& e) {
- errlog("XSK responder thread died because of PowerDNS exception: %s", e.reason);
+ SLOG(errlog("XSK responder thread died because of PowerDNS exception: %s", e.reason),
+ dnsdist::logging::getTopLogger()->error(Logr::Error, e.reason, "XSK responder thread died because of exception"));
}
catch (...) {
- errlog("XSK responder thread died because of an exception: %s", "unknown");
+ SLOG(errlog("XSK responder thread died because of an unknown exception"),
+ dnsdist::logging::getTopLogger()->info(Logr::Error, "XSK responder thread died because of an unknown exception"));
}
}
const auto& from = packet.getFromAddr();
expectProxyProtocol = expectProxyProtocolFrom(from);
if (!dnsdist::configuration::getCurrentRuntimeConfiguration().d_ACL.match(from) && !expectProxyProtocol) {
- vinfolog("Query from %s dropped because of ACL", from.toStringWithPort());
+ VERBOSESLOG(infolog("Query from %s dropped because of ACL", from.toStringWithPort()),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, "Query dropped because of ACL", "address", Logging::Loggable(from)));
++dnsdist::metrics::g_stats.aclDrops;
return false;
}
void XskRouter(std::shared_ptr<XskSocket> xsk)
{
setThreadName("dnsdist/XskRouter");
+ auto logger = dnsdist::logging::getTopLogger()->withName("xsk-router");
+
uint32_t failed = 0;
// packets to be submitted for sending
vector<XskPacket> fillInTx;
xsk->send(fillInTx);
}
catch (...) {
- vinfolog("Exception in XSK router loop");
+ VERBOSESLOG(infolog("Exception in XSK router loop"),
+ logger->info(Logr::Info, "Exception in XSK router loop"));
}
}
}
if (!muted) {
if (!ids.isXSK()) {
VERBOSESLOG(infolog("Got answer from %s, relayed to %s (UDP), took %d us", backend->d_config.remote.toStringWithPort(), ids.origRemote.toStringWithPort(), udiff),
- dnsResponse.getLogger()->withName("udp-response")->info(Logr::Info, "Got answer from backend, relayed to client", "backend", Logging::Loggable(backend->d_config.remote), "latency-us", Logging::Loggable(udiff)));
+ dnsResponse.getLogger()->withName("udp-response")->info(Logr::Info, "Got answer from backend, relayed to client"));
}
else {
VERBOSESLOG(infolog("Got answer from %s, relayed to %s (UDP via XSK), took %d us", backend->d_config.remote.toStringWithPort(), ids.origRemote.toStringWithPort(), udiff),
- dnsResponse.getLogger()->withName("udp-xsk-response")->info(Logr::Info, "Got answer from backend, relayed to client", "backend", Logging::Loggable(backend->d_config.remote), "latency-us", Logging::Loggable(udiff)));
+ dnsResponse.getLogger()->withName("udp-xsk-response")->info(Logr::Info, "Got answer from backend, relayed to client"));
}
}
else {
if (!ids.isXSK()) {
VERBOSESLOG(infolog("Got answer from %s, NOT relayed to %s (UDP) since that frontend is muted, took %d us", backend->d_config.remote.toStringWithPort(), ids.origRemote.toStringWithPort(), udiff),
- dnsResponse.getLogger()->withName("udp-response")->info(Logr::Info, "Got answer from backend, NOT relayed to client since that frontend is muted", "backend", Logging::Loggable(backend->d_config.remote), "latency-us", Logging::Loggable(udiff)));
+ dnsResponse.getLogger()->withName("udp-response")->info(Logr::Info, "Got answer from backend, NOT relayed to client since that frontend is muted"));
}
else {
VERBOSESLOG(infolog("Got answer from %s, relayed to %s (UDP via XSK), took %d us", backend->d_config.remote.toStringWithPort(), ids.origRemote.toStringWithPort(), udiff),
- dnsResponse.getLogger()->withName("udp-xsk-response")->info(Logr::Info, "Got answer from backend, NOT relayed to client since that frontend is muted", "backend", Logging::Loggable(backend->d_config.remote), "latency-us", Logging::Loggable(udiff)));
+ dnsResponse.getLogger()->withName("udp-xsk-response")->info(Logr::Info, "Got answer from backend, NOT relayed to client since that frontend is muted"));
}
}
ProcessQueryResult processQuery(DNSQuestion& dnsQuestion, std::shared_ptr<DownstreamState>& selectedBackend)
{
- dnsQuestion.getLogger()->info("test");
auto closer = dnsQuestion.ids.getCloser(__func__); // NOLINT(cppcoreguidelines-pro-bounds-array-to-pointer-decay)
const uint16_t queryId = ntohs(dnsQuestion.getHeader()->id);
try {
}
catch (const std::exception& e) {
if (secondsToWaitLog <= 0) {
- warnlog("Error during execution of maintenance function(s): %s", e.what());
+ SLOG(warnlog("Error during execution of maintenance function(s): %s", e.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Warning, e.what(), "Error during execution of maintenance function(s)"));
secondsToWaitLog = 61;
}
secondsToWaitLog -= interval;
}
acls += aclEntry;
}
- infolog("ACL allowing queries from: %s", acls);
+ SLOG(infolog("ACL allowing queries from: %s", acls),
+ setupLogger->info(Logr::Info, "Allowing queries from", "acl", Logging::Loggable(acls)));
}
{
std::string acls;
}
acls += entry;
}
- infolog("Console ACL allowing connections from: %s", acls.c_str());
+ SLOG(infolog("Console ACL allowing connections from: %s", acls),
+ setupLogger->info(Logr::Info, "Allowing console connections from", "acl", Logging::Loggable(acls)));
}
auto listeningSockets = initListeningSockets();
#if defined(HAVE_LIBSODIUM) || defined(HAVE_LIBCRYPTO)
if (dnsdist::configuration::getCurrentRuntimeConfiguration().d_consoleEnabled && dnsdist::configuration::getCurrentRuntimeConfiguration().d_consoleKey.empty()) {
- warnlog("Warning, the console has been enabled via 'controlSocket()' but no key has been set with 'setKey()' so all connections will fail until a key has been set");
+ SLOG(warnlog("Warning, the console has been enabled via 'controlSocket()' but no key has been set with 'setKey()' so all connections will fail until a key has been set"),
+ setupLogger->info(Logr::Warning, "The console has been enabled via 'controlSocket()' but no key has been set with 'setKey()' so allconnections will fail until a key has been set"));
}
#endif
/* the limit is completely arbitrary: hopefully high enough not to trigger too many false positives
but low enough to be useful */
if (maxTCPClientThreads >= 50U) {
- warnlog("setMaxTCPClientThreads(%d) might create a large number of TCP connections to backends, and is probably not needed, please consider lowering it", maxTCPClientThreads);
+ SLOG(warnlog("setMaxTCPClientThreads(%d) might create a large number of TCP connections to backends, and is probably not needed, please consider lowering it", maxTCPClientThreads),
+ setupLogger->info(Logr::Warning, "The current setMaxTCPClientThreads() value might create a large number of TCP connections to backends, and is probably not needed, please consider lowering it", "value", Logging::Loggable(maxTCPClientThreads)));
}
g_tcpclientthreads = std::make_unique<TCPClientCollection>(maxTCPClientThreads, std::vector<ClientState*>());
#endif
if (!queueHealthCheck(mplexer, dss, true)) {
dss->submitHealthCheckResult(true, false);
dss->setUpStatus(false);
- warnlog("Marking downstream %s as 'down'", dss->getNameWithAddr());
+ SLOG(warnlog("Marking downstream %s as 'down'", dss->getNameWithAddr()),
+ setupLogger->info(Logr::Warning, "Marking downstream backend server as 'down'", "backend-name", Logging::Loggable(dss->getName()), "address", Logging::Loggable(dss->d_config.remote)));
}
}
}
std::shared_ptr<const Logr::Logger> getLogger();
protected:
- std::shared_ptr<const Logr::Logger> getThisLogger() const;
+ virtual std::shared_ptr<const Logr::Logger> getThisLogger() const;
PacketBuffer& data;
std::shared_ptr<const Logr::Logger> d_logger;
DNSResponse(DNSResponse&&) = default;
const std::shared_ptr<DownstreamState>& d_downstream;
+
+protected:
+ std::shared_ptr<const Logr::Logger> getThisLogger() const override;
};
using pdns::stat_t;
}
unsigned int getQPSLimit() const;
+
+ [[nodiscard]] std::shared_ptr<const Logr::Logger> getLogger() const;
};
void responderThread(std::shared_ptr<DownstreamState> dss);
if (!unit->ids.selfGenerated) {
auto udiff = unit->ids.queryRealTime.udiff();
- vinfolog("Got answer from %s, relayed to %s (DoH3, %d bytes), took %d us", unit->downstream->d_config.remote.toStringWithPort(), unit->ids.origRemote.toStringWithPort(), unit->response.size(), udiff);
+ VERBOSESLOG(infolog("Got answer from %s, relayed to %s (DoH3, %d bytes), took %d us", unit->downstream->d_config.remote.toStringWithPort(), unit->ids.origRemote.toStringWithPort(), unit->response.size(), udiff),
+ dnsResponse.getLogger()->info("Got answer from backend, relayed to client"));
auto backendProtocol = unit->downstream->getProtocol();
if (backendProtocol == dnsdist::Protocol::DoUDP && unit->tcp) {
try {
if (!unit->dsc->d_responseSender.send(std::move(unit))) {
++dnsdist::metrics::g_stats.doh3ResponsePipeFull;
- vinfolog("Unable to pass a %s to the DoH3 worker thread because the pipe is full", description);
+ VERBOSESLOG(infolog("Unable to pass a %s to the DoH3 worker thread because the pipe is full", description),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, std::string("Unable to pass a ") + std::string(description) + " to the DoH3 worker thread because the pipe is full"));
}
}
catch (const std::exception& e) {
- vinfolog("Unable to pass a %s to the DoH3 worker thread because we couldn't write to the pipe: %s", description, e.what());
+ VERBOSESLOG(infolog("Unable to pass a %s to the DoH3 worker thread because we couldn't write to the pipe: %s", description, e.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, e.what(), std::string("Unable to pass a ") + std::string(description) + " to the DoH3 worker thread because we couldn't write to the pipe"));
}
}
ClientState& clientState = *dsc->clientState;
if (!dnsdist::configuration::getCurrentRuntimeConfiguration().d_ACL.match(remote)) {
- vinfolog("Query from %s (DoH3) dropped because of ACL", remote.toStringWithPort());
+ VERBOSESLOG(infolog("Query from %s (DoH3) dropped because of ACL", remote.toStringWithPort()),
+ dsc->df->getLogger().info("DoH3 query dropped because of ACL", "address", Logging::Loggable(remote)));
++dnsdist::metrics::g_stats.aclDrops;
unit->response.clear();
return;
}
catch (const std::exception& e) {
- vinfolog("Got an error in DOH3 question thread while parsing a query from %s, id %d: %s", remote.toStringWithPort(), queryId, e.what());
- unit->status_code = 500;
- handleImmediateResponse(std::move(unit), "DoH3 internal error");
+ if (unit) {
+ VERBOSESLOG(infolog("Got an error in DOH3 question thread while parsing a query from %s, id %d: %s", remote.toStringWithPort(), queryId, e.what()),
+ unit->dsc->df->getLogger().error(Logr::Info, e.what(), "Got an error in DoH3 question thread while parsing a query", "address", Logging::Loggable(remote), "query-id", Logging::Loggable(queryId)));
+ unit->status_code = 500;
+ handleImmediateResponse(std::move(unit), "DoH3 internal error");
+ }
return;
}
}
processDOH3Query(std::move(unit));
}
catch (const std::exception& exp) {
- vinfolog("Had error handling DoH3 DNS packet from %s: %s", remote.toStringWithPort(), exp.what());
+ VERBOSESLOG(infolog("Had error handling DoH3 DNS packet from %s: %s", remote.toStringWithPort(), exp.what()),
+ dsc.df->getLogger().error(Logr::Info, exp.what(), "Had error handling DoH3 DNS packet", "address", Logging::Loggable(remote)));
}
}
-static void flushResponses(pdns::channel::Receiver<DOH3Unit>& receiver)
+static void flushResponses(pdns::channel::Receiver<DOH3Unit>& receiver, const Logr::Logger& frontendLogger)
{
for (;;) {
try {
}
}
catch (const std::exception& e) {
- errlog("Error while processing response received over DoH3: %s", e.what());
+ SLOG(errlog("Error while processing response received over DoH3: %s", e.what()),
+ frontendLogger.error(e.what(), "Error while processing response received over DoH3"));
}
catch (...) {
- errlog("Unspecified error while processing response received over DoH3");
+ SLOG(errlog("Unspecified error while processing response received over DoH3"),
+ frontendLogger.info(Logr::Error, "Unspecified error while processing response received over DoH3"));
}
}
}
{
try {
std::shared_ptr<DOH3Frontend>& frontend = clientState->doh3Frontend;
+ auto frontendLogger = dnsdist::logging::getTopLogger()->withName("doh3-frontend")->withValues("address", Logging::Loggable(clientState->local));
frontend->d_server_config->clientState = clientState;
frontend->d_server_config->df = clientState->doh3Frontend;
+ frontend->d_logger = frontendLogger;
setThreadName("dnsdist/doh3");
}
if (std::find(readyFDs.begin(), readyFDs.end(), responseReceiverFD) != readyFDs.end()) {
- flushResponses(frontend->d_server_config->d_responseReceiver);
+ flushResponses(frontend->d_server_config->d_responseReceiver, *frontendLogger);
}
for (auto conn = frontend->d_server_config->d_connections.begin(); conn != frontend->d_server_config->d_connections.end();) {
}
}
catch (const std::exception& exp) {
- vinfolog("Caught exception in the main DoH3 thread: %s", exp.what());
+ VERBOSESLOG(infolog("Caught exception in the main DoH3 thread: %s", exp.what()),
+ frontendLogger->error(Logr::Info, exp.what(), "Caught exception in the main DoH3 thread"));
}
catch (...) {
- vinfolog("Unknown exception in the main DoH3 thread");
+ VERBOSESLOG(infolog("Unknown exception in the main DoH3 thread"),
+ frontendLogger->info(Logr::Info, "Caught unknown exception in the main DoH3 thread"));
}
}
}
#ifdef HAVE_DNS_OVER_HTTP3
#include "channel.hh"
+#include "dolog.hh"
#include "iputils.hh"
#include "libssl.hh"
#include "stat_t.hh"
void setup();
void reloadCertificates();
+ const Logr::Logger& getLogger()
+ {
+ return *d_logger;
+ }
+ std::shared_ptr<const Logr::Logger> d_logger{nullptr};
std::unique_ptr<DOH3ServerConfig> d_server_config;
ComboAddress d_local;
return encryptedTokenPacket;
}
catch (const std::exception& exp) {
- vinfolog("Error while minting DoH3 token: %s", exp.what());
+ VERBOSESLOG(infolog("Error while minting DoH3 token: %s", exp.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, exp.what(), "Error while minting DoH3 token"));
throw;
}
}
return PacketBuffer(plainText.begin() + (sizeof(ttd) + addrBytes.size()), plainText.end());
}
catch (const std::exception& exp) {
- vinfolog("Error while validating DoH3 token: %s", exp.what());
+ VERBOSESLOG(infolog("Error while validating DoH3 token: %s", exp.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, exp.what(), "Error while validating DoH3 token"));
return std::nullopt;
}
}
auto ret = sendto(sock.getHandle(), buffer.data(), buffer.size(), flags, reinterpret_cast<const struct sockaddr*>(&peer), peer.getSocklen());
if (ret < 0) {
auto error = errno;
- vinfolog("Error while sending QUIC datagram of size %d to %s: %s", buffer.size(), peer.toStringWithPort(), stringerror(error));
+ VERBOSESLOG(infolog("Error while sending QUIC datagram of size %d to %s: %s", buffer.size(), peer.toStringWithPort(), stringerror(error)),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, error, "Error while sending QUIC datagram", "size", Logging::Loggable(buffer.size()), "destination", Logging::Loggable(peer)));
}
return;
}
sendMsgWithOptions(sock.getHandle(), buffer.data(), buffer.size(), &peer, &local, 0, 0);
}
catch (const std::exception& exp) {
- vinfolog("Error while sending QUIC datagram of size %d from %s to %s: %s", buffer.size(), local.toStringWithPort(), peer.toStringWithPort(), exp.what());
+ VERBOSESLOG(infolog("Error while sending QUIC datagram of size %d from %s to %s: %s", buffer.size(), local.toStringWithPort(), peer.toStringWithPort(), exp.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, exp.what(), "Error while sending QUIC datagram", "size", Logging::Loggable(buffer.size()), "source", Logging::Loggable(local), "destination", Logging::Loggable(peer)));
}
}
if (!unit->ids.selfGenerated) {
auto udiff = unit->ids.queryRealTime.udiff();
- vinfolog("Got answer from %s, relayed to %s (quic, %d bytes), took %d us", unit->downstream->d_config.remote.toStringWithPort(), unit->ids.origRemote.toStringWithPort(), unit->response.size(), udiff);
+ VERBOSESLOG(infolog("Got answer from %s, relayed to %s (quic, %d bytes), took %d us", unit->downstream->d_config.remote.toStringWithPort(), unit->ids.origRemote.toStringWithPort(), unit->response.size(), udiff),
+ dnsResponse.getLogger()->info("Got answer from backend, relayed to client"));
auto backendProtocol = unit->downstream->getProtocol();
if (backendProtocol == dnsdist::Protocol::DoUDP && unit->tcp) {
try {
if (!unit->dsc->d_responseSender.send(std::move(unit))) {
++dnsdist::metrics::g_stats.doqResponsePipeFull;
- vinfolog("Unable to pass a %s to the DoQ worker thread because the pipe is full", description);
+ VERBOSESLOG(infolog("Unable to pass a %s to the DoQ worker thread because the pipe is full", description),
+ dnsdist::logging::getTopLogger()->info(Logr::Info, std::string("Unable to pass a ") + std::string(description) + " to the DoQ worker thread because the pipe is full"));
}
}
catch (const std::exception& e) {
- vinfolog("Unable to pass a %s to the DoQ worker thread because we couldn't write to the pipe: %s", description, e.what());
+ VERBOSESLOG(infolog("Unable to pass a %s to the DoQ worker thread because we couldn't write to the pipe: %s", description, e.what()),
+ dnsdist::logging::getTopLogger()->error(Logr::Info, e.what(), std::string("Unable to pass a ") + std::string(description) + " to the DoQ worker thread because we couldn't write to the pipe"));
}
}
ClientState& clientState = *dsc->clientState;
if (!dnsdist::configuration::getCurrentRuntimeConfiguration().d_ACL.match(remote)) {
- vinfolog("Query from %s (DoQ) dropped because of ACL", remote.toStringWithPort());
+ VERBOSESLOG(infolog("Query from %s (DoQ) dropped because of ACL", remote.toStringWithPort()),
+ dsc->df->getLogger().info("DoQ query dropped because of ACL", "address", Logging::Loggable(remote)));
++dnsdist::metrics::g_stats.aclDrops;
unit->response.clear();
return;
}
catch (const std::exception& e) {
- vinfolog("Got an error in DOQ question thread while parsing a query from %s, id %d: %s", remote.toStringWithPort(), queryId, e.what());
- handleImmediateResponse(std::move(unit), "DoQ internal error");
+ if (unit) {
+ VERBOSESLOG(infolog("Got an error in DOQ question thread while parsing a query from %s, id %d: %s", remote.toStringWithPort(), queryId, e.what()),
+ unit->dsc->df->getLogger().error(Logr::Info, e.what(), "Got an error in DOQ question thread while parsing a query", "address", Logging::Loggable(remote), "query-id", Logging::Loggable(queryId)));
+ handleImmediateResponse(std::move(unit), "DoQ internal error");
+ }
return;
}
}
processDOQQuery(std::move(unit));
}
catch (const std::exception& exp) {
- vinfolog("Had error handling DoQ DNS packet from %s: %s", remote.toStringWithPort(), exp.what());
+ VERBOSESLOG(infolog("Had error handling DoQ DNS packet from %s: %s", remote.toStringWithPort(), exp.what()),
+ dsc.df->getLogger().error(Logr::Info, exp.what(), "Had error handling DoQ DNS packet", "address", Logging::Loggable(remote)));
}
}
-static void flushResponses(pdns::channel::Receiver<DOQUnit>& receiver)
+static void flushResponses(pdns::channel::Receiver<DOQUnit>& receiver, const Logr::Logger& frontendLogger)
{
for (;;) {
try {
}
}
catch (const std::exception& e) {
- errlog("Error while processing response received over DoQ: %s", e.what());
+ SLOG(errlog("Error while processing response received over DoQ: %s", e.what()),
+ frontendLogger.error(e.what(), "Error while processing response received over DoQ"));
}
catch (...) {
- errlog("Unspecified error while processing response received over DoQ");
+ SLOG(errlog("Unspecified error while processing response received over DoQ"),
+ frontendLogger.info(Logr::Error, "Unspecified error while processing response received over DoQ"));
}
}
}
{
try {
std::shared_ptr<DOQFrontend>& frontend = clientState->doqFrontend;
+ auto frontendLogger = dnsdist::logging::getTopLogger()->withName("doq-frontend")->withValues("address", Logging::Loggable(clientState->local));
frontend->d_server_config->clientState = clientState;
frontend->d_server_config->df = clientState->doqFrontend;
+ frontend->d_logger = frontendLogger;
setThreadName("dnsdist/doq");
}
if (std::find(readyFDs.begin(), readyFDs.end(), responseReceiverFD) != readyFDs.end()) {
- flushResponses(frontend->d_server_config->d_responseReceiver);
+ flushResponses(frontend->d_server_config->d_responseReceiver, *frontendLogger);
}
for (auto conn = frontend->d_server_config->d_connections.begin(); conn != frontend->d_server_config->d_connections.end();) {
}
}
catch (const std::exception& exp) {
- vinfolog("Caught exception in the main DoQ thread: %s", exp.what());
+ VERBOSESLOG(infolog("Caught exception in the main DoQ thread: %s", exp.what()),
+ frontendLogger->error(Logr::Info, exp.what(), "Caught exception in the main DoQ thread"));
}
catch (...) {
- vinfolog("Unknown exception in the main DoQ thread");
+ VERBOSESLOG(infolog("Unknown exception in the main DoQ thread"),
+ frontendLogger->info(Logr::Info, "Caught unknown exception in the main DoQ thread"));
}
}
}
#include <memory>
#include "config.h"
-#include "channel.hh"
-#include "iputils.hh"
-#include "libssl.hh"
-#include "noinitvector.hh"
-#include "doq.hh"
-#include "stat_t.hh"
struct DOQServerConfig;
struct DownstreamState;
#ifdef HAVE_DNS_OVER_QUIC
+#include "channel.hh"
#include "dnsdist-idstate.hh"
#include "doq-common.hh"
+#include "dolog.hh"
+#include "iputils.hh"
+#include "libssl.hh"
+#include "noinitvector.hh"
+#include "stat_t.hh"
struct DOQFrontend
{
void setup();
void reloadCertificates();
+ const Logr::Logger& getLogger()
+ {
+ return *d_logger;
+ }
+ std::shared_ptr<const Logr::Logger> d_logger{nullptr};
std::unique_ptr<DOQServerConfig> d_server_config;
dnsdist::doq::QuicheParams d_quicheParams;
ComboAddress d_local;
}
}
catch (const std::exception& e) {
- infolog("Error parsing the status header for stream ID %d: %s", frame->hd.stream_id, e.what());
+ SLOG(infolog("Error parsing the status header for stream ID %d: %s", frame->hd.stream_id, e.what()),
+ dnsdist::logging::getTopLogger()->error(e.what(), "Error parsing the status header for stream", "stream-id", Logging::Loggable(frame->hd.stream_id)));
return NGHTTP2_ERR_CALLBACK_FAILURE;
}
}