On Wed, 2007-02-14 at 21:17 +0200, Tsantilas Christos wrote: > Hi Alex, > I try some test's. It is not so bad, but I saw that there are problems. > After surfing the web for a while the icap-client of squid failed and > the squid returned an error page to the web browser (ICAP protocoll > error .... ICAP server is not reachable ......) > The icap client sends an respmod request with preview data and after > the the server responds with 100 Continue the squid closes the connection. > I have the same error on some sites (e.g freshmeat.net) using c-icap > icap server. I compiled squid using gcc 4.1.2. > I did not have enough time to look more on it. I will try to find time > next days for tests and debuging.....
Nice logs, thank you. It looks like Squid is sending a 43 byte preview of a 43 byte body and does not expect 100 Continue because there is nothing to continue with. I suspect Squid should have sent ieof but I need to read the RFC and to think about it. We can also make Squid more robust and send a last-chunk even if the ICAP server should not have sent 100 Continue. Thank you, Alex. > My squid logs are: > 2007/02/14 20:21:19.587| ICAPModXact should offer 43-byte preview > (service wanted 1024) > 2007/02/14 20:21:19.587| ICAPModXact ICAP will write [FD > 13r;Rrw(1)P(43)B/ icapx338]: > RESPMOD icap://192.168.1.4:1344/srv_clamav ICAP/1.0 > Host: 192.168.1.4:1344 > Date: Wed, 14 Feb 2007 18:21:19 GMT > Encapsulated: req-hdr=0, res-hdr=597, res-body=821 > Preview: 43 > Allow: 204 > > GET > http://ads.in.gr/adlog.php?bannerid=815&clientid=224&zoneid=119&source=251&block=0&capping=0&cb=993fc456072f1bc18ea9ab8de58b1da9 > HTTP/1.1 > Host: ads.in.gr > User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1) > Gecko/20061023 SUSE/2.0-30 Firefox/2.0 > Accept: image/png,*/*;q=0.5 > Accept-Language: el,en-us;q=0.7,en;q=0.3 > Accept-Encoding: gzip,deflate > Accept-Charset: ISO-8859-7,utf-8;q=0.7,*;q=0.7 > Keep-Alive: 300 > Proxy-Connection: keep-alive > Referer: http://www.in.gr/news/category.asp?lngDtrID=251 > Via: 1.0 fortune.home.chtsanti.net (C-ICAP/120207 Clamav/Antivirus service ) > > HTTP/1.1 200 OK > Date: Wed, 14 Feb 2007 18:19:51 GMT > Server: Apache > X-Powered-By: PHP/4.4.4 > Pragma: no-cache > Cache-Control: private, max-age=0, no-cache > Content-Length: 43 > Connection: close > Content-Type: image/gif > > > 2007/02/14 20:21:19.587| ICAPModXact::noteCommConnected ended [FD > 13wr;Rrw(2)P(43)B/ icapx338] > 2007/02/14 20:21:19.588| ICAPModXact::noteCommWrote called [FD > 13wr;Rrw(2)P(43)B/ icapx338] > 2007/02/14 20:21:19.588| ICAP/ICAPModXact.cc(149) Wrote 1014 bytes > 2007/02/14 20:21:19.588| ICAP/ICAPModXact.cc(177) checking whether to > write more [FD 13r;Rrw(3)P(43)B/ icapx338] > 2007/02/14 20:21:19.588| ICAP/ICAPModXact.cc(216) will write Preview > body from 0x8525f40*2 [FD 13r;Rrw(3)P(43)B/ icapx338] > 2007/02/14 20:21:19.588| ICAP/ICAPModXact.cc(255) will write up to 43 > bytes of preview body > 2007/02/14 20:21:19.588| ICAP/ICAPModXact.cc(266) will write 43-byte > chunk of preview body > 2007/02/14 20:21:19.588| ICAP/ICAPModXact.cc(278) will write last-chunk > of preview body > 2007/02/14 20:21:19.588| ICAP/ICAPModXact.cc(283) will write 54 raw > bytes of preview body > 2007/02/14 20:21:19.588| ICAPModXact wrote entire Preview body [FD > 13wr;Rrw(3)B/P icapx338] > 2007/02/14 20:21:19.588| ICAPModXact::noteCommWrote ended [FD > 13wr;Rrw(4)B/P icapx338] > 2007/02/14 20:21:19.588| ICAPModXact::noteCommWrote called [FD > 13wr;Rrw(4)B/P icapx338] > 2007/02/14 20:21:19.589| ICAP/ICAPModXact.cc(149) Wrote 54 bytes > 2007/02/14 20:21:19.589| ICAP/ICAPModXact.cc(177) checking whether to > write more [FD 13r;Rrw(4)B/P icapx338] > 2007/02/14 20:21:19.589| ICAPModXact::noteCommWrote ended [FD > 13r;Rrw(4)B/P icapx338] > 2007/02/14 20:21:19.599| ICAP/ICAPXaction.cc(58) 0x84d8ac8 read returned 25 > 2007/02/14 20:21:19.599| ICAPModXact::noteCommRead called [FD > 13r;Rrw(4)B/P icapx338] > 2007/02/14 20:21:19.599| ICAP/ICAPXaction.cc(328) read 25 bytes > 2007/02/14 20:21:19.599| ICAP/ICAPModXact.cc(548) have 25 bytes to parse > [FD 13;Rrw(4)B/P icapx338] > 2007/02/14 20:21:19.599| ICAP/ICAPModXact.cc(549) > ICAP/1.0 100 Continue > > > 2007/02/14 20:21:19.599| ICAP/ICAPModXact.cc(577) parse ICAP headers > 2007/02/14 20:21:19.599| ICAP/ICAPModXact.cc(780) have 25 head bytes to > parse; state: 0 > 2007/02/14 20:21:19.600| HttpMsg::parse success (25 bytes) near > 'ICAP/1.0 100 Continue > > ' > 2007/02/14 20:21:19.600| ICAP/ICAPModXact.cc(792) parse success, consume > 25 bytes, return true > 2007/02/14 20:21:19.600| ICAP/ICAPModXact.cc(177) checking whether to > write more [FD 13;Rrw(5)B/P icapx338] > 2007/02/14 20:21:19.600| ICAPModXact::noteCommRead caught an exception: > virginWriteClaim.active() [FD 13;Rrw(5)B/P icapx338] > 2007/02/14 20:21:19.600| ICAPModXact will stop, reason: exception > 2007/02/14 20:21:19.600| ICAPModXact::noteCommRead ends xaction [FD > 13;Rrw(5)B/StoppedP icapx338] > 2007/02/14 20:21:19.600| ICAP/ICAPModXact.cc(943) swan sings [FD > 13;Rrw(5)B/StoppedP icapx338] > 2007/02/14 20:21:19.600| ICAP/ICAPModXact.cc(946) swan sings for > exception [FD 13;Rrw(5)B/StoppedP icapx338] > 2007/02/14 20:21:19.600| ICAP/ICAPModXact.cc(947) will call > ICAPInitiator::noteIcapHeadersAborted(0x8521d10) > 2007/02/14 20:21:19.600| ICAP/ICAPModXact.cc(412) will no longer write > [FD 13;Rrw(5)B/StoppedP icapx338] > 2007/02/14 20:21:19.601| ICAPModXact will no longer backup [FD > 13;RrB/StoppedwP icapx338] > 2007/02/14 20:21:19.601| ICAP/ICAPModXact.cc(376) consuming 43 out of 43 > virgin body bytes > 2007/02/14 20:21:19.601| ICAPModXact will not start sending [FD > 13;Rr/StoppedwP icapx338] > 2007/02/14 20:21:19.601| ICAP/ICAPModXact.cc(541) will stop consuming > [FD 13;Rr/StoppedwPS icapx338] > 2007/02/14 20:21:19.601| ICAP/ICAPXaction.cc(174) closing pconn [FD > 13;r/StoppedRwPS icapx338] > 2007/02/14 20:21:19.601| ICAP/ICAPXaction.cc(429) swan sang > [/StoppedRwPS icapx338] > 2007/02/14 20:21:19.601| ICAP/ICAPXaction.cc(489) > ICAPModXact::noteCommRead ended 0x84d8ac8 > 2007/02/14 20:21:19.623| entering > ICAPInitiator::noteIcapHeadersAborted(0x8521d10) > 2007/02/14 20:21:19.624| ICAPModXact destructed, this=0x84d8ac8 [icapx338] > 2007/02/14 20:21:19.624| Server.cc(464) handleIcapAborted; entry empty: 1 > 2007/02/14 20:21:19.624| Server.cc(470) creating ICAP error entry after > ICAP failure > 2007/02/14 20:21:19.624| Server.cc(478) bailing after ICAP failure > 2007/02/14 20:21:19.624| Server.cc(333) cleaning ICAP > 2007/02/14 20:21:19.624| http.cc(1302) closing HTTP server FD -1 this > 0x8521d10 > 2007/02/14 20:21:19.624| Server.cc(112) transaction done > 2007/02/14 20:21:19.624| http.cc(151) HttpStateData 0x8521d10 destroyed; > FD -1 > 2007/02/14 20:21:19.625| Server.cc(333) cleaning ICAP > 2007/02/14 20:21:19.625| exiting > ICAPInitiator::noteIcapHeadersAborted(0x8521d10) > ............................... >