Repository: borgbackup/borg

Issue:
Non fatal bug in removing lock after archive creation
Hi,

I run borg 1.2.6 like this:

`borg create --verbose --filter AME --list --stats --show-rc --compression auto,lzma,6 --noflags --noacls --noxattrs --exclude-caches "::${BORG_BACKUP_NAME_PREFIX}$(date '+%Y-%m-%d_%H-%M-%S')" "${BORG_BACKUP_SOURCE}" --exclude-from "${BORG_BACKUP_EXCLUDE_LIST}"`
(with BORG_REPO and BORG_PASSPHRASE set in environment)

and after most backups I get this non fatal exception and rc 2:

```
------------------------------------------------------------------------------
Repository: [snip]
Archive name: [snip]-2023-11-14_21-21-07
Archive fingerprint: [snip]
Time (start): Tue, 2023-11-14 21:21:08
Time (end):   Tue, 2023-11-14 21:22:01
Duration: 53.10 seconds
Number of files: 552009
Utilization of max. archive size: 0%
------------------------------------------------------------------------------
                       Original size      Compressed size    Deduplicated size
This archive:               31.26 GB             19.19 GB            451.76 kB
All archives:               29.34 TB             26.86 TB            772.90 GB

                       Unique chunks         Total chunks
Chunk index:                 1196589             38684220
------------------------------------------------------------------------------
Exception ignored in: <function Repository.__del__ at 0x7f9f2378a020>
Traceback (most recent call last):
  File "/usr/lib64/python3.11/site-packages/borg/repository.py", line 189, in __del__
    self.close()
  File "/usr/lib64/python3.11/site-packages/borg/repository.py", line 478, in close
    self.lock.release()
  File "/usr/lib64/python3.11/site-packages/borg/locking.py", line 417, in release
    self._roster.modify(EXCLUSIVE, REMOVE)
  File "/usr/lib64/python3.11/site-packages/borg/locking.py", line 316, in modify
    elements.remove(self.id)
KeyError: ('[snip]@141812767217169', 565630, 0)
Local Exception
OSError: [Errno 95] Operation not supported

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib64/python3.11/site-packages/borg/archiver.py", line 5324, in main
    exit_code = archiver.run(args)
                ^^^^^^^^^^^^^^^^^^
  File "/usr/lib64/python3.11/site-packages/borg/archiver.py", line 5255, in run
    return set_ec(func(args))
                  ^^^^^^^^^^
  File "/usr/lib64/python3.11/site-packages/borg/archiver.py", line 168, in wrapper
    with repository:
  File "/usr/lib64/python3.11/site-packages/borg/repository.py", line 214, in __exit__
    self.close()
  File "/usr/lib64/python3.11/site-packages/borg/repository.py", line 478, in close
    self.lock.release()
  File "/usr/lib64/python3.11/site-packages/borg/locking.py", line 417, in release
    self._roster.modify(EXCLUSIVE, REMOVE)
  File "/usr/lib64/python3.11/site-packages/borg/locking.py", line 320, in modify
    self.save(roster)
  File "/usr/lib64/python3.11/site-packages/borg/locking.py", line 291, in save
    with open(self.path, "w") as f:
OSError: [Errno 95] Operation not supported

Platform: Linux [snip] 6.5.10-200.fc38.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Nov  2 19:59:55 UTC 2023 x86_64
Linux: Unknown Linux  
Borg: 1.2.6  Python: CPython 3.11.6 msgpack: 1.0.4 fuse: llfuse 1.4.2 [pyfuse3,llfuse]
PID: 565630  CWD: /home/[snip]
sys.argv: ['/usr/bin/borg', 'create', '--verbose', '--filter', 'AME', '--list', '--stats', '--show-rc', '--compression', 'auto,lzma,6', '--noflags', '--noacls', '--noxattrs', '--exclude-caches', '::[snip]-2023-11-14_21-21-07', '/home/[snip]', '--exclude-from', '/home/[snip]']
SSH_ORIGINAL_COMMAND: None

terminating with error status, rc 2
```

after some local messing around with the borg python files I found that the lock here gets "removed" twice:
https://github.com/borgbackup/borg/blob/2cefe8f53db4a9e0cdd1eeff1b06ebdab0f18ae8/src/borg/locking.py#L316

When looking at the trace back the last superfluous unlock comes from error handler in 

https://github.com/borgbackup/borg/blob/2cefe8f53db4a9e0cdd1eeff1b06ebdab0f18ae8/src/borg/archiver.py#L5361

As workaround in locking.py#L316 just replaced the 
`elements.remove(self.id)`
with
`elements.discard(self.id)`

I would have expected to now see the issue that triggered the exception handling in archiver.py, but I get no (visible) exceptions anymore.

Discussion:

Patch:
diff --git a/src/borg/locking.py b/src/borg/locking.py
index 9a426780..ada8ae87 100644
--- a/src/borg/locking.py
+++ b/src/borg/locking.py
@@ -7,7 +7,7 @@
 from .helpers import Error, ErrorWithTraceback
 from .logger import create_logger
 
-ADD, REMOVE = 'add', 'remove'
+ADD, REMOVE, REMOVE2 = 'add', 'remove', 'remove2'
 SHARED, EXCLUSIVE = 'shared', 'exclusive'
 
 logger = create_logger(__name__)
@@ -285,6 +285,11 @@ def modify(self, key, op):
         if op == ADD:
             elements.add(self.id)
         elif op == REMOVE:
+            # note: we ignore it if the element is already not present anymore.
+            # this has been frequently seen in teardowns involving Repository.__del__ and Repository.__exit__.
+            elements.discard(self.id)
+        elif op == REMOVE2:
+            # needed for callers that do not want to ignore.
             elements.remove(self.id)
         else:
             raise ValueError('Unknown LockRoster op %r' % op)
@@ -299,7 +304,7 @@ def migrate_lock(self, key, old_id, new_id):
         killing, self.kill_stale_locks = self.kill_stale_locks, False
         try:
             try:
-                self.modify(key, REMOVE)
+                self.modify(key, REMOVE2)
             except KeyError:
                 # entry was not there, so no need to add a new one, but still update our id
                 self.id = new_id


Test patch:
diff --git a/src/borg/testsuite/locking.py b/src/borg/testsuite/locking.py
index 64a79281..6975ed70 100644
--- a/src/borg/testsuite/locking.py
+++ b/src/borg/testsuite/locking.py
@@ -162,7 +162,7 @@ def test_kill_stale(self, lockpath, free_pid):
             assert roster.get(SHARED) == {our_id}
         assert roster.get(EXCLUSIVE) == set()
         assert roster.get(SHARED) == set()
-        with pytest.raises(KeyError):
+        with pytest.raises(NotLocked):
             dead_lock.release()
 
         with Lock(lockpath, id=cant_know_if_dead_id, exclusive=True):