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 cee1e61a9414b2edbe029998a6653581c951df53..8f8bf4c3108e515ae9b1ed38a6eadf1097bce4eb 100644 (file)
--- a/src/client_side.cc
+++ b/src/client_side.cc
@@ -1390,6 +1390,7 @@ ClientSocketContextPushDeferredIfNeeded(ClientSocketContext::Pointer deferredReq
      */
 }
 
+/// called when we have successfully finished writing the response
 void
 ClientSocketContext::keepaliveNextRequest()
 {
@@ -1405,6 +1406,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);
+        comm_close(conn->fd);
+        return;
+    }
+
     /** \par
      * Attempt to parse a request from the request buffer.
      * If we've been fed a pipelined request it may already
@@ -1634,44 +1655,36 @@ ClientSocketContext::doClose()
     comm_close(fd());
 }
 
-/** 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();
+    http->getConn()->stopSending(reason); // closes ASAP
+}
 
-        if (conn != NULL) {
-            if (const int64_t expecting = conn->bodySizeLeft()) {
-                debugs(33, 5, HERE << "ClientSocketContext::initiateClose: " <<
-                       "closing, but first " << conn << " needs to read " <<
-                       expecting << " request body bytes with " <<
-                       conn->in.notYetUsed << " notYetUsed");
+void
+ConnStateData::stopSending(const char *error)
+{
+    debugs(33, 4, HERE << "sending error (FD " << fd << "): " << error <<
+           "; old receiving error: " <<
+           (stoppedReceiving() ? stoppedReceiving_ : "none"));
 
-                if (conn->closing()) {
-                    debugs(33, 2, HERE << "avoiding double-closing " << conn);
-                    return;
-                }
+    if (const char *oldError = stoppedSending()) {
+        debugs(33, 3, HERE << "already stopped sending: " << oldError);
+        return; // nothing has changed as far as this connection is concerned
+    }
 
-                /*
-                * 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);
+    stoppedSending_ = error;
 
-                return;
-            }
+    if (!stoppedReceiving()) {
+        if (const int64_t expecting = bodySizeLeft()) {
+            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();
+    comm_close(fd);
 }
 
 void
@@ -2928,16 +2941,11 @@ ConnStateData::handleRequestBodyData()
     if (!bodyPipe) {
         debugs(33,5, HERE << "produced entire request body for FD " << fd);
 
-        if (closing()) {
+        if (const char *reason = stoppedSending()) {
             /* we've finished reading like good clients,
              * now do the close that initiateClose initiated.
-             *
-             * XXX: do we have to close? why not check keepalive et.
-             *
-             * XXX: To support chunked requests safely, we need to handle
-             * the case of an endless request. This if-statement does not,
-             * because mayNeedMoreData is true if request size is not known.
              */
+            debugs(33, 3, HERE << "closing for earlier sending error: " << reason);
             comm_close(fd);
             return false;
         }
@@ -2952,7 +2960,7 @@ ConnStateData::noteMoreBodySpaceAvailable(BodyPipe::Pointer )
         return;
 
     // too late to read more body
-    if (!isOpen() || closing())
+    if (!isOpen() || stoppedReceiving())
         return;
 
     readSomeData();
@@ -2961,8 +2969,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 */
@@ -3755,7 +3766,9 @@ clientAclChecklistCreate(const acl_access * acl, ClientHttpRequest * http)
 
 CBDATA_CLASS_INIT(ConnStateData);
 
-ConnStateData::ConnStateData() :AsyncJob("ConnStateData"), transparent_ (false), closing_ (false), switchedToHttps_(false)
+ConnStateData::ConnStateData() :AsyncJob("ConnStateData"), transparent_ (false),
+    switchedToHttps_(false),
+    stoppedSending_(NULL), stoppedReceiving_(NULL)
 {
     pinning.fd = -1;
     pinning.pinned = false;
@@ -3798,33 +3811,24 @@ ConnStateData::expectRequestBody(int64_t size)
     return bodyPipe;
 }
 
-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 (FD " << fd << "): " << error <<
+           "; old sending error: " <<
+           (stoppedSending() ? stoppedSending_ : "none"));
 
-    assert(bodyPipe != NULL);
-    assert(bodySizeLeft() > 0);
+    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);
+        comm_close(fd);
+    }
 }
 
 void

diff --git a/src/client_side.h b/src/client_side.h
index d85d71bbd80b2ab81c93b7139a0ca14230650c26..9f5f07a7ae1fe26754a94865f0c132ffad225a25 100644 (file)
--- a/src/client_side.h
+++ b/src/client_side.h
@@ -214,8 +214,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);
@@ -293,9 +300,14 @@ private:
 private:
     CBDATA_CLASS2(ConnStateData);
     bool transparent_;
-    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