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

On Tue, May 10, 2011 at 12:07 PM, Alex Rousskov
<rousskov_at_measurement-factory.com> wrote:
> 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?

I understand. I thought Squid would close the connection after it had
downloaded enough for the preview and received an ICAP response that
indicated that no more data from that server was necessary.

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

Thank you.

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

That was it.

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

Ok. Thanks.

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

That was it. The response should have had a possibly zero-length body,
but it had none.
My bad. I added a dummy one just to test and it fixed the problem.

Thanks a lot Alex!

>
> HTH,
>
> Alex.
>
Received on Tue May 10 2011 - 20:08:55 MDT