rsync - Apr 2018 - [Bug 13385] New: rsync sometimes silently transfers more or fewer mtimes than it should

https://bugzilla.samba.org/show_bug.cgi?id=13385

            Bug ID: 13385
           Summary: rsync sometimes silently transfers more or fewer
                    mtimes than it should
           Product: rsync
           Version: 3.1.3
          Hardware: All
                OS: Linux
            Status: NEW
          Severity: regression
          Priority: P5
         Component: core
          Assignee: wayned at samba.org
          Reporter: silvanschmitz at gmail.com
        QA Contact: rsync-qa at samba.org

The support for comparing nanosecond timestamps introduced in 3.1.3 seems to
have had some unintended consequences which make rsync behave completely
erratically. I think I have narrowed it down to the following points:
* --modify-window with positive values is completely ignored. I have therefore
marked this as a regression.
* --size-only seems to only compare full seconds.
* rsync can encounter errors when retouching directories, but does not report
them.
* The output of --itemize-changes gives the user a false sense of security: It
shows exactly what you would expect rsync to do, but not what it actually does.

Steps to reproduce the first point (--modify-window is ignored):
===============================================================$ mkdir a b
$ touch -d "2018-04-13 12:00:00" a/test
$ touch -d "2018-04-13 12:00:01" b/test
$ stat --format "%n: %y" {a,b}/test
a/test: 2018-04-13 12:00:00.000000000 +0200
b/test: 2018-04-13 12:00:01.000000000 +0200
$ rsync -ai at 1 a/ b/
.d..t...... ./
$ stat --format "%n: %y" {a,b}/test
a/test: 2018-04-13 12:00:00.000000000 +0200
b/test: 2018-04-13 12:00:00.000000000 +0200

This creates directories a and b, each containing a file test, the mtimes of
which are 1 second apart, as verified by stat. When rsyncing a to b with
--modify-window=1 (- at 1), these files should be treated equal and nothing
should
be transferred. As expected, no line for the file shows up in the -i output.
However, a subsequent stat call shows the mtime of b/test has actually been set
to that of a/test.

Steps to reproduce the second point (--size-only compares only full seconds):
============================================================================(I
guess this is more an oversight in the implementation of sub-second
comparisons?)
$ mkdir a b
$ touch -d "2018-04-13 12:00:00.123" a/test
$ touch -d "2018-04-13 12:00:00.456" b/test
$ stat --format "%n: %y" {a,b}/test
a/test: 2018-04-13 12:00:00.123000000 +0200
b/test: 2018-04-13 12:00:00.456000000 +0200
$ rsync -ai at -1 a/ b/
.d..t...... ./
.f..t...... test
$ stat --format "%n: %y" {a,b}/test
a/test: 2018-04-13 12:00:00.123000000 +0200
b/test: 2018-04-13 12:00:00.456000000 +0200

Again, a/test and b/test are created. This time, their mtimes only differ in
the fractional part. Specifying - at -1 to rsync enables comparison of the
fractional parts, so the files should be treated as different. test therefore
shows up in the -i output this time (mtime transfer only), again as expected.
However, the mtime of b/test does not change.

Steps to reproduce the third point (rsync silently ignores errors):
==================================================================This requires
sudo, or some way to change the owner; just do not run rsync as
root.
$ mkdir a b
$ touch -d "2018-04-13 12:00:00.123" a
$ touch -d "2018-04-13 12:00:00.456" b
$ chmod go-w a b
$ sudo chown nobody a b
$ stat --format "%n: %y" a b
a: 2018-04-13 12:00:00.123000000 +0200
b: 2018-04-13 12:00:00.456000000 +0200
$ rsync -ai at -1 a/ b/
.d..t...... ./
$ stat --format "%n: %y" a b
a: 2018-04-13 12:00:00.123000000 +0200
b: 2018-04-13 12:00:00.456000000 +0200

This time, the mtimes of the directories differ only in the fractional part. We
also make sure we do not have permission to set the timestamps of b by chowning
it. When rsyncing a to b with - at -1, it should recognize the mtimes as
different, attempt to change b, and fail. However, no error is reported, and
the -i output shows that the operation was completed as instructed -- which, of
course, it could not have.

The reason here is that, as far as I can see, in set_file_attrs, ATTRS_SET_NANO
is not given and no attempt to set the mtime is made. Later however, in
touch_up_dirs, set_modtime is called on the directory. It fails, but there is
no error handling, because usually, the mtime would already have been set
before, and an error would have become apparent already. (I guess that is
anyway a dangerous assumption to make.)

===============
All three cases have in common that the output from --itemize-changes reports
that rsync has done exactly what was asked of it, yet rsync did something
completely different. And that is probably the most dangerous implication of
these observations: That I cannot trust the output of rsync, or check that what
I am about to do is sound and will not have disastrous consequences by using
-ni. What if it were to somehow forget to mention a delete? I agree that there
is no indication that this could happen right now, but something that has
happened to me is that rsync changed the mtime of a file (like in test case 1)
that was hard-linked to somewhere else, thus effectively changing something
outside of the target tree -- something I thought I had made sure would not
happen by using dry mode before.

-- 
You are receiving this mail because:
You are the QA Contact for the bug.

https://bugzilla.samba.org/show_bug.cgi?id=13385

--- Comment #1 from Silvan Schmitz <silvanschmitz at gmail.com> ---
Oops, I copy-pasted incorrectly and forgot the --size-only for the second test
case -- as I wrote it, both rsync's output and the result will be different.
Here's what I should have written (bug's still there):

$ mkdir a b
$ touch -d "2018-04-13 12:00:00.123" a/test
$ touch -d "2018-04-13 12:00:00.456" b/test
$ stat --format "%n: %y" {a,b}/test
a/test: 2018-04-13 12:00:00.123000000 +0200
b/test: 2018-04-13 12:00:00.456000000 +0200
$ rsync -ai at -1 --size-only a/ b/
.d..t...... ./
.f..t...... test
$ stat --format "%n: %y" {a,b}/test
a/test: 2018-04-13 12:00:00.123000000 +0200
b/test: 2018-04-13 12:00:00.456000000 +0200

-- 
You are receiving this mail because:
You are the QA Contact for the bug.

https://bugzilla.samba.org/show_bug.cgi?id=13385

--- Comment #2 from Silvan Schmitz <silvanschmitz at gmail.com> ---
Links also don't work ...

$ mkdir a b
$ ln -s / a/link
$ ln -s / b/link
$ touch -hd "2018-04-16 10:00:00.123" a/link
$ touch -hd "2018-04-16 10:00:00.456" b/link
$ stat --format "%n: %y" {a,b}/link
a/link: 2018-04-16 10:00:00.123000000 +0200
b/link: 2018-04-16 10:00:00.456000000 +0200
$ rsync -ai at -1 a/ b/
.d..t...... ./
.L..t...... link -> /
$ stat --format "%n: %y" {a,b}/link
a/link: 2018-04-16 10:00:00.123000000 +0200
b/link: 2018-04-16 10:00:00.456000000 +0200

-- 
You are receiving this mail because:
You are the QA Contact for the bug.

https://bugzilla.samba.org/show_bug.cgi?id=13385

Wayne Davison <wayne at opencoder.net> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|---                         |FIXED

--- Comment #3 from Wayne Davison <wayne at opencoder.net> ---
Thanks for pointing that out. The code was honoring the modify window when
checking if the file needed to be transferred, but the code checking if it
needed to call utime on a file had lost its modify-window logic. It was also
coded to not force just a nano-seconds change for a file that hadn't been
transferred or checksummed, but that seems like the wrong thing to do with
- at -1. Changes committed to git.

-- 
You are receiving this mail because:
You are the QA Contact for the bug.