From: Christos Tsantilas <chtsanti@users.sourceforge.net>
Date: Tue, 15 Nov 2016 09:41:26 +0000 (+0200)
Subject: Fixed Write.cc:41 "!ccb->active()" assertion.
X-Git-Tag: M-staged-PR71~371
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=24e1fd72cb91ada091059b7409c19d89a5278d3d;p=thirdparty%2Fsquid.git

Fixed 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 2ca06b6897..1efc69b7cc 100644
--- a/src/HttpControlMsg.cc
+++ b/src/HttpControlMsg.cc
@@ -11,6 +11,15 @@
 #include "CommCalls.h"
 #include "HttpControlMsg.h"
 
+void
+HttpControlMsgSink::wroteControlMsgOK()
+{
+    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);
+        wroteControlMsgOK();
         return;
     }
 
diff --git a/src/HttpControlMsg.h b/src/HttpControlMsg.h
index 6e8d22b0bf..eb51dd3e04 100644
--- 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 wroteControlMsgOK();
+
     /// callback to handle Comm::Write completion
     void wroteControlMsg(const CommIoCbParams &);
 
diff --git a/src/client_side.cc b/src/client_side.cc
index 0ceffb4835..ce37226459 100644
--- 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);
 
@@ -3831,6 +3833,17 @@ ConnStateData::sendControlMsg(HttpControlMsg msg)
     clientConnection->close();
 }
 
+void
+ConnStateData::wroteControlMsgOK()
+{
+    HttpControlMsgSink::wroteControlMsgOK();
+
+    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 04610561be..7d32b16596 100644
--- a/src/client_side.h
+++ b/src/client_side.h
@@ -77,6 +77,7 @@ public:
 
     /* HttpControlMsgSink API */
     virtual void sendControlMsg(HttpControlMsg);
+    virtual void wroteControlMsgOK();
 
     /// Traffic parsing
     bool clientParseRequests();
diff --git a/src/servers/Http1Server.cc b/src/servers/Http1Server.cc
index b564896c3c..ecdc2f12e1 100644
--- a/src/servers/Http1Server.cc
+++ b/src/servers/Http1Server.cc
@@ -309,7 +309,19 @@ Http::One::Server::handleReply(HttpReply *rep, StoreIOBuffer receivedData)
 void
 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);
+        // but still inform the caller (so it may resume its operation)
+        ScheduleCallHere(call);
+        return;
+    }
+
+    const ClientHttpRequest *http = context->http;
 
     // apply selected clientReplyContext::buildReplyHeader() mods
     // it is not clear what headers are required for control messages