[squid-users] url_rewrite (with rewrite-url): PinnedConnection failure results in total failure
Alex Rousskov
rousskov at measurement-factory.com
Tue Jun 18 19:03:47 UTC 2024
On 2024-06-18 11:34, Andreas Weigel wrote:
> 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.
The peek+splice and stare+bump cases are very different with regard to
how the request destination should be computed (including how pinned
connection should be reused) IMO. In my response, I will focus on the
stare+bump case.
> 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.
Overall, I believe that a Squid admin should be able to rewrite any HTTP
request (destination). Whether to classify the lack of this
functionality in current Squid bumping code as a regression bug or a
missing feature is currently unimportant AFAICT.
Needless to say, using another destination after a Squid-to-server
connection has been pinned to the client-to-Squid connection is not
quite compatible with some guarantees implied by "pinning", so extra
care should be done when (re)enabling this behavior. I would not be
surprised if we need to introduce several pinning categories, with
different guarantees and re-pinning options!
For example, a client pinned to a server after a failed Host validation
should not be able to send a second request to another destination
without Squid admin permission. I am not sure how to detect such a
permission when, say, a URL rewriter simply echoes client-chosen
destination (possibly trusting Squid to block any requests that are
attempting to escape their "pinned jail"). Distinguishing "intended"
destination rewrites from canonicalizing or DNS-resolving echoes may be
difficult!
It is also not clear whether the originally pinned Squid-to-server
connection should be preserved in such cases (to be used for future
non-redirected requests received on the same client-to-Squid connection,
if any). Again, the correct answer may depend on the "pinning category".
HTH,
Alex.
> 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).
> 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
>
More information about the squid-users
mailing list