[stunnel-users] Stunnel connection issue?

Flo Rance trourance at gmail.com
Thu Jul 5 13:12:45 CEST 2018 

Hi,

IMO it would be good to take a look at some debug backend logs.

Regards,
Flo

On Thu, Jul 5, 2018 at 11:58 AM, Spies, Will <Will_Spies at comcast.com> wrote:

> I’ve been trying to get Stunnel to work for some time now.  I have avoided
> using the mail list – but I see no recourse now.  I think I’ve tried just
> about every setting I could find.  I appear to be getting a connection
> issue – but as you will see the log just doesn’t indicate clearly what is
> going on.  The behavior is my client is failing to get a connection through
> Stunnel to my backend.  The log appears to be closing a socket (but can’t
> tell which one frontend or backend). Nothing wrong happens up until a
> client connects – 443 binds fine and later a connection to my backend 554
> appears to connect find. If someone/anyone can help direct me to how to
> trouble shoot this better I would greatly appreciate it.  As you will see
> in the log – the client attempts twice to get through. An excerpt of my log
> and the conf is below.
>
>
>
> /etc/stunnel.conf:
>
>
>
> socket = l:TCP_NODELAY=1
>
> socket = r:TCP_NODELAY=1
>
>
>
> output = /var/log/stunnel.log
>
>
>
> debug=7
>
>
>
> [rtsp]
>
> cert = /etc/stunnel/stunnel.pem
>
> accept=192.168.112.16:443
>
> connect=192.168.112.16:554
>
> TIMEOUTclose = 0
>
> TIMEOUTbusy = 5
>
> TIMEOUTidle = 30
>
> delay = yes
>
> sslVersion = TLSv1.2
>
>
>
>
>
> /var/log/stunnel.log:
>
>
>
> 2018.07.05 05:31:01 LOG7[main]: Service [rtsp] accepted (FD=3) from
> 192.168.112.197:43869
>
> 2018.07.05 05:31:01 LOG7[5]: Service [rtsp] started
>
> 2018.07.05 05:31:01 LOG7[5]: Setting local socket options (FD=3)
>
> 2018.07.05 05:31:01 LOG7[5]: Option TCP_NODELAY set on local socket
>
> 2018.07.05 05:31:01 LOG5[5]: Service [rtsp] accepted connection from
> 192.168.112.197:43869
>
> 2018.07.05 05:31:01 LOG6[5]: Peer certificate not required
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): before SSL initialization
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): before SSL initialization
>
> 2018.07.05 05:31:01 LOG7[5]: SNI: no virtual services defined
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS read client
> hello
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS write server
> hello
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS write
> certificate
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS write key
> exchange
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS write server
> done
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS write server
> done
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS read client key
> exchange
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS read change
> cipher spec
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS read finished
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS write change
> cipher spec
>
> 2018.07.05 05:31:01 LOG7[5]: TLS state (accept): SSLv3/TLS write finished
>
> 2018.07.05 05:31:01 LOG7[5]: New session callback
>
> 2018.07.05 05:31:01 LOG6[5]: No peer certificate received
>
> 2018.07.05 05:31:01 LOG7[5]:      6 server accept(s) requested
>
> 2018.07.05 05:31:01 LOG7[5]:      3 server accept(s) succeeded
>
> 2018.07.05 05:31:01 LOG7[5]:      0 server renegotiation(s) requested
>
> 2018.07.05 05:31:01 LOG7[5]:      0 session reuse(s)
>
> 2018.07.05 05:31:01 LOG7[5]:      3 internal session cache item(s)
>
> 2018.07.05 05:31:01 LOG7[5]:      0 internal session cache fill-up(s)
>
> 2018.07.05 05:31:01 LOG7[5]:      0 internal session cache miss(es)
>
> 2018.07.05 05:31:01 LOG7[5]:      0 external session cache hit(s)
>
> 2018.07.05 05:31:01 LOG7[5]:      0 expired session(s) retrieved
>
> 2018.07.05 05:31:01 LOG6[5]: TLS accepted: new session negotiated
>
> 2018.07.05 05:31:01 LOG6[5]: TLSv1.2 ciphersuite:
> ECDHE-RSA-AES256-GCM-SHA384 (256-bit encryption)
>
> 2018.07.05 05:31:01 LOG7[5]: Compression: null, expansion: null
>
> 2018.07.05 05:31:01 LOG6[5]: s_connect: connecting 192.168.112.16:554
>
> 2018.07.05 05:31:01 LOG7[5]: s_connect: s_poll_wait 192.168.112.16:554:
> waiting 10 seconds
>
> 2018.07.05 05:31:01 LOG5[5]: s_connect: connected 192.168.112.16:554
>
> 2018.07.05 05:31:01 LOG6[5]: persistence: 192.168.112.16:554 cached
>
> 2018.07.05 05:31:01 LOG5[5]: Service [rtsp] connected remote server from
> 192.168.112.16:58594
>
> 2018.07.05 05:31:01 LOG7[5]: Setting remote socket options (FD=9)
>
> 2018.07.05 05:31:01 LOG7[5]: Option TCP_NODELAY set on remote socket
>
> 2018.07.05 05:31:01 LOG7[5]: Remote descriptor (FD=9) initialized
>
> 2018.07.05 05:31:02 LOG6[5]: TLS socket closed (SSL_read)
>
> 2018.07.05 05:31:02 LOG7[5]: Sent socket write shutdown
>
> 2018.07.05 05:31:02 LOG5[5]: Connection closed: 0 byte(s) sent to TLS, 0
> byte(s) sent to socket
>
> 2018.07.05 05:31:02 LOG7[5]: Remote descriptor (FD=9) closed
>
> 2018.07.05 05:31:02 LOG7[5]: Local descriptor (FD=3) closed
>
> 2018.07.05 05:31:02 LOG7[5]: Service [rtsp] finished (0 left)
>
> 2018.07.05 05:31:02 LOG7[main]: Found 1 ready file descriptor(s)
>
> 2018.07.05 05:31:02 LOG7[main]: FD=4 events=0x2001 revents=0x0
>
> 2018.07.05 05:31:02 LOG7[main]: FD=7 events=0x2001 revents=0x1
>
> 2018.07.05 05:31:02 LOG7[main]: Service [rtsp] accepted (FD=3) from
> 192.168.112.197:43870
>
> 2018.07.05 05:31:02 LOG7[6]: Service [rtsp] started
>
> 2018.07.05 05:31:02 LOG7[6]: Setting local socket options (FD=3)
>
> 2018.07.05 05:31:02 LOG7[6]: Option TCP_NODELAY set on local socket
>
> 2018.07.05 05:31:02 LOG5[6]: Service [rtsp] accepted connection from
> 192.168.112.197:43870
>
> 2018.07.05 05:31:02 LOG6[6]: Peer certificate not required
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): before SSL initialization
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): before SSL initialization
>
> 2018.07.05 05:31:02 LOG7[6]: SNI: no virtual services defined
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS read client
> hello
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS write server
> hello
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS write
> certificate
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS write key
> exchange
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS write server
> done
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS write server
> done
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS read client key
> exchange
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS read change
> cipher spec
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS read finished
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS write change
> cipher spec
>
> 2018.07.05 05:31:02 LOG7[6]: TLS state (accept): SSLv3/TLS write finished
>
> 2018.07.05 05:31:02 LOG7[6]: New session callback
>
> 2018.07.05 05:31:02 LOG6[6]: No peer certificate received
>
> 2018.07.05 05:31:02 LOG7[6]:      7 server accept(s) requested
>
> 2018.07.05 05:31:02 LOG7[6]:      4 server accept(s) succeeded
>
> 2018.07.05 05:31:02 LOG7[6]:      0 server renegotiation(s) requested
>
> 2018.07.05 05:31:02 LOG7[6]:      0 session reuse(s)
>
> 2018.07.05 05:31:02 LOG7[6]:      4 internal session cache item(s)
>
> 2018.07.05 05:31:02 LOG7[6]:      0 internal session cache fill-up(s)
>
> 2018.07.05 05:31:02 LOG7[6]:      0 internal session cache miss(es)
>
> 2018.07.05 05:31:02 LOG7[6]:      0 external session cache hit(s)
>
> 2018.07.05 05:31:02 LOG7[6]:      0 expired session(s) retrieved
>
> 2018.07.05 05:31:02 LOG6[6]: TLS accepted: new session negotiated
>
> 2018.07.05 05:31:02 LOG6[6]: TLSv1.2 ciphersuite:
> ECDHE-RSA-AES256-GCM-SHA384 (256-bit encryption)
>
> 2018.07.05 05:31:02 LOG7[6]: Compression: null, expansion: null
>
> 2018.07.05 05:31:02 LOG6[6]: s_connect: connecting 192.168.112.16:554
>
> 2018.07.05 05:31:02 LOG7[6]: s_connect: s_poll_wait 192.168.112.16:554:
> waiting 10 seconds
>
> 2018.07.05 05:31:02 LOG5[6]: s_connect: connected 192.168.112.16:554
>
> 2018.07.05 05:31:02 LOG6[6]: persistence: 192.168.112.16:554 cached
>
> 2018.07.05 05:31:02 LOG5[6]: Service [rtsp] connected remote server from
> 192.168.112.16:58596
>
> 2018.07.05 05:31:02 LOG7[6]: Setting remote socket options (FD=9)
>
> 2018.07.05 05:31:02 LOG7[6]: Option TCP_NODELAY set on remote socket
>
> 2018.07.05 05:31:02 LOG7[6]: Remote descriptor (FD=9) initialized
>
> 2018.07.05 05:31:02 LOG6[6]: TLS socket closed (SSL_read)
>
> 2018.07.05 05:31:02 LOG7[6]: Sent socket write shutdown
>
> 2018.07.05 05:31:02 LOG5[6]: Connection closed: 0 byte(s) sent to TLS, 0
> byte(s) sent to socket
>
> 2018.07.05 05:31:02 LOG7[6]: Remote descriptor (FD=9) closed
>
> 2018.07.05 05:31:02 LOG7[6]: Local descriptor (FD=3) closed
>
> 2018.07.05 05:31:02 LOG7[6]: Service [rtsp] finished (0 left)
>
> 2018.07.05 05:31:05 LOG7[main]: Found 1 ready file descriptor(s)
>
> 2018.07.05 05:31:05 LOG7[main]: FD=4 events=0x2001 revents=0x0
>
> 2018.07.05 05:31:05 LOG7[main]: FD=7 events=0x2001 revents=0x1
>
> _______________________________________________
> stunnel-users mailing list
> stunnel-users at stunnel.org
> https://www.stunnel.org/cgi-bin/mailman/listinfo/stunnel-users
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.stunnel.org/pipermail/stunnel-users/attachments/20180705/3ca65c23/attachment.html>

More information about the stunnel-users mailing list