Bug 4174 partial: fix Write.cc:41 "!ccb->active()" assertion.

The following sequence of events triggers this assertion:
  - The server sends an 1xx control message.
  - http.cc schedules ConnStateData::sendControlMsg call.
  - Before sendControlMsg is fired, http.cc detects an error (e.g., I/O
    error or timeout) and starts writing the reply to the user.
  - The ConnStateData::sendControlMsg is fired, starts writing 1xx, and
    hits the "no concurrent writes" assertion.

We could only reproduce this sequence in the lab after changing Squid
code to trigger a timeout at the right moment, but the sequence looks
plausible. Other event sequences might result in the same outcome.

To avoid concurrent writes, Squid now drops the control message if
Http::One::Server detects that a reply is already being written. Also,
ConnStateData delays reply writing until a pending control message write
has been completed.

This is a Measurement Factory project.

diff --git a/src/HttpControlMsg.cc b/src/HttpControlMsg.cc
index 2ca06b6897cbbb8f2c5a8acf55ee7468c2bc8cb5..29f9888a7e98fbe2ac40fd3b7010a84a002e462d 100644 (file)
--- a/src/HttpControlMsg.cc
+++ b/src/HttpControlMsg.cc
@@ -11,6 +11,15 @@
 #include "CommCalls.h"
 #include "HttpControlMsg.h"
 
+void
+HttpControlMsgSink::doneWithControlMsg()
+{
+    if (cbControlMsgSent) {
+        ScheduleCallHere(cbControlMsgSent);
+        cbControlMsgSent = nullptr;
+    }
+}
+
 /// called when we wrote the 1xx response
 void
 HttpControlMsgSink::wroteControlMsg(const CommIoCbParams &params)
@@ -19,8 +28,7 @@ HttpControlMsgSink::wroteControlMsg(const CommIoCbParams &params)
         return;
 
     if (params.flag == Comm::OK) {
-        if (cbControlMsgSent)
-            ScheduleCallHere(cbControlMsgSent);
+        doneWithControlMsg();
         return;
     }
 

diff --git a/src/HttpControlMsg.h b/src/HttpControlMsg.h
index 6e8d22b0bf2d3c2cf935719a32085b83ae89d393..cfeb53903bb5761a517c633ff3b9139a2c793cb7 100644 (file)
--- a/src/HttpControlMsg.h
+++ b/src/HttpControlMsg.h
@@ -33,6 +33,8 @@ public:
     /// called to send the 1xx message and notify the Source
     virtual void sendControlMsg(HttpControlMsg msg) = 0;
 
+    virtual void doneWithControlMsg();
+
     /// callback to handle Comm::Write completion
     void wroteControlMsg(const CommIoCbParams &);
 

diff --git a/src/client_side.cc b/src/client_side.cc
index b45094d4c5c3f29d25cc3d79e7494ccc68bd1bff..dc4d885549aafa80971ccfcfcc500531f35f475e 100644 (file)
--- a/src/client_side.cc
+++ b/src/client_side.cc
@@ -814,6 +814,8 @@ clientSocketRecipient(clientStreamNode * node, ClientHttpRequest * http,
     // TODO: enforces HTTP/1 MUST on pipeline order, but is irrelevant to HTTP/2
     if (context != http->getConn()->pipeline.front())
         context->deferRecipientForLater(node, rep, receivedData);
+    else if (http->getConn()->cbControlMsgSent) // 1xx to the user is pending
+        context->deferRecipientForLater(node, rep, receivedData);
     else
         http->getConn()->handleReply(rep, receivedData);
 
@@ -3823,7 +3825,10 @@ ConnStateData::sendControlMsg(HttpControlMsg msg)
         typedef CommCbMemFunT<HttpControlMsgSink, CommIoCbParams> Dialer;
         AsyncCall::Pointer call = JobCallback(33, 5, Dialer, this, HttpControlMsgSink::wroteControlMsg);
 
-        writeControlMsgAndCall(rep.getRaw(), call);
+        if (!writeControlMsgAndCall(rep.getRaw(), call)) {
+            // but still inform the caller (so it may resume its operation)
+            doneWithControlMsg();
+        }
         return;
     }
 
@@ -3831,6 +3836,17 @@ ConnStateData::sendControlMsg(HttpControlMsg msg)
     clientConnection->close();
 }
 
+void
+ConnStateData::doneWithControlMsg()
+{
+    HttpControlMsgSink::doneWithControlMsg();
+
+    if (Http::StreamPointer deferredRequest = pipeline.front()) {
+        debugs(33, 3, clientConnection << ": calling PushDeferredIfNeeded after control msg wrote");
+        ClientSocketContextPushDeferredIfNeeded(deferredRequest, this);
+    }
+}
+
 /// Our close handler called by Comm when the pinned connection is closed
 void
 ConnStateData::clientPinnedConnectionClosed(const CommCloseCbParams &io)

diff --git a/src/client_side.h b/src/client_side.h
index 04610561bea24d0f36f44710f7f2e89827dac110..ba0d328e71a696cfbdaf6c6ebab3e56cbd66c0ca 100644 (file)
--- a/src/client_side.h
+++ b/src/client_side.h
@@ -77,6 +77,7 @@ public:
 
     /* HttpControlMsgSink API */
     virtual void sendControlMsg(HttpControlMsg);
+    virtual void doneWithControlMsg();
 
     /// Traffic parsing
     bool clientParseRequests();
@@ -263,7 +264,7 @@ public:
     void connectionTag(const char *aTag) { connectionTag_ = aTag; }
 
     /// handle a control message received by context from a peer and call back
-    virtual void writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &call) = 0;
+    virtual bool writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &call) = 0;
 
     /// ClientStream calls this to supply response header (once) and data
     /// for the current Http::Stream.

diff --git a/src/servers/FtpServer.cc b/src/servers/FtpServer.cc
index c30a1adb7a9dc600c593adefe032f5d78308d70f..42cbd0147d1420e9b6626eb9cc72baa0b474479d 100644 (file)
--- a/src/servers/FtpServer.cc
+++ b/src/servers/FtpServer.cc
@@ -1153,12 +1153,13 @@ Ftp::Server::writeForwardedForeign(const HttpReply *reply)
     writeErrorReply(reply, 451);
 }
 
-void
+bool
 Ftp::Server::writeControlMsgAndCall(HttpReply *reply, AsyncCall::Pointer &call)
 {
     // the caller guarantees that we are dealing with the current context only
     // the caller should also make sure reply->header.has(Http::HdrType::FTP_STATUS)
     writeForwardedReplyAndCall(reply, call);
+    return true;
 }
 
 void

diff --git a/src/servers/FtpServer.h b/src/servers/FtpServer.h
index f3025ba4112015ec00eabf1cfe84be0d0fe7d3fc..e44f7d5d3981382830a54d4aa12bf1a71f095fa7 100644 (file)
--- a/src/servers/FtpServer.h
+++ b/src/servers/FtpServer.h
@@ -97,7 +97,7 @@ protected:
     virtual void clientPinnedConnectionClosed(const CommCloseCbParams &io) override;
     virtual void handleReply(HttpReply *header, StoreIOBuffer receivedData) override;
     virtual int pipelinePrefetchMax() const override;
-    virtual void writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &call) override;
+    virtual bool writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &call) override;
     virtual time_t idleTimeout() const override;
 
     /* BodyPipe API */

diff --git a/src/servers/Http1Server.cc b/src/servers/Http1Server.cc
index b564896c3cb3d5478c8995b1e3a7853b3e9e0802..4129e0d4ceb1611d22ee0f763d2af0d838762434 100644 (file)
--- a/src/servers/Http1Server.cc
+++ b/src/servers/Http1Server.cc
@@ -306,10 +306,20 @@ Http::One::Server::handleReply(HttpReply *rep, StoreIOBuffer receivedData)
     context->sendStartOfMessage(rep, receivedData);
 }
 
-void
+bool
 Http::One::Server::writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &call)
 {
-    const ClientHttpRequest *http = pipeline.front()->http;
+    Http::StreamPointer context = pipeline.front();
+    Must(context != nullptr);
+
+    // Ignore this late control message if we have started sending a
+    // reply to the user already (e.g., after an error).
+    if (context->reply) {
+        debugs(11, 2, "drop 1xx made late by " << context->reply);
+        return false;
+    }
+
+    const ClientHttpRequest *http = context->http;
 
     // apply selected clientReplyContext::buildReplyHeader() mods
     // it is not clear what headers are required for control messages
@@ -325,6 +335,7 @@ Http::One::Server::writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &ca
     Comm::Write(clientConnection, mb, call);
 
     delete mb;
+    return true;
 }
 
 ConnStateData *

diff --git a/src/servers/Http1Server.h b/src/servers/Http1Server.h
index 4187a5c47d87482654694507749d6513c8d2f74c..d1cd50f865b29497b58d25634b210b96736e4718 100644 (file)
--- a/src/servers/Http1Server.h
+++ b/src/servers/Http1Server.h
@@ -32,7 +32,7 @@ protected:
     virtual Http::Stream *parseOneRequest();
     virtual void processParsedRequest(Http::StreamPointer &context);
     virtual void handleReply(HttpReply *rep, StoreIOBuffer receivedData);
-    virtual void writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &call);
+    virtual bool writeControlMsgAndCall(HttpReply *rep, AsyncCall::Pointer &call);
     virtual time_t idleTimeout() const;
 
     /* BodyPipe API */

diff --git a/src/tests/stub_HttpControlMsg.cc b/src/tests/stub_HttpControlMsg.cc
index 5b7b4723ec20792ac238ba173d907ccf99ee9b9c..9fa482dc063a53ecdc0758ba0599987e7c7e905a 100644 (file)
--- a/src/tests/stub_HttpControlMsg.cc
+++ b/src/tests/stub_HttpControlMsg.cc
@@ -13,4 +13,5 @@
 
 #include "HttpControlMsg.h"
 void HttpControlMsgSink::wroteControlMsg(CommIoCbParams const&) STUB
+void HttpControlMsgSink::doneWithControlMsg() STUB