I am running rsync over a VPN. The connection has been stable for some
time, but recently it has started failing. I am including the strace of
the failure below. Basically, the client disconnects typically with an
error 12. I have 3 other clients using the same openvpn/rsync
configuration, and those are stable, so I am fairly confident this is
something on this particular link.
The problem may be due to a new router at the server end; at least the
problem appeared approximately at the same time as the new router.
Unfortunately I don't have direct control over that router; all I can
do is ask my client to replace it or to ship a test router. Before I do
that, I'd like to understand what and why this is happening.
Can someone look through this and see what may be going on? I can't
interpret the server end of the strace.
Client end:
lstat("ACTD/ACTD-Joel W/Richard Tadler/CD SET/taddler-XREF-first floor
plan - block.dwg", {st_mode=S_IFREG|0760, st_size=1159424, ...}) = 0
open("ACTD/ACTD-Joel W/Richard Tadler/CD SET/taddler-XREF-first floor
plan - block.dwg", O_RDONLY) = 6
read(6, "AC1021\0\0\0\0\0\1\3 \r\0\0\33\1\36\0\0\33\1\0\0\0\0\0"...,
262640) = 262640
read(6, "\212\200\30\242\316KL\31\20Q\31\3o\201@\234\350\323%\241"...,
262640) = 262640
select(5, [4], [3], [3], {60, 0}) = 0 (Timeout)
... [ repeated many times ]
select(5, [4], [3], [3], {60, 0}) = 0 (Timeout)
select(5, [4], [3], [3], {60, 0}rsync: read error: Connection reset by
peer (104)
rsync error: error in rsync protocol data stream (code 12) at io.c(794)
[receiver=3.0.3]
) = 1 (in [4], left {31, 560000})
--- SIGCHLD (Child exited) @ 0 (0) ---
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 12}], WNOHANG, NULL) =
18791
wait4(-1, 0x7fff4bdee4dc, WNOHANG, NULL) = -1 ECHILD (No child processes)
rt_sigreturn(0xffffffffffffffff) = 1
select(5, [4], [], NULL, {60, 0}) = 1 (in [4], left {60, 0})
read(4, "", 8184) = 0
write(2, "rsync: connection unexpectedly c"..., 77rsync: connection
unexpectedly closed (255 bytes received so far) [generator]) = 77
write(2, "\n", 1
) = 1
rt_sigaction(SIGUSR1, {SIG_IGN}, NULL, 8) = 0
rt_sigaction(SIGUSR2, {SIG_IGN}, NULL, 8) = 0
kill(18791, SIGUSR1) = -1 ESRCH (No such process)
write(2, "rsync error: error in rsync prot"..., 89rsync error: error
in
rsync protocol data stream (code 12) at io.c(635) [generator=3.0.3]) = 89
write(2, "\n", 1
) = 1
exit_group(12) = ?
Process 18776 detached
server end:
menn:/etc# strace /usr/bin/rsync --config /etc/rsyncd.conf --no-detach
--daemon
execve("/usr/bin/rsync", ["/usr/bin/rsync",
"--config",
"/etc/rsyncd.conf", "--no-detach", "--daemon"],
[/* 18 vars */]) = 0
brk(0) = 0x80af000
uname({sys="Linux", node="menn", ...}) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7f84000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or
directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=19595, ...}) = 0
mmap2(NULL, 19595, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7f7f000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
open("/lib/libacl.so.1", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\240\24"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=22240, ...}) = 0
mmap2(NULL, 25116, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0)
= 0xb7f78000
mmap2(0xb7f7e000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x5) = 0xb7f7e000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
open("/lib/libpopt.so.0", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220\26"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=33284, ...}) = 0
mmap2(NULL, 36172, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0)
= 0xb7f6f000
mmap2(0xb7f77000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7) = 0xb7f77000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
open("/lib/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\260e\1"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1356012, ...}) = 0
mmap2(NULL, 1361520, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3,
0) = 0xb7e22000
mmap2(0xb7f69000, 12288, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x147) = 0xb7f69000
mmap2(0xb7f6c000, 9840, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7f6c000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
open("/lib/libattr.so.1", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0p\f\0\000"...,
512) = 512
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7e21000
fstat64(3, {st_mode=S_IFREG|0644, st_size=12820, ...}) = 0
mmap2(NULL, 15680, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0)
= 0xb7e1d000
mmap2(0xb7e20000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2) = 0xb7e20000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7e1c000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7e1c6b0,
limit:1048575, seg_32bit:1, contents:0, read_exec_only:0,
limit_in_pages:1, seg_not_present:0, useable:1}) = 0
mprotect(0xb7f69000, 4096, PROT_READ) = 0
munmap(0xb7f7f000, 19595) = 0
rt_sigaction(SIGUSR1, {0x8062f10, [], SA_RESTORER|SA_NOCLDSTOP,
0xb7e4cfa8}, NULL, 8) = 0
rt_sigaction(SIGUSR2, {0x8063910, [], SA_RESTORER|SA_NOCLDSTOP,
0xb7e4cfa8}, NULL, 8) = 0
rt_sigaction(SIGCHLD, {0x8063960, [], SA_RESTORER|SA_NOCLDSTOP,
0xb7e4cfa8}, NULL, 8) = 0
time(NULL) = 1218454958
geteuid32() = 0
umask(0) = 022
brk(0) = 0x80af000
brk(0x80d0000) = 0x80d0000
open("/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=1282816, ...}) = 0
mmap2(NULL, 1282816, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7ce2000
close(3) = 0
open("/usr/share/locale/locale.alias", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2586, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7f83000
read(3, "# Locale name alias data base.\n#"..., 1024) = 1024
read(3, "ies are case independent.\n\n# Not"..., 1024) = 1024
read(3, "rean.euc \tko_KR.eucKR\nko_KR\t\tko_"..., 1024) = 538
read(3, "", 1024) = 0
close(3) = 0
munmap(0xb7f83000, 4096) = 0
open("/usr/lib/locale/cs_CZ.UTF-8/LC_CTYPE", O_RDONLY) = -1 ENOENT (No
such file or directory)
open("/usr/lib/locale/cs_CZ.utf8/LC_CTYPE", O_RDONLY) = -1 ENOENT (No
such file or directory)
open("/usr/lib/locale/cs_CZ/LC_CTYPE", O_RDONLY) = -1 ENOENT (No such
file or directory)
open("/usr/lib/locale/cs.UTF-8/LC_CTYPE", O_RDONLY) = -1 ENOENT (No
such
file or directory)
open("/usr/lib/locale/cs.utf8/LC_CTYPE", O_RDONLY) = -1 ENOENT (No
such
file or directory)
open("/usr/lib/locale/cs/LC_CTYPE", O_RDONLY) = -1 ENOENT (No such
file
or directory)
open("/usr/etc/popt", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file
or
directory)
open("/etc/popt", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or
directory)
stat64("/etc/popt.d", 0xbf9d44a8) = -1 ENOENT (No such file or
directory)
open("/root/.popt", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or
directory)
rt_sigaction(SIGINT, {0x80522f0, [], SA_RESTORER|SA_NOCLDSTOP,
0xb7e4cfa8}, NULL, 8) = 0
rt_sigaction(SIGHUP, {0x80522f0, [], SA_RESTORER|SA_NOCLDSTOP,
0xb7e4cfa8}, NULL, 8) = 0
rt_sigaction(SIGTERM, {0x80522f0, [], SA_RESTORER|SA_NOCLDSTOP,
0xb7e4cfa8}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [HUP INT USR1 USR2 TERM CHLD], NULL, 8) = 0
rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
rt_sigaction(SIGXFSZ, {SIG_IGN}, NULL, 8) = 0
getcwd("/etc", 4095) = 5
getsockopt(0, SOL_SOCKET, SO_TYPE, 0xbf9d4564, 0xbf9d4560) = -1 ENOTSOCK
(Socket operation on non-socket)
open("/etc/rsyncd.conf", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=157, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7f83000
read(3, "[tndchas]\n exclude = \"*.b"..., 1024) = 157
close(3) = 0
munmap(0xb7f83000, 4096) = 0
getpid() = 18279
time(NULL) = 1218454958
open("/etc/localtime", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
fstat64(3, {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7f83000
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0"...,
1024) = 1024
read(3, "\0\1\0\1\0\1\0\1\2\3\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1"...,
1024) = 1024
_llseek(3, 1447, [3495], SEEK_CUR) = 0
read(3, "\nEST5EDT,M3.2.0,M11.1.0\n", 1024) = 24
close(3) = 0
munmap(0xb7f83000, 4096) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3519, ...}) =
0
socket(PF_FILE, SOCK_DGRAM, 0) = 3
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
connect(3, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
time(NULL) = 1218454958
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3519, ...}) =
0
send(3, "<30>Aug 11 07:42:38 rsyncd[18279"..., 88, MSG_NOSIGNAL)
= 88
socket(PF_NETLINK, SOCK_RAW, 0) = 4
bind(4, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(4, {sa_family=AF_NETLINK, pid=18279, groups=00000000}, [12]) = 0
time(NULL) = 1218454958
sendto(4, "\24\0\0\0\26\0\1\3\256%\240H\0\0\0\0\0\0\0\0", 20, 0,
{sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000},
msg_iov(1)=[{"0\0\0\0\24\0\2\0\256%\240HgG\0\0\2\10\200\376\1\0\0\0\10"...,
4096}], msg_controllen=0, msg_flags=0}, 0) = 212
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000},
msg_iov(1)=[{"@\0\0\0\24\0\2\0\256%\240HgG\0\0\n\200\200\376\1\0\0\0"...,
4096}], msg_controllen=0, msg_flags=0}, 0) = 128
recvmsg(4, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000},
msg_iov(1)=[{"\24\0\0\0\3\0\2\0\256%\240HgG\0\0\0\0\0\0\1\0\0\0\24\0"...,
4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(4) = 0
open("/etc/gai.conf", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=2349, ...}) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=2349, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7f83000
read(4, "# Configuration for getaddrinfo("..., 1024) = 1024
read(4, "ask> <value>\n# Add another "..., 1024) = 1024
read(4, "\n# and 10.3 in RFC 3484. The"..., 1024) = 301
read(4, "", 1024) = 0
close(4) = 0
munmap(0xb7f83000, 4096) = 0
socket(PF_INET6, SOCK_DGRAM, IPPROTO_IP) = 4
connect(4, {sa_family=AF_INET6, sin6_port=htons(873),
inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0,
sin6_scope_id=0}, 28) = 0
getsockname(4, {sa_family=AF_INET6, sin6_port=htons(35626),
inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0,
sin6_scope_id=0}, [28]) = 0
connect(4, {sa_family=AF_UNSPEC,
sa_data="\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 16) = 0
connect(4, {sa_family=AF_INET, sin_port=htons(873),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
getsockname(4, {sa_family=AF_INET6, sin6_port=htons(35626),
inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr),
sin6_flowinfo=0,
sin6_scope_id=0}, [28]) = 0
close(4) = 0
socket(PF_INET6, SOCK_STREAM, IPPROTO_TCP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_IPV6, IPV6_V6ONLY, [1], 4) = 0
bind(4, {sa_family=AF_INET6, sin6_port=htons(873), inet_pton(AF_INET6,
"::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 5
setsockopt(5, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(5, {sa_family=AF_INET, sin_port=htons(873),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
listen(4, 5) = 0
listen(5, 5) = 0
select(6, [4 5], NULL, NULL, NULL) = 1 (in [5])
accept(5, {sa_family=AF_INET, sin_port=htons(48481),
sin_addr=inet_addr("10.10.0.1")}, [16]) = 6
rt_sigaction(SIGCHLD, {0x80768c0, [], SA_RESTORER|SA_NOCLDSTOP,
0xb7e4cfa8}, NULL, 8) = 0
clone(child_stack=0,
flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7e1c6f8) = 18280
close(6) = 0
select(6, [4 5], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
--- SIGCHLD (Child exited) @ 0 (0) ---
waitpid(-1, NULL, WNOHANG) = 18280
waitpid(-1, NULL, WNOHANG) = -1 ECHILD (No child processes)
sigreturn() = ? (mask now [])
select(6, [4 5], NULL, NULL, NULL
--
o__
,>/'_ o__
(_)\(_) ,>/'_ o__
Yan Seiner (_)\(_) ,>/'_ o__
Personal Trainer (_)\(_) ,>/'_ o__
Professional Engineer (_)\(_) ,>/'_
Who says engineers have to be pencil necked geeks? (_)\(_)
"I worry about my child and the Internet all the time, even though
she's too young to have logged on yet. Here's what I worry about. I
worry that 10 or 15 years from now, she will come to me and say 'Daddy,
where were you when they took freedom of the press away from the
Internet?'"
--Mike Godwin, Electronic Frontier Foundation
