Re: [squid-users] Squid 3.3.4 icap request issue

From: Alex Rousskov <rousskov_at_measurement-factory.com>
Date: Fri, 17 May 2013 18:25:07 -0600

On 05/15/2013 09:12 AM, Guy Helmer wrote:

> I'm seeing something odd with icap REQMOD requests for HTTP POST
> requests in Squid 3.3.4: the encapsulated body appears to not be
> terminated by \r\n0\r\n. This seems to occur consistently with bumped
> SSL requests to graph.facebook.com:

The ICAP-encapsulated HTTP request body is not terminated because Squid
has not received the entire HTTP request body yet. Your ICAP server
timeout is too aggressive for this particular transaction.

Here are the logged steps, FYI:

> 44:51.886 kid1| comm.cc(145) commHandleRead: comm_read_try: FD 11, size 4095, retval 520, errno 0

Squid received HTTP request headers (520 bytes).

> 44:51.897 kid1| ModXact.cc(74) ModXact: initialized. [RG/ job101878]

Squid started an ICAP REQMOD transaction (job101878).

> 44:51.899 kid1| ModXact.cc(191) handleCommConnected: will write [FD 25r;Rrw(1)BG/ job101878]:
> REQMOD icap://127.0.0.1:1344/ca ICAP/1.0
> ...
> 44:51.900 kid1| Write.cc(29) Write: local=127.0.0.1:27210 remote=127.0.0.1:1344 FD 25 flags=1: sz 704

Squid wrote ICAP and HTTP request headers (704 bytes total).

> 44:51.900 kid1| comm.cc(145) commHandleRead: comm_read_try: FD 11, size 4095, retval 4095, errno 0

Squid read the beginning of the HTTP request body (4095 bytes).

> 44:51.902 kid1| ModXact.cc(328) writeSomeBody: will write 4095-byte chunk of prime virgin body
> 44:51.903 kid1| ModXact.cc(201) handleCommWrote: Wrote 4102 bytes

Squid wrote the beginning of the HTTP request body (4095 HTTP bytes).

> 44:51.903 kid1| ModXact.cc(337) writeSomeBody: has no writable prime virgin body content
> 44:52.271 kid1| EventLoop.cc(58) checkEngine: Engine 0xbfbfdc6c is idle.

Squid knows that there is no additional HTTP body data to write (yet)
and does nothing (i.e., waits for more data to arrive from the HTTP client).

> 45:06.920 kid1| ModXact.cc(647) parseMore:
> ICAP/1.0 400 Bad Request
> ...

15 seconds later, the ICAP server gives up and returns a [bogus] error
to Squid.

HTH,

Alex.
Received on Sat May 18 2013 - 00:25:19 MDT

This archive was generated by hypermail 2.2.0 : Sun May 19 2013 - 12:00:08 MDT