Hi again! Thanks for the info!
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: 22/11/30 07:51:39 kid1| Current Directory is / 2022/11/30 07:51:39 kid1| Creating missing swap directories 2022/11/30 07:51:39 kid1| No cache_dir stores are configured. 2022/11/30 07:51:39| Removing PID file (/run/squid.pid) 2022/11/30 07:51:39 kid1| Current Directory is / 2022/11/30 07:51:39 kid1| Starting Squid Cache version 5.7 for x86_64-pc-linux-gnu... 2022/11/30 07:51:39 kid1| Service Name: squid 2022/11/30 07:51:39 kid1| Process ID 64694 2022/11/30 07:51:39 kid1| Process Roles: worker 2022/11/30 07:51:39 kid1| With 1024 file descriptors available 2022/11/30 07:51:39 kid1| Initializing IP Cache... 2022/11/30 07:51:39 kid1| DNS Socket created at [::], FD 9 2022/11/30 07:51:39 kid1| DNS Socket created at 0.0.0.0, FD 10 2022/11/30 07:51:39 kid1| Adding nameserver 127.0.0.53 from /etc/resolv.conf 2022/11/30 07:51:39 kid1| Adding domain dev.ops.mitekcloud.local from /etc/resolv.conf 2022/11/30 07:51:39 kid1| helperOpenServers: Starting 5/32 'security_file_certgen' processes 2022/11/30 07:51:39 kid1| Logfile: opening log daemon:/var/log/squid/custom.log 2022/11/30 07:51:39 kid1| Logfile Daemon: opening log /var/log/squid/custom.log 2022/11/30 07:51:40 kid1| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec 2022/11/30 07:51:40 kid1| Store logging disabled 2022/11/30 07:51:40 kid1| Swap maxSize 0 + 262144 KB, estimated 20164 objects 2022/11/30 07:51:40 kid1| Target number of buckets: 1008 2022/11/30 07:51:40 kid1| Using 8192 Store buckets 2022/11/30 07:51:40 kid1| Max Mem size: 262144 KB 2022/11/30 07:51:40 kid1| Max Swap size: 0 KB 2022/11/30 07:51:40 kid1| Using Least Load store dir selection 2022/11/30 07:51:40 kid1| Current Directory is / 2022/11/30 07:51:40 kid1| Finished loading MIME types and icons. 2022/11/30 07:51:40 kid1| HTCP Disabled. 2022/11/30 07:51:40 kid1| Pinger socket opened on FD 27 2022/11/30 07:51:40 kid1| Squid plugin modules loaded: 0 2022/11/30 07:51:40 kid1| Adaptation support is off. 2022/11/30 07:51:40 kid1| Accepting HTTP Socket connections at conn13 local=[::]:3128 remote=[::] FD 23 flags=9 2022/11/30 07:51:40 kid1| Accepting NAT intercepted HTTP Socket connections at conn15 local=[::]:3129 remote=[::] FD 24 flags=41 2022/11/30 07:51:40 kid1| Accepting NAT intercepted SSL bumped HTTPS Socket connections at conn17 local=[::]:3130 remote=[::] FD 25 flags=41 2022/11/30 07:51:40| pinger: Initialising ICMP pinger ... 2022/11/30 07:51:40| pinger: ICMP socket opened. 2022/11/30 07:51:40| pinger: ICMPv6 socket opened 2022/11/30 07:51:41 kid1| storeLateRelease: released 0 objects 2022/11/30 07:52:09 kid1| Preparing for shutdown after 3 requests ... Starts ending the connections for shutdown, ends with next message... *2022/11/30 07:52:40 kid1| Squid Cache (Version 5.7): Exiting normally.* 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). Also if I needed, this is shared as an attachment? Thanks in advance! El mar, 29 nov 2022 a las 21:52, Gabriel Vilariño (<gvilari...@gmail.com>) escribió: > Thanks Alex! > > 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. 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 (<gvilari...@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 (<gvilari...@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 - ORIGINAL_DST/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 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 - ORIGINAL_DST/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 to certificate >>> name/subjectAltName 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 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 bumped: conn99 >>> local=SQUID-INTERNAL-IP:44264 remote=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 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@lists.squid-cache.org http://lists.squid-cache.org/listinfo/squid-users
