<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"><head><META HTTP-EQUIV="Content-Type" CONTENT="text/html; charset=us-ascii"><meta name=Generator content="Microsoft Word 14 (filtered medium)"><style><!--
/* Font Definitions */
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
@font-face
{font-family:Tahoma;
panose-1:2 11 6 4 3 5 4 4 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri","sans-serif";}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:blue;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:purple;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal;
font-family:"Calibri","sans-serif";
color:windowtext;}
span.EmailStyle18
{mso-style-type:personal-reply;
font-family:"Calibri","sans-serif";
color:#1F497D;}
.MsoChpDefault
{mso-style-type:export-only;
font-size:10.0pt;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]--></head><body lang=EN-US link=blue vlink=purple><div class=WordSection1><p class=MsoNormal><span style='color:#1F497D'>This turned out to be an issue with rsync-3.1.0, and fixed in rsync-3.1.1:<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'> - Fixed a bug in the early daemon protocol where a timeout failed to be<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'> honored (e.g. if the remote side fails to send us the initial protocol<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'> greeting).<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'>Thanks,<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'>Steve<o:p></o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><p class=MsoNormal><span style='color:#1F497D'><o:p> </o:p></span></p><div style='border:none;border-left:solid blue 1.5pt;padding:0in 0in 0in 4.0pt'><div><div style='border:none;border-top:solid #B5C4DF 1.0pt;padding:3.0pt 0in 0in 0in'><p class=MsoNormal><b><span style='font-size:10.0pt;font-family:"Tahoma","sans-serif"'>From:</span></b><span style='font-size:10.0pt;font-family:"Tahoma","sans-serif"'> stunnel-users [mailto:stunnel-users-bounces@stunnel.org] <b>On Behalf Of </b>Polyack, Steve<br><b>Sent:</b> Wednesday, October 22, 2014 12:36 PM<br><b>To:</b> stunnel-users@stunnel.org<br><b>Cc:</b> Saathoff, Graham<br><b>Subject:</b> [stunnel-users] stunnel service leaves stale connections to rsync on the server side<o:p></o:p></span></p></div></div><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Hi,<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>We’ve been running a rsync service over stunnel for some time now. After upgrading our environment, which involved moving from an old version of Linux to FreeBSD 9.3, and from stunnel-4.29 to stunnel-5.06, we’ve had a problem pop up.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Ever since switching over, we see that rsync daemon processes slowly build up over time on our server, each consuming 100% CPU. The vast majority of our clients are working just fine, and the problematic rsync processes just seem to have been dead/aborted connections from the clients (which are using wireless aircard, so connectivity can be shotty). <o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>A quick ‘truss’ on the process shows they are doing nothing but sitting there and read()’ing in a loop indefinitely:<o:p></o:p></p><p class=MsoNormal># truss -p 14689 | head<o:p></o:p></p><p class=MsoNormal>read(6,0x7fffffff8240,1) = 0 (0x0)<o:p></o:p></p><p class=MsoNormal>read(6,0x7fffffff8240,1) = 0 (0x0)<o:p></o:p></p><p class=MsoNormal>read(6,0x7fffffff8240,1) = 0 (0x0)<o:p></o:p></p><p class=MsoNormal>read(6,0x7fffffff8240,1) = 0 (0x0)<o:p></o:p></p><p class=MsoNormal>read(6,0x7fffffff8240,1) = 0 (0x0)<o:p></o:p></p><p class=MsoNormal>read(6,0x7fffffff8240,1) = 0 (0x0)<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Furthermore, the connection appears to be closed:<o:p></o:p></p><p class=MsoNormal># sockstat -4 | grep 14689<o:p></o:p></p><p class=MsoNormal>root rsync 14689 3 tcp4 127.0.0.1:873 127.0.0.1:27724<o:p></o:p></p><p class=MsoNormal>netstat -an | grep 27724<o:p></o:p></p><p class=MsoNormal>netstat: kvm not available: /dev/mem: No such file or directory<o:p></o:p></p><p class=MsoNormal>tcp4 0 0 127.0.0.1.873 127.0.0.1.27724 CLOSED<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Looking through the stunnel logs, it looks like no data was ever really passed (perhaps the client gave up?): <o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: Service [rsync] started <o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG5[34384941056]: Service [rsync] accepted connection from 1.1.1.1:63095<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): before/accept initialization<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 read client hello A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 write server hello A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 write certificate A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 write server done A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 flush data<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 read client key exchange A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 read finished A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 write change cipher spec A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 write finished A<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: SSL state (accept): SSLv3 flush data<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 41 items in the session cache<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 0 client connects (SSL_connect())<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 0 client connects that finished<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 0 client renegotiations requested<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 110 server connects (SSL_accept())<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 107 server connects that finished<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 0 server renegotiations requested<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 66 session cache hits<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 0 external session cache hits<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 32 session cache misses<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: 0 session cache timeouts<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG6[34384941056]: No peer certificate received<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG6[34384941056]: SSL accepted: new session negotiated<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG6[34384941056]: Negotiated SSLv3 ciphersuite AES256-SHA (256-bit encryption)<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG6[34384941056]: Compression: null, expansion: null<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG6[34384941056]: s_connect: connecting 127.0.0.1:873<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG5[34384941056]: s_connect: connected 127.0.0.1:873<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG5[34384941056]: Service [rsync] connected remote server from 127.0.0.1:27724<o:p></o:p></p><p class=MsoNormal>2014.10.22 10:45:52 LOG7[34384941056]: Remote socket (FD=11) initialized<o:p></o:p></p><p class=MsoNormal>2014.10.22 11:01:12 LOG3[34384941056]: SSL_read: Connection reset by peer (54)<o:p></o:p></p><p class=MsoNormal>2014.10.22 11:01:12 LOG5[34384941056]: Connection reset: 56 byte(s) sent to SSL, 56 byte(s) sent to socket<o:p></o:p></p><p class=MsoNormal>2014.10.22 11:01:12 LOG7[34384941056]: Remote socket (FD=11) closed<o:p></o:p></p><p class=MsoNormal>2014.10.22 11:01:12 LOG7[34384941056]: Local socket (FD=10) closed<o:p></o:p></p><p class=MsoNormal>2014.10.22 11:01:12 LOG7[34384941056]: Service [rsync] finished (4 left)<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>The clients are generally field units running stunnel versions in the 4.x range. Unfortunately, updating them is not an easy task and is not really under my control. Either way, this seems like a server side issue, and possibly an issue with rsync (we’re running 3.1.0).<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Has anyone run into anything like this before? Does anyone have any suggestions for additional debugging we can do to try to pinpoint the problem? We are going to try rolling back to stunnel-4.29 to see if the problem still occurs there on the new system.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Thanks,<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Steve<o:p></o:p></p></div></div></body></html>