error in rsync protocol data stream

Bug #1971932 reported by jmbaudach
22
This bug affects 4 people
Affects Status Importance Assigned to Milestone
rsync (Ubuntu)
Confirmed
Low
Unassigned
Bionic
Confirmed
Low
Unassigned
Focal
Confirmed
Low
Unassigned

Bug Description

When synchronizing to other systems, rsync exits with "error in rsync protocol data stream (code 12)".

The problem occurs since ubuntu 22.04 LTS with two different destination systems not running ubuntu but plain debian. The error did not occur under 20.04 LTS.

Synchronisation runs fine for most other files, but always stops at the same (relative large) file. The file itself has also been changed on a test basis to make sure the file is not the problem itself.

Log snippet:
------------

...
chunk[46131] len=46120 offset=2127561720 sum1=2f48caf4
chunk[46132] len=46120 offset=2127607840 sum1=5dfcb4ee
chunk[46133] len=46120 offset=2127653960 sum1=d1037d81
chunk[46134] len=8870 offset=2127700080 sum1=6deedc97
send_files mapped /path/backup/subdir/.thunderbird/profile/ImapMail/imap.domain.com/INBOX of size 2135722584
calling match_sums /path/backup/subdir/.thunderbird/profile/ImapMail/imap.domain.com/INBOX
built hash table
hash search b=46120 len=2135722584
sum=1e1722dc k=46120
hash search s->blength=46120 len=2135722584 count=46135
potential match at 0 i=0 sum=1e1722dc
match at 0 last_match=0 j=0 len=46120 n=0
potential match at 46120 i=1 sum=c482d6b6
match at 46120 last_match=46120 j=1 len=46120 n=0
potential match at 92240 i=2 sum=b21c7e11
match at 92240 last_match=92240 j=2 len=46120 n=0
potential match at 138360 i=3 sum=d066473a
match at 138360 last_match=138360 j=3 len=46120 n=0
potential match at 184480 i=4 sum=a32a2984
match at 184480 last_match=184480 j=4 len=46120 n=0
potential match at 230600 i=5 sum=39cc049f
match at 230600 last_match=230600 j=5 len=46120 n=0
potential match at 276720 i=6 sum=ad3de98a
match at 276720 last_match=276720 j=6 len=46120 n=0
potential match at 322840 i=7 sum=83e16fa9
match at 322840 last_match=322840 j=7 len=46120 n=0
deflate on token returned 0 (8512 bytes left)
rsync error: error in rsync protocol data stream (code 12) at token.c(476) [sender=3.2.3]
[sender] _exit_cleanup(code=12, file=token.c, line=476): entered
[sender] _exit_cleanup(code=12, file=token.c, line=476): about to call exit(12)

Sender system: (rsync 3.2.3-8ubuntu3)
-------------------------------------

rsync version 3.2.3 protocol version 31
Copyright (C) 1996-2020 by Andrew Tridgell, Wayne Davison, and others.
Web site: https://rsync.samba.org/
Capabilities:
    64-bit files, 64-bit inums, 64-bit timestamps, 64-bit long ints,
    socketpairs, hardlinks, hardlink-specials, symlinks, IPv6, atimes,
    batchfiles, inplace, append, ACLs, xattrs, optional protect-args, iconv,
    symtimes, prealloc, stop-at, no crtimes
Optimizations:
    SIMD, no asm, openssl-crypto
Checksum list:
    xxh128 xxh3 xxh64 (xxhash) md5 md4 none
Compress list:
    zstd lz4 zlibx zlib none

rsync comes with ABSOLUTELY NO WARRANTY. This is free software, and you
are welcome to redistribute it under certain conditions. See the GNU
General Public Licence for details.

Recipient systems: (rsync 3.1.3-6)
----------------------------------

rsync version 3.1.3 protocol version 31
Copyright (C) 1996-2018 by Andrew Tridgell, Wayne Davison, and others.
Web site: http://rsync.samba.org/
Capabilities:
    64-bit files, 64-bit inums, 64-bit timestamps, 64-bit long ints,
    socketpairs, hardlinks, symlinks, IPv6, batchfiles, inplace,
    append, ACLs, xattrs, iconv, symtimes, prealloc

rsync comes with ABSOLUTELY NO WARRANTY. This is free software, and you
are welcome to redistribute it under certain conditions. See the GNU
General Public Licence for details.

Revision history for this message
Paride Legovini (paride) wrote :

Hello and thanks for this bug report. I tried to reproduce this locally but I failed. We're certainly willing to investigate this, but first we need some steps to reproduce the problem. Could you please try to identify a somehow reliable way to reproduce the issue and share your findings? Thanks!

Changed in rsync (Ubuntu):
status: New → Incomplete
Revision history for this message
jmbaudach (jmbaudach) wrote :

Thanks for your efforts and fast answer.

In the meantime I verified that it is compression related, as I read "deflate on token returned 0 (8512 bytes left)" as an indication on this.

Usually the action is performed using -avz parameters. When not activating compression (-av only), the synchronization performs successfully. So this is my temporary workaround now.

When trying to reproduce, did you use an according large file?

Revision history for this message
Paride Legovini (paride) wrote :

Well, "large" can span orders of magnitude, depending who you ask. :-)

Can you please try to identify some steps to reproduce that include the big file generation? For example:

  # 100MB file, random data (difficult to compress)
  head -c 100M /dev/urandom > foo

  # 100MB file, all 0s (easy to compress)
  head -c 100M /dev/zero > foo

Then you can try to rsync it to localhost via ssh to a different directory (I assume you're using ssh and not the rsync protocol). Thanks!

Revision history for this message
Robie Basak (racb) wrote :

This reminds me of bug 1384503, and a search reveals some other bugs that may be related too. Perhaps it's a recurrence of the same underlying issue?

Revision history for this message
jmbaudach (jmbaudach) wrote :

After further reading on the subject, I guess that the problem is the size of over 2 GB. All other thousands of files (incl. hardly further compressible mp3, jpeg, mpeg etc.) are synchronized without problems. Under ubuntu 20.04 LTS the problem did not occur.

Revision history for this message
Lena Voytek (lvoytek) wrote :

I attempted to reproduce by running the command through localhost over ssh and it succeeded using a 3GB file. This may be due to the transfer between Ubuntu and Debian then. Here is my test case:

# lxc launch images:ubuntu/jammy test-rsync
# lxc exec test-rsync bash
# apt update && apt dist-upgrade -y
# apt install rsync openssh-server
# passwd ubuntu
# su ubuntu
# cd
# mkdir dest
# head -c 3GB /dev/urandom > test
# rsync -avz --stats -e ssh test localhost:~/dest/

@jmbaudach can you try to transfer your over 2GB file locally with ssh to see if it fails there. That will help us narrow down the issue.

Thanks!

Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for rsync (Ubuntu) because there has been no activity for 60 days.]

Changed in rsync (Ubuntu):
status: Incomplete → Expired
MBS (mbs2019)
Changed in rsync (Ubuntu):
status: Expired → Confirmed
Revision history for this message
MBS (mbs2019) wrote :

It's rsync! The new version does not like to work with the old one.
I had the same problems. After I upgraded my Ubuntu server (running VMs) from LTS 20.04 to LTS 22.4.1. Since then the backups using rsync of the VMs (max file size 6.2 GB) to the backup server (Debian 10) failed. Intern (within the Ubuntu file tree) rsync still works fine.
The rsync error always occurred at the large file (max 6.2 Gb).

Ubuntu 22.04: apt-cache policy rsync
Installed: 3.2.3-8ubuntu3
Candidate: 3.2.3-8ubuntu3
Version table:
*** 3.2.3-8ubuntu3 500

Debian 10: apt-cache policy rsync
Installed: 3.1.3-6
Candidate: 3.1.3-6
Version table:
*** 3.1.3-6 500

After I upgraded my Debian from 10 (buster) to 11 (bullseye) I had a new version for rsync:
apt-cache policy rsync
rsync:
  Installed: 3.2.3-4+deb11u1
  Candidate: 3.2.3-4+deb11u1
  Version table:
 *** 3.2.3-4+deb11u1 500

... tadaa, and it worked

Revision history for this message
jmbaudach (jmbaudach) wrote :

Unfortunately, since I cannot update the target, which is an embedded system, I have been able to help myself by disabling compression. Instead of calling rsync with the parameters -avz I use temporarily only -av for the affected target systems and the synchronization runs without problems.

Revision history for this message
MBS (mbs2019) wrote :

-z, really? If you could have sent an earlier post with this information, I would have used this solution.
Maybe next time ;-)
Cheers

Revision history for this message
jmbaudach (jmbaudach) wrote :

Please excuse me, it slipped my mind and I only became aware of it through the email notification about a new activity in the bug tracker.

Revision history for this message
Lucas Kanashiro (lucaskanashiro) wrote :

Since there is known workaround for this I am setting the Importance to Low.

Changed in rsync (Ubuntu):
importance: Undecided → Low
Revision history for this message
Sergio Durigan Junior (sergiodj) wrote :

There are a few upstream issues that seem to be related to this one, but https://github.com/WayneD/rsync/issues/86 seems like the most likely candidate.

Not using "-z" was determined to be a possible workaround here. If any of you (who can actually reproduce the issue) can check if "-zz" also works, then we can establish the relation between both bugs.

Thanks.

Revision history for this message
Paride Legovini (paride) wrote :

Looks like there' also an openSUSE bug about this issue:

https://bugzilla.opensuse.org/show_bug.cgi?id=1175854

As I understand it the culprit is the old rsync (3.1.3). Upstream suggests recompiling it with -with-included-zlib=yes, which I doubt we're going to do, especially in stable releases. The openSUSE bug has an attached patch for rsync 3.1.3:

https://bugzilla.opensuse.org/attachment.cgi?id=853856&action=diff

If confirmed working we could SRU this fix to Focal (rsync 3.1.3) and maybe Bionic (rsync 3.1.2), but first we need one of the affected users to verify that the patch works, as as we're unable to reproduce the bug at the moment.

Revision history for this message
jmbaudach (jmbaudach) wrote :

I just checked the behaviour when using the -zz option.
On one of my two affected systems, -zz works. However, on the other, an older embedded system (NAS), it does not. The error message on this system is as follows:
rsync: on remote machine: --new-compress: unknown option
rsync error: requested action not supported (code 4) at clientserver.c(849) [Receiver=3.0.9]
rsync: [sender] read error: Connection reset by peer (104)
rsync error: error in socket IO (code 10) at io.c(784) [sender=3.2.3]

Revision history for this message
Michael Knichel (m-knichel) wrote :

I have confirmed this bug as well. Here is what I have done:

rsync failed when transferring large files over network with error 12 when using compression (z option). rsync succeeded when I transferred large files over USB to external SSD when using compression (z option). rsync succeeded when transferring large files over network when NOT using compression (z option).

Hope this offers some assistance in tracking and correcting this bug.

Revision history for this message
Paride Legovini (paride) wrote :

That's consistent with the comments above as the USB->SSD transfer doesn't use the rsync protocol.

What we need to move this forward is a verification that applying [1] to the version of rsync in Bionic (3.1.2) or Focal (3.1.3) fixes the issue.

If any of you affected users is available for testing an experimental package we can prepare one and publish it to a PPA. Once the fix is verified we can start the actual SRU process, which will require more feedback (verification) from affected users.

[1] https://bugzilla.opensuse.org/attachment.cgi?id=853856&action=diff

Bryce Harrington (bryce)
no longer affects: rsync (Ubuntu Jammy)
no longer affects: rsync (Ubuntu Kinetic)
no longer affects: rsync (Ubuntu Lunar)
Changed in rsync (Ubuntu Bionic):
status: New → Confirmed
Changed in rsync (Ubuntu Focal):
status: New → Confirmed
importance: Undecided → Low
Changed in rsync (Ubuntu Bionic):
importance: Undecided → Low
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.