Discussion:
[squid-users] squid reverse proxy (accelerator) for MS Exchange OWA
Vieri
2017-01-20 00:03:59 UTC
Permalink
Hi,

I'm trying to set up Squid as a reverse proxy on a host with IP address 10.215.144.91 so that web browsers can connect to it on port 443 and request pages from an OWA server at 10.215.144.21:443.

I have this in my squid.conf:

https_port 10.215.144.91:443 accel cert=/etc/ssl/squid/owa_cert.cer key=/etc/ssl/squid/owa_key.pem defaultsite=webmail2.mydomain.org

cache_peer 10.215.144.21 parent 443 0 no-query originserver login=PASS ssl sslcert=/etc/ssl/squid/client.cer sslkey=/etc/ssl/squid/client_key.pem ssloptions=ALL sslflags=DONT_VERIFY_PEER,DONT_VERIFY_DOMAIN name=owaServer
# cache_peer 10.215.144.21 parent 80 0 no-query originserver login=PASS front-end-https=on name=owaServer

acl OWA dstdomain webmail2.mydomain.org
cache_peer_access owaServer allow OWA
never_direct allow OWA

http_access allow OWA
http_access deny all
miss_access allow OWA
miss_access deny all

Note that if I comment out the "cache_peer parent 443" line above and uncomment the "cache_peer parent 80" line then the web browser client successfully connects and can view the OWA pages after logging in.

However, the connection fails if I use 443 between squid at 10.215.144.91 and the OWA backend at 10.215.144.21. The client views a Squid error page with an SSL handshake error.

Here's the cache log when I try to connect with a client:

2017/01/20 00:10:42.284 kid1| Error negotiating SSL on FD 16: error:00000000:lib(0):func(0):reason(0) (5/0/0)
2017/01/20 00:10:42.284 kid1| TCP connection to 10.215.144.21/443 failed
2017/01/20 00:10:42.285 kid1| 5,5| comm.cc(1038) comm_remove_close_handler: comm_remove_close_handler: FD 16, AsyncCall=0x80d93a00*2
2017/01/20 00:10:42.285 kid1| 9,5| AsyncCall.cc(56) cancel: will not call Ssl::PeerConnector::commCloseHandler [call453] because comm_remove_close_handler
2017/01/20 00:10:42.285 kid1| 17,4| AsyncCall.cc(93) ScheduleCall: PeerConnector.cc(742) will call FwdState::ConnectedToPeer(0x80d8b9f0, local=10.215.144.91:55948 remote=10.215.144.21:443 FD 16 flags=1, 0x809d49a0/0x809d49a0) [call451]
2017/01/20 00:10:42.285 kid1| 93,5| AsyncJob.cc(137) callEnd: Ssl::PeerConnector::negotiateSsl() ends job [ FD 16 job42]
2017/01/20 00:10:42.285 kid1| 83,5| PeerConnector.cc(58) ~PeerConnector: Peer connector 0x80d8b590 gone
2017/01/20 00:10:42.285 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0x80d8b5b4 type=Ssl::PeerConnector [job42]
2017/01/20 00:10:42.285 kid1| 17,4| AsyncCallQueue.cc(55) fireNext: entering FwdState::ConnectedToPeer(0x80d8b9f0, local=10.215.144.91:55948 remote=10.215.144.21:443 FD 16 flags=1, 0x809d49a0/0x809d49a0)
2017/01/20 00:10:42.285 kid1| 17,4| AsyncCall.cc(38) make: make call FwdState::ConnectedToPeer [call451]
2017/01/20 00:10:42.285 kid1| 17,3| FwdState.cc(415) fail: ERR_SECURE_CONNECT_FAIL "Service Unavailable"
https://webmail2.mydomain.org/Exchange2/
2017/01/20 00:10:42.285 kid1| TCP connection to 10.215.144.21/443 failed

I don't understand the "Service Unavailable" bit above.
I can connect just fine from the command line on the squid server at 10.215.144.91 as you can see below.

# wget --no-check-certificate -O - https://10.215.144.21
--2017-01-20 00:41:10-- https://10.215.144.21/
Connecting to 10.215.144.21:443... connected.
WARNING: cannot verify 10.215.144.21's certificate, issued by '/C=xx/ST=xx/O=xx/OU=xx/CN=xxx/emailAddress=***@xx.xxx':
Unable to locally verify the issuer's authority.
WARNING: certificate common name 'XYZ' doesn't match requested host name '10.215.144.21'.
HTTP request sent, awaiting response... 200 OK
Length: 1546 (1.5K) [text/html]

What can I try?

Thanks,

Vieri
Amos Jeffries
2017-01-20 09:13:19 UTC
Permalink
Post by Vieri
Hi,
I'm trying to set up Squid as a reverse proxy on a host with IP address 10.215.144.91 so that web browsers can connect to it on port 443 and request pages from an OWA server at 10.215.144.21:443.
https_port 10.215.144.91:443 accel cert=/etc/ssl/squid/owa_cert.cer key=/etc/ssl/squid/owa_key.pem defaultsite=webmail2.mydomain.org
cache_peer 10.215.144.21 parent 443 0 no-query originserver login=PASS ssl sslcert=/etc/ssl/squid/client.cer sslkey=/etc/ssl/squid/client_key.pem ssloptions=ALL sslflags=DONT_VERIFY_PEER,DONT_VERIFY_DOMAIN name=owaServer
# cache_peer 10.215.144.21 parent 80 0 no-query originserver login=PASS front-end-https=on name=owaServer
The ssloptions and sslflags values are bad for debugging.
* The ssloptions=ALL may be adding unknown new issues OWA does not like
from all the insecure things it turns on in Squids TLS handshake.
* The sslflags disabling verify actions is hiding from you any issues
Squid will have with the OWA handshake security settings.

Knowing what all that hidden stuff does is important to finding the
right fixes or workarounds.
Post by Vieri
acl OWA dstdomain webmail2.mydomain.org
cache_peer_access owaServer allow OWA
never_direct allow OWA
http_access allow OWA
http_access deny all
miss_access allow OWA
miss_access deny all
The miss_access is not useful. Your earlier *_access rules already
prevent the unwanted things happening.
Post by Vieri
Note that if I comment out the "cache_peer parent 443" line above and uncomment the "cache_peer parent 80" line then the web browser client successfully connects and can view the OWA pages after logging in.
However, the connection fails if I use 443 between squid at 10.215.144.91 and the OWA backend at 10.215.144.21. The client views a Squid error page with an SSL handshake error.
2017/01/20 00:10:42.284 kid1| Error negotiating SSL on FD 16: error:00000000:lib(0):func(0):reason(0) (5/0/0)
2017/01/20 00:10:42.284 kid1| TCP connection to 10.215.144.21/443 failed
2017/01/20 00:10:42.285 kid1| 5,5| comm.cc(1038) comm_remove_close_handler: comm_remove_close_handler: FD 16, AsyncCall=0x80d93a00*2
2017/01/20 00:10:42.285 kid1| 9,5| AsyncCall.cc(56) cancel: will not call Ssl::PeerConnector::commCloseHandler [call453] because comm_remove_close_handler
2017/01/20 00:10:42.285 kid1| 17,4| AsyncCall.cc(93) ScheduleCall: PeerConnector.cc(742) will call FwdState::ConnectedToPeer(0x80d8b9f0, local=10.215.144.91:55948 remote=10.215.144.21:443 FD 16 flags=1, 0x809d49a0/0x809d49a0) [call451]
2017/01/20 00:10:42.285 kid1| 93,5| AsyncJob.cc(137) callEnd: Ssl::PeerConnector::negotiateSsl() ends job [ FD 16 job42]
2017/01/20 00:10:42.285 kid1| 83,5| PeerConnector.cc(58) ~PeerConnector: Peer connector 0x80d8b590 gone
2017/01/20 00:10:42.285 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0x80d8b5b4 type=Ssl::PeerConnector [job42]
2017/01/20 00:10:42.285 kid1| 17,4| AsyncCallQueue.cc(55) fireNext: entering FwdState::ConnectedToPeer(0x80d8b9f0, local=10.215.144.91:55948 remote=10.215.144.21:443 FD 16 flags=1, 0x809d49a0/0x809d49a0)
2017/01/20 00:10:42.285 kid1| 17,4| AsyncCall.cc(38) make: make call FwdState::ConnectedToPeer [call451]
2017/01/20 00:10:42.285 kid1| 17,3| FwdState.cc(415) fail: ERR_SECURE_CONNECT_FAIL "Service Unavailable"
https://webmail2.mydomain.org/Exchange2/
2017/01/20 00:10:42.285 kid1| TCP connection to 10.215.144.21/443 failed
I don't understand the "Service Unavailable" bit above.
It is Squid telling the client it cannot proxy the request. Because the
cache_peer failed. Just one of the symptoms of whatever the problem is.

The key part is the "Error negotiating SSL on FD 16:
error:00000000:lib(0):func(0):reason(0) (5/0/0)"

Which is OpenSSL's very obtuse way of telling Squid "an error
rhappened". With no helpful details about what error it was.
Post by Vieri
I can connect just fine from the command line on the squid server at 10.215.144.91 as you can see below.
# wget --no-check-certificate -O - https://10.215.144.21
--2017-01-20 00:41:10-- https://10.215.144.21/
Connecting to 10.215.144.21:443... connected.
Unable to locally verify the issuer's authority.
WARNING: certificate common name 'XYZ' doesn't match requested host name '10.215.144.21'.
Firstly remove the ssloptions=ALL from your config.

Traffic should be able to go through at that point. But dont take that
as "working", the TLS layer is not in any way secure yet.
- if not try the front-end-https setting I mentioned earlier.

Then add a sslcafile= option to tell Squid the CA cert which signed the
OWA servers certificate.

Then remove the sslflags option. Traffic should stay working with that.

Amos
Vieri
2017-01-20 09:44:51 UTC
Permalink
----- Original Message -----
Post by Amos Jeffries
Firstly remove the ssloptions=ALL from your config.
Traffic should be able to go through at that point.
Thanks for the feedback.

I tried it again, but this time with a non-OWA IIS HTTPS server.

Here's the squid.conf:

https_port 10.215.144.91:35443 accel cert=/etc/ssl/squid/cert.cer key=/etc/ssl/squid/key.pem defaultsite=www.mydomain.org

cache_peer 10.215.144.66 parent 443 0 no-query originserver login=PASS ssl sslcert=/etc/ssl/squid/client.cer sslkey=/etc/ssl/squid/client_key.pem front-end-https=on name=httpsServer

acl HTTPSACL dstdomain www.mydomain.org
cache_peer_access httpsServer allow HTTPSACL
never_direct allow HTTPSACL

http_access allow HTTPSACL
http_access deny all

And here's the log when trying to connect from a web browser:

2017/01/20 10:31:06.724 kid1| 5,3| comm.cc(553) commSetConnTimeout: local=10.215.144.91:57753 remote=10.215.144.66:443 FD 14 flags=1 timeout 30
2017/01/20 10:31:06.724 kid1| 5,5| ModEpoll.cc(116) SetSelect: FD 14, type=1, handler=1, client_data=0x80cb86e0, timeout=0
2017/01/20 10:31:06.724 kid1| 93,5| AsyncJob.cc(152) callEnd: Ssl::PeerConnector status out: [ FD 14 job16]
2017/01/20 10:31:06.724 kid1| 93,5| AsyncCallQueue.cc(57) fireNext: leaving AsyncJob::start()
2017/01/20 10:31:06.724 kid1| 83,5| bio.cc(118) read: FD 14 read 0 <= 7
2017/01/20 10:31:06.724 kid1| Error negotiating SSL on FD 14: error:00000000:lib(0):func(0):reason(0) (5/0/0)
2017/01/20 10:31:06.724 kid1| TCP connection to 10.215.144.66/443 failed
2017/01/20 10:31:06.724 kid1| 5,5| comm.cc(1038) comm_remove_close_handler: comm_remove_close_handler: FD 14, AsyncCall=0x80cd0ff8*2
2017/01/20 10:31:06.724 kid1| 9,5| AsyncCall.cc(56) cancel: will not call Ssl::PeerConnector::commCloseHandler [call117] because comm_remove_close_handler
2017/01/20 10:31:06.724 kid1| 17,4| AsyncCall.cc(93) ScheduleCall: PeerConnector.cc(742) will call FwdState::ConnectedToPeer(0x80cae868, local=10.215.144.91:57753 remote=10.215.144.66:443 FD 14 flags=1, 0x80cd0ed0/0x80cd0ed0) [call115]
2017/01/20 10:31:06.724 kid1| 93,5| AsyncJob.cc(137) callEnd: Ssl::PeerConnector::negotiateSsl() ends job [ FD 14 job16]
2017/01/20 10:31:06.724 kid1| 83,5| PeerConnector.cc(58) ~PeerConnector: Peer connector 0x80cb86e0 gone
2017/01/20 10:31:06.724 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0x80cb8704 type=Ssl::PeerConnector [job16]
2017/01/20 10:31:06.725 kid1| 17,4| AsyncCallQueue.cc(55) fireNext: entering FwdState::ConnectedToPeer(0x80cae868, local=10.215.144.91:57753 remote=10.215.144.66:443 FD 14 flags=1, 0x80cd0ed0/0x80cd0ed0)
2017/01/20 10:31:06.725 kid1| 17,4| AsyncCall.cc(38) make: make call FwdState::ConnectedToPeer [call115]
2017/01/20 10:31:06.725 kid1| 17,3| FwdState.cc(415) fail: ERR_SECURE_CONNECT_FAIL "Service Unavailable"

I'm not getting any useful debug information, at least not the one I can understand.

Maybe I should rebuild Squid?

# squid -v
Squid Cache: Version 3.5.14
Service Name: squid
configure options: '--prefix=/usr' '--build=i686-pc-linux-gnu' '--host=i686-pc-linux-gnu' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--datadir=/usr/share' '--sysconfdir=/etc' '--localstatedir=/var/lib' '--disable-dependency-tracking' '--disable-silent-rules' '--libdir=/usr/lib' '--sysconfdir=/etc/squid' '--libexecdir=/usr/libexec/squid' '--localstatedir=/var' '--with-pidfile=/run/squid.pid' '--datadir=/usr/share/squid' '--with-logdir=/var/log/squid' '--with-default-user=squid' '--enable-removal-policies=lru,heap' '--enable-storeio=aufs,diskd,rock,ufs' '--enable-disk-io' '--enable-auth-basic=MSNT-multi-domain,NCSA,POP3,getpwnam,SMB,LDAP,PAM,RADIUS' '--enable-auth-digest=file,LDAP,eDirectory' '--enable-auth-ntlm=smb_lm' '--enable-auth-negotiate=kerberos,wrapper' '--enable-external-acl-helpers=file_userip,session,unix_group,wbinfo_group,LDAP_group,eDirectory_userip,kerberos_ldap_group' '--enable-log-daemon-helpers' '--enable-url-rewrite-helpers' '--enable-cache-digests' '--enable-delay-pools' '--enable-eui' '--enable-icmp' '--enable-follow-x-forwarded-for' '--with-large-files' '--disable-strict-error-checking' '--disable-arch-native' '--with-ltdl-includedir=/usr/include' '--with-ltdl-libdir=/usr/lib' '--with-libcap' '--enable-ipv6' '--disable-snmp' '--with-openssl' '--with-nettle' '--with-gnutls' '--enable-ssl-crtd' '--disable-ecap' '--disable-esi' '--enable-htcp' '--enable-wccp' '--enable-wccpv2' '--enable-linux-netfilter' '--with-mit-krb5' '--without-heimdal-krb5' 'build_alias=i686-pc-linux-gnu' 'host_alias=i686-pc-linux-gnu' 'CC=i686-pc-linux-gnu-gcc' 'CFLAGS=-O2 -march=i686 -pipe' 'LDFLAGS=-Wl,-O1 -Wl,--as-needed' 'CXXFLAGS=-O2 -march=i686 -pipe' 'PKG_CONFIG_PATH=/usr/lib/pkgconfig'

Thanks,

Vieri
Amos Jeffries
2017-01-20 10:07:54 UTC
Permalink
Post by Vieri
----- Original Message -----
From: Amos Jeffries
Post by Amos Jeffries
Firstly remove the ssloptions=ALL from your config.
Traffic should be able to go through at that point.
Thanks for the feedback.
I tried it again, but this time with a non-OWA IIS HTTPS server.
<snip>
Post by Vieri
I'm not getting any useful debug information, at least not the one I can understand.
Maybe I should rebuild Squid?
You could try with a newer Squid version since the bio.cc code might be
making something else happen in 3.5.23. If that still fails the 4.0 beta
has different logic and far better debug info in this area.

Amos
Vieri
2017-01-22 23:02:50 UTC
Permalink
----- Original Message -----
Post by Amos Jeffries
You could try with a newer Squid version since the bio.cc code might be
making something else happen in 3.5.23. If that still fails the 4.0 beta
has different logic and far better debug info in this area.
I tried 3.5.23 and I finally got a clear hint.
Basically, I was missing sslcafile.
My setup works now.

Thanks

Vieri
Vieri
2017-01-24 08:02:05 UTC
Permalink
----- Original Message -----
Post by Amos Jeffries
You could try with a newer Squid version since the bio.cc code might be
making something else happen in 3.5.23. If that still fails the 4.0 beta
has different logic and far better debug info in this area.
Hi again,

I'm still struggling with my reverse proxy setup. As stated in my previous post, after upgrading to squid 3.5.23, I successfully connected with a web browser FROM an external location (internet) to the Squid proxy which in turn connected via https on port 443 to an internal MS Exchange OWA server.
Apparently, all I was missing was sslcafile in cache_peer.

However, I'm now trying (but failing) to do the same thing locally. I'm connecting from a web browser in the local network to the Squid reverse proxy and that, in turn, is trying to connect to the OWA server on the same LAN.
I set up the client's hosts file to point webmail2.mydomain.org to Squid's IP address.

Here's squid.conf:

https_port 0.0.0.0:443 accel cert=/etc/ssl/squid/accel_cert.cer key=/etc/ssl/squid/accel_key.pem defaultsite=webmail2.mydomain.org

cache_peer 10.215.144.21 parent 443 0 no-query originserver login=PASS ssl sslcert=/etc/ssl/squid/client_cert.cer sslkey=/etc/ssl/squid/client_key.pem sslcafile=/etc/ssl/CA/cacert.pem front-end-https=on name=owaServer

acl OWA dstdomain webmail2.mydomain.org
cache_peer_access owaServer allow OWA
never_direct allow OWA

http_access allow OWA
http_access deny all

Since it didn't work with Squid 3, I updated to the latest Squid 4 version.

I get this in the log when trying to connect:

2017/01/24 07:58:57.075 kid1| 83,5| bio.cc(116) write: FD 18 wrote 312 <= 312
2017/01/24 07:58:57.075 kid1| 83,5| bio.cc(139) read: FD 18 read -1 <= 65535
2017/01/24 07:58:57.076 kid1| 83,5| bio.cc(144) read: error: 11 ignored: 1
2017/01/24 07:58:57.076 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=10.215.144.92:56236 remote=10.215.144.21:443 FD 18 flags=1 timeout 30
2017/01/24 07:58:57.076 kid1| 5,5| ModEpoll.cc(117) SetSelect: FD 18, type=1, handler=1, client_data=0xb7cf8be8, timeout=0
2017/01/24 07:58:57.076 kid1| 93,5| AsyncJob.cc(154) callEnd: Security::BlindPeerConnector status out: [ FD 18 job60]
2017/01/24 07:58:57.076 kid1| 93,5| AsyncCallQueue.cc(57) fireNext: leaving AsyncJob::start()
2017/01/24 07:58:57.076 kid1| 83,5| bio.cc(139) read: FD 18 read 0 <= 65535
2017/01/24 07:58:57.076 kid1| 83,5| NegotiationHistory.cc(83) retrieveNegotiatedInfo: SSL connection info on FD 18 SSL version NONE/0.0 negotiated cipher
2017/01/24 07:58:57.076 kid1| Error negotiating SSL on FD 18: error:00000000:lib(0):func(0):reason(0) (5/0/0)
2017/01/24 07:58:57.076 kid1| TCP connection to 10.215.144.21/443 failed
2017/01/24 07:58:57.077 kid1| 15,2| neighbors.cc(1246) peerConnectFailedSilent: TCP connection to 10.215.144.21/443 dead

# squid -v
Squid Cache: Version 4.0.17-20170122-r14968
Service Name: squid
configure options: '--prefix=/usr' '--build=i686-pc-linux-gnu' '--host=i686-pc-linux-gnu' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--datadir=/usr/share' '--sysconfdir=/etc' '--localstatedir=/var/lib' '--disable-dependency-tracking' '--disable-silent-rules' '--docdir=/usr/share/doc/squid-4.0.17_beta_p2017012214968' '--htmldir=/usr/share/doc/squid-4.0.17_beta_p2017012214968/html' '--libdir=/usr/lib' '--sysconfdir=/etc/squid' '--libexecdir=/usr/libexec/squid' '--localstatedir=/var' '--with-pidfile=/run/squid.pid' '--datadir=/usr/share/squid' '--with-logdir=/var/log/squid' '--with-default-user=squid' '--enable-removal-policies=lru,heap' '--enable-storeio=aufs,diskd,rock,ufs' '--enable-disk-io' '--enable-auth-basic=NCSA,POP3,getpwnam,SMB,LDAP,PAM,RADIUS' '--enable-auth-digest=file,LDAP,eDirectory' '--enable-auth-ntlm=SMB_LM' '--enable-auth-negotiate=kerberos,wrapper' '--enable-external-acl-helpers=file_userip,session,unix_group,wbinfo_group,LDAP_group,eDirectory_userip,kerberos_ldap_group' '--enable-log-daemon-helpers' '--enable-url-rewrite-helpers' '--enable-cache-digests' '--enable-delay-pools' '--enable-eui' '--enable-icmp' '--enable-follow-x-forwarded-for' '--with-large-files' '--disable-strict-error-checking' '--disable-arch-native' '--with-ltdl-includedir=/usr/include' '--with-ltdl-libdir=/usr/lib' '--with-libcap' '--enable-ipv6' '--disable-snmp' '--with-openssl' '--with-nettle' '--with-gnutls' '--disable-ssl-crtd' '--disable-ecap' '--disable-esi' '--enable-htcp' '--enable-wccp' '--enable-wccpv2' '--enable-linux-netfilter' '--with-mit-krb5' '--without-heimdal-krb5' 'build_alias=i686-pc-linux-gnu' 'host_alias=i686-pc-linux-gnu' 'CC=i686-pc-linux-gnu-gcc' 'CFLAGS=-O2 -march=i686 -pipe' 'LDFLAGS=-Wl,-O1 -Wl,--as-needed' 'CXXFLAGS=-O2 -march=i686 -pipe' 'PKG_CONFIG_PATH=/usr/lib/pkgconfig'

# openssl version
OpenSSL 1.0.2j 26 Sep 2016

Unfortunately, Squid's or OpenSSL's log message isn't too informative, even in Squid 4.
Also, I'm not sure why the SSL version isn't picked up (NONE/0.0) but I don't think it changes anything.

What else can I try?

Thanks,

Vieri
Alex Rousskov
2017-01-24 18:41:54 UTC
Permalink
Post by Vieri
2017/01/24 07:58:57.076 kid1| 83,5| bio.cc(139) read: FD 18 read 0 <= 65535
The peer at 10.215.144.21:443 accepted Squid connection and then closed
it, probably before sending anything to Squid (you did not show enough
FD 18 history to confirm that with certainty, but it is likely).
Post by Vieri
2017/01/24 07:58:57.076 kid1| 83,5| NegotiationHistory.cc(83) retrieveNegotiatedInfo: SSL connection info on FD 18 SSL version NONE/0.0 negotiated cipher
Nothing was negotiated.
Post by Vieri
2017/01/24 07:58:57.076 kid1| Error negotiating SSL on FD 18: error:00000000:lib(0):func(0):reason(0) (5/0/0)
More-or-less confirms the above -- an SSL-violating end of TCP connection.
Post by Vieri
2017/01/24 07:58:57.076 kid1| TCP connection to 10.215.144.21/443 failed
2017/01/24 07:58:57.077 kid1| 15,2| neighbors.cc(1246) peerConnectFailedSilent: TCP connection to 10.215.144.21/443 dead
More echoes of the same error.
Post by Vieri
Also, I'm not sure why the SSL version isn't picked up (NONE/0.0)
Probably because the server did not send its SSL version to Squid.
Post by Vieri
What else can I try?
I would start by capturing TCP packets between Squid and the server in
question to confirm that the server (a) receives SSL ClientHello from
Squid and (b) closes the connection before sending SSL ServerHello to Squid.

If that is confirmed, you could interrogate the server about its
decision to close the connection. For example, it may not like the
ciphers offered by Squid. Establishing similar SSL connections from
Squid IP address to the server using OpenSSL command-line client may
help triage this further.


HTH,

Alex.
Vieri
2017-01-25 07:45:25 UTC
Permalink
----- Original Message -----
Post by Alex Rousskov
The peer at 10.215.144.21:443 accepted Squid connection and then closed
it, probably before sending anything to Squid
Thanks Alex.

I was lucky enough to try the following options in cache_peer:
ssloptions=NO_SSLv3,NO_SSLv2,NO_TLSv1_2,NO_TLSv1_1

This solves the issue. I understand it forces using TLS 1.0. In fact, the OWA origin server is a Windows server 2003 and only supports SSLv{2,3} and TLS 1.0.

It seems that Squid delegates SSL to OpenSSL and it's really too bad the latter can't be a little bit more verbose. I know this isn't the right list for this but couldn't OpenSSL simply have logged something regarding "unsupported TLS/SSL versions"? I'm only supposing that without the ssloptions I posted above, openssl will try TLS 1.2 and silently fail if that doesn't succeed.

Regardless, it all seems to be working now, even with Squid 3.5.14.

Thanks again,

Vieri
Alex Rousskov
2017-01-25 15:10:25 UTC
Permalink
From: Alex Rousskov
Post by Alex Rousskov
The peer at 10.215.144.21:443 accepted Squid connection and then closed
it, probably before sending anything to Squid
It seems that Squid delegates SSL to OpenSSL and it's really too bad
the latter can't be a little bit more verbose. I know this isn't the
right list for this but couldn't OpenSSL simply have logged something
regarding "unsupported TLS/SSL versions"?
If my reconstruction of the events was correct, then OpenSSL supplied as
much information as it could -- the "unsupported TLS/SSL versions" is
_your_ conclusion based on the information that neither Squid nor
OpenSSL had access to.
I'm only supposing that
without the ssloptions I posted above, openssl will try TLS 1.2 and
silently fail if that doesn't succeed.
It takes two to tango. How silent that failure is depends, in part, on
the server. AFAICT, your server was 100% silent about the reason behind
its abrupt connection closure, and OpenSSL correctly declined to
speculate about those reasons due to lack of info. From OpenSSL/client
point of view, it could have been anything from an unsupported TLS
version to a crashed server.

Glad you figured it out!

Alex.
Vieri
2017-01-26 10:16:13 UTC
Permalink
----- Original Message -----
Post by Alex Rousskov
If my reconstruction of the events was correct, then OpenSSL supplied as
much information as it could -- the "unsupported TLS/SSL versions" is
_your_ conclusion based on the information that neither Squid nor
OpenSSL had access to.
Post by Vieri
I'm only supposing that
without the ssloptions I posted above, openssl will try TLS 1.2 and
silently fail if that doesn't succeed.
It takes two to tango. How silent that failure is depends, in part, on
the server. AFAICT, your server was 100% silent about the reason behind
its abrupt connection closure, and OpenSSL correctly declined to
speculate about those reasons due to lack of info. From OpenSSL/client
point of view, it could have been anything from an unsupported TLS
version to a crashed server.
Thanks for taking the time to explain. I understand the point you make but I'm still a bit scepticle, probably due to my lack of knowledge in this domain.

I haven't read the RFCs for TLSv1*, SSLv*, etc. However, let's try to give a simple and straightforward example, just to clear things up. Suppose you (the client) meet someone (the server) and ask her/him out. That person can turn away and refuse your proposal without saying a word so you'll never know the reason. That's what you explained and I get that. However, you must "obviously" know what you told that person. Maybe it's not that "obvious" in the case of Squid & OpenSSL, but I'm guessing that it should be possible for Squid to tell OpenSSL to report what it actually said to the server without the need for an admin to do a traffic dump and analysis.

Let's take this simple example into consideration where I use cURL to connect to the same MS Exchange server:

# curl -k -v https://10.215.144.21
* Rebuilt URL to: https://10.215.144.21/
* Trying 10.215.144.21...
* Connected to 10.215.144.21 (10.215.144.21) port 443 (#0)
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
* CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: /etc/ssl/certs
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* Unknown SSL protocol error in connection to 10.215.144.21:443
* Closing connection 0
curl: (35) Unknown SSL protocol error in connection to 10.215.144.21:443

Now that's clear. cURL tried to use TLS1.2 and failed. The nasty server didn't even say hello.

It's interesting to note that the following actually DOES give more information (unsupported protocol):

# curl --tlsv1.1 -k -v https://10.215.144.21/
* Trying 10.215.144.21...
* Connected to 10.215.144.21 (10.215.144.21) port 443 (#0)
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
* CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: /etc/ssl/certs
* TLSv1.1 (OUT), TLS header, Certificate Status (22):
* TLSv1.1 (OUT), TLS handshake, Client hello (1):
* error:14077102:SSL routines:SSL23_GET_SERVER_HELLO:unsupported protocol
* Closing connection 0
curl: (35) error:14077102:SSL routines:SSL23_GET_SERVER_HELLO:unsupported protocol


Of course, the following test succeeds:

# curl --tlsv1.0 -k -v https://10.215.144.21/
* Trying 10.215.144.21...
* Connected to 10.215.144.21 (10.215.144.21) port 443 (#0)
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
* CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: /etc/ssl/certs
* TLSv1.0 (OUT), TLS header, Certificate Status (22):
* TLSv1.0 (OUT), TLS handshake, Client hello (1):
* TLSv1.0 (IN), TLS handshake, Server hello (2):
* TLSv1.0 (IN), TLS handshake, Certificate (11):
* TLSv1.0 (IN), TLS handshake, Server finished (14):
* TLSv1.0 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.0 (OUT), TLS change cipher, Client hello (1):
* TLSv1.0 (OUT), TLS handshake, Finished (20):
* TLSv1.0 (IN), TLS change cipher, Client hello (1):
* TLSv1.0 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.0 / DES-CBC3-SHA


Now with the openssl command-line client:

# openssl s_client -connect 10.215.144.21:443 -tls1_2
CONNECTED(00000003)
3072153276:error:1409E0E5:SSL routines:ssl3_write_bytes:ssl handshake failure:s3_pkt.c:656:


# openssl s_client -connect 10.215.144.21:443 -tls1_1
CONNECTED(00000003)
3072530108:error:1408F10B:SSL routines:SSL3_GET_RECORD:wrong version number:s3_pkt.c:362:


...and it obviously works with -tls1.

I haven't looked at the source code but I guess Squid uses the OpenSSL library.

I searched the Squid log above and below these lines:

2017/01/24 17:20:28.997 kid1| 83,5| NegotiationHistory.cc(83) retrieveNegotiatedInfo: SSL connection info on FD 18 SSL version NONE/0.0 negotiated cipher
2017/01/24 17:20:28.997 kid1| Error negotiating SSL on FD 18: error:00000000:lib(0):func(0):reason(0) (5/0/0)
2017/01/24 17:20:28.997 kid1| TCP connection to 10.215.144.21/443 failed


However, I haven't found any hint of what the client (cache_peer) tried to offer.

Maybe if Squid gets an SSL negotiation error with no apparent reason then it might need to retry connecting by being more explicit, just like in my cURL and openssl binary examples above.


I used the latest Squid 4 beta by the way.

I would have understood earlier the reason of the connection failure if Squid/OpenSSL had logged how they were actually hitting on the server.

Anyway, it's not a big deal now that I know what to do if this kind of connection issue comes back up. It could be useful to others though if the logging could be a tad more verbose or if Squid could retry connections by explictly specifying protocols (and logging them).

Thanks,

Vieri
Alex Rousskov
2017-01-26 18:18:01 UTC
Permalink
Post by Vieri
I'm guessing that it
should be possible for Squid to tell OpenSSL to report what it
actually said to the server without the need for an admin to do a
traffic dump and analysis.
Your are correct, but, in most cases, it is a lot easier to dump and
analyze traffic than to ask OpenSSL inside Squid to report what it
actually said. This is, in part, Squid's own fault, but OpenSSL does not
make it easy either. More on that below at (**).
Post by Vieri
# curl -k -v https://10.215.144.21
* Rebuilt URL to: https://10.215.144.21/
* Trying 10.215.144.21...
* Connected to 10.215.144.21 (10.215.144.21) port 443 (#0)
* ALPN, offering http/1.1
* CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: /etc/ssl/certs
* Unknown SSL protocol error in connection to 10.215.144.21:443
* Closing connection 0
curl: (35) Unknown SSL protocol error in connection to 10.215.144.21:443
Now that's clear. cURL tried to use TLS1.2 and failed. The nasty server didn't even say hello.
Please note that the information you see above details what Curl did,
not what OpenSSL did.

(**) Squid prints many similar details as well, but because Squid
generally deals with many concurrent transactions over a long time, and
does a lot more than Curl does, those details are not as easy to
find/isolate in Squid debugging logs. You found some of them. Again,
Squid could do a lot better in this area, but nobody is working on that
right now AFAIK, and even my attempts to form consensus on how this
should be done have failed so far.
* If the server sent nothing, then Curl gave you potentially incorrect
information (i.e., Curl is just _guessing_ what went wrong).

* If the server sent something, then either Squid situation was
different or I did not see that additional info in the logs you have
posted.

Based on everything I have seen so far, it is probably the former -- the
server sent nothing.
Post by Vieri
I haven't looked at the source code but I guess Squid uses the OpenSSL library.
Yes, in your case, it does.
Post by Vieri
However, I haven't found any hint of what the client (cache_peer) tried to offer.
Cache_peer is not the client here, but yes, see (**) above.
Post by Vieri
Maybe if Squid gets an SSL negotiation error with no apparent reason
then it might need to retry connecting by being more explicit, just
like in my cURL and openssl binary examples above.
Sorry, I do not know what "retry connecting by being more explicit"
means. AFAICT, neither Curl nor s_client tried reconnecting in your
examples. Also, an appropriate default for a command-line client is
often a bad default for a proxy. It is complicated.
Post by Vieri
I would have understood earlier the reason of the connection failure
if Squid/OpenSSL had logged how they were actually hitting on the
server.
Agreed.
Post by Vieri
Anyway, it's not a big deal now that I know what to do if this kind
of connection issue comes back up. It could be useful to others
though if the logging could be a tad more verbose or if Squid could
retry connections by explictly specifying protocols (and logging
them).
Agreed in general, but the devil is in the details. Improving this is
difficult, and nobody is working on it at the moment AFAIK.

http://wiki.squid-cache.org/SquidFaq/AboutSquid#How_to_add_a_new_Squid_feature.2C_enhance.2C_of_fix_something.3F


Cheers,

Alex.
Vieri
2017-01-27 08:31:05 UTC
Permalink
----- Original Message -----
Post by Alex Rousskov
Post by Vieri
It's interesting to note that the following actually DOES give more information (unsupported
protocol):>
* If the server sent nothing, then Curl gave you potentially incorrect
information (i.e., Curl is just _guessing_ what went wrong).
I never tried telling Squid to use TLS 1.1 ONLY so I never got to see Squid's log when using that protocol. I'm supposing I would have seen the same thing in Squid as I've seen it with CURL.
So I'm sure Squid would log useful information for the sys admin but... (see below).
Post by Alex Rousskov
Post by Vieri
Maybe if Squid gets an SSL negotiation error with no apparent reason
then it might need to retry connecting by being more explicit, just
like in my cURL and openssl binary examples above.
Sorry, I do not know what "retry connecting by being more explicit"
means. AFAICT, neither Curl nor s_client tried reconnecting in your
examples. Also, an appropriate default for a command-line client is
often a bad default for a proxy. It is complicated.
Let me rephrase my point but please keep in mind that I have no idea how Squid actually behaves. Simply put, when Squid tries to connect for the first time, it will probably (I'm guessing here) try the most secure protcol known today (ie. TSL 1.2), or let OpenSSL decide by default which is probably the same. In my case, the server replies nothing. That would be like running:

# curl -k -v https://10.215.144.21
or
# openssl s_client -connect 10.215.144.21:443

They give me the same information as Squid's log... almost nothing.

So my point is, if that first connection fails and gives me nothing for TLS 1.2 (or whatever the default is), two things can happen: either the remote site is failing or it isn't supporting the protocol. Why not "try again" but this time by being more specific? It would be like doing something like this:

# openssl s_client -connect 10.215.144.21:443 || openssl s_client -connect 10.215.144.21:443 -tls1_1 || openssl s_client -connect 10.215.144.21:443 -tls1


Of course, this shouldn't be done each and every time it tries to connect because it would probably give performance issues. If Squid successfully connects with TSL 1.0 then it could "remember" that for later connections to the same peer. It could also forget it after a sensible timeout, in case the remote peer starts supporting a safer protocol.
Post by Alex Rousskov
Agreed in general, but the devil is in the details. Improving this is
difficult, and nobody is working on it at the moment AFAIK.
I can imagine it must be difficult...


Instead of improving the source code, maybe a FAQ or some doc related to "squid error negotiating SSL" which would describe what to try when the error message is a mere "handshake failure". In the end, it's as simple as setting ssloptions correctly (in my case, NO_SSLv3,NO_SSLv2,NO_TLSv1_2,NO_TLSv1_1). I know there could be many other reasons for such a failure but at least that would be a good starting point.


Or even better... if Squid detects an SSL handshake failure with no extra info like in my case, can't it simply log an extra string that would look something like "Failed to negotiate SSL for unknown reason. Try setting ssloptions (cache_peer) or options (https_port) with a combination of NO_SSLv2 NO_SSLv3
NO_TLSv1 NO_TLSv1_1 NO_TLSv1_2. Find out which SSL protocol is supported by the remote peer. If the connection still fails then you will need to analyze traffic with the peer to find out the reason."

In my case, that would have been enough info in Squid's log to fix the issue.

Thanks again.

Vieri
Amos Jeffries
2017-02-01 16:19:20 UTC
Permalink
----- Original Message ----- From: Alex Rousskov
Post by Alex Rousskov
Post by Vieri
It's interesting to note that the following actually DOES give
more information (unsupported
protocol):>
* If the server sent nothing, then Curl gave you potentially
incorrect information (i.e., Curl is just _guessing_ what went
wrong).
I never tried telling Squid to use TLS 1.1 ONLY so I never got to see
Squid's log when using that protocol. I'm supposing I would have seen
the same thing in Squid as I've seen it with CURL. So I'm sure Squid
would log useful information for the sys admin but... (see below).
Post by Alex Rousskov
Post by Vieri
Maybe if Squid gets an SSL negotiation error with no apparent
reason then it might need to retry connecting by being more
explicit, just like in my cURL and openssl binary examples
above.
Sorry, I do not know what "retry connecting by being more
explicit" means. AFAICT, neither Curl nor s_client tried
reconnecting in your examples. Also, an appropriate default for a
command-line client is often a bad default for a proxy. It is
complicated.
Let me rephrase my point but please keep in mind that I have no idea
how Squid actually behaves.
Let me pause you right there. What you describe is essentially how the
TLS protocol handshake is actually performed.
Simply put, when Squid tries to connect
for the first time, it will probably (I'm guessing here) try the most
secure protcol known today (ie. TSL 1.2), or let OpenSSL decide by
default which is probably the same.
That is exactly what happens.
In my case, the server replies
# curl -k -v https://10.215.144.21 or # openssl s_client -connect
10.215.144.21:443
They give me the same information as Squid's log... almost nothing.
So my point is, if that first connection fails and gives me nothing
either the remote site is failing or it isn't supporting the
protocol. Why not "try again" but this time by being more specific?
Several reasons.

Reason #1 is that the TLS protocol is a security protocol for securing a
single 'hop' (just one TCP connection). So ideally TLS details would not
be remembered at all, it's a dangerous thing in security to remember
details in the middleware.


Reason #2 is that Squid has passed on the 'terminate' signal to the
client (curl).

As far as Squid is concerned, there is no "again" connection. There is a
connection, which fails. The end.

There is a connection. Which fails. The end.

There is a connection. Which fails. The end.

... and so on. These connections may be from the same client, or
different ones. May be to same or different servers. They are
independent of each other and only TCP at this point.

The TLS setup/handshake parts never get far enough for there to be
anything to remember. Except that TCP connection failed.

Well, Squid does remember that and tries a different IP next time. Until
it runs out of IPs, then it resets its bad-ID memory with a new DNS
lookup and the cycle begins again.


NP: if you are interested you can see the GOOD/BAD flags on IPs in the
ipcache cache manager report (squidclient mgr:ipcache).
# openssl s_client -connect 10.215.144.21:443 || openssl s_client
-connect 10.215.144.21:443 -tls1_1 || openssl s_client -connect
10.215.144.21:443 -tls1
Which brings us to reason #3; downgrade attacks.

You may have heard of the POODLE attack. It is basically a middleware
(like Squid) forcing the other endpoint(s) to re-try with lower TLS
versions until a version is reached and cipher selected that the
attacker can decrypt or steal the keys from.

Squid (mostly) avoids the whole class of vulnerabilities by leaving the
fallback decisions to the client whenever it can.

Since the curl command only did the one request, that is all that
happened. No retry.


Amos
Yuri Voinov
2017-02-01 16:29:38 UTC
Permalink
I'm sorry to interrupt, gentlemen - but Microsoft does not use
certificate pinning in OWA?
Post by Amos Jeffries
----- Original Message ----- From: Alex Rousskov
Post by Alex Rousskov
Post by Vieri
It's interesting to note that the following actually DOES give
more information (unsupported
protocol):>
* If the server sent nothing, then Curl gave you potentially
incorrect information (i.e., Curl is just _guessing_ what went
wrong).
I never tried telling Squid to use TLS 1.1 ONLY so I never got to see
Squid's log when using that protocol. I'm supposing I would have seen
the same thing in Squid as I've seen it with CURL. So I'm sure Squid
would log useful information for the sys admin but... (see below).
Post by Alex Rousskov
Post by Vieri
Maybe if Squid gets an SSL negotiation error with no apparent
reason then it might need to retry connecting by being more
explicit, just like in my cURL and openssl binary examples
above.
Sorry, I do not know what "retry connecting by being more
explicit" means. AFAICT, neither Curl nor s_client tried
reconnecting in your examples. Also, an appropriate default for a
command-line client is often a bad default for a proxy. It is
complicated.
Let me rephrase my point but please keep in mind that I have no idea
how Squid actually behaves.
Let me pause you right there. What you describe is essentially how the
TLS protocol handshake is actually performed.
Simply put, when Squid tries to connect
for the first time, it will probably (I'm guessing here) try the most
secure protcol known today (ie. TSL 1.2), or let OpenSSL decide by
default which is probably the same.
That is exactly what happens.
In my case, the server replies
# curl -k -v https://10.215.144.21 or # openssl s_client -connect
10.215.144.21:443
They give me the same information as Squid's log... almost nothing.
So my point is, if that first connection fails and gives me nothing
either the remote site is failing or it isn't supporting the
protocol. Why not "try again" but this time by being more specific?
Several reasons.
Reason #1 is that the TLS protocol is a security protocol for securing a
single 'hop' (just one TCP connection). So ideally TLS details would not
be remembered at all, it's a dangerous thing in security to remember
details in the middleware.
Reason #2 is that Squid has passed on the 'terminate' signal to the
client (curl).
As far as Squid is concerned, there is no "again" connection. There is a
connection, which fails. The end.
There is a connection. Which fails. The end.
There is a connection. Which fails. The end.
... and so on. These connections may be from the same client, or
different ones. May be to same or different servers. They are
independent of each other and only TCP at this point.
The TLS setup/handshake parts never get far enough for there to be
anything to remember. Except that TCP connection failed.
Well, Squid does remember that and tries a different IP next time. Until
it runs out of IPs, then it resets its bad-ID memory with a new DNS
lookup and the cycle begins again.
NP: if you are interested you can see the GOOD/BAD flags on IPs in the
ipcache cache manager report (squidclient mgr:ipcache).
# openssl s_client -connect 10.215.144.21:443 || openssl s_client
-connect 10.215.144.21:443 -tls1_1 || openssl s_client -connect
10.215.144.21:443 -tls1
Which brings us to reason #3; downgrade attacks.
You may have heard of the POODLE attack. It is basically a middleware
(like Squid) forcing the other endpoint(s) to re-try with lower TLS
versions until a version is reached and cipher selected that the
attacker can decrypt or steal the keys from.
Squid (mostly) avoids the whole class of vulnerabilities by leaving the
fallback decisions to the client whenever it can.
Since the curl command only did the one request, that is all that
happened. No retry.
Amos
_______________________________________________
squid-users mailing list
http://lists.squid-cache.org/listinfo/squid-users
--
Bugs to the Future
Vieri
2017-02-02 13:05:02 UTC
Permalink
----- Original Message -----
Post by Amos Jeffries
Reason #1 is that the TLS protocol is a security protocol for securing a
single 'hop' (just one TCP connection). So ideally TLS details would not
be remembered at all, it's a dangerous thing in security to remember
details in the middleware.
Reason #2 is that Squid has passed on the 'terminate' signal to the
client (curl).
As far as Squid is concerned, there is no "again" connection. There is a
connection, which fails. The end.
Post by Vieri
# openssl s_client -connect 10.215.144.21:443 || openssl s_client
-connect 10.215.144.21:443 -tls1_1 || openssl s_client -connect
10.215.144.21:443 -tls1>
Which brings us to reason #3; downgrade attacks.
You may have heard of the POODLE attack.
Squid (mostly) avoids the whole class of vulnerabilities by leaving the
fallback decisions to the client whenever it can.
Thank you very much for explaining all this. It's quite clear now.
There's just one little thing that may be useful in the log, though.
I might be wrong or maybe everyone already knows what to try when they get a non-informative SSL handshake error but it would have helped me to get a "hint" from Squid telling me to try fiddling with the ssloptions and options flags. I realize now it's great if Squid follows the secure logic of "There is a connection, which fails. The end.", but whenever that happens (and the info is 0, only "handshake error") wouldn't it be safe to just print a hint line in the server's log?


Anyway, as I said before, I know what to do from now on so it's not a big deal. ;-)

Thanks again,

Vieri

Alex Rousskov
2017-01-20 15:59:31 UTC
Permalink
Post by Amos Jeffries
error:00000000:lib(0):func(0):reason(0) (5/0/0)"
Which is OpenSSL's very obtuse way of telling Squid "an error
rhappened". With no helpful details about what error it was.
Actually, this is Squid's very obtuse way of telling us that peer closed
the connection while violating the SSL protocol (i.e., a
protocol-violating EOF during an SSL_connect() network read).

OpenSSL error reporting is ugly indeed, but we should not blame it for
our own lack of code to render OpenSSL-supplied details in a
human-friendly way (or for losing critical information along the way).


Cheers,

Alex.
Loading...