rsync - Jun 2003 - Cygwin Rsync 2.5.6 over SSH hangs on Win2k->Win2k

When using Cygwin Rsync 2.5.6/OpenSSH 3.6.1 for copying files from
Win2k->Win2k, I get 2 or 3 hung processes on the receiving-side out of about
every 50 runs.  These hung processes cause the system to be unable to
reboot(?!), requiring a hard reset.  Killing the processes allows a graceful
reboot every time.  I'm currently running both ssh and rsync as services on
the recieving side.  Originally, I ran them as the SYSTEM user, but that
prevented easy killing of the processes, so I now run them under an
administrative account.

Here's the invocation I'm using on the client side (SSH is forwarding
port
2001 on the localhost to the remote machine through a firewall):

rsync --blocking-io --stats --port=2100 -ur --force --delete
/cygdrive/d/srcfolder username@localhost::module/destfolder

I've tried using various levels of verbose output (such as -vvv) as was
suggested previously as a fix for older rsync versions, but to no avail.
Turning it off doesn't help either.  I've also turned off rsync logging
for
fear that it might be locking the log file.  I've also tried the patched
version of Cygwin Rsync that was posted recently on the mailing list as a
URL.  No change.

In case it will help any Cygwin hackers monitoring the list, I've attached
the output of cygcheck for the receiving-side computer.  If anything else I
can provide might help, please let me know.  

Our testing didn't catch this problem before we went to production, and
we've been suffering from this for some time, while all my research and
efforts have failed.  I really want rsync/ssh to be our solution (Open
Source advocacy is a hot button in our shop here!) but I can't let this
failure to log off or restart production servers continue.

jpt

------------------------------------
James Tillman
Advanced Systems Design
FDLE Webmaster
850-410-8415
JamesTillman@fdle.state.fl.us


-------------- next part --------------

Cygwin Win95/NT Configuration Diagnostics
Current System Time: Mon Jun 23 09:40:20 2003

Windows NT Ver 4.0 Build 1381 Service Pack 6

Path:	C:\cygwin\usr\local\bin
	C:\cygwin\bin
	C:\cygwin\bin
	C:\cygwin\bin
	c:\Perl\bin
	c:\WINNT\system32
	c:\WINNT
	c:\Program Files\Mts
	c:\MSSQL7\BINN

C:\cygwin\bin\id.exe output (nontsec)
UID: 1010(Webmaster)  GID: 544(Administrators)
513(None)             544(Administrators)
545(Users)

C:\cygwin\bin\id.exe output (ntsec)
UID: 1010(Webmaster)  GID: 544(Administrators)
513(None)             544(Administrators)
545(Users)

SysDir: C:\WINNT\System32
WinDir: C:\WINNT

CYGWIN = `ntsec tty'
HOME = `C:\cygwin\home\Webmaster'
MAKE_MODE = `unix'
PWD = `/'
USER = `Webmaster'

COMPUTERNAME = `WEB2'
COMSPEC = `C:\WINNT\system32\cmd.exe'
HOMEDRIVE = `C:'
HOMEPATH = `\'
INCLUDE = `C:\Program Files\Mts\Include'
LIB = `C:\Program Files\Mts\Lib'
LOGONSERVER = `\\WEB2'
MANPATH = `:/usr/ssl/man'
NUMBER_OF_PROCESSORS = `2'
OLDPWD = `/usr'
OS2LIBPATH = `C:\WINNT\system32\os2\dll;'
OS = `Windows_NT'
PATHEXT = `.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH'
PROCESSOR_ARCHITECTURE = `x86'
PROCESSOR_IDENTIFIER = `x86 Family 6 Model 8 Stepping 6, GenuineIntel'
PROCESSOR_LEVEL = `6'
PROCESSOR_REVISION = `0806'
PROMPT = `$P$G'
PS1 = `\[\033]0;\w\007
\033[32m\]\u@\h \[\033[33m\w\033[0m\]
$ '
SHLVL = `1'
SYSTEMDRIVE = `C:'
SYSTEMROOT = `C:\WINNT'
TEMP = `c:\TEMP'
TERM = `cygwin'
USERDOMAIN = `WEB2'
USERNAME = `webmaster'
USERPROFILE = `C:\WINNT\Profiles\webmaster'
WINDIR = `C:\WINNT'
_ = `/usr/bin/cygcheck'

HKEY_CURRENT_USER\Software\Cygnus Solutions
HKEY_CURRENT_USER\Software\Cygnus Solutions\Cygwin
HKEY_CURRENT_USER\Software\Cygnus Solutions\Cygwin\mounts v2
  (default) = `/cygdrive'
  cygdrive flags = 0x00000022
HKEY_CURRENT_USER\Software\Cygnus Solutions\Cygwin\Program Options
HKEY_LOCAL_MACHINE\SOFTWARE\Cygnus Solutions
HKEY_LOCAL_MACHINE\SOFTWARE\Cygnus Solutions\Cygwin
HKEY_LOCAL_MACHINE\SOFTWARE\Cygnus Solutions\Cygwin\mounts v2
  (default) = `/cygdrive'
  cygdrive flags = 0x00000022
HKEY_LOCAL_MACHINE\SOFTWARE\Cygnus Solutions\Cygwin\mounts v2\/
  (default) = `C:/cygwin'
  flags = 0x0000000a
HKEY_LOCAL_MACHINE\SOFTWARE\Cygnus Solutions\Cygwin\mounts v2\/usr/bin
  (default) = `C:/cygwin/bin'
  flags = 0x0000000a
HKEY_LOCAL_MACHINE\SOFTWARE\Cygnus Solutions\Cygwin\mounts v2\/usr/lib
  (default) = `C:/cygwin/lib'
  flags = 0x0000000a
HKEY_LOCAL_MACHINE\SOFTWARE\Cygnus Solutions\Cygwin\Program Options

a:  fd  FAT        1Mb   2% CP    UN           
c:  hd  NTFS    4094Mb  54% CP CS UN PA FC     
d:  hd  NTFS   13225Mb  54% CP CS UN PA FC     
e:  cd           N/A    N/A                    

.              /cygdrive  user    binmode,cygdrive
C:/cygwin      /          system  binmode
C:/cygwin/bin  /usr/bin   system  binmode
C:/cygwin/lib  /usr/lib   system  binmode
.              /cygdrive  system  binmode,cygdrive

Found: C:\cygwin\bin\awk.exe
Found: C:\cygwin\bin\bash.exe
Found: C:\cygwin\bin\cat.exe
Found: C:\cygwin\bin\cp.exe
Not Found: cpp (good!)
Found: C:\cygwin\bin\find.exe
Not Found: gcc
Not Found: gdb
Found: C:\cygwin\bin\grep.exe
Found: C:\cygwin\bin\ld.exe
Found: C:\cygwin\bin\ls.exe
Not Found: make
Found: C:\cygwin\bin\mv.exe
Found: C:\cygwin\bin\rm.exe
Found: C:\cygwin\bin\sed.exe
Found: C:\cygwin\bin\sh.exe
Found: C:\cygwin\bin\tar.exe

   58k 2002/05/07 C:\cygwin\bin\cygbz2-1.dll - os=4.0 img=1.0 sys=4.0
                  "cygbz2-1.dll" v0.0 ts=2002/5/7 2:33
  848k 2003/04/11 C:\cygwin\bin\cygcrypto-0.9.7.dll - os=4.0 img=1.0 sys=4.0
                  "cygcrypto-0.9.7.dll" v0.0 ts=2003/4/11 6:33
  645k 2003/04/11 C:\cygwin\bin\cygcrypto.dll - os=4.0 img=1.0 sys=4.0
                  "cygcrypto.dll" v0.0 ts=2003/4/11 6:37
   45k 2001/04/25 C:\cygwin\bin\cygform5.dll - os=4.0 img=1.0 sys=4.0
                  "cygform5.dll" v0.0 ts=2001/4/25 1:28
   35k 2002/01/09 C:\cygwin\bin\cygform6.dll - os=4.0 img=1.0 sys=4.0
                  "cygform6.dll" v0.0 ts=2002/1/9 1:03
   76k 2003/03/09 C:\cygwin\bin\cygform7.dll - os=4.0 img=1.0 sys=4.0
                  "cygform7.dll" v0.0 ts=2003/3/9 15:51
   28k 2003/03/22 C:\cygwin\bin\cyggdbm-3.dll - os=4.0 img=1.0 sys=4.0
                  "cyggdbm-3.dll" v0.0 ts=2003/3/22 17:19
   19k 2003/03/22 C:\cygwin\bin\cyggdbm.dll - os=4.0 img=1.0 sys=4.0
                  "cyggdbm.dll" v0.0 ts=2002/2/19 22:05
   15k 2003/03/22 C:\cygwin\bin\cyggdbm_compat-3.dll - os=4.0 img=1.0 sys=4.0
                  "cyggdbm_compat-3.dll" v0.0 ts=2003/3/22 17:22
   17k 2001/06/28 C:\cygwin\bin\cyghistory4.dll - os=4.0 img=1.0 sys=4.0
                  "cyghistory4.dll" v0.0 ts=2001/1/6 23:34
   20k 2002/10/10 C:\cygwin\bin\cyghistory5.dll - os=4.0 img=1.0 sys=4.0
                  "cyghistory5.dll" v0.0 ts=2002/10/10 13:28
  929k 2002/06/24 C:\cygwin\bin\cygiconv-2.dll - os=4.0 img=1.0 sys=4.0
                  "cygiconv-2.dll" v0.0 ts=2002/6/24 14:24
   22k 2001/12/13 C:\cygwin\bin\cygintl-1.dll - os=4.0 img=1.0 sys=4.0
                  "cygintl-1.dll" v0.0 ts=2001/12/13 4:28
   28k 2002/09/20 C:\cygwin\bin\cygintl-2.dll - os=4.0 img=1.0 sys=4.0
                  "cygintl-2.dll" v0.0 ts=2002/9/19 23:13
   26k 2001/04/25 C:\cygwin\bin\cygmenu5.dll - os=4.0 img=1.0 sys=4.0
                  "cygmenu5.dll" v0.0 ts=2001/4/25 1:27
   20k 2002/01/09 C:\cygwin\bin\cygmenu6.dll - os=4.0 img=1.0 sys=4.0
                  "cygmenu6.dll" v0.0 ts=2002/1/9 1:03
   48k 2003/03/09 C:\cygwin\bin\cygmenu7.dll - os=4.0 img=1.0 sys=4.0
                  "cygmenu7.dll" v0.0 ts=2003/3/9 15:51
  156k 2001/04/25 C:\cygwin\bin\cygncurses++5.dll - os=4.0 img=1.0 sys=4.0
                  "cygncurses++5.dll" v0.0 ts=2001/4/25 1:29
  175k 2002/01/09 C:\cygwin\bin\cygncurses++6.dll - os=4.0 img=1.0 sys=4.0
                  "cygncurses++6.dll" v0.0 ts=2002/1/9 1:03
  226k 2001/04/25 C:\cygwin\bin\cygncurses5.dll - os=4.0 img=1.0 sys=4.0
                  "cygncurses5.dll" v0.0 ts=2001/4/25 1:17
  202k 2002/01/09 C:\cygwin\bin\cygncurses6.dll - os=4.0 img=1.0 sys=4.0
                  "cygncurses6.dll" v0.0 ts=2002/1/9 1:03
  284k 2003/03/09 C:\cygwin\bin\cygncurses7.dll - os=4.0 img=1.0 sys=4.0
                  "cygncurses7.dll" v0.0 ts=2003/3/9 15:50
   15k 2001/04/25 C:\cygwin\bin\cygpanel5.dll - os=4.0 img=1.0 sys=4.0
                  "cygpanel5.dll" v0.0 ts=2001/4/25 1:27
   12k 2002/01/09 C:\cygwin\bin\cygpanel6.dll - os=4.0 img=1.0 sys=4.0
                  "cygpanel6.dll" v0.0 ts=2002/1/9 1:03
   31k 2003/03/09 C:\cygwin\bin\cygpanel7.dll - os=4.0 img=1.0 sys=4.0
                  "cygpanel7.dll" v0.0 ts=2003/3/9 15:50
   66k 2003/06/12 C:\cygwin\bin\cygpcre-0.dll - os=4.0 img=1.0 sys=4.0
                  "cygpcre-0.dll" v0.0 ts=2003/6/12 4:36
   63k 2003/04/11 C:\cygwin\bin\cygpcre.dll - os=4.0 img=1.0 sys=4.0
                  "cygpcre.dll" v0.0 ts=2003/4/11 4:31
   15k 2003/06/12 C:\cygwin\bin\cygpcreposix-0.dll - os=4.0 img=1.0 sys=4.0
                  "cygpcreposix-0.dll" v0.0 ts=2003/6/12 4:36
   61k 2003/04/11 C:\cygwin\bin\cygpcreposix.dll - os=4.0 img=1.0 sys=4.0
                  "cygpcreposix.dll" v0.0 ts=2003/4/11 4:31
   22k 2002/06/09 C:\cygwin\bin\cygpopt-0.dll - os=4.0 img=1.0 sys=4.0
                  "cygpopt-0.dll" v0.0 ts=2002/6/9 1:45
  108k 2001/06/28 C:\cygwin\bin\cygreadline4.dll - os=4.0 img=1.0 sys=4.0
                  "cygreadline4.dll" v0.0 ts=2001/1/6 23:34
  127k 2002/10/10 C:\cygwin\bin\cygreadline5.dll - os=4.0 img=1.0 sys=4.0
                  "cygreadline5.dll" v0.0 ts=2002/10/10 13:28
  176k 2003/04/11 C:\cygwin\bin\cygssl-0.9.7.dll - os=4.0 img=1.0 sys=4.0
                  "cygssl-0.9.7.dll" v0.0 ts=2003/4/11 6:33
  165k 2003/04/11 C:\cygwin\bin\cygssl.dll - os=4.0 img=1.0 sys=4.0
                  "cygssl.dll" v0.0 ts=2003/4/11 6:37
   50k 2002/03/12 C:\cygwin\bin\cygz.dll - os=4.0 img=1.0 sys=4.0
                  "cygz.dll" v0.0 ts=2002/3/11 23:38
  948k 2003/03/18 C:\cygwin\bin\cygwin1.dll - os=4.0 img=1.0 sys=4.0
                  "cygwin1.dll" v0.0 ts=2003/3/18 9:20
    Cygwin DLL version info:
        DLL version: 1.3.22
        DLL epoch: 19
        DLL bad signal mask: 19005
        DLL old termios: 5
        DLL malloc env: 28
        API major: 0
        API minor: 78
        Shared data: 3
        DLL identifier: cygwin1
        Mount registry: 2
        Cygnus registry name: Cygnus Solutions
        Cygwin registry name: Cygwin
        Program options name: Program Options
        Cygwin mount registry name: mounts v2
        Cygdrive flags: cygdrive flags
        Cygdrive prefix: cygdrive prefix
        Cygdrive default prefix: 
        Build date: Tue Mar 18 09:20:11 EST 2003
        CVS tag: dontuse-21
        Shared id: cygwin1S3


Cygwin Package Information
Last downloaded files to:
C:\WINNT\Profiles\webmaster\Desktop\http%3a%2f%2fmirror.averse.net%2fcygwin
Last downloaded files from: http://mirror.averse.net/cygwin

Package              Version
_update-info-dir     00168-1
ash                  20020731-1
base-files           1.3-1
base-passwd          1.1-1
bash                 2.05b-9
binutils             20030307-1
bzip2                1.0.2-2
clear                1.0-1
crypt                1.0-1
cygrunsrv            0.96-1
cygutils             1.1.4-2
cygwin               1.3.22-1
diff                 1.0-1
diffutils            2.8.1-1
expect               20030128-1
fileutils            4.1-1
findutils            4.1.7-4
gawk                 3.1.2-2
gdbm                 1.8.3-1
grep                 2.5-1
groff                1.18.1-2
gzip                 1.3.3-4
inetutils            1.3.2-22
less                 378-1
libbz2_1             1.0.2-2
libgdbm              1.8.0-5
libgdbm-devel        1.8.3-1
libgdbm3             1.8.3-1
libiconv2            1.8-2
libintl1             0.10.40-1
libintl2             0.11.5-1
libncurses5          5.2-1
libncurses6          5.2-8
libncurses7          5.3-1
libpcre              4.1-1
libpcre0             4.2-2
libpopt0             1.6.4-4
libreadline4         4.1-2
libreadline5         4.3-2
login                1.9-5
man                  1.5j-2
mktemp               1.4-1
mt                   2.0.1-1
ncurses              5.3-1
openssh              3.6.1p1-2
openssl              0.9.7b-1
openssl096           0.9.6j-1
patch                2.5.8-3
pcre                 4.2-2
pcre-doc             4.2-2
popt                 1.6.4-4
readline             4.3-2
rsync                2.5.6-1
sed                  4.0.7-1
sh-utils             2.0.15-3
shellutils           0.0
tar                  1.13.25-1
tcltk                20030214-1
termcap              20020930-1
terminfo             5.3-2
texinfo              4.2-4
textutils            2.0.21-1
time                 1.7-1
unzip                5.50-2
vim                  6.2-1
which                1.5-1
zip                  2.3-2
zlib                 1.1.4-1

Use -h to see help about each section

Tillman, James wrote:
>> When using Cygwin Rsync 2.5.6/OpenSSH 3.6.1 for copying files from
>> Win2k->Win2k, I get 2 or 3 hung processes on the receiving-side out
of
about
>> every 50 runs.  These hung processes cause the system to be unable to
>> reboot(?!), requiring a hard reset.  Killing the processes allows a
graceful
>> reboot every time.  I'm currently running both ssh and rsync as
services
on
>> the recieving side.  Originally, I ran them as the SYSTEM user, but
that
>> prevented easy killing of the processes, so I now run them under an
>> administrative account.
I suggest building and using an unstripped version of rsync, and then using
gdb to obtain a backtrace from a hung process.

Max.

> -----Original Message-----
> From: Tillman, James 
> Sent: Thursday, June 26, 2003 12:18 PM
> To: 'rsync@lists.samba.org'
> Subject: Cygwin Rsync 2.5.6 over SSH hangs on Win2k->Win2k
> 
> 
> When using Cygwin Rsync 2.5.6/OpenSSH 3.6.1 for copying files from
> Win2k->Win2k, I get 2 or 3 hung processes on the 
> receiving-side out of about
> every 50 runs.  
I left out a few details that might help:

1. The hung processes come in 2's.  So it's either 2 or 4 or 6, etc.  I
read
somewhere about rsync using one process for sending and a second process for
receiving, so perhaps that why the hangs come in pairs.

2. I tried attaching to the processes with strace, but received no output at
all.  It might be that I didn't know what I was doing.  I used this
invocation on each one:

strace -p 123  (where 123 is the process id)

jpt

> When using Cygwin Rsync 2.5.6/OpenSSH 3.6.1 for copying files from
> Win2k->Win2k, I get 2 or 3 hung processes on the receiving-side out of
about
> every 50 runs.  These hung processes cause the system to be unable to
> reboot(?!), requiring a hard reset.  Killing the processes allows a
graceful
> reboot every time.  I'm currently running both ssh and rsync as
services on
> the recieving side.  Originally, I ran them as the SYSTEM user, but that
> prevented easy killing of the processes, so I now run them under an
> administrative account.
This has been reported by a number of users.  Happily(?), it started to
happen to me a week ago so I have been able to poke around and see what
is happening.

At the end of the transfer, on the receiving machine the child goes
into an msleep loop waiting for the parent to kill it with a
USR2 signal.  See line 442 of main.c (rsync 2.5.6):

        /* finally we go to sleep until our parent kills us
           with a USR2 signal. We sleep for a short time as on
           some OSes a signal won't interrupt a sleep! */
        while (msleep(20))
                ;

On cygwin the child sometimes hangs at this point.  When this happens,
any cygwin signal fails to kill the child (including kill -9).

While I haven't found the root cause (and I don't know any cygwin
internals), the following workaround solves the problem for me.
Replace msleep() wit sleep():

        while ( 1 ) {
            sleep(1);
        }

There's something about signals and msleep() that cygwin doesn't grok...

Craig

> -----Original Message-----
> From: cbarratt@users.sourceforge.net
> [mailto:cbarratt@users.sourceforge.net]
> Sent: Friday, June 27, 2003 1:48 AM
> To: Tillman, James
> Cc: 'rsync@lists.samba.org'
> Subject: Re: Cygwin Rsync 2.5.6 over SSH hangs on Win2k->Win2k 
> 
> 
[...]
> While I haven't found the root cause (and I don't know any cygwin
> internals), the following workaround solves the problem for me.
> Replace msleep() wit sleep():
> 
>         while ( 1 ) {
>             sleep(1);
>         }
> 
> There's something about signals and msleep() that cygwin 
> doesn't grok...
> 
> Craig
> 
The sleep(1) mod didn't work for me.  I had a hung process within an hour
(processes run every 5 minutes).  I'm going to try applying Anthony
Heading's patch, which was posted earlier this morning (Subject: PATCH/RFC:
Another stab at the Cygwin hang problem) to see if it works for me.  I've
got nothing to lose at this point!

I had been questioning the wisdom of the whole kill/signal usage, myself,
but I'm certainly not experienced enough at this point to have a worthy
opinion in such matters...  There's almost certainly a reason it was done
that way.

jpt

Last week, I sent this msg:
> The sleep(1) mod didn't work for me. I had a hung process within an
hour
> (processes run every 5 minutes). I'm going to try applying Anthony
Heading's 
> patch, which was posted earlier this morning (Subject: PATCH/RFC: Another 
> stab at the Cygwin hang problem) to see if it works for me. I've got
nothing 
> to lose at this point!
I just wanted to say that Anthony's patch worked perfectly for me (so far) 
and my current crisis is averted.  I'm closely watching the running system.
I 
want to thank everyone who provided assistance.  

This is yet another example I can use to point out the benefits of open
source 
software to any stalwarts in my organization.  I received real help with my 
problem in less than 6 hours after my original email, and I had rsync
recompiled 
and deployed less than an hour after I decided to use Anthony's patch.
Thanks 
so much.

jpt

------------------------------------
James Tillman
Advanced Systems Design
FDLE Webmaster