HI,
thanks for your response!

it happens on average  once in every 50 connections
it is always exactly 30 seconds

I tried looking into the servers log and it looks like the session doesn't get to the message received  
am not familiar with Stunnel but it started happening after upgrading Stunnel from 5.14 to 5.58 ( it happens on 5.57 as well)  
Ditty

On Tue, Dec 22, 2020 at 6:05 PM Christopher Schultz <chris@christopherschultz.net> wrote:
Ditty,

Does this happen a lot? Is it always 30 seconds (exactly)? 30 seconds
sounds suspiciously like an IO read timeout. Is the connection with the
client a fast and reliable one?

-chris

On 12/21/20 13:09, dittyadler@gmail.com wrote:
> Hi,
>
> I'm running stunnel version 5.58 on Windows,
> everything works perfectly besides that sometimes stunnel gets stuck for 30 seconds -
> Nothing special in stunnel log, except for the 30 seconds delay:
>
> 2020.12.21 14:48:36 LOG6[8]: TLS connected: previous session reused
> 2020.12.21 14:48:36 LOG6[8]: TLSv1.3 ciphersuite: TLS_AES_256_GCM_SHA384 (256-bit encryption)
> 2020.12.21 14:48:36 LOG6[8]: Peer temporary key: X25519, 253 bits
> 2020.12.21 14:48:36 LOG7[8]: Compression: null, expansion: null
> 2020.12.21 14:48:36 LOG6[8]: Session id: 8E62D0D8EB6359FEA7370E64AA7CC58EF9DB68059A5E01417E7038B773CE60D3
> 2020.12.21 14:48:36 LOG7[8]: TLS state (connect): SSL negotiation finished successfully
> 2020.12.21 14:48:36 LOG7[8]: TLS state (connect): SSL negotiation finished successfully
> 2020.12.21 14:48:36 LOG7[8]: Initializing application specific data for session authenticated
> 2020.12.21 14:48:36 LOG7[8]: New session callback
> 2020.12.21 14:48:36 LOG7[8]: Deallocating application specific data for session connect address
> 2020.12.21 14:48:36 LOG6[8]: Session id: AF8ED185555C6734403C71B514A3F6B75F8484A5AC4EAE6058CFF4D35D929B36
> 2020.12.21 14:48:36 LOG7[8]: TLS state (connect): SSLv3/TLS read server session ticket
> 30 sec delay
> 2020.12.21 14:49:06 LOG6[8]: Read socket closed (readsocket)
> 2020.12.21 14:49:06 LOG7[8]: Sending close_notify alert
> 2020.12.21 14:49:06 LOG7[8]: TLS alert (write): warning: close notify
> 2020.12.21 14:49:06 LOG6[8]: SSL_shutdown successfully sent close_notify alert
> 2020.12.21 14:49:06 LOG3[8]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing
> 2020.12.21 14:49:06 LOG7[8]: FD=4540 ifds=--x ofds=---
> 2020.12.21 14:49:06 LOG7[8]: FD=4792 ifds=r-x ofds=---
> 2020.12.21 14:49:06 LOG5[8]: Connection closed: 64 byte(s) sent to TLS, 0 byte(s) sent to socket
> 2020.12.21 14:49:06 LOG7[8]: Remote descriptor (FD=4792) closed
> 2020.12.21 14:49:06 LOG7[8]: Local descriptor (FD=4540) closed
> 2020.12.21 14:49:06 LOG7[8]: Service [SLNP pem file] finished (0 left)
> log example when stunnel doesn't get stuck:
> 2020.12.21 14:49:06 LOG6[9]: TLS connected: previous session reused
> 2020.12.21 14:49:06 LOG6[9]: TLSv1.3 ciphersuite: TLS_AES_256_GCM_SHA384 (256-bit encryption)
> 2020.12.21 14:49:06 LOG6[9]: Peer temporary key: X25519, 253 bits
> 2020.12.21 14:49:06 LOG7[9]: Compression: null, expansion: null
> 2020.12.21 14:49:06 LOG6[9]: Session id: AF8ED185555C6734403C71B514A3F6B75F8484A5AC4EAE6058CFF4D35D929B36
> 2020.12.21 14:49:06 LOG7[9]: TLS state (connect): SSL negotiation finished successfully
> 2020.12.21 14:49:06 LOG7[9]: TLS state (connect): SSL negotiation finished successfully
> 2020.12.21 14:49:06 LOG7[9]: Initializing application specific data for session authenticated
> 2020.12.21 14:49:06 LOG7[9]: New session callback
> 2020.12.21 14:49:06 LOG7[9]: Deallocating application specific data for session connect address
> 2020.12.21 14:49:06 LOG6[9]: Session id: 44E9010787EFDBC0FCA92724415AD30EF9EDB626D734D894061606C79CD26402
> 2020.12.21 14:49:06 LOG7[9]: TLS state (connect): SSLv3/TLS read server session ticket
> 2020.12.21 14:49:06 LOG6[9]: Read socket closed (readsocket)
> 2020.12.21 14:49:06 LOG7[9]: Sending close_notify alert
> 2020.12.21 14:49:06 LOG7[9]: TLS alert (write): warning: close notify
> 2020.12.21 14:49:06 LOG6[9]: SSL_shutdown successfully sent close_notify alert
> 2020.12.21 14:49:06 LOG3[9]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing
> 2020.12.21 14:49:06 LOG7[9]: FD=2464 ifds=r-x ofds=---
> 2020.12.21 14:49:06 LOG7[9]: FD=2788 ifds=--x ofds=---
> 2020.12.21 14:49:06 LOG5[9]: Connection closed: 64 byte(s) sent to TLS, 108 byte(s) sent to socket
> 2020.12.21 14:49:06 LOG7[9]: Remote descriptor (FD=2464) closed
> 2020.12.21 14:49:06 LOG7[9]: Local descriptor (FD=2788) closed
> 2020.12.21 14:49:06 LOG7[9]: Service [SLNP pem file] finished (0 left)
>
> My stunnel conf:
> debug = 7
> output = stunnel.log
> fips = no
> options = NO_SSLv2
> [SLNP pem file]
> key = SLNP_urmsand01_new.pem
> cert = SLNP_urmsand01_new.pem
> client = yes
> accept = 8003
> connect = host:6443
> TIMEOUTbusy = 30
> TIMEOUTclose = 0
> TIMEOUTconnect = 60
> TIMEOUTidle = 86400
> With the old stunnel(5.14) it doesn’t happen.
>
> Thanks,
>
>
> Ditty.
> _______________________________________________
> stunnel-users mailing list -- stunnel-users@stunnel.org
> To unsubscribe send an email to stunnel-users-leave@stunnel.org
>
_______________________________________________
stunnel-users mailing list -- stunnel-users@stunnel.org
To unsubscribe send an email to stunnel-users-leave@stunnel.org