Permissions error on merging indexes on CIFS mount

[Matthew Rankine]

I'm getting a permissions error on merging indexes when the bup directory is on a CIFS mount.

PermissionError: [Errno 13] Permission denied: b'/mnt/nas_backup/temp/bupindex-qgiuwhik/pending' -> b'/mnt/nas_backup/temp/bupindex'

This is 0.33.2 (0.33.2-1~deb12u1) on Raspberry Pi OS bookworm. I didn't get these errors on Raspberry Pi OS bullseye.

I don't get errors if the bup directory is on a local ext4 filesystem.

bup is running as root (via sudo). The CIFS share is mounted as root.

Maybe this is really a problem with my CIFS mount - but overwriting files normally works, i.e. both of these commands succeed:

- sudo touch foo bar; sudo mv foo bar

- sudo python -c "import os; os.rename(\"foo\",\"bar\")"

Steps to replicate:

sudo mount -t cifs "//[address]/backup" "/mnt/nas_backup" -o credentials="[creds]",iocharset=utf8

cd /mnt/nas_backup/

sudo bup -d temp init

sudo touch foo bar

sudo bup -d temp index foo

Indexing: 1, done (135 paths/s).

sudo bup -d temp index bar

Indexing: 1, done (146 paths/s)

bup: merging indexes (8/8), done.

Traceback (most recent call last):

  File "<frozen runpy>", line 198, in _run_module_as_main

  File "<frozen runpy>", line 88, in _run_code

  File "/usr/lib/bup/bup/main.py", line 417, in <module>

    main()

  File "/usr/lib/bup/bup/main.py", line 414, in main

    wrap_main(lambda : run_subcmd(cmd_module, subcmd))

  File "/usr/lib/bup/bup/compat.py", line 98, in wrap_main

    sys.exit(main())

             ^^^^^^

  File "/usr/lib/bup/bup/main.py", line 414, in <lambda>

    wrap_main(lambda : run_subcmd(cmd_module, subcmd))

                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

  File "/usr/lib/bup/bup/main.py", line 409, in run_subcmd

    run_module_cmd(module, args)

  File "/usr/lib/bup/bup/main.py", line 323, in run_module_cmd

    import_and_run_main(module, args)

  File "/usr/lib/bup/bup/main.py", line 287, in import_and_run_main

    module.main(args)

  File "/usr/lib/bup/bup/cmd/index.py", line 283, in main

    update_index(rp, excluded_paths, exclude_rxs, indexfile,

  File "/usr/lib/bup/bup/cmd/index.py", line 196, in update_index

    mi.close()

  File "/usr/lib/bup/bup/index.py", line 586, in close

    with self.cleanup:

  File "/usr/lib/python3.11/contextlib.py", line 589, in __exit__

    raise exc_details[1]

  File "/usr/lib/python3.11/contextlib.py", line 574, in __exit__

    if cb(*exc_details):

       ^^^^^^^^^^^^^^^^

  File "/usr/lib/bup/bup/helpers.py", line 772, in __exit__

    os.rename(self.tmp_path, self.path)

PermissionError: [Errno 13] Permission denied: b'/mnt/nas_backup/temp/bupindex-qgiuwhik/pending' -> b'/mnt/nas_backup/temp/bupindex'

[Rob Browning]

Matthew Rankine <mat...@mrankine.com> writes:

> I'm getting a permissions error on merging indexes when the bup directory
> is on a CIFS mount.
>
> PermissionError: [Errno 13] Permission denied:
> b'/mnt/nas_backup/temp/bupindex-qgiuwhik/pending' ->
> b'/mnt/nas_backup/temp/bupindex'

Hmm, I'm not sure if this is exactly the same, but I suspect it might
be. I think we've seen any number of similar errors with CIFS over the
years. Might try searching the list archives.

In any case, I'm all in favor of fixing the problem if we can, but I
don't use CIFS and haven't taken a lot of time to delve.

--
Rob Browning
rlb @defaultvalue.org and @debian.org
GPG as of 2011-07-10 E6A9 DA3C C9FD 1FF8 C676 D2C4 C0F0 39E9 ED1B 597A
GPG as of 2002-11-03 14DD 432F AE39 534D B592 F9A0 25C8 D377 8C7E 73A4

[Matthew Rankine]

On Tue, 17 Oct 2023 at 01:44, Rob Browning <r...@defaultvalue.org> wrote:

Matthew Rankine <mat...@mrankine.com> writes:

> I'm getting a permissions error on merging indexes when the bup directory
> is on a CIFS mount.
>
> PermissionError: [Errno 13] Permission denied:
> b'/mnt/nas_backup/temp/bupindex-qgiuwhik/pending' ->
> b'/mnt/nas_backup/temp/bupindex'

Hmm, I'm not sure if this is exactly the same, but I suspect it might
be.  I think we've seen any number of similar errors with CIFS over the
years.  Might try searching the list archives.

Found an identical report: https://groups.google.com/g/bup-list/c/3Mfp3tYxNPM/m/fBM3ca9mBwAJ 

In any case, I'm all in favor of fixing the problem if we can, but I
don't use CIFS and haven't taken a lot of time to delve.

I built bup on my Pi (aarch64, Debian bookworm, Python 3.11).

In 0.32.1, merging indexes succeeds. 0.33 introduces the permissions error.

Let me know if I can test further.

[Rob Browning]

Matthew Rankine <mat...@mrankine.com> writes:

> I built bup on my Pi (aarch64, Debian bookworm, Python 3.11).
>
> In 0.32.1, merging indexes succeeds. 0.33 introduces the permissions error.

That's interesting... And it's fairly reliable? (If so, imagine we
have a good chance of tracking it down.)

One suspect might be mmap wrt cifs -- bup and git use mmap heavily in
general, and for bup, specifically with respect to the index.

For example, it might be that we're doing something with mmap that's
fine with "normal" filesystems and linux, but not with cifs.

I did try to clean up our mmap/munmap handling recently, e.g. trying to
make sure we *always* munmap via context managers, etc. Though offhand,
I would have imagined that'd make it less likely we'd have trouble, not
more.

> Let me know if I can test further.

If you want to, and have time, I imagine you could start adding some
print statements to see what it's doing when it fails, i.e. perhaps try
to figure out if maybe the index is still mmaped at the time, somehow,
or...dunno.

(And of course mmap might have nothing to do with it -- just a random
guess.)

Thanks for the help

[Rob Browning]

Matthew Rankine <mat...@mrankine.com> writes:

> I'm getting a permissions error on merging indexes when the bup directory
> is on a CIFS mount.

Oh, and one other thing I should mention in case it's a possibility
(though I imagine you were aware). If you can, you might have better
performance and behavior if you can avoid network filesystems and use
bup's built-in remote support instead to index and save (via "bup on
HOST ..." or commands like "save -r", depending on the direction).

(We still don't have symmetric support wrt restore...)

Regardless, happy to fix the original problem if we can.

[Matthew Rankine]

On Thu, 19 Oct 2023 at 01:56, Rob Browning <r...@defaultvalue.org> wrote:
>
> That's interesting... And it's fairly reliable? (If so, imagine we
> have a good chance of tracking it down.)

Yes, the error is always seen on 0.33 and main branch, and never seen on 0.32.1.

> If you want to, and have time, I imagine you could start adding some
> print statements to see what it's doing when it fails, i.e. perhaps try
> to figure out if maybe the index is still mmaped at the time, somehow,
> or...dunno.

As you suggest, the index appears to still be mmapped when it is renamed over.

Log showing successful run on ext4 and failure on CIFS:
https://gist.github.com/mrankine/bfbad7d2560591db788b768dc49ef4fd
Branch with test script: https://github.com/mrankine/bup/tree/mrankine-cifs

[Rob Browning]

Matthew Rankine <mat...@mrankine.com> writes:

> As you suggest, the index appears to still be mmapped when it is renamed over.
>
> Log showing successful run on ext4 and failure on CIFS:
> https://gist.github.com/mrankine/bfbad7d2560591db788b768dc49ef4fd
> Branch with test script: https://github.com/mrankine/bup/tree/mrankine-cifs

Thanks - very helpful. I'm not sure yet, but I suspect the problem is
with the nesting at the end of update_index, specifically that we can't
let the writer do an atomic replacement while we're still in the "wr"
context -- at least not without an explicit, earlier close of some sort.

So maybe we could just reverse the nesting like this instead (untested):

else:
ri.save()
wi.flush()
if wi.count:
with index.Writer(indexfile, msw, tmax) as mi, \
wi.new_reader() as wr:
if check:
log('check: before merging: oldfile\n')
check_index(ri, verbose)
log('check: before merging: newfile\n')
check_index(wr, verbose)
for e in index.merge(ri, wr):
# FIXME: shouldn't we remove deleted entries
# eventually? When?
mi.add_ixentry(e)
mi.close()

...plus or minus the required check semantics, i.e. assuming it's OK to
check after we've opened the writer.