On Wed, 2007-02-14 at 13:19 -0700, Alex Rousskov wrote: > 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.
My suspicion was correct. The untested fix has been committed to squid3-icap. Squid should now append ieof extension to the last chunk whenever Preview contains the entire body. Please try again. 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) > > ............................... > >