Handle ICAP persistent connection races better.

When an ICAP transaction loses a persistent connection race with an ICAP
server (i.e., Squid sends the ICAP request on a persistent connection just
closed by the ICAP server), the transaction throws and the exception is
treated as a regular error. Even though the transaction may be retried, the
negative side-effects may include ICAP service suspension due to transaction
failures.

This patch logs ICAP transactions that fail due to pconn races with
ERR_ICAP_RACE status and does _not_ blame the ICAP service for the failure.

The following problem was exposed by the pconn races but its fix is
useful in other scopes as well:

When the ICAP connection times out, we now close the connection before
throwing because an exception may be bypassed, and we will throw again (during
peaceful bypass) if Comm tells us that the connection is ready after we timed
out (yes, that can happen because Comm timeouts do not auto-close the
connection).

Based on lp 3p1-rock branch, r9623.

diff --git a/src/adaptation/icap/Elements.cc b/src/adaptation/icap/Elements.cc
index ade7591ac14daf29ecbb17e5ef1c92e44eb6d7f1..17a26130d7400a538ded426bc896147805f769b8 100644 (file)
--- a/src/adaptation/icap/Elements.cc
+++ b/src/adaptation/icap/Elements.cc
@@ -8,6 +8,7 @@ namespace Icap
 {
 
 const XactOutcome xoUnknown = "ICAP_ERR_UNKNOWN";
+const XactOutcome xoRace = "ICAP_ERR_RACE";
 const XactOutcome xoError = "ICAP_ERR_OTHER";
 const XactOutcome xoOpt = "ICAP_OPT";
 const XactOutcome xoEcho = "ICAP_ECHO";

diff --git a/src/adaptation/icap/Elements.h b/src/adaptation/icap/Elements.h
index 7dad0e4a4857865a5d48e0e6db5ae431b383e2e1..ec78a55f6c420175fd6b56961085200d9e24db5f 100644 (file)
--- a/src/adaptation/icap/Elements.h
+++ b/src/adaptation/icap/Elements.h
@@ -64,6 +64,7 @@ using Adaptation::vectPointStr;
 
 typedef const char *XactOutcome; ///< transaction result for logging
 extern const XactOutcome xoUnknown; ///< initial value: outcome was not set
+extern const XactOutcome xoRace; ///< ICAP server closed pconn when we started
 extern const XactOutcome xoError; ///< all kinds of transaction errors
 extern const XactOutcome xoOpt; ///< OPTION transaction
 extern const XactOutcome xoEcho; ///< preserved virgin message (ICAP 204)

diff --git a/src/adaptation/icap/Xaction.cc b/src/adaptation/icap/Xaction.cc
index 8c4bfe9df9054d42e8d07aa3902aa4849581288c..027908fe2419efafad3eb53c6bf119ad858acd17 100644 (file)
--- a/src/adaptation/icap/Xaction.cc
+++ b/src/adaptation/icap/Xaction.cc
@@ -268,7 +268,9 @@ void Adaptation::Icap::Xaction::handleCommTimedout()
            theService->cfg().methodStr() << " " <<
            theService->cfg().uri << status());
     reuseConnection = false;
-    throw TexcHere(connector != NULL ?
+    const bool whileConnecting = connector != NULL;
+    closeConnection(); // so that late Comm callbacks do not disturb bypass
+    throw TexcHere(whileConnecting ?
                    "timed out while connecting to the ICAP service" :
                    "timed out while talking to the ICAP service");
 }
@@ -354,6 +356,18 @@ void Adaptation::Icap::Xaction::noteCommRead(const CommIoCbParams &io)
     Must(io.flag == COMM_OK);
     Must(io.size >= 0);
 
+    if (!io.size) {
+        commEof = true;
+        reuseConnection = false;
+
+        // detect a pconn race condition: eof on the first pconn read
+        if (!al.icap.bytesRead && retriable()) {
+            setOutcome(xoRace);
+            mustStop("pconn race");
+            return;
+        }
+    } else {
+
     al.icap.bytesRead+=io.size;
 
     updateTimeout();
@@ -365,12 +379,8 @@ void Adaptation::Icap::Xaction::noteCommRead(const CommIoCbParams &io)
      * here instead of reading directly into readBuf.buf.
      */
 
-    if (io.size > 0) {
         readBuf.append(commBuf, io.size);
         disableRetries(); // because pconn did not fail
-    } else {
-        reuseConnection = false;
-        commEof = true;
     }
 
     handleCommRead(io.size);