From: Remi Gacogne <remi.gacogne@powerdns.com>
Date: Thu, 11 May 2023 13:22:25 +0000 (+0200)
Subject: dnsdist: Add the query ID to health-check log messages, fix nits
X-Git-Tag: dnsdist-1.8.1~23^2
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=f502527a40df345f80fbbaf3585e58d9a351dc38;p=thirdparty%2Fpdns.git

dnsdist: Add the query ID to health-check log messages, fix nits

(cherry picked from commit 385fca46ffe3a6f84806aab67d47c8b80ebac26c)
---

diff --git a/pdns/dnsdistdist/dnsdist-healthchecks.cc b/pdns/dnsdistdist/dnsdist-healthchecks.cc
index 4a52052276..a173772b83 100644
--- a/pdns/dnsdistdist/dnsdist-healthchecks.cc
+++ b/pdns/dnsdistdist/dnsdist-healthchecks.cc
@@ -106,15 +106,13 @@ static bool handleResponse(std::shared_ptr<HealthCheckData>& data)
       return false;
     }
   }
-  catch(const std::exception& e)
-  {
+  catch(const std::exception& e) {
     if (g_verboseHealthChecks) {
       infolog("Error checking the health of backend %s: %s", ds->getNameWithAddr(), e.what());
     }
     return false;
   }
-  catch(...)
-  {
+  catch (...) {
     if (g_verboseHealthChecks) {
       infolog("Unknown exception while checking the health of backend %s", ds->getNameWithAddr());
     }
@@ -171,8 +169,9 @@ static void healthCheckUDPCallback(int fd, FDMultiplexer::funcparam_t& param)
   data->d_buffer.resize(512);
   auto got = recvfrom(data->d_udpSocket.getHandle(), &data->d_buffer.at(0), data->d_buffer.size(), 0, reinterpret_cast<sockaddr *>(&from), &fromlen);
   if (got < 0) {
+    int savederrno = errno;
     if (g_verboseHealthChecks) {
-      infolog("Error receiving health check response from %s: %s", data->d_ds->d_config.remote.toStringWithPort(), stringerror());
+      infolog("Error receiving health check response from %s: %s", data->d_ds->d_config.remote.toStringWithPort(), stringerror(savederrno));
     }
     data->d_ds->submitHealthCheckResult(data->d_initial, false);
     return;
@@ -263,8 +262,7 @@ static void healthCheckTCPCallback(int fd, FDMultiplexer::funcparam_t& param)
 
 bool queueHealthCheck(std::unique_ptr<FDMultiplexer>& mplexer, const std::shared_ptr<DownstreamState>& ds, bool initialCheck)
 {
-  try
-  {
+  try {
     uint16_t queryID = dnsdist::getRandomDNSID();
     DNSName checkName = ds->d_config.checkName;
     uint16_t checkType = ds->d_config.checkType.getCode();
@@ -343,7 +341,7 @@ bool queueHealthCheck(std::unique_ptr<FDMultiplexer>& mplexer, const std::shared
       if (sent < 0) {
         int ret = errno;
         if (g_verboseHealthChecks) {
-          infolog("Error while sending a health check query to backend %s: %d", ds->getNameWithAddr(), ret);
+          infolog("Error while sending a health check query (ID %d) to backend %s: %d", queryID, ds->getNameWithAddr(), ret);
         }
         return false;
       }
@@ -359,18 +357,18 @@ bool queueHealthCheck(std::unique_ptr<FDMultiplexer>& mplexer, const std::shared
       }
     }
     else {
-      time_t now = time(nullptr);
       data->d_tcpHandler = std::make_unique<TCPIOHandler>(ds->d_config.d_tlsSubjectName, ds->d_config.d_tlsSubjectIsAddr, sock.releaseHandle(), timeval{ds->d_config.checkTimeout,0}, ds->d_tlsCtx);
       data->d_ioState = std::make_unique<IOStateHandler>(*mplexer, data->d_tcpHandler->getDescriptor());
       if (ds->d_tlsCtx) {
         try {
+          time_t now = time(nullptr);
           auto tlsSession = g_sessionCache.getSession(ds->getID(), now);
           if (tlsSession) {
             data->d_tcpHandler->setTLSSession(tlsSession);
           }
         }
         catch (const std::exception& e) {
-          vinfolog("Unable to restore a TLS session for the DoT healthcheck: %s", e.what());
+          vinfolog("Unable to restore a TLS session for the DoT healthcheck for backend %s: %s", ds->getNameWithAddr(), e.what());
         }
       }
       data->d_tcpHandler->tryConnect(ds->d_config.tcpFastOpen, ds->d_config.remote);
@@ -392,15 +390,13 @@ bool queueHealthCheck(std::unique_ptr<FDMultiplexer>& mplexer, const std::shared
 
     return true;
   }
-  catch (const std::exception& e)
-  {
+  catch (const std::exception& e) {
     if (g_verboseHealthChecks) {
       infolog("Error checking the health of backend %s: %s", ds->getNameWithAddr(), e.what());
     }
     return false;
   }
-  catch (...)
-  {
+  catch (...) {
     if (g_verboseHealthChecks) {
       infolog("Unknown exception while checking the health of backend %s", ds->getNameWithAddr());
     }
@@ -419,6 +415,10 @@ void handleQueuedHealthChecks(FDMultiplexer& mplexer, bool initial)
       }
       break;
     }
+    if (ret > 0) {
+      /* we got at least one event other than a timeout */
+      continue;
+    }
 
     handleH2Timeouts(mplexer, now);
 
@@ -430,6 +430,7 @@ void handleQueuedHealthChecks(FDMultiplexer& mplexer, bool initial)
 
       auto data = boost::any_cast<std::shared_ptr<HealthCheckData>>(timeout.second);
       try {
+        /* UDP does not have an IO state, H2 is handled separately */
         if (data->d_ioState) {
           data->d_ioState.reset();
         }
@@ -437,19 +438,19 @@ void handleQueuedHealthChecks(FDMultiplexer& mplexer, bool initial)
           mplexer.removeReadFD(timeout.first);
         }
         if (g_verboseHealthChecks) {
-          infolog("Timeout while waiting for the health check response from backend %s", data->d_ds->getNameWithAddr());
+          infolog("Timeout while waiting for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
         }
 
         data->d_ds->submitHealthCheckResult(initial, false);
       }
       catch (const std::exception& e) {
         if (g_verboseHealthChecks) {
-          infolog("Error while dealing with a timeout for the health check response from backend %s: %s", data->d_ds->getNameWithAddr(), e.what());
+          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());
         }
       }
       catch (...) {
         if (g_verboseHealthChecks) {
-          infolog("Error while dealing with a timeout for the health check response from backend %s", data->d_ds->getNameWithAddr());
+          infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
         }
       }
     }
@@ -461,21 +462,22 @@ void handleQueuedHealthChecks(FDMultiplexer& mplexer, bool initial)
       }
       auto data = boost::any_cast<std::shared_ptr<HealthCheckData>>(timeout.second);
       try {
+        /* UDP does not block while writing, H2 is handled separately */
         data->d_ioState.reset();
         if (g_verboseHealthChecks) {
-          infolog("Timeout while waiting for the health check response from backend %s", data->d_ds->getNameWithAddr());
+          infolog("Timeout while waiting for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
         }
 
         data->d_ds->submitHealthCheckResult(initial, false);
       }
       catch (const std::exception& e) {
         if (g_verboseHealthChecks) {
-          infolog("Error while dealing with a timeout for the health check response from backend %s: %s", data->d_ds->getNameWithAddr(), e.what());
+          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());
         }
       }
       catch (...) {
         if (g_verboseHealthChecks) {
-          infolog("Error while dealing with a timeout for the health check response from backend %s", data->d_ds->getNameWithAddr());
+          infolog("Error while dealing with a timeout for the health check response (ID %d) from backend %s", data->d_queryID, data->d_ds->getNameWithAddr());
         }
       }
     }