Search squid archive

url_rewrite (with rewrite-url): PinnedConnection failure results in total failure

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi,

updating from a (security-patched) Squidv4 to Squidv6, problems occurred with regard to url_rewrite Feature used for content-filtering. The external helper uses "OK rewrite-url=" to point to a custom page that Squid used to retrieve and present to the Client. This used to work with SSL-Interception, but it does no longer in Squidv6. It does not matter in that regard if peek+splice or stare+bump is used, Squid always fails with ERR_CANNOT_FORWARD.

Digging into the codebase, I can see that with v4, Squid first checked the validity of any pinned connection and if none is found, still retrieves the "replacement page". It seems that daf80700130b6f98256b75c511916d1a79b23597 changed the logic in that regard, causing the FwdState to fail hard and not try any of the remaining peer options (see log excerpts below), although I can see that it added two selections (PINNED and HIER_DIRECT).

I understand that using the rewrite-url mechanism is discouraged, but would still like to understand if this is intended behavior (and the reasoning behind it) or if this has to be considered a bug. Any pointers to additional ressources or explanations to understand the behavior would be much appreciated.

Kind regards,
Andreas Weigel

PS:

log excerpt from squid-v4.16 (successful rewrite-url)

2024/06/14 14:46:30.750 kid1| 61,2| /client_side_request.cc(1266) clientRedirectDone: URL-rewriter diverts URL from https://youtube.com/ to http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:46:30.750 kid1| 33,5| /store_client.cc(317) doCopy: store_client::doCopy: co: 0, hi: 0 2024/06/14 14:46:30.750 kid1| 17,3| /FwdState.cc(340) Start: 'http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener=' 2024/06/14 14:46:30.750 kid1| 17,2| /FwdState.cc(142) FwdState: Forwarding client request local=172.217.13.206:443 remote=192.168.180.10:33836 FD 11 flags=33, url=http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f 2024/06/14 14:46:30.750 kid1| 17,3| /FwdState.cc(149) FwdState: FwdState constructed, this=0x559ad7e89b88 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(161) peerSelect: e:=XIV/0x559ad7e89500*2 http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(472) peerSelectFoo: GET 127.0.0.1 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(477) peerSelectFoo: peerSelectFoo: direct = DIRECT_UNKNOWN (always_direct to be checked) 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(218) peerCheckAlwaysDirectDone: peerCheckAlwaysDirectDone: ALLOWED 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(224) peerCheckAlwaysDirectDone: direct = DIRECT_YES (always_direct allow) 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(472) peerSelectFoo: GET 127.0.0.1 2024/06/14 14:46:30.750 kid1| 33,7| /client_side.cc(4119) validatePinnedConnection: local=192.168.41.35:47842 remote=172.217.13.206:443 FD 13 flags=1 2024/06/14 14:46:30.750 kid1| 33,3| /client_side.cc(4154) unpinConnection: local=192.168.41.35:47842 remote=172.217.13.206:443 FD 13 flags=1 2024/06/14 14:46:30.750 kid1| 33,5| src/base/AsyncCall.cc(54) cancel: will not call ConnStateData::clientPinnedConnectionClosed [call63] because comm_remove_close_handler 2024/06/14 14:46:30.750 kid1| 33,3| src/base/AsyncCall.cc(54) cancel: will not call ConnStateData::clientPinnedConnectionRead [call64] because comm_read_cancel 2024/06/14 14:46:30.750 kid1| 33,3| src/base/AsyncCall.cc(54) cancel: will not call ConnStateData::clientPinnedConnectionRead [call64] also because comm_read_cancel 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(978) peerAddFwdServer: adding HIER_DIRECT#127.0.0.1 2024/06/14 14:46:30.750 kid1| 44,2| /peer_select.cc(295) peerSelectDnsPaths: Find IP destination for: http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener=' via 127.0.0.1 2024/06/14 14:46:30.750 kid1| 44,2| /peer_select.cc(316) peerSelectDnsPaths: Found sources for 'http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener=' 2024/06/14 14:46:30.750 kid1| 44,2| /peer_select.cc(317) peerSelectDnsPaths: always_direct = ALLOWED 2024/06/14 14:46:30.750 kid1| 44,2| /peer_select.cc(318) peerSelectDnsPaths: never_direct = DENIED 2024/06/14 14:46:30.750 kid1| 44,2| /peer_select.cc(322) peerSelectDnsPaths: DIRECT = local=0.0.0.0 remote=127.0.0.1:8081 flags=1 2024/06/14 14:46:30.750 kid1| 44,2| /peer_select.cc(331) peerSelectDnsPaths: timedout = 0 2024/06/14 14:46:30.750 kid1| 17,3| /FwdState.cc(418) startConnectionOrFail: http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:46:30.750 kid1| 17,3| /FwdState.cc(832) connectStart: fwdConnectStart: http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:46:30.750 kid1| 17,3| src/base/AsyncCall.cc(25) AsyncCall: The AsyncCall fwdConnectDoneWrapper constructed, this=0x559ad7e16a00 [call81] 2024/06/14 14:46:30.750 kid1| 44,3| /peer_select.cc(103) ~ps_state: http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:46:30.750 kid1| 17,3| src/base/AsyncCall.cc(92) ScheduleCall: ../../../squid-4.16/src/comm/ConnOpener.cc(139) will call fwdConnectDoneWrapper(local=127.0.0.1:45660 remote=127.0.0.1:8081 FD 13 flags=1, data=0x559ad7e89b88) [call81] 2024/06/14 14:46:30.750 kid1| 17,3| src/base/AsyncCallQueue.cc(55) fireNext: entering fwdConnectDoneWrapper(local=127.0.0.1:45660 remote=127.0.0.1:8081 FD 13 flags=1, data=0x559ad7e89b88) 2024/06/14 14:46:30.750 kid1| 17,3| src/base/AsyncCall.cc(37) make: make call fwdConnectDoneWrapper [call81] 2024/06/14 14:46:30.750 kid1| 17,3| /FwdState.cc(706) connectDone: local=127.0.0.1:45660 remote=127.0.0.1:8081 FD 13 flags=1: 'http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener='

log excerpt for the same setup from squid-v6.9 (Squid reporting ERR_CANNOT_FORWARD)

024/06/14 14:59:40.463 kid1| 61,5| /redirect.cc(83) redirectHandleReply: reply={result=OK, notes={rewrite-url: http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener=; cf-info: DENIED,proxy%2dnet%5cnoyoutub 2024/06/14 14:59:40.463 kid1| 61,2| /client_side_request.cc(1236) clientRedirectDone: URL-rewriter diverts URL from https://youtube.com/ to http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:59:40.463 kid1| 33,5| /store_client.cc(374) doCopy: 0x55a9d80fc678 into ioBuf(@0, len=4096, 0x55a9d8127770) hi: 0 objectLen: -1 past_answers: 0 2024/06/14 14:59:40.463 kid1| 17,3| /FwdState.cc(373) Start: 'http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener=' 2024/06/14 14:59:40.463 kid1| 17,2| /FwdState.cc(133) FwdState: Forwarding client request conn19 local=172.217.13.206:443 remote=192.168.180.10:55036 FD 11 flags=33, url=http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2 2024/06/14 14:59:40.463 kid1| 17,3| /FwdState.cc(140) FwdState: FwdState constructed, this=0x55a9d812ceb8 2024/06/14 14:59:40.463 kid1| 17,4| src/base/AsyncCall.cc(29) AsyncCall: The AsyncCall FwdState::Abort constructed, this=0x55a9d80fc790 [call90] 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(309) peerSelect: e:=XIV/0x55a9d80fc5f0*3 http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(612) selectMore: GET 127.0.0.1 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(617) selectMore: direct = DIRECT_UNKNOWN (always_direct to be checked) 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(373) checkAlwaysDirectDone: ALLOWED 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(379) checkAlwaysDirectDone: direct = DIRECT_YES (always_direct allow) 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(612) selectMore: GET 127.0.0.1 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(1102) addSelection: adding PINNED#127.0.0.1 2024/06/14 14:59:40.463 kid1| 44,3| /peer_select.cc(1102) addSelection: adding HIER_DIRECT#127.0.0.1 2024/06/14 14:59:40.463 kid1| 44,2| /peer_select.cc(1176) handlePath: PeerSelector2 found pinned, destination #1 for http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:59:40.463 kid1| 44,2| /peer_select.cc(1180) handlePath: always_direct = ALLOWED 2024/06/14 14:59:40.463 kid1| 44,2| /peer_select.cc(1181) handlePath: never_direct = DENIED 2024/06/14 14:59:40.463 kid1| 44,2| /peer_select.cc(1182) handlePath: timedout = 0 2024/06/14 14:59:40.463 kid1| 33,7| /client_side.cc(3954) borrowPinnedConnection: conn30 local=192.168.41.35:50322 remote=172.217.13.206:443 ORIGINAL_DST FD 13 flags=1 2024/06/14 14:59:40.463 kid1| 33,3| /client_side.cc(3997) unpinConnection: conn30 local=192.168.41.35:50322 remote=172.217.13.206:443 ORIGINAL_DST FD 13 flags=1 2024/06/14 14:59:40.463 kid1| 33,5| src/base/AsyncCall.cc(58) cancel: will not call ConnStateData::clientPinnedConnectionClosed [call73] because comm_remove_close_handler 2024/06/14 14:59:40.463 kid1| 33,3| src/base/AsyncCall.cc(58) cancel: will not call ConnStateData::clientPinnedConnectionRead [call74] because comm_read_cancel 2024/06/14 14:59:40.463 kid1| 33,3| src/base/AsyncCall.cc(58) cancel: will not call ConnStateData::clientPinnedConnectionRead [call74] also because comm_read_cancel 2024/06/14 14:59:40.465 kid1| 17,3| /FwdState.cc(471) fail: ERR_CANNOT_FORWARD "Service Unavailable" http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:59:40.465 kid1| 17,3| /FwdState.cc(185) stopAndDestroy: for pinned connection failure 2024/06/14 14:59:40.465 kid1| 44,3| /peer_select.cc(1149) interestedInitiator: PeerSelector2 initiator lost interest 2024/06/14 14:59:40.465 kid1| 44,3| /peer_select.cc(405) selectionAborted: Aborting peer selection: Initiator gone or lost interest. 2024/06/14 14:59:40.465 kid1| 44,3| /peer_select.cc(241) ~PeerSelector: http://127.0.0.1:8081/?cat=&cat_all=&action=URLLIST&srv=&url=https%3a%2f%2fyoutube%2ecom%2f&shortener= 2024/06/14 14:59:40.465 kid1| 17,3| /FwdState.cc(310) ~FwdState: FwdState destructor start 2024/06/14 14:59:40.466 kid1| 33,5| /store_client.cc(374) doCopy: 0x55a9d80fc678 into ioBuf(@0, len=4096, 0x55a9d8127770) hi: 148495 objectLen: -1 past_answers: 0 2024/06/14 14:59:40.466 kid1| 33,5| /store_client.cc(422) doCopy: just send HTTP headers: 207 2024/06/14 14:59:40.466 kid1| 17,4| src/base/AsyncCall.cc(58) cancel: will not call FwdState::Abort [call90] because FwdState object destructed 2024/06/14 14:59:40.466 kid1| 17,3| /FwdState.cc(332) ~FwdState: FwdState destructed, this=0x55a9d812ceb8

--
Andreas Weigel
UTM Backend Developer

Securepoint GmbH
Bleckeder Landstraße 28
D-21337 Lüneburg
https://www.securepoint.de

Geschäftsführer: René Hofmann
Amtsgericht Lüneburg HRB 1776

_______________________________________________
squid-users mailing list
squid-users@xxxxxxxxxxxxxxxxxxxxx
https://lists.squid-cache.org/listinfo/squid-users




[Index of Archives]     [Linux Audio Users]     [Samba]     [Big List of Linux Books]     [Linux USB]     [Yosemite News]

  Powered by Linux