Re: [squid-users] Problem with Squid-3.0.STABLE1 and ICAP

From: Guy Helmer <ghelmer@dont-contact.us>
Date: Mon, 07 Jan 2008 16:04:38 -0600

selvi wrote:
> Hi Christos,
>
> Thanks for your reply. I am posting the squid-icap server conversation
> and also the debug messages here.
>
> Christos Tsantilas wrote:
>> Hi Selvi,
>> selvi wrote:
>>
>>> Hello All,
>>>
>>> I am in the process of integrating squid-3.0.STABLE1 with Python based
>>> ICAP Server. Here, i am not able to get the response modification.
>>>
>>
>> Is it a custom ICAP server?
>>
>
> I am using the Python based ICAP Server.
>>
>>> ICAP related configurations given are:
>>>
>>> icap_enable on
>>> icap_send_client_ip on
>>> icap_service content respmod_precache 0 icap://<IP
>>> Address>:1344/respmod
>>> icap_class class_1 content
>>> icap_access class_1 allow all
>>>
>>> I am not seeing any error messages in the ICAP Server side. Squid also
>>> behaves normally except the following message in cache.log
>>> "essential ICAP service is invalidated by reconfigure: icap://<IP
>>> Address>:1344/respmod [down,gone,!opt]". But when i perform some web
>>> access through ICAP enabled squid proxy, empty page is displayed (the
>>> browser displays nothing).
>>>
>>>
>>
>> This message means that the squid tried to send an options request to
>> the ICAP server and the ICAP server answer was not correct (or just did
>> not like to the squid)
>> I am suggesting to enable debug for ICAP client in squid3:
>> debug_options 93,9 0,9
>> And search in debug messages to see what they say about. You can also
>> post the debug messages here.
>>
>> Also grabbing the conversation between squid and ICAP server using
>> wireshark or similar tool will be helpful...
>>
>> Regards,
>> Christos
>>
>>
> A snapshot of the conversation between squid and ICAP server is given
> below (using tcpdump).
>
> 11:04:02.978996 IP squid225.kovaiteam.com.60111 >
> squid225.kovaiteam.com.1344: S 2637131307:2637131307(0) win 32767 <mss
> 16396,sackOK,timestamp 1238745316 0,nop,wscale 8>
> E..<..@.@.0
> ...........@./n+........+.....@....
>
> I...........
FWIW, I have found that output from Wireshark's text-mode program tshark
is better than tcpdump's plaintext output mode since it displays the
results in a handy offset / data bytes format when the '-x' option is
used, like this:

1199742865.861775 192.16.1.240 -> 205.237.115.33 HTTP GET / HTTP/1.0

0000 00 30 48 41 4b a8 00 11 d8 50 cb a3 08 00 45 00 .0HAK....P....E.
0010 02 a3 1c 7c 40 00 40 06 2c ca c0 10 01 f0 cd ed ...|@.@.,.......
0020 73 21 d6 c9 00 50 e9 5e 8a c1 2a 5d 81 3c 80 18 s!...P.^..*].<..
0030 20 86 f1 a4 00 00 01 01 08 0a 1a 13 f9 ec 25 ad .............%.
0040 b7 77 47 45 54 20 2f 20 48 54 54 50 2f 31 2e 30 .wGET / HTTP/1.0
0050 0d 0a 48 6f 73 74 3a 20 77 77 77 2e 70 61 6c 69 ..Host: www.pali
...

I suggest this because I've found that Squid 3's ICAP parser is more
pedantic than Squid 2.6's, and seeing the exact byte values and offsets
has helped me find ICAP protocol violations in the past.

Anyway, I would suspect the "Encapsulated: " line in the ICAP response
below is the root of the problem; as I believe Christos mentioned, the
values must be separated by commas, not just whitespace.
> 2008/01/05 15:19:41.425| ICAP/ICAPModXact.cc(574) have 428 bytes to
> parse [FD 14;RrB/w icapx1]
> 2008/01/05 15:19:41.425| ICAP/ICAPModXact.cc(575)
> ICAP/1.0 200 OK^M
> Date: Sat, 05 Jan 2008 09:49:41 GMT^M
> Encapsulated: res-hdr=0 res-body=269^M
> Server: ICAP-Server-Software/1.0^M
> ^M
> HTTP/1.0 200 OK^M
> Content-Length: 29^M
> Accept-Ranges: bytes^M
> Server: Apache/2.0.52 (Red Hat)^M
> Last-Modified: Sat, 05 Jan 2008 07:22:49 GMT^M
> Connection: close^M
> ETag: "64cce7-1d-442f47e85e440"^M
> Connection: close^M
> ETag: "64cce7-1d-442f47e85e440"^M
> Date: Sat, 05 Jan 2008 09:49:41 GMT^M
> Content-Type: text/html; charset=UTF-8^M
> ^M
> <html>
> Hello Selvi
> </html>
>
>
> ^M
>
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(653) parse ICAP headers
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(882) have 428 head bytes
> to parse; state: 0
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(894) parse success,
> consume 128 bytes, return true
> 2008/01/05 15:19:41.426| ICAPModXact will no longer backup [FD
> 14;RrBp(1)S(2)/w icapx1]
> 2008/01/05 15:19:41.426| consumption guards: 00
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(383) max virgin
> consumption offset=29 acts 00 consumed=0 from [0<=29<=29 29+2018
> pipe0x6000000000451288 cons0x6000000000459768]
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(395) consuming 29 out of
> 29 virgin body bytes
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(567) will stop consuming
> [FD 14;Rrp(1)S(2)/w icapx1]
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(658) parse HTTP headers
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(882) have 300 head bytes
> to parse; state: 1
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(894) parse success,
> consume 269 bytes, return true
> 2008/01/05 15:19:41.426| ICAP/ICAPModXact.cc(926) not expecting a body
This doesn't look good -- I would suspect that the ICAP parser didn't
find the res-body value in the Encapsulated: header due to the erroneous
separator character, and it's dumping your replacement HTML data as a
result.
> ...
> Thanks
> Selvi
>>> The same setup with squid-2.5.STABLE13 works properly (the page is
>>> displayed).
>>>
>>> What could be the problem?
>>>
>>> Thanks for your assistance.
>>>
>>> Thanks
>>> Selvi
>>>
>>
>>
>>

-- 
Guy Helmer, Ph.D.
Chief System Architect
Palisade Systems, Inc.
Received on Mon Jan 07 2008 - 15:04:55 MST

This archive was generated by hypermail pre-2.1.9 : Fri Feb 01 2008 - 12:00:04 MST