On 12/1/22 10:41, Gabriel Vilariño wrote:
About the motivation Alex, really the only thing that concerns me is the
strange log (TCP_TUNNEL and error 500).
Based on your debugging cache.log (thank you!) and superficial Squid
code analysis, I believe HTTP status code 500 in your use case is a
Squid bug. The transaction was actually successful.
Squid did not send a CONNECT response because your Squid intercepts
traffic (and the client does not send CONNECT requests and does not
expect CONNECT responses). Instead of logging a "-" for the sent HTTP
status code in this case, Squid logged 500. That is a bug.
Your next steps are summarized at
https://wiki.squid-cache.org/SquidFaq/AboutSquid#How_to_add_a_new_Squid_feature.2C_enhance.2C_of_fix_something.3F
HTH,
Alex.
On the usage side, I can not
tell if that call is working (going trough or not) since I don´t even
use that service. I was evaluating how Squid works and simply run in
that strange log. My final objective is to simply understand what´s
going on (tunnel or 500) but there is nothing critical that I have to fix.
Link: https://privfile.com/download.php?fid=6388c98c4ad19-MTQ5ODM=
<https://privfile.com/download.php?fid=6388c98c4ad19-MTQ5ODM=> is valid
for one day, password is "pepe" without "".
Thanks!
El mié, 30 nov 2022 a las 9:16, Gabriel Vilariño (<gvilarino6@xxxxxxxxx
<mailto:gvilarino6@xxxxxxxxx>>) escribió:
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
<http://arsenal.us-west-2.amazonaws.com> splice
/CN=arsenal.us-west-2.amazonaws.com
<http://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
(<gvilarino6@xxxxxxxxx <mailto:gvilarino6@xxxxxxxxx>>) 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@xxxxxxxxx <mailto:gvilarino6@xxxxxxxxx>>) 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@xxxxxxxxx <mailto:gvilarino6@xxxxxxxxx>>) 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@xxxxxxxxxxxxxxxxxxxxx
http://lists.squid-cache.org/listinfo/squid-users
_______________________________________________
squid-users mailing list
squid-users@xxxxxxxxxxxxxxxxxxxxx
http://lists.squid-cache.org/listinfo/squid-users
