[squid-users] Logs not showing ssl::servername
Alex Rousskov
rousskov at measurement-factory.com
Tue Nov 29 21:15:36 UTC 2022
On 11/29/22 15:52, Gabriel Vilariño wrote:
> Here are the fixed logs:
> |1669726977.734 INTERNAL_CLIENT_IP TCP_TUNNEL/500
> arsenal.us-west-2.amazonaws.com splice /CN=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.
Yeah. Without more information, I cannot tell whether Squid logs the
wrong "500" status code or the wrong "splice" action in this case.
> 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*.
Correct.
> If not, *where I should be looking for this error?
My current bet is that either
* there is no error at all (but Squid logs the wrong 500 status code) OR
* there is an error (but you are looking at the wrong cache.log lines
that are not about the transaction that ended with an error).
FWIW, IMHO, you should not be looking for information in debugging
cache.log (ALL,3 or higher) because the latter is not designed for admin
use. Instead, you should:
* log %err_code/%err_detail to access.log and share that info (along
with any associated level-0/1 messages in cache.log).
* If that information is not sufficient, then you should share debugging
cache.log, so that folks who know "where to look for this error" can
look for it.
https://wiki.squid-cache.org/SquidFaq/BugReporting#Debugging_a_single_transaction
Said that, the answer to your question is: The misleading "will tunnel
instead of negotiating" line in an ALL,5+ debugging cache.log is
associated with a no-error successful-splicing-at-step3 transaction
outcome. If the same transaction ends with an error from client or
origin point of view, then that error usually happens _after_ Squid
splices the connections. In that case, Squid will not "see" that error.
HTH,
Alex.
> El mar, 29 nov 2022 a las 14:06, Gabriel Vilariño (<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