B2 backend doesn't work with latest version of 'b2'

Bug #1785520 reported by Chris Hunt
18
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Duplicity
Fix Released
Medium
Unassigned

Bug Description

Duplicity version: 0.7.12
Python version: 2.7.12
OS Distro and version: Ubuntu 16.04
Type of target filesystem: Linux
Log output:
# duplicity --verbosity debug --archive-dir /cache /backup b2://$B2_APP_KEY_ID:$B2_APP_KEY@pc-backup

Backing up to b2://$B2_APP_KEY_ID:$B2_APP_KEY@pc-backup
Using archive dir: /cache/f2c3af886cbcb461a5cb4c2bb05baf87
Using backup name: f2c3af886cbcb461a5cb4c2bb05baf87
GPG binary is gpg, version 1.4.20
Import of duplicity.backends.acdclibackend Succeeded
Import of duplicity.backends.azurebackend Succeeded
Import of duplicity.backends.b2backend Succeeded
Import of duplicity.backends.botobackend Succeeded
Import of duplicity.backends.cfbackend Succeeded
Import of duplicity.backends.dpbxbackend Failed: No module named dropbox
Import of duplicity.backends.gdocsbackend Succeeded
Import of duplicity.backends.giobackend Succeeded
Import of duplicity.backends.hsibackend Succeeded
Import of duplicity.backends.hubicbackend Succeeded
Import of duplicity.backends.imapbackend Succeeded
Import of duplicity.backends.lftpbackend Succeeded
Import of duplicity.backends.localbackend Succeeded
Import of duplicity.backends.mediafirebackend Succeeded
Import of duplicity.backends.megabackend Succeeded
Import of duplicity.backends.multibackend Succeeded
Import of duplicity.backends.ncftpbackend Succeeded
Import of duplicity.backends.onedrivebackend Succeeded
Import of duplicity.backends.par2backend Succeeded
Import of duplicity.backends.pydrivebackend Succeeded
Import of duplicity.backends.rsyncbackend Succeeded
Import of duplicity.backends.ssh_paramiko_backend Succeeded
Import of duplicity.backends.ssh_pexpect_backend Succeeded
Import of duplicity.backends.swiftbackend Succeeded
Import of duplicity.backends.sxbackend Succeeded
Import of duplicity.backends.tahoebackend Succeeded
Import of duplicity.backends.webdavbackend Succeeded
B2 Backend (path= , bucket= pc-backup, minimum_part_size= 100000000)
Bucket found
Main action: inc
Acquiring lockfile /cache/f2c3af886cbcb461a5cb4c2bb05baf87/lockfile
================================================================================
duplicity 0.7.17 (February 26, 2018)
Args: /usr/local/bin/duplicity --verbosity debug --archive-dir /cache /backup b2://$B2_APP_KEY_ID:$B2_APP_KEY@pc-backup
Linux backup 4.15.2-041502-generic #201802072230 SMP Wed Feb 7 22:32:02 UTC 2018 x86_64 x86_64
/usr/bin/python2 2.7.12 (default, Dec 4 2017, 14:50:18)
[GCC 5.4.0 20160609]
================================================================================
Using temporary directory /tmp/duplicity-3WCPKp-tempdir
Registering (mkstemp) temporary file /tmp/duplicity-3WCPKp-tempdir/mkstemp-C3rqZA-1
Temp has 1000001536 available, backup will use approx 272629760.
Local and Remote metadata are synchronized, no sync needed.
6 files exist on backend
5 files exist in cache
Extracting backup chains from list of files: [u'duplicity-full-signatures.20180805T203349Z.sigtar.gpg', u'duplicity-full.20180805T203349Z.manifest.gpg', u'duplicity-full.20180805T203349Z.vol1.difftar.gpg', u'duplicity-inc.20180805T203349Z.to.20180805T203414Z.manifest.gpg', u'duplicity-inc.20180805T203349Z.to.20180805T203414Z.vol1.difftar.gpg', u'duplicity-new-signatures.20180805T203349Z.to.20180805T203414Z.sigtar.gpg']
File duplicity-full-signatures.20180805T203349Z.sigtar.gpg is not part of a known set; creating new set
Ignoring file (rejected by backup set) 'duplicity-full-signatures.20180805T203349Z.sigtar.gpg'
File duplicity-full.20180805T203349Z.manifest.gpg is not part of a known set; creating new set
File duplicity-full.20180805T203349Z.vol1.difftar.gpg is part of known set
File duplicity-inc.20180805T203349Z.to.20180805T203414Z.manifest.gpg is not part of a known set; creating new set
File duplicity-inc.20180805T203349Z.to.20180805T203414Z.vol1.difftar.gpg is part of known set
File duplicity-new-signatures.20180805T203349Z.to.20180805T203414Z.sigtar.gpg is not part of a known set; creating new set
Ignoring file (rejected by backup set) 'duplicity-new-signatures.20180805T203349Z.to.20180805T203414Z.sigtar.gpg'
Found backup chain [Sun Aug 5 20:33:49 2018]-[Sun Aug 5 20:33:49 2018]
Added incremental Backupset (start_time: Sun Aug 5 20:33:49 2018 / end_time: Sun Aug 5 20:34:14 2018)
Added set Sun Aug 5 20:34:14 2018 to pre-existing chain [Sun Aug 5 20:33:49 2018]-[Sun Aug 5 20:34:14 2018]
Last full backup date: Sun Aug 5 20:33:49 2018
Collection Status
-----------------
Connecting with backend: BackendWrapper
Archive dir: /cache/f2c3af886cbcb461a5cb4c2bb05baf87

Found 0 secondary backup chains.

Found primary backup chain with matching signature chain:
-------------------------
Chain start time: Sun Aug 5 20:33:49 2018
Chain end time: Sun Aug 5 20:34:14 2018
Number of contained backup sets: 2
Total number of contained volumes: 2
 Type of backup set: Time: Num volumes:
                Full Sun Aug 5 20:33:49 2018 1
         Incremental Sun Aug 5 20:34:14 2018 1
-------------------------
No orphaned or incomplete backup sets found.
Registering (mktemp) temporary file /tmp/duplicity-3WCPKp-tempdir/mktemp-9Oy7dc-2
Get: duplicity-inc.20180805T203349Z.to.20180805T203414Z.manifest.gpg -> /tmp/duplicity-3WCPKp-tempdir/mktemp-9Oy7dc-2
Deleting /tmp/duplicity-3WCPKp-tempdir/mktemp-9Oy7dc-2
Forgetting temporary file /tmp/duplicity-3WCPKp-tempdir/mktemp-9Oy7dc-2
Processing remote manifest duplicity-inc.20180805T203349Z.to.20180805T203414Z.manifest.gpg (155)
Found manifest volume 1
Found 1 volumes in manifest
Processing local manifest /cache/f2c3af886cbcb461a5cb4c2bb05baf87/duplicity-inc.20180805T203349Z.to.20180805T203414Z.manifest (155)
Found manifest volume 1
Found 1 volumes in manifest
Using temporary directory /cache/f2c3af886cbcb461a5cb4c2bb05baf87/duplicity-Y5WMYF-tempdir
Registering (mktemp) temporary file /cache/f2c3af886cbcb461a5cb4c2bb05baf87/duplicity-Y5WMYF-tempdir/mktemp-opfM7X-1
Using temporary directory /cache/f2c3af886cbcb461a5cb4c2bb05baf87/duplicity-C60a2D-tempdir
Registering (mktemp) temporary file /cache/f2c3af886cbcb461a5cb4c2bb05baf87/duplicity-C60a2D-tempdir/mktemp-o64nb2-1
AsyncScheduler: instantiating at concurrency 0
Registering (mktemp) temporary file /tmp/duplicity-3WCPKp-tempdir/mktemp-UpFna2-3
Selecting /backup
Comparing . and .
Selection: examining path /backup/backup-20171111142945.log
Selection: + no selection functions found. Including
Selecting /backup/backup-20171111142945.log
Comparing backup-20171111142945.log and backup-20171111142945.log
Selection: examining path /backup/backup.20171119134933.log
Selection: + no selection functions found. Including
Selecting /backup/backup.20171119134933.log
Comparing backup.20171119134933.log and backup.20171119134933.log
Selection: examining path /backup/backup.20171119134939.log
Selection: + no selection functions found. Including
Selecting /backup/backup.20171119134939.log
Comparing backup.20171119134939.log and backup.20171119134939.log
Selection: examining path /backup/backup.20171119140544.log
Selection: + no selection functions found. Including
Selecting /backup/backup.20171119140544.log
Comparing backup.20171119140544.log and backup.20171119140544.log
Selection: examining path /backup/backup.20171119140620.log
Selection: + no selection functions found. Including
Selecting /backup/backup.20171119140620.log
Comparing backup.20171119140620.log and backup.20171119140620.log
Selection: examining path /backup/backup.20171119143650.log
Selection: + no selection functions found. Including
Selecting /backup/backup.20171119143650.log
Comparing backup.20171119143650.log and backup.20171119143650.log
Selection: examining path /backup/backup.20171119151319.log
Selection: + no selection functions found. Including
Selecting /backup/backup.20171119151319.log
Comparing backup.20171119151319.log and backup.20171119151319.log
Selection: examining path /backup/foo
Selection: + no selection functions found. Including
Selecting /backup/foo
Comparing foo and foo
Removing still remembered temporary file /cache/f2c3af886cbcb461a5cb4c2bb05baf87/duplicity-Y5WMYF-tempdir/mktemp-opfM7X-1
Removing still remembered temporary file /cache/f2c3af886cbcb461a5cb4c2bb05baf87/duplicity-C60a2D-tempdir/mktemp-o64nb2-1
AsyncScheduler: running task synchronously (asynchronicity disabled)
Writing duplicity-inc.20180805T203414Z.to.20180805T204023Z.vol1.difftar.gpg
Put: /tmp/duplicity-3WCPKp-tempdir/mktemp-UpFna2-3 -> duplicity-inc.20180805T203414Z.to.20180805T204023Z.vol1.difftar.gpg
Backtrace of previous error: Traceback (innermost last):
  File "/usr/local/lib/python2.7/dist-packages/duplicity/backend.py", line 369, in inner_retry
    return fn(self, *args)
  File "/usr/local/lib/python2.7/dist-packages/duplicity/backend.py", line 529, in put
    self.__do_put(source_path, remote_filename)
  File "/usr/local/lib/python2.7/dist-packages/duplicity/backend.py", line 515, in __do_put
    self.backend._put(source_path, remote_filename)
  File "/usr/local/lib/python2.7/dist-packages/duplicity/backends/b2backend.py", line 111, in _put
    progress_listener=B2ProgressListener())
  File "/usr/local/lib/python2.7/dist-packages/logfury/v0_1/trace_call.py", line 84, in wrapper
    return function(*wrapee_args, **wrapee_kwargs)
  File "/usr/local/lib/python2.7/dist-packages/b2/bucket.py", line 342, in upload_local_file
    progress_listener=progress_listener
  File "/usr/local/lib/python2.7/dist-packages/logfury/v0_1/trace_call.py", line 84, in wrapper
    return function(*wrapee_args, **wrapee_kwargs)
  File "/usr/local/lib/python2.7/dist-packages/b2/bucket.py", line 390, in upload
    return f.result()
  File "/usr/local/lib/python2.7/dist-packages/concurrent/futures/_base.py", line 455, in result
    return self.__get_result()
  File "/usr/local/lib/python2.7/dist-packages/concurrent/futures/thread.py", line 63, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/local/lib/python2.7/dist-packages/b2/bucket.py", line 403, in _upload_small_file
    with progress_listener:
 AttributeError: B2ProgressListener instance has no attribute '__exit__'

Attempt 1 failed. AttributeError: B2ProgressListener instance has no attribute '__exit__'

I received the error above then trying to use duplicity with b2 from master (https://github.com/Backblaze/B2_Command_Line_Tool/commit/46f0ce8a721e9b12382ce774ce6985e56bc7c253 at the time of writing). It looks like commit 653736d1 from 2018-08-01 uses the progress listener provided to bucket.upload as a context manager, which is not implemented by the B2ProgressListener defined in backends/b2backend.py.

Per the b2 code, objects passed to upload should adhere to b2.progress.AbstractProgressListener (https://github.com/Backblaze/B2_Command_Line_Tool/blob/653736d1ec1161360789f7785c5d15af122fbc3f/b2/progress.py#L31) which has for 2 years had __enter__ and __exit__ methods, so I wouldn't consider this a regression with b2 necessarily.

I have attached a patch that fixes the issue.

Tags: b2
Revision history for this message
Chris Hunt (chrahunt) wrote :
Revision history for this message
Kenneth Loafman (kenneth-loafman) wrote :

Is this backwards compatible with previous B2 releases, i.e. pip, repo?

Revision history for this message
Chris Hunt (chrahunt) wrote :

Yes, I tested with all versions from 0.6.8 (2016-10-14) to present (skipping 1.3.2 due to a bug reported here: https://github.com/Backblaze/B2_Command_Line_Tool/issues/485) using the following:

```
#!/bin/sh

set -e

B2_BUCKET_NAME=${B2_BUCKET_NAME:-}
B2_CREDENTIALS_PATH=${B2_CREDENTIALS_PATH:-/container/b2_credentials}
B2_ACCOUNT_ID=$(cat "$B2_CREDENTIALS_PATH" | cut -d' ' -f1)
B2_APPLICATION_KEY=$(cat "$B2_CREDENTIALS_PATH" | cut -d' ' -f2)

urlencode() {
    printf "%s" "$1" | python -c '
import sys
import urllib
print(urllib.quote_plus(sys.stdin.read()))
'
}

export PASSPHRASE='hello world'
# url encoded
account_id=$(urlencode "$B2_ACCOUNT_ID")
application_key=$(urlencode "$B2_APPLICATION_KEY")
bucket_url="b2://$account_id:$application_key@$B2_BUCKET_NAME"
echo "Backing up to $bucket_url"
#echo "Duplicity version: $(duplicity --version)"
echo "b2 version: $(b2 version)"
# Starting backup
duplicity \
    --verbosity debug \
    --archive-dir /cache \
    /backup \
    "$bucket_url"
```

You can see the logs attached.

Revision history for this message
Chris Hunt (chrahunt) wrote :

Also please note that b2 version 1.3.4 released yesterday does contain the changes mentioned, so it is incompatible with the current version of duplicity (0.7.17).

Revision history for this message
Kenneth Loafman (kenneth-loafman) wrote :

Thanks for the patch. Will get it done.

Changed in duplicity:
status: New → In Progress
importance: Undecided → Medium
assignee: nobody → Kenneth Loafman (kenneth-loafman)
milestone: none → 0.7.18
Changed in duplicity:
status: In Progress → Fix Committed
assignee: Kenneth Loafman (kenneth-loafman) → nobody
Changed in duplicity:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Bug attachments

Remote bug watches

Bug watches keep track of this bug in other bug trackers.