ssh over stunnel hangs on second connection
cygwin@kosowsky.org
cygwin@kosowsky.org
Fri Feb 16 04:00:23 GMT 2024
matthew patton wrote at about 00:01:04 +0000 on Friday, February 16, 2024:
> can you turn stunnel debug up higher?also post your stunnel.conf?
It's already at debug=7 as you can see from the LOG7 in the snippet I
posted.
I will include the detailed client log below:
My client stunnel.conf is pretty simple
pid = /var/run/stunnel.pid
output = /var/log/stunnel.log
# https://www.stunnel.org/faq.html
# Potentially helps speed up connection
socket = r:TCP_NODELAY=1
socket = l:TCP_NODELAY=1
debug = 7
[ssh]
client=yes
accept = localhost:1234
connect = mydomain.com:443
verifyChain = yes
CAfile = /etc/stunnel/stunnel.crt
checkHost = mydomain.com
> Beyond that, why something this convoluted when you could use ssh port-forwarding by way of the remote Stunnel endpoint? Or use Stunnel as a SOCKS proxy and configure SSH client to connect that way?https://hamy.io/post/0013/how-to-setup-an-encrypted-socks-proxy-using-stunnel/
Well, I want to tunnel SSH over SSL/port 443 since this helps me punch
through various corporate firewalls -- it works well and is widely
recommended in various online FAQs.
Not sure in what way it is convoluted... the path is...
ssh -p 1234 ocalhost --> stunnel client -> remote:443 -> localhost:22 (sshd)
Am I missing something here?
-----------------------------------------------------------------------
Here is the detailed debug=7 log
#### stunnel startup:
2024.02.15 22:28:29 LOG6[ui]: Initializing inetd mode configuration
2024.02.15 22:28:29 LOG7[ui]: Clients allowed=1562
2024.02.15 22:28:29 LOG5[ui]: stunnel 5.71 on x86_64-pc-cygwin platform
2024.02.15 22:28:29 LOG5[ui]: Compiled with OpenSSL 3.0.11 19 Sep 2023
2024.02.15 22:28:29 LOG5[ui]: Running with OpenSSL 3.0.12 24 Oct 2023
2024.02.15 22:28:29 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,OCSP,PSK,SNI Auth:LIBWRAP
2024.02.15 22:28:29 LOG7[ui]: errno: (*__errno())
2024.02.15 22:28:29 LOG6[ui]: Initializing inetd mode configuration
2024.02.15 22:28:29 LOG5[ui]: Reading configuration from file /etc/stunnel/stunnel.conf
2024.02.15 22:28:29 LOG5[ui]: UTF-8 byte order mark not detected
2024.02.15 22:28:29 LOG5[ui]: FIPS mode disabled
2024.02.15 22:28:29 LOG6[ui]: Compression disabled
2024.02.15 22:28:29 LOG7[ui]: No PRNG seeding was required
2024.02.15 22:28:29 LOG6[ui]: Initializing service [ssh]
2024.02.15 22:28:29 LOG7[ui]: Initializing context [ssh]
2024.02.15 22:28:29 LOG6[ui]: stunnel default security level set: 2
2024.02.15 22:28:29 LOG7[ui]: Ciphers: HIGH:!aNULL:!SSLv2:!DH:!kDHEPSK
2024.02.15 22:28:29 LOG7[ui]: TLSv1.3 ciphersuites: TLS_AES_256_GCM_SHA384:TLS_AES_128_GCM_SHA256:TLS_CHACHA20_POLY1305_SHA256
2024.02.15 22:28:29 LOG7[ui]: TLS options: 0x2100000 (+0x0, -0x0)
2024.02.15 22:28:29 LOG6[ui]: Session resumption enabled
2024.02.15 22:28:29 LOG7[ui]: No certificate or private key specified
2024.02.15 22:28:29 LOG6[ui]: Configured trusted server CA: C=US, ST=MyState, L=MyCity, O=MyOrg, CN=mydomain.com, emailAddress=cert@mydomain.com
2024.02.15 22:28:29 LOG7[ui]: OCSP: Client OCSP stapling enabled
2024.02.15 22:28:29 LOG6[ui]: DH initialization skipped: client section
2024.02.15 22:28:29 LOG7[ui]: ECDH initialization
2024.02.15 22:28:29 LOG7[ui]: ECDH initialized with curves X25519:P-256:X448:P-521:P-384
2024.02.15 22:28:29 LOG5[ui]: Configuration successful
2024.02.15 22:28:29 LOG7[ui]: Deallocating deployed section defaults
2024.02.15 22:28:29 LOG7[ui]: Cleaning up context [stunnel]
2024.02.15 22:28:29 LOG7[ui]: Binding service [ssh]
2024.02.15 22:28:29 LOG7[ui]: Listening file descriptor created (FD=8)
2024.02.15 22:28:29 LOG7[ui]: Setting accept socket options (FD=8)
2024.02.15 22:28:29 LOG7[ui]: Option SO_REUSEADDR set on accept socket
2024.02.15 22:28:29 LOG6[ui]: Service [ssh] (FD=8) bound to ::1:1234
2024.02.15 22:28:29 LOG7[ui]: Listening file descriptor created (FD=10)
2024.02.15 22:28:29 LOG7[ui]: Setting accept socket options (FD=10)
2024.02.15 22:28:29 LOG7[ui]: Option SO_REUSEADDR set on accept socket
2024.02.15 22:28:29 LOG6[ui]: Service [ssh] (FD=10) bound to 127.0.0.1:1234
2024.02.15 22:28:29 LOG7[main]: Created pid file /var/run/stunnel.pid
2024.02.15 22:28:29 LOG7[per-second]: Per-second thread initialized
2024.02.15 22:28:29 LOG6[main]: Accepting new connections
2024.02.15 22:28:29 LOG7[per-day]: Per-day thread initialized
2024.02.15 22:28:29 LOG6[per-day]: Executing per-day jobs
2024.02.15 22:28:29 LOG6[per-day]: Per-day jobs completed in 0 seconds
2024.02.15 22:28:29 LOG7[per-day]: Waiting 86400 seconds
####First ssh connection
2024.02.15 22:29:04 LOG7[main]: Found 1 ready file descriptor(s)
2024.02.15 22:29:04 LOG7[main]: FD=4 events=0x1 revents=0x0
2024.02.15 22:29:04 LOG7[main]: FD=8 events=0x1 revents=0x1
2024.02.15 22:29:04 LOG7[main]: FD=10 events=0x1 revents=0x0
2024.02.15 22:29:04 LOG7[main]: Service [ssh] accepted (FD=3) from ::1:52049
2024.02.15 22:29:04 LOG7[0]: Service [ssh] started
2024.02.15 22:29:04 LOG7[0]: Setting local socket options (FD=3)
2024.02.15 22:29:04 LOG7[0]: Option TCP_NODELAY set on local socket
2024.02.15 22:29:04 LOG5[0]: Service [ssh] accepted connection from ::1:52049
2024.02.15 22:29:04 LOG6[0]: s_connect: connecting 123.123.123.123:443
2024.02.15 22:29:04 LOG7[0]: s_connect: s_poll_wait 123.123.123.123:443: waiting 10 seconds
2024.02.15 22:29:04 LOG7[0]: FD=6 events=0x1 revents=0x0
2024.02.15 22:29:04 LOG7[0]: FD=12 events=0x5 revents=0x0
2024.02.15 22:29:04 LOG5[0]: s_connect: connected 123.123.123.123:443
2024.02.15 22:29:04 LOG5[0]: Service [ssh] connected remote server from 10.0.0.205:52050
2024.02.15 22:29:04 LOG7[0]: Setting remote socket options (FD=12)
2024.02.15 22:29:04 LOG7[0]: Option TCP_NODELAY set on remote socket
2024.02.15 22:29:04 LOG7[0]: Remote descriptor (FD=12) initialized
2024.02.15 22:29:04 LOG6[0]: SNI: sending servername: mydomain.com
2024.02.15 22:29:04 LOG6[0]: Peer certificate required
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): before SSL initialization
2024.02.15 22:29:04 LOG7[0]: Initializing application specific data for session authenticated
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): SSLv3/TLS write client hello
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): SSLv3/TLS write client hello
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): SSLv3/TLS read server hello
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): TLSv1.3 read encrypted extensions
2024.02.15 22:29:04 LOG7[0]: Verification started at depth=0: C=US, ST=MyState, L=MyCity, O=MyOrg, CN=mydomain.com, emailAddress=cert@mydomain.com
2024.02.15 22:29:04 LOG7[0]: CERT: Pre-verification succeeded
2024.02.15 22:29:04 LOG6[0]: CERT: Host name "mydomain.com" matched with "mydomain.com"
2024.02.15 22:29:04 LOG7[0]: OCSP: Waiting for OCSP stapling response
2024.02.15 22:29:04 LOG5[0]: Certificate accepted at depth=0: C=US, ST=MyState, L=MyCity, O=MyOrg, CN=mydomain.com, emailAddress=cert@mydomain.com
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): SSLv3/TLS read server certificate
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): TLSv1.3 read server certificate verify
2024.02.15 22:29:04 LOG7[0]: OCSP stapling: Client callback called
2024.02.15 22:29:04 LOG7[0]: OCSP: Ignoring the root certificate
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): SSLv3/TLS read finished
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): SSLv3/TLS write change cipher spec
2024.02.15 22:29:04 LOG7[0]: TLS state (connect): SSLv3/TLS write finished
2024.02.15 22:29:04 LOG7[0]: 1 client connect(s) requested
2024.02.15 22:29:04 LOG7[0]: 1 client connect(s) succeeded
2024.02.15 22:29:04 LOG7[0]: 0 client renegotiation(s) requested
2024.02.15 22:29:04 LOG7[0]: 0 session reuse(s)
2024.02.15 22:29:04 LOG6[0]: TLS connected: new session negotiated
2024.02.15 22:29:04 LOG6[0]: TLSv1.3 ciphersuite: TLS_AES_256_GCM_SHA384 (256-bit encryption)
2024.02.15 22:29:04 LOG6[0]: Peer temporary key: X25519, 253 bits
2024.02.15 22:29:04 LOG7[0]: Compression: null, expansion: null
2024.02.15 22:29:05 LOG7[0]: TLS state (connect): SSL negotiation finished successfully
2024.02.15 22:29:05 LOG7[0]: TLS state (connect): SSL negotiation finished successfully
2024.02.15 22:29:05 LOG7[0]: Initializing application specific data for session authenticated
2024.02.15 22:29:05 LOG7[0]: Deallocating application specific data for session connect address
2024.02.15 22:29:05 LOG7[0]: New session callback
2024.02.15 22:29:05 LOG7[0]: Peer certificate was cached (1444 bytes)
2024.02.15 22:29:05 LOG6[0]: Session id: F676D7E3E5CF84E15EC518BB54BD78CA8C1F9D3770F12DEB3FAFD98E50AAAA1C
2024.02.15 22:29:05 LOG7[0]: TLS state (connect): SSLv3/TLS read server session ticket
2024.02.15 22:29:05 LOG7[0]: TLS state (connect): SSL negotiation finished successfully
2024.02.15 22:29:05 LOG7[0]: TLS state (connect): SSL negotiation finished successfully
2024.02.15 22:29:05 LOG7[0]: Initializing application specific data for session authenticated
2024.02.15 22:29:05 LOG7[0]: New session callback
2024.02.15 22:29:05 LOG7[0]: Deallocating application specific data for session connect address
2024.02.15 22:29:05 LOG6[0]: Session id: 117BD7B86EA5575EEC2591DE8D973075993999B912710C9C11E5E1C4973AA1E5
2024.02.15 22:29:05 LOG7[0]: TLS state (connect): SSLv3/TLS read server session ticket
####First ssh exit
2024.02.15 22:29:16 LOG6[0]: Read socket closed (readsocket)
2024.02.15 22:29:16 LOG7[0]: Sending close_notify alert
2024.02.15 22:29:16 LOG7[0]: TLS alert (write): warning: close notify
2024.02.15 22:29:16 LOG6[0]: SSL_shutdown successfully sent close_notify alert
2024.02.15 22:29:17 LOG7[0]: TLS alert (read): warning: close notify
2024.02.15 22:29:17 LOG6[0]: TLS closed (SSL_read)
2024.02.15 22:29:17 LOG7[0]: Sent socket write shutdown
2024.02.15 22:29:17 LOG5[0]: Connection closed: 3097 byte(s) sent to TLS, 3001 byte(s) sent to socket
2024.02.15 22:29:17 LOG7[0]: Remote descriptor (FD=12) closed
2024.02.15 22:29:17 LOG7[0]: Local descriptor (FD=3) closed
2024.02.15 22:29:17 LOG7[0]: Service [ssh] finished (0 left)
####Second ssh attempt
2024.02.15 22:39:56 LOG7[main]: Found 1 ready file descriptor(s)
2024.02.15 22:39:56 LOG7[main]: FD=4 events=0x1 revents=0x0
2024.02.15 22:39:56 LOG7[main]: FD=8 events=0x1 revents=0x1
2024.02.15 22:39:56 LOG7[main]: FD=10 events=0x1 revents=0x0
2024.02.15 22:39:56 LOG7[main]: Service [ssh] accepted (FD=3) from ::1:52079
The above is the last log message posted no matter how many times I
try to ssh again... so it seems frozen/hung
More information about the Cygwin
mailing list