Bug 1542513 - [possible regression in 3.1.3] rsync fails with error 11 when mirroring Fedora quick-fedora-mirror
Summary: [possible regression in 3.1.3] rsync fails with error 11 when mirroring Fedor...
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: rsync
Version: 27
Hardware: All
OS: All
unspecified
high
Target Milestone: ---
Assignee: Michal Ruprich
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-02-06 13:39 UTC by Vedran Miletić
Modified: 2018-11-30 20:17 UTC (History)
6 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2018-11-30 20:17:31 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Vedran Miletić 2018-02-06 13:39:12 UTC
After upgrading to 3.1.3-1 (I presume -2 wouldn't be different?) on my Fedora mirror running Fedora 27, I started getting errors like:

Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync: read error: Connection reset by peer (104)
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync error: error in socket IO (code 10) at io.c(785) [Receiver=3.1.3]
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync: read error: Connection reset by peer (104)
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync error: error in socket IO (code 10) at io.c(785) [Receiver=3.1.3]
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync: read error: Connection reset by peer (104)
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync error: error in socket IO (code 10) at io.c(785) [Receiver=3.1.3]
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: [Receiver] io timeout after 901 seconds -- exiting
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync error: timeout in data send/receive (code 30) at io.c(195) [Receiver=3.1.3]
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: [Receiver] io timeout after 901 seconds -- exiting
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync error: timeout in data send/receive (code 30) at io.c(195) [Receiver=3.1.3]
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync: write failed on "/mnt/fedora-buffet8/pub/fedoraproject/alt/atomic/testing/Atomic/aarch64/iso/Fedora-Atomic-ostree-aarch64-27-20180128.0.iso": Success (0)
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync error: error in file IO (code 11) at receiver.c(374) [receiver=3.1.3]
Sij 30 05:01:03 mirror.miletic.net quick-fedora-mirror[20040]: rsync: read error: Connection reset by peer (104)

Changing RSYNCOPTS did not help, but using rsync without q-f-m did work without issues. After downgrading to 3.1.2 the problem goes away.

Comment 1 Jason Tibbitts 2018-02-08 23:28:44 UTC
I just got the update here and am seeing the same issue.

quick-fedora-mirror just calls rsync (with options) so the issue isn't really an issue with quick-fedora-mirror.  I can call rsync directly with the same options outside of q-f-m and get the same failure.

Looking at the message:

rsync: write failed on "/srv/mirror/pub/fedora-buffet/alt/atomic/testing/Atomic/aarch64/iso/Fedora-Atomic-ostree-aarch64-27-20180208.0.iso": Success (0)

I realized that the issue might have to do with preallocation, so I set things to call rsync without it and it does appear to work fine.  I will push an update to quick-fedora-mirror in a bit which disables preallocation completely.  It only worked in 3.1.0, 3.1.1 and 3.1.2 but now seems to have been broken.

For the record, this is how rsync is getting called (for me; others would of course use a different source machine and destination path)

/usr/bin/rsync -aSH -f'R .~tmp~' --stats --preallocate --delay-updates --out-format='@ %i  %n%L' --no-motd --files-from=master-transferlist.sorted rsync://dl-tier1.fedoraproject.org/fedora-buffet0/ /srv/mirror/pub/fedora-buffet

master-transferlist.sorted in this case has the complete list of files to be transferred, which doesn't have to be large; the first time I saw this there were only 83 files in the transfer list.  The rsync process aborts pretty quickly after it starts.

Comment 2 Jason Tibbitts 2018-02-09 00:20:51 UTC
Further info: removing either -S (for copying sparse files) or --preallocate makes things work. 

I tracked this down to this code in syscall.c:

#ifdef HAVE_FALLOCATE
# ifdef HAVE_FALLOC_FL_PUNCH_HOLE
        if (fallocate(fd, FALLOC_FL_PUNCH_HOLE | FALLOC_FL_KEEP_SIZE, pos, len) == 0) {
                if (do_lseek(fd, len, SEEK_CUR) != pos + len)
                        return -1;
                return 0;
        }
# endif

Strace shows:

9266  fallocate(7, FALLOC_FL_KEEP_SIZE|FALLOC_FL_PUNCH_HOLE, 159857, 32768) = 0
9266  lseek(7, 32768, SEEK_CUR)         = 32768

immediately before the error message is printed.  So the rsync code expects that an lseek over the punched hole will advance over the hole, and at least on current Fedora 27 that doesn't appear to be the case.  I honestly do not know what the proper behavior is here.  The actual behavior might even differ depending on which filesystem is in use.  (I'm on XFS here.)

I tried to report this upstream but I have to request access to their bugzilla via email.  I've done so but I don't know how long that will take.

Comment 3 Jason Tibbitts 2018-02-09 01:07:08 UTC
Talked to an XFS developer who had a look confirmed that the rsync code is simply broken here.  It might be a good idea to disable HAVE_FALLOC_FL_PUNCH_HOLE in the Fedora builds.

I've simply disabled --preallocate in the current quick-fedora-mirror git head.

Comment 4 Vedran Miletić 2018-02-09 16:55:12 UTC
Thanks!

For the record, I have reproduced the issue with ex4 as well as XFS.

Comment 5 Jason Tibbitts 2018-02-12 23:15:10 UTC
Note that I did not ever hear back about registering a bugzilla account so that I could file this upstream, so I hope the Fedora maintainers can report this properly.

Comment 6 Jason Tibbitts 2018-03-08 01:49:02 UTC
The upstream bug for this is: https://bugzilla.samba.org/show_bug.cgi?id=13320

Comment 7 Ben Cotton 2018-11-27 16:43:17 UTC
This message is a reminder that Fedora 27 is nearing its end of life.
On 2018-Nov-30  Fedora will stop maintaining and issuing updates for
Fedora 27. It is Fedora's policy to close all bug reports from releases
that are no longer maintained. At that time this bug will be closed as
EOL if it remains open with a Fedora  'version' of '27'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 27 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 8 Ben Cotton 2018-11-30 20:17:31 UTC
Fedora 27 changed to end-of-life (EOL) status on 2018-11-30. Fedora 27 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.