MemoryError while verifying backup

[hackel]

While trying to verify a backup (launched from deja-dup), I receive the following error. My system currently shows 11G of RAM available plus 23G of swap. Possibly related to #1720159?

Traceback (most recent call last):
  File "/usr/bin/duplicity", line 1546, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1540, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1391, in main
    do_backup(action)
  File "/usr/bin/duplicity", line 1468, in do_backup
    restore(col_stats)
  File "/usr/bin/duplicity", line 731, in restore
    restore_get_patched_rop_iter(col_stats)):
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 560, in Write_ROPaths
    for ropath in rop_iter:
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 523, in integrate_patch_iters
    for patch_seq in collated:
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 389, in yield_tuples
    setrorps(overflow, elems)
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 378, in setrorps
    elems[i] = iter_list[i].next()
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 107, in filter_path_iter
    for path in path_iter:
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 121, in difftar2path_iter
    tarinfo_list = [tar_iter.next()]
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 339, in next
    self.set_tarfile()
  File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line 333, in set_tarfile
    self.current_fp = self.fileobj_iter.next()
  File "/usr/bin/duplicity", line 763, in get_fileobj_iter
    manifest = backup_set.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 224, in get_local_manifest
    return manifest.Manifest().from_string(manifest_buffer)
  File "/usr/lib/python2.7/dist-packages/duplicity/manifest.py", line 214, in from_string
    for match in vi_iterator:
MemoryError

ProblemType: Bug
DistroRelease: Ubuntu 17.10
Package: duplicity 0.7.12-1ubuntu1
ProcVersionSignature: Ubuntu 4.13.0-16.19-generic 4.13.4
Uname: Linux 4.13.0-16-generic x86_64
ApportVersion: 2.20.7-0ubuntu3.1
Architecture: amd64
CurrentDesktop: GNOME
Date: Mon Nov 6 10:50:12 2017
EcryptfsInUse: Yes
InstallationDate: Installed on 2014-08-03 (1190 days ago)
InstallationMedia: Ubuntu 14.04.1 LTS "Trusty Tahr" - Release amd64 (20140722.2)
SourcePackage: duplicity
UpgradeStatus: Upgraded to artful on 2017-09-29 (37 days ago)

[Olivier Crête (olivier-crete)]

This isn't a duplicate of the previous, I can reproduce the same exact stack trace with 0.7.15 when trying to make a backup from deja-dup.

Traceback (innermost last):
  File "/usr/bin/duplicity", line 1559, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1545, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1394, in main
    do_backup(action)
  File "/usr/bin/duplicity", line 1526, in do_backup
    check_last_manifest(col_stats) # not needed for full backup
  File "/usr/bin/duplicity", line 1228, in check_last_manifest
    last_backup_set.check_manifests()
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 208, in check_manifests
    remote_manifest = self.get_remote_manifest()
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 249, in get_remote_manifest
    return manifest.Manifest().from_string(manifest_buffer)
  File "/usr/lib64/python2.7/site-packages/duplicity/manifest.py", line 201, in from_string
    for match in vi_iterator:
 MemoryError

[Kenneth Loafman (kenneth-loafman)]

@Olivier,

- When you upgraded to 0.7.15, did you remove the distro's version?

- How much memory do you have? Is it the same as previous?

- How long of an incremental change list do you have?

- Have you tried making a full backup?

On Wed, Jan 17, 2018 at 2:22 PM, Olivier Crête <email address hidden>
wrote:

> This isn't a duplicate of the previous, I can reproduce the same exact
> stack trace with 0.7.15 when trying to make a backup from deja-dup.
>
>
> Traceback (innermost last):
> File "/usr/bin/duplicity", line 1559, in <module>
> with_tempdir(main)
> File "/usr/bin/duplicity", line 1545, in with_tempdir
> fn()
> File "/usr/bin/duplicity", line 1394, in main
> do_backup(action)
> File "/usr/bin/duplicity", line 1526, in do_backup
> check_last_manifest(col_stats) # not needed for full backup
> File "/usr/bin/duplicity", line 1228, in check_last_manifest
> last_backup_set.check_manifests()
> File "/usr/lib64/python2.7/site-packages/duplicity/collections.py",
> line 208, in check_manifests
> remote_manifest = self.get_remote_manifest()
> File "/usr/lib64/python2.7/site-packages/duplicity/collections.py",
> line 249, in get_remote_manifest
> return manifest.Manifest().from_string(manifest_buffer)
> File "/usr/lib64/python2.7/site-packages/duplicity/manifest.py", line
> 201, in from_string
> for match in vi_iterator:
> MemoryError
>
> ** This bug is no longer a duplicate of bug 1720159
> Cannot allocate memory with large manifest file since 0.7.03
>
> --
> You received this bug notification because you are subscribed to
> duplicity in Ubuntu.
> https://bugs.launchpad.net/bugs/1730451
>
> Title:
> MemoryError while verifying backup
>
> Status in duplicity package in Ubuntu:
> New
>
> Bug description:
> While trying to verify a backup (launched from deja-dup), I receive
> the following error. My system currently shows 11G of RAM available
> plus 23G of swap. Possibly related to #1720159?
>
> Traceback (most recent call last):
> File "/usr/bin/duplicity", line 1546, in <module>
> with_tempdir(main)
> File "/usr/bin/duplicity", line 1540, in with_tempdir
> fn()
> File "/usr/bin/duplicity", line 1391, in main
> do_backup(action)
> File "/usr/bin/duplicity", line 1468, in do_backup
> restore(col_stats)
> File "/usr/bin/duplicity", line 731, in restore
> restore_get_patched_rop_iter(col_stats)):
> File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
> 560, in Write_ROPaths
> for ropath in rop_iter:
> File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
> 523, in integrate_patch_iters
> for patch_seq in collated:
> File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
> 389, in yield_tuples
> setrorps(overflow, elems)
> File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
> 378, in setrorps
> elems[i] = iter_list[i].next()
> File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
> 107, in filter_path_iter
> for path in path_iter:
> File "/usr/lib/python2.7/dist-packages/duplicity/patchdir.py", line
> ...

[Olivier Crête (olivier-crete)]

For some reason, a manually triggered backup from deja-dup worked this time, and it did an incremental backup. I'm not sure what changed, as it had failed multiple times today.

- When you upgraded to 0.7.15, did you remove the distro's version?

I use the distro's package (Fedora has 0.7.15)

- How much memory do you have? Is it the same as previous?

Yeah, I have 16 GB of RAM, so I doubt that's the problem.

- How long of an incremental change list do you have?

How do I get that?

- Have you tried making a full backup?

Making full backups works fine it seems, it's only incremental that's broken.

[Kenneth Loafman (kenneth-loafman)]

OK, sounds like the distro is keeping up. I like that.

One way to find out how many incrementals you have is "--collection-status", like so:

$ duplicity --collection-status <target-url>

and then counting the number of incrementals for the current backup. As a rule of thumb, you should have fewer that 30 incrementals before doing a full backup.

[Kenneth Loafman (kenneth-loafman)]

Also, would you please provide the duplicity command line for the incremental?

[Olivier Crête (olivier-crete)]

Found 0 secondary backup chains.

Found primary backup chain with matching signature chain:
-------------------------
Chain start time: Fri Jan 5 18:45:00 2018
Chain end time: Wed Jan 17 16:44:04 2018
Number of contained backup sets: 2
Total number of contained volumes: 1741
 Type of backup set: Time: Num volumes:
                Full Fri Jan 5 18:45:00 2018 1628
         Incremental Wed Jan 17 16:44:04 2018 113
-------------------------

[Kenneth Loafman (kenneth-loafman)]

Is this the backup causing the error reported?

If not, please run against that one.

[Olivier Crête (olivier-crete)]

I get the same error running against this one.

[Olivier Crête (olivier-crete)]

Here is a slightly different traceback

Traceback (innermost last):
  File "/usr/bin/duplicity", line 1559, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1545, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1394, in main
    do_backup(action)
  File "/usr/bin/duplicity", line 1420, in do_backup
    action).set_values()
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 720, in set_values
    self.get_backup_chains(partials + backend_filename_list)
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 846, in get_backup_chains
    add_to_sets(f)
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 834, in add_to_sets
    if set.add_filename(filename):
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 102, in add_filename
    self.set_manifest(filename)
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 153, in set_manifest
    self.set_files_changed()
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 129, in set_files_changed
    mf = self.get_manifest()
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 256, in get_manifest
    return self.get_local_manifest()
  File "/usr/lib64/python2.7/site-packages/duplicity/collections.py", line 234, in get_local_manifest
    return manifest.Manifest().from_string(manifest_buffer)
  File "/usr/lib64/python2.7/site-packages/duplicity/manifest.py", line 201, in from_string
    for match in vi_iterator:
 MemoryError

With the matching status after this failure:

Warning, found incomplete backup sets, probably left from aborted session
Last full backup date: Fri Jan 5 18:45:00 2018
Collection Status
-----------------
Connecting with backend: BackendWrapper
Archive dir: <redacted>
Found 0 secondary backup chains.

Found primary backup chain with matching signature chain:
-------------------------
Chain start time: Fri Jan 5 18:45:00 2018
Chain end time: Wed Jan 17 16:44:04 2018
Number of contained backup sets: 2
Total number of contained volumes: 1741
 Type of backup set: Time: Num volumes:
                Full Fri Jan 5 18:45:00 2018 1628
         Incremental Wed Jan 17 16:44:04 2018 113
-------------------------
Also found 0 backup sets not part of any chain,
and 1 incomplete backup set.
These may be deleted by running duplicity with the "cleanup" command.

[Kenneth Loafman (kenneth-loafman)]

- Please post the duplicity command line.

- Please do an 'ls -l' or equivalent of the backup target directory and add as an attachment to this bug report. (see green + at bottom of display).

[Olivier Crête (olivier-crete)]

Duplicity is run by deja-dup in my case:

 python2 /usr/bin/duplicity --exclude=/mnt/Backup/duplicity --include=/home/ocrete/.cache/deja-dup/metadata --exclude=/home/ocrete/.ccache --exclude=/home/ocrete/.cache --exclude=/home/ocrete/Videos --exclude=/home/ocrete/.local/share/Trash --exclude=/home/ocrete/.thumbnails --exclude=/home/ocrete/.steam/root --exclude=/home/ocrete/.gvfs --exclude=/home/ocrete/.ccache --exclude=/home/ocrete/.adobe/Flash_Player/AssetCache --exclude=/home/ocrete/.cache/deja-dup --exclude=/home/ocrete/.cache --include=/home/ocrete --exclude=/var/cache --exclude=/var/tmp --exclude=/sys --exclude=/run --exclude=/proc --exclude=/var/tmp --exclude=/tmp --exclude=** --dry-run --volsize=50 / gio+file:///mnt/Backup/duplicity --verbosity=9 --gpg-options=--no-use-agent --archive-dir=/home/ocrete/.cache/deja-dup --tempdir=/var/tmp --log-fd=17

[Olivier Crête (olivier-crete)]

Also, deja-dup seems to run the "cleanup" command when it tries to do a backup after failing. So this list is after the cleanup is done.

[Launchpad Janitor (janitor)]

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

[Launchpad Janitor (janitor)]

This bug was fixed in the package duplicity - 0.7.17-0ubuntu1

---------------
duplicity (0.7.17-0ubuntu1) bionic; urgency=medium

  * New upstream bug-fix release
    - Reverts a new feature that required too much memory, causing
      OOM crashes (LP: #1730451)

 -- Michael Terry <email address hidden> Tue, 13 Mar 2018 11:12:30 -0400

[Stefan Wolf (stefwolf)]

I received a pretty similar error and thought I'd share my workaround. It may be OT but people are bound to come across this bug when they google.

The process would look like the backup was working (and for < 200MB and a small number of files it did) - but larger folders would do up to 4 MemoryErrors before they would time out.

I received the error with the main version (I believe it was 0.7.12) as well as with a more recent version (0.7.18.2).

My workaround was that I would MOUNT the remote folder (with sshfs) before executing my backup against the mounted folder. The commands remained otherwise unchanged. I've since done a full 100GB backup with > 400K files successfully.

Former statement:
duplicity full --encrypt-key="XXX" /source/files scp://<email address hidden>/files

Working statement:
duplicity full --encrypt-key="XXX" /source/files file:///mnt/destination/files

Curious indeed.
Hope this helps anyone.