On 11/18/2009 08:22 AM, Silamael wrote:
On 11/18/2009 01:59 AM, Amos Jeffries wrote:
Maybe yes, maybe no....
What configuration are you referring too?
Is the ICAP server setting Content-Length correctly to the size of the
error page body?
Hello Amos,
As far as i can say, the Content-Length is set properly. I have some
simple test working as intended with an ancient Squid 2.5 + ICAP patch.
Configuration for ICAP is quite simple:
> icap_enable on
> icap_service icap_server reqmod_precache 0 icap://<some_ip>/
> adaption_service_set class_1 icap_server
> adaption_access class_1 allow all
In the debug output for ICAP i cannot see any errors or some hint that
the Content-Length in the response body is set wrong.
If needed i can provide the debugging output.
-- Matthias
Hello Amos,
I found out that my test creates an invalid Encapsulated header. After
fixing it, squid dies with an assertion failure in BodyPipe::undoCheckout().
Attached you find the cache.log of my test.
Greetings,
Matthias
starting 'build-i386/src/squid -f /var/tmp/t_23908/etc/squid/squid-127.0.0.1:18190.conf -N' DEBUGINC=
2009/11/23 09:15:16| WARNING cache_mem is larger than total disk cache space!
2009/11/23 09:15:16| Starting Squid Cache version 3.1.0.14 for i386-unknown-openbsd4.4...
2009/11/23 09:15:17.037| squid-3.1.0.14/src/adaptation/Config.cc(91) finalize: Found 1 service configs.
2009/11/23 09:15:17.037| AsyncJob of type Adaptation::Icap::ServiceRep constructed, this=0x839a7098 [async1]
2009/11/23 09:15:17.037| squid-3.1.0.14/src/adaptation/Service.cc(12) Service: creating adaptation service icap_server
2009/11/23 09:15:17.037| squid-3.1.0.14/src/adaptation/Config.cc(105) finalize: Created 1 message adaptation services.
2009/11/23 09:15:17.037| Adaptation support is on
2009/11/23 09:15:17.037| squid-3.1.0.14/src/adaptation/Config.cc(117) FinalizeEach: Initialized 1 message adaptation services
2009/11/23 09:15:17.037| squid-3.1.0.14/src/adaptation/ServiceGroups.cc(78) finalize: finalized adaptation set: class_1
2009/11/23 09:15:17.037| squid-3.1.0.14/src/adaptation/Config.cc(117) FinalizeEach: Initialized 1 message adaptation service groups
2009/11/23 09:15:17.037| squid-3.1.0.14/src/adaptation/Config.cc(117) FinalizeEach: Initialized 1 message adaptation access rules
2009/11/23 09:15:17.768| AsyncJob of type ConnStateData constructed, this=0x8730f100 [async2]
2009/11/23 09:15:17.768| AsyncJob of type ClientHttpRequest constructed, this=0x891f0410 [async3]
2009/11/23 09:15:17.768| AsyncJob of type AccessCheck constructed, this=0x81f7203c [async4]
2009/11/23 09:15:17.768| squid-3.1.0.14/src/adaptation/AccessCheck.cc(49) AccessCheck: AccessCheck constructed for REQMOD PRECACHE
2009/11/23 09:15:17.768| The AsyncCall AsyncJob::noteStart constructed, this=0x7df3fc40 [call94]
2009/11/23 09:15:17.768| squid-3.1.0.14/src/base/AsyncJob.cc(18) will call AsyncJob::noteStart() [call94]
2009/11/23 09:15:17.769| entering AsyncJob::noteStart()
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call AsyncJob::noteStart [call94]
2009/11/23 09:15:17.769| AccessCheck status in: [ job4]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(74) check: start checking
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(188) isCandidate: checking candidacy of 1, group class_1
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/ServiceGroups.cc(134) findService: class_1 checks service at 0
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/ServiceGroups.cc(144) findService: class_1 has matching service at 0
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(198) isCandidate: class_1 wants
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(80) check: check: rule '1' is a candidate
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(96) checkCandidates: has 1 rules
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(119) AccessCheckCallbackWrapper: callback answer=1
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(134) noteAnswer: 1 answer=1
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(171) topGroup: top group for 1 is 0x81485540*2
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/AccessCheck.cc(155) callBack: 0x81485540*2
2009/11/23 09:15:17.769| squid-3.1.0.14/src/client_side_request.cc(636) adaptationAclCheckDone: 0x7ef0b010 adaptationAclCheckDone called
2009/11/23 09:15:17.769| AsyncJob of type Iterator constructed, this=0x8874b044 [async5]
2009/11/23 09:15:17.769| The AsyncCall AsyncJob::noteStart constructed, this=0x81e26bc0 [call96]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncJob.cc(18) will call AsyncJob::noteStart() [call96]
2009/11/23 09:15:17.769| AccessCheck will stop, reason: done
2009/11/23 09:15:17.769| AsyncJob::noteStart() ends job [Stopped, reason:done job4]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncJob.cc(140) callEnd: AsyncJob::noteStart() ended 0x81f7203c
2009/11/23 09:15:17.769| leaving AsyncJob::noteStart()
2009/11/23 09:15:17.769| entering AsyncJob::noteStart()
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call AsyncJob::noteStart [call96]
2009/11/23 09:15:17.769| Iterator status in: [ job5]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/ServiceGroups.cc(134) findService: class_1 checks service at 0
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/ServiceGroups.cc(144) findService: class_1 has matching service at 0
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/Iterator.cc(49) step: #1 plan: class_1[0..1]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/Iterator.cc(69) step: using adaptation service: icap_server
2009/11/23 09:15:17.769| AsyncJob of type Adaptation::Icap::ModXactLauncher constructed, this=0x7d14c038 [async6]
2009/11/23 09:15:17.769| The AsyncCall AsyncJob::noteStart constructed, this=0x81e26400 [call97]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncJob.cc(18) will call AsyncJob::noteStart() [call97]
2009/11/23 09:15:17.769| Iterator status out: [ job5]
2009/11/23 09:15:17.769| leaving AsyncJob::noteStart()
2009/11/23 09:15:17.769| entering AsyncJob::noteStart()
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call AsyncJob::noteStart [call97]
2009/11/23 09:15:17.769| Adaptation::Icap::ModXactLauncher status in: [ job6]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/icap/Launcher.cc(42) launchXaction: launching first xaction #1
2009/11/23 09:15:17.769| AsyncJob of type Adaptation::Icap::ModXact constructed, this=0x7f4ce454 [async7]
2009/11/23 09:15:17.769| Adaptation::Icap::ModXact constructed, this=0x7f4ce010 [icapx7]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(70) ModXact: initialized. [G/R icapx7]
2009/11/23 09:15:17.769| Adaptation::Icap::ModXact from now on cannot be repeated because over icap_retry_limit [G/R icapx7]
2009/11/23 09:15:17.769| The AsyncCall AsyncJob::noteStart constructed, this=0x7df3fc40 [call98]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncJob.cc(18) will call AsyncJob::noteStart() [call98]
2009/11/23 09:15:17.769| Adaptation::Icap::ModXactLauncher status out: [ job6]
2009/11/23 09:15:17.769| leaving AsyncJob::noteStart()
2009/11/23 09:15:17.769| entering AsyncJob::noteStart()
2009/11/23 09:15:17.769| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call AsyncJob::noteStart [call98]
2009/11/23 09:15:17.769| Adaptation::Icap::ModXact status in: [G/R icapx7]
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(1535) estimateVirginBody: does not expect virgin body
2009/11/23 09:15:17.769| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(98) waitForService: will wait for the ICAP service [G/R icapx7]
2009/11/23 09:15:17.769| The AsyncCall Adaptation::Icap::ModXact::noteServiceReady constructed, this=0x81e26b40 [call99]
2009/11/23 09:15:17.770| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(201) callWhenReady: Adaptation::Icap::Service is asked to call Adaptation::Icap::ModXact::noteServiceReady() when ready [down,!opt]
2009/11/23 09:15:17.770| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(358) startGettingOptions: will get new options [down,!opt]
2009/11/23 09:15:17.770| AsyncJob of type Adaptation::Icap::OptXactLauncher constructed, this=0x8209f02c [async8]
2009/11/23 09:15:17.770| The AsyncCall AsyncJob::noteStart constructed, this=0x81e26940 [call100]
2009/11/23 09:15:17.770| squid-3.1.0.14/src/base/AsyncJob.cc(18) will call AsyncJob::noteStart() [call100]
2009/11/23 09:15:17.770| Adaptation::Icap::ModXact status out: [UG/R icapx7]
2009/11/23 09:15:17.770| leaving AsyncJob::noteStart()
2009/11/23 09:15:17.770| entering AsyncJob::noteStart()
2009/11/23 09:15:17.770| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call AsyncJob::noteStart [call100]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXactLauncher status in: [ job8]
2009/11/23 09:15:17.770| squid-3.1.0.14/src/adaptation/icap/Launcher.cc(42) launchXaction: launching first xaction #1
2009/11/23 09:15:17.770| AsyncJob of type Adaptation::Icap::OptXact constructed, this=0x856283dc [async9]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact constructed, this=0x85628010 [icapx9]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact from now on cannot be repeated because over icap_retry_limit [/ icapx9]
2009/11/23 09:15:17.770| The AsyncCall AsyncJob::noteStart constructed, this=0x81e26340 [call101]
2009/11/23 09:15:17.770| squid-3.1.0.14/src/base/AsyncJob.cc(18) will call AsyncJob::noteStart() [call101]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXactLauncher status out: [ job8]
2009/11/23 09:15:17.770| leaving AsyncJob::noteStart()
2009/11/23 09:15:17.770| entering AsyncJob::noteStart()
2009/11/23 09:15:17.770| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call AsyncJob::noteStart [call101]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact status in: [/ icapx9]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact from now on cannot be retried [/ icapx9]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact opens connection to 127.0.0.1:8197
2009/11/23 09:15:17.770| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x81aaee00 [call102]
2009/11/23 09:15:17.770| The AsyncCall Adaptation::Icap::Xaction::noteCommClosed constructed, this=0x8998a580 [call103]
2009/11/23 09:15:17.770| The AsyncCall Adaptation::Icap::Xaction::noteCommConnected constructed, this=0x8998ac00 [call104]
2009/11/23 09:15:17.770| commConnectStart: FD 11, cb 0x8998ac00*1, 127.0.0.1:8197
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact status out: [FD 11;/ icapx9]
2009/11/23 09:15:17.770| leaving AsyncJob::noteStart()
2009/11/23 09:15:17.770| squid-3.1.0.14/src/comm.cc(927) will call Adaptation::Icap::Xaction::noteCommConnected(FD 11, data=0x85628010, ) [call104]
2009/11/23 09:15:17.770| entering Adaptation::Icap::Xaction::noteCommConnected(FD 11, data=0x85628010, )
2009/11/23 09:15:17.770| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::Xaction::noteCommConnected [call104]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact status in: [FD 11;/ icapx9]
2009/11/23 09:15:17.770| The AsyncCall Adaptation::Icap::Xaction::noteCommRead constructed, this=0x81aaee00 [call107]
2009/11/23 09:15:17.770| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x8998ac80 [call108]
2009/11/23 09:15:17.770| squid-3.1.0.14/src/adaptation/icap/OptXact.cc(40) handleCommConnected: request [FD 11r;/ icapx9]:
OPTIONS icap://127.0.0.1:8197/ ICAP/1.0
Host: 127.0.0.1:8197
2009/11/23 09:15:17.770| The AsyncCall Adaptation::Icap::Xaction::noteCommWrote constructed, this=0x8998ad00 [call109]
2009/11/23 09:15:17.770| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x8998ad80 [call110]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact status out: [FD 11wr;/ icapx9]
2009/11/23 09:15:17.770| leaving Adaptation::Icap::Xaction::noteCommConnected(FD 11, data=0x85628010, )
2009/11/23 09:15:17.770| squid-3.1.0.14/src/comm.cc(163) will call Adaptation::Icap::Xaction::noteCommWrote(FD 11, data=0x85628010) [call109]
2009/11/23 09:15:17.770| entering Adaptation::Icap::Xaction::noteCommWrote(FD 11, data=0x85628010)
2009/11/23 09:15:17.770| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::Xaction::noteCommWrote [call109]
2009/11/23 09:15:17.770| Adaptation::Icap::OptXact status in: [FD 11wr;/ icapx9]
2009/11/23 09:15:17.771| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x8998af80 [call111]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/OptXact.cc(62) handleCommWrote: finished writing 65-byte request [FD 11r;/ icapx9]
2009/11/23 09:15:17.771| Adaptation::Icap::OptXact status out: [FD 11r;/ icapx9]
2009/11/23 09:15:17.771| leaving Adaptation::Icap::Xaction::noteCommWrote(FD 11, data=0x85628010)
2009/11/23 09:15:17.771| squid-3.1.0.14/src/comm.cc(163) will call Adaptation::Icap::Xaction::noteCommRead(FD 11, data=0x85628010, size=207, buf=0x8772a000) [call107]
2009/11/23 09:15:17.771| entering Adaptation::Icap::Xaction::noteCommRead(FD 11, data=0x85628010, size=207, buf=0x8772a000)
2009/11/23 09:15:17.771| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::Xaction::noteCommRead [call107]
2009/11/23 09:15:17.771| Adaptation::Icap::OptXact status in: [FD 11r;/ icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Xaction.cc(353) noteCommRead: read 207 bytes
2009/11/23 09:15:17.771| Adaptation::Icap::OptXact still cannot be retried [FD 11;/ icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/OptXact.cc(83) parseResponse: have 207 bytes to parse [FD 11;/ icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/OptXact.cc(84) parseResponse:
ICAP/1.0 200 OK
Date: Mon, 23 Nov 2009 08:15:17 GMT
Methods: RESPMOD,REQMOD
Service: GeNUA ICAP Test Server
ISTag: "W3E4R7U9-L2E4-2"
Max-Connections: 10
Options-TTL: 7200
Encapsulated: null-body=0
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Xaction.cc(381) parseHttpMsg: have 207 head bytes to parse
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Xaction.cc(437) setOutcome: ICAP_OPT
2009/11/23 09:15:17.771| The AsyncCall Initiator::noteAdaptAnswer constructed, this=0x81e26d00 [call112]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/Initiate.cc(68) will call Initiator::noteAdaptAnswer(0x82870fd8) [call112]
2009/11/23 09:15:17.771| Adaptation::Icap::Xaction::noteCommRead(FD 11, data=0x85628010, size=207, buf=0x8772a000) ends job [FD 11;/ icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Xaction.cc(173) closeConnection: not reusing pconn due to pending I/O [FD 11;/ icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Xaction.cc(188) closeConnection: closing pconn [FD 11;/ icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/Initiate.cc(48) swanSong: swan sings [/ icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/Initiate.cc(55) swanSong: swan sang [/ icapx9]
2009/11/23 09:15:17.771| Adaptation::Icap::OptXact destructed, this=0x85628010 [icapx9]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/base/AsyncJob.cc(140) callEnd: Adaptation::Icap::Xaction::noteCommRead(FD 11, data=0x85628010, size=207, buf=0x8772a000) ended 0x856283dc
2009/11/23 09:15:17.771| leaving Adaptation::Icap::Xaction::noteCommRead(FD 11, data=0x85628010, size=207, buf=0x8772a000)
2009/11/23 09:15:17.771| entering Initiator::noteAdaptAnswer(0x82870fd8)
2009/11/23 09:15:17.771| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Initiator::noteAdaptAnswer [call112]
2009/11/23 09:15:17.771| Adaptation::Icap::OptXactLauncher status in: [ job8]
2009/11/23 09:15:17.771| The AsyncCall Initiator::noteAdaptAnswer constructed, this=0x81e26c00 [call115]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/Initiate.cc(68) will call Initiator::noteAdaptAnswer(0x82870fd8) [call115]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Launcher.cc(58) noteAdaptationAnswer: Adaptation::Icap::Launcher::noteAdaptationAnswer exiting
2009/11/23 09:15:17.771| Initiator::noteAdaptAnswer(0x82870fd8) ends job [ job8]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/Initiate.cc(48) swanSong: swan sings [ job8]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/Initiate.cc(55) swanSong: swan sang [ job8]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/base/AsyncJob.cc(140) callEnd: Initiator::noteAdaptAnswer(0x82870fd8) ended 0x8209f02c
2009/11/23 09:15:17.771| leaving Initiator::noteAdaptAnswer(0x82870fd8)
2009/11/23 09:15:17.771| entering Initiator::noteAdaptAnswer(0x82870fd8)
2009/11/23 09:15:17.771| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Initiator::noteAdaptAnswer [call115]
2009/11/23 09:15:17.771| Adaptation::Icap::ServiceRep status in:[down,!opt,fetch]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(322) noteAdaptationAnswer: is interpreting new options [down,!opt]
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Options.cc(132) cfgIntHeader: int header: Max-Connections: 10
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Options.cc(132) cfgIntHeader: int header: Options-TTL: 7200
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/Options.cc(132) cfgIntHeader: int header: Preview: -1
2009/11/23 09:15:17.771| Adaptation::Icap::Options::cfgTransferList: no Transfer-Preview extensions
2009/11/23 09:15:17.771| Adaptation::Icap::Options::cfgTransferList: no Transfer-Ignore extensions
2009/11/23 09:15:17.771| Adaptation::Icap::Options::cfgTransferList: no Transfer-Complete extensions
2009/11/23 09:15:17.771| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(234) changeOptions: changes options from 0 to 0x8998ac00 [down,!opt]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(349) handleNewOptions: got new options and is now [up]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(409) optionsFetchTime: options expire on 1258971317 >= 1258964117
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(381) scheduleUpdate: raw OPTIONS fetch at 1258971297 or in 7180 sec
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(383) scheduleUpdate: last fetched at 1258964117 or 0 sec ago
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(396) scheduleUpdate: will fetch OPTIONS in 7180 sec
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(222) scheduleNotification: will notify 1 clients
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::ServiceRep::noteTimeToNotify constructed, this=0x81e26500 [call116]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(223) will call Adaptation::Icap::ServiceRep::noteTimeToNotify() [call116]
2009/11/23 09:15:17.772| Adaptation::Icap::ServiceRep status out:[up]
2009/11/23 09:15:17.772| leaving Initiator::noteAdaptAnswer(0x82870fd8)
2009/11/23 09:15:17.772| entering Adaptation::Icap::ServiceRep::noteTimeToNotify()
2009/11/23 09:15:17.772| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::ServiceRep::noteTimeToNotify [call116]
2009/11/23 09:15:17.772| Adaptation::Icap::ServiceRep status in:[up]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(181) noteTimeToNotify: notifies 1 clients [up,notif]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ServiceRep.cc(189) will call Adaptation::Icap::ModXact::noteServiceReady() [call99]
2009/11/23 09:15:17.772| Adaptation::Icap::ServiceRep status out:[up]
2009/11/23 09:15:17.772| leaving Adaptation::Icap::ServiceRep::noteTimeToNotify()
2009/11/23 09:15:17.772| entering Adaptation::Icap::ModXact::noteServiceReady()
2009/11/23 09:15:17.772| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::ModXact::noteServiceReady [call99]
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact status in: [UG/R icapx7]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(1346) decideOnPreview: should not offer preview for /
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact from now on cannot be retried [w(1)G/R icapx7]
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact opens connection to 127.0.0.1:8197
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x81aaee00 [call117]
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommClosed constructed, this=0x8998a580 [call118]
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommConnected constructed, this=0x8998ac80 [call119]
2009/11/23 09:15:17.772| commConnectStart: FD 11, cb 0x8998ac80*1, 127.0.0.1:8197
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact status out: [FD 11;rw(1)G/R icapx7]
2009/11/23 09:15:17.772| leaving Adaptation::Icap::ModXact::noteServiceReady()
2009/11/23 09:15:17.772| squid-3.1.0.14/src/comm.cc(927) will call Adaptation::Icap::Xaction::noteCommConnected(FD 11, data=0x7f4ce010, ) [call119]
2009/11/23 09:15:17.772| entering Adaptation::Icap::Xaction::noteCommConnected(FD 11, data=0x7f4ce010, )
2009/11/23 09:15:17.772| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::Xaction::noteCommConnected [call119]
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact status in: [FD 11;rw(1)G/R icapx7]
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommRead constructed, this=0x8998ad80 [call121]
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x8998ae00 [call122]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(1248) makeRequestHeaders: will allow 204s outside of preview
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(141) handleCommConnected: will write [FD 11r;rw(1)G/R icapx7]:
REQMOD icap://127.0.0.1:8197/ ICAP/1.0
Host: 127.0.0.1:8197
Date: Mon, 23 Nov 2009 08:15:17 GMT
Encapsulated: req-hdr=0, null-body=40
Allow: 204
GET http://127.0.0.1:11895/ HTTP/1.0
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommWrote constructed, this=0x81aaee00 [call123]
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x8998aa00 [call124]
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact status out: [FD 11wr;rw(2)G/R icapx7]
2009/11/23 09:15:17.772| leaving Adaptation::Icap::Xaction::noteCommConnected(FD 11, data=0x7f4ce010, )
2009/11/23 09:15:17.772| squid-3.1.0.14/src/comm.cc(163) will call Adaptation::Icap::Xaction::noteCommWrote(FD 11, data=0x7f4ce010) [call123]
2009/11/23 09:15:17.772| entering Adaptation::Icap::Xaction::noteCommWrote(FD 11, data=0x7f4ce010)
2009/11/23 09:15:17.772| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::Xaction::noteCommWrote [call123]
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact status in: [FD 11wr;rw(2)G/R icapx7]
2009/11/23 09:15:17.772| The AsyncCall Adaptation::Icap::Xaction::noteCommTimedout constructed, this=0x8998ad00 [call125]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(151) handleCommWrote: Wrote 192 bytes
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(441) stopWriting: will no longer write [FD 11r;rw(2)G/R icapx7]
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact status out: [FD 11r;rG/Rw icapx7]
2009/11/23 09:15:17.772| leaving Adaptation::Icap::Xaction::noteCommWrote(FD 11, data=0x7f4ce010)
2009/11/23 09:15:17.772| squid-3.1.0.14/src/comm.cc(163) will call Adaptation::Icap::Xaction::noteCommRead(FD 11, data=0x7f4ce010, size=399, buf=0x8770a000) [call121]
2009/11/23 09:15:17.772| entering Adaptation::Icap::Xaction::noteCommRead(FD 11, data=0x7f4ce010, size=399, buf=0x8770a000)
2009/11/23 09:15:17.772| squid-3.1.0.14/src/base/AsyncCall.cc(32) make: make call Adaptation::Icap::Xaction::noteCommRead [call121]
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact status in: [FD 11r;rG/Rw icapx7]
2009/11/23 09:15:17.772| squid-3.1.0.14/src/adaptation/icap/Xaction.cc(353) noteCommRead: read 399 bytes
2009/11/23 09:15:17.772| Adaptation::Icap::ModXact still cannot be retried [FD 11;rG/Rw icapx7]
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(585) parseMore: have 399 bytes to parse [FD 11;rG/Rw icapx7]
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(586) parseMore:
ICAP/1.0 200 OK
Server: Perl ICAP Test Server
ISTag: "W3E4R7U9-L2E4-2"
Encapsulated: res-hdr=0, res-body=108
HTTP/1.1 403 Forbidden
Server: Apache/1.3.12 (Unix)
Content-Length: 175
Content-Type: text/html
42
<html>
<body>
You are not allowed to view this page!<br>
6d
If you think this page should be unblocked please contact your local
administrator!
</body>
</html>
0
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(671) parseHeaders: parse ICAP headers
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(944) parseHead: have 399 head bytes to parse; state: 0
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(959) parseHead: parse success, consume 116 bytes, return true
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(676) parseHeaders: parse HTTP headers
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/Xaction.cc(437) setOutcome: ICAP_SAT
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(944) parseHead: have 283 head bytes to parse; state: 1
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(959) parseHead: parse success, consume 102 bytes, return true
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(967) decideOnParsingBody: expecting a body
2009/11/23 09:15:17.773| squid-3.1.0.14/src/BodyPipe.cc(134) BodyPipe: created BodyPipe [0<=0<=? 0+2047 pipe0x8bd3b010 prod0x7f4ce3dc]
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(1548) makeAdaptedBodyPipe: will supply adapted response from the ICAP server via 0x8bd3b010*2 pipe
2009/11/23 09:15:17.773| Adaptation::Icap::ModXact still cannot be repeated because sent headers [FD 11;rp(2)S(2)G/Rw icapx7]
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(642) disableBypass: not protecting group bypass because sent headers
2009/11/23 09:15:17.773| The AsyncCall Initiator::noteAdaptAnswer constructed, this=0x81e26ac0 [call126]
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/Initiate.cc(68) will call Initiator::noteAdaptAnswer(0x82871074) [call126]
2009/11/23 09:15:17.773| squid-3.1.0.14/src/adaptation/icap/ModXact.cc(984) parseBody: have 181 body bytes to parse
2009/11/23 09:15:17.773| found chunk-size end: 2-4
2009/11/23 09:15:17.773| found chunk: 66
2009/11/23 09:15:17.773| found chunk-size end: 68-70
2009/11/23 09:15:17.773| assertion failed: squid-3.1.0.14/src/BodyPipe.cc:337: "checkout.checkedOutSize == currentSize"
