Author: Alex Rousskov <rousskov@measurement-factory.com>

Bug 3420: Request body consumption races and !theConsumer exception.

Also fixes endless waiting for HTTP client to send req body we no longer need.

Before these changes, the client side used a single "closing" state to
handle two different error conditions:

  1. We stopped receiving request body because of some error.
  2. We stopped sending response because of some error.

When a "directional" error occurred, we try to keep the transaction going in
the other direction (e.g., to give ICAP the entire request or to give HTTP
client the entire response). However, because there was just one "closing"
state, the code failed to correctly detect or process many corner cases,
resulting in stuck transactions and !theConsumer assertions/exceptions due to
races between enableAutoConsumption() and expectNoConsumption() calls.

This patch replaces the "closing" state with two direction-specific "we
stopped sending/receiving" flags.

Now, when the response sending code is done, it now checks whether the
receiving code stopped and closes the connection as needed. This is done both
when we encounter a sending error (ClientSocketContext::initiateClose) and
when we successfully sent the entire response to the client
(ClientSocketContext::keepaliveNextRequest).

Similarly, when the request body reading code is done, it now checks whether
the receiving code stopped and closes the connection as needed. This is done
both when we encounter a receiving error
(ConnStateData::noteBodyConsumerAborted) and when we successfully receive the
entire request body from the client (ClientSocketContext::writeComplete).

TODO: This patch focuses on various error cases. We might still have problems
when there is an early HTTP response and no errors of any kind. I marked the
corresponding old code with an XXX.

diff --git a/src/client_side.cc b/src/client_side.cc
index 2504571bf4310cec8b3676bdd2c7fd2968af0e55..4b3b6f5f79cad842d1b5f1090e9eb90b3998ecb4 100644 (file)
--- a/src/client_side.cc
+++ b/src/client_side.cc
@@ -1520,6 +1520,7 @@ ClientSocketContextPushDeferredIfNeeded(ClientSocketContext::Pointer deferredReq
      */
 }
 
+/// called when we have successfully finished writing the response
 void
 ClientSocketContext::keepaliveNextRequest()
 {
@@ -1534,6 +1535,26 @@ ClientSocketContext::keepaliveNextRequest()
         return;
     }
 
+    /** \par
+     * We are done with the response, and we are either still receiving request
+     * body (early response!) or have already stopped receiving anything.
+     *
+     * If we are still receiving, then clientParseRequest() below will fail.
+     * (XXX: but then we will call readNextRequest() which may succeed and
+     * execute a smuggled request as we are not done with the current request).
+     *
+     * If we stopped because we got everything, then try the next request.
+     *
+     * If we stopped receiving because of an error, then close now to avoid
+     * getting stuck and to prevent accidental request smuggling.
+     */
+
+    if (const char *reason = conn->stoppedReceiving()) {
+        debugs(33, 3, HERE << "closing for earlier request error: " << reason);
+        conn->clientConnection->close();
+        return;
+    }
+
     /** \par
      * Attempt to parse a request from the request buffer.
      * If we've been fed a pipelined request it may already
@@ -1778,44 +1799,35 @@ ClientSocketContext::doClose()
     clientConnection->close();
 }
 
-/** Called to initiate (and possibly complete) closing of the context.
- * The underlying socket may be already closed */
+/// called when we encounter a response-related error
 void
 ClientSocketContext::initiateClose(const char *reason)
 {
-    debugs(33, 5, HERE << "initiateClose: closing for " << reason);
-
-    if (http != NULL) {
-        ConnStateData * conn = http->getConn();
-
-        if (conn != NULL) {
-            if (const int64_t expecting = conn->mayNeedToReadMoreBody()) {
-                debugs(33, 5, HERE << "ClientSocketContext::initiateClose: " <<
-                       "closing, but first " << conn << " needs to read " <<
-                       expecting << " request body bytes with " <<
-                       conn->in.notYetUsed << " notYetUsed");
+    http->getConn()->stopSending(reason); // closes ASAP
+}
 
-                if (conn->closing()) {
-                    debugs(33, 2, HERE << "avoiding double-closing " << conn);
-                    return;
-                }
+void
+ConnStateData::stopSending(const char *error)
+{
+    debugs(33, 4, HERE << "sending error (" << clientConnection << "): " << error <<
+           "; old receiving error: " <<
+           (stoppedReceiving() ? stoppedReceiving_ : "none"));
 
-                /*
-                * XXX We assume the reply fits in the TCP transmit
-                * window.  If not the connection may stall while sending
-                * the reply (before reaching here) if the client does not
-                * try to read the response while sending the request body.
-                * As of yet we have not received any complaints indicating
-                * this may be an issue.
-                */
-                conn->startClosing(reason);
+    if (const char *oldError = stoppedSending()) {
+        debugs(33, 3, HERE << "already stopped sending: " << oldError);
+        return; // nothing has changed as far as this connection is concerned
+    }
+    stoppedSending_ = error;
 
-                return;
-            }
+    if (!stoppedReceiving()) {
+        if (const int64_t expecting = mayNeedToReadMoreBody()) {
+            debugs(33, 5, HERE << "must still read " << expecting <<
+                   " request body bytes with " << in.notYetUsed << " unused");
+            return; // wait for the request receiver to finish reading
         }
     }
 
-    doClose();
+    clientConnection->close();
 }
 
 void
@@ -2936,10 +2948,11 @@ ConnStateData::handleRequestBodyData()
     if (!bodyPipe) {
         debugs(33,5, HERE << "produced entire request body for " << clientConnection);
 
-        if (closing()) {
+        if (const char *reason = stoppedSending()) {
             /* we've finished reading like good clients,
              * now do the close that initiateClose initiated.
              */
+            debugs(33, 3, HERE << "closing for earlier sending error: " << reason);
             clientConnection->close();
             return false;
         }
@@ -3036,7 +3049,7 @@ ConnStateData::noteMoreBodySpaceAvailable(BodyPipe::Pointer )
         return;
 
     // too late to read more body
-    if (!isOpen() || closing())
+    if (!isOpen() || stoppedReceiving())
         return;
 
     readSomeData();
@@ -3045,8 +3058,11 @@ ConnStateData::noteMoreBodySpaceAvailable(BodyPipe::Pointer )
 void
 ConnStateData::noteBodyConsumerAborted(BodyPipe::Pointer )
 {
-    if (!closing())
-        startClosing("body consumer aborted");
+    // request reader may get stuck waiting for space if nobody consumes body
+    if (bodyPipe != NULL)
+        bodyPipe->enableAutoConsumption();
+
+    stopReceiving("virgin request body consumer aborted"); // closes ASAP
 }
 
 /** general lifetime handler for HTTP requests */
@@ -3856,8 +3872,9 @@ CBDATA_CLASS_INIT(ConnStateData);
 
 ConnStateData::ConnStateData() :
         AsyncJob("ConnStateData"),
-        closing_(false),
-        switchedToHttps_(false)
+        switchedToHttps_(false),
+        stoppedSending_(NULL),
+        stoppedReceiving_(NULL)
 {
     pinning.pinned = false;
     pinning.auth = false;
@@ -3914,32 +3931,24 @@ ConnStateData::mayNeedToReadMoreBody() const
     return needToProduce - haveAvailable;
 }
 
-bool
-ConnStateData::closing() const
-{
-    return closing_;
-}
-
-/**
- * Called by ClientSocketContext to give the connection a chance to read
- * the entire body before closing the socket.
- */
 void
-ConnStateData::startClosing(const char *reason)
+ConnStateData::stopReceiving(const char *error)
 {
-    debugs(33, 5, HERE << "startClosing " << this << " for " << reason);
-    assert(!closing());
-    closing_ = true;
+    debugs(33, 4, HERE << "receiving error (" << clientConnection << "): " << error <<
+           "; old sending error: " <<
+           (stoppedSending() ? stoppedSending_ : "none"));
 
-    assert(bodyPipe != NULL);
+    if (const char *oldError = stoppedReceiving()) {
+        debugs(33, 3, HERE << "already stopped receiving: " << oldError);
+        return; // nothing has changed as far as this connection is concerned
+    }
 
-    // We do not have to abort the body pipeline because we are going to
-    // read the entire body anyway.
-    // Perhaps an ICAP server wants to log the complete request.
+    stoppedReceiving_ = error;
 
-    // If a consumer abort have caused this closing, we may get stuck
-    // as nobody is consuming our data. Allow auto-consumption.
-    bodyPipe->enableAutoConsumption();
+    if (const char *sendError = stoppedSending()) {
+        debugs(33, 3, HERE << "closing because also stopped sending: " << sendError);
+        clientConnection->close();
+    }
 }
 
 void

diff --git a/src/client_side.h b/src/client_side.h
index e895024f0442ad12f1a61e0e118572d9f02d37a5..c3be97d05d40bf3f776b2159ffca8f8ae1aec0ac 100644 (file)
--- a/src/client_side.h
+++ b/src/client_side.h
@@ -260,8 +260,15 @@ public:
     bool reading() const;
     void stopReading(); ///< cancels comm_read if it is scheduled
 
-    bool closing() const;
-    void startClosing(const char *reason);
+    /// true if we stopped receiving the request
+    const char *stoppedReceiving() const { return stoppedReceiving_; }
+    /// true if we stopped sending the response
+    const char *stoppedSending() const { return stoppedSending_; }
+    /// note request receiving error and close as soon as we write the response
+    void stopReceiving(const char *error);
+    /// note response sending error and close as soon as we read the request
+    void stopSending(const char *error);
+
     void expectNoForwarding(); ///< cleans up virgin request [body] forwarding state
 
     BodyPipe::Pointer expectRequestBody(int64_t size);
@@ -341,9 +348,14 @@ private:
 
     // XXX: CBDATA plays with public/private and leaves the following 'private' fields all public... :(
     CBDATA_CLASS2(ConnStateData);
-    bool closing_;
 
     bool switchedToHttps_;
+
+    /// the reason why we no longer write the response or nil
+    const char *stoppedSending_;
+    /// the reason why we no longer read the request or nil
+    const char *stoppedReceiving_;
+
     String sslHostName; ///< Host name for SSL certificate generation
     AsyncCall::Pointer reader; ///< set when we are reading
     BodyPipe::Pointer bodyPipe; // set when we are reading request body