rsync Failure
Shawn Geraghty
sgeraghty at trufina.com
Tue Dec 9 19:15:07 GMT 2008
Matt, et. al:
Sorry, was down a couple days sick.
I ran the debug-script on the remote host. I definitely getting out
of my bailiwick here. Any help if appreciated.
Here is the output:
strce generated via the rsync-debug script on the machine being backed
up:
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\315F\261r\2534\333\310$3m15L
\266\23\33Ov2\250"..., 4096) = 4096
gettimeofday({1228847928, 762022}, NULL) = 0
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\371\16\26\21V\273\211\v\27\r\303_
\327\23\265"..., 4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\241\0063\351\200\327pU\27\246 \216\360:\271"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7Vdc\26y0q\351T\346\223\267T\206\303\346\216"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\335\341J\234\251\256\325|Z
\201\347\210\3\372"..., 4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\217\214\3709\351\347Ev5a\10Q\370\342t@!0\\"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\26\337\346\371\351\313\21\16\26\300gfJJ\22"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\360\313\23\261\"n\371Q\354\347\30z@\227\262"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\241\4Q\223\232\"\377\r\312!\244vx
\16\340\270"..., 4096) = 4096
gettimeofday({1228847928, 764075}, NULL) = 0
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\10fs\322\203f\232\246rF\320\204]G\2\320\26"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\314~;\355`\224\264}\204\366\330\341Xr!\333"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\336\0239\364\375\353G\315z\10Q\r
\305Y7\'\340"..., 4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\313\364\205\207\351\v7\2575\2\2779LE-
\204\265"..., 4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\7\272m\266#tH\272\311\324\247B\365\222\v\360"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "\374\17\0\0072\255m\330/f\32\267\330\2546#,\305\271\223"...,
4096) = 4096
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}) = 0 (Timeout)
select(2, NULL, [1], NULL, {60, 0}
Last 75 lines of rsync log (generated using -vvv) on server performing
backup:
2008/12/09 13:37:36 [7386] send_files(3217,//home/dgranzow/om51/
cygdrive/d/readme_content.htm)
2008/12/09 13:37:36 [7386] send_files mapped //home/dgranzow/om51/
cygdrive/d/readme_content.htm of size 21677
2008/12/09 13:37:36 [7386] recv_files(home/dgranzow/om51/cygdrive/d/
readme_content.htm)
2008/12/09 13:37:36 [7386] calling match_sums //home/dgranzow/om51/
cygdrive/d/readme_content.htm
2008/12/09 13:37:36 [7386] sending file_sum
2008/12/09 13:37:36 [7386] got file_sum
2008/12/09 13:37:36 [7386] >f????????? home/dgranzow/om51/cygdrive/d/
readme_content.htm
2008/12/09 13:37:36 [7386] set modtime of home/dgranzow/om51/cygdrive/
d/.readme_content.htm.KvmPLJ to (1155331401) Fri Aug 11 17:23:21 2006
2008/12/09 13:37:36 [7386] set uid of home/dgranzow/om51/cygdrive/
d/.readme_content.htm.KvmPLJ from 0 to 601
2008/12/09 13:37:36 [7386] set gid of home/dgranzow/om51/cygdrive/
d/.readme_content.htm.KvmPLJ from 0 to 601
2008/12/09 13:37:36 [7386] renaming home/dgranzow/om51/cygdrive/
d/.readme_content.htm.KvmPLJ to home/dgranzow/om51/cygdrive/d/
readme_content.htm
2008/12/09 13:37:36 [7386] false_alarms=0 tag_hits=0 matches=0
2008/12/09 13:37:36 [7386] sender finished //home/dgranzow/om51/
cygdrive/d/readme_content.htm
2008/12/09 13:37:36 [7386] send_files(3219,//home/dgranzow/om51/
cygdrive/d/runtime.img)
2008/12/09 13:37:36 [7386] send_files mapped //home/dgranzow/om51/
cygdrive/d/runtime.img of size 132243456
2008/12/09 13:37:36 [7386] recv_files(home/dgranzow/om51/cygdrive/d/
runtime.img)
2008/12/09 13:37:36 [7386] calling match_sums //home/dgranzow/om51/
cygdrive/d/runtime.img
2008/12/09 13:54:57 [7386] rsync: connection unexpectedly closed
(113545865 bytes received so far) [receiver]
2008/12/09 13:54:57 [7361] rsync: writefd_unbuffered failed to write
4092 bytes [generator]: Broken pipe (32)
2008/12/09 13:54:57 [7386] rsync error: error in rsync protocol data
stream (code 12) at io.c(453) [receiver=2.6.9]
2008/12/09 13:54:57 [7386] _exit_cleanup(code=12, file=io.c,
line=453): about to call exit(12)
2008/12/09 13:54:57 [7361] rsync error: error in rsync protocol data
stream (code 12) at io.c(1122) [generator=2.6.9]
2008/12/09 13:54:57 [7361] _exit_cleanup(code=12, file=io.c,
line=1122): about to call exit(12)
strace from same machine:
7362 <... write resumed> ) = 8192
7386 <... read resumed> "\26\337\346\371\351\313\21\16\26\300gfJJ
\22\253\231\270\326<\210\347\351\303\315Z~\3604\243\227\311"..., 4092)
= 4092
7362 select(8, [4], [], NULL, NULL <unfinished ...>
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\374\17\0\7", 4) = 4
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\360\313\23\261\"n\371Q\354\347\30z@\227\262\372E
\35\342b\335\0r\325\301SM\374}\233\367g"..., 4092) = 4092
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\374\17\0\7", 4) = 4
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\241\4Q\223\232\"\377\r\312!\244vx\16\340\270Z
\37\377\37h\374\373\271\177\fb\330k\'{\322"..., 4092) = 4092
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\374\17\0\7", 4) = 4
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\10fs\322\203f\232\246rF\320\204]G
\2\320\26\266\256]\202m\351dP\345\2128%\336\276\223"..., 4092) = 4092
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\374\17\0\7", 4) = 4
7386 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
7386 read(6, "\314~;\355`\224\264}\204\366\330\341Xr!\333)\346N\r
\274\275\346y\270\234\262\25\363X\352^"..., 4092) = 4092
7386 select(7, [6], [], NULL, {60, 0} <unfinished ...>
7361 <... select resumed> ) = 0 (Timeout)
7361 select(6, [4], [5], [5], {60, 0} <unfinished ...>
7386 <... select resumed> ) = 0 (Timeout)
7386 select(7, [6], [], NULL, {60, 0} <unfinished ...>
7361 <... select resumed> ) = 0 (Timeout)
7361 select(6, [4], [5], [5], {60, 0} <unfinished ...>
7386 <... select resumed> ) = 0 (Timeout)
7386 select(7, [6], [], NULL, {60, 0} <unfinished ...>
7361 <... select resumed> ) = 0 (Timeout)
7361 select(6, [4], [5], [5], {60, 0} <unfinished ...>
7386 <... select resumed> ) = 0 (Timeout)
7386 select(7, [6], [], NULL, {60, 0} <unfinished ...>
7361 <... select resumed> ) = 0 (Timeout)
7361 select(6, [4], [5], [5], {60, 0} <unfinished ...>
7386 <... select resumed> ) = 0 (Timeout)
7386 select(7, [6], [], NULL, {60, 0} <unfinished ...>
7361 <... select resumed> ) = 0 (Timeout)
7361 select(6, [4], [5], [5], {60, 0} <unfinished ...>
7386 <... select resumed> ) = 0 (Timeout)
7386 select(7, [6], [], NULL, {60, 0} <unfinished ...>
7361 <... select resumed> ) = 0 (Timeout)
.
.
.
.
386 select(7, [6], [], NULL, {60, 0} <unfinished ...>
7361 <... select resumed> ) = 0 (Timeout)
7361 select(6, [4], [5], [5], {60, 0} <unfinished ...>
7362 <... select resumed> ) = 1 (in [4])
7362 read(4, "", 8192) = 0
7362 rt_sigaction(SIGWINCH, NULL, {0x8000b6d0, [], 0}, 8) = 0
7362 rt_sigaction(SIGWINCH, {SIG_DFL}, NULL, 8) = 0
7362 close(5) = 0
7362 close(6) = 0
7362 close(7) = 0
7362 munmap(0xb7d1c000, 1118208) = 0
7362 ioctl(0, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfa92f28) = -1 EINVAL
(Invalid argument)
7362 fcntl64(0, F_GETFL) = 0x802 (flags O_RDWR|
O_NONBLOCK)
7362 fcntl64(0, F_SETFL, O_RDWR) = 0
7362 ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfa92f28) = -1 EINVAL
(Invalid argument)
7362 fcntl64(1, F_GETFL) = 0x802 (flags O_RDWR|
O_NONBLOCK)
7362 fcntl64(1, F_SETFL, O_RDWR) = 0
7362 ioctl(2, SNDCTL_TMR_TIMEBASE or TCGETS, {B9600 opost isig icanon
echo ...}) = 0
7362 write(2, "Connection to localhost closed b"..., 48) = 48
7362 gettimeofday({1228848897, 158149}, NULL) = 0
7362 shutdown(4, 2 /* send and receive */) = 0
7362 close(4) = 0
7362 brk(0x80e7a000) = 0x80e7a000
7362 brk(0x80e72000) = 0x80e72000
7362 brk(0x80e55000) = 0x80e55000
7362 exit_group(-1) = ?
7386 <... select resumed> ) = 1 (in [6], left {51, 738000})
7361 <... select resumed> ) = 1 (out [5], left {56, 419000})
7386 read(6, <unfinished ...>
7361 --- SIGCHLD (Child exited) @ 0 (0) ---
7386 <... read resumed> "", 4) = 0
7361 waitpid(-1, <unfinished ...>
7386 time( <unfinished ...>
7361 <... waitpid resumed> [{WIFEXITED(s) && WEXITSTATUS(s) == 255}],
WNOHANG) = 7362
7386 <... time resumed> NULL) = 1228848897
7361 waitpid(-1, <unfinished ...>
7386 stat64("/etc/localtime", <unfinished ...>
7361 <... waitpid resumed> 0xbfe0cd60, WNOHANG) = 0
7386 <... stat64 resumed> {st_mode=S_IFREG|0644, st_size=3519, ...})
= 0
7361 sigreturn( <unfinished ...>
7386 write(3, "2008/12/09 13:54:57 [7386] rsync"..., 110
<unfinished ...>
7361 <... sigreturn resumed> ) = ? (mask now [])
7386 <... write resumed> ) = 110
7361 write(5, "\0\0\0\0\0\0\0\0\206G\0\0\0\0\0\0\0\0\0\0\0\0\0\0\207G
\0\0\0\0\0\0"..., 4092 <unfinished ...>
7386 write(2, "rsync: connection unexpectedly c"..., 82
<unfinished ...>
7361 <... write resumed> ) = -1 EPIPE (Broken pipe)
7386 <... write resumed> ) = 82
7386 write(2, "\n", 1) = 1
7386 rt_sigaction(SIGUSR1, {SIG_IGN}, <unfinished ...>
7361 --- SIGPIPE (Broken pipe) @ 0 (0) ---
7386 <... rt_sigaction resumed> NULL, 8) = 0
7361 time( <unfinished ...>
7386 rt_sigaction(SIGUSR2, {SIG_IGN}, <unfinished ...>
7361 <... time resumed> NULL) = 1228848897
7386 <... rt_sigaction resumed> NULL, 8) = 0
7361 stat64("/etc/localtime", <unfinished ...>
7386 waitpid(7362, <unfinished ...>
7361 <... stat64 resumed> {st_mode=S_IFREG|0644, st_size=3519, ...})
= 0
7386 <... waitpid resumed> 0xbfe0ad98, WNOHANG) = -1 ECHILD (No child
processes)
7361 write(3, "2008/12/09 13:54:57 [7361] rsync"..., 110
<unfinished ...>
7386 unlink("home/dgranzow/om51/cygdrive/d/.runtime.img.065hxq"
<unfinished ...>
7361 <... write resumed> ) = 110
7386 <... unlink resumed> ) = 0
7361 write(2, "rsync: writefd_unbuffered failed"..., 82
<unfinished ...>
7386 kill(7362, SIGUSR1 <unfinished ...>
7361 <... write resumed> ) = 82
7361 write(2, "\n", 1 <unfinished ...>
7386 <... kill resumed> ) = -1 ESRCH (No such process)
7361 <... write resumed> ) = 1
7386 time( <unfinished ...>
7361 rt_sigaction(SIGUSR1, {SIG_IGN}, <unfinished ...>
7386 <... time resumed> NULL) = 1228848897
7361 <... rt_sigaction resumed> NULL, 8) = 0
7361 rt_sigaction(SIGUSR2, {SIG_IGN}, <unfinished ...>
7386 stat64("/etc/localtime", <unfinished ...>
7361 <... rt_sigaction resumed> NULL, 8) = 0
7386 <... stat64 resumed> {st_mode=S_IFREG|0644, st_size=3519, ...})
= 0
7361 waitpid(7362, <unfinished ...>
7386 write(3, "2008/12/09 13:54:57 [7386] rsync"..., 116
<unfinished ...>
7361 <... waitpid resumed> 0xbfe0d048, WNOHANG) = 0
7386 <... write resumed> ) = 116
7361 kill(7362, SIGUSR1 <unfinished ...>
7386 write(2, "rsync error: error in rsync prot"..., 88
<unfinished ...>
7361 <... kill resumed> ) = -1 ESRCH (No such process)
7386 <... write resumed> ) = 88
7386 write(2, "\n", 1 <unfinished ...>
7361 kill(7386, SIGUSR1 <unfinished ...>
7386 <... write resumed> ) = 1
7386 time( <unfinished ...>
7361 <... kill resumed> ) = 0
7386 <... time resumed> NULL) = 1228848897
7361 time( <unfinished ...>
7386 --- SIGUSR1 (User defined signal 1) @ 0 (0) ---
7361 <... time resumed> NULL) = 1228848897
7386 stat64("/etc/localtime", <unfinished ...>
7361 stat64("/etc/localtime", <unfinished ...>
7386 <... stat64 resumed> {st_mode=S_IFREG|0644, st_size=3519, ...})
= 0
7361 <... stat64 resumed> {st_mode=S_IFREG|0644, st_size=3519, ...})
= 0
7386 write(3, "2008/12/09 13:54:57 [7386] _exit"..., 95
<unfinished ...>
7361 write(3, "2008/12/09 13:54:57 [7361] rsync"..., 118
<unfinished ...>
7386 <... write resumed> ) = 95
7361 <... write resumed> ) = 118
7386 write(1, "_exit_cleanup(code=12, file=io.c"..., 68
<unfinished ...>
7361 write(2, "rsync error: error in rsync prot"..., 90
<unfinished ...>
7386 <... write resumed> ) = 68
7361 <... write resumed> ) = 90
7386 exit_group(12) = ?
7361 write(2, "\n", 1) = 1
7361 time(NULL) = 1228848897
7361 stat64("/etc/localtime", {st_mode=S_IFREG|0644,
st_size=3519, ...}) = 0
7361 write(3, "2008/12/09 13:54:57 [7361] _exit"..., 96) = 96
7361 write(1, "_exit_cleanup(code=12, file=io.c"..., 69) = 69
7361 exit_group(12)
On Dec 6, 2008, at 12:07 AM, Matt McCutchen wrote:
> On Fri, 2008-12-05 at 11:42 -0500, Shawn Geraghty wrote:
>> Upgrading will be done, but not really an option at this point,
>> unless
>> of course, that is the fix. I'm a limited resource and other stuff
>> is
>> backing up.
>
> I understand, but if the strace does indicate that you're hitting a
> hang
> bug in rsync 2.6.9, I don't know that anyone will care to investigate
> the bug unless it can be reproduced with the latest stable rsync.
>
>> Here is an strace from server A.
>>
>>
>> 11242 stat64("/etc/localtime", {st_mode=S_IFREG|0644,
>> st_size=3519, ...}) = 0
>> 11242 write(3, "2008/12/05 08:04:55 [11242] recv"..., 92) = 92
>> 11242 write(1, "recv_file_name(usr/share/icons/L"..., 64) = 64
>> 11242 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 11242 read(6, "9\0\0\t", 4) = 4
>> 11242 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 11242 read(6, "make_file(1,usr/share/icons/Loco"..., 57) = 57
>> 11242 time(NULL) = 1228482295
>> 11242 stat64("/etc/localtime", {st_mode=S_IFREG|0644,
>> st_size=3519, ...}) = 0
>> 11242 write(3, "2008/12/05 08:04:55 [11242] make"..., 85) = 85
>> 11242 write(1, "make_file(1,usr/share/icons/Loco"..., 57) = 57
>> 11242 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 11242 read(6, "\f\0\0\7", 4) = 4
>> 11242 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 11242 read(6, "\276&\5p.pngt\1\0\0", 12) = 12
>> 11242 time(NULL) = 1228482295
>> 11242 stat64("/etc/localtime", {st_mode=S_IFREG|0644,
>> st_size=3519, ...}) = 0
>> 11242 write(3, "2008/12/05 08:04:55 [11242] recv"..., 88) = 88
>> 11242 write(1, "recv_file_name(usr/share/icons/L"..., 60) = 60
>> 11242 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 11242 read(6, ":\0\0\t", 4) = 4
>> 11242 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 11242 read(6, "make_file(1,usr/share/icons/Loco"..., 58) = 36
>> 11242 select(7, [6], [], NULL, {60, 0}) = 0 (Timeout)
>> 11242 select(7, [6], [], NULL, {60, 0}) = 0 (Timeout)
>> 11242 select(7, [6], [], NULL, {60, 0}) = 0 (Timeout)
>> [...]
>
> So the receiver was waiting for the sender to send it the rest of the
> (non-incremental) file list. That's what it's supposed to do, so I
> need
> to know what the sender was doing to diagnose the hang.
>
>> The server being backed up doesn't run rsync as a daemon. I've read
>> in the rsync docs that backups can be done initiated from the server
>> with out the client running rsync as a daemon. For this case, I
>> don't
>> think I can get an strace. But, if possible, let me know and I will
>> track down how to do that.
>
> You can, and you'll need to if we are to get to the root of the
> problem.
> See the "rsync-debug" script described at:
>
> http://rsync.samba.org/issues.html
>
>> I also tried to back-up another server, and captured an strace from
>> Server A. Here is that trace.
>>
>> The big difference here was that I had to ^C the process after about
>> an hour. Usually, it looks like ssh shuts down the tunnel after a
>> period of 15 minutes.
>>
>> 4872 <... select resumed> ) = 2 (in [4], out [6])
>> 4891 select(7, [6], [], NULL, {60, 0} <unfinished ...>
>> 4872 write(6, "\374\17\0\7glade2\0\f.xpm\0\347images\0\6/yelp\0"...,
>> 16384 <unfinished ...>
>> 4891 <... select resumed> ) = 1 (in [6], left {60, 0})
>> 4872 <... write resumed> ) = 16384
>> 4891 read(6, <unfinished ...>
>> 4872 read(4, <unfinished ...>
>> 4891 <... read resumed> "urrent.desktop\0\5win95.desktop\0\3756"...,
>> 4092) = 4092
>> 4872 <... read resumed> "\243\36c\274aVv\324\16\307z
>> \347\17\274\247\34\331\327\333X\256\177\222\360\246\"\v\301\"pA%"...,
>> 8192) = 8192
>> 4891 select(7, [6], [], NULL, {60, 0} <unfinished ...>
>> 4872 select(8, [4 5], [], NULL, NULL <unfinished ...>
>> 4891 <... select resumed> ) = 1 (in [6], left {60, 0})
>> 4872 <... select resumed> ) = 1 (in [4])
>> 4891 read(6, <unfinished ...>
>> 4872 read(4, <unfinished ...>
>> 4891 <... read resumed> "\374\17\0\7", 4) = 4
>> 4872 <... read resumed> "\270\335\204#\373QM\217U\225K
>> \241\22\2750\357\256\2504\215\206L\255M\264\364\362\267\366D
>> \335\350"..., 8192) = 3040
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "t-preferences.glade2\0\1asciitable"..., 4092) = 4092
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4872 select(8, [4 5], [6], NULL, NULL <unfinished ...>
>> 4891 read(6, <unfinished ...>
>> 4872 <... select resumed> ) = 1 (out [6])
>> 4891 <... read resumed> "glade2\0\f.xpm\0\347images\0\6/yelp\0\5/
>> em"..., 4092) = 4092
>> 4872 write(6, "\374\17\0\7ORWARDING_DENIED\0\1TP_DISABLE"..., 16384
>> <unfinished ...>
>> 4891 select(7, [6], [], NULL, {60, 0} <unfinished ...>
>> 4872 <... write resumed> ) = 16384
>> 4891 <... select resumed> ) = 1 (in [6], left {60, 0})
>> 4872 select(8, [4 5], [], NULL, NULL <unfinished ...>
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "t-config-nfs.png\0\371test.py\0\0mainW"..., 4092) =
>> 4092
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "RWARDING_DENIED\0\1TP_DISABLED\0\3FA"..., 4092) = 4092
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "NG_DENIED\0\1TP_DISABLED\0\3FAILURE\0"..., 4092) =
>> 4092
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "ORWARDING_DENIED\0\1TP_DISABLED\0\3F"..., 4092) = 4092
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "elogs\0\377suexec\0\0certwatch\0\0aepdae"..., 4092) =
>> 4092
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "slinux\0\0talk\0\1elnet\0\0ime\0\377wget\0\0"...,
>> 4092)
>> = 4092
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "\374\17\0\7", 4) = 4
>> 4891 select(7, [6], [], NULL, {60, 0}) = 1 (in [6], left {60, 0})
>> 4891 read(6, "changethehostname\0\0einit_wrapper"..., 4092) = 4092
>> 4891 select(7, [6], [], NULL, {60, 0} <unfinished ...>
>> 4871 <... select resumed> ) = 0 (Timeout)
>> 4871 select(5, [4], [], NULL, {60, 0} <unfinished ...>
>> 4891 <... select resumed> ) = 0 (Timeout)
>> 4891 select(7, [6], [], NULL, {60, 0} <unfinished ...>
>> 4871 <... select resumed> ) = 0 (Timeout)
>> 4871 select(5, [4], [], NULL, {60, 0} <unfinished ...>
>> 4891 <... select resumed> ) = 0 (Timeout)
>> 4891 select(7, [6], [], NULL, {60, 0} <unfinished ...>
>> 4871 <... select resumed> ) = 0 (Timeout)
>>
>> .
>> .
>> same message another 100 times
>
> Here it looks like a file transfer was in progress and the receiver
> (4891) was waiting for more file data from the sender. Again, I
> need to
> see what the sender was doing.
>
> Matt
More information about the rsync
mailing list