From: Alex Rousskov <rousskov@measurement-factory.com>
Date: Thu, 19 May 2022 19:34:05 +0000 (+0000)
Subject: Fix PeerConnector::handleNegotiationResult() error debugging (#1055)
X-Git-Tag: SQUID_6_0_1~182
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=70638a6a578339356acb15717ed0138a51f9bb24;p=thirdparty%2Fsquid.git

Fix PeerConnector::handleNegotiationResult() error debugging (#1055)

    ERROR: failure while establishing TLS connection on FD: 70x123456*1

* FD value was malformed. Now report all Connection details instead.
* Error details were not reported (a pointer value was reported).

Also, for error message prefix, use a single/constant phrase instead of
error-dependent phrases. This principle is for level-0/1 messages, but
it is OK to apply it here as well, especially given the related TODO.

Also improved RawPointer reporting so that we can use it for this fix.
Some of these changes are not necessary (for the final code state), but
all of them except the last one were necessary at some point during the
work on this fix, and they all may become handy in the future:

* Print nothing if ptr is nil. Both existing callers benefit from this.
* Allow the caller to set the label/object delimiter. Also faster.
* Support reporting object values on a dedicated Debug::Extra line.
* Support (and do not attempt to print) nil RawPointer() labels.
---

diff --git a/src/base/IoManip.h b/src/base/IoManip.h
index 7f14953ead..f13c697b62 100644
--- a/src/base/IoManip.h
+++ b/src/base/IoManip.h
@@ -9,17 +9,25 @@
 #ifndef SQUID_SRC_BASE_IO_MANIP_H
 #define SQUID_SRC_BASE_IO_MANIP_H
 
+#include "debug/Stream.h"
+
 #include <iostream>
 #include <iomanip>
 
-/// debugs objects pointed by possibly nil pointers: label=object
+/// Safely prints an object pointed to by the given pointer: [label]<object>
+/// Prints nothing at all if the pointer is nil.
 template <class Pointer>
 class RawPointerT {
 public:
     RawPointerT(const char *aLabel, const Pointer &aPtr):
         label(aLabel), ptr(aPtr) {}
+
+    /// Report the pointed-to-object on a dedicated Debug::Extra line.
+    RawPointerT<Pointer> &asExtra() { onExtraLine = true; return *this; }
+
     const char *label; /// the name or description of the being-debugged object
     const Pointer &ptr; /// a possibly nil pointer to the being-debugged object
+    bool onExtraLine = false;
 };
 
 /// convenience wrapper for creating  RawPointerT<> objects
@@ -35,11 +43,17 @@ template <class Pointer>
 inline std::ostream &
 operator <<(std::ostream &os, const RawPointerT<Pointer> &pd)
 {
-    os << pd.label << '=';
-    if (pd.ptr)
-        os << *pd.ptr;
-    else
-        os << "[nil]";
+    if (!pd.ptr)
+        return os;
+
+    if (pd.onExtraLine)
+        os << Debug::Extra;
+
+    if (pd.label)
+        os << pd.label;
+
+    os << *pd.ptr;
+
     return os;
 }
 
diff --git a/src/security/PeerConnector.cc b/src/security/PeerConnector.cc
index 61eac7eb5e..27c6ceedb8 100644
--- a/src/security/PeerConnector.cc
+++ b/src/security/PeerConnector.cc
@@ -276,8 +276,9 @@ Security::PeerConnector::handleNegotiationResult(const Security::IoResult &resul
     }
 
     // TODO: Honor result.important when working in a reverse proxy role?
-    debugs(83, 2, "ERROR: " << result.errorDescription <<
-           " while establishing TLS connection on FD: " << serverConnection()->fd << result.errorDetail);
+    debugs(83, 2, "ERROR: Cannot establish a TLS connection to " << serverConnection() << ':' <<
+           Debug::Extra << "problem: " << result.errorDescription <<
+           RawPointer("detail: ", result.errorDetail).asExtra());
     recordNegotiationDetails();
     noteNegotiationError(result.errorDetail);
 }
@@ -339,7 +340,7 @@ Security::PeerConnector::sslCrtvdHandleReply(Ssl::CertValidationResponse::Pointe
     if (Debug::Enabled(83, 5)) {
         Security::SessionPointer ssl(fd_table[serverConnection()->fd].ssl);
         SBuf *server = static_cast<SBuf *>(SSL_get_ex_data(ssl.get(), ssl_ex_index_server));
-        debugs(83,5, RawPointer("host", server) << " cert validation result: " << validationResponse->resultCode);
+        debugs(83, 5, "cert validation result: " << validationResponse->resultCode << RawPointer(" host: ", server));
     }
 
     if (validationResponse->resultCode == ::Helper::Error) {