Bug 5090: Must(!request->pinnedConnection()) violation (#930)

The bug may be asymptomatic. Visible bug symptoms, if any, may include:

    FATAL: check failed: !request->pinnedConnection()
    exception location: FwdState.cc(1124) connectStart

    FATAL: check failed: transportWait
    exception location: FwdState.cc(675) noteDestinationsEnd

FwdState::usingDestination() should cover 3 post-transportWait periods:

1. peerWait: opening a CONNECT tunnel through the cache_peer
2. encryptionWait: TLS negotiations to secure the connection
3. Comm::IsConnOpen(serverConn): a Squid-peer transaction

The condition for the last period did not account for the time between
FwdState::unregister() and FwdState::complete() (or their equivalents),
when the transport connection is either closed or moved to the pconn
pool, but FwdState is still waiting for complete() and must not attempt
to connect to another destination. The bug is usually hidden because
complete() is usually called immediately after unregister(). However,
RESPMOD adaptation (at least) may delay complete(). If peer selection
news comes during that delay, usingDestination() lies, and various
Must()s may fail, depending on Squid version and HTTP request details.

Now, FwdState does not rely on the to-peer connection state for the
third period condition. Instead, we explicitly track whether the last
dispatch()ed activity has ended. This tracking is tricky because
complete() may be called without dispatching an asynchronous activity,
and because there are at least three ways for an activity to end:
explicit complete(), explicit handleUnregisteredServerEnd(), and
implicit serverClosed() connection closure callback. This tracking will
become easier and more reliable when FwdState no longer co-owns/stores
the to-peer connection. This change simplifies the future removal of
that connection ownership.

Also reordered usingDestination() conditions to match the chronological
order of the corresponding three periods.

Also reordered transportWait-vs-usingDestination() checks to match the
chronological order of those two forwarding stages.

diff --git a/src/FwdState.cc b/src/FwdState.cc
index a9b3200a1084274dcc1ce26cf869ea4ae4d046c2..cc94b1e8f791abc02c3d1c632640079d1b0b56c3 100644 (file)
--- a/src/FwdState.cc
+++ b/src/FwdState.cc
@@ -149,6 +149,7 @@ FwdState::FwdState(const Comm::ConnectionPointer &client, StoreEntry * e, HttpRe
     clientConn(client),
     start_t(squid_curtime),
     n_tries(0),
+    waitingForDispatched(false),
     destinations(new ResolvedPeers()),
     pconnRace(raceImpossible),
     storedWholeReply_(nullptr)
@@ -565,6 +566,9 @@ FwdState::complete()
 
     logReplyStatus(n_tries, replyStatus);
 
+    // will already be false if complete() was called before/without dispatch()
+    waitingForDispatched = false;
+
     if (reforward()) {
         debugs(17, 3, "re-forwarding " << replyStatus << " " << entry->url());
 
@@ -590,10 +594,13 @@ FwdState::complete()
     }
 }
 
+/// Whether a forwarding attempt to some selected destination X is in progress
+/// (after successfully opening/reusing a transport connection to X).
+/// See also: transportWait
 bool
-FwdState::usingDestination() const
+FwdState::transporting() const
 {
-    return encryptionWait || peerWait || Comm::IsConnOpen(serverConn);
+    return peerWait || encryptionWait || waitingForDispatched;
 }
 
 void
@@ -625,18 +632,15 @@ FwdState::noteDestination(Comm::ConnectionPointer path)
 
     destinations->addPath(path);
 
-    if (usingDestination()) {
-        // We are already using a previously opened connection, so we cannot be
-        // waiting for it. We still receive destinations for backup.
-        Must(!transportWait);
-        return;
-    }
-
     if (transportWait) {
+        assert(!transporting());
         notifyConnOpener();
         return; // and continue to wait for FwdState::noteConnection() callback
     }
 
+    if (transporting())
+        return; // and continue to receive destinations for backup
+
     // This is the first path candidate we have seen. Use it.
     useDestinations();
 }
@@ -665,16 +669,13 @@ FwdState::noteDestinationsEnd(ErrorState *selectionError)
     // if all of them fail, forwarding as whole will fail
     Must(!selectionError); // finding at least one path means selection succeeded
 
-    if (usingDestination()) {
-        // We are already using a previously opened connection, so we cannot be
-        // waiting for it. We were receiving destinations for backup.
-        Must(!transportWait);
-        return;
+    if (transportWait) {
+        assert(!transporting());
+        notifyConnOpener();
+        return; // and continue to wait for FwdState::noteConnection() callback
     }
 
-    Must(transportWait); // or we would be stuck with nothing to do or wait for
-    notifyConnOpener();
-    // and continue to wait for FwdState::noteConnection() callback
+    Must(transporting()); // or we would be stuck with nothing to do or wait for
 }
 
 /// makes sure connection opener knows that the destinations have changed
@@ -783,6 +784,10 @@ FwdState::serverClosed()
     serverConn = nullptr;
     closeHandler = nullptr;
     destinationReceipt = nullptr;
+
+    // will already be false if this closure happened before/without dispatch()
+    waitingForDispatched = false;
+
     retryOrBail();
 }
 
@@ -826,6 +831,10 @@ FwdState::handleUnregisteredServerEnd()
     assert(!Comm::IsConnOpen(serverConn));
     serverConn = nullptr;
     destinationReceipt = nullptr;
+
+    // might already be false due to uncertainties documented in serverClosed()
+    waitingForDispatched = false;
+
     retryOrBail();
 }
 
@@ -1124,7 +1133,7 @@ FwdState::connectStart()
     Must(!request->pinnedConnection());
 
     assert(!destinations->empty());
-    assert(!usingDestination());
+    assert(!transporting());
 
     // Ditch error page if it was created before.
     // A new one will be created if there's another problem
@@ -1200,6 +1209,9 @@ FwdState::dispatch()
      */
     assert(Comm::IsConnOpen(serverConn));
 
+    assert(!waitingForDispatched);
+    waitingForDispatched = true;
+
     fd_note(serverConnection()->fd, entry->url());
 
     fd_table[serverConnection()->fd].noteUse();

diff --git a/src/FwdState.h b/src/FwdState.h
index 20d8cfe017025cb52f385e0d7ab2906301fcb718..80294ffc1117105429bb9f31da7b10063cfb34a3 100644 (file)
--- a/src/FwdState.h
+++ b/src/FwdState.h
@@ -114,9 +114,8 @@ private:
     /* PeerSelectionInitiator API */
     virtual void noteDestination(Comm::ConnectionPointer conn) override;
     virtual void noteDestinationsEnd(ErrorState *selectionError) override;
-    /// whether the successfully selected path destination or the established
-    /// server connection is still in use
-    bool usingDestination() const;
+
+    bool transporting() const;
 
     void noteConnection(HappyConnOpenerAnswer &);
 
@@ -198,6 +197,9 @@ private:
     /// over the (encrypted, if needed) transport connection to that cache_peer
     JobWait<Http::Tunneler> peerWait;
 
+    /// whether we are waiting for the last dispatch()ed activity to end
+    bool waitingForDispatched;
+
     ResolvedPeersPointer destinations; ///< paths for forwarding the request
     Comm::ConnectionPointer serverConn; ///< a successfully opened connection to a server.
     PeerConnectionPointer destinationReceipt; ///< peer selection result (or nil)