Re: Stunnel-5.55 client close TLS socket before it could read more bytes

Ming Lu (陆明) <[email protected]> Tue, 14 Jan 2020 05:00:59 +0000
Newsgroups gmane.network.stunnel.user
Message-ID <[email protected]>
--===============7837591136009863093==
Content-Language: en-US
Content-Type: multipart/alternative;
	boundary="_000_157897805926791004citrixcom_"

--_000_157897805926791004citrixcom_
Content-Type: text/plain; charset="gb2312"
Content-Transfer-Encoding: base64

P0p1c3QgYW4gdXBkYXRlIG9uIHRoaXMgaXNzdWUuDQoNCk15IGNvbGxlYWd1ZSBSb3NzIExhZ2Vy
d2FsbCBmb3VuZCB0aGF0IHRoaXMgd2FzIGNhdXNlZCBieSBzZXJ2ZXIgc2lkZSBub3Qgc2VuZGlu
ZyBzc2wgYWxlcnQgYmVmb3JlIGNsb3Npbmcgc3NsIGNvbm5lY3Rpb24uDQoNCg0KQSBmdXJ0aGVy
IGRlYnVnIHNob3dzIHRoYXQgb24gc2VydmVyIHNpZGUsIHNpbmNlICJUSU1FT1VUY2xvc2UiIHdh
cyBjb25maWd1cmVkIGFzIDAsICJzX3BvbGxfd2FpdCIgaW4gInRyYW5zZmVyIiBmdW5jdGlvbiBp
biAic3JjL2NsaWVudC5jIiByZXR1cm5lZCBhcyB0aW1lb3V0IGltbWVkaWF0ZWx5LiBUaGlzIG1h
ZGUgInRyYW5zZmVyIiByZXR1cm4gd2l0aG91dCBzZW5kaW5nIHNzbCBhbGVydCB0byBjbGllbnQg
ZXZlbiB0aGUgInNodXRkb3duX3dhbnRzX3dyaXRlIiB3YXMgMS4NCg0KPw0KDQpfX19fX19fX19f
X19fX19fX19fX19fX19fX19fX19fXw0KRnJvbTogTWluZyBMdQ0KU2VudDogRnJpZGF5LCBEZWNl
bWJlciAxMywgMjAxOSAxNzo0OA0KVG86IHN0dW5uZWwtdXNlcnNAc3R1bm5lbC5vcmcNCkNjOiBN
aW5nIEx1DQpTdWJqZWN0OiBTdHVubmVsLTUuNTUgY2xpZW50IGNsb3NlIFRMUyBzb2NrZXQgYmVm
b3JlIGl0IGNvdWxkIHJlYWQgbW9yZSBieXRlcw0KDQoNCkhlbGxvLA0KDQoNCk1heSBJIHBsZWFz
ZSBoYXZlIGhlbHAgb24gdGhpcyBpc3N1ZT8gVGhhbmtzIGluIGFkdmFuY2UhDQoNCg0KSSBoYWQg
YSBzdHVubmVsIHNlcnZlciBhbmQgY2xpZW50IGNvbW11bmljYXRpbmcgd2l0aCBUTFN2MS4yIChi
b3RoIG9mIHRoZW0gYXJlIHN0dW5uZWwgNS41NSBhbmQgT3BlblNTTC0xLjEuMWQpIG9uIENlbnRP
UyA3IGJhc2VkIExpbnV4IChrZXJuZWwgd2FzIHVwZGF0ZWQgYXMgNC4xOS4wKS4gVGhlIGNhc2Ug
aXMgdGhhdCBjbGllbnQgc2VuZHMgYSBIVFRQIHJlcXVlc3QgdG8gc2VydmVyLCBhbmQgdGhlbiBz
ZXJ2ZXIgcmVzcG9uZHMgYSBwYXlsb2FkIHdpdGggbW9yZSB0aGFuIDY0MEtCIHNpemUuIE5vcm1h
bGx5LCB0aGUgc2VydmVyIHdpbGwgY2xvc2UgdGhlIGNvbm5lY3Rpb24gYnkgc2VuZGluZyBhbiBh
bGVydCBmaXJzdGx5Lg0KDQoNClRoZSBpc3N1ZSBpcyB0aGF0IHNvbWV0aW1lcyAobm90IDEwMCUg
cmVwcm9kdWNpYmxlKSwgc3R1bm5lbCBjbGllbnQgcmVwb3J0ZWQ6ICJUTFMgc29ja2V0IGNsb3Nl
ZCAocmVhZCBoYW5ndXApIi4gYW5kIHRoZW4gY2xvc2VkIHRoZSBUTFMgc29ja2V0LiBTbyBJIGNv
dWxkIGZpbmQgYW4gYWxlcnQgc2VudCBmcm9tIGNsaWVudCB0byBzZXJ2ZXIgZmlyc3RseSBmcm9t
IHRjcGR1bXAuIENvbnNlcXVlbnRseSwgdGhpcyBjYXVzZWQgdGhlIGFwcGxpY2F0aW9uIHJlcG9y
dGVkICJ1bmV4cGVjdGVkIGVuZCBvZiBpbnB1dD8iIGFzIHRoZXJlIHNob3VsZCBiZSBtb3JlIGRh
dGEgdG8gYmUgcmVjZWl2ZWQuDQoNCg0KSSBhZGRlZCBhIGZldyBkZWJ1ZyBsb2dpYyBhbmQgSSBp
bmRlZWQgZm91bmQgdGhhdDogdGhlcmUgd2VyZSBvY2N1cnJlbmNlcyB0aGF0IGlmIHN0dW5uZWwg
Y2xpZW50IGRpZCBub3QgY2xvc2UgdGhlIFRMUyBzb2NrZXQsIGl0IGNvdWxkIHJlYWQgbW9yZSBk
YXRhIGZyb20gVExTIHNvY2tldCBpbiBuZXh0IHBvbGwgbG9vcDoNCg0KDQotLS0tLS0tLS0tLS0t
LS0tLS0tLQ0KDQowMzo1OTo0NiBsb2NhbGhvc3Qgc3R1bm5lbDogTE9HNlswXTogTWluZ0w6IFBP
TExSREhVUDogODE5Mg0KMDM6NTk6NDYgbG9jYWxob3N0IHN0dW5uZWw6IExPRzZbMF06IE1pbmdM
OiBpb2N0bHNvY2tldDogMA0KMDM6NTk6NDYgbG9jYWxob3N0IHN0dW5uZWw6IExPRzZbMF06IE1p
bmdMOiBieXRlczogMCAgICA8PT0gY2xpZW50IGRpZG4ndCBjbG9zZSB0aGUgc29jayBpbiBteSBk
ZWJ1ZyB2ZXJzaW9uLg0KMDM6NTk6NDYgbG9jYWxob3N0IHN0dW5uZWw6IExPRzZbMF06IE1pbmdM
OiBhZnRlciBjaGVja2luZw0KMDM6NTk6NDYgbG9jYWxob3N0IHN0dW5uZWw6IExPRzZbMF06IE1p
bmdMOiBzX3BvbGxfd2FpdDogcmV0dXJuIDENCjAzOjU5OjQ2IGxvY2FsaG9zdCBzdHVubmVsOiBM
T0c2WzBdOiBNaW5nTDogc29ja19jYW5fcmQ6IG4NCjAzOjU5OjQ2IGxvY2FsaG9zdCBzdHVubmVs
OiBMT0c2WzBdOiBNaW5nTDogc29ja19jYW5fd3I6IFkNCjAzOjU5OjQ2IGxvY2FsaG9zdCBzdHVu
bmVsOiBMT0c2WzBdOiBNaW5nTDogc3NsX2Nhbl9yZDogbg0KMDM6NTk6NDYgbG9jYWxob3N0IHN0
dW5uZWw6IExPRzZbMF06IE1pbmdMOiBzc2xfY2FuX3dyOiBuDQowMzo1OTo0NiBsb2NhbGhvc3Qg
c3R1bm5lbDogTE9HNlswXTogTWluZ0w6IHBlbmRpbmc6IDENCjAzOjU5OjQ2IGxvY2FsaG9zdCBz
dHVubmVsOiBMT0c2WzBdOiBNaW5nTDogd3JpdGUgdG8gc29jayAxODQzMg0KMDM6NTk6NDYgbG9j
YWxob3N0IHN0dW5uZWw6IExPRzZbMF06IE1pbmdMOiByZWFkX3dhbnRzX3JlYWQgWQ0KMDM6NTk6
NDYgbG9jYWxob3N0IHN0dW5uZWw6IExPRzZbMF06IE1pbmdMOiB3cml0ZV93YW50c193cml0ZW4N
CjAzOjU5OjQ2IGxvY2FsaG9zdCBzdHVubmVsOiBMT0c2WzBdOiBNaW5nTDogcmVhZCBmcm9tIFRM
UyAxMDE2OCAgPD09IHRoZW4gSSBvYnNlcnZlZCB0aGUgZnVydGhlciByZWFkIGZyb20gVExTLg0K
LS0tLS0tLS0tLS0tLS0tLS0tLS0NCg0KDQpBbnkgaGVscCB3aWxsIGJlIGFwcHJlY2lhdGVkIQ0K
DQpNaW5nDQoNCg==

--_000_157897805926791004citrixcom_
Content-Type: text/html; charset="gb2312"
Content-Transfer-Encoding: quoted-printable

<html>
<head>
<meta http-equiv=3D"Content-Type" content=3D"text/html; charset=3Dgb2312">
<style type=3D"text/css" style=3D"display:none"><!-- p { margin-top: 0px; m=
argin-bottom: 0px; }--></style>
</head>
<body dir=3D"ltr" style=3D"font-size:12pt;color:#000000;background-color:#F=
FFFFF;font-family:'Courier New',monospace;">
<p>&#8203;Just an update on this issue.<br>
</p>
<p>My colleague Ross Lagerwall found that this was caused by server side no=
t sending ssl alert before closing ssl connection.<br>
</p>
<p><br>
</p>
<p>A further&nbsp;debug shows that&nbsp;on server side,&nbsp;since &quot;TI=
MEOUTclose&quot; was configured as 0, &quot;s_poll_wait&quot; in &quot;tran=
sfer&quot; function in&nbsp;&quot;src/client.c&quot; returned as timeout im=
mediately. This made &quot;transfer&quot; return without sending ssl alert =
to client even the &quot;shutdown_wants_write&quot;
 was&nbsp;1.<br>
</p>
<p>&#8203;<br>
</p>
<div dir=3D"ltr" style=3D"font-size:12pt; color:#000000; background-color:#=
FFFFFF; font-family:'Courier New',monospace">
<hr tabindex=3D"-1" style=3D"display:inline-block; width:98%">
<div id=3D"divRplyFwdMsg" dir=3D"ltr"><font face=3D"Calibri, sans-serif" co=
lor=3D"#000000" style=3D"font-size:11pt"><b>From:</b> Ming Lu<br>
<b>Sent:</b> Friday, December 13, 2019 17:48<br>
<b>To:</b> [email protected]<br>
<b>Cc:</b> Ming Lu<br>
<b>Subject:</b> Stunnel-5.55 client close TLS socket before it could read m=
ore bytes</font>
<div>&nbsp;</div>
</div>
<div>
<p>Hello,<br>
</p>
<p><br>
</p>
<p>May I please have help on this issue? Thanks in advance!<br>
</p>
<p><br>
</p>
<p>I had a stunnel server and client communicating with TLSv1.2 (both of th=
em are stunnel 5.55 and OpenSSL-1.1.1d) on CentOS 7 based&nbsp;Linux (kerne=
l was updated as&nbsp;4.19.0). The case is that&nbsp;client sends a HTTP re=
quest to server, and then&nbsp;server responds a payload
 with more than 640KB size. Normally, the server will close the connection =
by sending an alert firstly.<br>
</p>
<p><br>
</p>
<p>The issue is that sometimes (not 100% reproducible), stunnel client repo=
rted:&nbsp;<span style=3D"font-size:12pt">&quot;TL</span><span style=3D"fon=
t-size:12pt">S socket closed (read hangup)&quot;.&nbsp;</span><span style=
=3D"font-size:12pt">and then closed the TLS socket. So I could
 find an alert sent from client to server firstly from tcpdump. Consequentl=
y, this caused the application reported &quot;unexpected end of input&#8203=
;&quot; as there should be more data to be received.</span></p>
<p><br>
</p>
<p>I added a few debug logic&nbsp;and I indeed found that:&nbsp;<span style=
=3D"font-size:12pt">there were occurrences that if stunnel client did not c=
lose the TLS socket, it could read more data from TLS socket in next poll l=
oop:</span></p>
<p><br>
</p>
<p>--------------------<br>
</p>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: POLLRDHUP: 8192&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: ioctlsocket: 0&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: bytes: 0&nbsp; &nbsp; &lt;=
=3D=3D client didn't&nbsp;close the sock in&nbsp;my debug version.<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: after checking&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: s_poll_wait:&nbsp;return 1=
&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: sock_can_rd: n&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: sock_can_wr: Y&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: ssl_can_rd: n&nbsp;</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: ssl_can_wr: n&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: pending: 1&nbsp;<br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: write to sock 18432&nbsp;<=
br>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: read_wants_read Y&nbsp;</d=
iv>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: write_wants_writen&nbsp;<b=
r>
</div>
<div>03:59:46 localhost stunnel: LOG6[0]: MingL: read from TLS 10168&nbsp; =
&lt;=3D=3D then I observed the further read from TLS.<br>
</div>
<div><span style=3D"font-family:&quot;Courier New&quot;,monospace; font-siz=
e:16px; background-color:rgb(255,255,255)">--------------------</span><br>
</div>
<div><span style=3D"font-family:&quot;Courier New&quot;,monospace; font-siz=
e:16px; background-color:rgb(255,255,255)"><br>
</span></div>
<div><br>
</div>
<div>Any help will be appreciated!<br>
</div>
<div><br>
</div>
<div>Ming<br>
</div>
<p><br>
</p>
</div>
</div>
</body>
</html>

--_000_157897805926791004citrixcom_--

--===============7837591136009863093==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

_______________________________________________
stunnel-users mailing list
[email protected]
https://www.stunnel.org/cgi-bin/mailman/listinfo/stunnel-users

--===============7837591136009863093==--