------------------------------------------------------------ revno: 14119 revision-id: squid3@treenet.co.nz-20161209015833-xm965d5l6u03qhew parent: squid3@treenet.co.nz-20161130233304-lk3q0bx8gn5l3l85 fixes bug: http://bugs.squid-cache.org/show_bug.cgi?id=4174 author: Christos Tsantilas committer: Amos Jeffries branch nick: 3.5 timestamp: Fri 2016-12-09 14:58:33 +1300 message: 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. ------------------------------------------------------------ # Bazaar merge directive format 2 (Bazaar 0.90) # revision_id: squid3@treenet.co.nz-20161209015833-xm965d5l6u03qhew # target_branch: http://bzr.squid-cache.org/bzr/squid3/3.5 # testament_sha1: 103c6fc1fa45d78ba7f9e85ab3d89fff898ee762 # timestamp: 2016-12-09 02:51:06 +0000 # source_branch: http://bzr.squid-cache.org/bzr/squid3/3.5 # base_revision_id: squid3@treenet.co.nz-20161130233304-\ # lk3q0bx8gn5l3l85 # # Begin patch === modified file 'src/client_side.cc' --- src/client_side.cc 2016-09-23 20:49:24 +0000 +++ src/client_side.cc 2016-12-09 01:58:33 +0000 @@ -340,7 +340,21 @@ AsyncCall::Pointer call = commCbCall(33, 5, "ClientSocketContext::wroteControlMsg", CommIoCbPtrFun(&WroteControlMsg, this)); - getConn()->writeControlMsgAndCall(this, rep.getRaw(), call); + if (!getConn()->writeControlMsgAndCall(this, rep.getRaw(), call)) { + // but still inform the caller (so it may resume its operation) + doneWithControlMsg(); + } +} + +void +ClientSocketContext::doneWithControlMsg() +{ + ScheduleCallHere(cbControlMsgSent); + cbControlMsgSent = NULL; + + debugs(33, 3, clientConnection << ": calling PushDeferredIfNeeded after control msg wrote"); + ClientSocketContextPushDeferredIfNeeded(this, getConn()); + } /// called when we wrote the 1xx response @@ -351,7 +365,7 @@ return; if (errflag == Comm::OK) { - ScheduleCallHere(cbControlMsgSent); + doneWithControlMsg(); return; } @@ -1455,6 +1469,8 @@ if (context != http->getConn()->getCurrentContext()) context->deferRecipientForLater(node, rep, receivedData); + else if (context->controlMsgIsPending()) + context->deferRecipientForLater(node, rep, receivedData); else http->getConn()->handleReply(rep, receivedData); === modified file 'src/client_side.h' --- src/client_side.h 2016-06-18 13:36:07 +0000 +++ src/client_side.h 2016-12-09 01:58:33 +0000 @@ -129,9 +129,13 @@ /// starts writing 1xx control message to the client void writeControlMsg(HttpControlMsg &msg); + /// true if 1xx to the user is pending + bool controlMsgIsPending() {return cbControlMsgSent != NULL;} + protected: static IOCB WroteControlMsg; void wroteControlMsg(const Comm::ConnectionPointer &conn, char *bufnotused, size_t size, Comm::Flag errflag, int xerrno); + void doneWithControlMsg(); private: void prepareReply(HttpReply * rep); @@ -387,7 +391,7 @@ void connectionTag(const char *aTag) { connectionTag_ = aTag; } /// handle a control message received by context from a peer and call back - virtual void writeControlMsgAndCall(ClientSocketContext *context, HttpReply *rep, AsyncCall::Pointer &call) = 0; + virtual bool writeControlMsgAndCall(ClientSocketContext *context, HttpReply *rep, AsyncCall::Pointer &call) = 0; /// ClientStream calls this to supply response header (once) and data /// for the current ClientSocketContext. === modified file 'src/servers/FtpServer.cc' --- src/servers/FtpServer.cc 2016-06-30 21:09:12 +0000 +++ src/servers/FtpServer.cc 2016-12-09 01:58:33 +0000 @@ -1152,12 +1152,13 @@ writeErrorReply(reply, 451); } -void +bool Ftp::Server::writeControlMsgAndCall(ClientSocketContext *context, 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(HDR_FTP_STATUS) writeForwardedReplyAndCall(reply, call); + return true; } void === modified file 'src/servers/FtpServer.h' --- src/servers/FtpServer.h 2016-03-15 18:14:15 +0000 +++ src/servers/FtpServer.h 2016-12-09 01:58:33 +0000 @@ -94,7 +94,7 @@ virtual void clientPinnedConnectionClosed(const CommCloseCbParams &io); virtual void handleReply(HttpReply *header, StoreIOBuffer receivedData); virtual int pipelinePrefetchMax() const; - virtual void writeControlMsgAndCall(ClientSocketContext *context, HttpReply *rep, AsyncCall::Pointer &call); + virtual bool writeControlMsgAndCall(ClientSocketContext *context, HttpReply *rep, AsyncCall::Pointer &call); virtual time_t idleTimeout() const; /* BodyPipe API */ === modified file 'src/servers/HttpServer.cc' --- src/servers/HttpServer.cc 2016-01-01 00:14:27 +0000 +++ src/servers/HttpServer.cc 2016-12-09 01:58:33 +0000 @@ -35,7 +35,7 @@ virtual ClientSocketContext *parseOneRequest(Http::ProtocolVersion &ver); virtual void processParsedRequest(ClientSocketContext *context, const Http::ProtocolVersion &ver); virtual void handleReply(HttpReply *rep, StoreIOBuffer receivedData); - virtual void writeControlMsgAndCall(ClientSocketContext *context, HttpReply *rep, AsyncCall::Pointer &call); + virtual bool writeControlMsgAndCall(ClientSocketContext *context, HttpReply *rep, AsyncCall::Pointer &call); virtual time_t idleTimeout() const; /* BodyPipe API */ @@ -167,9 +167,16 @@ context->sendStartOfMessage(rep, receivedData); } -void +bool Http::Server::writeControlMsgAndCall(ClientSocketContext *context, HttpReply *rep, AsyncCall::Pointer &call) { + // 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; + } + // apply selected clientReplyContext::buildReplyHeader() mods // it is not clear what headers are required for control messages rep->header.removeHopByHopEntries(); @@ -184,6 +191,7 @@ Comm::Write(context->clientConnection, mb, call); delete mb; + return true; } ConnStateData *