[prev in list] [next in list] [prev in thread] [next in thread]
List: stunnel-users
Subject: [stunnel-users] Re: stunnel is stuck for 30 seconds
From: DITTY ADLER <dittyadler () gmail ! com>
Date: 2020-12-23 8:06:49
Message-ID: CAFi6uH-04XbaosdO+dvwWFq5sUfLF0_mOiNFPm0hYFVKenaLOg () mail ! gmail ! com
[Download RAW message or body]
[Attachment #2 (multipart/alternative)]
thanks for helping
I found this:
https://issues.apache.org/jira/browse/DIRMINA-1132
" While trying to Implement TLSv1.3 in our systems, we found an issue with
Mina Core dependency. For TLSv1.2 we never had the issue. But with TLSv1.3,
randomly the message sent by the client is discarded. In such scenarios,
the server waits for session to pass idle timeout and closes the session"
*Issue:*
The actual issue is that the messageReceived() is not being triggered
immediately after sending the request. This is happening
randomly
adding this line to stunnel conf solved the issue:
sslVersion = TLSv1.2
On Tue, Dec 22, 2020 at 6:24 PM DITTY ADLER <dittyadler@gmail.com> wrote:
> 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
>>
>
[Attachment #5 (text/html)]
<div dir="ltr">thanks for helping <div>I found this:<div><p class="MsoNormal" \
style="margin:0cm 0cm 0.0001pt;font-size:11pt;font-family:Calibri,sans-serif"><a \
href="https://issues.apache.org/jira/browse/DIRMINA-1132" \
style="color:rgb(5,99,193)">https://issues.apache.org/jira/browse/DIRMINA-1132</a></p><p \
class="MsoNormal" style="margin:0cm 0cm \
0.0001pt;font-size:11pt;font-family:Calibri,sans-serif"><br></p><p class="MsoNormal" \
style="margin:0cm 0cm \
0.0001pt;font-size:11pt;font-family:Calibri,sans-serif">"<span \
style="font-size:10.5pt;font-family:-apple-system;color:rgb(23,43,77);background-image \
:initial;background-position:initial;background-size:initial;background-repeat:initial;background-origin:initial;background-clip:initial"> \
While trying to Implement TLSv1.3 in our systems, we found an issue with Mina Core \
dependency. For TLSv1.2 we never had the issue. But with TLSv1.3, randomly the \
message sent by the client is discarded. In such scenarios, the server waits for \
session to pass idle timeout and closes the session"</span></p><p \
class="MsoNormal" style="margin:0cm 0cm \
0.0001pt;font-size:11pt;font-family:Calibri,sans-serif"><span \
style="font-size:10.5pt;font-family:-apple-system;color:rgb(23,43,77);background-image \
:initial;background-position:initial;background-size:initial;background-repeat:initial;background-origin:initial;background-clip:initial"></span></p><p \
class="MsoNormal" style="margin:0cm 0cm \
0.0001pt;font-size:11pt;font-family:Calibri,sans-serif"><b><span \
style="font-size:10.5pt;font-family:-apple-system;color:rgb(23,43,77);background:rgb(244,245,247)">Issue:</span></b><span \
style="font-size:10.5pt;font-family:-apple-system;color:rgb(23,43,77)"><br> <span \
style="background:rgb(244,245,247)">The actual issue is that the messageReceived() is \
not being triggered immediately after sending the request. This is \
happening</span><br> <span style="background:rgb(244,245,247)">randomly</span><span \
style="background-image:initial;background-position:initial;background-size:initial;ba \
ckground-repeat:initial;background-origin:initial;background-clip:initial"></span></span></p><p \
class="MsoNormal" style="margin:0cm 0cm \
0.0001pt;font-size:11pt;font-family:Calibri,sans-serif">adding this line to stunnel \
conf solved the issue:</p><p class="MsoNormal" style="margin:0cm 0cm \
0.0001pt;font-size:11pt;font-family:Calibri,sans-serif"><span \
style="font-size:10.5pt;font-family:-apple-system;color:rgb(23,43,77);background-image \
:initial;background-position:initial;background-size:initial;background-repeat:initial;background-origin:initial;background-clip:initial">
</span></p><p class="MsoNormal" style="margin:0cm 0cm \
0.0001pt;font-size:11pt;font-family:Calibri,sans-serif">sslVersion = \
TLSv1.2</p></div></div></div><br><div class="gmail_quote"><div dir="ltr" \
class="gmail_attr">On Tue, Dec 22, 2020 at 6:24 PM DITTY ADLER <<a \
href="mailto:dittyadler@gmail.com">dittyadler@gmail.com</a>> \
wrote:<br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px \
0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><div \
dir="ltr">HI,<br>thanks for your response!<br><br>it happens on average once in \
every 50 connections<br>it is always <u>exactly </u>30 seconds<br><br>I tried looking \
into the servers log and it looks like the session doesn't get to the message \
received <br>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) \
<br><div>Ditty</div></div><br><div class="gmail_quote"><div dir="ltr" \
class="gmail_attr">On Tue, Dec 22, 2020 at 6:05 PM Christopher Schultz <<a \
href="mailto:chris@christopherschultz.net" \
target="_blank">chris@christopherschultz.net</a>> wrote:<br></div><blockquote \
class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid \
rgb(204,204,204);padding-left:1ex">Ditty,<br> <br>
Does this happen a lot? Is it always 30 seconds (exactly)? 30 seconds <br>
sounds suspiciously like an IO read timeout. Is the connection with the <br>
client a fast and reliable one?<br>
<br>
-chris<br>
<br>
On 12/21/20 13:09, <a href="mailto:dittyadler@gmail.com" \
target="_blank">dittyadler@gmail.com</a> wrote:<br> > Hi,<br>
> <br>
> I'm running stunnel version 5.58 on Windows,<br>
> everything works perfectly besides that sometimes stunnel gets stuck for 30 \
seconds -<br> > Nothing special in stunnel log, except for the 30 seconds \
delay:<br> > <br>
> 2020.12.21 14:48:36 LOG6[8]: TLS connected: previous session reused<br>
> 2020.12.21 14:48:36 LOG6[8]: TLSv1.3 ciphersuite: TLS_AES_256_GCM_SHA384 \
(256-bit encryption)<br> > 2020.12.21 14:48:36 LOG6[8]: Peer temporary key: \
X25519, 253 bits<br> > 2020.12.21 14:48:36 LOG7[8]: Compression: null, expansion: \
null<br> > 2020.12.21 14:48:36 LOG6[8]: Session id: \
8E62D0D8EB6359FEA7370E64AA7CC58EF9DB68059A5E01417E7038B773CE60D3<br> > 2020.12.21 \
14:48:36 LOG7[8]: TLS state (connect): SSL negotiation finished successfully<br> > \
2020.12.21 14:48:36 LOG7[8]: TLS state (connect): SSL negotiation finished \
successfully<br> > 2020.12.21 14:48:36 LOG7[8]: Initializing application specific \
data for session authenticated<br> > 2020.12.21 14:48:36 LOG7[8]: New session \
callback<br> > 2020.12.21 14:48:36 LOG7[8]: Deallocating application specific data \
for session connect address<br> > 2020.12.21 14:48:36 LOG6[8]: Session id: \
AF8ED185555C6734403C71B514A3F6B75F8484A5AC4EAE6058CFF4D35D929B36<br> > 2020.12.21 \
14:48:36 LOG7[8]: TLS state (connect): SSLv3/TLS read server session ticket<br> > \
30 sec delay<br> > 2020.12.21 14:49:06 LOG6[8]: Read socket closed \
(readsocket)<br> > 2020.12.21 14:49:06 LOG7[8]: Sending close_notify alert<br>
> 2020.12.21 14:49:06 LOG7[8]: TLS alert (write): warning: close notify<br>
> 2020.12.21 14:49:06 LOG6[8]: SSL_shutdown successfully sent close_notify \
alert<br> > 2020.12.21 14:49:06 LOG3[8]: transfer: s_poll_wait: TIMEOUTclose \
exceeded: closing<br> > 2020.12.21 14:49:06 LOG7[8]: FD=4540 ifds=--x ofds=---<br>
> 2020.12.21 14:49:06 LOG7[8]: FD=4792 ifds=r-x ofds=---<br>
> 2020.12.21 14:49:06 LOG5[8]: Connection closed: 64 byte(s) sent to TLS, 0 \
byte(s) sent to socket<br> > 2020.12.21 14:49:06 LOG7[8]: Remote descriptor \
(FD=4792) closed<br> > 2020.12.21 14:49:06 LOG7[8]: Local descriptor (FD=4540) \
closed<br> > 2020.12.21 14:49:06 LOG7[8]: Service [SLNP pem file] finished (0 \
left)<br> > log example when stunnel doesn't get stuck:<br>
> 2020.12.21 14:49:06 LOG6[9]: TLS connected: previous session reused<br>
> 2020.12.21 14:49:06 LOG6[9]: TLSv1.3 ciphersuite: TLS_AES_256_GCM_SHA384 \
(256-bit encryption)<br> > 2020.12.21 14:49:06 LOG6[9]: Peer temporary key: \
X25519, 253 bits<br> > 2020.12.21 14:49:06 LOG7[9]: Compression: null, expansion: \
null<br> > 2020.12.21 14:49:06 LOG6[9]: Session id: \
AF8ED185555C6734403C71B514A3F6B75F8484A5AC4EAE6058CFF4D35D929B36<br> > 2020.12.21 \
14:49:06 LOG7[9]: TLS state (connect): SSL negotiation finished successfully<br> > \
2020.12.21 14:49:06 LOG7[9]: TLS state (connect): SSL negotiation finished \
successfully<br> > 2020.12.21 14:49:06 LOG7[9]: Initializing application specific \
data for session authenticated<br> > 2020.12.21 14:49:06 LOG7[9]: New session \
callback<br> > 2020.12.21 14:49:06 LOG7[9]: Deallocating application specific data \
for session connect address<br> > 2020.12.21 14:49:06 LOG6[9]: Session id: \
44E9010787EFDBC0FCA92724415AD30EF9EDB626D734D894061606C79CD26402<br> > 2020.12.21 \
14:49:06 LOG7[9]: TLS state (connect): SSLv3/TLS read server session ticket<br> > \
2020.12.21 14:49:06 LOG6[9]: Read socket closed (readsocket)<br> > 2020.12.21 \
14:49:06 LOG7[9]: Sending close_notify alert<br> > 2020.12.21 14:49:06 LOG7[9]: \
TLS alert (write): warning: close notify<br> > 2020.12.21 14:49:06 LOG6[9]: \
SSL_shutdown successfully sent close_notify alert<br> > 2020.12.21 14:49:06 \
LOG3[9]: transfer: s_poll_wait: TIMEOUTclose exceeded: closing<br> > 2020.12.21 \
14:49:06 LOG7[9]: FD=2464 ifds=r-x ofds=---<br> > 2020.12.21 14:49:06 LOG7[9]: \
FD=2788 ifds=--x ofds=---<br> > 2020.12.21 14:49:06 LOG5[9]: Connection closed: 64 \
byte(s) sent to TLS, 108 byte(s) sent to socket<br> > 2020.12.21 14:49:06 LOG7[9]: \
Remote descriptor (FD=2464) closed<br> > 2020.12.21 14:49:06 LOG7[9]: Local \
descriptor (FD=2788) closed<br> > 2020.12.21 14:49:06 LOG7[9]: Service [SLNP pem \
file] finished (0 left)<br> > <br>
> My stunnel conf:<br>
> debug = 7<br>
> output = stunnel.log<br>
> fips = no<br>
> options = NO_SSLv2<br>
> [SLNP pem file]<br>
> key = SLNP_urmsand01_new.pem<br>
> cert = SLNP_urmsand01_new.pem<br>
> client = yes<br>
> accept = 8003<br>
> connect = host:6443<br>
> TIMEOUTbusy = 30<br>
> TIMEOUTclose = 0<br>
> TIMEOUTconnect = 60<br>
> TIMEOUTidle = 86400<br>
> With the old stunnel(5.14) it doesn't happen.<br>
> <br>
> Thanks,<br>
> <br>
> <br>
> Ditty.<br>
> _______________________________________________<br>
> stunnel-users mailing list -- <a href="mailto:stunnel-users@stunnel.org" \
target="_blank">stunnel-users@stunnel.org</a><br> > To unsubscribe send an email \
to <a href="mailto:stunnel-users-leave@stunnel.org" \
target="_blank">stunnel-users-leave@stunnel.org</a><br> > <br>
_______________________________________________<br>
stunnel-users mailing list -- <a href="mailto:stunnel-users@stunnel.org" \
target="_blank">stunnel-users@stunnel.org</a><br> To unsubscribe send an email to <a \
href="mailto:stunnel-users-leave@stunnel.org" \
target="_blank">stunnel-users-leave@stunnel.org</a><br> </blockquote></div>
</blockquote></div>
_______________________________________________
stunnel-users mailing list -- stunnel-users@stunnel.org
To unsubscribe send an email to stunnel-users-leave@stunnel.org
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic