timout of 'SSL bumped' connect triggers assert in forward.cc

Assuming that a client attempted to contact a HTTPS server which is
actually a 'port 443 blackhole' (meaning, attempts to connect to the
corresponding address and port 443 don't result in any kind of reply)
and this request was intercepted by a squid configured to do 'server
first' SSL bumping, the timeout squid enforces for the asynchronous
connect requests ultimatively triggers in assert in forward.cc. This
happens because the ConnOpener::timeout method calls
ConnOpener::connect which - in turn - calls comm_connect_addr to
determine the status of the connection attempt. This routine uses
getsockopt/ SOL_SOCKET/ SO_ERROR to determine if the connect
succeeded. Because nothing was received from the remote endpoint, at
least on Linux, the result will be 'no error' which means a 'false
positive' 'connection sucessfully established' situation
occurs. Somewhat later, a second timeout will occur for the file
descriptor in question which leads to the destruction of the
corresponding FwdState. Because nothing was ever received and no
'error status' was set, this triggers the assert on line 217. of
forward.cc, causing squid to abort.

Below is a (somewhat hackish) patch with a suggested fix for this
situation which avoids a major code re-shuffling (IMHO, ::timeout
should call ::connect to begin with ...). It consists of two pieces:
The timeout checks in ConnOpener::connect are modified to use >=
instead of > to detect if a timeout occurred. This is necessary
because the ::timeout timeout happens quickly enough after the timeout
expired that another second hasn't passed by the time ::connect gets a
chance to check for it. The second part is a change to
comm_connect_addr: After 'no error' was returned by the getsockopt
call, F->write_handler is checked for being still set. If this is the
case, comm_connect_addr was not called because the descriptor really
became writeable since the 'I/O multiplexing code' had otherwise
cleared the write_handler member prior to invoking the corresponding
function. errno is then set to EINPROGESS, reflecting the actual state
of the connection. This causes the caller to do its timeout check
which leads to an 'orderly abort' of failed connection attempt.

The patch applies cleanly to the lasted to the r12450 squid 3.3.0.3
'auto-generated' release.

-----------------
--- mad-squid/src/comm.cc 8 Jan 2013 18:29:41 -0000 1.1.1.2.2.1
+++ mad-squid/src/comm.cc 13 Jan 2013 21:35:41 -0000 1.1.1.2.2.2
@@ -887,7 +887,24 @@
 
 #endif
 #endif
-
+ /* If an 'in progress' connect attempt times out,
+ * this routine will be called (via ConnOpener::connect)
+ * from ConnOpener::timeout. Because errno will be 0 in
+ * this case, it will be confused with successful
+ * establishment of a connection, ultimatively (at least
+ * for 'server first' bumped intercepted HTTPS requests)
+ * triggering an assert in forward.cc when the 'expired'
+ * file descriptor is forcibly closed after a subsequent
+ * timeout occurred.
+ *
+ * F->write_handler will have been cleared in case
+ * this routine was called because the descriptor actually
+ * became writeable so it can be used to detect the situation
+ * describe above and to signal to the caller that the
+ * connection wasn't really established.
+ */
+ if (!errno && F->write_handler)
+ errno = EINPROGRESS;
     }
 
     /* Squid seems to be working fine without this code. With this code,
--- mad-squid/src/comm/ConnOpener.cc 8 Jan 2013 18:30:27 -0000 1.1.1.1.2.1
+++ mad-squid/src/comm/ConnOpener.cc 13 Jan 2013 21:36:41 -0000 1.1.1.1.2.3
@@ -243,7 +243,7 @@
 
     case COMM_INPROGRESS:
         // check for timeout FIRST.
- if (squid_curtime - connectStart_ > connectTimeout_) {
+ if (squid_curtime - connectStart_ >= connectTimeout_) {
             debugs(5, 5, HERE << conn_ << ": * - ERR took too long already.");
             calls_.earlyAbort_->cancel("Comm::ConnOpener::connect timed out");
             doneConnecting(COMM_TIMEOUT, errno);
@@ -264,7 +264,7 @@
         ++failRetries_;
 
         // check for timeout FIRST.
- if (squid_curtime - connectStart_ > connectTimeout_) {
+ if (squid_curtime - connectStart_ >= connectTimeout_) {
             debugs(5, 5, HERE << conn_ << ": * - ERR took too long to receive response.");
             calls_.earlyAbort_->cancel("Comm::ConnOpener::connect timed out");
             doneConnecting(COMM_TIMEOUT, errno);
Received on Mon Jan 14 2013 - 00:02:20 MST