borg crashes when backing up to gvfs volume

[steelman]

Have you checked borgbackup docs, FAQ, and open GitHub issues?

Yes

Is this a BUG / ISSUE report or a QUESTION?

BUG

System information. For client/server mode post info for both machines.

Your borg version (borg -V).

borg 1.2.4

Operating system (distribution) and version.

Debian 12.5

Hardware / network configuration, and filesystems used.

Source: local ext4

Destination: CIFS mounted via FUSE (gvfs) with gio mount smb://….

How much data is handled by borg?

(The question isn't clear)

Archive name: 2024-W08-1
Archive fingerprint: 39956c1531fc491e35c5a20c2622a7335a0a53b463145bf0200722cb1662ac89
Comment: 
Hostname: darkstar
Username: steelman
Time (start): Mon, 2024-02-19 10:13:04
Time (end): Mon, 2024-02-19 10:13:36
Duration: 31.38 seconds
Number of files: 77911
Command line: /usr/bin/borg create -e Maildir/.notmuch -C zlib,9 -p -v -s ::2024-W08-1 ./Mail ./Maildir ./.notmuch-config ./.authinfo.gpg ./.config
Utilization of maximum supported archive size: 0%
------------------------------------------------------------------------------
                       Original size      Compressed size    Deduplicated size
This archive:                6.58 GB              4.13 GB             46.77 MB
All archives:               51.44 GB             32.20 GB              3.86 GB

                       Unique chunks         Total chunks
Chunk index:                   82452               630062

Full borg commandline that lead to the problem (leave away excludes and passwords)

borg check ::2024-W08-1

Describe the problem you're observing.

borg crashes

Can you reproduce the problem? If so, describe how. If not, describe troubleshooting steps you took before opening the issue.

Yes, it happens every time.

Include any warning/errors/backtraces from the system logs

Failed to securely erase old repository config file (hardlinks not supported). Old repokey data, if any, might persist on physical storage.                                                                      
Failed to securely erase old repository config file (hardlinks not supported). Old repokey data, if any, might persist on physical storage.                                                                      
Exception ignored in: <function Repository.__del__ at 0x7f2948f3e660>                                                                                                                                            
Traceback (most recent call last):                                                                                                                                                                               
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 189, in __del__                                                                                                                                 
    self.close()                                                                                                                                                                                                 
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 478, in close                                                                                                                                   
    self.lock.release()                                                                                                                                                                                          
  File "/usr/lib/python3/dist-packages/borg/locking.py", line 417, in release                                                                                                                                    
    self._roster.modify(EXCLUSIVE, REMOVE)                                                                                                                                                                       
  File "/usr/lib/python3/dist-packages/borg/locking.py", line 316, in modify                                                                                                                                     
    elements.remove(self.id)                                                                                                                                                                                     
KeyError: ('darkstar@220292345999402', 1536376, 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/lib/python3/dist-packages/borg/archiver.py", line 5213, in main                                                                                                                                     
    exit_code = archiver.run(args)                                                                                                                                                                               
                ^^^^^^^^^^^^^^^^^^                                                                                                                                                                               
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 5144, in run
    return set_ec(func(args))
                  ^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/borg/archiver.py", line 168, in wrapper
    with repository:
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 214, in __exit__
    self.close()
  File "/usr/lib/python3/dist-packages/borg/repository.py", line 478, in close
    self.lock.release()
  File "/usr/lib/python3/dist-packages/borg/locking.py", line 417, in release
    self._roster.modify(EXCLUSIVE, REMOVE)
  File "/usr/lib/python3/dist-packages/borg/locking.py", line 320, in modify
    self.save(roster)                                                                                                                                                                                            
  File "/usr/lib/python3/dist-packages/borg/locking.py", line 291, in save
    with open(self.path, "w") as f:
OSError: [Errno 95] Operation not supported

Platform: Linux darkstar 6.5.0-0.deb12.4-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.5.10-1~bpo12+1 (2023-11-23) x86_64
Linux: Unknown Linux
Borg: 1.2.4  Python: CPython 3.11.2 msgpack: 1.0.3 fuse: pyfuse3 3.2.1 [pyfuse3,llfuse]
PID: 1536376  CWD: /home/steelman
sys.argv: ['/usr/bin/borg', 'check', '::2024-W08-1']
SSH_ORIGINAL_COMMAND: None

[ThomasWaldmann]

Your filesystem doesn't work correctly.

borg does a file "open" and the fs responds with:

OSError: [Errno 95] Operation not supported

[ThomasWaldmann]

7937 also had this issue.

[steelman]

Indeed it looks very similar. However, it needs to be noted that:

a) it happens only with borg check and not with borg create b) I can open() files for writing on this file system (especially inside the borg repository) without any problems.

[ThomasWaldmann]

You can try to reproduce this on a local filesystem to see whether it only happens on cifs.

"not supported" as error response to "open()" is weird.

[ThomasWaldmann]

Oh, and try without that "gvfs" and just do a normal cifs mount and try with that also.

[steelman]

On kernel-based cifs volume borg check works fine. On gvfs with strace(1) attached to gvfs-fuse serving /run/user/2137/gvfs borg works fine. Without strace(1) it fails. From my experience this looks like some race condition in gvfs. But it is borg that is able to trigger it and that is interesting.

EDIT: borg check running under strace(1) also does not crash.

EVEN MORE EDIT: Even weirder is that the exception happens on the second attempt to open /run/user/2137/gvfs/smb-share:server=[snip],share=homefolder/steelman/Backup/Mail/lock.roster after asking for the password. The first successful attempt takes place right after startup.

[steelman]

I played with touch(1) and strace(1). The former randomly fails to create files in /run/user/2137/gvfs/smb-share:server=[snip],share=homefolder/steelman/Backup/Mail/ (with EOPNOTSUPP) so it seems there is little chance this isn't a fault of gvfs. I will keep investigating.

EDIT: No, it's not at random. openat(2) sets errno to EOPNOTSUPP when the file to be created exists. The first call succeeds:

openat(AT_FDCWD, "/run/user/2137/gvfs/smb-share:server=[snip],share=homefolder/steelman/Backup/Mail/__test__", O_WRONLY|O_CREAT|O_NOCTTY|O_NONBLOCK, 0666) = 3

consequent fail:

openat(AT_FDCWD, "/run/user/2137/gvfs/smb-share:server=[snip],share=homefolder/steelman/Backup/Mail/__test__", O_WRONLY|O_CREAT|O_NOCTTY|O_NONBLOCK, 0666) = -1 EOPNOTSUPP (Operation not supported)

[ThomasWaldmann]

OK, so guess this is a gvfs bug? Or is borg doing something wrong or unusual?

[steelman]

It looks like a gvfs bug to me, but this is just like, my opinion. I will find out.