borg
borg copied to clipboard
borgbackup
Unable to backup using a pCloud drive as repository
Hello, I just started using Vorta and Borg and I had successfully tested backing up on an external USB disk. Since I have a lifetime plan on pCloud with 500GB available, I wanted to use some of this space to store a second copy of my backup. The backup started normally, but around 30% was interrupted with an error (see logs). I assumed I could use any mounted folder to store my files (regardless of the cloud being used), isn't this the case? Yeah, I'm aware there are native solutions like BorgBase (and I admit the price would be even reasonable), but I'm trying to understand if I can reuse the space I already have, before purchasing additional one.
Some additional info on my system:
OS MacOS 14.2.1
Version of Vorta 0.8.11
Version of Borg 1.2.6
Logs with error:
2023-12-22 11:04:34,700 - vorta.borg.borg_job - INFO - Initializing repository at "/Users/andrea/pCloud Drive/Backups/pCrypto"
2023-12-22 11:04:34,733 - vorta.borg.borg_job - WARNING - Failed to securely erase old repository config file (hardlinks not supported). Old repokey data, if any, might persist on physical storage.
2023-12-22 11:04:34,751 - vorta.borg.borg_job - INFO - Key in "<Repository /Users/andrea/pCloud Drive/Backups/pCrypto>" created.
2023-12-22 11:04:34,753 - vorta.borg.borg_job - INFO - Keep this key safe. Your data will be inaccessible without it.
2023-12-22 11:04:34,813 - vorta.borg.borg_job - INFO - Synchronizing chunks cache...
2023-12-22 11:04:34,813 - vorta.borg.borg_job - INFO - Archives: 0, w/ cached Idx: 0, w/ outdated Idx: 0, w/o cached Idx: 0.
2023-12-22 11:04:34,822 - vorta.borg.borg_job - INFO - Done.
2023-12-22 11:04:34,825 - vorta.borg.borg_job - WARNING -
By default repositories initialized with this version will produce security
errors if written to with an older version (up to and including Borg 1.0.8).
If you want to use these older versions, you can disable the check by running:
borg upgrade --disable-tam '/Users/andrea/pCloud Drive/Backups/pCrypto'
See https://borgbackup.readthedocs.io/en/stable/changes.html#pre-1-0-9-manifest-spoofing-vulnerability for details about the security implications.
2023-12-22 11:04:34,825 - vorta.borg.borg_job - WARNING -
IMPORTANT: you will need both KEY AND PASSPHRASE to access this repo!
If you used a repokey mode, the key is stored in the repo, but you should back it up separately.
Use "borg key export" to export the key, optionally in printable format.
Write down the passphrase. Store both at safe place(s).
2023-12-22 11:04:34,962 - vorta.keyring.darwin - DEBUG - Saved password for repo /Users/andrea/pCloud Drive/Backups/pCrypto
2023-12-22 11:04:34,962 - vorta.borg.jobs_manager - DEBUG - Finish job for site: default
2023-12-22 11:04:34,963 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: default
2023-12-22 11:04:35,182 - vorta.keyring.abc - DEBUG - No module named 'secretstorage'
2023-12-22 11:04:35,182 - vorta.keyring.abc - DEBUG - Using VortaDarwinKeyring
2023-12-22 11:04:35,182 - vorta.borg.borg_job - DEBUG - Using VortaDarwinKeyring keyring to store passwords.
2023-12-22 11:04:35,185 - vorta.keyring.darwin - DEBUG - Retrieved password for repo /Users/andrea/pCloud Drive/Backups/pCrypto
2023-12-22 11:04:35,191 - vorta.borg.jobs_manager - DEBUG - Add job for site 2
2023-12-22 11:04:35,191 - vorta.borg.jobs_manager - DEBUG - Start job on site: 2
2023-12-22 11:04:35,222 - vorta.borg.borg_job - INFO - Running command /opt/homebrew/bin/borg list --info --log-json --json /Users/andrea/pCloud Drive/Backups/pCrypto
2023-12-22 11:04:35,664 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 2
2023-12-22 11:04:35,665 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 2
2023-12-22 11:04:35,665 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2023-12-22 11:04:53,138 - vorta.views.source_tab - DEBUG - Added item number 0 from 1
2023-12-22 11:04:53,139 - vorta.views.source_tab - DEBUG - Updating source in row 0.
2023-12-22 11:04:53,139 - vorta.views.source_tab - DEBUG - Updated info for previously added item.
2023-12-22 11:05:31,672 - vorta.keyring.abc - DEBUG - No module named 'secretstorage'
2023-12-22 11:05:31,672 - vorta.keyring.abc - DEBUG - Using VortaDarwinKeyring
2023-12-22 11:05:31,672 - vorta.borg.borg_job - DEBUG - Using VortaDarwinKeyring keyring to store passwords.
2023-12-22 11:05:31,674 - vorta.keyring.darwin - DEBUG - Retrieved password for repo /Users/andrea/pCloud Drive/Backups/pCrypto
2023-12-22 11:05:31,710 - vorta.borg.jobs_manager - DEBUG - Add job for site 2
2023-12-22 11:05:31,710 - vorta.borg.jobs_manager - DEBUG - Start job on site: 2
2023-12-22 11:05:31,711 - vorta.borg.borg_job - INFO - Running command /opt/homebrew/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 /Users/andrea/pCloud Drive/Backups/pCrypto::Andreas-MacBook-Pro-M2.local-2023-12-22-110531 /Users/andrea/pCrypto
2023-12-22 11:05:31,891 - vorta.borg.borg_job - INFO - Creating archive at "/Users/andrea/pCloud Drive/Backups/pCrypto::Andreas-MacBook-Pro-M2.local-2023-12-22-110531"
2023-12-22 11:06:19,432 - vorta.borg.borg_job - WARNING - Exception ignored in: <function Repository.__del__ at 0x1058f4180>
2023-12-22 11:06:19,433 - vorta.borg.borg_job - WARNING - Traceback (most recent call last):
2023-12-22 11:06:19,433 - vorta.borg.borg_job - WARNING - File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/repository.py", line 189, in __del__
2023-12-22 11:06:19,433 - vorta.borg.borg_job - WARNING - self.close()
2023-12-22 11:06:19,433 - vorta.borg.borg_job - WARNING - File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/repository.py", line 478, in close
2023-12-22 11:06:19,433 - vorta.borg.borg_job - WARNING - self.lock.release()
2023-12-22 11:06:19,434 - vorta.borg.borg_job - WARNING - File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/locking.py", line 417, in release
2023-12-22 11:06:19,434 - vorta.borg.borg_job - WARNING - self._roster.modify(EXCLUSIVE, REMOVE)
2023-12-22 11:06:19,434 - vorta.borg.borg_job - WARNING - File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/locking.py", line 316, in modify
2023-12-22 11:06:19,434 - vorta.borg.borg_job - WARNING - elements.remove(self.id)
2023-12-22 11:06:19,434 - vorta.borg.borg_job - WARNING - KeyError: ('andreas-macbook-pro-m2.local@169661970087823', 10214, 0)
2023-12-22 11:06:19,435 - vorta.borg.borg_job - ERROR - Failed to release the lock /Users/andrea/pCloud Drive/Backups/pCrypto/lock.exclusive (was not locked).
2023-12-22 11:06:19,435 - vorta.borg.borg_job - ERROR - Traceback (most recent call last):
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 183, in wrapper
return method(self, args, repository=repository, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 664, in do_create
create_inner(archive, cache, fso)
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 597, in create_inner
self._rec_walk(path=path, parent_fd=None, name=None,
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 812, in _rec_walk
self._rec_walk(
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 812, in _rec_walk
self._rec_walk(
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 812, in _rec_walk
self._rec_walk(
[Previous line repeated 2 more times]
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 775, in _rec_walk
status = self._process_any(path=path, parent_fd=parent_fd, name=name, st=st, fso=fso, cache=cache,
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 677, in _process_any
return fso.process_file(path=path, parent_fd=parent_fd, name=name, st=st, cache=cache)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archive.py", line 1455, in process_file
self.process_file_chunks(item, cache, self.stats, self.show_progress, backup_io_iter(self.chunker.chunkify(None, fd)))
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archive.py", line 1277, in process_file_chunks
item.chunks.append(chunk_processor(chunk))
^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archive.py", line 1265, in chunk_processor
chunk_entry = cache.add_chunk(chunk_id, data, stats, wait=False)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/cache.py", line 950, in add_chunk
data = self.key.encrypt(chunk)
^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/crypto/key.py", line 442, in encrypt
next_iv = self.nonce_manager.ensure_reservation(self.cipher.next_iv(),
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/crypto/nonces.py", line 79, in ensure_reservation
repo_free_nonce = self.get_repo_free_nonce()
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/crypto/nonces.py", line 38, in get_repo_free_nonce
return self.repository.get_free_nonce()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/repository.py", line 347, in get_free_nonce
raise AssertionError("bug in code, exclusive lock should exist here")
AssertionError: bug in code, exclusive lock should exist here
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 5324, in main
exit_code = archiver.run(args)
^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 5255, in run
return set_ec(func(args))
^^^^^^^^^^
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/archiver.py", line 168, in wrapper
with repository:
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/repository.py", line 214, in __exit__
self.close()
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/repository.py", line 478, in close
self.lock.release()
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/locking.py", line 420, in release
self._lock.release()
File "/opt/homebrew/Cellar/borgbackup-fuse/1.2.6/libexec/lib/python3.11/site-packages/borg/locking.py", line 167, in release
raise NotLocked(self.path)
borg.locking.NotLocked: Failed to release the lock /Users/andrea/pCloud Drive/Backups/pCrypto/lock.exclusive (was not locked).
Platform: Darwin Andreas-MacBook-Pro-M2.local 23.2.0 Darwin Kernel Version 23.2.0: Wed Nov 15 21:55:06 PST 2023; root:xnu-10002.61.3~2/RELEASE_ARM64_T6020 arm64
Borg: 1.2.6 Python: CPython 3.11.6 msgpack: 1.0.5 fuse: llfuse 1.5.0 [pyfuse3,llfuse]
PID: 10214 CWD: /
sys.argv: ['/opt/homebrew/bin/borg', 'create', '--list', '--progress', '--info', '--log-json', '--json', '--filter=AM', '-C', 'lz4', '/Users/andrea/pCloud Drive/Backups/pCrypto::Andreas-MacBook-Pro-M2.local-2023-12-22-110531', '/Users/andrea/pCrypto']
SSH_ORIGINAL_COMMAND: None
2023-12-22 11:06:19,551 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 2
2023-12-22 11:06:19,552 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 2
2023-12-22 11:06:19,552 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
2023-12-22 11:13:57,419 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2023-12-22 11:13:57,423 - vorta.scheduler - INFO - Setting timer for profile 1
2023-12-22 11:13:57,426 - vorta.scheduler - DEBUG - Scheduling next run for 2023-12-23 00:00:00
2023-12-22 11:13:57,429 - vorta.scheduler - DEBUG - Scheduler for profile 2 is disabled.
Thanks for your help 🙏
Looks like the pCloud drive filesystem you use is misbehaved (like not POSIX compliant or having other consistency or behavioural issues) and triggers that assertion.
Looks like the pCloud drive filesystem you use is misbehaved (like not POSIX compliant or having other consistency or behavioural issues) and triggers that assertion.
Thanks Thomas. Being closed source we can only guess if it's POSIX compliant, but one thing I know is that it uses FUSE (it installs it too as requirement).
I'm wondering if this is a pCloud client issue or if it's a more generic FUSE limitation (ie: would another cloud space based on FUSE work?).
In the next days I will try to experiment with a repository stored on iCloud Disk, to see if it has the same problem.
Thanks
Maybe check if pCloud drive has some (debug) log and whether there are some warning or error messages logged in there.
I was curious and just signed up for pCloud trial. Let's see what i find...
BTW, they are using macFUSE, that is the same FUSE implementation as borg mount uses (but of course they use their own code on top of that to implement pCloud drive, while borg uses its own code to implement borgfs).
Could be a race condition:
- I directly used borg (no vorta), using 1.2-maint latest code
- my first two test backups to pCloud worked
- my 3rd test backup (nothing changed) also gave that
NotLockedexception as you have posted above
Did some more test backups, then this happened, different exception with IOError:
Exception ignored in: <function Repository.__del__ at 0x1036e9800>
Traceback (most recent call last):
File "/Users/tw/w/borg/src/borg/repository.py", line 192, in __del__
self.close()
File "/Users/tw/w/borg/src/borg/repository.py", line 481, in close
self.lock.release()
File "/Users/tw/w/borg/src/borg/locking.py", line 425, in release
self._lock.release()
File "/Users/tw/w/borg/src/borg/locking.py", line 167, in release
raise NotLocked(self.path)
borg.locking.NotLocked: Failed to release the lock /Users/tw/pCloud Drive/borg12-test-repo/lock.exclusive (was not locked).
Local Exception
Traceback (most recent call last):
File "/Users/tw/w/borg/src/borg/archiver.py", line 5343, in main
exit_code = archiver.run(args)
^^^^^^^^^^^^^^^^^^
File "/Users/tw/w/borg/src/borg/archiver.py", line 5263, in run
return set_ec(func(args))
^^^^^^^^^^
File "/Users/tw/w/borg/src/borg/archiver.py", line 174, in wrapper
with repository:
File "/Users/tw/w/borg/src/borg/repository.py", line 217, in __exit__
self.close()
File "/Users/tw/w/borg/src/borg/repository.py", line 481, in close
self.lock.release()
File "/Users/tw/w/borg/src/borg/locking.py", line 425, in release
self._lock.release()
File "/Users/tw/w/borg/src/borg/locking.py", line 176, in release
raise err
File "/Users/tw/w/borg/src/borg/locking.py", line 172, in release
os.rmdir(self.path)
OSError: [Errno 5] Input/output error: '/Users/tw/pCloud Drive/borg12-test-repo/lock.exclusive'
Platform: Darwin mba2020.local 23.2.0 Darwin Kernel Version 23.2.0: Wed Nov 15 21:53:34 PST 2023; root:xnu-10002.61.3~2/RELEASE_ARM64_T8103 arm64
Borg: 1.2.8.dev5+ga714f77c Python: CPython 3.11.6 msgpack: 1.0.7 fuse: llfuse 1.5.0 [pyfuse3,llfuse]
PID: 3261 CWD: /Users/tw/w/borg
sys.argv: ['/Users/tw/w/borg-env/bin/borg', 'create', '--list', '::archive-{now}', './src']
SSH_ORIGINAL_COMMAND: None
IOError definitely points at a low level problem in the (repo) storage filesystem, here: on pCloud drive.
Guess pCloud is doing strange things internally.
IIRC, borg does not create lock.exclusive directories suffixed by (1) or (2) (notable is also the inconsistency of the latter having an additional space).
tw@mba2020 pCloud Drive % ls -l borg12-test-repo
total 280
-rw-r--r-- 1 tw staff 73 Dec 24 15:21 README
-rw-r--r-- 1 tw staff 700 Dec 24 15:21 config
drwxr-xr-x 3 tw staff 4096 Dec 24 15:21 data
-rw-r--r-- 1 tw staff 65199 Dec 24 15:31 hints.141
-rw-r--r-- 1 tw staff 41258 Dec 24 15:31 index.141
-rw-r--r-- 1 tw staff 190 Dec 24 15:31 integrity.141
drwxr-xr-x 2 tw staff 4096 Dec 24 15:31 lock.exclusive (2)
drwxr-xr-x 2 tw staff 4096 Dec 24 15:27 lock.exclusive(1)
-rw-r--r-- 1 tw staff 58 Dec 24 15:31 lock.roster
-rw-r--r-- 1 tw staff 16 Dec 24 15:31 nonce
borg check noted:
Failed to securely erase old repository config file (hardlinks not supported). Old repokey data, if any, might persist on physical storage.
Hardlinks unsupported: no big surprise, but also no big problem, this is just a warning, not an error.
Looks like pCloud drive has troubles with rmdir of the lock directory (when borg releases the lock).
I tried adding a sleep for 10s before the rmdir, but it didn't help
After playing around a while with it, I don't think you can use that as a reliable repo storage for borg, at least not as pCloud drive is implemented now:
- I found all repo files borg deletes still living on in the pCloud Trash (still taking up space): lock dirs / files, deleted segment files, etc.. When
borg compactruns, that would lead to a significant increase in cloud storage use, as it will delete non-compact segment files after writing their contents to new segment files. In case of pCloud the delete will not free space because pCloud chooses to move the files to the trash and keep them. - It showed the "syncing" icon in the finder view of
repo/datafor some segment files long after borg has terminated. Also it seemed to be unordered what was synced and what not. borg does misc.os.fsync,os.fdatasyncon the files and directories to make sure stuff is actually written (in correct order), but for pCloud drive that might be only true for the local cache, but obviously not for the "it is uploaded to the cloud" state. - The web view and the macOS finder view gave inconsistent results of the pCloud drive folder contents.
- After a playing around a while, it stopped working for me. I now have 5.37GB "locked" and 5GB "free" after deleting all my borg experiments. And it shows > 10GB cloud storage for me, but I guess I only have 5GB in the free account!? Not sure what "locked" means.
- At the end, I found the debug log activation in pcloud drive app settings. But I could not reproduce the crashes after activating that, maybe because it somehow internally already was in a weird state.
Looks like pCloud drive has troubles with
rmdirof the lock directory (when borg releases the lock).I tried adding a sleep for 10s before the rmdir, but it didn't help
I'm far away from my laptop at the moment so I can't do any tests right now, but I remember another strange pCloud behaviour related to file deletion. The other day, after I finished doing my tests, I was trying to delete che Backups folder inside pCloud, I deleted it from MacOS File manager and pCloud was re-creating the folder again and again (just like it was syncing down from the Backups folder available in cloud). To finally delete it, I had to open the web version of pCloud and delete it from there.
If this is a pCloud bug, my guess is that the .lock file was being synced up/down quickly to/from cloud, resulting in not being deleted.
One thing I could do, is to exclude *.lock file from being synced in pCloud.
Update: or maybe I should exclude "lock.exclusive" or whatever its name is
I start thinking that maybe pCloud isn't that reliable in general, to keep my files safe, not just as Borg repository.
Context: I'm currently using pCloud to store the encrypted files of a Cryptomator volume. The reason I started using Borg is because I didn't 100% trust Cryptomator and in case it corrupted something, I wanted to have a backup copy (I'm currently backing up the mounted/unencrypted volume from Cryptomator).
All these weird behaviours make me think pCloud could be the point of failure.
Why I'm using it? Because I purchased a lifetime account a few years ago 😓
Maybe I should just buy more space on iCloud and use it instead.
I never tested borg with iCloud, so better first try if that is more reliable. Often such cloud filesystems are less reliable and somehow misbehaved.
On https://borgbackup.org/ we list some borg storage providers.
I never tested borg with iCloud, so better first try if that is more reliable. Often such cloud filesystems are less reliable and somehow misbehaved.
On https://borgbackup.org/ we list some borg storage providers.
Thanks, I think I will be using BorgBase (which from my earlier tests it seemed to be nice and reliable) for the backup.
Will keep this open for a while, maybe interesting for other users and also I want to retry later (if/when my pcloud drive "recovered").
Having the same issues with pCloud. Ended up migrating to borgbase as it's cheaper and I don't need the storage for anything else. Not the most helpful comment I know but I was struggling for about two days trying to solve the locking issues.
@aaaronlucas thanks for the feedback.
I am closing this now as it is not a borg issue, but likely the fs implemented by pcloud does not work reliably enough for borg.
This may change over time of course, so if in future somebody finds this ticket AND pcloud fs worked reliably for them with borg, please leave some feedback below.