From cc92803c8f9df20140610f19f89acce2116f16c7 Mon Sep 17 00:00:00 2001 From: Christos Tsantilas Date: Mon, 28 Nov 2016 23:08:16 +1300 Subject: [PATCH] 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. --- src/HttpControlMsg.cc | 12 ++++++++++-- src/HttpControlMsg.h | 2 ++ src/client_side.cc | 18 +++++++++++++++++- src/client_side.h | 3 ++- src/servers/FtpServer.cc | 3 ++- src/servers/FtpServer.h | 2 +- src/servers/Http1Server.cc | 15 +++++++++++++-- src/servers/Http1Server.h | 2 +- src/tests/stub_HttpControlMsg.cc | 1 + 9 files changed, 49 insertions(+), 9 deletions(-) diff --git a/src/HttpControlMsg.cc b/src/HttpControlMsg.cc index 2ca06b6897..29f9888a7e 100644 --- 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 ¶ms) @@ -19,8 +28,7 @@ HttpControlMsgSink::wroteControlMsg(const CommIoCbParams ¶ms) return; if (params.flag == Comm::OK) { - if (cbControlMsgSent) - ScheduleCallHere(cbControlMsgSent); + doneWithControlMsg(); return; } diff --git a/src/HttpControlMsg.h b/src/HttpControlMsg.h index 6e8d22b0bf..cfeb53903b 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 doneWithControlMsg(); + /// callback to handle Comm::Write completion void wroteControlMsg(const CommIoCbParams &); diff --git a/src/client_side.cc b/src/client_side.cc index b45094d4c5..dc4d885549 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); @@ -3823,7 +3825,10 @@ ConnStateData::sendControlMsg(HttpControlMsg msg) typedef CommCbMemFunT 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 04610561be..ba0d328e71 100644 --- 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 c30a1adb7a..42cbd0147d 100644 --- 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 f3025ba411..e44f7d5d39 100644 --- 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 b564896c3c..4129e0d4ce 100644 --- 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 4187a5c47d..d1cd50f865 100644 --- 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 5b7b4723ec..9fa482dc06 100644 --- 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 -- 2.47.3