rsync error: protocol incompatibility (code 2) and other divergent behavior on contrived tree with hard links.

[cr1901]

I have created a minimized tree of files, with one duplicate hard link, that causes rsync to error out with a cryptic File-list index 24 not in 31 - 32 (finish_hard_link) [generator] rsync error: protocol incompatibility (code 2) at rsync.c(740) [generator=3.1.1]: duplicate.tar.gz.

I created this tree after getting this error while examining previous backups using rsync with the compare-dest argument.

Duplicating the Error

To duplicate, untar, and run the supplied build-error.sh. I have gotten this error on multiple machines and multiple rsync versions, including the HEAD of master earlier today:

Run 1

william@xubuntu-dtrain:/shares/wjones/work/lr-prep$ tar xzf duplicate.tar.gz
william@xubuntu-dtrain:/shares/wjones/work/lr-prep$ cd duplicate/
william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$ cat build-error.sh
#!/bin/sh
${RSYNC:-rsync} -aHphiv --compare-dest=`pwd`/shares/wjones/backup/living-room/william/2019-10-26-204137/.cargo/git/checkouts/ `pwd`/home/william/.cargo/git/checkouts/ `pwd`/error
william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$ ./build-error.sh
sending incremental file list
created directory /shares/wjones/work/lr-prep/duplicate/error
cd..t...... ./
cd+++++++++ msp430-rt-746ea4089a4b6007/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/pack/
>f+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/pack/pack-524f05f69ee946cb582d7f4d988964b2015b63e6.idx
cd..t...... msp430g2211-2175d5cab83139eb/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/.git/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/
>f+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
File-list index 24 not in 31 - 32 (finish_hard_link) [generator]
rsync error: protocol incompatibility (code 2) at rsync.c(740) [generator=3.1.1]
william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$

Run 1, Part 2

If ./build-error.sh immediately run a second time after the above error, the second run of rsync succeeds:

william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$ ./build-error.sh
sending incremental file list
.d..t...... msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/

sent 624 bytes  received 29 bytes  1.31K bytes/sec
total size is 28.05K  speedup is 42.96

However, only one copy of 7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx gets to the destination directory:

william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$ find error -type f
error/msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
error/msp430-rt-746ea4089a4b6007/34faeea/.git/objects/pack/pack-524f05f69ee946cb582d7f4d988964b2015b63e6.idx

Things That Hide The Error

Run 2

If pack-524f05f69ee946cb582d7f4d988964b2015b63e6.idx is deleted from the tree, the rsync invocation returns no error without modification. However, only one file is sent!:

william@xubuntu-dtrain:/shares/wjones/work/lr-prep$ find duplicate -type f
duplicate/shares/wjones/backup/living-room/william/2019-10-26-204137/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
duplicate/home/william/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
duplicate/home/william/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
duplicate/build-error.sh
william@xubuntu-dtrain:/shares/wjones/work/lr-prep$ cd duplicate/
william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$ ./build-error.sh
sending incremental file list
created directory /shares/wjones/work/lr-prep/duplicate/error
cd..t...... ./
cd+++++++++ msp430-rt-746ea4089a4b6007/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/pack/
cd..t...... msp430g2211-2175d5cab83139eb/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/.git/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/
cd..t...... msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/
>f+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx

sent 2.31K bytes  received 164 bytes  4.96K bytes/sec
total size is 3.32K  speedup is 1.34

Run 3

If the --compare-dest argument is removed from ./build-error.sh, the rsync invocation succeeds, with the same file size as in the above Run 1, Part 2 section, but with different files sent compared to the above!:

william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$ cat build-error.sh
#!/bin/sh
${RSYNC:-rsync} -aHphiv `pwd`/home/william/.cargo/git/checkouts/ `pwd`/error
william@xubuntu-dtrain:/shares/wjones/work/lr-prep/duplicate$ ./build-error.sh    [0/1984]sending incremental file list
created directory /shares/wjones/work/lr-prep/duplicate/error
cd+++++++++ ./
cd+++++++++ msp430-rt-746ea4089a4b6007/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/
cd+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/pack/
>f+++++++++ msp430-rt-746ea4089a4b6007/34faeea/.git/objects/pack/pack-524f05f69ee946cb582d7f4d988964b2015b63e6.idx
cd+++++++++ msp430g2211-2175d5cab83139eb/
cd+++++++++ msp430g2211-2175d5cab83139eb/2abf4dd/
cd+++++++++ msp430g2211-2175d5cab83139eb/2abf4dd/.git/
cd+++++++++ msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/
cd+++++++++ msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/
cd+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/
>f+++++++++ msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
hf+++++++++ msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx => msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx

sent 27.26K bytes  received 295 bytes  55.12K bytes/sec
total size is 28.05K  speedup is 1.02

Expected Behavior

I am not sure where to even begin diagnosing the behavior I'm seeing here. Depending on how I run rsync, rsync will have divergent behavior when I don't expect it to. Based on the three (I'm counting "running the script twice" as one way) ways I'm running this script on this tree, I would expect all three runs to transfer all files to the destination directory. Actual behavior may cause rsync to error out with protocol incompatibility (code 2) and/or not transfer all files.

Description of the Tar File

The duplicate tree has "5" files including the supplied script. This was the best I could do after several hours to minimize a repeatable test case. Two of the "three" 7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx files have the same inode.

william@xubuntu-dtrain:/shares/wjones/work/lr-prep$ find duplicate -type f -exec ls -i {} \;
133508891 duplicate/shares/wjones/backup/living-room/william/2019-10-26-204137/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
133508892 duplicate/home/william/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/6f39636/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
133508892 duplicate/home/william/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
133508894 duplicate/home/william/.cargo/git/checkouts/msp430-rt-746ea4089a4b6007/34faeea/.git/objects/pack/pack-524f05f69ee946cb582d7f4d988964b2015b63e6.idx
133508895 duplicate/build-error.sh

The contents of all "three" copies of 7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx are identical:

william@xubuntu-dtrain:/shares/wjones/work/lr-prep$ diff -u duplicate/home/william/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx duplicate/shares/wjones/backup/living-room/william/2019-10-26-204137/.cargo/git/checkouts/msp430g2211-2175d5cab83139eb/2abf4dd/.git/objects/pack/pack-7bf52a3b7e19db9d1f63fe6366d0abbac678d60e.idx
william@xubuntu-dtrain:/shares/wjones/work/lr-prep$ echo $?
0

[WayneD]

I would expect all three runs to transfer all files to the destination directory.

That is not a valid expectation given that only some of the runs use --compare-dest, whose purpose is to elide files from the destination that are already present in the alt-dest directory (the option creates a sparse tree of just the modified/added files).

What looks to be going on is that rsync finds that the 2nd file is already in the compare dir, so rsync marks it as finished and skips it. However, its source file is hard-linked to another later file in the transfer, so rsync throws an error when that later file's transfer can't find the omitted file in the "lingering" list of files that need to be hard-linked together. Rsync's confusion stems from the fact that nothing marked the hard-link group as finished yet, and the 2nd file is listed as last in a group of 2 files (so it expects there to be an earlier file that need to be hard-linked with this new file) and rsync only keeps around data for unfinished files (to save memory). It is strange that the run 1 part 2 does not run into the same problem, but then I figured out that when the file doesn't need to be transferred, there hasn't been enough time for the generator to throw away the earlier file-list data yet, so it finds the linked file and notices that it is already flagged as finished and leaves it alone.

There are a couple ways this could be fixed. The easiest is to make rsync refuse to allow --hard-links when --compare-dest is used, since it's a weird use case to want hard-linking when creating a sparse tree of changed files. The other solution would be to figure out how to affect the flags to remove an elided file from the list of hard-linked files, which can shorten a hard-link group. I believe that there is some code that already elides an error-generating file from the hard-linked list, so the latter fix may not be too bad. I can give it a look soon.

My compliments on the wonderful bug report and such a thorough abundance of information. Let me know if you disagree with my conclusions.

[cr1901]

My compliments on the wonderful bug report and such a thorough abundance of information.

I appreciate this more than you know. Creating that test case was rather stressful/not enjoyable. I had to finally learn about the full filter rules syntax and kept getting caught by the "if a parent dir is excluded, everything below it also also excluded" filter rule. Eventually I got it down to those few files as a minimum test case. But I couldn't easily duplicate with more reasonable file names, so I found cp -Rp --parents did what I want to duplicate the source tree with the same error. And thankfully tar knows about hard links so I can xfer the tree to multiple machines.

Let me know if you disagree with my conclusions.

No, I think you're right from taking a brief read. But I need some time to think/finish my current rsync task :D. It's certainly feasible I was stressed out when making that report b/c it's about an error I didn't understand. And I'm still doing my pruning :).

My gut reaction: --compare-dest and --hard-links being mutually exclusive sounds reasonable if you think my use-case for combining both is inappropriate (and other ppl aren't affected :P). Maybe put a nice comment explaining the problem as you described it?

since it's a weird use case to want hard-linking when creating a sparse tree of changed files.

I don't know if I need hard-linking here. The context of this bug report is that I'm doing a yearly "prune old backups" by comparing an old backup to what I currently actually have on my disk. I have -H set to somewhat- not exact but "good enough"- duplicate the rsync command line I used when originally creating the backup. My idea is "duplicate the flags so the correct files are pruned or sent to the (compare-)old-to-new directory."

[eharris]

I've just been bitten by this problem as well. To my mind, it would be good to fix it so that --hard-links works with --compare-dest, as the whole point of the exercise is to minimize copying extra data (and taking up unnecessary additional space), and both options are needed to maximize the space savings.

My use case is mirroring a tree that contains a bunch of hard-linked incremental-appearing-as-full backups, and creating an incremental backup of that whole tree against a prior snapshot for use to update a remote backup server, so needs both options to be usable.

Error:

File-list index 879545 not in 880160 - 884094 (finish_hard_link) [generator]
rsync error: protocol incompatibility (code 2) at rsync.c(815) [generator=3.2.7]
rsync: [sender] write error: Broken pipe (32)

The "protocol incompatibility" threw me off initially because this was a local copy, so exact same instance of rsync

[eharris]

I should probably also mention, that if these bugs were fixed #528 #530 #533, then there would at least be a workaround for this bug, which is to use --itemize-changes to generate a file list to pass to --files-from, which would work around the need for --compare-dest (although at the cost of needing to invoke rsync and traverse the file tree twice, along with a lot of extra time and wasted IOPS).