Crash during restore: "assert ropath.index == (), ropath.index"

Bug #929067 reported by Matthew Stephenson on 2012-02-08
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Duplicity
Medium
Unassigned
duplicity (Ubuntu)
Undecided
Unassigned

Bug Description

Duplicity version: 0.6.15
Python version: 2.7.2+
OS: Ubuntu 11.10
Target filesystem: Linux (Synology NAS, via sftp)

I'm experiencing a repeatable crash which manifests itself on restore, when the initial backup is interrupted and resumed. The data I use doesn't seem to matter. Steps to reproduce:

1. Create a directory of test data. Mine was around 125MiB
2. duplicity --no-encryption TestDir ssh://user@target/backup/TestDir
3. Wait until one or two tar files have been uploaded, then Ctrl-C to kill duplicity
4. duplicity --no-encryption TestDir ssh://user@target/backup/TestDir (duplicity should resume the backup where it left off; allow it to complete this time)
5. duplicity --no-encryption TestDir ssh://user@target/backup/TestDir (repeat the command a third time - note that duplicity reports a nonzero number of DeletedFiles even though the data has not changed.
6. rm -r TestDir
7. duplicity --no-encryption ssh://user@target/backup/TestDir TestDir (attempt to restore -> crash)

The crash output is as follows:

user@laptop:~$ duplicity --no-encryption ssh://user@target/backup/Test4 Test4
Local and Remote metadata are synchronized, no sync needed.
Last full backup date: Wed Feb 8 19:29:16 2012
Traceback (most recent call last):
  File "/usr/bin/duplicity", line 1359, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1342, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1276, in main
    restore(col_stats)
  File "/usr/bin/duplicity", line 591, in restore
    restore_get_patched_rop_iter(col_stats)):
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 523, in Write_ROPaths
    ITR( ropath.index, ropath )
  File "/usr/lib/python2.7/dist-packages/duplicity/lazy.py", line 320, in __call__
    self.process_w_branch(index, self.root_branch, args)
  File "/usr/lib/python2.7/dist-packages/duplicity/lazy.py", line 293, in process_w_branch
    branch.start_process, args)
  File "/usr/lib/python2.7/dist-packages/duplicity/robust.py", line 37, in check_common_error
    return function(*args)
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 545, in start_process
    assert ropath.index == (), ropath.index
AssertionError: somefile.dat

I can provide more information, log output, test data (although the data doesn't seem to matter), or test with other versions of duplicity if requested.

Related branches

Michael Terry (mterry) wrote :

I can reproduce using your steps! Thanks so much for the clear sequence. Looking into this.

Changed in duplicity:
assignee: nobody → Michael Terry (mterry)
status: New → Confirmed
summary: - Crash on restore when initial backup interrupted
+ Crash during restore: "assert ropath.index == (), ropath.index"
Michael Terry (mterry) wrote :

For anyone affected by this bug, try this workaround and please report back:

 * sudo gedit /usr/share/pyshared/duplicity/diffdir.py
 * Find a line like "if delta is not None:" and replace it with "if delta is not None and not (delta.index == () and delta.difftype == 'deleted'):"
 * Close gedit and try restoring again

For the technical details of what's going on:
The interrupted backup is causing two identical "snapshot/" directory entries to be put into the full sigtar. This confuses duplicity and it thinks the base directory (i.e. "." or () depending on whether you talk duplicity or not) is deleted.

I think there's a two pronged approach to this. 1) Gracefully ignore base iters that claim to be deleted, since that's just bogus. (And that's what the above patch does). 2) Don't write duplicate snapshot/ entries in the tar file in the first place. Looking into that one.

Michael Terry (mterry) wrote :

Sorry, I meant edit patchdir.py, not diffdir.py. :-/

Michael Terry (mterry) on 2012-09-28
Changed in duplicity:
status: Confirmed → In Progress
Launchpad Janitor (janitor) wrote :

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

Changed in duplicity (Ubuntu):
status: New → Confirmed
Changed in duplicity:
status: In Progress → Confirmed
milestone: none → 0.6.20
Changed in duplicity:
status: Confirmed → Fix Committed
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package duplicity - 0.6.19-0ubuntu2

---------------
duplicity (0.6.19-0ubuntu2) quantal; urgency=low

  * debian/patches/06nodeletebasedir.dpatch:
    - Backport patch to fix possible error during restore due to
      duplicate entries in backup metadata from resumed backups.
      LP: #929067
 -- Michael Terry <email address hidden> Thu, 13 Sep 2012 12:43:50 -0400

Changed in duplicity (Ubuntu):
status: Confirmed → Fix Released
Changed in duplicity:
importance: Undecided → Medium
assignee: Michael Terry (mterry) → nobody
Changed in duplicity:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers