Why is my strictly confined snap unable to copy a specific file to $SNAP_USER_DATA?

snapd
1

I’m trying to copy a file from $SNAP to $SNAP_USER_DATA. When running in strict confinement, this fails and I get operation not permitted in my logs:

Oct 13, 2021 18:57:32.017 [0x7f710b7fe700] ERROR - Couldn't copy file "/snap/plex/x1/resources/com.plexapp.plugins.library.db" to "/home/tamas/snap/plex/x1/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db": Operation not permitted

But this works in devmode, so it must be the confinement:

Oct 13, 2021 18:51:25.296 [0x7fea98ecb700] DEBUG - Installing Library Database from ["/snap/plex/x1/resources/com.plexapp.plugins.library.db"] to ["/home/tamas/snap/plex/x1/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db"]

I was under the impression that $SNAP_USER_DATA is writable by the snap, and I am indeed able to see files being written there. But not this one. How can I debug what’s going on here?

I’m getting the following denials from apparmor:

Oct 13 19:01:59 mamut audit[705432]: AVC apparmor="DENIED" operation="open" profile="snap.plex.plex" name="/home/tamas/Documents/" pid=705432 comm="head" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
Oct 13 19:01:59 mamut kernel: audit: type=1400 audit(1634144519.898:40955): apparmor="DENIED" operation="open" profile="snap.plex.plex" name="/home/tamas/Documents/" pid=705432 comm="head" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
Oct 13 19:02:00 mamut audit[705478]: AVC apparmor="DENIED" operation="open" profile="snap.plex.plex" name="/proc/705478/setgroups" pid=705478 comm="Plex" requested_mask="w" denied_mask="w" fsuid=1000 ouid=1000
Oct 13 19:02:00 mamut kernel: audit: type=1400 audit(1634144520.346:40956): apparmor="DENIED" operation="open" profile="snap.plex.plex" name="/proc/705478/setgroups" pid=705478 comm="Plex" requested_mask="w" denied_mask="w" fsuid=1000 ouid=1000
2

something is running head against /home/tamas/Documents/ … that does not look like $SNAP_USER_DATA (and i believe this denial is completely unrelated, but would be silenced when defining and connecting the home plug)

try installing the snappy-debug snap and run the snappy-debug command from a second terminal while restarting plex, that should give some helpful hints …

3

Gotcha, I didn’t have the home interface connected. The output I get from snappy-debug is now:

❯ sudo journalctl --output=short --follow --all | sudo snappy-debug
kernel.printk_ratelimit = 0
= AppArmor =
Time: Oct 13 19:38:04
Log: apparmor="DENIED" operation="open" profile="snap.plex.plex" name="/proc/712870/setgroups" pid=712870 comm="Plex" requested_mask="w" denied_mask="w" fsuid=1000 ouid=1000
File: /proc/712870/setgroups (write)
Suggestion:
* adjust program to not access '@{PROC}/@{pid}/setgroups'

I’m not quite sure what’s calling setgroups.

4

the comm= always shows which command tried to call something … there must be a setgroups() call somewhere in the code. If it does not cause any actually visible issues i’d just ignore it …

5

It does cause a visible issue (a sqlite db not being loaded), but there isn’t an explicit setgroups call in our codebase. It could be a dependency, but I don’t know how to figure out which.

1 Like
6

Strace:

722146 openat(AT_FDCWD, "/snap/plex/x1/resources/com.plexapp.plugins.library.db", O_RDONLY|O_CLOEXEC) = 33
722146 fstat(33, {st_dev=makedev(0x7, 0xb), st_ino=623, st_mode=S_IFREG|0664, st_nlink=1, st_uid=0, st_gid=0, st_blksize=1024, st_blocks=622, st_size=318464, st_atime=1634063560 /* 2021-10-12T20:32:40+0200 */, st_atime_nsec=0, st_mtime=1634063560 /* 2021-10-12T20:32:40+0200 */, st_mtime_nsec=0, st_ctime=1634063560 /* 2021-10-12T20:32:40+0200 */, st_ctime_nsec=0}) = 0
722146 openat(AT_FDCWD, "/home/tamas/snap/plex/x1/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_CLOEXEC, 0100664) = 34
722146 fstat(34, {st_dev=makedev(0x103, 0x2), st_ino=19668730, st_mode=S_IFREG|0644, st_nlink=1, st_uid=1000, st_gid=1000, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1634149101 /* 2021-10-13T20:18:21.935478143+0200 */, st_atime_nsec=935478143, st_mtime=1634149101 /* 2021-10-13T20:18:21.935478143+0200 */, st_mtime_nsec=935478143, st_ctime=1634149101 /* 2021-10-13T20:18:21.935478143+0200 */, st_ctime_nsec=935478143}) = 0
722146 fstatfs(33, {f_type=SQUASHFS_MAGIC, f_bsize=131072, f_blocks=1687, f_bfree=0, f_bavail=0, f_files=2236, f_ffree=0, f_fsid={val=[0x70b, 0]}, f_namelen=256, f_frsize=131072, f_flags=ST_VALID|ST_RDONLY|ST_NODEV|ST_RELATIME}) = 0
722146 copy_file_range(33, NULL, 34, NULL, 318464, 0) = -1 EPERM (Operation not permitted)

I would assume this is the same as Snap no longer has write permission but it sounds like my snapd version should have the fix already:

❯ snap --version
snap    2.53+21.10ubuntu1
snapd   2.53+21.10ubuntu1
series  16
ubuntu  21.10
kernel  5.13.0-16-generic

Am I wrong in assuming that this is the same issue? Has the fix not landed yet? I am not

@jdstrand do you have any input on this?

7 
ogra@anubis:~/datengrab/devel/branches/snapd:master$ grep /setgroups interfaces/builtin/*
interfaces/builtin/browser_support.go:owner @{PROC}/@{pid}/setgroups rw,
interfaces/builtin/greengrass_support.go:@{PROC}/[0-9]*/setgroups r,
interfaces/builtin/hardware_observe.go:#@{PROC}/@{pid}/setgroups r,
ogra@anubis:~/datengrab/devel/branches/snapd:master$

it might be possible to cheat and use the browser-plugin plug as a temporary workaround … but assuming your snap also uses daemon: that will force you into manual review when uploading to the store and you will have to convince the reviewers to allow this combination …

the fix from @ijohnson that you linked above only covers the actual setgroups() syscall in seccomp, but does not add permission to write to /proc/$PID/setgroups …

8

If your daemon isn’t running as the user tamas then it will be being denied by virtue of not running as the user who owns /home/tamas/snap/plex. For daemons the usual place to put files is $SNAP_DATA or $SNAP_COMMON to avoid this issue.

3 Likes
9

To be clear that denial above is for the copy_file_range syscall, not the setgroups syscall, the two are very different.

10

This is not Plex Media Server but a new snap I’m working on (Plex for Linux, i.e. a Plex client), so it’s not running as a daemon. This client uses Qt, Chromium and mpv internally. I added the browser-support plug fully expecting that I would need it but that doesn’t seem to make a difference. Initially I tried to use SNAP_USER_COMMON and SNAP_USER_DATA was only choosen as an experiment to see if that had to do with something (but I would probably want to go back to SNAP_USER_DATA).

1 Like
11

The apparmor denial and snappy-debug output says setgroups:

Log: apparmor="DENIED" operation="open" profile="snap.plex.plex" name="/proc/712870/setgroups" pid=712870 comm="Plex" requested_mask="w" denied_mask="w" fsuid=1000 ouid=1000
File: /proc/712870/setgroups (write)
Suggestion:
* adjust program to not access '@{PROC}/@{pid}/setgroups'

copy_file_range is what I found failing in the strace output. FWIW I I tracked down the problematic file copy to a boost::filesystem::copy_file call.

12

the strange thing is copy_file_range is explicitly allowed through seccomp, so it must be being denied by apparmor?

Wild shot in the dark - are the permissions and ownership all lined up on /home/tamas down through /home/tamas/snap/plex/x1/Plex Media Server/ Plug-in Support/Databases/com.plexapp.plugins.library.db? (I suspect they’re fine, but worth a look to be sure)

Second wild shot in the dark - are the paths /snap/plex/x1/resources, and /snap/plex/x1/resources/com.plexapp.plugins.library.db readable by your user, and executable for resources so your user can traverse - it might be readable by root only if it was created during build time with a restricted umask or otherwise told to not be readable beyond it’s owner…

13

It looks like the permissions and ownership are correct everywhere. The snap is also able to write to this location (for example, the logs are also in this directory). It just seems that it’s this one file that fails, probably because of copy_file_range.

14

I wonder if it’s a byproduct of going cross-filesystem starting on a squashfs image? ISTR there are some quirks with cross-fs copying but can’t remember the specifics… it might be rather than permission denied more “I’m sorry, I can’t to do that, Dave”… Worth checking whether a different copy mechanism works in case this specific case of squashfs+copy_file_range is one of those quirks

15

There might be something to that, although errno clearly indicates EPERM (I know that from the logs in my initial post). Thanks for the suggestion I’ll try to rule this out.

16

Yeah if you don’t see a seccomp denial for copy_file_range that may be a red herring to debug your issue here

17

@ijohnson I rebuilt/reran everything and now I’m seeing the following the snappy-debug output:

= Seccomp =
Time: Oct 18 15:31:24
Log: auid=1000 uid=1000 gid=1000 ses=2 subj=snap.plex.plex pid=25130 comm="Plex" exe="/snap/plex/x1/bin/Plex" sig=0 arch=c000003e 326(copy_file_range) compat=0 ip=0x7f205b94c89d code=0x50000
Syscall: copy_file_range

(not sure why I didn’t see this before, maybe snappy-debug got refreshed in the meantime)

18

Ah ha very interesting, that is totally unexpected that you see this, since the fix to allow copy_file_range has indeed landed and should definitely be in 2.53 as you have from above. To be clear, have you tried removing and then reinstalling the snap in question?

19

Yes, I am in fact purging and reinstalling the snap on every iteration since the file will actually exist in the destination dir after this, but its contents will be corrupted. If the file exists, we won’t try to copy again, so I opted to always reinstall everything until I can resolve this.

20

I am now switching to classic confinement for this snap in order to progress. Let me know if I can provide any additional information or the actual snap to reproduce this issue. Further confirming that it’s the confinement causing the issue is the fact that with --classic it works fine.