]> git.ipfire.org Git - thirdparty/squid.git/commitdiff
Report context of level-0/1 cache.log messages (#483)
authorAlex Rousskov <rousskov@measurement-factory.com>
Fri, 4 Oct 2019 14:14:09 +0000 (14:14 +0000)
committerSquid Anubis <squid-anubis@squid-cache.org>
Fri, 11 Oct 2019 13:03:45 +0000 (13:03 +0000)
Most runtime level-0/1 cache.log messages do not carry information
sufficient to identify the transaction that caused the problem. Admins
are forced to guess the transaction based on message timestamp and, if
they are lucky to get one, request URL. The associated triage and
mitigation delay costs are often significant and can be huge, especially
when administering busy proxies in complex deployment environments.

The focus of this change is associating level-0/1 cache.log messages
with access.log records, but the same API is also used for associating
master transactions with (sections of) debugging cache.log messages.

Since level-0/1 messages are rare, association code usually wastes
resources. This performance overhead is reduced by saving pointers to
the existing transaction information (e.g., ALE). ALE gives access to
HttpRequest and MasterXaction (where available), is available in
contexts where HttpRequest and MasterXaction do not exist, and (unlike
HttpRequest) represents the whole master transaction rather than its
(often repeated) component.

CodeContext::Current() represents the current master transaction (or a
similar "primary processing task" context). A new context is created
when the master transaction (or a similar "primary processing task")
starts. Context changes usually happen in low-level transaction-unaware
callback-calling "context switching" code such as DoSelect().

The vast majority of AsyncCalls, including AsyncCall-based callbacks,
should run in their creator's context. This association is easily
automated. The primary difficulty is in handling C-style typeless calls
that prohibit context storage and restoration automation:

* In our design, the "context switching" code is ultimately responsible
  for associating the being-saved callback with the current code context
  and for restoring CodeContext::Current() when calling that callback.

* An alternative design would task the higher-level callback creator and
  callback recipient with saving/restoring CodeContext::Current(). That
  design is inferior because there are a lot more callback creators and
  recipients than "context switchers". That alternative would require a
  lot more manual changes.

The code context remains unknown if the context creator is not
instrumented to set CodeContext::Current(). TODO: Instrument ICP query
listener. Check for others.

The code context gets forgotten if the context switcher dealing with
C-style callbacks does not remember and restore CodeContext::Current().
TODO: Instrument remaining DoSelect()s, event.cc, as well as DNS, ICP,
HTCP, and IPC listeners/handlers. Check for others.

This change covers epoll DoSelect(), TcpAcceptor, ConnStateData, and SMP
disk I/O (IpcIoFile). It already annotates several level-0/1 messages
and significantly improves complex debugging. The remaining
instrumentation TODOs are likely to use similar techniques.

Squid might report wrong context until all context switchers are
instrumented, but the vast majority of uninstrumented cases result in
benign loss of context knowledge rather than mis-attribution. No design
guarantees correct attribution until all C-style callbacks are gone.

TODO: Remove legacy ctx_enter()/exit() debugging that covers very little
while suffering from worse mis-attribution problems.

Also log "-" instead of the made-up method "NONE".

33 files changed:
src/AccessLogEntry.cc
src/AccessLogEntry.h
src/Debug.h
src/DiskIO/IpcIo/IpcIoFile.cc
src/DiskIO/IpcIo/IpcIoFile.h
src/anyp/PortCfg.cc
src/anyp/PortCfg.h
src/base/AsyncCall.cc
src/base/AsyncCall.h
src/base/AsyncCallQueue.cc
src/base/CodeContext.cc [new file with mode: 0644]
src/base/CodeContext.h [new file with mode: 0644]
src/base/InstanceId.h
src/base/Makefile.am
src/base/RefCount.h
src/base/Subscription.h
src/base/TextException.cc
src/base/TextException.h
src/base/forward.h
src/client_side.cc
src/client_side_request.cc
src/comm.cc
src/comm/Connection.cc
src/comm/Connection.h
src/comm/ModEpoll.cc
src/comm/TcpAcceptor.cc
src/comm/TcpAcceptor.h
src/debug.cc
src/fde.h
src/htcp.cc
src/http/Stream.cc
src/neighbors.cc
src/tests/stub_libcomm.cc

index c1a8b15a364308df139bc6d719596b7d50c455d4..cf95c153e3f23e4d4565e62d5df7eb9aa0eba680 100644 (file)
@@ -120,6 +120,49 @@ AccessLogEntry::~AccessLogEntry()
 #endif
 }
 
+ScopedId
+AccessLogEntry::codeContextGist() const
+{
+    if (request) {
+        if (const auto &mx = request->masterXaction)
+            return mx->id.detach();
+    }
+    // TODO: Carefully merge ALE and MasterXaction.
+    return ScopedId("ALE w/o master");
+}
+
+std::ostream &
+AccessLogEntry::detailCodeContext(std::ostream &os) const
+{
+    // TODO: Consider printing all instead of the first most important detail.
+
+    if (request) {
+        if (const auto &mx = request->masterXaction)
+            return os << Debug::Extra << "current master transaction: " << mx->id;
+    }
+
+    // provide helpful details since we cannot identify the transaction exactly
+
+    if (tcpClient)
+        return os << Debug::Extra << "current from-client connection: " << tcpClient;
+    else if (!cache.caddr.isNoAddr())
+        return os << Debug::Extra << "current client: " << cache.caddr;
+
+    const auto optionalMethod = [this,&os]() {
+        if (hasLogMethod())
+            os << getLogMethod() << ' ';
+        return "";
+    };
+    if (const auto uri = effectiveVirginUrl())
+        return os << Debug::Extra << "current client request: " << optionalMethod() << *uri;
+    else if (!url.isEmpty())
+        return os << Debug::Extra << "current request: " << optionalMethod() << url;
+    else if (hasLogMethod())
+        return os << Debug::Extra << "current request method: " << getLogMethod();
+
+    return os;
+}
+
 const SBuf *
 AccessLogEntry::effectiveVirginUrl() const
 {
index 7168562db33583ea111127c74c179063b8b0d5dc..c114757ca15b8cbc728677c3e1e1f8f72cdc0c45 100644 (file)
@@ -10,7 +10,7 @@
 #define SQUID_HTTPACCESSLOGENTRY_H
 
 #include "anyp/PortCfg.h"
-#include "base/RefCount.h"
+#include "base/CodeContext.h"
 #include "comm/Connection.h"
 #include "HierarchyLogEntry.h"
 #include "http/ProtocolVersion.h"
@@ -36,14 +36,18 @@ class HttpReply;
 class HttpRequest;
 class CustomLog;
 
-class AccessLogEntry: public RefCountable
+class AccessLogEntry: public CodeContext
 {
 
 public:
     typedef RefCount<AccessLogEntry> Pointer;
 
     AccessLogEntry();
-    ~AccessLogEntry();
+    virtual ~AccessLogEntry();
+
+    /* CodeContext API */
+    virtual std::ostream &detailCodeContext(std::ostream &os) const override;
+    virtual ScopedId codeContextGist() const override;
 
     /// Fetch the client IP log string into the given buffer.
     /// Knows about several alternate locations of the IP
index 756f498860e537f9ddee030bf40f135b038c574d..4741e6c0aedd5450195a1b3ef73dab9bf019990f 100644 (file)
@@ -99,6 +99,10 @@ public:
 
     /// configures the active debugging context to write syslog ALERT
     static void ForceAlert();
+
+    /// prefixes each grouped debugs() line after the first one in the group
+    static std::ostream& Extra(std::ostream &os) { return os << "\n    "; }
+
 private:
     static Context *Current; ///< deepest active context; nil outside debugs()
 };
index 1d828ad34a24922409f4be868d39f241b5b35b61..ffbd0e0a7a683086db2c9739750dfdf952d5f6f7 100644 (file)
@@ -9,6 +9,7 @@
 /* DEBUG: section 47    Store Directory Routines */
 
 #include "squid.h"
+#include "base/CodeContext.h"
 #include "base/RunnersRegistry.h"
 #include "base/TextException.h"
 #include "DiskIO/IORequestor.h"
@@ -332,7 +333,9 @@ IpcIoFile::push(IpcIoPendingRequest *const pending)
 {
     // prevent queue overflows: check for responses to earlier requests
     // warning: this call may result in indirect push() recursion
-    HandleResponses("before push");
+    CallService(nullptr, [] {
+        HandleResponses("before push");
+    });
 
     debugs(47, 7, HERE);
     Must(diskId >= 0);
@@ -460,16 +463,16 @@ void
 IpcIoFile::handleResponse(IpcIoMsg &ipcIo)
 {
     const int requestId = ipcIo.requestId;
-    debugs(47, 7, HERE << "popped disker response: " <<
-           SipcIo(KidIdentifier, ipcIo, diskId));
 
     Must(requestId);
     if (IpcIoPendingRequest *const pending = dequeueRequest(requestId)) {
-        pending->completeIo(&ipcIo);
-        delete pending; // XXX: leaking if throwing
+        CallBack(pending->codeContext, [&] {
+            debugs(47, 7, "popped disker response to " << SipcIo(KidIdentifier, ipcIo, diskId));
+            pending->completeIo(&ipcIo);
+            delete pending; // XXX: leaking if throwing
+        });
     } else {
-        debugs(47, 4, HERE << "LATE disker response to " << ipcIo.command <<
-               "; ipcIo" << KidIdentifier << '.' << requestId);
+        debugs(47, 4, "LATE disker response to " << SipcIo(KidIdentifier, ipcIo, diskId));
         // nothing we can do about it; completeIo() has been called already
     }
 }
@@ -556,13 +559,12 @@ IpcIoFile::checkTimeouts()
     typedef RequestMap::const_iterator RMCI;
     for (RMCI i = olderRequests->begin(); i != olderRequests->end(); ++i) {
         IpcIoPendingRequest *const pending = i->second;
-
-        const unsigned int requestId = i->first;
-        debugs(47, 7, HERE << "disker timeout; ipcIo" <<
-               KidIdentifier << '.' << requestId);
-
-        pending->completeIo(NULL); // no response
-        delete pending; // XXX: leaking if throwing
+        CallBack(pending->codeContext, [&] {
+            const auto requestId = i->first;
+            debugs(47, 7, "disker timeout; ipcIo" << KidIdentifier << '.' << requestId);
+            pending->completeIo(nullptr); // no response
+            delete pending; // XXX: leaking if throwing
+        });
     }
     olderRequests->clear();
 
@@ -575,10 +577,14 @@ IpcIoFile::checkTimeouts()
 void
 IpcIoFile::scheduleTimeoutCheck()
 {
-    // we check all older requests at once so some may be wait for 2*Timeout
-    eventAdd("IpcIoFile::CheckTimeouts", &IpcIoFile::CheckTimeouts,
-             reinterpret_cast<void *>(diskId), Timeout, 0, false);
-    timeoutCheckScheduled = true;
+    // We may be running in an I/O requestor CodeContext, but are scheduling
+    // one-for-all CheckTimeouts() that is not specific to any request.
+    CallService(nullptr, [&] {
+        // we check all older requests at once so some may be wait for 2*Timeout
+        eventAdd("IpcIoFile::CheckTimeouts", &IpcIoFile::CheckTimeouts,
+        reinterpret_cast<void *>(diskId), Timeout, 0, false);
+        timeoutCheckScheduled = true;
+    });
 }
 
 /// returns and forgets the right IpcIoFile pending request
@@ -629,7 +635,10 @@ IpcIoMsg::IpcIoMsg():
 /* IpcIoPendingRequest */
 
 IpcIoPendingRequest::IpcIoPendingRequest(const IpcIoFile::Pointer &aFile):
-    file(aFile), readRequest(NULL), writeRequest(NULL)
+    file(aFile),
+    readRequest(nullptr),
+    writeRequest(nullptr),
+    codeContext(CodeContext::Current())
 {
 }
 
index e2e0e382cd200fc6f04cfeb91b2a52635b79d5a2..5d323e74c78980de9ed0b3ab04652c5eea3cb220 100644 (file)
@@ -166,6 +166,8 @@ public:
     ReadRequest *readRequest; ///< set if this is a read requests
     WriteRequest *writeRequest; ///< set if this is a write request
 
+    CodeContext::Pointer codeContext; ///< requestor's context
+
 private:
     IpcIoPendingRequest(const IpcIoPendingRequest &d); // not implemented
     IpcIoPendingRequest &operator =(const IpcIoPendingRequest &d); // ditto
index 8700ace13c907360f037a113d904d0e8f04deab8..b0ca10d30a5ed91bad2288f21be099240ae60745 100644 (file)
@@ -79,3 +79,23 @@ AnyP::PortCfg::clone() const
     return b;
 }
 
+ScopedId
+AnyP::PortCfg::codeContextGist() const
+{
+    // Unfortunately, .name lifetime is too short in FTP use cases.
+    // TODO: Consider adding InstanceId<uint32_t> to all RefCountable classes.
+    return ScopedId("port");
+}
+
+std::ostream &
+AnyP::PortCfg::detailCodeContext(std::ostream &os) const
+{
+    // parsePortSpecification() defaults optional port name to the required
+    // listening address so we cannot easily distinguish one from the other.
+    if (name)
+        os << Debug::Extra << "listening port: " << name;
+    else if (s.port())
+        os << Debug::Extra << "listening port address: " << s;
+    return os;
+}
+
index a4f29d719257201ba2ce7c23aec29c131703f646..336885f82d7a71a7d0e57873570dc87575aa6f0e 100644 (file)
@@ -12,6 +12,7 @@
 #include "anyp/forward.h"
 #include "anyp/ProtocolVersion.h"
 #include "anyp/TrafficMode.h"
+#include "base/CodeContext.h"
 #include "comm/Connection.h"
 #include "sbuf/SBuf.h"
 #include "security/ServerOptions.h"
 namespace AnyP
 {
 
-class PortCfg : public RefCountable
+class PortCfg : public CodeContext
 {
 public:
     PortCfg();
     ~PortCfg();
     AnyP::PortCfgPointer clone() const;
 
+    /* CodeContext API */
+    virtual ScopedId codeContextGist() const override;
+    virtual std::ostream &detailCodeContext(std::ostream &os) const override;
+
     PortCfgPointer next;
 
     Ip::Address s;
index e24cb0900c1e96814a752af8cd1fb864fbeaf08e..dc7f86e8b5a6cdd1e9d79d32b165934a02e1549f 100644 (file)
@@ -7,9 +7,9 @@
  */
 
 #include "squid.h"
-#include "AsyncCall.h"
 #include "base/AsyncCall.h"
 #include "base/AsyncCallQueue.h"
+#include "base/CodeContext.h"
 #include "cbdata.h"
 #include "Debug.h"
 #include <ostream>
@@ -18,9 +18,13 @@ InstanceIdDefinitions(AsyncCall, "call");
 
 /* AsyncCall */
 
-AsyncCall::AsyncCall(int aDebugSection, int aDebugLevel,
-                     const char *aName): name(aName), debugSection(aDebugSection),
-    debugLevel(aDebugLevel), theNext(0), isCanceled(NULL)
+AsyncCall::AsyncCall(int aDebugSection, int aDebugLevel, const char *aName):
+    name(aName),
+    codeContext(CodeContext::Current()),
+    debugSection(aDebugSection),
+    debugLevel(aDebugLevel),
+    theNext(nullptr),
+    isCanceled(nullptr)
 {
     debugs(debugSection, debugLevel, "The AsyncCall " << name << " constructed, this=" << this <<
            " [" << id << ']');
@@ -91,6 +95,12 @@ ScheduleCall(const char *fileName, int fileLine, AsyncCall::Pointer &call)
 {
     debugs(call->debugSection, call->debugLevel, fileName << "(" << fileLine <<
            ") will call " << *call << " [" << call->id << ']' );
+
+    // Support callback creators that did not get their context from service A,
+    // but the current caller (service B) got that context from another source.
+    if (!call->codeContext)
+        call->codeContext = CodeContext::Current();
+
     AsyncCallQueue::Instance().schedule(call);
     return true;
 }
index 233a717cce2af5279903747b8cf1cfc19b6f9481..598b59548163c632e493cde2adf586c46a31ce13 100644 (file)
@@ -9,6 +9,7 @@
 #ifndef SQUID_ASYNCCALL_H
 #define SQUID_ASYNCCALL_H
 
+#include "base/CodeContext.h"
 #include "base/InstanceId.h"
 #include "event.h"
 #include "RefCount.h"
@@ -74,6 +75,10 @@ public:
 
 public:
     const char *const name;
+
+    /// what the callee is expected to work on
+    CodeContext::Pointer codeContext;
+
     const int debugSection;
     const int debugLevel;
     const InstanceId<AsyncCall> id;
index ed93ce5bc4d4a1f4685e976782522471845de6b6..fa44d0665332c6d544f70f91fc0b9e144a68e99e 100644 (file)
@@ -38,8 +38,12 @@ bool
 AsyncCallQueue::fire()
 {
     const bool made = theHead != NULL;
-    while (theHead != NULL)
+    while (theHead) {
+        CodeContext::Reset(theHead->codeContext);
         fireNext();
+    }
+    if (made)
+        CodeContext::Reset();
     return made;
 }
 
diff --git a/src/base/CodeContext.cc b/src/base/CodeContext.cc
new file mode 100644 (file)
index 0000000..a4e7b17
--- /dev/null
@@ -0,0 +1,100 @@
+/*
+ * Copyright (C) 1996-2019 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 code_contexts for details.
+ */
+
+#include "squid.h"
+#include "base/CodeContext.h"
+#include "Debug.h"
+
+/// represents a being-forgotten CodeContext (while it may be being destroyed)
+class FadingCodeContext: public CodeContext
+{
+public:
+    /* CodeContext API */
+    virtual ScopedId codeContextGist() const override { return gist; }
+    virtual std::ostream &detailCodeContext(std::ostream &os) const override { return os << gist; }
+
+    ScopedId gist; ///< identifies the being-forgotten CodeContext
+};
+
+/// guarantees the forever existence of the pointer, starting from the first use
+static CodeContext::Pointer &
+Instance()
+{
+    static const auto Instance = new CodeContext::Pointer(nullptr);
+    return *Instance;
+}
+
+const CodeContext::Pointer &
+CodeContext::Current()
+{
+    return Instance();
+}
+
+/// Forgets the current known context, possibly triggering its destruction.
+/// Preserves the gist of the being-forgotten context during its destruction.
+/// Knows nothing about the next context -- the caller must set it.
+void
+CodeContext::ForgetCurrent()
+{
+    static const RefCount<FadingCodeContext> fadingCodeContext = new FadingCodeContext();
+    auto &current = Instance();
+    assert(current);
+    fadingCodeContext->gist = current->codeContextGist();
+    current = fadingCodeContext;
+}
+
+/// Switches the current context to the given known context. Improves debugging
+/// output by replacing omni-directional "Reset" with directional "Entering".
+void
+CodeContext::Entering(const Pointer &codeCtx)
+{
+    auto &current = Instance();
+    if (current)
+        ForgetCurrent(); // ensure orderly closure of the old context
+    current = codeCtx;
+    debugs(1, 5, codeCtx->codeContextGist());
+}
+
+/// Forgets the current known context. Improves debugging output by replacing
+/// omni-directional "Reset" with directional "Leaving".
+void
+CodeContext::Leaving()
+{
+    ForgetCurrent();
+    auto &current = Instance();
+    debugs(1, 7, *current);
+    current = nullptr;
+}
+
+void
+CodeContext::Reset()
+{
+    if (Instance())
+        Leaving();
+}
+
+void
+CodeContext::Reset(const Pointer codeCtx)
+{
+    if (codeCtx == Current())
+        return; // context has not actually changed
+
+    if (!codeCtx)
+        return Leaving();
+
+    Entering(codeCtx);
+}
+
+std::ostream &
+CurrentCodeContextDetail(std::ostream &os)
+{
+    if (const auto ctx = CodeContext::Current())
+        ctx->detailCodeContext(os);
+    return os;
+}
+
diff --git a/src/base/CodeContext.h b/src/base/CodeContext.h
new file mode 100644 (file)
index 0000000..5d1adc4
--- /dev/null
@@ -0,0 +1,121 @@
+/*
+ * Copyright (C) 1996-2019 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 code_contexts for details.
+ */
+
+#ifndef SQUID_BASE_CODE_CONTEXT_H
+#define SQUID_BASE_CODE_CONTEXT_H
+
+#include "base/InstanceId.h"
+#include "base/RefCount.h"
+
+#include <iosfwd>
+
+/// Interface for reporting what Squid code is working on.
+/// Such reports are usually requested outside creator's call stack.
+/// They are especially useful for attributing low-level errors to transactions.
+class CodeContext: public RefCountable
+{
+public:
+    typedef RefCount<CodeContext> Pointer;
+
+    /// \returns the known global context or, to indicate unknown context, nil
+    static const Pointer &Current();
+
+    /// forgets the current context, setting it to nil/unknown
+    static void Reset();
+
+    /// changes the current context; nil argument sets it to nil/unknown
+    static void Reset(const Pointer);
+
+    virtual ~CodeContext() {}
+
+    /// \returns a small, permanent ID of the current context
+    /// gists persist forever and are suitable for passing to other SMP workers
+    virtual ScopedId codeContextGist() const = 0;
+
+    /// appends human-friendly context description line(s) to a cache.log record
+    virtual std::ostream &detailCodeContext(std::ostream &os) const = 0;
+
+private:
+    static void ForgetCurrent();
+    static void Entering(const Pointer &codeCtx);
+    static void Leaving();
+};
+
+/// by default, only small context gist is printed
+inline
+std::ostream &operator <<(std::ostream &os, const CodeContext &ctx)
+{
+    return os << ctx.codeContextGist();
+}
+
+/* convenience context-reporting wrappers that also reduce linking problems */
+std::ostream &CurrentCodeContextBrief(std::ostream &os);
+std::ostream &CurrentCodeContextDetail(std::ostream &os);
+
+/// Convenience class that automatically restores the current/outer CodeContext
+/// when leaving the scope of the new-context following/inner code. \see Run().
+class CodeContextGuard
+{
+public:
+    CodeContextGuard(const CodeContext::Pointer &newContext): savedCodeContext(CodeContext::Current()) { CodeContext::Reset(newContext); }
+    ~CodeContextGuard() { CodeContext::Reset(savedCodeContext); }
+
+    // no copying of any kind (for simplicity and to prevent accidental copies)
+    CodeContextGuard(CodeContextGuard &&) = delete;
+
+    CodeContext::Pointer savedCodeContext;
+};
+
+/// Executes service `callback` in `callbackContext`. If an exception occurs,
+/// the callback context is preserved, so that the exception is associated with
+/// the callback that triggered them (rather than with the service).
+///
+/// Service code running in its own service context should use this function.
+template <typename Fun>
+inline void
+CallBack(const CodeContext::Pointer &callbackContext, Fun &&callback)
+{
+    // TODO: Consider catching exceptions and letting CodeContext handle them.
+    const auto savedCodeContext(CodeContext::Current());
+    CodeContext::Reset(callbackContext);
+    callback();
+    CodeContext::Reset(savedCodeContext);
+}
+
+/// Executes `service` in `serviceContext` but due to automatic caller context
+/// restoration, service exceptions are associated with the caller that suffered
+/// from (and/or caused) them (rather than with the service itself).
+///
+/// Service code running in caller's context should use this function to escape
+/// into service context (e.g., for submitting caller-agnostic requests).
+template <typename Fun>
+inline void
+CallService(const CodeContext::Pointer &serviceContext, Fun &&service)
+{
+    // TODO: Consider catching exceptions and letting CodeContext handle them.
+    CodeContextGuard guard(serviceContext);
+    service();
+}
+
+/// Executes context `creator` in the service context. If an exception occurs,
+/// the creator context is preserved, so that the exception is associated with
+/// the creator that triggered them (rather than with the service).
+///
+/// Service code running in its own context should use this function to create
+/// new code contexts. TODO: Use or, if this pattern is not repeated, remove.
+template <typename Fun>
+inline void
+CallContextCreator(Fun &&creator)
+{
+    const auto savedCodeContext(CodeContext::Current());
+    creator();
+    CodeContext::Reset(savedCodeContext);
+}
+
+#endif
+
index 3dae7f280ddbe7babdae0c484debadaef3a46292..f5fcfbca96ee29f5a732f6623f8d2256a1ff36f4 100644 (file)
 
 #include <iosfwd>
 
+/// Represents an InstanceId<C> value independent from its owner class C. These
+/// "detached" IDs can be stored by and exchanged among C-unaware users at the
+/// price of storing a short scope c-string (that InstanceIds hard-code instead)
+/// and, in some cases, using more bits/space than InstanceId<C>::value uses.
+class ScopedId
+{
+public:
+    ScopedId(): scope(nullptr), value(0) {}
+    explicit ScopedId(const char *s): scope(s), value(0) {}
+    // when the values is zero/unknown, use other constructors
+    ScopedId(const char *s, uint64_t v): scope(s), value(v) { /* assert(value) */ }
+
+    /// either the prefix() of the InstanceId object that we were detached from
+    /// or, for 0 values, some other description (with endless lifetime) or nil
+    const char *scope;
+
+    /// either the value of the InstanceId object that we were detached from
+    /// or, if our creator did not know the exact value, zero
+    uint64_t value;
+};
+
+inline std::ostream&
+operator <<(std::ostream &os, const ScopedId &id)
+{
+    if (id.value)
+        os << id.scope << id.value;
+    else if (id.scope)
+        os << id.scope;
+    else
+        os << "[unknown]";
+    return os;
+}
+
 typedef unsigned int InstanceIdDefaultValueType;
 /** Identifier for class instances
  *   - unique IDs for a large number of concurrent instances, but may wrap;
@@ -32,12 +65,16 @@ public:
     bool operator !=(const InstanceId &o) const { return !(*this == o); }
     void change();
 
-    /// prints class-pecific prefix followed by ID value; \todo: use HEX for value printing?
+    /// writes a compact text representation of the ID
     std::ostream &print(std::ostream &) const;
 
-    /// returns the class-pecific prefix
+    // TODO: Refactor into static Scope().
+    /// \returns Class-specific nickname (with endless lifetime)
     const char * prefix() const;
 
+    /// \returns a copy of the ID usable outside our Class context
+    ScopedId detach() const { return ScopedId(prefix(), value); }
+
 public:
     Value value = Value(); ///< instance identifier
 
index 5ebcc0ef7726cadeaa2c116ac21f12963fac94e2..c891b4f819ea64ef25afcd33104ae3bf94bb105d 100644 (file)
@@ -24,6 +24,8 @@ libbase_la_SOURCES = \
        CbDataList.h \
        CharacterSet.cc \
        CharacterSet.h \
+       CodeContext.cc \
+       CodeContext.h \
        EnumIterator.h \
        File.cc \
        File.h \
index 7ba8580e913443f2d95d5d1d10b20b4f0f3cd280..02d8a7b18cb9832a87cc737385a4449af2b8d785 100644 (file)
@@ -43,6 +43,12 @@ public:
         p.p_=NULL;
     }
 
+    /// Base::Pointer = Derived::Pointer
+    template <class Other>
+    RefCount(const RefCount<Other> &p): p_(p.getRaw()) {
+        reference(*this);
+    }
+
     RefCount& operator = (const RefCount& p) {
         // DO NOT CHANGE THE ORDER HERE!!!
         // This preserves semantics on self assignment
index dfe4f5cbf11415d23f503378d1ee1434cad0d137..cba3dc11f0fd0e4ac5de5136207644a1b410a80a 100644 (file)
@@ -50,7 +50,13 @@ class CallSubscription: public Subscription
 public:
     /// Must be passed an object. nil pointers are not permitted.
     explicit CallSubscription(const RefCount<Call_> &aCall) : call(aCall) { assert(aCall != NULL); }
-    virtual AsyncCall::Pointer callback() const { return new Call_(*call); }
+    virtual AsyncCall::Pointer callback() const
+    {
+        const AsyncCall::Pointer cb = new Call_(*call);
+        if (!cb->codeContext || CodeContext::Current())
+            cb->codeContext = CodeContext::Current();
+        return cb;
+    }
 
 private:
     const RefCount<Call_> call; ///< gets copied to create callback calls
index 1535267ef209625763cfefc50926d6db9321124a..4ea9db50aaa609972f7850cfb38af2e57642592c 100644 (file)
@@ -36,9 +36,9 @@ TextException::~TextException() throw()
 std::ostream &
 TextException::print(std::ostream &os) const
 {
-    os << std::runtime_error::what() << "\n" <<
-       "    exception location: " << where << "\n";
-    // TODO: error_detail: " << (ERR_DETAIL_EXCEPTION_START+id()) << "\n";
+    os << std::runtime_error::what() <<
+        Debug::Extra << "exception location: " << where;
+    // TODO: ...error_detail: " << (ERR_DETAIL_EXCEPTION_START+id());
     return os;
 }
 
index f704a8a8eb0c57a5b15f4a6075ed9bd61de4e4ae..733ed1e787ccb26de6c2ddd8e9ec3ae7900301a6 100644 (file)
@@ -74,9 +74,9 @@ std::ostream &CurrentException(std::ostream &);
     try { \
         code \
     } catch (...) { \
-        debugs(0, DBG_IMPORTANT, "BUG: ignoring exception;\n" << \
-               "    bug location: " << Here() << "\n" << \
-               "    ignored exception: " << CurrentException); \
+        debugs(0, DBG_IMPORTANT, "BUG: ignoring exception;" << \
+               Debug::Extra << "bug location: " << Here() << \
+               Debug::Extra << "ignored exception: " << CurrentException); \
     }
 
 #endif /* SQUID__TEXTEXCEPTION_H */
index 08397c44afb22dac3c1db2515c3e8ba6bb36f331..bb49b34e720792ca53b2073625b9fb3f92182cc5 100644 (file)
@@ -9,10 +9,17 @@
 #ifndef SQUID_SRC_BASE_FORWARD_H
 #define SQUID_SRC_BASE_FORWARD_H
 
+class AsyncCallQueue;
+class AsyncJob;
+class CallDialer;
+class CodeContext;
+class ScopedId;
+
 template<class Cbc> class CbcPointer;
+template<class RefCountableKid> class RefCount;
 
-class AsyncJob;
 typedef CbcPointer<AsyncJob> AsyncJobPointer;
+typedef RefCount<CodeContext> CodeContextPointer;
 
 #endif /* SQUID_SRC_BASE_FORWARD_H */
 
index 15b25bc365b1ba7c536290f9dad1a8c74ea2680b..61f1c2f322b1153affe56a91376e76aa47ccd3f7 100644 (file)
@@ -2623,20 +2623,25 @@ ConnStateData::postHttpsAccept()
 
         MasterXaction::Pointer mx = new MasterXaction(XactionInitiator::initClient);
         mx->tcpClient = clientConnection;
-        // Create a fake HTTP request for ssl_bump ACL check,
+        // Create a fake HTTP request and ALE for the ssl_bump ACL check,
         // using tproxy/intercept provided destination IP and port.
+        // XXX: Merge with subsequent fakeAConnectRequest(), buildFakeRequest().
+        // XXX: Do this earlier (e.g., in Http[s]::One::Server constructor).
         HttpRequest *request = new HttpRequest(mx);
         static char ip[MAX_IPSTRLEN];
         assert(clientConnection->flags & (COMM_TRANSPARENT | COMM_INTERCEPTION));
         request->url.host(clientConnection->local.toStr(ip, sizeof(ip)));
         request->url.port(clientConnection->local.port());
         request->myportname = port->name;
+        const AccessLogEntry::Pointer connectAle = new AccessLogEntry;
+        CodeContext::Reset(connectAle);
+        // TODO: Use these request/ALE when waiting for new bumped transactions.
 
         ACLFilledChecklist *acl_checklist = new ACLFilledChecklist(Config.accessList.ssl_bump, request, NULL);
         acl_checklist->src_addr = clientConnection->remote;
         acl_checklist->my_addr = port->s;
         // Build a local AccessLogEntry to allow requiresAle() acls work
-        acl_checklist->al = new AccessLogEntry;
+        acl_checklist->al = connectAle;
         acl_checklist->al->cache.start_time = current_time;
         acl_checklist->al->tcpClient = clientConnection;
         acl_checklist->al->cache.port = port;
@@ -3362,8 +3367,8 @@ clientHttpConnectionsOpen(void)
         const SBuf &scheme = AnyP::UriScheme(s->transport.protocol).image();
 
         if (MAXTCPLISTENPORTS == NHttpSockets) {
-            debugs(1, DBG_IMPORTANT, "WARNING: You have too many '" << scheme << "_port' lines.");
-            debugs(1, DBG_IMPORTANT, "         The limit is " << MAXTCPLISTENPORTS << " HTTP ports.");
+            debugs(1, DBG_IMPORTANT, "WARNING: You have too many '" << scheme << "_port' lines." <<
+                   Debug::Extra << "The limit is " << MAXTCPLISTENPORTS << " HTTP ports.");
             continue;
         }
 
index 7760d1db96ec387b3837db58463970879b807cdc..21772b8c57ad820b377c12af04d2f507525c77a9 100644 (file)
@@ -168,6 +168,7 @@ ClientHttpRequest::ClientHttpRequest(ConnStateData * aConn) :
 {
     setConn(aConn);
     al = new AccessLogEntry;
+    CodeContext::Reset(al);
     al->cache.start_time = current_time;
     if (aConn) {
         al->tcpClient = clientConnection = aConn->clientConnection;
index 4e27ce3c8620bb1e948ba0f7d389a4387e235f6d..8e38c01981ac45977cd6183a48ffabbcbecbaabe 100644 (file)
@@ -733,6 +733,7 @@ commCallCloseHandlers(int fd)
     }
 }
 
+// XXX: This code has been broken, unused, and untested since 933dd09. Remove.
 #if LINGERING_CLOSE
 static void
 commLingerClose(int fd, void *unused)
@@ -835,6 +836,7 @@ comm_close_complete(const FdeCbParams &params)
     ++ statCounter.syscalls.sock.closes;
 
     /* When one connection closes, give accept() a chance, if need be */
+    CodeContext::Reset(); // exit FD-specific context
     Comm::AcceptLimiter::Instance().kick();
 }
 
@@ -877,6 +879,11 @@ _comm_close(int fd, char const *file, int line)
 
     F->flags.close_request = true;
 
+    // We have caller's context and fde::codeContext. In the unlikely event they
+    // differ, it is not clear which context is more applicable to this closure.
+    // For simplicity sake, we remain in the caller's context while still
+    // allowing individual advanced callbacks to overwrite it.
+
     if (F->ssl) {
         AsyncCall::Pointer startCall=commCbCall(5,4, "commStartTlsClose",
                                                 FdeCbPtrFun(commStartTlsClose, nullptr));
@@ -1572,14 +1579,19 @@ checkTimeouts(void)
 
         if (writeTimedOut(fd)) {
             // We have an active write callback and we are timed out
+            CodeContext::Reset(F->codeContext);
             debugs(5, 5, "checkTimeouts: FD " << fd << " auto write timeout");
             Comm::SetSelect(fd, COMM_SELECT_WRITE, NULL, NULL, 0);
             COMMIO_FD_WRITECB(fd)->finish(Comm::COMM_ERROR, ETIMEDOUT);
+            CodeContext::Reset();
 #if USE_DELAY_POOLS
         } else if (F->writeQuotaHandler != nullptr && COMMIO_FD_WRITECB(fd)->conn != nullptr) {
+            // TODO: Move and extract quota() call to place it inside F->codeContext.
             if (!F->writeQuotaHandler->selectWaiting && F->writeQuotaHandler->quota() && !F->closing()) {
+                CodeContext::Reset(F->codeContext);
                 F->writeQuotaHandler->selectWaiting = true;
                 Comm::SetSelect(fd, COMM_SELECT_WRITE, Comm::HandleWrite, COMMIO_FD_WRITECB(fd), 0);
+                CodeContext::Reset();
             }
             continue;
 #endif
@@ -1587,6 +1599,7 @@ checkTimeouts(void)
         else if (AlreadyTimedOut(F))
             continue;
 
+        CodeContext::Reset(F->codeContext);
         debugs(5, 5, "checkTimeouts: FD " << fd << " Expired");
 
         if (F->timeoutHandler != NULL) {
@@ -1598,6 +1611,8 @@ checkTimeouts(void)
             debugs(5, 5, "checkTimeouts: FD " << fd << ": Forcing comm_close()");
             comm_close(fd);
         }
+
+        CodeContext::Reset();
     }
 }
 
index 03c8520c1dbfe15f1b77718996b3a72acaf7114c..4f071a30a5817037da62b761b27ddf47abba3618 100644 (file)
@@ -19,6 +19,8 @@
 #include "SquidTime.h"
 #include <ostream>
 
+InstanceIdDefinitions(Comm::Connection, "conn");
+
 class CachePeer;
 bool
 Comm::IsConnOpen(const Comm::ConnectionPointer &conn)
@@ -154,10 +156,25 @@ Comm::Connection::connectTimeout(const time_t fwdStart) const
     return min(ctimeout, ftimeout);
 }
 
+ScopedId
+Comm::Connection::codeContextGist() const {
+    return id.detach();
+}
+
+std::ostream &
+Comm::Connection::detailCodeContext(std::ostream &os) const
+{
+    return os << Debug::Extra << "connection: " << *this;
+}
+
 std::ostream &
 operator << (std::ostream &os, const Comm::Connection &conn)
 {
-    os << "local=" << conn.local << " remote=" << conn.remote;
+    os << conn.id;
+    if (!conn.local.isNoAddr() || conn.local.port())
+        os << " local=" << conn.local;
+    if (!conn.remote.isNoAddr() || conn.remote.port())
+        os << " remote=" << conn.remote;
     if (conn.peerType)
         os << ' ' << hier_code_str[conn.peerType];
     if (conn.fd >= 0)
index 910820f4e713610ce4f5c4f259570d4a9bd4e8b1..95488f2a4ce14b04ee9564d836aa8caaa59ef782 100644 (file)
@@ -11,6 +11,8 @@
 #ifndef _SQUIDCONNECTIONDETAIL_H_
 #define _SQUIDCONNECTIONDETAIL_H_
 
+#include "base/CodeContext.h"
+#include "base/InstanceId.h"
 #include "comm/forward.h"
 #include "defines.h"
 #if USE_SQUID_EUI
@@ -62,7 +64,7 @@ namespace Comm
  * These objects should not be passed around directly,
  * but a Comm::ConnectionPointer should be passed instead.
  */
-class Connection : public RefCountable
+class Connection: public CodeContext
 {
     MEMPROXY_CLASS(Comm::Connection);
 
@@ -70,7 +72,7 @@ public:
     Connection();
 
     /** Clear the connection properties and close any open socket. */
-    ~Connection();
+    virtual ~Connection();
 
     /** Copy an existing connections IP and properties.
      * This excludes the FD. The new copy will be a closed connection.
@@ -123,6 +125,10 @@ public:
     Security::NegotiationHistory *tlsNegotiations();
     const Security::NegotiationHistory *hasTlsNegotiations() const {return tlsHistory;}
 
+    /* CodeContext API */
+    virtual ScopedId codeContextGist() const override;
+    virtual std::ostream &detailCodeContext(std::ostream &os) const override;
+
 private:
     /** These objects may not be exactly duplicated. Use copyDetails() instead. */
     Connection(const Connection &c);
@@ -169,6 +175,8 @@ public:
     Eui::Eui64 remoteEui64;
 #endif
 
+    InstanceId<Connection> id;
+
 private:
     /** cache_peer data object (if any) */
     CachePeer *peer_;
index b456fdfaa3becde74b19982b0722a8df892ed84e..a7558c141bf9f2932c9fbdb5c445dc0d7a61064e 100644 (file)
@@ -32,6 +32,7 @@
 
 #if USE_EPOLL
 
+#include "base/CodeContext.h"
 #include "comm/Loops.h"
 #include "fde.h"
 #include "globals.h"
@@ -178,6 +179,12 @@ Comm::SetSelect(int fd, unsigned int type, PF * handler, void *client_data, time
 
     if (timeout)
         F->timeout = squid_curtime + timeout;
+
+    if (timeout || handler) // all non-cleanup requests
+        F->codeContext = CodeContext::Current(); // TODO: Avoid clearing if set?
+    else if (!ev.events) // full cleanup: no more FD-associated work expected
+        F->codeContext = nullptr;
+    // else: direction-specific/timeout cleanup requests preserve F->codeContext
 }
 
 static void commIncomingStats(StoreEntry * sentry);
@@ -253,6 +260,7 @@ Comm::DoSelect(int msec)
     for (i = 0, cevents = pevents; i < num; ++i, ++cevents) {
         fd = cevents->data.fd;
         F = &fd_table[fd];
+        CodeContext::Reset(F->codeContext);
         debugs(5, DEBUG_EPOLL ? 0 : 8, HERE << "got FD " << fd << " events=" <<
                std::hex << cevents->events << " monitoring=" << F->epoll_state <<
                " F->read_handler=" << F->read_handler << " F->write_handler=" << F->write_handler);
@@ -290,6 +298,8 @@ Comm::DoSelect(int msec)
         }
     }
 
+    CodeContext::Reset();
+
     PROF_stop(comm_handle_ready_fd);
 
     return Comm::OK;
index 3988eae110d41678f421bacb0d8d3b8b8ad7086b..0c1f405b3b4bceefdc98185330c083725128cfbe 100644 (file)
@@ -74,6 +74,8 @@ Comm::TcpAcceptor::unsubscribe(const char *reason)
 void
 Comm::TcpAcceptor::start()
 {
+    if (listenPort_)
+        CodeContext::Reset(listenPort_);
     debugs(5, 5, HERE << status() << " AsyncCall Subscription: " << theCallSub);
 
     Must(IsConnOpen(conn));
@@ -153,7 +155,7 @@ Comm::TcpAcceptor::setListen()
     errcode = errno = 0;
     if (listen(conn->fd, Squid_MaxFD >> 2) < 0) {
         errcode = errno;
-        debugs(50, DBG_CRITICAL, "ERROR: listen(" << status() << ", " << (Squid_MaxFD >> 2) << "): " << xstrerr(errcode));
+        debugs(50, DBG_CRITICAL, "ERROR: listen(..., " << (Squid_MaxFD >> 2) << ") system call failed: " << xstrerr(errcode));
         return;
     }
 
@@ -255,18 +257,21 @@ Comm::TcpAcceptor::okToAccept()
     return false;
 }
 
-static void
-logAcceptError(const Comm::ConnectionPointer &conn)
+void
+Comm::TcpAcceptor::logAcceptError(const ConnectionPointer &tcpClient) const
 {
     AccessLogEntry::Pointer al = new AccessLogEntry;
-    al->tcpClient = conn;
+    CodeContext::Reset(al);
+    al->tcpClient = tcpClient;
     al->url = "error:accept-client-connection";
     al->setVirginUrlForMissingRequest(al->url);
     ACLFilledChecklist ch(nullptr, nullptr, nullptr);
-    ch.src_addr = conn->remote;
-    ch.my_addr = conn->local;
+    ch.src_addr = tcpClient->remote;
+    ch.my_addr = tcpClient->local;
     ch.al = al;
     accessLogLog(al, &ch);
+
+    CodeContext::Reset(listenPort_);
 }
 
 void
@@ -296,10 +301,13 @@ Comm::TcpAcceptor::acceptOne()
         /* register interest again */
         debugs(5, 5, "try later: " << conn << " handler Subscription: " << theCallSub);
     } else {
+        // TODO: When ALE, MasterXaction merge, use them or ClientConn instead.
+        CodeContext::Reset(newConnDetails);
         debugs(5, 5, "Listener: " << conn <<
                " accepted new connection " << newConnDetails <<
                " handler Subscription: " << theCallSub);
         notify(flag, newConnDetails);
+        CodeContext::Reset(listenPort_);
     }
 
     SetSelect(conn->fd, COMM_SELECT_READ, doAccept, this, 0);
@@ -368,7 +376,7 @@ Comm::TcpAcceptor::oldAccept(Comm::ConnectionPointer &details)
             debugs(50, 3, status() << ": " << xstrerr(errcode));
             return Comm::COMM_ERROR;
         } else {
-            debugs(50, DBG_IMPORTANT, MYNAME << status() << ": " << xstrerr(errcode));
+            debugs(50, DBG_IMPORTANT, "ERROR: failed to accept an incoming connection: " << xstrerr(errcode));
             return Comm::COMM_ERROR;
         }
     }
index 998eb515590181aac164f8e13b682b4909dd69c1..a19a8be78a64af5c98a87852b6990147965882ba 100644 (file)
@@ -105,6 +105,7 @@ private:
     void handleClosure(const CommCloseCbParams &io);
     /// whether we are listening on one of the squid.conf *ports
     bool intendedForUserConnections() const { return bool(listenPort_); }
+    void logAcceptError(const ConnectionPointer &tcpClient) const;
 };
 
 } // namespace Comm
index a93cfd498995124728c91cc4db228ea22a5795da..4de7a3b78d41425b69ee9b3b4cf82d8fa30d771b 100644 (file)
@@ -843,6 +843,11 @@ Debug::Start(const int section, const int level)
 void
 Debug::Finish()
 {
+    // TODO: #include "base/CodeContext.h" instead if doing so works well.
+    extern std::ostream &CurrentCodeContextDetail(std::ostream &os);
+    if (Current->level <= DBG_IMPORTANT)
+        Current->buf << CurrentCodeContextDetail;
+
     // TODO: Optimize to remove at least one extra copy.
     _db_print(Current->forceAlert, "%s\n", Current->buf.str().c_str());
     Current->forceAlert = false;
index 0b57293acf9fa1c448af102244a43a134e1e4eff..835b8d84d4a41ad4fa908d179c5f8837d151b647 100644 (file)
--- a/src/fde.h
+++ b/src/fde.h
@@ -9,6 +9,8 @@
 #ifndef SQUID_FDE_H
 #define SQUID_FDE_H
 
+#include "base/CodeContext.h" /* XXX: Remove by de-inlining ctor and clear() */
+#include "base/forward.h"
 #include "comm.h"
 #include "defines.h"
 #include "ip/Address.h"
@@ -165,6 +167,12 @@ public:
                                                 connection, whereas nfmarkToServer is the value to set on packets
                                                 *leaving* Squid.   */
 
+    // TODO: Remove: Auto-convert legacy SetSelect() callers to AsyncCalls like
+    // comm_add_close_handler(CLCB) does, making readMethod_/writeMethod_
+    // AsyncCalls and giving each read/write a dedicated context instead.
+    /// What the I/O handlers are supposed to work on.
+    CodeContextPointer codeContext;
+
 private:
     // I/O methods connect Squid to the device/stack/library fde represents
     READ_HANDLER *readMethod_ = nullptr; ///< imports bytes into Squid
index 5ca6d512060aa87331c81e93ebee1d2c6b970198..3f564758d473915013c26a37bc9735356dd4bc08 100644 (file)
@@ -119,7 +119,7 @@ struct _htcpAuthHeader {
     Countstr signature;
 };
 
-class htcpSpecifier : public RefCountable, public StoreClient
+class htcpSpecifier: public CodeContext, public StoreClient
 {
     MEMPROXY_CLASS(htcpSpecifier);
 
@@ -134,6 +134,10 @@ public:
         dhdr = aDataHeader;
     }
 
+    /* CodeContext API */
+    virtual ScopedId codeContextGist() const; // override
+    virtual std::ostream &detailCodeContext(std::ostream &os) const; // override
+
     /* StoreClient API */
     void created(StoreEntry *);
     virtual LogTags *loggingTags();
@@ -914,6 +918,38 @@ htcpClrReply(htcpDataHeader * dhdr, int purgeSucceeded, Ip::Address &from)
     htcpSend(pkt, (int) pktlen, from);
 }
 
+ScopedId
+htcpSpecifier::codeContextGist() const
+{
+    if (al) {
+        const auto gist = al->codeContextGist();
+        if (gist.value)
+            return gist;
+    }
+
+    if (request) {
+        if (const auto &mx = request->masterXaction)
+            return mx->id.detach();
+    }
+
+    return ScopedId("HTCP w/o master");
+}
+
+std::ostream &
+htcpSpecifier::detailCodeContext(std::ostream &os) const
+{
+    if (al)
+        return al->detailCodeContext(os);
+
+    if (request) {
+        if (const auto &mx = request->masterXaction)
+            return os << Debug::Extra << "current master transaction: " << mx->id;
+    }
+
+    // TODO: Report method, uri, and version if they have been set
+    return os;
+}
+
 void
 htcpSpecifier::checkHit()
 {
@@ -1261,6 +1297,8 @@ htcpForwardClr(char *buf, int sz)
 static void
 htcpHandleMsg(char *buf, int sz, Ip::Address &from)
 {
+    // TODO: function-scoped CodeContext::Reset(...("HTCP message from", from))
+
     htcpHeader htcpHdr;
     htcpDataHeader hdr;
     char *hbuf;
index 1cd7c68deb892d72198405c7f5a57279014000a6..98c96a8aa47d1be6bf832e58f80e5884b5969a5d 100644 (file)
@@ -88,6 +88,8 @@ Http::Stream::writeComplete(size_t size)
     case STREAM_COMPLETE: {
         debugs(33, 5, clientConnection << " Stream complete, keepalive is " <<
                http->request->flags.proxyKeepalive);
+        // XXX: This code assumes we are done with the transaction, but we may
+        // still be receiving request body. TODO: Extend stopSending() instead.
         ConnStateData *c = getConn();
         if (!http->request->flags.proxyKeepalive)
             clientConnection->close();
@@ -570,6 +572,7 @@ Http::Stream::noteIoError(const int xerrno)
 void
 Http::Stream::finished()
 {
+    CodeContext::Reset(clientConnection);
     ConnStateData *conn = getConn();
 
     /* we can't handle any more stream data - detach */
index 9259b082e6c55eca4056ed7fdbdbbdac626af322..5ec5da1c66aa743a60940bf4b1615f15c5bf7ca9 100644 (file)
@@ -569,9 +569,8 @@ neighbors_init(void)
                 if (thisPeer->http_port != s->s.port())
                     continue;
 
-                debugs(15, DBG_IMPORTANT, "WARNING: Peer looks like this host");
-
-                debugs(15, DBG_IMPORTANT, "         Ignoring " <<
+                debugs(15, DBG_IMPORTANT, "WARNING: Peer looks like this host." <<
+                       Debug::Extra << "Ignoring " <<
                        neighborTypeStr(thisPeer) << " " << thisPeer->host <<
                        "/" << thisPeer->http_port << "/" <<
                        thisPeer->icp.port);
@@ -1779,6 +1778,7 @@ neighborsHtcpReply(const cache_key * key, HtcpReplyData * htcp, const Ip::Addres
     }
 
     debugs(15, 3, "neighborsHtcpReply: e = " << e);
+    // TODO: Refactor (ping_reply_callback,ircb_data) to add CodeContext.
     mem->ping_reply_callback(p, ntype, AnyP::PROTO_HTCP, htcp, mem->ircb_data);
 }
 
index e0813e4ca8af906b76b04c60fb6d36ca7bcf5b5b..65ef77d3d8fe517655bd97c8034415fb699f29bf 100644 (file)
@@ -26,6 +26,9 @@ Comm::ConnectionPointer Comm::Connection::copyDetails() const STUB_RETVAL(NULL)
 void Comm::Connection::close() STUB
 CachePeer * Comm::Connection::getPeer() const STUB_RETVAL(NULL)
 void Comm::Connection::setPeer(CachePeer * p) STUB
+ScopedId Comm::Connection::codeContextGist() const STUB_RETVAL(id.detach())
+std::ostream &Comm::Connection::detailCodeContext(std::ostream &os) const STUB_RETVAL(os)
+InstanceIdDefinitions(Comm::Connection, "conn");
 
 #include "comm/ConnOpener.h"
 CBDATA_NAMESPACED_CLASS_INIT(Comm, ConnOpener);