Report cache_peer context in probe and standby pool messages (#1960)

The absence of the usual "current master transaction:..." detail in
certain errors raises "Has Squid lost the current transaction context?"
red flags:

    ERROR: Connection to peerXyz failed

In some cases, Squid may have lost that context, but for cache_peer TCP
probes, Squid has not because those probes are not associated with
master transactions. It is difficult to distinguish the two cases
because no processing context is reported.  To address those concerns,
we now report current cache_peer probing context (instead of just not
reporting absent master transaction context):

    ERROR: Connection to peerXyz failed
        current cache_peer probe: peerXyzIP

When maintaining a cache_peer standy=N connection pool, Squid has and
now reports both contexts, attributing messages to pool maintenance:

    ERROR: Connection to peerXyz failed
        current cache_peer standby pool: peerXyz
        current master transaction: master1234

The new PrecomputedCodeContext class handles both reporting cases and
can be reused whenever the cost of pre-computing detailCodeContext()
output is acceptable.

Author: eduard-bagdasaryan

src/CachePeer.cc

@@ -8,13 +8,15 @@
 
 #include "squid.h"
 #include "acl/Gadgets.h"
+#include "base/PrecomputedCodeContext.h"
 #include "CachePeer.h"
 #include "defines.h"
 #include "neighbors.h"
 #include "NeighborTypeDomainList.h"
 #include "pconn.h"
 #include "PeerDigest.h"
 #include "PeerPoolMgr.h"
+#include "sbuf/Stream.h"
 #include "SquidConfig.h"
 #include "util.h"
 
@@ -23,7 +25,8 @@ CBDATA_CLASS_INIT(CachePeer);
 CachePeer::CachePeer(const char * const hostname):
     name(xstrdup(hostname)),
     host(xstrdup(hostname)),
-    tlsContext(secure, sslContext)
+    tlsContext(secure, sslContext),
+    probeCodeContext(new PrecomputedCodeContext("cache_peer probe", ToSBuf("current cache_peer probe: ", *this)))
 {
     Tolower(host); // but .name preserves original spelling
 }

src/CachePeer.h

@@ -11,6 +11,7 @@
 
 #include "acl/forward.h"
 #include "base/CbcPointer.h"
+#include "base/forward.h"
 #include "enums.h"
 #include "http/StatusCode.h"
 #include "icp_opcode.h"
@@ -224,6 +225,8 @@ class CachePeer
     int front_end_https = 0; ///< 0 - off, 1 - on, 2 - auto
     int connection_auth = 2; ///< 0 - off, 1 - on, 2 - auto
 
+    PrecomputedCodeContextPointer probeCodeContext;
+
 private:
     void countFailure();
 };

src/PeerPoolMgr.cc

@@ -9,6 +9,7 @@
 #include "squid.h"
 #include "AccessLogEntry.h"
 #include "base/AsyncCallbacks.h"
+#include "base/PrecomputedCodeContext.h"
 #include "base/RunnersRegistry.h"
 #include "CachePeer.h"
 #include "CachePeers.h"
@@ -23,18 +24,27 @@
 #include "neighbors.h"
 #include "pconn.h"
 #include "PeerPoolMgr.h"
+#include "sbuf/Stream.h"
 #include "security/BlindPeerConnector.h"
 #include "SquidConfig.h"
 
 CBDATA_CLASS_INIT(PeerPoolMgr);
 
 PeerPoolMgr::PeerPoolMgr(CachePeer *aPeer): AsyncJob("PeerPoolMgr"),
     peer(cbdataReference(aPeer)),
-    request(),
     transportWait(),
     encryptionWait(),
     addrUsed(0)
 {
+    const auto mx = MasterXaction::MakePortless<XactionInitiator::initPeerPool>();
+
+    codeContext = new PrecomputedCodeContext("cache_peer standby pool", ToSBuf("current cache_peer standby pool: ", *peer,
+            Debug::Extra, "current master transaction: ", mx->id));
+
+    // ErrorState, getOutgoingAddress(), and other APIs may require a request.
+    // We fake one. TODO: Optionally send this request to peers?
+    request = new HttpRequest(Http::METHOD_OPTIONS, AnyP::PROTO_HTTP, "http", "*", mx);
+    request->url.host(peer->host);
 }
 
 PeerPoolMgr::~PeerPoolMgr()
@@ -46,13 +56,6 @@ void
 PeerPoolMgr::start()
 {
     AsyncJob::start();
-
-    const auto mx = MasterXaction::MakePortless<XactionInitiator::initPeerPool>();
-    // ErrorState, getOutgoingAddress(), and other APIs may require a request.
-    // We fake one. TODO: Optionally send this request to peers?
-    request = new HttpRequest(Http::METHOD_OPTIONS, AnyP::PROTO_HTTP, "http", "*", mx);
-    request->url.host(peer->host);
-
     checkpoint("peer initialized");
 }
 
@@ -228,7 +231,14 @@ PeerPoolMgr::checkpoint(const char *reason)
 void
 PeerPoolMgr::Checkpoint(const Pointer &mgr, const char *reason)
 {
-    CallJobHere1(48, 5, mgr, PeerPoolMgr, checkpoint, reason);
+    if (!mgr.valid()) {
+        debugs(48, 5, reason << " but no mgr");
+        return;
+    }
+
+    CallService(mgr->codeContext, [&] {
+        CallJobHere1(48, 5, mgr, PeerPoolMgr, checkpoint, reason);
+    });
 }
 
 /// launches PeerPoolMgrs for peers configured with standby.limit
@@ -254,7 +264,9 @@ PeerPoolMgrsRr::syncConfig()
         if (p->standby.limit) {
             p->standby.mgr = new PeerPoolMgr(p);
             p->standby.pool = new PconnPool(p->name, p->standby.mgr);
-            AsyncJob::Start(p->standby.mgr.get());
+            CallService(p->standby.mgr->codeContext, [&] {
+                AsyncJob::Start(p->standby.mgr.get());
+            });
         }
     }
 }

src/PeerPoolMgr.h

@@ -10,6 +10,7 @@
 #define SQUID_SRC_PEERPOOLMGR_H
 
 #include "base/AsyncJob.h"
+#include "base/forward.h"
 #include "base/JobWait.h"
 #include "comm/forward.h"
 #include "security/forward.h"
@@ -32,6 +33,8 @@ class PeerPoolMgr: public AsyncJob
     explicit PeerPoolMgr(CachePeer *aPeer);
     ~PeerPoolMgr() override;
 
+    PrecomputedCodeContextPointer codeContext;
+
 protected:
     /* AsyncJob API */
     void start() override;

src/base/Makefile.am

@@ -51,6 +51,7 @@ libbase_la_SOURCES = \
 	OnOff.h \
 	Packable.h \
 	PackableStream.h \
+	PrecomputedCodeContext.h \
 	Random.cc \
 	Random.h \
 	RandomUuid.cc \

src/base/PrecomputedCodeContext.h

@@ -0,0 +1,37 @@
+/*
+ * Copyright (C) 1996-2024 The Squid Software Foundation and contributors
+ *
+ * Squid software is distributed under GPLv2+ license and includes
+ * contributions from numerous individuals and organizations.
+ * Please see the COPYING and CONTRIBUTORS files for details.
+ */
+
+#ifndef SQUID_SRC_BASE_PRECOMPUTEDCODECONTEXT_H
+#define SQUID_SRC_BASE_PRECOMPUTEDCODECONTEXT_H
+
+#include "base/CodeContext.h"
+#include "base/InstanceId.h"
+#include "sbuf/SBuf.h"
+
+#include <ostream>
+
+/// CodeContext with constant details known at construction time
+class PrecomputedCodeContext: public CodeContext
+{
+public:
+    typedef RefCount<PrecomputedCodeContext> Pointer;
+
+    PrecomputedCodeContext(const char *gist, const SBuf &detail): gist_(gist), detail_(detail)
+    {}
+
+    /* CodeContext API */
+    ScopedId codeContextGist() const override { return ScopedId(gist_); }
+    std::ostream &detailCodeContext(std::ostream &os) const override { return os << Debug::Extra << detail_; }
+
+private:
+    const char *gist_; ///< the id used in codeContextGist()
+    const SBuf detail_; ///< the detail used in detailCodeContext()
+};
+
+#endif /* SQUID_SRC_BASE_PRECOMPUTEDCODECONTEXT_H */
+

src/base/forward.h

@@ -15,6 +15,7 @@ class AsyncJob;
 class CallDialer;
 class CodeContext;
 class DelayedAsyncCalls;
+class PrecomputedCodeContext;
 class Raw;
 class RegexPattern;
 class ScopedId;
@@ -28,6 +29,7 @@ template<class Answer> class AsyncCallback;
 typedef CbcPointer<AsyncJob> AsyncJobPointer;
 typedef RefCount<CodeContext> CodeContextPointer;
 using AsyncCallPointer = RefCount<AsyncCall>;
+using PrecomputedCodeContextPointer = RefCount<PrecomputedCodeContext>;
 
 #endif /* SQUID_SRC_BASE_FORWARD_H */
 

src/neighbors.cc

@@ -14,6 +14,7 @@
 #include "base/EnumIterator.h"
 #include "base/IoManip.h"
 #include "base/PackableStream.h"
+#include "base/PrecomputedCodeContext.h"
 #include "CacheDigest.h"
 #include "CachePeer.h"
 #include "CachePeers.h"
@@ -569,9 +570,12 @@ neighborsUdpPing(HttpRequest * request,
 
     reqnum = icpSetCacheKey((const cache_key *)entry->key);
 
+    const auto savedContext = CodeContext::Current();
     for (size_t i = 0; i < Config.peers->size(); ++i) {
         const auto p = &Config.peers->nextPeerToPing(i);
 
+        CodeContext::Reset(p->probeCodeContext);
+
         debugs(15, 5, "candidate: " << *p);
 
         if (!peerWouldBePinged(p, ps))
@@ -660,6 +664,7 @@ neighborsUdpPing(HttpRequest * request,
         if ((p->type != PEER_MULTICAST) && (p->stats.probe_start == 0))
             p->stats.probe_start = squid_curtime;
     }
+    CodeContext::Reset(savedContext);
 
     /*
      * How many replies to expect?
@@ -1053,8 +1058,7 @@ int
 neighborUp(const CachePeer * p)
 {
     if (!p->tcp_up) {
-        // TODO: When CachePeer gets its own CodeContext, pass that context instead of nullptr
-        CallService(nullptr, [&] {
+        CallService(p->probeCodeContext, [&] {
             peerProbeConnect(const_cast<CachePeer*>(p));
         });
         return 0;
@@ -1170,8 +1174,12 @@ peerDnsRefreshCheck(void *)
 static void
 peerDnsRefreshStart()
 {
-    for (const auto &p: CurrentCachePeers())
+    const auto savedContext = CodeContext::Current();
+    for (const auto &p: CurrentCachePeers()) {
+        CodeContext::Reset(p->probeCodeContext);
         ipcache_nbgethostbyname(p->host, peerDNSConfigure, p.get());
+    }
+    CodeContext::Reset(savedContext);
 
     peerScheduleDnsRefreshCheck(3600.0);
 }