<div dir="ltr"><div style="font-size:12.8px">Hello,</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">I just installed BackupPC in a Debian box to use it as backup server. As you know, this software makes use, among others, of rsync. When using the rsync option, it fails.</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">Server:</div><div style="font-size:12.8px">Debian Jessie.</div><div style="font-size:12.8px">BackupPC 3.3.1 built from source, executed by user "backup-user".</div><div style="font-size:12.8px">Rsync 3.1.2 built from source with the default options.</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">Client</div><div style="font-size:12.8px">Debian Jessie.</div><div style="font-size:12.8px">Rsync 3.1.2 built from source with the default options.</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">After the fail, the rsync command used can be found in BackupPC's logs. Trying the command in a shell, logged as the BackupPC user, I run into this "protocol version mismatch -- is your shell clean?" error. The command is:</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">/usr/bin/ssh -q -x -l backup-user 192.168.10.20 /usr/local/bin/rsync --server --sender --numeric-ids --perms --owner --group -D --links --hard-links --times --block-size=2048 --recursive --ignore-times . /home/backup-user/test</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">Adding some verbose to the rsync command sent to the client, it says:</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">FILE_STRUCT_LEN=24, EXTRA_LEN=4</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">(Server) Protocol versions: remote=168430090, negotiated=31</div><div style="font-size:12.8px">########################### Notice the remote protocol version</div><div style="font-size:12.8px">protocol version mismatch -- is your shell clean?</div><div style="font-size:12.8px">(see the rsync man page for an explanation)</div><div style="font-size:12.8px">[sender] _exit_cleanup(code=2, file=compat.c, line=178): entered</div><div style="font-size:12.8px">rsync error: protocol incompatibility (code 2) at compat.c(178) [sender=3.1.2]</div><div style="font-size:12.8px">[sender] _exit_cleanup(code=2, file=compat.c, line=178): about to call exit(2)</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">In the client, using the debug script I found in this site:</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">/usr/bin/ssh -q -x -l backup-user 192.168.206.103 /home/backup-user/rsync-debug --server --sender --numeric-ids --perms --owner --group -D --links --hard-links --times --block-size=2048 --recursive --ignore-times . /home/backup-user/test</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">rsync-2991.out content:</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">2997  00:58:30 brk(0)                   = 0xefb000</div><div style="font-size:12.8px">2997  00:58:30 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)</div><div style="font-size:12.8px">2997  00:58:30 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fefc7341000</div><div style="font-size:12.8px">2997  00:58:30 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)</div><div style="font-size:12.8px">2997  00:58:30 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3</div><div style="font-size:12.8px">2997  00:58:30 fstat(3, {st_mode=S_IFREG|0644, st_size=33837, ...}) = 0</div><div style="font-size:12.8px">2997  00:58:30 mmap(NULL, 33837, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fefc7338000</div><div style="font-size:12.8px">2997  00:58:30 close(3)                 = 0</div><div style="font-size:12.8px">2997  00:58:30 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)</div><div style="font-size:12.8px">2997  00:58:30 open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3</div><div style="font-size:12.8px">2997  00:58:30 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\34\2\0\0\0\0\0@\0\0\0\0\0\0\0\300T\32\0\0\0\0\0\0\0\0\0@\0008\0\n\0@\0D\0C\0\6\0\0\0\5\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0000\2\0\0\0\0\0\0000\2\0\0\0\0\0\0\10\0\0\0\0\0\0\0\3\0\0\0\4\0\0\0000\303\26\0\0\0\0\0000\303\26\0\0\0\0\0000\303\26\0\0\0\0\0\34\0\0\0\0\0\0\0\34\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0\1\0\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\364\352\31\0\0\0\0\0\364\352\31\0\0\0\0\0\0\0 \0\0\0\0\0\1\0\0\0\6\0\0\0@\367\31\0\0\0\0\0@\3679\0\0\0\0\0@\3679\0\0\0\0\0\370O\0\0\0\0\0\0\340\222\0\0\0\0\0\0\0\0 \0\0\0\0\0\2\0\0\0\6\0\0\0\240 \32\0\0\0\0\0\240 :\0\0\0\0\0\240 :\0\0\0\0\0\340\1\0\0\0\0\0\0\340\1\0\0\0\0\0\0\10\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0p\2\0\0\0\0\0\0p\2\0\0\0\0\0\0p\2\0\0\0\0\0\0D\0\0\0\0\0\0\0D\0\0\0\0\0\0\0\4\0\0\0\0\0\0\0\7\0\0\0\4\0\0\0@\367\31\0\0\0\0\0@\3679\0\0\0\0\0@\3679\0\0\0\0\0\20\0\0\0\0\0\0\0\200\0\0\0\0\0\0\0\10\0\0\0\0\0\0\0P\345td\4\0\0\0L\303\26\0\0\0\0\0L\303\26\0\0\0\0\0L\303\26\0\0\0\0\0$j\0\0\0\0\0\0$j\0\0\0\0\0\0\4\0\0\0\0\0\0\0Q\345td\6\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0R\345td\4\0\0\0@\367\31\0\0\0\0\0@\3679\0\0\0\0\0@\3679\0\0\0\0\0\3008\0\0\0\0\0\0\3008\0\0\0\0\0\0\1\0\0\0\0\0\0\0\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\371?y\343\344|\332K|C=\2\323!\316@\34J\205\1\4\0\0\0\20\0\0\0\1\0\0\0GNU\0\0\0\0\0\2\0\0\0\6\0\0\0 \0\0\0\0\0\0\0\363\3\0\0\n\0\0\0\0\1\0\0\16\0\0\0\0000\20D\240 \2\1\210\3\346\220\305E\214\0\300\0\10\0\5\200\0`\300\200\0\r\212\f\0\4\20\0\210D2\10.@\210P4, \16\"H&\204\300\214\4\10\0\2\2\16\241\254\32\4f\300\0\3002\0\300\0P\1 \201\10\204\v  ($\0\4 P\0\20X\200\312DB(\0\6\200\20\30B\0 @\200\0\tP\0Q\212@\20\0\0\0\0\10\0\0\21\20", 832) = 832</div><div style="font-size:12.8px">2997  00:58:30 fstat(3, {st_mode=S_IFREG|0755, st_size=1729984, ...}) = 0</div><div style="font-size:12.8px">2997  00:58:30 mmap(NULL, 3836448, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fefc6d7a000</div><div style="font-size:12.8px">2997  00:58:30 mprotect(0x7fefc6f19000, 2097152, PROT_NONE) = 0</div><div style="font-size:12.8px">2997  00:58:30 mmap(0x7fefc7119000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19f000) = 0x7fefc7119000</div><div style="font-size:12.8px">2997  00:58:30 mmap(0x7fefc711f000, 14880, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fefc711f000</div><div style="font-size:12.8px">2997  00:58:30 close(3)                 = 0</div><div style="font-size:12.8px">2997  00:58:30 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fefc7337000</div><div style="font-size:12.8px">2997  00:58:30 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fefc7336000</div><div style="font-size:12.8px">2997  00:58:30 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fefc7335000</div><div style="font-size:12.8px">2997  00:58:30 arch_prctl(ARCH_SET_FS, 0x7fefc7336700) = 0</div><div style="font-size:12.8px">2997  00:58:30 mprotect(0x7fefc7119000, 16384, PROT_READ) = 0</div><div style="font-size:12.8px">2997  00:58:30 mprotect(0x7fefc7343000, 4096, PROT_READ) = 0</div><div style="font-size:12.8px">2997  00:58:30 munmap(0x7fefc7338000, 33837) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGUSR1, {0x41c690, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGUSR2, {0x41d220, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGCHLD, {0x41c630, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 geteuid()                = 1001</div><div style="font-size:12.8px">2997  00:58:30 getegid()                = 1001</div><div style="font-size:12.8px">2997  00:58:30 umask(0)                 = 022</div><div style="font-size:12.8px">2997  00:58:30 umask(022)               = 0</div><div style="font-size:12.8px">2997  00:58:30 brk(0)                   = 0xefb000</div><div style="font-size:12.8px">2997  00:58:30 brk(0xf1c000)            = 0xf1c000</div><div style="font-size:12.8px">2997  00:58:30 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3</div><div style="font-size:12.8px">2997  00:58:30 fstat(3, {st_mode=S_IFREG|0644, st_size=1607632, ...}) = 0</div><div style="font-size:12.8px">2997  00:58:30 mmap(NULL, 1607632, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fefc71ac000</div><div style="font-size:12.8px">2997  00:58:30 close(3)                 = 0</div><div style="font-size:12.8px">2997  00:58:30 open("/etc/popt", O_RDONLY) = -1 ENOENT (No such file or directory)</div><div style="font-size:12.8px">2997  00:58:30 open("/home/backup-user/.popt", O_RDONLY) = -1 ENOENT (No such file or directory)</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGINT, {0x40cca0, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGHUP, {0x40cca0, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGTERM, {0x40cca0, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigprocmask(SIG_UNBLOCK, [HUP INT USR1 USR2 TERM CHLD], NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 rt_sigaction(SIGXFSZ, {SIG_IGN, [], SA_RESTORER|SA_NOCLDSTOP, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:30 getcwd("/home/backup-user", 4095) = 13</div><div style="font-size:12.8px">2997  00:58:30 fcntl(0, F_GETFL)        = 0 (flags O_RDONLY)</div><div style="font-size:12.8px">2997  00:58:30 fcntl(0, F_SETFL, O_RDONLY|O_NONBLOCK) = 0</div><div style="font-size:12.8px">2997  00:58:30 fcntl(1, F_GETFL)        = 0x1 (flags O_WRONLY)</div><div style="font-size:12.8px">2997  00:58:30 fcntl(1, F_SETFL, O_WRONLY|O_NONBLOCK) = 0</div><div style="font-size:12.8px">2997  00:58:30 fcntl(0, F_GETFL)        = 0x800 (flags O_RDONLY|O_NONBLOCK)</div><div style="font-size:12.8px">2997  00:58:30 fcntl(1, F_GETFL)        = 0x801 (flags O_WRONLY|O_NONBLOCK)</div><div style="font-size:12.8px">2997  00:58:30 write(1, "\37\0\0\0", 4) = 4</div><div style="font-size:12.8px">#################################### Here is where the script stops #############</div><div style="font-size:12.8px">############################# I have to hit return several times in the server ########</div><div style="font-size:12.8px">2997  00:58:30 select(1, [0], NULL, [0], {60, 0}) = 1 (in [0], left {55, 558348})</div><div style="font-size:12.8px">2997  00:58:34 read(0, "\n", 4)         = 1</div><div style="font-size:12.8px">2997  00:58:34 select(1, [0], NULL, [0], {60, 0}) = 1 (in [0], left {59, 793510})</div><div style="font-size:12.8px">2997  00:58:35 read(0, "\n", 3)         = 1</div><div style="font-size:12.8px">2997  00:58:35 select(1, [0], NULL, [0], {60, 0}) = 1 (in [0], left {59, 975726})</div><div style="font-size:12.8px">2997  00:58:35 read(0, "\n", 2)         = 1</div><div style="font-size:12.8px">2997  00:58:35 select(1, [0], NULL, [0], {60, 0}) = 1 (in [0], left {59, 968630})</div><div style="font-size:12.8px">2997  00:58:35 read(0, "\n", 1)         = 1</div><div style="font-size:12.8px">2997  00:58:35 write(2, "protocol version mismatch -- is your shell clean?", 49) = 49</div><div style="font-size:12.8px">2997  00:58:35 write(2, "\n", 1)        = 1</div><div style="font-size:12.8px">2997  00:58:35 write(2, "(see the rsync man page for an explanation)", 43) = 43</div><div style="font-size:12.8px">2997  00:58:35 write(2, "\n", 1)        = 1</div><div style="font-size:12.8px">2997  00:58:35 rt_sigaction(SIGUSR1, {SIG_IGN, [], SA_RESTORER, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:35 rt_sigaction(SIGUSR2, {SIG_IGN, [], SA_RESTORER, 0x7fefc6daf180}, NULL, 8) = 0</div><div style="font-size:12.8px">2997  00:58:35 write(2, "rsync error: protocol incompatibility (code 2) at compat.c(178) [sender=3.1.2]", 78) = 78</div><div style="font-size:12.8px">2997  00:58:35 write(2, "\n", 1)        = 1</div><div style="font-size:12.8px">2997  00:58:35 nanosleep({0, 100000000}, NULL) = 0</div><div style="font-size:12.8px">2997  00:58:35 exit_group(2)            = ?</div><div style="font-size:12.8px">2997  00:58:35     exited with 2    </div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">After some hours of research, I can't figure out what is wrong. I removed and checked everything that could write any text (ssh welcome message, .bashrc echos, passphrase and even the system prompt) and rsync is still unable to gather the files. ssh connection is made passwordless. </div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">Looks like the 168430090 in the remote protocol is the decimal representation for 0xA0A0A0A, but no clue of what is writing it. I searched for similar errors in the list, but all I found are due to things I already checked. </div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">The lines:</div><div style="font-size:12.8px">2997  00:58:30 open("/etc/popt", O_RDONLY) = -1 ENOENT (No such file or directory)</div><div style="font-size:12.8px">2997  00:58:30 open("/home/backup-user/.popt", O_RDONLY) = -1 ENOENT (No such file or directory)</div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">Looks suspicious to me, but also checked the libraries involved.  </div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">Options --server and --sender are added by BackupPC, but are not supposed to be needed in a regular use, as the rsync documentation states. </div><div style="font-size:12.8px"><br></div><div style="font-size:12.8px">Hope this information is clear enough. Thanks for your time.</div>
</div>