rsync backend Remote filesize 0 does not match local size N, retrying

On 26.09.2018 02:07, BenRifkah Bergsten-Buret wrote:
> New question #674425 on Duplicity:
> https://answers.launchpad.net/duplicity/+question/674425
>
> I'm trying to get backups running from my CentOS server to a RHEL remote server. I keep getting this error when I try to back up:
>
> "Remote filesize 0 for 'duplicity-full.20180925T231400Z.vol1.difftar.gz' does not match local size 496, retrying."
>
> It appears 5 times and then duplicity gives up. When I check the files on the remote server they have a non-zero size. It looks like the rsync backend is having trouble checking and reporting the size. I have a minimum example that produces the message but syncs to a different directory on the source host.
>
> Here's the info level log output:
>
> "$ duplicity full --no-encryption pkgs rsync://localhost//home/CHSCC/bburnett/duplicity_backup_test/pkgs/
> Local and Remote metadata are synchronized, no sync needed.
> Last full backup date: none
> Remote filesize 0 for 'duplicity-full.20180926T000202Z.vol1.difftar.gz' does not match local size 496, retrying.
> Remote filesize 0 for 'duplicity-full.20180926T000202Z.vol1.difftar.gz' does not match local size 496, retrying.
> Remote filesize 0 for 'duplicity-full.20180926T000202Z.vol1.difftar.gz' does not match local size 496, retrying.
> Remote filesize 0 for 'duplicity-full.20180926T000202Z.vol1.difftar.gz' does not match local size 496, retrying.
> Remote filesize 0 for 'duplicity-full.20180926T000202Z.vol1.difftar.gz' does not match local size 496, retrying.
> --------------[ Backup Statistics ]--------------
> StartTime 1537920123.57 (Tue Sep 25 17:02:03 2018)
> EndTime 1537920123.61 (Tue Sep 25 17:02:03 2018)
> ElapsedTime 0.03 (0.03 seconds)
> SourceFiles 29
> SourceFileSize 86 (86 bytes)
> NewFiles 29
> NewFileSize 86 (86 bytes)
> DeletedFiles 0
> ChangedFiles 0
> ChangedFileSize 0 (0 bytes)
> ChangedDeltaSize 0 (0 bytes)
> DeltaEntries 29
> RawDeltaSize 0 (0 bytes)
> TotalDestinationSizeChange 496 (496 bytes)
> Errors 0
> -------------------------------------------------
>
> bburnett@chrusm0:~$ ssh localhost ls -lG duplicity_backup_test/pkgs/ 2>/dev/null total 5
> -rw-------. 1 bburnett 193 Sep 25 17:02 duplicity-full.20180926T000202Z.manifest
> -rw-------. 1 bburnett 496 Sep 25 17:02 duplicity-full.20180926T000202Z.vol1.difftar.gz
> -rw-------. 1 bburnett 509 Sep 25 17:02 duplicity-full-signatures.20180926T000202Z.sigtar.gz
> $ duplicity --version
> duplicity 0.7.18.1
> $ lsb_release -a
> LSB Version: :core-4.1-amd64:core-4.1-noarch:cxx-4.1-amd64:cxx-4.1-noarch:desktop-4.1-amd64:desktop-4.1-noarch:lan
> guages-4.1-amd64:languages-4.1-noarch:printing-4.1-amd64:printing-4.1-noarch
> Distributor ID: CentOS
> Description: CentOS Linux release 7.5.1804 (Core)
> Release: 7.5.1804
> Codename: Core"
>
> (SSH Auth is being handled by an agent)
>
> I don't have this problem when I try the same rsync-to-localhost using Ubuntu on Windows 10 with duplicity 0.7.17. Has anyone seen this before?
>

hey Ben,

nope, at least this never came up on the list until now. rsync backend does not support reporting file sizes, so this error should never occur.

1.
what is your duplicity version?

2.
please run the backup with max. verbosity '-v9' and put the _full_ terminal output on a filehoster/pastebin or such and post the link. somewhere view/downloadable. obfuscate private strings in it beforehand if needed.

..ede/duply.net

> -----Original Message-----
> From: <email address hidden> <email address hidden> On Behalf Of
> edso
> >
> > I'm trying to get backups running from my CentOS server to a RHEL remote
> server. I keep getting this error when I try to back up:
> >
> > "Remote filesize 0 for 'duplicity-full.20180925T231400Z.vol1.difftar.gz' does
> not match local size 496, retrying."
> >
> > I don't have this problem when I try the same rsync-to-localhost using
> Ubuntu on Windows 10 with duplicity 0.7.17. Has anyone seen this before?
> >
>
> hey Ben,
>
> nope, at least this never came up on the list until now. rsync backend
> does not support reporting file sizes, so this error should never occur.
>
> 1.
> what is your duplicity version?
>
> 2.
> please run the backup with max. verbosity '-v9' and put the _full_ terminal
> output on a filehoster/pastebin or such and post the link. somewhere
> view/downloadable. obfuscate private strings in it beforehand if needed.
>
> ..ede/duply.net

Edso, thanks for your attention. This is duplicity 0.7.18.1. I've run it again with the sftp backend and I'm getting the same error. Here's the -v9 output of the rsync run followed by the sftp run: https://pastebin.com/YaVz0j7P.

I have a feeling I'm doing something wrong, I just don't see it. If it makes a difference the destination filesystem for these tests is nfs4 mounted from an OmniOS host where the filesystem is zfs.

Thanks,

--
Ben

I did some more digging and this looks to me like a bug in duplicity 0.7.18.1. I was able to reproduce it with the both rsync and scp backends on the following new Vagrant Box installations:

ubuntu/bionic64 – built locally. No RPM available
centos/7 – from EPEL package

I couldn't reproduce it with duplicity 0.7.17:
ubuntu/bionic64 – from RPM
centos/7 – built locally. No RPM available

I'm happy to provide more details but if this needs to be turned into a bug report let me know and I'll provide details there.

Thanks,

--
Ben

On 28.09.2018 00:17, BenRifkah Bergsten-Buret wrote:
> Question #674425 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/674425
>
> BenRifkah Bergsten-Buret gave more information on the question:
> I did some more digging and this looks to me like a bug in duplicity
> 0.7.18.1. I was able to reproduce it with the both rsync and scp
> backends on the following new Vagrant Box installations:
>
> ubuntu/bionic64 – built locally. No RPM available
> centos/7 – from EPEL package
>
> I couldn't reproduce it with duplicity 0.7.17:
> ubuntu/bionic64 – from RPM
> centos/7 – built locally. No RPM available
>
> I'm happy to provide more details but if this needs to be turned into a
> bug report let me know and I'll provide details there.
>
> Thanks,
>

seems to be
"
* Partial fix of bug #1734144 with patch from Joris van Eijden
  - Note: this is really just a partial fix for now, since it only covers
    the case where the local size does not yet match the remote size. A
    case where -1 is the returned length is not fixed.
"
  https://bazaar.launchpad.net/~duplicity-team/duplicity/0.7-series/revision/1354

it does not check if the entry is 'None' which is the case if the backend does not support file size meta data fetching (most do not)
  https://bazaar.launchpad.net/~duplicity-team/duplicity/0.8-series/view/head:/duplicity/backend.py#L616

for now you can stick w/ 0.7.17.. hopefully Ken will fix this soonish, as it probably breaks lot's of installations.

..ede/duply.net

I'll stick with 0.7.17 for now in production. Will post to bug #1788558 the results of testing this against trunk.

Thanks,

--
Ben

I also get this error with 0.7.18.1 and the SFTP backend:

| $ duplicity --version
| duplicity 0.7.18.1
|
| $ duplicity incremental --name "##########" --full-if-older-than 15D --gpg-options="--cipher-algo=AES" --num-retries 10 --backend-retry-delay 10 --asynchronous-upload --verbosity notice "/srv/##########" "par2+sftp://##########/"
| ...
| Local and Remote metadata are synchronized, no sync needed.
| Last full backup date: Wed Oct 10 04:00:24 2018
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
| --------------[ Backup Statistics ]--------------
| StartTime 1539695707.10 (Tue Oct 16 15:15:07 2018)
| EndTime 1539695740.43 (Tue Oct 16 15:15:40 2018)
| ElapsedTime 33.33 (33.33 seconds)
| SourceFiles 81755
| SourceFileSize 1926239011 (1.79 GB)
| NewFiles 44
| NewFileSize 78586390 (74.9 MB)
| DeletedFiles 9
| ChangedFiles 8
| ChangedFileSize 22545363 (21.5 MB)
| ChangedDeltaSize 0 (0 bytes)
| DeltaEntries 61
| RawDeltaSize 82924326 (79.1 MB)
| TotalDestinationSizeChange 9099547 (8.68 MB)
| Errors 0
| -------------------------------------------------
|
| $ echo $?
| 0

The error doesn't happen with 0.7.17.

Clemens,

this is fixed in trunk but unreleased so far
  https://bazaar.launchpad.net/~duplicity-team/duplicity/0.7-series/revision/1365
feel free to manually patch 0.7.18 or use 0.7.17 instead.

@Ken: this is really a showstopper and should be released asap.

..ede/duply.net

On 16.10.2018 16:32, Clemens Fuchslocher wrote:
> Question #674425 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/674425
>
> Clemens Fuchslocher posted a new comment:
> I also get this error with 0.7.18.1 and the SFTP backend:
>
> | $ duplicity --version
> | duplicity 0.7.18.1
> |
> | $ duplicity incremental --name "##########" --full-if-older-than 15D --gpg-options="--cipher-algo=AES" --num-retries 10 --backend-retry-delay 10 --asynchronous-upload --verbosity notice "/srv/##########" "par2+sftp://##########/"
> | ...
> | Local and Remote metadata are synchronized, no sync needed.
> | Last full backup date: Wed Oct 10 04:00:24 2018
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | Remote filesize 0 for 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does not match local size 9099547, retrying.
> | --------------[ Backup Statistics ]--------------
> | StartTime 1539695707.10 (Tue Oct 16 15:15:07 2018)
> | EndTime 1539695740.43 (Tue Oct 16 15:15:40 2018)
> | ElapsedTime 33.33 (33.33 seconds)
> | SourceFiles 81755
> | SourceFileSize 1926239011 (1.79 GB)
> | NewFiles 44
> | NewFileSize 78586390 (74.9 MB)
> | DeletedFiles 9
> | ChangedFiles 8
> | ChangedFileSize 22545363 (21.5 MB)
> | ChangedDeltaSize 0 (0 bytes)
> | DeltaEntries 61
> | RawDeltaSize 82924326 (79.1 MB)
> | TotalDestinationSizeChange 9099547 (8.68 MB)
> | Errors 0
> | -------------------------------------------------
> |
> | $ echo $?
> | 0
>
> The error doesn't happen with 0.7.17.
>

Will try to get a release out in a couple days.

...Ken

On Tue, Oct 16, 2018 at 9:51 AM edso <email address hidden>
wrote:

> Question #674425 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/674425
>
> edso posted a new comment:
> Clemens,
>
> this is fixed in trunk but unreleased so far
>
> https://bazaar.launchpad.net/~duplicity-team/duplicity/0.7-series/revision/1365
> feel free to manually patch 0.7.18 or use 0.7.17 instead.
>
> @Ken: this is really a showstopper and should be released asap.
>
> ..ede/duply.net
>
> On 16.10.2018 16:32, Clemens Fuchslocher wrote:
> > Question #674425 on Duplicity changed:
> > https://answers.launchpad.net/duplicity/+question/674425
> >
> > Clemens Fuchslocher posted a new comment:
> > I also get this error with 0.7.18.1 and the SFTP backend:
> >
> > | $ duplicity --version
> > | duplicity 0.7.18.1
> > |
> > | $ duplicity incremental --name "##########" --full-if-older-than 15D
> --gpg-options="--cipher-algo=AES" --num-retries 10 --backend-retry-delay 10
> --asynchronous-upload --verbosity notice "/srv/##########"
> "par2+sftp://##########/"
> > | ...
> > | Local and Remote metadata are synchronized, no sync needed.
> > | Last full backup date: Wed Oct 10 04:00:24 2018
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | Remote filesize 0 for
> 'duplicity-inc.20181016T020018Z.to.20181016T131506Z.vol1.difftar.gpg' does
> not match local size 9099547, retrying.
> > | --------------[ Backup Statistics ]--------------
> > | StartTime 1539695707.10 (Tue Oct 16 15:15:07 2018)
> > | EndTime 1539695740.43 (Tue Oct 16 15:15:40 2018)
> > | ElapsedTime 33.33 (33.33 seconds)
> > | SourceFiles 81755
> > | SourceFileSize 1926239011 (1.79 GB)
> > | NewFiles 44
> > | NewFileSize 78586390 (74.9 MB)
> > | DeletedFiles 9
> > | ChangedFiles 8
> > | ChangedFileSize 22545363 (21.5 MB)
> > | ChangedDeltaSize 0 (0 bytes)
> > | DeltaEntries 61
> > | RawDeltaSize 82924326 (79.1 MB)
> > | TotalDestinationSizeChange 9099547 (8.68 MB)
> > | Errors 0
> > | -------------------------------------------------
> > |
> > | $ echo $?
> > | 0
> >
> > The error doesn't happen with 0.7.17.
> >
>
> --
> You received this question notification because your team duplicity-team
> is an answer contact for Duplicity.
>
> _______________________________________________
> Mailing list: https://launchpad.net/~duplicity-team
> Post to : <email address hidden>
> Unsubscribe : https://launchpad.net/~duplicity-team
> More help : https://help.launchpad.net/ListHelp
>