Subject: Failure to cope with changing inode

From: martin f krafft <[email-masked]>
Date: Fri, 5 Aug 2016 12:49:49 +0200

Package: rsync
Version: 3.1.1-3
Severity: important
Tags: upstream

I am using rsync client-side for backups. Just now, it started to
process a 3.5G file, but shortly after the first couple of read()s,
the inode was overwritten; the file was not deleted (as then the
read() would just keep working against the still-referenced inode),
but the inode content replaced, e.g. like so:

  echo > file

The result of this operation is a length-1 file with the same inode
number as the 3.5G file before.

Subsequently, read() returns 0 (EOF) and I'd kinda expect rsync to
take note and exit. Unison, for instance, will skip a file and warn
about it if it changes during read.

rsync, however, cowardly keeps processing the file to its end, and
this is what strace sees:

  lseek(3, 610795520, SEEK_SET)           = 610795520
  read(3, "", 262144)                     = 0
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999998})
  write(1, "\4\200\0\7\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"..., 32776) = 28672
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {57, 457836})
  write(1, "\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"..., 4104) = 4104
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999997})
  write(1, "\4\200\0\7\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"..., 32760) = 32760
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999997})
  write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\200\0\0", 16) = 16
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999997})
  write(1, "\4\200\0\7\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"..., 32776) = 32776
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999997})
  write(1, "\4\200\0\7\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"..., 32776) = 32776
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999997})
  write(1, "\4\200\0\7\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"..., 32776) = 28672
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {58, 240363})
  write(1, "\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"..., 4104) = 4104
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999996})
  write(1, "\4\200\0\7\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"..., 32760) = 32760
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999996})
  write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\200\0\0", 16) = 16
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999998})
  write(1, "\4\200\0\7\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"..., 32776) = 32776
  select(2, [], [1], [], {60, 0})         = 1 (out [1], left {59, 999997})
  write(1, "\4\200\0\7\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"..., 32776) = 32776
  lseek(3, 611057664, SEEK_SET)           = 611057664

I have not dived into the code, but I assume what's happening here
is that

  1. rsync read()s and gets EOF, but fails to act on that;
  2. rsync transmits the content of the buffer (which was not
     updated) to the remote;
  3. rsync lseek()s to the next 256k block and repeats, sending the
     same content of the buffer again.

This seems to happen until the entire file has been processed, and
it would be bad because the file on the receiving end will be
completely broken, due to the reuse of the buffer. However, I have
not verified this.

-- System Information:
Debian Release: stretch/sid
  APT prefers unstable
  APT policy: (500, 'unstable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 4.6.0-1-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_NZ, LC_CTYPE=en_NZ.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages rsync depends on:
ii  base-files  9.6
ii  libacl1     2.2.52-3
ii  libattr1    1:2.4.47-2
ii  libc6       2.23-4
ii  libpopt0    1.16-10
ii  lsb-base    9.20160629

rsync recommends no packages.

Versions of packages rsync suggests:
ii  openssh-client  1:7.2p2-7
ii  openssh-server  1:7.2p2-7

-- no debconf information

-- 
 .''`.   martin f. krafft <[email-masked]> @martinkrafft
: :'  :  proud Debian developer
`. `'`   http://people.debian.org/~madduck
  `-  Debian - when you have better things to do than fixing systems