AssertionError in manifest.py: assert filecount == len(self.files_changed)

Bug #1538333 reported by Grishnackh on 2016-01-26
46
This bug affects 7 people
Affects Status Importance Assigned to Milestone
Duplicity
High
Unassigned
duplicity (Ubuntu)
High
Unassigned
Zesty
High
Unassigned

Bug Description

Duplicity was almost finishing a full backup to a FTP server. When I restarted the backup, the following error occured:

root@MyMachine:~# duply MyProfile backup
Start duply v1.11, time is 2016-01-26 23:38:21.
Using profile '/root/.duply/MyProfile'.
Using installed duplicity version 0.7.06, python 2.7.3, gpg 1.4.12 (Home: ~/.gnupg), awk 'mawk 1.3.3 Nov 1996, Copyright (C) Michael D. Brennan', grep 'grep (GNU grep) 2.12', bash 'GNU bash, Version 4.2.37(1)-release (i486-pc-linux-gnu)'.
Autoset found secret key of first GPG_KEY entry 'XXXXXXXX' for signing.
Checking TEMP_DIR '/tmp' is a folder and writable (OK)
Test - Encrypt to 'XXXXXXXX' & Sign with 'XXXXXXXX' (OK)
Test - Decrypt (OK)
Test - Compare (OK)
Cleanup - Delete '/tmp/duply.16938.1453847902_*'(OK)

--- Start running command PRE at 23:38:24.349 ---
Skipping n/a script '/root/.duply/MyProfile/pre'.
--- Finished state OK at 23:38:24.400 - Runtime 00:00:00.051 ---

--- Start running command BKP at 23:38:24.447 ---
LFTP version is 4.3.6
Reading globbing filelist /root/.duply/MyProfile/exclude
Local and Remote metadata are synchronized, no sync needed.
Traceback (most recent call last):
  File "/usr/local/bin/duplicity", line 1532, in <module>
    with_tempdir(main)
  File "/usr/local/bin/duplicity", line 1526, in with_tempdir
    fn()
  File "/usr/local/bin/duplicity", line 1380, in main
    do_backup(action)
  File "/usr/local/bin/duplicity", line 1405, in do_backup
    globals.archive_dir).set_values()
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 710, in set_values
    self.get_backup_chains(partials + backend_filename_list)
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 835, in get_backup_chains
    add_to_sets(f)
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 829, in add_to_sets
    if new_set.add_filename(filename):
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 101, in add_filename
    self.set_manifest(filename)
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 149, in set_manifest
    self.set_files_changed()
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 128, in set_files_changed
    mf = self.get_manifest()
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 250, in get_manifest
    return self.get_local_manifest()
  File "/usr/local/lib/python2.7/dist-packages/duplicity/collections.py", line 225, in get_local_manifest
    return manifest.Manifest().from_string(manifest_buffer)
  File "/usr/local/lib/python2.7/dist-packages/duplicity/manifest.py", line 207, in from_string
    assert filecount == len(self.files_changed)
AssertionError

23:38:36.860 Task 'BKP' failed with exit code '30'.
--- Finished state FAILED 'code 30' at 23:38:36.860 - Runtime 00:00:12.412 ---

--- Start running command POST at 23:38:36.930 ---
Skipping n/a script '/root/.duply/MyProfile/post'.
--- Finished state OK at 23:38:36.983 - Runtime 00:00:00.052 ---

Probably the version of python got updated in the meantime, but I'm not sure about this.

Similar tickets, eventually this bug report is a duplicate of those:
- https://bugs.launchpad.net/duplicity/+bug/1485579
- https://bugzilla.redhat.com/show_bug.cgi?id=1288702

Changed in duplicity:
importance: Undecided → Medium
milestone: none → 0.7.07
status: New → Fix Committed
Changed in duplicity:
status: Fix Committed → Fix Released
Vej (vej) on 2017-03-06
Changed in duplicity (Ubuntu):
status: New → Triaged
importance: Undecided → High
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package duplicity - 0.7.06-2ubuntu3

---------------
duplicity (0.7.06-2ubuntu3) zesty; urgency=medium

  * d/p/backport-fix-tags-in-locked-folders.patch:
    - Fix OSError looking for tag in locked folders with exclude-if-present
      (LP: #1620085)
  * d/p/backport-crash-on-restore.patch:
    - Guard a chown call to avoid a stacktrace (LP: #1642813)
  * d/p/backport-ignore-excluded-locked-files.patch:
    - Ignore excluded locked files rather than giving noisy errors
      (LP: #1089131)
  * d/p/backport-downgrade-error.patch:
    - Make locked file messages be warnings not errors, again. This avoids
      confusing deja-dup. (LP: #1605939)
  * d/p/backport-flush-after-write.patch:
    - Flush after writing a temp file, to keep disk in sync (LP: #1538333)
  * d/p/backport-gpg2.patch:
    - Improve support for gpg2 (fixing FTBFS in process)

 -- Michael Terry <email address hidden> Tue, 07 Mar 2017 18:48:01 -0500

Changed in duplicity (Ubuntu Zesty):
status: Triaged → Fix Released
Michael Terry (mterry) wrote :

The fix for this got reverted in duplicity (due to bug 1570293). Should this be re-opened?

Reopening

Changed in duplicity:
assignee: nobody → Michael Terry (mterry)
milestone: 0.7.07 → 0.7.13
status: Fix Released → In Progress
Michael Terry (mterry) on 2017-05-02
Changed in duplicity (Ubuntu):
status: Fix Released → New
Michael Terry (mterry) on 2017-05-02
Changed in duplicity:
assignee: Michael Terry (mterry) → nobody

This bug was fixed in 0.7.07.1. I cannot reproduce.

Changed in duplicity:
status: In Progress → Won't Fix
status: Won't Fix → New
milestone: 0.7.13 → none
Stefano Rago (stefano-rago) wrote :

I am still experiencing this issue with duplicity 0.7.12 on Ubuntu 15.04.

A previous backup terminated abnormally with this message:

"""
Giving up after 5 attempts. MemoryError:
"""

Any subsequent attempt to backup returns the AssertionError above.

Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in duplicity (Ubuntu):
status: New → Confirmed
Changed in duplicity:
importance: Medium → High

I have been unable to reproduce this in testing. If you encounter this error, please provide the following:

1) full command line
2) full unencrypted manifest file (attached as a file)
3) detailed (ls -l style) listing of the remote system (attached as a file)
4) as much of the logging as possible, especially the first 200 lines and last 200 lines at -v9 level (attached as a file)

NOTE: Comment #5 references a memory error. This is a different bug that we're working on.

Changed in duplicity:
milestone: none → 0.7.14
status: New → Incomplete
Tomek Korek (cytadela8) wrote :

I encountered this error today. Here is the data requested.

1) duplicity cleanup -v9 --force 'sftp://__MY_SERVER__/__MY_FOLDER__' 2&>1 > logfile1
2) 'duplicity-inc.20170609T192036Z.to.20170620T202313Z.manifest.part' the file causing problems
3) 'filelist' got with command echo "ls -la ." | sftp -q "__MY_SERVER__:/__MY_FOLDER__'" > filelist
4) 'logfile1' result of 1)

I can only add one attachment so I zipped everything.
I get the same exception also when I try to recover an folder.

Changed in duplicity:
assignee: nobody → Kenneth Loafman (kenneth-loafman)
status: Incomplete → In Progress

* Fixed bug #1538333 Assertion error in manifest.py: assert filecount == ...
  - Made sure to never pass .part files as true manifest files
  - Changed assert to log.Error to warn about truncated/corrupt filelist
  - Added unit test to make sure detection works
  - Note: while this condition is serious, it will not affect the basic backup and restore
    functions. Interactive options like --list-files-changed and --file-changed will not
    work correctly for this backup set, so it is advised to run a full backup as soon as
    possible after this error occurs.

Changed in duplicity:
assignee: Kenneth Loafman (kenneth-loafman) → nobody
status: In Progress → Fix Committed
Changed in duplicity:
status: Fix Committed → Fix Released
Niklas Sombert (ytvwld) wrote :

I've just experienced this bug on Zesty with duplicity 0.7.06-2ubuntu3.

I was doing a full backup when the underlying filesystem disappeared (partly my fault).
I remounted it and trying to resume the backup, but duplicity won't start with
Traceback (most recent call last):
  File "/usr/bin/duplicity", line 1532, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1526, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1380, in main
    do_backup(action)
  File "/usr/bin/duplicity", line 1405, in do_backup
    globals.archive_dir).set_values()
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 710, in set_values
    self.get_backup_chains(partials + backend_filename_list)
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 835, in get_backup_chains
    add_to_sets(f)
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 829, in add_to_sets
    if new_set.add_filename(filename):
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 101, in add_filename
    self.set_manifest(filename)
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 149, in set_manifest
    self.set_files_changed()
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 128, in set_files_changed
    mf = self.get_manifest()
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 250, in get_manifest
    return self.get_local_manifest()
  File "/usr/lib/python2.7/dist-packages/duplicity/collections.py", line 225, in get_local_manifest
    return manifest.Manifest().from_string(manifest_buffer)
  File "/usr/lib/python2.7/dist-packages/duplicity/manifest.py", line 207, in from_string
    assert filecount == len(self.files_changed)
AssertionError

This bug is marked as fixed but I haven't seen an update for Zesty. Did I miss something?

darthvader (sarmbruster) wrote :

I was able to recover from this situation by doing a `rm -rf ~/.config/duplicity/duply_<jobname>`

Changed in duplicity (Ubuntu):
status: Confirmed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers