rsync hangs during --remove-source-files
Thomas Gutzler
thomas.gutzler at gmail.com
Fri Oct 17 07:34:03 GMT 2008
Hi,
I had another rsync hang. I've attached a text file with the stack
traces you asked for and some other info. There were three rsync
processes running at the time.
I haven't heard anything from Wayne yet - maybe this generates more
interest.
Cheers,
Tom
Matt McCutchen wrote:
> On Mon, 2008-10-13 at 21:19 +0800, Thomas Gutzler wrote:
>> I'm using the following command to move files from a to b:
>> rsync -avvvv --remove-source-files --ignore-existing /path/to/dir1/
>> /path/to/dir2 >> logfile
>> dir2 isn't empty so I only move files from dir1 to dir2 that don't exist
>> already.
>> Every so often rsync stops in the middle and doesn't continue with the
>> result that I have to kill it.
>
>> Any suggestions how to debug this so that I can find out what's going
>> on? Unfortunately I haven't found a way to reproduce it. Every time I
>> kill and execute the same command again, it works.
>
> The next time rsync hangs, before you kill it, attach gdb to each of the
> three rsync processes ("gdb /PATH/TO/rsync PID") and get a stack trace
> ("bt"). Wayne should have more suggestions for what information would
> be helpful for debugging.
>
> Matt
-------------- next part --------------
root at jo:~# ps ax | grep rsync
5249 ? S 0:00 sh -c /usr/local/rsync3/bin/rsync -avvvv --remove-source-files --ignore-existing /home/backup/snapshots/frequent_2008-10-09_18-00-01/ /home/backup/snapshots/daily_2008-10-17_05-00-01 >> /home/backup/logs/frequent_2008-10-17_12-00-01.log 2>&1
5250 ? S 0:02 /usr/local/rsync3/bin/rsync -avvvv --remove-source-files --ignore-existing /home/backup/snapshots/frequent_2008-10-09_18-00-01/ /home/backup/snapshots/daily_2008-10-17_05-00-01
5251 ? S 0:00 /usr/local/rsync3/bin/rsync -avvvv --remove-source-files --ignore-existing /home/backup/snapshots/frequent_2008-10-09_18-00-01/ /home/backup/snapshots/daily_2008-10-17_05-00-01
5252 ? S 0:02 /usr/local/rsync3/bin/rsync -avvvv --remove-source-files --ignore-existing /home/backup/snapshots/frequent_2008-10-09_18-00-01/ /home/backup/snapshots/daily_2008-10-17_05-00-01
root at jo:~# lsof | grep rsync | grep backup
COMMAND PID USER FD TYPE DEVICE SIZE NODE NAME
rsync 5250 root cwd DIR 254,0 4096 15290437 /home/backup/snapshots/frequent_2008-10-09_18-00-01
rsync 5250 root 1w REG 254,0 1258828 76689435 /home/backup/logs/frequent_2008-10-17_12-00-01.log
rsync 5250 root 2w REG 254,0 1258828 76689435 /home/backup/logs/frequent_2008-10-17_12-00-01.log
rsync 5251 root cwd DIR 254,0 4096 15294467 /home/backup/snapshots/daily_2008-10-17_05-00-01
rsync 5251 root 2w REG 254,0 1258828 76689435 /home/backup/logs/frequent_2008-10-17_12-00-01.log
rsync 5252 root cwd DIR 254,0 4096 15294467 /home/backup/snapshots/daily_2008-10-17_05-00-01
rsync 5252 root 2w REG 254,0 1258828 76689435 /home/backup/logs/frequent_2008-10-17_12-00-01.log
root at jo:/home/backup/logs# tail -2 frequent_2008-10-17_12-00-01.log
touch_up_dirs: home/io/obel/acuratolo/.winnt/profile/Cookies (20)
set modtime of home/io/obel/acuratolo/.winnt/profile/Cookies to (1223546878) Thu Oct 9 18:07:58 2008
root at jo:/home/backup/snapshots# ll -d daily_2008-10-17_05-00-01/home/io/obel/acuratolo/.winnt/profile/Cookies frequent_2008-10-09_18-00-01/home/io/obel/acuratolo/.winnt/profile/Cookies
drwx------ 2 1161 1097 4096 2008-10-09 18:07 daily_2008-10-17_05-00-01/home/io/obel/acuratolo/.winnt/profile/Cookies/
drwx------ 2 1161 1097 4096 2008-10-17 12:15 frequent_2008-10-09_18-00-01/home/io/obel/acuratolo/.winnt/profile/Cookies/
root at jo:~# gdb /usr/local/rsync3/bin/rsync 5250
GNU gdb 6.4.90-debian
Copyright (C) 2006 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...Using host libthread_db library "/lib/tls/i686/cmov/libthread_db.so.1".
Attaching to program: /usr/local/rsync3/bin/rsync, process 5250
Reading symbols from /lib/tls/i686/cmov/libc.so.6...done.
Loaded symbols for /lib/tls/i686/cmov/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/tls/i686/cmov/libnss_compat.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_compat.so.2
Reading symbols from /lib/tls/i686/cmov/libnsl.so.1...done.
Loaded symbols for /lib/tls/i686/cmov/libnsl.so.1
Reading symbols from /lib/tls/i686/cmov/libnss_nis.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_nis.so.2
Reading symbols from /lib/tls/i686/cmov/libnss_files.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_files.so.2
0xffffe410 in __kernel_vsyscall ()
(gdb) bt
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb7ecd2ed in select () from /lib/tls/i686/cmov/libc.so.6
#2 0x08070433 in read_timeout (fd=5,
buf=0xbffe9478 "set modtime of home/io/obel/acuratolo/.winnt/profile/Cookies to (1223546878) Thu Oct 9 18:07:58 2008\nfault/Mail/mail.ee.uwa.edu.au to (1218426141) Mon Aug 11 11:42:21 2008\n:31 2008\n11].txt\nplication "..., len=4) at io.c:685
#3 0x0807094e in read_loop (fd=5,
buf=0xbffe9478 "set modtime of home/io/obel/acuratolo/.winnt/profile/Cookies to (1223546878) Thu Oct 9 18:07:58 2008\nfault/Mail/mail.ee.uwa.edu.au to (1218426141) Mon Aug 11 11:42:21 2008\n:31 2008\n11].txt\nplication "..., len=3221132132) at io.c:1018
#4 0x08070bae in readfd_unbuffered (fd=5, buf=0xbffeaad8 "", len=1) at io.c:1055
#5 0x080711d6 in readfd (fd=5, buffer=0xbffeaad8 "", N=1) at io.c:1184
#6 0x080715f1 in read_ndx (f=5) at io.c:1800
#7 0x080526fc in read_ndx_and_attrs (f_in=5, iflag_ptr=0xbffeac4c, type_ptr=0xbffeac53 "\200",
buf=0xbffeac54 "", len_ptr=0xbffeac48) at rsync.c:254
#8 0x0805b957 in send_files (f_in=5, f_out=4) at sender.c:187
#9 0x08064043 in client_run (f_in=5, f_out=<value optimized out>, pid=5251, argc=1, argv=0x80b1df8)
at main.c:1027
#10 0x08065038 in main (argc=Cannot access memory at address 0x1483
) at main.c:1275
root at jo:~# gdb /usr/local/rsync3/bin/rsync 5251
GNU gdb 6.4.90-debian
Copyright (C) 2006 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...Using host libthread_db library "/lib/tls/i686/cmov/libthread_db.so.1".
Attaching to program: /usr/local/rsync3/bin/rsync, process 5251
Reading symbols from /lib/tls/i686/cmov/libc.so.6...done.
Loaded symbols for /lib/tls/i686/cmov/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/tls/i686/cmov/libnss_compat.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_compat.so.2
Reading symbols from /lib/tls/i686/cmov/libnsl.so.1...done.
Loaded symbols for /lib/tls/i686/cmov/libnsl.so.1
Reading symbols from /lib/tls/i686/cmov/libnss_nis.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_nis.so.2
Reading symbols from /lib/tls/i686/cmov/libnss_files.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_files.so.2
0xffffe410 in __kernel_vsyscall ()
(gdb) bt
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb7ecd2ed in select () from /lib/tls/i686/cmov/libc.so.6
#2 0x08070433 in read_timeout (fd=3, buf=0x80b3720 "9", len=8184) at io.c:685
#3 0x08070d7f in readfd_unbuffered (fd=3,
buf=0xbffe8088 "set modtime of home/io/obel/acuratolo/.winnt/profile/Application Data/Thunderbird/Profiles/eqbe5hfh.default/Mail/Local Folders/Companies.sbd/.wptec optics.msf.w3PP8z to (1223519288) Thu Oct 9 10:28:0"..., len=4) at io.c:1041
#4 0x080711d6 in readfd (fd=3,
buffer=0xbffe8088 "set modtime of home/io/obel/acuratolo/.winnt/profile/Application Data/Thunderbird/Profiles/eqbe5hfh.default/Mail/Local Folders/Companies.sbd/.wptec optics.msf.w3PP8z to (1223519288) Thu Oct 9 10:28:0"..., N=4) at io.c:1184
#5 0x0806ed4a in read_msg_fd () at io.c:374
#6 0x08071ae5 in increment_active_files (ndx=302, itemizing=1, code=FLOG) at io.c:493
#7 0x08057ea6 in recv_generator (
fname=0xbffeabb4 "home/io/obel/acuratolo/.winnt/profile/Recent/HOPS2 axial resolution.doc.lnk",
file=0xb7d022e4, ndx=302, itemizing=1, code=FLOG, f_out=1) at generator.c:1918
#8 0x080588ac in generate_files (f_out=1, local_name=0x0) at generator.c:2259
#9 0x08063c0f in do_recv (f_in=0, f_out=1, local_name=0x0) at main.c:830
#10 0x0806443b in start_server (f_in=0, f_out=1, argc=2, argv=0xbffeccfc) at main.c:940
#11 0x08065be8 in child_main (argc=2, argv=0xbffeccf8) at main.c:947
#12 0x0807b5eb in local_child (argc=2, argv=0xbffeccf8, f_in=0xbffedd2c, f_out=0xbffedd28,
child_main=0x8065bc0 <child_main>) at pipe.c:156
#13 0x08064fbb in main (argc=Cannot access memory at address 0xffffffff
) at main.c:463
root at jo:~# gdb /usr/local/rsync3/bin/rsync 5252
GNU gdb 6.4.90-debian
Copyright (C) 2006 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...Using host libthread_db library "/lib/tls/i686/cmov/libthread_db.so.1".
Attaching to program: /usr/local/rsync3/bin/rsync, process 5252
Reading symbols from /lib/tls/i686/cmov/libc.so.6...done.
Loaded symbols for /lib/tls/i686/cmov/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/tls/i686/cmov/libnss_compat.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_compat.so.2
Reading symbols from /lib/tls/i686/cmov/libnsl.so.1...done.
Loaded symbols for /lib/tls/i686/cmov/libnsl.so.1
Reading symbols from /lib/tls/i686/cmov/libnss_nis.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_nis.so.2
Reading symbols from /lib/tls/i686/cmov/libnss_files.so.2...done.
Loaded symbols for /lib/tls/i686/cmov/libnss_files.so.2
0xffffe410 in __kernel_vsyscall ()
(gdb) bt
#0 0xffffe410 in __kernel_vsyscall ()
#1 0xb7ecd2ed in select () from /lib/tls/i686/cmov/libc.so.6
#2 0x08070433 in read_timeout (fd=0, buf=0xbffe63f8 "\001", len=4) at io.c:685
#3 0x0807094e in read_loop (fd=0, buf=0xbffe63f8 "\001", len=3221119716) at io.c:1018
#4 0x08070bae in readfd_unbuffered (fd=0, buf=0xbffe7a58 "", len=1) at io.c:1055
#5 0x080711d6 in readfd (fd=0, buffer=0xbffe7a58 "", N=1) at io.c:1184
#6 0x080715f1 in read_ndx (f=0) at io.c:1800
#7 0x080526fc in read_ndx_and_attrs (f_in=0, iflag_ptr=0xbffe7bb0, type_ptr=0xbffe7bb7 "\200",
buf=0xbffe9bb8 "", len_ptr=0xbffe7bac) at rsync.c:254
#8 0x0805a028 in recv_files (f_in=0, local_name=0x0) at receiver.c:409
#9 0x08063ae6 in do_recv (f_in=0, f_out=1, local_name=0x0) at main.c:774
#10 0x0806443b in start_server (f_in=0, f_out=1, argc=2, argv=0xbffeccfc) at main.c:940
#11 0x08065be8 in child_main (argc=2, argv=0xbffeccf8) at main.c:947
#12 0x0807b5eb in local_child (argc=2, argv=0xbffeccf8, f_in=0xbffedd2c, f_out=0xbffedd28,
child_main=0x8065bc0 <child_main>) at pipe.c:156
#13 0x08064fbb in main (argc=Cannot access memory at address 0xffffffff
) at main.c:463
More information about the rsync
mailing list