[squid-users] Problem with squid not returning the ICAP modified response to the client

Hello,

I have an ICAP server that I am using with squid (3.1.12.1 but have
tried others) in order to support RESPMOD. It usually works fine but I
am now having problems trying to implement what I think should be a
simple service.

I am not including full logs in this initial email as I'm not sure
exactly what would help (I have not seen error messages) and I don't
want to just dump everything. I will gladly sent whatever could help.

The problem:

A RESPMOD service which returns a 302 (I have also tried a 404 but the
results were the same) following a GET request from a client (wget).

I have no problem downloading the file without going through ICAP.
All caching is disabled.
I have tried with different files on different servers.
There are no visible network / routing issues.
The ICAP service is respmod_precache and bypass on.
Strange: For some reason, it has worked on very few occasions (maybe
5/6 on dozens of attempts).
The ICAP exchange appears to be completed without problems (the socket
is closed by the ICAP server).
The ICAP server implements other services (both REQMOD and RESPMOD)
with squid and they work well.

Case A - The file is locally hosted
Case B - The file is hosted on an external, third party website

Case A:

   1. Squid receives the GET request for the file.
   2. Squid starts fetching the file from the origin server.
   3. Squid sends (in parallel) the RESPMOD request and receives an
answer from the ICAP server (302/Redirect).
   4. Squid continues downloading data from the origin server.
   5. At some point (> preview size, < total size) Squid sends a
RST/ACK to the origin server and closes the connection.
   6. Squid sends the 302 to the client.

Case B:

   1. Squid receives the GET request for the file.
   2. Squid starts fetching the file from the origin server.
   3. Squid sends (in parallel) the RESPMOD request and receives an
answer from the ICAP server (302/Redirect).
   4. Squid continues downloading data from the origin server.
   5. At some point (> preview size, < total size) Squid sends a "TCP
Window Full" to the origin server.
   6. Squid and the origin server enter a TCP Zero Window Probe cycle
that they never get out of.
   7. Squid never gets done with the connection to the origin server
and therefore does not send the 302 to the client.
   8. The client is stuck waiting for a reply to its original GET
while Squid is stuck downloading data that it does not need in order
to send the reply.

As noted above, it seems that squid starts fetching the original
requested media as soon as it receives the GET request even though the
ICAP RESPMOD modifies the response to just send a 302.
It also appears that it does not return an answer to the client until
it is done with the origin server from which it is getting the file.

The reason why Case B leads to a Window Full is still unclear. The
window is full before it has downloaded the number of bytes at which
it closes the connection itself in Case A. That suggests that it
should have enough buffer space to continue storing the response.

I'm not sure why squid, after it has received the response from the
ICAP server needs to continue downloading from the origin server, why
it needs this to end in order to send the ICAP response to the client,
and why it gets in a situation where it stops reading from the origin
server (window full) and therefore blocks the request. Is it waiting
for something to consume the original file? If so, what should? Why
does local hosting make a difference?

The ICAP exchange (the log below is with returning a 404 but it's the
same with a 302 + Location header (the original problem)).

----
RESPMOD icap://127.0.0.1:1344/df ICAP/1.0
Host: 127.0.0.1:1344
Date: Mon, 09 May 2011 14:43:09 GMT
Encapsulated: req-hdr=0, res-hdr=128, res-body=374
Preview: 64
X-Client-IP: 127.0.0.1
GET http://172.16.199.35/sanity/media/PrinceOfPersia.flv HTTP/1.0
User-Agent: Wget/1.11.4
Accept: */*
Host: 172.16.199.35
HTTP/1.1 200 OK
Date: Mon, 09 May 2011 14:43:09 GMT
Server: Apache/2.2.3 (Red Hat)
Last-Modified: Mon, 04 Oct 2010 14:30:31 GMT
ETag: "74c0111-5bffc8-491cb62ee0fc0"
Accept-Ranges: bytes
Content-Length: 6029256
Content-Type: video/x-flv
40
FLV.............K.........
onMetaData.......duration._at_b.|..hs..s
0
ICAP/1.0 200 OK
Encapsulated: res-hdr=0, null-body=26
Connection: close
Date: Mon, 09 May 2011 14:43:09 GMT
Server: Optimizer
ISTag: "757795719"
HTTP/1.1 404 Not Found
----
Any help would be appreciated. Thanks.
John Craws