Score:1

stunnel + squid = 1 request for 5minutes (rest connection reset by peer)

us flag

tl;dr;

Configuration with stunnel on client which connect to squid proxy with x509 certificate authentication work only for one request per 5minutes. Scenario:

  • Squid and stunnel configured and started
  • wget configured to use localhost as proxy (stunnel)
  • Only 1 request (e.g. wget https://github.com) per 5 minutes (or stunnel restart) work rest got connection reset by peer
  • Using raw connection e.g openssl s_client -key -cert -connect using direct communication to squid works properly

Description

I am setting up architecture of stunnel installed on client which leads to squid proxy with x509 Certificate authentication.

Client setup stunnel with his certificate which connects to squid, then set up HTTP_PROXY to aim for stunnel endpoint at localhost.

Trust path is correctly configured on each side, so both squid trust certificates from client, and client trust squid's certificate on each level - Root CA and intermediate CA.

Configuration of stunnel:

sslVersion=TLSv1.2
output=/var/log/stunnel4/stunnel.log
[squid-gcp]
cert = /etc/letsencrypt/live/test.internal/fullchain.pem
key = /etc/letsencrypt/live/test.internal/privkey.pem
CAFile = /usr/local/share/ca-certificates/root.crt
client = yes
debug=7
accept = 127.0.0.1:3128
connect = squid.internal:3128

Configuration of squid

acl localnet src 0.0.0.1-0.255.255.255  # RFC 1122 "this" network (LAN)
acl localnet src 10.0.0.0/8             # RFC 1918 local private network (LAN)
acl localnet src 100.64.0.0/10          # RFC 6598 shared address space (CGN)
acl localnet src 169.254.0.0/16         # RFC 3927 link-local (directly plugged) machines
acl localnet src 172.16.0.0/12          # RFC 1918 local private network (LAN)
acl localnet src 192.168.0.0/16         # RFC 1918 local private network (LAN)
acl localnet src fc00::/7               # RFC 4193 local private network range
acl localnet src fe80::/10              # RFC 4291 link-local (directly plugged) machines
acl SSL_ports port 443
acl Safe_ports port 80          # http
acl Safe_ports port 21          # ftp
acl Safe_ports port 443         # https
acl Safe_ports port 70          # gopher
acl Safe_ports port 210         # wais
acl Safe_ports port 1025-65535  # unregistered ports
acl Safe_ports port 280         # http-mgmt
acl Safe_ports port 488         # gss-http
acl Safe_ports port 591         # filemaker
acl Safe_ports port 777         # multiling http
acl CONNECT method CONNECT
acl cert user_cert CN test.internal
http_access allow localhost manager
http_access deny manager
http_access deny to_localhost
http_access allow cert
http_access allow localhost
http_access allow servicedesk
http_access deny all
https_port 3128 tls-cert=/etc/letsencrypt/live/squid.internal/cert.pem tls-key=/etc/letsencrypt/live/squid.internal/privkey.pem options=NO_SSLv3:NO_TLSv1:NO_TLSv1_1:NO_TLSv1_3:NO_TICKET clientca=/usr/local/share/ca-certificates/root.crt cafile=/usr/local/share/ca-certificates/root.crt tls-default-ca=off
client_idle_pconn_timeout 5 minutes
client_persistent_connections on
pconn_lifetime 0
logformat squidtls %tl %ts.%03tu %6tr %>a %Ss/%03>Hs %<st %rm %ru %[un %Sh/%<a %mt "%ssl::>cert_subject"
access_log daemon:/var/log/squid/access-tls.log squidtls
cache deny all
cache_dir null /tmp
shutdown_lifetime 1 seconds
coredump_dir /var/cache/squid

Now what happens on client, having configured properly HTTPS_PROXY=localhost:3128, first request through squid is accepted, and next are rejected with connection reset by peer. After 5minutes or stunnel restart next request is handled properly.

Logs from stunnel when this occure, first reqeust ok, second one rejected:

2021.07.07 14:27:59 LOG7[0]: Service [squid-gcp] started
2021.07.07 14:27:59 LOG7[0]: Setting local socket options (FD=3)
2021.07.07 14:27:59 LOG7[0]: Option TCP_NODELAY set on local socket
2021.07.07 14:27:59 LOG5[0]: Service [squid-gcp] accepted connection from 127.0.0.1:50142
2021.07.07 14:27:59 LOG6[0]: s_connect: connecting 100.112.0.62:3128
2021.07.07 14:27:59 LOG7[0]: s_connect: s_poll_wait 100.112.0.62:3128: waiting 10 seconds
2021.07.07 14:27:59 LOG7[0]: FD=6 events=0x2001 revents=0x0
2021.07.07 14:27:59 LOG7[0]: FD=11 events=0x2005 revents=0x0
2021.07.07 14:27:59 LOG5[0]: s_connect: connected 100.112.0.62:3128
2021.07.07 14:27:59 LOG5[0]: Service [squid-gcp] connected remote server from 100.112.0.63:50392
2021.07.07 14:27:59 LOG7[0]: Setting remote socket options (FD=11)
2021.07.07 14:27:59 LOG7[0]: Option TCP_NODELAY set on remote socket
2021.07.07 14:27:59 LOG7[0]: Remote descriptor (FD=11) initialized
2021.07.07 14:27:59 LOG6[0]: SNI: sending servername: squid.internal
2021.07.07 14:27:59 LOG6[0]: Peer certificate not required
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): before SSL initialization
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write client hello
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write client hello
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS read server hello
2021.07.07 14:27:59 LOG6[0]: Certificate verification disabled
2021.07.07 14:27:59 LOG6[0]: Certificate verification disabled
2021.07.07 14:27:59 LOG6[0]: Certificate verification disabled
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS read server certificate
2021.07.07 14:27:59 LOG6[0]: Client CA: O=GCP Internal CA, CN=GCP Internal CA Root CA
2021.07.07 14:27:59 LOG6[0]: Client CA: O=GCP Internal CA, CN=GCP Internal CA Intermediate CA
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS read server certificate request
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS read server done
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write client certificate
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write client key exchange
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write certificate verify
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write change cipher spec
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write finished
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS write finished
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS read change cipher spec
2021.07.07 14:27:59 LOG7[0]: TLS state (connect): SSLv3/TLS read finished
2021.07.07 14:27:59 LOG7[0]: New session callback
2021.07.07 14:27:59 LOG7[0]: Peer certificate was cached (2601 bytes)
2021.07.07 14:27:59 LOG6[0]: Session id: 383CDD4E8AA87AC2ED148172C025D1A5ECE0A1FF114362503BCDED36B9BB44B0
2021.07.07 14:27:59 LOG7[0]:      1 client connect(s) requested
2021.07.07 14:27:59 LOG7[0]:      1 client connect(s) succeeded
2021.07.07 14:27:59 LOG7[0]:      0 client renegotiation(s) requested
2021.07.07 14:27:59 LOG7[0]:      0 session reuse(s)
2021.07.07 14:27:59 LOG6[0]: TLS connected: new session negotiated
2021.07.07 14:27:59 LOG6[0]: TLSv1.2 ciphersuite: AES256-GCM-SHA384 (256-bit encryption)
2021.07.07 14:27:59 LOG7[0]: Compression: null, expansion: null
2021.07.07 14:27:59 LOG6[0]: Read socket closed (readsocket)
2021.07.07 14:27:59 LOG7[0]: Sending close_notify alert
2021.07.07 14:27:59 LOG7[0]: TLS alert (write): warning: close notify
2021.07.07 14:27:59 LOG6[0]: SSL_shutdown successfully sent close_notify alert
2021.07.07 14:27:59 LOG7[0]: TLS alert (read): warning: close notify
2021.07.07 14:27:59 LOG6[0]: TLS closed (SSL_read)
2021.07.07 14:27:59 LOG7[0]: Sent socket write shutdown
2021.07.07 14:27:59 LOG5[0]: Connection closed: 737 byte(s) sent to TLS, 234207 byte(s) sent to socket
2021.07.07 14:27:59 LOG7[0]: Remote descriptor (FD=11) closed
2021.07.07 14:27:59 LOG7[0]: Local descriptor (FD=3) closed
2021.07.07 14:27:59 LOG7[0]: Service [squid-gcp] finished (0 left)
2021.07.07 14:28:01 LOG7[1]: Service [squid-gcp] started
2021.07.07 14:28:01 LOG7[1]: Setting local socket options (FD=3)
2021.07.07 14:28:01 LOG7[1]: Option TCP_NODELAY set on local socket
2021.07.07 14:28:01 LOG5[1]: Service [squid-gcp] accepted connection from 127.0.0.1:50146
2021.07.07 14:28:01 LOG6[1]: s_connect: connecting 100.112.0.62:3128
2021.07.07 14:28:01 LOG7[1]: s_connect: s_poll_wait 100.112.0.62:3128: waiting 10 seconds
2021.07.07 14:28:01 LOG7[1]: FD=6 events=0x2001 revents=0x0
2021.07.07 14:28:01 LOG7[1]: FD=11 events=0x2005 revents=0x0
2021.07.07 14:28:01 LOG5[1]: s_connect: connected 100.112.0.62:3128
2021.07.07 14:28:01 LOG5[1]: Service [squid-gcp] connected remote server from 100.112.0.63:50396
2021.07.07 14:28:01 LOG7[1]: Setting remote socket options (FD=11)
2021.07.07 14:28:01 LOG7[1]: Option TCP_NODELAY set on remote socket
2021.07.07 14:28:01 LOG7[1]: Remote descriptor (FD=11) initialized
2021.07.07 14:28:01 LOG6[1]: SNI: sending servername: squid.internal
2021.07.07 14:28:01 LOG6[1]: Peer certificate not required
2021.07.07 14:28:01 LOG7[1]: TLS state (connect): before SSL initialization
2021.07.07 14:28:01 LOG7[1]: TLS state (connect): SSLv3/TLS write client hello
2021.07.07 14:28:01 LOG3[1]: SSL_connect: Peer suddenly disconnected
2021.07.07 14:28:01 LOG5[1]: Connection reset: 0 byte(s) sent to TLS, 0 byte(s) sent to socket
2021.07.07 14:28:01 LOG7[1]: Remote descriptor (FD=11) closed
2021.07.07 14:28:01 LOG7[1]: Local descriptor (FD=3) closed
2021.07.07 14:28:01 LOG7[1]: Service [squid-gcp] finished (0 left)

it clearly looks like first request TLS negotiation succeed while second one is not even started.

logs from squid access log:

07/Jul/2021:14:27:59 +0000 1625668079.646    496 100.112.0.63 TCP_TUNNEL/200 234207 CONNECT github.com:443 - HIER_DIRECT/140.82.121.4 - "/CN=test.internal"
07/Jul/2021:14:28:01 +0000 1625668081.958      0 100.112.0.63 NONE/000 0 NONE error:transaction-end-before-headers - HIER_NONE/- - "-"

Logs from cache:

2021/07/07 14:28:01 kid1| Error negotiating SSL connection on FD 11: error:00000001:lib(0):func(0):reason(1) (1/-1)

BONUS

When I try to use openssl s_client and then GET https://github.com like this:

openssl s_client -cert /etc/letsencrypt/live/test.internal/cert.pem -key /etc/letsencrypt/live/test.internal/privkey.pem -connect squid.internal:3128

each request is successful:

log from squid:

07/Jul/2021:14:33:24 +0000 1625668404.188    369 100.112.0.63 TCP_MISS/200 227308 GET https://github.com/ - HIER_DIRECT/140.82.121.4 text/html "/CN=test.internal"
07/Jul/2021:14:33:50 +0000 1625668430.041     25 100.112.0.63 TCP_MISS/200 227578 GET https://github.com/ - HIER_DIRECT/140.82.121.4 text/html "/CN=test.internal"
07/Jul/2021:14:33:55 +0000 1625668435.218     39 100.112.0.63 TCP_MISS/200 227580 GET https://github.com/ - HIER_DIRECT/140.82.121.4 text/html "/CN=test.internal"

I am loosing my mind with this problem. I would appreciate any help with this.

Tom Yan avatar
in flag
Are you making stunnel `connect = ` to the the address:port of the squid instance? IIRC that's not how stunnel is used. Rather you'll need to have stunnel running in server mode (i.e. without `client = yes`) on the remote host on another port, which is what stunnel `connect=` to. Then what goes to `accept = ` on the local side will be captured and forwarded by stunnel to the remote side.
Tom Yan avatar
in flag
Note that it might be possible to use squid as a server for stunnel, but it probably does not fit for your use case. Btw you should probably use `http_port` instead of `https_port` for the approach mentioned above. (Well, unless you want `wget` to use https proxy...double encryption? I'm not sure if `wget` actually supports https proxy like `curl` does though; seems like its `https_proxy` is just an alias to `http_proxy`; or in the sense of, "http proxy for your https connections"...)
us flag
hey @TomYan thanks for time put into make those comments! I want to make certificate based authentication to `squid` instance. If I make `stunnel` server instance on squid and then `connect` to `squid` on local host, I will have both source certificate and IP match localhost (I want it to be client both IP and certificate appear in logs) thats why I am using `https_port` as well. Problem here is that first request I made on client machine is valid while another are reseted after `client hello` by squid I believe there is something wrong with squid or stunnel conf but I cannot find what ;(
Score:0
my flag

Do successful requests actually succeed, or do they hang (maybe for other unrelated reasons)?

The interesting thing in your Squid configuration is that:

client_idle_pconn_timeout 5 minutes
client_persistent_connections on
pconn_lifetime 0

In other words, once a client connects to the proxy, a persistent connection is established and it closes it after 5 minutes of idle time.

Some possible solutions:

  • disabling client_persistent_connections. This essentially means every new TCP handshake is treated as if it was completely new, which may have an overall performance impact but should solve your problem

  • explicitly increasing the number of simultaneous connections from the same source IP that can be supported. You can do this by setting up an ACL with limitusercon maxconn 5 (or another number).

  • increasing the idle timeout to something much larger. This also has a performance impact (it keeps connections up and running for a lot of time, which can exhaust your resources).

Hope that helps.

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.