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

Wed Sep 13 16:47:02 UTC 2023

Hi all

I was trying to configure the ssl-bump feature. I forgot to allow the
initial CONNECT (or the fake CONNECT, in case of intercepting proxy). This
led me to some strange results which I'd like to point out. I am using
CentOS 8 with squid 6.13 recompiled from the Fedora RPM.
First case, forward proxy. The configuration is:

debug_options 83,8
logformat timereadable %tl %6tr %>a %Ss/%03Hs %<st %rm %ru %un %Sh/%<A %mt
logformat timereadableWithMilli %{%FT%T}tl.%03tu%{%z}tl %6tr %>a %Ss/%03Hs
%<st %rm %ru %un %Sh/%<A %mt
access_log daemon:/var/log/squid/access.log timereadableWithMilli

acl localnet src 0.0.0.1-0.255.255.255  # RFC 1122 "this" network (LAN)
acl localnet src 10.0.0.0/8             # RFC 1918 local private network
(LAN)
acl localnet src 100.64.0.0/10          # RFC 6598 shared address space
(CGN)
acl localnet src 169.254.0.0/16         # RFC 3927 link-local (directly
plugged) machines
acl localnet src 172.16.0.0/12          # RFC 1918 local private network
(LAN)
acl localnet src 192.168.0.0/16         # RFC 1918 local private network
(LAN)
acl localnet src fc00::/7               # RFC 4193 local private network
range
acl localnet src fe80::/10              # RFC 4291 link-local (directly
plugged) machines

acl SSL_ports port 443
acl Safe_ports port 80          # http
acl Safe_ports port 21          # ftp
acl Safe_ports port 443         # https
acl Safe_ports port 70          # gopher
acl Safe_ports port 210         # wais
acl Safe_ports port 1025-65535  # unregistered ports
acl Safe_ports port 280         # http-mgmt
acl Safe_ports port 488         # gss-http
acl Safe_ports port 591         # filemaker
acl Safe_ports port 777         # multiling http

http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports
http_access allow localhost manager
http_access deny manager
http_access allow localhost
http_access deny to_localhost
http_access deny to_linklocal
http_access deny all

http_port 3130 ssl-bump generate-host-certificates=on
dynamic_cert_mem_cache_size=6MB cert=/etc/squid/ssl_cert/myCA.pem
ssl_bump peek all
ssl_bump splice all

coredump_dir /var/spool/squid
refresh_pattern ^ftp:           1440    20%     10080
refresh_pattern -i (/cgi-bin/|\?) 0     0%      0
refresh_pattern .               0       20%     4320

I'm only peeking as long as possible, and then splice at step3. Or at least,
this is what I was trying to do. My browser is explicitly configured to use
Squid on port 3130.

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, 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