evan gozali wrote:
Hi, my name is Evan. I'm currently trying to connect an open source ICAP server Poesia 3.5 with Squid 3.0 STABLE4. While testing, I meet a problem when opening url http://marc.info/?l=squid=dev&r=1&w=2. The problem seems to me like when Squid sent the RESPMOD message, Squid didn't send the Http-body to the ICAP-server. Here is the log (ICAP-part only)
Please do not use Squid 3.0 earlier that STABLE7. http://www.squid-cache.org/Advisories/SQUID-2008_1.txt
********************************************************* 2008/08/13 13:52:19.755| ICAPAccessCheck constructed for RESPMOD PRECACHE 2008/08/13 13:52:19.755| ICAPAccessCheck::check 2008/08/13 13:52:19.755| ICAP/ICAPConfig.cc(277) looking for the first matching service in class class_req 2008/08/13 13:52:19.755| ICAP/ICAPConfig.cc(329) found no matching services in class class_req 2008/08/13 13:52:19.755| ICAP/ICAPConfig.cc(277) looking for the first matching service in class class_resp 2008/08/13 13:52:19.755| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no Transfer-Preview extensions 2008/08/13 13:52:19.755| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no Transfer-Complete extensions 2008/08/13 13:52:19.755| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no Transfer-Ignore extensions 2008/08/13 13:52:19.755| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no extensions; using default: Transfer-Complete 2008/08/13 13:52:19.755| ICAP/ICAPConfig.cc(315) found first matching service in class class_resp: service_resp 2008/08/13 13:52:19.755| ICAPAccessCheck::check: class 'class_resp' has candidate service 'service_resp' 2008/08/13 13:52:19.755| ICAPAccessCheckCallbackWrapper: answer=1 2008/08/13 13:52:19.755| ICAPAccessCheckCallbackWrapper matchedClass = class_resp 2008/08/13 13:52:19.768| ICAPAccessCheckCallbackEvent 2008/08/13 13:52:19.768| ICAPAccessCheck::do_callback 2008/08/13 13:52:19.768| ICAPAccessCheck::do_callback matchedClass = class_resp 2008/08/13 13:52:19.768| ICAP/ICAPConfig.cc(277) looking for the first matching up service in class class_resp 2008/08/13 13:52:19.768| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no Transfer-Preview extensions 2008/08/13 13:52:19.769| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no Transfer-Complete extensions 2008/08/13 13:52:19.769| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no Transfer-Ignore extensions 2008/08/13 13:52:19.769| ICAPOptions url /?l=squid-dev&r=1&w=2 matches no extensions; using default: Transfer-Complete 2008/08/13 13:52:19.769| ICAP/ICAPConfig.cc(315) found first matching up service in class class_resp: service_resp 2008/08/13 13:52:19.769| ICAP/ICAPConfig.cc(262) do_callback: with service icap://127.0.0.1:1344/respmod 2008/08/13 13:52:19.769| Server.cc(414) will send virgin reply body to 0x85e0fd0*2; size: -1 2008/08/13 13:52:19.769| ICAP/AsyncJob.cc(14) will call AsyncJob::noteStart(0x85b42bc) 2008/08/13 13:52:19.780| entering AsyncJob::noteStart(0x85b42bc) 2008/08/13 13:52:19.780| ICAPModXactLauncher::noteStart called 2008/08/13 13:52:19.780| ICAP/ICAPLauncher.cc(35) launching xaction #1 2008/08/13 13:52:19.780| ICAPModXact constructed, this=0x85b8358 [icapx39] 2008/08/13 13:52:19.781| ICAPModXact initialized. [R/ icapx39] 2008/08/13 13:52:19.781| ICAP/AsyncJob.cc(14) will call AsyncJob::noteStart(0x85b8358) 2008/08/13 13:52:19.781| ICAPModXactLauncher::noteStart ended 2008/08/13 13:52:19.781| exiting AsyncJob::noteStart(0x85b42bc) 2008/08/13 13:52:19.792| entering AsyncJob::noteStart(0x85b8358) 2008/08/13 13:52:19.792| ICAPModXact::noteStart called [R/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact expects virgin body from 0x85e0fd0*4; size: -1 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(1232) preview disabled by squid.conf 2008/08/13 13:52:19.793| ICAPModXact becomes final [Rw(1)/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact remains final [Rw(1)/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact opens connection to 127.0.0.1:1344 2008/08/13 13:52:19.793| ICAPModXact::noteStart ended [FD 16;Rrw(1)/ icapx39] 2008/08/13 13:52:19.793| exiting AsyncJob::noteStart(0x85b8358) 2008/08/13 13:52:19.793| ICAPModXact::noteCommConnected called [FD 16;Rrw(1)/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact ICAP will write [FD 16r;Rrw(1)/ icapx39]: RESPMOD icap://127.0.0.1:1344/respmod ICAP/1.0 Host: 127.0.0.1:1344 Date: Wed, 13 Aug 2008 06:52:19 GMT Encapsulated: req-hdr=0, res-hdr=456, res-body=659 X-Client-IP: 167.205.34.163 GET http://marc.info/?l=squid-dev&r=1&w=2 HTTP/1.1 Host: marc.info User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.1) Gecko/20061204 Firefox/2.0.0.1 Accept: application/x-shockwave-flash,text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/plain;q=0.8,image/png,*/*;q=0.5 Accept-Language: en-us,en;q=0.5 Accept-Encoding: gzip,deflate Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Proxy-Connection: keep-alive HTTP/1.1 200 OK Date: Wed, 13 Aug 2008 06:52:29 GMT Server: Apache Last-Modified: Wed Aug 13 06:52:29 2008 Expires: Wed Aug 13 07:52:29 2008 Cache-Control: max-age=3600 Content-Type: text/html; 2008/08/13 13:52:19.793| ICAPModXact::noteCommConnected ended [FD 16wr;Rrw(2)/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact::noteMoreBodyDataAvailable called [FD 16wr;Rrw(2)/ icapx39] 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(182) checking whether to write more [FD 16wr;Rrw(2)/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact::noteMoreBodyDataAvailable ended [FD 16wr;Rrw(2)/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact::noteCommWrote called [FD 16wr;Rrw(2)/ icapx39] 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(154) Wrote 849 bytes 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(182) checking whether to write more [FD 16r;Rrw(5)/ icapx39] 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(260) will write up to 276 bytes of prime virgin body 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(271) will write 276-byte chunk of prime virgin body 2008/08/13 13:52:19.793| consumption guards: 00 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(383) max virgin consumption offset=276 acts 10 consumed=0 from [0<=276<=? 276+1771 pipe0x85e0fd0 prod0x85dce14 cons0x85b83b4] 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(395) consuming 276 out of 276 virgin body bytes 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(296) will write 283 raw bytes of prime virgin body 2008/08/13 13:52:19.793| ICAPModXact::noteCommWrote ended [FD 16wr;Rrw(5)/ icapx39] 2008/08/13 13:52:19.793| ICAPModXact::noteCommWrote called [FD 16wr;Rrw(5)/ icapx39] 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(154) Wrote 283 bytes 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(182) checking whether to write more [FD 16r;Rrw(5)/ icapx39] 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(260) will write up to 0 bytes of prime virgin body 2008/08/13 13:52:19.793| ICAPModXact has no writable prime virgin body content 2008/08/13 13:52:19.793| ICAP/ICAPModXact.cc(296) will write 0 raw bytes of prime virgin body 2008/08/13 13:52:19.793| ICAPModXact::noteCommWrote ended [FD 16r;Rrw(5)/ icapx39] ******************************************************** And the log from ICAP-server is like the following: ******************************************************** Aug 13, 2008 1:52:19 PM [Thread-32] FINE: Received HTTP response headers ........... Aug 13, 2008 2:07:19 PM [Thread-32] FINE: releasing 15 ******************************************************** I see that the ICAP server didn't receive the http body from Squid. Is it a problem in Squid or not? And i noticed too that the HTTP response header from the website didn't contain "Content-length" header. Can it be a problem? Thanks for the reply.
Might be a problem. Retry with current Squid. If the problem persists, file a bug report with new data. Amos -- Please use Squid 2.7.STABLE3 or 3.0.STABLE8
