[squid-users] ssl-bump strange behaviour with incomplete config

Wed Sep 13 17:12:44 UTC 2023

On 2023-09-13 12:47, squid at iotti.biz wrote:

> I'm only peeking as long as possible, and then splice at step3.
> 
> I got the regular Squid access denied screen (and this is right, since the
> CONNECT is not allowed) but in access.log I find:
> 
> 2023-09-13T17:12:52.855+0200     12 192.168.1.179 TCP_DENIED/200 0 CONNECT
> www.nytimes.com:443 - HIER_NONE/- -
> 2023-09-13T17:12:52.855+0200      0 192.168.1.179 NONE_NONE/403 3952 GET
> https://www.nytimes.com/ - HIER_NONE/- text/html
> 
> See the second GET. It seems that Squid here is kind-of bumping

Yes, if Squid encounters an error during SslBump processing steps, it 
will try to bump the TLS client connection (if it has not been bumped 
already) to (later) deliver an HTTP response describing that error to 
the user agent.

Squid bumps the TLS client connection and then waits for and responds to 
the first request after CONNECT because popular browsers do not show 
CONNECT responses to users, including CONNECT responses containing Squid 
access denied errors. In other words, without bumping, the browser would 
not show that "Squid access denied screen" that you consider "right".

This SslBump error-handling behavior works well in some use cases and 
breaks some other use cases. I expect it to become configurable at some 
point.

HTH,

Alex.

, instead of
> splicing, since it did read what should be the encrypted request.
> Also the TCP_DENIED/200 is not clear to me: shouldn't it be TCP_DENIED/403?
> I checked with tcpdump, and the CONNECT is really allowed with 200 code, a
> client hello and server hello are exchanged, than the connections is closed
> after some transaction.
> 
> I started debugging the ssl-bump thing with debug_options 83,8 and in
> cache.log I see:
> 
> 2023/09/13 17:14:00.283 kid1| 83,7| LogTags.cc(57) update: TAG_NONE to
> TCP_DENIED
> 2023/09/13 17:14:00.283 kid1| 83,3| client_side_request.cc(1501)
> sslBumpNeed: sslBump required: bump
> 2023/09/13 17:14:00.283 kid1| 83,3| client_side_request.cc(1501)
> sslBumpNeed: sslBump required: client-first
> 
> Why " sslBump required: bump" and not splice? Even "worse", why does it do
> client-first then? Is it right it defaults to this if the CONNECT is
> refused?
> Then in cache.log I see a lot of messages where it seems that Squid is
> talking TLS with the client, probably sending the access denied page.
> 
> If I simply add in the config
> acl lux src 192.168.1.179
> http_access allow lux
> 
> then it works, with
> 2023-09-13T17:28:21.877+0200 108353 192.168.1.179 TCP_TUNNEL/200 4853
> CONNECT vp.nyt.com:443 - HIER_DIRECT/vp.nyt.com -
> 2023-09-13T17:28:21.878+0200 108441 192.168.1.179 TCP_TUNNEL/200 7894
> CONNECT mwcm.nytimes.com:443 - HIER_DIRECT/mwcm.nytimes.com -
> 2023-09-13T17:28:21.879+0200 110154 192.168.1.179 TCP_TUNNEL/200 6337
> CONNECT a.nytimes.com:443 - HIER_DIRECT/a.nytimes.com -
> 2023-09-13T17:28:21.879+0200 111702 192.168.1.179 TCP_TUNNEL/200 514229
> CONNECT g1.nyt.com:443 - HIER_DIRECT/g1.nyt.com -
> 2023-09-13T17:28:21.880+0200 111702 192.168.1.179 TCP_TUNNEL/200 648915
> CONNECT static01.nyt.com:443 - HIER_DIRECT/static01.nyt.com -
> 2023-09-13T17:28:21.880+0200 111890 192.168.1.179 TCP_TUNNEL/200 10986
> CONNECT samizdat-graphql.nytimes.com:443 -
> HIER_DIRECT/samizdat-graphql.nytimes.com -
> 2023-09-13T17:28:21.881+0200 112017 192.168.1.179 TCP_TUNNEL/200 72448
> CONNECT static01.nytimes.com:443 - HIER_DIRECT/static01.nytimes.com -
> 2023-09-13T17:28:21.881+0200 112018 192.168.1.179 TCP_TUNNEL/200 286645
> CONNECT static01.nytimes.com:443 - HIER_DIRECT/static01.nytimes.com -
> 2023-09-13T17:28:21.882+0200 112043 192.168.1.179 TCP_TUNNEL/200 15345
> CONNECT g1.nyt.com:443 - HIER_DIRECT/g1.nyt.com -
> 2023-09-13T17:28:21.883+0200 112333 192.168.1.179 TCP_TUNNEL/200 2390864
> CONNECT www.nytimes.com:443 - HIER_DIRECT/www.nytimes.com -
> 
> And in cache.log, no more client-first mentions:
> 2023/09/13 17:26:33.523 kid1| 83,3| client_side_request.cc(1748) doCallouts:
> Doing clientInterpretRequestHeaders()
> 2023/09/13 17:26:33.523 kid1| 83,3| client_side_request.cc(1501)
> sslBumpNeed: sslBump required: peek
> 2023/09/13 17:26:33.523 kid1| 83,3| client_side_request.cc(1842) doCallouts:
> calling processRequest()
> 
> 
> I also tried with an interception proxy (transparent proxy) config. The
> results are similar but not identical:
> I added to the original config (the one which prohibits the CONNECT):
> http_port 3128
> 
> and changed port 3130 so:
> https_port 3130 intercept ssl-bump generate-host-certificates=on
> dynamic_cert_mem_cache_size=6MB cert=/etc/squid/ssl_cert/myCA.pem
> 
> Now I get:
> 2023-09-13T17:52:17.109+0200      6 192.168.1.179 TCP_DENIED/000 0 CONNECT
> 151.101.241.164:443 - HIER_NONE/- -
> 2023-09-13T17:52:17.109+0200      0 192.168.1.179 NONE_NONE/403 3732 GET
> https://www. nytimes.com/ - HIER_NONE/- text/html
> 
> TCP_DENIED/000 is more clear than TCP_DENIED/200. But the GET, making me
> think to some bumping code, is still there.
> 
> In cache.log, I find:
> 
> 2023/09/13 17:53:06.539 kid1| 83,7| LogTags.cc(57) update: TAG_NONE to
> TCP_DENIED
> 2023/09/13 17:53:06.539 kid1| 83,3| client_side_request.cc(1501)
> sslBumpNeed: sslBump required: peek
> 2023/09/13 17:53:06.539 kid1| 83,3| client_side_request.cc(1501)
> sslBumpNeed: sslBump required: client-first
> 
> So this time, it is doing peek first (and this is ok with the config), but
> then it recurs to client-first, which could be the reason why the encrypted
> HTTPS traffic is decoded and the HTTP GET is shown.
> 
> Is this whole behavior correct? Anyway, when I white-list the CONNECT,
> everything seems to work right.
> 
> Thank you,
> Luigi
> 
> _______________________________________________
> squid-users mailing list
> squid-users at lists.squid-cache.org
> https://lists.squid-cache.org/listinfo/squid-users