Duplicity

sometimes reads manifest from remote unnecessarily

Bug #1170113 reported by Dave Cottingham on 2013-04-17

This bug report is a duplicate of: Bug #1875937: Download of vol1 in validate_encryption_settings() fails when using S3 glacier. Edit Remove

This bug affects 4 people

Affects		Status	Importance	Assigned to	Milestone
	Duplicity	New	Undecided	Unassigned

Bug Description

Duplicity sometimes reads a manifest from the backup location even though there's a copy in the cache.

For more info, see this mailing list thread:
http://lists.nongnu.org/archive/html/duplicity-talk/2013-04/msg00026.html

Note that this bug is usually innocuous, but if using S3 with a lifecycle rule transitioning everything to Glacier, it is fatal.

Duplicity 0.6.21
Python 2.6.2
OS Slackware 13.0
File system: Linux

Command line:
duplicity incremental --full-if-older-than 60D --archive-dir /home/dc/.cache/duplicity --name eclipse2 --encrypt-key 1A5F5E6E -v9 --exclude /disk2/dc/torrents /disk2 s3+http://caverns-of-mount-catoctin/eclipse2

...

File duplicity-full.20130323T023004Z.vol27.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol28.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol29.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol3.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol30.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol31.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol32.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol33.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol34.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol35.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol36.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol37.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol38.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol39.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol4.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol40.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol41.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol42.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol43.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol44.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol45.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol46.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol47.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol48.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol49.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol5.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol50.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol51.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol52.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol53.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol54.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol55.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol56.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol57.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol58.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol59.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol6.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol60.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol61.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol62.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol63.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol64.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol65.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol66.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol67.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol68.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol69.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol7.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol70.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol71.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol72.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol73.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol74.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol75.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol76.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol77.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol78.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol79.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol8.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol80.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol81.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol82.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol83.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol84.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol85.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol86.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol87.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol88.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol89.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol9.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol90.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol91.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol92.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol93.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol94.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol95.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol96.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol97.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol98.difftar.gpg is part of known set
File duplicity-full.20130323T023004Z.vol99.difftar.gpg is part of known set
File duplicity-inc.20130323T023004Z.to.20130324T023004Z.manifest.gpg is not part of a known set; creating new set
File duplicity-inc.20130323T023004Z.to.20130324T023004Z.vol1.difftar.gpg is part of known set
File duplicity-inc.20130323T023004Z.to.20130324T023004Z.vol2.difftar.gpg is part of known set
File duplicity-inc.20130323T023004Z.to.20130324T023004Z.vol3.difftar.gpg is part of known set
File duplicity-inc.20130323T023004Z.to.20130324T023004Z.vol4.difftar.gpg is part of known set
File duplicity-inc.20130324T023004Z.to.20130325T023007Z.manifest.gpg is not part of a known set; creating new set
File duplicity-inc.20130324T023004Z.to.20130325T023007Z.vol1.difftar.gpg is part of known set
File duplicity-inc.20130325T023007Z.to.20130326T023010Z.manifest.gpg is not part of a known set; creating new set
File duplicity-inc.20130325T023007Z.to.20130326T023010Z.vol1.difftar.gpg is part of known set
File duplicity-inc.20130326T023010Z.to.20130327T023032Z.manifest.gpg is not part of a known set; creating new set
File duplicity-inc.20130326T023010Z.to.20130327T023032Z.vol1.difftar.gpg is part of known set
File duplicity-inc.20130327T023032Z.to.20130328T023004Z.manifest.gpg is not part of a known set; creating new set
File duplicity-inc.20130327T023032Z.to.20130328T023004Z.vol1.difftar.gpg is part of known set
File duplicity-inc.20130327T023032Z.to.20130328T023004Z.vol2.difftar.gpg is part of known set
File duplicity-new-signatures.20130323T023004Z.to.20130324T023004Z.sigtar.gpg is not part of a known set; creating new set
Ignoring file (rejected by backup set) 'duplicity-new-signatures.20130323T023004Z.to.20130324T023004Z.sigtar.gpg'
File duplicity-new-signatures.20130324T023004Z.to.20130325T023007Z.sigtar.gpg is not part of a known set; creating new set
Ignoring file (rejected by backup set) 'duplicity-new-signatures.20130324T023004Z.to.20130325T023007Z.sigtar.gpg'
File duplicity-new-signatures.20130325T023007Z.to.20130326T023010Z.sigtar.gpg is not part of a known set; creating new set
Ignoring file (rejected by backup set) 'duplicity-new-signatures.20130325T023007Z.to.20130326T023010Z.sigtar.gpg'
File duplicity-new-signatures.20130326T023010Z.to.20130327T023032Z.sigtar.gpg is not part of a known set; creating new set
Ignoring file (rejected by backup set) 'duplicity-new-signatures.20130326T023010Z.to.20130327T023032Z.sigtar.gpg'
File duplicity-new-signatures.20130327T023032Z.to.20130328T023004Z.sigtar.gpg is not part of a known set; creating new set
Ignoring file (rejected by backup set) 'duplicity-new-signatures.20130327T023032Z.to.20130328T023004Z.sigtar.gpg'
Found backup chain [Fri Mar 22 22:30:04 2013]-[Fri Mar 22 22:30:04 2013]
Added incremental Backupset (start_time: Fri Mar 22 22:30:04 2013 / end_time: Sat Mar 23 22:30:04 2013)
Added set Sat Mar 23 22:30:04 2013 to pre-existing chain [Fri Mar 22 22:30:04 2013]-[Sat Mar 23 22:30:04 2013]
Added incremental Backupset (start_time: Sat Mar 23 22:30:04 2013 / end_time: Sun Mar 24 22:30:07 2013)
Added set Sun Mar 24 22:30:07 2013 to pre-existing chain [Fri Mar 22 22:30:04 2013]-[Sun Mar 24 22:30:07 2013]
Added incremental Backupset (start_time: Sun Mar 24 22:30:07 2013 / end_time: Mon Mar 25 22:30:10 2013)
Added set Mon Mar 25 22:30:10 2013 to pre-existing chain [Fri Mar 22 22:30:04 2013]-[Mon Mar 25 22:30:10 2013]
Added incremental Backupset (start_time: Mon Mar 25 22:30:10 2013 / end_time: Tue Mar 26 22:30:32 2013)
Added set Tue Mar 26 22:30:32 2013 to pre-existing chain [Fri Mar 22 22:30:04 2013]-[Tue Mar 26 22:30:32 2013]
Added incremental Backupset (start_time: Tue Mar 26 22:30:32 2013 / end_time: Wed Mar 27 22:30:04 2013)
Added set Wed Mar 27 22:30:04 2013 to pre-existing chain [Fri Mar 22 22:30:04 2013]-[Wed Mar 27 22:30:04 2013]
Last full backup date: Fri Mar 22 22:30:04 2013
Collection Status
-----------------
Connecting with backend: BotoBackend
Archive dir: /home/dc/.cache/duplicity/eclipse2

Found 0 secondary backup chains.

Found primary backup chain with matching signature chain:
-------------------------
Chain start time: Fri Mar 22 22:30:04 2013
Chain end time: Wed Mar 27 22:30:04 2013
Number of contained backup sets: 6
Total number of contained volumes: 181
Type of backup set: Time: Num volumes:
                Full Fri Mar 22 22:30:04 2013 172
         Incremental Sat Mar 23 22:30:04 2013 4
         Incremental Sun Mar 24 22:30:07 2013 1
         Incremental Mon Mar 25 22:30:10 2013 1
         Incremental Tue Mar 26 22:30:32 2013 1
         Incremental Wed Mar 27 22:30:04 2013 2
-------------------------
No orphaned or incomplete backup sets found.
Registering (mktemp) temporary file /tmp/duplicity-7YmZM6-tempdir/mktemp-QQ7uXI-2
Downloading s3+http://caverns-of-mount-catoctin/eclipse2/duplicity-inc.20130327T023032Z.to.20130328T023004Z.manifest.gpg
Download s3+http://caverns-of-mount-catoctin/eclipse2/duplicity-inc.20130327T023032Z.to.20130328T023004Z.manifest.gpg failed (attempt #1, reason: S3ResponseError: S3ResponseError: 403 Forbidden
<?xml version="1.0" encoding="UTF-8"?>
<Error><Code>InvalidObjectState</Code><Message>The operation is not valid for the object's storage class</Message><RequestId>6A4D2E92468B7EAE</RequestId><HostId>LNvu3wn691YiwB4lKxIx8BvinLmJgNkUq2PNWnaD76obrIimT2Rxyn8VbnZhRN9+</HostId></Error>)
Backtrace of previous error: Traceback (innermost last):
  File "/usr/lib/python2.6/site-packages/duplicity/backends/_boto_single.py", line 241, in get
    key.get_contents_to_filename(local_path.name)
  File "/usr/lib/python2.6/site-packages/boto/s3/key.py", line 1504, in get_contents_to_filename
    response_headers=response_headers)
  File "/usr/lib/python2.6/site-packages/boto/s3/key.py", line 1451, in get_contents_to_file
    response_headers=response_headers)
  File "/usr/lib/python2.6/site-packages/boto/s3/key.py", line 1300, in get_file
    query_args=None)
  File "/usr/lib/python2.6/site-packages/boto/s3/key.py", line 1329, in _get_file_internal
    override_num_retries=override_num_retries)
  File "/usr/lib/python2.6/site-packages/boto/s3/key.py", line 288, in open
    override_num_retries=override_num_retries)
  File "/usr/lib/python2.6/site-packages/boto/s3/key.py", line 238, in open_read
    self.resp.reason, body)
S3ResponseError: S3ResponseError: 403 Forbidden
<?xml version="1.0" encoding="UTF-8"?>
<Error><Code>InvalidObjectState</Code><Message>The operation is not valid for the object's storage class</Message><RequestId>6A4D2E92468B7EAE</RequestId><HostId>LNvu3wn691YiwB4lKxIx8BvinLmJgNkUq2PNWnaD76obrIimT2Rxyn8VbnZhRN9+</HostId></Error>

Downloading s3+http://caverns-of-mount-catoctin/eclipse2/duplicity-inc.20130327T023032Z.to.20130328T023004Z.manifest.gpg
Removing still remembered temporary file /tmp/duplicity-7YmZM6-tempdir/mktemp-QQ7uXI-2
Removing still remembered temporary file /tmp/duplicity-7YmZM6-tempdir/mkstemp-jjKlHs-1
GPG error detail: Traceback (most recent call last):
  File "/usr/bin/duplicity", line 1411, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1404, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1385, in main
    check_last_manifest(col_stats) # not needed for full backup
  File "/usr/bin/duplicity", line 1105, in check_last_manifest
    last_backup_set.check_manifests()
  File "/usr/lib/python2.6/site-packages/duplicity/collections.py", line 186, in check_manifests
    remote_manifest = self.get_remote_manifest()
  File "/usr/lib/python2.6/site-packages/duplicity/collections.py", line 220, in get_remote_manifest
    manifest_buffer = self.backend.get_data(self.remote_manifest_name)
  File "/usr/lib/python2.6/site-packages/duplicity/backend.py", line 631, in get_data
    assert not fin.close()
  File "/usr/lib/python2.6/site-packages/duplicity/dup_temp.py", line 225, in close
    assert not self.fileobj.close()
  File "/usr/lib/python2.6/site-packages/duplicity/gpg.py", line 251, in close
    self.gpg_failed()
  File "/usr/lib/python2.6/site-packages/duplicity/gpg.py", line 218, in gpg_failed
    raise GPGError, msg
GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: decrypt_message failed: eof
gpg: WARNING: unsafe ownership on homedir `/home/dc/.gnupg'
===== End GnuPG log =====

GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: decrypt_message failed: eof
gpg: WARNING: unsafe ownership on homedir `/home/dc/.gnupg'
===== End GnuPG log =====

Fri Apr 12 08:49:02 EDT 2013

Revision history for this message

Dave Cottingham (dcottingham00) wrote on 2013-04-18:

log-inc Edit (12.6 KiB, text/plain)

Actually, I think duplicity always reads the latest manifest from the remote, even if it's in the cache. That should make the problem easier to reproduce.

To test this I set up a backup of a small folder, ran the full, then ran an inc. The log file shows duplicity loading the manifest from remote. Since, for this run, I am using ssh and not S3/Glacier, the bug isn't fatal. I have attached the log file.

For this test:
Duplicity 0.6.21
Python 2.7.3
OS Ubuntu 12.04.2 LTS
File system: Linux

Command line:
/home/dc/local/bin/duplicity incremental --full-if-older-than 60D -v9 --ssh-backend pexpect --ssh-askpass --archive-dir /home/dc/.cache/duplicity --name kauai-debug /home/dc/Music/Wanda_Landowska sftp://dc@localhost/kauai-debug

Revision history for this message

Dave Cottingham (dcottingham00) wrote on 2013-12-06:

I have identified why this bug occurs. For incremental backups duplicity always calls BackupSet.check_manifests(), described as "Make sure remote manifest is equal to local one." It reads the manifest from the remote and checks that it is identical to the local copy. I believe this is the only file that duplicity checks in this way.

Of course, the usual case is that the remote files are encrypted and duplicity is not in possession of the secret key. After reading the file from remote, if duplicity finds this is the case then it just proceeds as if the comparison had succeeded.

As I mentioned above, this behavior is fatal if the remote is Amazon S3 transitioned to Glacier. But there are several ways one could imagine patching it:

1. Get rid of check_manifests() altogether. I don't see why in this one case we should be paranoid about a remote file not matching the one in the local cache.

2. Instead of ignoring only the exception that the secret key is not available, also ignore the exception of not being able to read from the remote.

3. Add a command line flag to disable check_manifests().

Revision history for this message

Matt Thompson (chameleonator) wrote on 2014-03-20:

This may be unrelated to your use case but at my business we are using http://bazaar.launchpad.net/~chameleonator/duplicity/s3-skip-glacier/revision/968 to avoid downloading transitioned glacier files. We're only ever restoring/testing the latest backup so this works great for us.

Revision history for this message

Jack (jack-234521) wrote on 2020-08-12:

I know this is an old issue, but this is still a blocker on v8.14 using Boto3 -

When I create a full backup using the --s3-use-deep-archive flag, everything works well. Archive files are stored in the DEEP_ARCHIVE class, as are signature files (I'll come back to that). The manifest files are stored in the STANDARD class.

When I attempt to run an incremental, Duplicity encounters a fatal issue trying to validate the remote signature file:

Command 'backup' returned non-zero exit status 50.
+ exec dup /sourcefolder boto3+s3://bucketname/
Synchronizing remote metadata to local cache...
Copying manifest-backup.remote.server-duplicity-full.time.manifest.gpg to local cache.
Copying manifest-backup.remote.server-duplicity-inc.time.to.time.manifest.gpg to local cache.
Copying signature-backup.remote.server-duplicity-full-signatures.time.sigtar.gpg to local cache.
Attempt 1 failed. ClientError: An error occurred (InvalidObjectState) when calling the GetObject operation: The operation is not valid for the object's storage class
Attempt 2 failed. ClientError: An error occurred (InvalidObjectState) when calling the GetObject operation: The operation is not valid for the object's storage class
Attempt 3 failed. ClientError: An error occurred (InvalidObjectState) when calling the GetObject operation: The operation is not valid for the object's storage class
Attempt 4 failed. ClientError: An error occurred (InvalidObjectState) when calling the GetObject operation: The operation is not valid for the object's storage class
Giving up after 5 attempts. ClientError: An error occurred (InvalidObjectState) when calling the GetObject operation: The operation is not valid for the object's storage class

So here's my million $ question...

If Duplicity now supports glacier "out of the box" (and writing directly to a non-standard storage class), then shouldn't the signature files also be stored in the STANDARD class, not the DEEP_ARCHIVE (in my case)? Otherwise, incrementals will always fail.

Am I missing something? How do I get around this without creating my own fork and compiling...

I know this is an old issue, but this is still a blocker on v8.14 using Boto3 -

When I create a full backup using the --s3-use-deep-archive flag, everything works well.  Archive files are stored in the DEEP_ARCHIVE class, as are signature files (I'll come back to that).  The manifest files are stored in the STANDARD class.

When I attempt to run an incremental, Duplicity encounters a fatal issue trying to validate the remote signature file:

So here's my million $ question...

Am I missing something?  How do I get around this without creating my own fork and compiling...