Squid-ICAP 2.6
Hello, I would like to give a try to the 2.6 branch of the ICAP patch and I didn't manage to apply the patch available at: http://devel.squid-cache.org/projects.html#icap I tried on squid-2.6.STABLE9-20070220, squid-2.6.STABLE9 and squid-2.6.STABLE8 without success. Is there anywhere: - an history if the icap patch ? - a changelog - a documentation explaining on which squid version an icap patch apply ? Regards, Christophe.
Re: Squid-ICAP 2.6
Bonjour Jeremy, Here is the answer I got, and I managed to patch squid correctly thanks to it: http://www.squid-cache.org/mail-archive/squid-users/200702/0143.html Would you have a corrected patch ? Because I am applying manually and it is a bit long and not obvious to not make a mistake. Christophe.
Re: Squid-ICAP problem (bug?)
Hi all,
Tsantilas Christos wrote :
If you are still looking for the solution, try the following patch in
icap_reqmod.c file. With this patch the icapReqModPassHttpBody function
called if the icap-reqmod.http_entity.buf.size is zero, and at this
phase can handle correctly, the case that the
icap-flags.reqmod_http_entity_eof==1.
Unfortunately it still segfaults.
But, I had time to work on my client's test platform and I spent a whole
day hacking icap_reqmod.c.
The only modification (except adding excessive debug logging) is that one:
in icapReqModReadHttpBody function replacing the test
if (icap-reqmod.http_entity.bytes_read = icap-request-content_length)
by
if (icap-chunk_size 0)
which correct the initial problem ie not reading the 0\r\n marking thee
end of the chunk.
The new problem is that squid correctly reads the end of the chunk but
dies immediatly.
The dying occurs in the icapReqModPassHttpBody function and I spent many
time to find why. In fact I focussed on the call of this function from
the icapReqModReadHttpBody function and I didn't manage to find the
logic of the test and the function parameters (because I don't know well
the squid and icap patch code).
Anyway this I found that the function was called with icap = 0 parameter
(I spent too more time to search a buf=0 or callback=0); so I added a
simple test in the beginning of the function:
static void
icapReqModPassHttpBody(IcapStateData * icap, char *buf, size_t size,
CBCB * callback, void *cbdata)
{
debug(81, 3) (%s:%d: icapReqModPassHttpBody: called\n, __FILE__,
__LINE__);
if (!icap) {
debug(81, 1) (%s:%d: icapReqModPassHttpBody: FD %d called with
icap = (nil) !\n, __FILE__, __LINE__);
return;
}
I added this to prevent segfaulting but without knowing if the return
would lead to a correct behaviour. And it seems that is is ok. We made
some tests and we did not have any more segfaults.
I then tried with gdb (I should have used it before but I am not
familiar with it) to get a backtrace as you asked in a previous mail and
I saw that the icapReqModPassHttpBody call with icap=0 is not called
from the icapReqModReadHttpBody:
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread -1218496992 (LWP 9508)]
0x08087411 in icapReqModPassHttpBody (icap=0x0, buf=0x0,
size=4294967295, callback=0, cbdata=0x8c95e00) at icap_reqmod.c:933
933 icap_reqmod.c: Aucun fichier ou repertoire de ce type.
in icap_reqmod.c
(gdb) bt
#0 0x08087411 in icapReqModPassHttpBody (icap=0x0, buf=0x0,
size=4294967295, callback=0, cbdata=0x8c95e00) at icap_reqmod.c:933
#1 0x08083905 in requestAbortBody (request=0x8c94578) at HttpRequest.c:215
#2 0x0807a183 in httpStateFree (fd=9, data=0x8cc72a0) at http.c:69
#3 0x08065ccd in commCallCloseHandlers (fd=44) at comm.c:573
#4 0x08065dec in comm_close (fd=44) at comm.c:655
#5 0x0807b32c in httpReadReply (fd=44, data=0x8cc72a0) at http.c:852
#6 0x08067749 in comm_poll (msec=13) at comm_select.c:445
#7 0x0808fc77 in main (argc=4, argv=0xbfff9494) at main.c:754
Here is a sumup of the logs when icap value is tested and squid does not
segfault anymore:
2006/12/01 18:18:19| icapReqModParseHttpRequest: successfully parsed the
HTTP request
2006/12/01 18:18:19| handing request bodies in ICAP REQMOD
2006/12/01 18:18:19| icap_reqmod.c:859: icapReqModReadHttpBody: FD 53 called
2006/12/01 18:18:19| icap_reqmod.c:861: icapReqModReadHttpBody: read
returns 33
2006/12/01 18:18:19| icap_reqmod.c:872: icapReqModReadHttpBody: Before
icapParseChunkedBody bytes_read = 0
2006/12/01 18:18:19| icap_common.c:695: chunk_size=0
2006/12/01 18:18:19| icap_common.c:702: bufOffset=0, len=33
2006/12/01 18:18:19| icap_common.c:705: bufOffset=0, len=33
2006/12/01 18:18:19| icap_common.c:604: icapParseChunkSize:
buf=0x8ccd1b8, len=33
2006/12/01 18:18:19| icap_common.c:607: icapParseChunkSize: start=0
2006/12/01 18:18:19| icapLineLength: returning 4
2006/12/01 18:18:19| icap_common.c:646: icapParseChunkSize: start=0, end=2
2006/12/01 18:18:19| icap_common.c:672: icapParseChunkSize: return
nextStart=4
2006/12/01 18:18:19| icap_common.c:716: got chunksize 27, new offset 4
2006/12/01 18:18:19| icap_common.c:723: X
2006/12/01 18:18:19| icap_common.c:705: bufOffset=31, len=33
2006/12/01 18:18:19| icap_common.c:604: icapParseChunkSize:
buf=0x8ccd1d7, len=2
2006/12/01 18:18:19| icap_common.c:607: icapParseChunkSize: start=0
2006/12/01 18:18:19| icapLineLength: returning 2
2006/12/01 18:18:19| icap_common.c:607: icapParseChunkSize: start=2
2006/12/01 18:18:19| icap_reqmod.c:876: icapReqModReadHttpBody: After
icapParseChunkedBody bytes_read = 27
2006/12/01 18:18:19| icap_reqmod.c:884 icapReqModReadHttpBody: chunk_size=0
Here is the first modification: even if we read the 27 bytes of the body
we continue reading because chunk_size is not -2:
2006/12/01 18:18:19| icap_reqmod.c:892 icapReqModReadHttpBody: call
commSetSelect -
Re: Squid-ICAP problem (bug?)
Tsantilas Christos a e'crit :
Hello Christos,
Maybe I was not clear on my last mail. Sorry.
You were but I forgot to mention that I tried what you adviced.
But in the same function replace the test:
if (icap-reqmod.http_entity.callback
icap-reqmod.http_entity.buf.size) {
icapReqModPassHttpBody(icap,
icap-reqmod.http_entity.callback_buf,
icap-reqmod.http_entity.callback_bufsize,
with:
if (icap-reqmod.http_entity.callback) {
icapReqModPassHttpBody(icap,
icap-reqmod.http_entity.callback_buf,
icap-reqmod.http_entity.callback_bufsize,
Did you try it?
Yes we tried it and this leads to segfault too.
and we exit the icapReqModReadHttpBody function without calling
icapReqModPassHttpBody because http_entity.buf.size is 0.
With the previous change this function must called here.
Did you make this change? Are you still seeing segfaults?
I did not test extensively but it seems that calling
icapReqModPassHttpBody without testing if http_entity.buf.size is 0 will
work in this very specific case (when end chunk is read in an extra
pass) but will lead to segfault in cases which used to work perfectly
before changing this test.
In my tests I am not seeing any problem any more. But maybe I am losing
something
I don't have any magic recipe to reproduce the problem but it occurs
when parsing the request's body in REQMOD and that occurs generally when
doint a POST request (as there is no body in a GET request).
With your modification, we ends with segfaults during GET request !
By reading the log I just noticed that with your modification the
icapReqModPassHttpBody is not called:
This is for the specific request (POST):
2006/11/24 14:15:22| handing request bodies in ICAP REQMOD
2006/11/24 14:15:22| icapReqModReadHttpBody: FD 38 called
2006/11/24 14:15:22| icapReqModReadHttpBody: read returns 33
2006/11/24 14:15:22| icap_common.c:695: chunk_size=0
2006/11/24 14:15:22| icap_common.c:702: bufOffset=0, len=33
2006/11/24 14:15:22| icap_common.c:705: bufOffset=0, len=33
2006/11/24 14:15:22| icapParseChunkSize: buf=0x997fbe0, len=33
2006/11/24 14:15:22| icapParseChunkSize: start=0
2006/11/24 14:15:22| icapLineLength: returning 4
2006/11/24 14:15:22| icapParseChunkSize: start=0, end=2
2006/11/24 14:15:22| icapParseChunkSize: return nextStart=4
2006/11/24 14:15:22| got chunksize 27, new offset 4
2006/11/24 14:15:22| icap_common.c:723: X
2006/11/24 14:15:22| icap_common.c:705: bufOffset=31, len=33
2006/11/24 14:15:22| icapParseChunkSize: buf=0x997fbff, len=2
2006/11/24 14:15:22| icapParseChunkSize: start=0
2006/11/24 14:15:22| icapLineLength: returning 2
2006/11/24 14:15:22| icapParseChunkSize: start=2
2006/11/24 14:15:22| icap_reqmod.c:882 chunk_size=0
2006/11/24 14:15:22| icap_reqmod.c:892 http_entity.callback=(nil)
2006/11/24 14:15:22| icap_reqmod.c:894 http_entity.buf.size=27
2006/11/24 14:15:22| icap_reqmod.c:896 http_entity.callback_bufsize=0
2006/11/24 14:15:22| icapReqModReadHttpBody: FD 38 called
2006/11/24 14:15:22| icapReqModReadHttpBody: read returns 5
2006/11/24 14:15:22| icap_common.c:695: chunk_size=0
2006/11/24 14:15:22| icap_common.c:702: bufOffset=0, len=7
2006/11/24 14:15:22| icap_common.c:705: bufOffset=0, len=7
2006/11/24 14:15:22| icapParseChunkSize: buf=0x997fbe0, len=7
2006/11/24 14:15:22| icapParseChunkSize: start=0
2006/11/24 14:15:22| icapLineLength: returning 2
2006/11/24 14:15:22| icapParseChunkSize: start=2
2006/11/24 14:15:22| icapLineLength: returning 3
2006/11/24 14:15:22| icapParseChunkSize: start=2, end=3
2006/11/24 14:15:22| icapParseChunkSize: return nextStart=5
2006/11/24 14:15:22| got chunksize -2, new offset 5
2006/11/24 14:15:22| zero end chunk reached
2006/11/24 14:15:22| icap_reqmod.c:882 chunk_size=-2
2006/11/24 14:15:22| icap_reqmod.c:892 http_entity.callback=(nil)
2006/11/24 14:15:22| icap_reqmod.c:894 http_entity.buf.size=27
2006/11/24 14:15:22| icap_reqmod.c:896 http_entity.callback_bufsize=0
2006/11/24 14:15:22| icapSendRespMod: Create a new connection to icap
server service_4/icap://xx.xx.xx.xx:1344/wwrespmod/?wwprofile=HTTP_
But what is very strange is:
- respmod seems not to be called;
- the next request which is a GET is handled strangely:
2006/11/24 14:15:34| icapParseEncapsulated: res-hdr=-1, req-hdr=0,
null-body=791, res-body=-1, req-body=-1, opt-body=-1
2006/11/24 14:15:34| icapReqModReadIcapPart: directResponse=0 from ICAP
server service_3/icap://xx.xx.xx.xx:1344/wwreqmod/?wwprofile=HTTP_
2006/11/24 14:15:34| icapReqModReadHttpHdrs:
2006/11/24 14:15:34| expect=791
2006/11/24 14:15:34| so_far=0
2006/11/24 14:15:34| needed=791
2006/11/24 14:15:34| icapReqModReadHttpHdrs: read 791 bytes
2006/11/24 14:15:34| icapReqModReadHttpHdrs: read the entire request headers
2006/11/24 14:15:34| icapReqModParseHttpRequest: URI is
'http://x.xxx/rtn_FR.gif'
2006/11/24 14:15:34| icapReqModParseHttpRequest: Client HTTP version 1.1.
2006/11/24 14:15:34|
Re: Squid-ICAP problem (bug?)
Hello,
Thanks for you support.
I tried the patch from Tsantilas:
if (icap-chunk_size 0)
icap-flags.reqmod_http_entity_eof = 1;
instead of:
if (icap-reqmod.http_entity.bytes_read = icap-request-content_length)
icap-flags.reqmod_http_entity_eof = 1;
And that corrects the initial problem: remaining data waiting on the
wire is read (\r\n0\r\n).
But there is a new problem.
After the conditionnal call to commSetSelect there is a conditionnal
call to icapReqModPassHttpBody and this where is the problem:
if (icap-reqmod.http_entity.callback
icap-reqmod.http_entity.buf.size) {
icapReqModPassHttpBody(icap,
icap-reqmod.http_entity.callback_buf,
icap-reqmod.http_entity.callback_bufsize,
icap-reqmod.http_entity.callback,
icap-reqmod.http_entity.callback_data);
icap-reqmod.http_entity.callback = NULL;
cbdataUnlock(icap-reqmod.http_entity.callback_data);
}
When calling this function, the test is on
icap-reqmod.http_entity.buf.size but the parameter sent to the function
is cap-reqmod.http_entity.callback_bufsize. Is it normal ?
I added some logs and here is the output:
2006/11/14 13:43:25| icapReqModReadHttpBody: FD 38 called
2006/11/14 13:43:25| icapReqModReadHttpBody: read returns 33
2006/11/14 13:43:25| icap_common.c:695: chunk_size=0
2006/11/14 13:43:25| icap_common.c:702: bufOffset=0, len=33
2006/11/14 13:43:25| icap_common.c:705: bufOffset=0, len=33
2006/11/14 13:43:25| icapParseChunkSize: buf=0x9e362d0, len=33
2006/11/14 13:43:25| icapParseChunkSize: start=0
2006/11/14 13:43:25| icapLineLength: returning 4
2006/11/14 13:43:25| icapParseChunkSize: start=0, end=2
2006/11/14 13:43:25| icapParseChunkSize: return nextStart=4
2006/11/14 13:43:25| got chunksize 27, new offset 4
2006/11/14 13:43:25| icap_common.c:723: X
2006/11/14 13:43:25| icap_common.c:705: bufOffset=31, len=33
2006/11/14 13:43:25| icapParseChunkSize: buf=0x9e362ef, len=2
2006/11/14 13:43:25| icapParseChunkSize: start=0
2006/11/14 13:43:25| icapLineLength: returning 2
2006/11/14 13:43:25| icapParseChunkSize: start=2
2006/11/14 13:43:25| icap_reqmod.c:882 chunk_size=0
2006/11/14 13:43:25| icap_reqmod.c:892 http_entity.callback=(nil)
2006/11/14 13:43:25| icap_reqmod.c:894 http_entity.buf.size=27
2006/11/14 13:43:25| icap_reqmod.c:896 http_entity.callback_bufsize=0
2006/11/14 13:43:25| icapService: type=ICAP_SERVICE_REQMOD_POSTCACHE
2006/11/14 13:43:25| icapService: checking service service_3/id=0
2006/11/14 13:43:25| icapService: checking service service_4/id=0
2006/11/14 13:43:25| icapService: no service found
2006/11/14 13:43:25| icapReqModPassHttpBody: called
2006/11/14 13:43:25| icapReqModPassHttpBody: entity buf size = 27
2006/11/14 13:43:25| icapReqModPassHttpBody: giving 27 bytes to other side
2006/11/14 13:43:25| icapReqModPassHttpBody: entity buf size now = 0
2006/11/14 13:43:25| icapReqModPassHttpBody: called
2006/11/14 13:43:25| icapReqModPassHttpBody: entity buf size = 0
2006/11/14 13:43:25| icapReqModReadHttpBody: FD 38 called
2006/11/14 13:43:25| icapReqModReadHttpBody: read returns 5
2006/11/14 13:43:25| icap_common.c:695: chunk_size=0
2006/11/14 13:43:25| icap_common.c:702: bufOffset=0, len=7
2006/11/14 13:43:25| icap_common.c:705: bufOffset=0, len=7
2006/11/14 13:43:25| icapParseChunkSize: buf=0x9e362d0, len=7
2006/11/14 13:43:25| icapParseChunkSize: start=0
2006/11/14 13:43:25| icapLineLength: returning 2
2006/11/14 13:43:25| icapParseChunkSize: start=2
2006/11/14 13:43:25| icapLineLength: returning 3
2006/11/14 13:43:25| icapParseChunkSize: start=2, end=3
2006/11/14 13:43:25| icapParseChunkSize: return nextStart=5
2006/11/14 13:43:25| got chunksize -2, new offset 5
2006/11/14 13:43:25| zero end chunk reached
2006/11/14 13:43:25| icap_reqmod.c:882 chunk_size=-2
2006/11/14 13:43:25| icap_reqmod.c:892 http_entity.callback=0x807c994
2006/11/14 13:43:25| icap_reqmod.c:894 http_entity.buf.size=0
2006/11/14 13:43:25| icap_reqmod.c:896 http_entity.callback_bufsize=8192
2006/11/14 13:43:25| icapReqModPassHttpBody: called
FATAL: Received Segment Violation...dying.
Perhaps there is a problem with parameters passed to
icapReqModPassHttpBody ?
Christophe.
Re: Squid-ICAP problem (bug?)
Henrik Nordstrom a écrit : We have read enough data (27 bytes) to have all the body (as content-length is 27), so we set the eof flag. if (!icap-flags.reqmod_http_entity_eof) commSetSelect(fd, COMM_SELECT_READ, icapReqModReadHttpBody, icap, 0); eof in ICAP is that 0 chunk... so something is not right here in the ICAP patch. The problem is that this 0\r\n arrives after the first read of the 27 first bytes. Note: As Adrian said most efforts is focused on the Squid-3 release, which also includes ICAP support. I understand that but the problem is that we have this bug in production on heavy loaded site (we took several weeks to find it out) and we have to correct it anyway (and I don't think think that targetting Squid3 is possible (I thought Squid3 was considered beta?)). Regards, Christophe.
Squid-ICAP problem (bug?)
contains \r\n left. So there is no more chunk size to read and the while loop stops (in the icapParseChunkedBody function in icap_commons.c): 2006/11/02 15:10:23| icap_reqmod.c:884 http_entity.callback=(nil) 2006/11/02 15:10:23| icap_reqmod.c:886 http_entity.buf.size=27 Here is the function icapReqModReadHttpBody (in icap_reqmod.c) which reads data from network: icap-reqmod.http_entity.bytes_read += icapParseChunkedBody(icap, icapReqModMemBufAppend, icap-reqmod.http_entity.buf); So, after the dechunkization of the body we have icap-reqmod.http_entity.bytes_read = 27 The second problem occurs there: if (icap-reqmod.http_entity.bytes_read = icap-request-content_length) icap-flags.reqmod_http_entity_eof = 1; We have read enough data (27 bytes) to have all the body (as content-length is 27), so we set the eof flag. if (!icap-flags.reqmod_http_entity_eof) commSetSelect(fd, COMM_SELECT_READ, icapReqModReadHttpBody, icap, 0); The eof flag is set so we do not read again data from webwasher althought there is still the \0\r\n data waiting on the wire ! So Squid goes on to another task (in this cas this is to call a respmod request): 2006/11/02 15:10:23| icapSendRespMod: Create a new connection to icap server service_4/icap://10.17.30.41:1344/wwrespmod/?wwprofile=HTTP_Sortante 2006/11/02 15:10:23| icapConnect: reused pconn FD 34 2006/11/02 15:10:23| icapConnectOver: FD 34, status=0 2006/11/02 15:10:23| icapSendRespMod: new connection to icap server (using FD=34) and sends the request to Webwasher: 2006/11/02 15:10:23| icapSendRespModDone: FD 34: size 2746: errflag 0. 2006/11/02 15:10:23| icapSendRespModDone: FD 34: commSetSelect on read icapRespModReadReply. and while waiting the respmod's request answer receives the end of the previous reqmod request: --- begin cut --- 0\r\n\r\n end cut 2006/11/02 15:10:23| recv(FD 34, ..., MSG_PEEK) ret 5 2006/11/02 15:10:23| headlen=5 2006/11/02 15:10:23| Parse icap header : 0 At this moment squid thinks that this is the response of the respmod request and throws an error: from ICAP server service_4/icap://10.17.30.41:1344/wwrespmod/?wwprofile=HTTP_Sortante 2006/11/02 15:10:23| BAD ICAP status line 0 from ICAP server service_4/icap://10.17.30.41:1344/wwrespmod/?wwprofile=HTTP_Sortante 2006/11/02 15:10:23| icapStateFree: FD 34, icap 0x8f8a5a8 I do not know if webwasher should send the last part of the chunk in a new stream, but on the squid-icap part it cannot work this way and I do not see an easy patch to correct this problem as the icapParseChunkedBody returns the correct length read ! The webwasher support sads this is a misinterpreation of the Squid client. What is your point of view ? Cordialement, Christophe Boyanique. -- http://www.alcove.fr - Alcôve: L'informatique est libre ! 15 avenue de l'Agent Sarre - 92700 Colombes Tél : +33 1 46 49 25 00 - Fax : +33 1 46 49 25 01
Introduction before mailing-list subscribing
Hello, I'm writing this message to introduce myself before subsbribing to this mailing-list. I am working for Alcove (http://www.alcove.fr) a french free software company. Amongst other subjects we propose support on any free software technology and we have some clients using Squid-ICAP and Webwasher. As we work with Squid and the Squid-ICAP patch i'd like to participate to this mailing-list to report bugs and patches to the community. Regards, Christophe.
