Re: [squid-dev] is this really an ICAP 206 response "protocol error", if so what?
On 11/12/2015 05:27 PM, Eliezer Croitoru wrote:
> What I have found is an exception in the logs which results in
> "ICAP_ERR_OTHER" but I am unable to understand what the issue is.
>
> The lines from the log are:
> 2015/11/13 01:47:22.072 kid1| 0,3| TextException.cc(87) Throw:
> ModXact.cc:918: exception: state.allowedPostview206
The code on that line is pretty clear IMO:
> void Adaptation::Icap::ModXact::handle206PartialContent()
> {
> if (state.writing == State::writingPaused) {
> Must(preview.enabled());
> Must(state.allowedPreview206);
> debugs(93, 7, HERE << "206 inside preview");
> } else {
> Must(state.writing > State::writingPaused);
> Must(state.allowedPostview206);
> debugs(93, 7, HERE << "206 outside preview");
> }
The state.allowedPostview206 exception means that Squid thinks that the
following are all true:
1. Squid received ICAP 206 response;
2. Squid received a response outside of Preview; and
3. Squid did _not_ allow 206 outside of Preview.
You need to figure out which of those three assumptions are false.
If you start digging around, you may eventually find that Squid did not
allow your service to send a 206 response in the first place:
> RESPMOD icap://127.0.0.2:1344/allow_cache ICAP/1.0
> Encapsulated: req-hdr=0, res-hdr=144, null-body=444
> Allow: 204
but your service did anyway:
> ICAP/1.0 206 Partial Content
> Encapsulated: res-hdr=0, res-body=331
There are other problems with your service response. For example, it
tells Squid to use a body (use-original-body=0) that Squid said does not
exist (null-body).
As I have mentioned before, writing a high-quality ICAP service is more
difficult than it may seem. Correctly handling 206 transactions is even
more so.
As a consolation prize, consider reproducing and filing a bug report
against Squid as well: AFAICT, the state.writing == State::writingPaused
condition in handle206PartialContent() is wrong because when there is no
HTTP message body at all, Squid may be in Preview state (from the ICAP
point of view), but state.writing will not be State::writingPaused. It
will be State::writingReallyDone AFAICT. Your logs seem to confirm that.
HTH,
Alex.
P.S. Please do not use .gz extension for bzip2-compressed files.
___
squid-dev mailing list
squid-dev@lists.squid-cache.org
http://lists.squid-cache.org/listinfo/squid-dev
Re: [squid-dev] is this really an ICAP 206 response "protocol error", if so what?
I have tried to do something that horrified me for a very long time "looking at a ALL,9 debug!". What I have found is an exception in the logs which results in "ICAP_ERR_OTHER" but I am unable to understand what the issue is. The lines from the log are: 2015/11/13 01:47:22.072 kid1| 0,3| TextException.cc(87) Throw: ModXact.cc:918: exception: state.allowedPostview206 2015/11/13 01:47:22.072 kid1| 93,3| ../../../src/base/AsyncJobCalls.h(177) dial: Adaptation::Icap::Xaction::noteCommRead threw exception: state.allowedPostview206 2015/11/13 01:47:22.072 kid1| 45,9| cbdata.cc(492) cbdataReferenceValid: 0x8640ea8 2015/11/13 01:47:22.072 kid1| 11,5| HttpRequest.cc(474) detailError: current error details: 35/396407110 2015/11/13 01:47:22.072 kid1| 93,4| Xaction.cc(514) setOutcome: ICAP_ERR_OTHER 2015/11/13 01:47:22.072 kid1| 93,4| ServiceRep.cc(80) noteFailure: failure 1 out of 10 allowed in 0sec [up,fail1] And the full cache.log is at: http://ngtech.co.il/squid/icap_206_error/cache_debug_all_9.log or compressed at: http://ngtech.co.il/squid/icap_206_error/cache_debug_all_9.tar.gz I am unsure what caused the issue from squid point of view. Thanks, Eliezer On 13/11/2015 01:38, Alex Rousskov wrote: On 11/12/2015 04:09 PM, Eliezer Croitoru wrote: I have been experimenting with ICAP and 206 response. ... I have couple special cases which result in a "protocol error" but nothing more then that. Since you can reproduce this error, you should be able to tell where Squid detects a "protocol error". Knowing that place may help you (or others) fix Squid, 206 specs, and/or your ICAP service. I have attached two wireshark dumps which one works while the other result in a protocol error. FWIW, I do not see anything obviously wrong in those dumps. Cheers, Alex. ___ squid-dev mailing list squid-dev@lists.squid-cache.org http://lists.squid-cache.org/listinfo/squid-dev
Re: [squid-dev] is this really an ICAP 206 response "protocol error", if so what?
OK now I get the issue I was having trouble with!!
I didn't captured\filtered\analyzed the right tcpdump!!!
It is indeed my bad!!
It seems like I need to add couple more tests to the service when it
handles some more complex cases such as when there is a null body and
the allowed method.
Thanks!!!
Eliezer
* sorry for the bzip2 file, z\j confusion, I fixed it and added the icap
dump which shows the issue at:
http://ngtech.co.il/squid/icap_206_error/icap-206-14.pcap
* I will try to write the bug
* This ICAP service was kind of a hobby coding project to override the
content caching ability. This code actually will help to write a StoreID
ICAP enabled service.
On 13/11/2015 03:54, Alex Rousskov wrote:
On 11/12/2015 05:27 PM, Eliezer Croitoru wrote:
What I have found is an exception in the logs which results in
"ICAP_ERR_OTHER" but I am unable to understand what the issue is.
The lines from the log are:
2015/11/13 01:47:22.072 kid1| 0,3| TextException.cc(87) Throw:
ModXact.cc:918: exception: state.allowedPostview206
The code on that line is pretty clear IMO:
void Adaptation::Icap::ModXact::handle206PartialContent()
{
if (state.writing == State::writingPaused) {
Must(preview.enabled());
Must(state.allowedPreview206);
debugs(93, 7, HERE << "206 inside preview");
} else {
Must(state.writing > State::writingPaused);
Must(state.allowedPostview206);
debugs(93, 7, HERE << "206 outside preview");
}
The state.allowedPostview206 exception means that Squid thinks that the
following are all true:
1. Squid received ICAP 206 response;
2. Squid received a response outside of Preview; and
3. Squid did _not_ allow 206 outside of Preview.
You need to figure out which of those three assumptions are false.
If you start digging around, you may eventually find that Squid did not
allow your service to send a 206 response in the first place:
RESPMOD icap://127.0.0.2:1344/allow_cache ICAP/1.0
Encapsulated: req-hdr=0, res-hdr=144, null-body=444
Allow: 204
but your service did anyway:
ICAP/1.0 206 Partial Content
Encapsulated: res-hdr=0, res-body=331
There are other problems with your service response. For example, it
tells Squid to use a body (use-original-body=0) that Squid said does not
exist (null-body).
As I have mentioned before, writing a high-quality ICAP service is more
difficult than it may seem. Correctly handling 206 transactions is even
more so.
As a consolation prize, consider reproducing and filing a bug report
against Squid as well: AFAICT, the state.writing == State::writingPaused
condition in handle206PartialContent() is wrong because when there is no
HTTP message body at all, Squid may be in Preview state (from the ICAP
point of view), but state.writing will not be State::writingPaused. It
will be State::writingReallyDone AFAICT. Your logs seem to confirm that.
HTH,
Alex.
P.S. Please do not use .gz extension for bzip2-compressed files.
___
squid-dev mailing list
squid-dev@lists.squid-cache.org
http://lists.squid-cache.org/listinfo/squid-dev
