duplicity falsely reports succeeded backup, empty manifest file

[9johnny]

duplicity version duplicity 0.6.09
Python 2.5.2
Distributor ID: Debian
Description: Debian GNU/Linux 5.0.6 (lenny)
Release: 5.0.6
Codename: lenny

==backup log snip==
ionice -c 3 nice -n 9 duplicity incremental --full-if-older-than 2W --asynchronous-upload --no-encryption --asynchronous-upload --no-encryption --exclude '/tmp/**' --exclude '/proc/**' --exclude '/dev/**' --exclude '/sys/**' --exclude '/root/.cache/**' --exclude '/var/cache/duplicity/**' --exclude '/var/marsnet/duplicity/**' --exclude '/var/alternc/mnt/**' --exclude '/var/lib/mysql/**' --exclude '/var/alternc/db/**' --exclude '/var/log/mysql/**' / ssh://backup@mybckhost//opt/marsnet/backups/
Local and Remote metadata are synchronized, no sync needed.
Last full backup date: Thu Oct 28 01:13:25 2010
Last full backup is too old, forcing full backup
--------------[ Backup Statistics ]--------------
StartTime 1289607215.28 (Sat Nov 13 01:13:35 2010)
EndTime 1289636885.88 (Sat Nov 13 09:28:05 2010)
ElapsedTime 29670.59 (8 hours 14 minutes 30.59 seconds)
SourceFiles 1730868
SourceFileSize 106161258939 (98.9 GB)
NewFiles 1730868
NewFileSize 106161244989 (98.9 GB)
DeletedFiles 0
ChangedFiles 0
ChangedFileSize 0 (0 bytes)
ChangedDeltaSize 0 (0 bytes)
DeltaEntries 1730868
RawDeltaSize 105419449446 (98.2 GB)
TotalDestinationSizeChange 65491887291 (61.0 GB)
Errors 0
-------------------------------------------------

++ hostname --fqdn
+ ionice -c 3 nice -n 9 duplicity remove-all-but-n-full 1 --force --no-encryption ssh://backup@mybckhost//opt/marsnet/backups/
Local and Remote metadata are synchronized, no sync needed.
Last full backup date: Sat Nov 13 01:13:30 2010
Deleting backup set at time:
Thu Oct 28 01:13:25 2010
Deleting this file from backend:
duplicity-full-signatures.20101027T231325Z.sigtar.gz
==end snip==

This is the log from the backup that failed. Ihave conditional execution so backups aren't removed if duplicity fails. In this case there was no error, but I found an empty manifest file in the destination directory. Sorry, i don't use extra verbose output in my backup scripts.
All the restore scripts fail silently: they see the archive as empty, this could be the reason why duplicity reported success on exit?
(very annoying, i just had to restore a file, i'm trying to recover at least a part of it using simple gunzip and tar..)

[9johnny (s.j.)]

I also have a verify step running every once in a while (it ran this time), but since duplicity thinks this archive is fine, it didn't report any failures. Verifying the archive otherwise is impossible since i can't know which files will change since the backup.

[9johnny (s.j.)]

So this backup has failed in more than one ways, not only was the manifests file empty, but there was at least one directory that was completely ignored from the backup (i did the following script to try and find the files in the archives:
==snip bash code==
cd /opt/marsnet/backups
for i in*; do
  if gunzip --stdout $i |tar tl |grep -q '/var/alternc/html'; then
    echo $i
  fi
done
==end snip==
the entire html directory was skipped.

[Marcus Williams (marcus-lp)]

I think I might be hitting this bug as well - I can now reproduce this with a small full backup. I've emailed the mailing list with these details, but I'm adding here so I can track this.

Heres the log of a failed session (I get the same on a local filesystem, but this log is from nfs mounted directory):

+++++++++++++++ Logs etc follow +++++++++++++++

This is the log of a backup via the command line of:

duplicity -v9 --volsize 512 --encrypt-key FB04F88E include/ file:///backup/tst

Version of duplicity etc:

duplicity 0.6.11
Python 2.6.5
gpg (GnuPG) 1.4.6

Produced backup dir:

-rw------- 1 nobody nogroup 10824 Dec 7 12:15 duplicity-full-signatures.20101207T121533Z.sigtar.gpg
-rw------- 1 nobody nogroup 0 Dec 7 12:15 duplicity-full.20101207T121533Z.manifest.gpg
-rw------- 1 nobody nogroup 87296 Dec 7 12:15 duplicity-full.20101207T121533Z.vol1.difftar.gpg

Notice the zero size manifest.

Logs (-v9):

Using archive dir: /root/.cache/duplicity/e5289d7bf194599a13f8830c08099343
Using backup name: e5289d7bf194599a13f8830c08099343
Import of duplicity.backends.sshbackend Succeeded
Import of duplicity.backends.localbackend Succeeded
Import of duplicity.backends.imapbackend Succeeded
Import of duplicity.backends.botobackend Succeeded
Import of duplicity.backends.hsibackend Succeeded
Import of duplicity.backends.tahoebackend Succeeded
Import of duplicity.backends.rsyncbackend Succeeded
Import of duplicity.backends.ftpbackend Succeeded
Import of duplicity.backends.cloudfilesbackend Succeeded
Import of duplicity.backends.giobackend Failed: No module named gio
Import of duplicity.backends.webdavbackend Succeeded
Main action: inc
================================================================================
duplicity 0.6.11 (November 20, 2010)
Args: /usr/local/bin/duplicity -v9 --volsize 512 --encrypt-key FB04F88E include/ file:///backup/tst
Linux stampy 2.4.32.20060811 #1 SMP Fri Aug 11 10:25:54 BST 2006 i686
/usr/local/bin/python2.6 2.6.5 (r265:79063, May 21 2010, 12:18:58)
[GCC 3.3.5 (Debian 1:3.3.5-13)]
================================================================================
Using temporary directory /exports/tmp/duplicity-U9IGVk-tempdir
Registering (mkstemp) temporary file /exports/tmp/duplicity-U9IGVk-tempdir/mkstemp-6Vvb5C-1
Temp has 99190284288 available, backup will use approx 697932185.
Synchronizing remote metadata to local cache...
Deleting local /root/.cache/duplicity/e5289d7bf194599a13f8830c08099343/duplicity-full-signatures.20101207T121342Z.sigtar.gz (not authoritative at backend).
Deleting local /root/.cache/duplicity/e5289d7bf194599a13f8830c08099343/duplicity-full.20101207T121342Z.manifest (not authoritative at backend).
0 files exist on backend
0 files exist in cache
Extracting backup chains from list of files: []
Last full backup date: none
Collection Status
-----------------
Connecting with backend: LocalBackend
Archive dir: /root/.cache/duplicity/e5289d7bf194599a13f8830c08099343

Found 0 secondary backup chains.
No backup chains with active signatures found
No orphaned or incomplete backup sets found.
No signatures found, switching to full backup.
Using temporary directory /root/.cache/duplicity/e5289d7bf194599a1...

[Marcus Williams (marcus-lp)]

I'm non Debian 3.1, python 2.6. I'm using the TMPDIR variable to move tmp access outside of /tmp, but it makes no difference to the outcome. There is plenty of space on both partitions.

Under strace, its not 100% reproducable but I've uploaded a log of a failure here: http://thesafebox.com/backup-failed.log (approx 500k)

[Jan Reidemeister (jan-reidemeister)]

Same problem here with 0.6.11 running on a Synology DS1010+ (Linux 2.6.32.12 x86_64, Python 2.6.6). The solution suggested on http://comments.gmane.org/gmane.comp.sysutils.backup.duplicity.general/4290 to replace the GnuPGInterface with the original works.

[Rüdiger Kupper (ruediger.kupper)]

Same problem here with 0.6.10 (that's the version in the ubuntu maverick package sources). Any chance that this will be fixed soon?
Question: The manifest file in the local cache directory seems intact. Can I simply copy this file to the remote location to fix the problem?

[Kenneth Loafman (kenneth-loafman)]

Has anyone tried this on a later version of duplicity, 0.6.13 for example?

[Kenneth Loafman (kenneth-loafman)]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

 status confirmed
 importance medium
 done
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEExwf+p6/3mDvUSsaGH1G0ZBEHM/EFAmBmHRQACgkQH1G0ZBEH
M/E/AAf+MZaZWPdkBWLx6pZV/wxe6uj8ONurmdDQokXiXWyCflydf9gJxCUX1FKb
M51L4nlApghWR9uYf5lX0JYb8oaSsspIu8JMz5IS/7l29MeGS6b0wt0shPmQM6fY
c2gcLdq9cbuLGw98ZonZf8Q2hCfYjtBI4SL2VxWSXZ3mcEWY4YP140iv053DmLnp
BFtdQpgFX+1V5a7TC5B8UwzQ+i6eW7B7OIUM2J4KJrVcqdp9AOsYkWXKfiNVVCjj
0cB3PE4jsk/S+Q4DvJJR4A8FE7uJnfZGv0r01ugC0JMcxbRqOsOnv3VfNHKpPvCT
PwsSlp9CfJKLto64SymqJU3SWIUTWw==
=CdqP
-----END PGP SIGNATURE-----