Re: Problem with squid not returning the ICAP modified response to the client

From: Alex Rousskov <rousskov_at_measurement-factory.com>
Date: Tue, 10 May 2011 10:07:04 -0600

On 05/10/2011 08:05 AM, John Craws wrote:

> "This would be http://bugs.squid-cache.org/show_bug.cgi?id=3153 yes?
> Neither Alex nor Christos who are working on it read this mailing
> list. Contact them via bugzilla or squid-dev please."
>
> I don't think this looks like 3153. The client is not disconnecting
> and the server is not aborting.
> Please see below for the details and differences.
>
> Thanks a lot!
>
> ---
>
> 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.

The Squid behavior you describe seems correct and reasonable. The origin
server does not know about your ICAP service and should not be punished
with connection resets and other nasties just because your service does
not care about the response. What alternative behavior would you prefer
in this case?

If you would like to prevent useless response transfers and do not
really care about the response itself, consider moving your service to
precache REQMOD vectoring point and using ICAP request satisfaction
instead. There may be other, more complex options as well.

> 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.

This should not be happening. If it does, it is a Squid bug, IMO. From
client point of view, your ICAP RESPMOD service is, essentially, the
HTTP origin server.

However, your HTTP adapted response is kind of malformed, which may
cause symptoms similar to the above. See below for details.

> 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,

Squid just wants to complete the HTTP transaction nicely. HTTP does not
have a way of saying "I changed my mind, do not send me the rest of this
response". See above for one of the options to prevent this waste.

> 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?

Does your ICAP RESPMOD service consume the ICAP request with the
embedded HTTP response body after returning an ICAP 200 response? It
must. See also ICAP 206 extension that was recently added to Squid, IIRC.

The local-vs-remove hosting of the response probably changes some TCP
stack timings/buffering and is not really relevant to the core problem.

> 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
>
>
> ----

The above embedded adapted HTTP 404 response must have a (possibly
zero-length) body (from HTTP rules point of view). Yet, your ICAP
service says there is no HTTP response body. I do not know how Squid
will handle this contradiction, but you should change the response to
have a body or, at the very least, add a "Content-Length: 0" HTTP
response header. Same for the HTTP 302 response.

HTH,

Alex.
Received on Tue May 10 2011 - 16:07:17 MDT

This archive was generated by hypermail 2.2.0 : Wed May 11 2011 - 12:00:04 MDT