Bug 11866 - rsync fails (failed to re-stat) when using double fuzzy + link-dest on renamed files
rsync fails (failed to re-stat) when using double fuzzy + link-dest on rename...
Status: NEW
Product: rsync
Classification: Unclassified
Component: core
3.1.1
All Linux
: P5 normal
: ---
Assigned To: Wayne Davison
Rsync QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2016-04-21 06:54 UTC by Mike Joseph
Modified: 2017-07-04 14:49 UTC (History)
2 users (show)

See Also:


Attachments
rsync_double_fuzzy_11866 (353 bytes, patch)
2017-07-04 14:49 UTC, Ben RUBSON
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Mike Joseph 2016-04-21 06:54:23 UTC
When using rsync with --fuzzy --fuzzy (double fuzzy) and --link-dest, rsync fails if a file was renamed to a new name on the source that does not exist in the link-dest.  As an example:

mj@backup-server:~/foo$ rm -rf .sync && mkdir .sync && rsync -azSHAXxrsyy --ignore-existing --fake-super --link-dest=/home/mj/foo/current --files-from=:/home/mj/files-to-backup root@backup-client:/ .sync
rsync: failed to re-stat "/home/mj/foo/.sync/etc/motd.old": No such file or directory (2)
rsync: failed to re-stat "/home/mj/foo/.sync/var/log/alternatives.log.1": No such file or directory (2)
rsync: failed to re-stat "/home/mj/foo/.sync/var/log/auth.log.3.gz": No such file or directory (2)
rsync: failed to re-stat "/home/mj/foo/.sync/var/log/daemon.log.3.gz": No such file or directory (2)
rsync: failed to re-stat "/home/mj/foo/.sync/var/log/dpkg.log.1": No such file or directory (2)
rsync: failed to re-stat "/home/mj/foo/.sync/var/log/messages.3.gz": No such file or directory (2)
rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1655) [generator=3.1.1]

In each case above, the files which rsync failed to re-stat were ones that existed in the link-dest (/home/mj/foo/current) but under a different name.  For instance:

mj@backup-server:~/foo$ ls -al /home/mj/foo/current/etc/motd*
-rw-r--r-- 7 mj mj 286 Dec 24  2014 /home/mj/foo/current/etc/motd

root@backup-client:/etc# ls -al motd*
-rw-r--r-- 1 root root 314 Apr 21 06:32 motd
-rw-r--r-- 1 root root 286 Apr 21 06:33 motd.bak
-rw-r--r-- 1 root root 286 Dec 24  2014 motd.old

Note that, in this case, rsync didn't fail on motd.bak, just motd.old.  Both contain the same content, but only motd.old has a matching timestamp.

I can completely reproduce this problem on multiple machine pairs and with different file sets.  The problem is resolved by removing the double-fuzzy configuration but, of course, that impairs performance.

All rsync binaries involved are version 3.1.1 (debian 3.1.1-3_amd64).
Comment 1 Ben RUBSON 2017-07-04 11:00:19 UTC
I can easily reproduce this dangerous bug.
Both sides running rsync 3.1.2.

# cd /tmp/ && mkdir -p test && cd test && rm -f *
# ssh $usr@$srv "rm -rf /tmp/dst*"

# for i in `seq 0 9`
  do
  echo content_$i > $i
  done

# rsync -a . $usr@$srv:/tmp/dst1/

# rsync -a --link-dest=../dst1 . $usr@$srv:/tmp/dst2/

# ssh $usr@$srv "ls -lin /tmp/dst1 /tmp/dst2"
/tmp/dst1:
total 45
660319 -rw-r--r--  2 501  0  10  4 Jul 12:55 0
660320 -rw-r--r--  2 501  0  10  4 Jul 12:55 1
660321 -rw-r--r--  2 501  0  10  4 Jul 12:55 2
660322 -rw-r--r--  2 501  0  10  4 Jul 12:55 3
660323 -rw-r--r--  2 501  0  10  4 Jul 12:55 4
660324 -rw-r--r--  2 501  0  10  4 Jul 12:55 5
660325 -rw-r--r--  2 501  0  10  4 Jul 12:55 6
660326 -rw-r--r--  2 501  0  10  4 Jul 12:55 7
660327 -rw-r--r--  2 501  0  10  4 Jul 12:55 8
660328 -rw-r--r--  2 501  0  10  4 Jul 12:55 9
/tmp/dst2:
total 45
660319 -rw-r--r--  2 501  0  10  4 Jul 12:55 0
660320 -rw-r--r--  2 501  0  10  4 Jul 12:55 1
660321 -rw-r--r--  2 501  0  10  4 Jul 12:55 2
660322 -rw-r--r--  2 501  0  10  4 Jul 12:55 3
660323 -rw-r--r--  2 501  0  10  4 Jul 12:55 4
660324 -rw-r--r--  2 501  0  10  4 Jul 12:55 5
660325 -rw-r--r--  2 501  0  10  4 Jul 12:55 6
660326 -rw-r--r--  2 501  0  10  4 Jul 12:55 7
660327 -rw-r--r--  2 501  0  10  4 Jul 12:55 8
660328 -rw-r--r--  2 501  0  10  4 Jul 12:55 9

// Perfect, --link-dest correctly works.

# for i in `seq 0 9`
  do
  cp -a $i $i.orig
  echo content_$i >> $i
  done

# rsync -a -y --progress --stats --link-dest=../dst1 . $usr@$srv:/tmp/dst2/
./
0
             20 100%    0.00kB/s    0:00:00 (xfr#1, to-chk=19/21)
0.orig
             10 100%    9.77kB/s    0:00:00 (xfr#2, to-chk=18/21)
1
             20 100%   19.53kB/s    0:00:00 (xfr#3, to-chk=17/21)
1.orig
             10 100%    9.77kB/s    0:00:00 (xfr#4, to-chk=16/21)
2
             20 100%   19.53kB/s    0:00:00 (xfr#5, to-chk=15/21)
2.orig
             10 100%    9.77kB/s    0:00:00 (xfr#6, to-chk=14/21)
3
             20 100%   19.53kB/s    0:00:00 (xfr#7, to-chk=13/21)
3.orig
             10 100%    9.77kB/s    0:00:00 (xfr#8, to-chk=12/21)
4
             20 100%   19.53kB/s    0:00:00 (xfr#9, to-chk=11/21)
4.orig
             10 100%    9.77kB/s    0:00:00 (xfr#10, to-chk=10/21)
5
             20 100%    9.77kB/s    0:00:00 (xfr#11, to-chk=9/21)
5.orig
             10 100%    4.88kB/s    0:00:00 (xfr#12, to-chk=8/21)
6
             20 100%    9.77kB/s    0:00:00 (xfr#13, to-chk=7/21)
6.orig
             10 100%    4.88kB/s    0:00:00 (xfr#14, to-chk=6/21)
7
             20 100%    9.77kB/s    0:00:00 (xfr#15, to-chk=5/21)
7.orig
             10 100%    4.88kB/s    0:00:00 (xfr#16, to-chk=4/21)
8
             20 100%    9.77kB/s    0:00:00 (xfr#17, to-chk=3/21)
8.orig
             10 100%    4.88kB/s    0:00:00 (xfr#18, to-chk=2/21)
9
             20 100%    9.77kB/s    0:00:00 (xfr#19, to-chk=1/21)
9.orig
             10 100%    3.26kB/s    0:00:00 (xfr#20, to-chk=0/21)
Number of files: 21 (reg: 20, dir: 1)
Number of created files: 10 (reg: 10)
Number of deleted files: 0
Number of regular files transferred: 20
Total file size: 300 bytes
Total transferred file size: 300 bytes
Literal data: 190 bytes
Matched data: 110 bytes
File list size: 0
File list generation time: 0.002 seconds
File list transfer time: 0.000 seconds
Total bytes sent: 1,422
Total bytes received: 549
sent 1,422 bytes  received 549 bytes  1,314.00 bytes/sec
total size is 300  speedup is 0.15

# ssh $usr@$srv "ls -lin /tmp/dst2"
total 90
660330 -rw-r--r--  1 501  0  20  4 Jul 12:55 0
660331 -rw-r--r--  1 501  0  10  4 Jul 12:55 0.orig
660332 -rw-r--r--  1 501  0  20  4 Jul 12:55 1
660333 -rw-r--r--  1 501  0  10  4 Jul 12:55 1.orig
660334 -rw-r--r--  1 501  0  20  4 Jul 12:55 2
660335 -rw-r--r--  1 501  0  10  4 Jul 12:55 2.orig
660336 -rw-r--r--  1 501  0  20  4 Jul 12:55 3
660343 -rw-r--r--  1 501  0  10  4 Jul 12:55 3.orig
660344 -rw-r--r--  1 501  0  20  4 Jul 12:55 4
660345 -rw-r--r--  1 501  0  10  4 Jul 12:55 4.orig
660346 -rw-r--r--  1 501  0  20  4 Jul 12:55 5
660347 -rw-r--r--  1 501  0  10  4 Jul 12:55 5.orig
660348 -rw-r--r--  1 501  0  20  4 Jul 12:55 6
660349 -rw-r--r--  1 501  0  10  4 Jul 12:55 6.orig
660350 -rw-r--r--  1 501  0  20  4 Jul 12:55 7
660351 -rw-r--r--  1 501  0  10  4 Jul 12:55 7.orig
660352 -rw-r--r--  1 501  0  20  4 Jul 12:55 8
660353 -rw-r--r--  1 501  0  10  4 Jul 12:55 8.orig
660354 -rw-r--r--  1 501  0  20  4 Jul 12:55 9
660355 -rw-r--r--  1 501  0  10  4 Jul 12:55 9.orig

// Perfect, update correctly done.

# rsync -a -yy --progress --stats --link-dest=../dst1 . $usr@$srv:/tmp/dst3/
sending incremental file list
./
0
             20 100%    0.00kB/s    0:00:00 (xfr#1, to-chk=19/21)
1
             20 100%   19.53kB/s    0:00:00 (xfr#2, to-chk=17/21)
2
             20 100%   19.53kB/s    0:00:00 (xfr#3, to-chk=15/21)
3
             20 100%   19.53kB/s    0:00:00 (xfr#4, to-chk=13/21)
4
             20 100%   19.53kB/s    0:00:00 (xfr#5, to-chk=11/21)
5
             20 100%   19.53kB/s    0:00:00 (xfr#6, to-chk=9/21)
6
             20 100%   19.53kB/s    0:00:00 (xfr#7, to-chk=7/21)
7
             20 100%   19.53kB/s    0:00:00 (xfr#8, to-chk=5/21)
8
             20 100%   19.53kB/s    0:00:00 (xfr#9, to-chk=3/21)
9
             20 100%   19.53kB/s    0:00:00 (xfr#10, to-chk=1/21)
Number of files: 21 (reg: 20, dir: 1)
Number of created files: 0
Number of deleted files: 0
Number of regular files transferred: 10
Total file size: 300 bytes
Total transferred file size: 200 bytes
Literal data: 100 bytes
Matched data: 100 bytes
File list size: 0
File list generation time: 0.003 seconds
File list transfer time: 0.000 seconds
Total bytes sent: 882
Total bytes received: 279
sent 882 bytes  received 279 bytes  2,322.00 bytes/sec
total size is 300  speedup is 0.26

// ! rsync does not return any error but did not sync renamed files !

# ssh $usr@$srv "ls -lin /tmp/dst3"
total 45
660357 -rw-r--r--  1 501  0  20  4 Jul 12:55 0
660358 -rw-r--r--  1 501  0  20  4 Jul 12:55 1
660359 -rw-r--r--  1 501  0  20  4 Jul 12:55 2
660360 -rw-r--r--  1 501  0  20  4 Jul 12:55 3
660361 -rw-r--r--  1 501  0  20  4 Jul 12:55 4
660362 -rw-r--r--  1 501  0  20  4 Jul 12:55 5
660363 -rw-r--r--  1 501  0  20  4 Jul 12:55 6
660364 -rw-r--r--  1 501  0  20  4 Jul 12:55 7
660365 -rw-r--r--  1 501  0  20  4 Jul 12:55 8
660366 -rw-r--r--  1 501  0  20  4 Jul 12:55 9

Double fuzzy is then absolutly dangerous as it can lead to silent data loss.
Comment 2 Ben RUBSON 2017-07-04 14:49:54 UTC
Created attachment 13342 [details]
rsync_double_fuzzy_11866

Bug found, patch attached.
Wayne could you please review and commit please ?
Thank you very much !