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

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 35cba8c40a40ae405714af572d18d2587d1f05bd..226f159248a74037de26f39013ea099b23a311f4 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 ab3b1c8f87e19457caabc92ed848269f6842fb9a..92156969608eb1da6574f26f4f03ccc9d28f0d7b 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 87a1ca0e55cb8f7142cc325be2264d674bfe2ac7..09a21944f6604ab4b86b23a8f77691a2ce0875c9 100644 (file)
--- a/src/adaptation/icap/Xaction.cc
+++ b/src/adaptation/icap/Xaction.cc
@@ -269,9 +269,10 @@ void Adaptation::Icap::Xaction::handleCommTimedout()
            theService->cfg().methodStr() << " " <<
            theService->cfg().uri << status());
     reuseConnection = false;
-    service().noteFailure();
 
-    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");
 }
@@ -356,6 +357,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();
@@ -367,12 +380,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);