[squid-users] Logs not showing ssl::servername
Alex Rousskov
rousskov at measurement-factory.com
Wed Nov 30 15:48:03 UTC 2022
On 11/30/22 03:16, Gabriel Vilariño wrote:
> Log with error code and error detail at the end, both "-":
> 1669794718.051 INTERNAL_IP TCP_TUNNEL/500
> arsenal.us-west-2.amazonaws.com splice /CN=arsenal.us-west-2.amazonaws.com
> 54.240.254.131 - -
>
> The cache.log with ALL,1 does not look to share a lot, in fact I don´t
> see any messages referencing this transaction
Looks good, thank you. All of the above indirectly supports (but does
not yet prove) my working theory that there is no TLS failure here (that
Squid is aware of).
> I checked with further log levels but it outputs a lot of data (I know
> this one is not for admins, I wanted to try to sent only the relevant
> logs since those aws agents do several calls and I was not to only
> record one transaction).
Do not worry about the volume of data as long as you do your best to
reproduce the problem using as few transactions as possible (and
compress logs before sharing a pointer to them). As you know, there are
some hints for doing this at
https://wiki.squid-cache.org/SquidFaq/BugReporting#Debugging_a_single_transaction
Also, it would be nice if, when sharing the logs, you restate what the
current reproduced/observed problem is. Thank you.
> Also if I needed, this is shared as an attachment?
Most likely, this mailing list software will not let you share large
archives. Posting a (temporary) link to them usually works best.
Cheers,
Alex.
> El mar, 29 nov 2022 a las 21:52, Gabriel Vilariño (<gvilarino6 at gmail.com>) escribió:
>
> Thanks Alex!
>
> Here are the fixed logs:
> |1669726977.734 INTERNAL_CLIENT_IP TCP_TUNNEL/500
> arsenal.us-west-2.amazonaws.com
> <http://arsenal.us-west-2.amazonaws.com> splice
> /CN=arsenal.us-west-2.amazonaws.com
> <http://arsenal.us-west-2.amazonaws.com> 54.240.251.223|
> |
> |
> |As you can see, the destination is an aws service, more
> interesting, it effectively *logs the splice* action! That´s why I
> though it was letting the traffic go trough. Also the debug logs
> from SSL show this:|
> ||2022/11/29 10:32:38.943 kid1| 83,5| PeekingPeerConnector.cc(273)
> *startTunneling: will tunnel instead of negotiating TLS* # Last line
> from previously attached logs||
> ||
> ||
> ||As far as I know this means *is getting to the TCP_TUNNEL, at that
> point it can not know anything about the internal status on the
> connection between client and host*. If not, *where I should be
> looking for this error? *Should try to review further the debug ssl
> logs to se if I fend something more useful? Maybe tcpdump? This
> could be just the end service failing on the request? Or is an error
> between Squid and the end sever?||
> ||
> ||
> ||If I understand right the request that fails is the fake connect
> and I need to understand why. Also note almost same config logged
> this as TCP_TUNNEL/200 on version 3.5. But as said before, I really
> not sure how to check, since that service is just an agent installed
> on some aws machines and don´t know how to reproduce this behavior.
> ||
> |
> |
> |
> |
> |
> |
> |
> |
> |Thanks again! Hope I answered fine since I didn´t get the answer email.
> |
>
>
> El mar, 29 nov 2022 a las 14:06, Gabriel Vilariño
> (<gvilarino6 at gmail.com <mailto:gvilarino6 at gmail.com>>) escribió:
>
> Just got it solved. Was caused because of checking default
> access.log. Using a new file solves all the problems.
>
> However, in this context, what means TCP_TUNNEL/500? is it
> because the TLS handshake? I would like to know if it is
> tunneling correctly or is having some trouble (not easy to test
> right now).
>
> Thanks!
>
> El mar, 29 nov 2022 a las 13:16, Gabriel Vilariño
> (<gvilarino6 at gmail.com <mailto:gvilarino6 at gmail.com>>) escribió:
>
> Hi there,
>
> I am setting up an HTTP/HTTPS transparent proxy, meaning the
> clients not need any certificates for using the proxy. This
> works fine on version 3.5 of Squid, however after upgrading
> to 5.7 the behavior of the logs change:
>
> 1669723133.174 8037 10.184.19.220 TCP_TUNNEL/500 6207
> CONNECT 54.240.253.128:443 <http://54.240.253.128:443> -
> ORIGINAL_DST/54.240.253.128 <http://54.240.253.128> -
>
> Directive: logformat squid %ts.%03tu %>a %Ss/%03>Hs
> %ssl::>sni %ssl::bump_mode ssl::>cert_subject %<ru
>
> On version 3.5 we were obtaining the domain name (an aws
> service) in the place of ORIGINAL_DST. Also now we are not
> seeing any information about the bump_mode in no one of the
> connections while before we were seeing it. One could trough
> that it could be because of the /500 message, however on a
> 200 one to docs.ansble.com <http://docs.ansble.com> it also
> don´t show any data on the sni field:
>
> 1669723513.363 332 10.184.19.220 TCP_TUNNEL/200 38192
> CONNECT 104.26.0.234:443 <http://104.26.0.234:443> -
> ORIGINAL_DST/104.26.0.234 <http://104.26.0.234> -
>
> Also the 500 looks to come from the squid not understanding
> something on the SSL negotiation:
>
> |2022/11/29 10:32:38.943 kid1| 83,4| support.cc(248)
> check_domain: Verifying server domain
> arsenal.us-west-2.amazonaws.com
> <http://arsenal.us-west-2.amazonaws.com> to certificate
> name/subjectAltName arsenal.us-west-2.amazonaws.com
> <http://arsenal.us-west-2.amazonaws.com> ||2022/11/29
> 10:32:38.943 kid1| 83,5| bio.cc(136) read: FD 28 read 347 <=
> 65535 ||2022/11/29 10:32:38.943 kid1| 83,5| Io.cc(91)
> Handshake: -1/0 for TLS connection 0x558453168970 over
> conn99 local=SQUID-INTERNAL-IP:44264
> remote=54.240.251.223:443 <http://54.240.251.223:443>
> ORIGINAL_DST FD 28 flags=1 ||2022/11/29 10:32:38.943 kid1|
> 83,2| PeerConnector.cc(256) handleNegotiationResult: ERROR:
> failure while establishing TLS connection on FD:
> 280x558452b68980*1 ||2022/11/29 10:32:38.943 kid1| 83,5|
> NegotiationHistory.cc(85) retrieveNegotiatedInfo: SSL
> connection info on FD 28 SSL version NONE/0.0 negotiated
> cipher ||2022/11/29 10:32:38.943 kid1| 83,5|
> PeekingPeerConnector.cc(84) checkForPeekAndSpliceMatched:
> Will check for peek and splice on FD 28 ||2022/11/29
> 10:32:38.943 kid1| 83,5| PeekingPeerConnector.cc(395)
> serverCertificateVerified: HTTPS server CN:
> arsenal.us-west-2.amazonaws.com
> <http://arsenal.us-west-2.amazonaws.com> bumped: conn99
> local=SQUID-INTERNAL-IP:44264 remote=54.240.251.223:443
> <http://54.240.251.223:443> ORIGINAL_DST FD 28 flags=1 |
> |2022/11/29 10:32:38.943 kid1| 83,5|
> PeekingPeerConnector.cc(273) startTunneling: will tunnel
> instead of negotiating TLS|
>
> It is clear that in creates the tunnel so the 500 probably
> is that error? Why the bump/sni messages never log anything
> (according to
> https://wiki.squid-cache.org/Features/SslPeekAndSplice
> <https://wiki.squid-cache.org/Features/SslPeekAndSplice>
> they should log splice not -). This is the config for bumping:
>
>
>
> acl step1 at_step SslBump1
> acl step2 at_step SslBump2
> acl step3 at_step SslBump3
> ssl_bump peek step1 all
>
> .... http rules ...
>
> acl allowed_https_sites ssl::server_name_regex
> "/etc/squid/whitelist.txt"
> ssl_bump peek step2 allowed_https_sites
> ssl_bump splice step3 allowed_https_sites
> ssl_bump terminate step2 all
>
>
>
>
> Ip tables simply redirect:
>
> iptables -t nat -A PREROUTING -p tcp --dport 80 -j REDIRECT
> --to-port 3129
> iptables -t nat -A PREROUTING -p tcp --dport 443 -j REDIRECT
> --to-port 3130 # https port on squid: https_port 3130
> intercept ssl-bump cert=/etc/squid/ssl/dummy.pem
>
> Thanks in advance, i have been trying this for a week now
> reading a lot of posts but not luck...
>
>
> _______________________________________________
> squid-users mailing list
> squid-users at lists.squid-cache.org
> http://lists.squid-cache.org/listinfo/squid-users
More information about the squid-users
mailing list