Snaps in multiuser system with NFS home

Hi all,

I am not able to refresh my snaps and the refreshing process ends with a permission denied error.

  • Copy snap “rdplot” data (cannot copy “/home/user1/snap/rdplot/18” to “/home/user1/snap/rdplot/20”: failed to copy all: “cp: cannot create directory ‘/home/user1/snap/rdplot/20’: Permission denied” (1))

  • /home is a NFS drive and home directories are /home/$USER

  • Obviously I am dealing with a multiuser system.

Actually, I do not quite understand why the refreshing process needs to modify a users homedir. I think the permission error is related to the fact that not all machines have root-access to the NFS share but even if all the data was on a local drive I do not really want an application write to any users homedir.

Is it a bug or a feautre and how can I get around that? I want to run snap refresh nightly on every machine and all snaps should be up-to-date at any point in time. Is that possible?

1 Like

Snaps have data stored in $SNAP_USER_COMMON and $SNAP_USER_DATA which correspond to ~/snap/<name>/common and ~/snap/<name>/<revision>, respectively. On snap refresh, snapd will copy forward anything from ~/snap/<name>/<previous revision> to ~/snap/<name>/<new revision>.

The only way I can see fixing this would be for snapd to drop privileges to the the owner of these directories. AFAICT, snapdata.go is copying the data by preserving the perms, which wouldn’t be sufficient to handle the NFS case as you describe it.

Thank you very much for the response!

Do I get this right assuming that there is no solution for this problem? I cannot simply drop the privs to the owner of these directories as the owners are several ones (multi user system).

Nothing more on that? I would really appreciate any help.

1 Like

We’re slowly moving to have what we call “snapshots” replace the current copying of data. Currently (with 2.36 at least) you can manage snapshots manually (see snap help save).
The interesting thing about snapshots, as well as them being compressed, is that they drop privileges. This means they should work on NFS. It should be safe for you to try: snap save, then snap restore, should work without errors.
If it does work without errors, one workaround for your current issue would be to do snap save, rename the relevant snap data directories, refresh, and then snap restore.
Things might break, so don’t go deleting the data before you’ve tried it though.

Thank you for pointing to that workaround. Unfortunately the snap save command is not available in my installation.

$ snap version 
snap    2.36.3
snapd   2.36.3
series  16
ubuntu  16.04
kernel  4.4.0-140-generic


$ snap help save
error: Unknown command "save". Try 'snap help'.

Am I missing some configuration or should I install some additional packages?

you can switch your core snap (which ships the snapd binary) temporarily to the edge channel with:

sudo snap refresh core --edge

to test out a newer snapd …
to switch back again you can just do:

sudo snap refresh core --stable

on my devices running the core snap from edge i definitely get proper help output for the save command.

1 Like

Thanks to @ogra I managed to run snap save and snap restore. However, snap restore gives me the permission error already mentioned in my initial question.

I am still a little bit confused about the whole process. Which user is performing the refresh operation? Even if it was root, it would / should not be possible to modify any users homedir on my system as the root user would not be same on the NFS drive. If a process (e.g. snap save, snap restore) can manage to modify a users homedir in anyway without the user’s password , this would be really insecure.
IMHO, I really would need to prevent snap refresh to write to users home directories in order to solve that issue.

snap save and snap restore run as the user whose data is being saved or restored. When it’s run for all users, snapd first determines which users have data that needs operating on, and then loops over those users.

Could you show me the error you get on restore?

Sure,

$ snap restore 1
error: cannot perform the following tasks:
- Restore data of snap "snappy-debug" from snapshot set #1 (mkdir /home/$USER/snap/snappy-debug/.snapshot980942652: permission denied)
- Restore data of snap "snapcraft" from snapshot set #1 (mkdir /home/$USER/snap/snapcraft/.snapshot671214586: permission denied)
- Restore data of snap "rdplot" from snapshot set #1 (mkdir /home/OTHERUSER/snap/rdplot/.snapshot334990097: permission denied)

I even get a permission denied error for directories I own (see, upper two errors).

I’ll look into it. It’s possible the initial mkdir isn’t done as the user, which of course wouldn’t work in your case…

Would it be OK if I gave you a custom build of snapd for testing purposes? If so, what architecture are you on?

Yes! This is definitely ok! I am on amd64.

OK, run this:

wget -O snapd https://people.canonical.com/~john/snapd_2.37pre+drop-privs
sudo systemctl stop snapd.\*
sudo SNAP_REEXEC=0 SNAPD_DEBUG=1 ./snapd

and in another terminal, try the snap restore again. Then show me the output of that, and the output of this.

Thank you!

Here it comes

$  snap restore 1
error: cannot perform the following tasks:
- Restore data of snap "snappy-debug" from snapshot set #1 (mkdir /home/schneider/snap/snappy-debug/.snapshot524918028: permission denied)
- Restore data of snap "snapcraft" from snapshot set #1 (context canceled)
- Restore data of snap "rdplot" from snapshot set #1 (mkdir /home/mjcho/snap/rdplot/.snapshot093361994: permission denied)

and in the other terminal:

2019/01/11 14:03:12.830378 daemon.go:296: DEBUG: pid=8150;uid=1459;socket=/run/snapd.socket;@ POST /v2/snapshots 3.690722533s 202
2019/01/11 14:03:12.832291 taskrunner.go:420: DEBUG: Running task 22962 on Do: Restore data of snap "snapcraft" from snapshot set #1
2019/01/11 14:03:12.832453 taskrunner.go:420: DEBUG: Running task 22963 on Do: Restore data of snap "rdplot" from snapshot set #1
2019/01/11 14:03:12.832504 taskrunner.go:420: DEBUG: Running task 22961 on Do: Restore data of snap "snappy-debug" from snapshot set #1
2019/01/11 14:03:12.832565 taskrunner.go:420: DEBUG: Running task 22964 on Do: Restore data of snap "core" from snapshot set #1
2019/01/11 14:03:13.156820 reader.go:292: DEBUG: Restoring "archive.tgz" from "/var/lib/snapd/snapshots/1_core_16-2.37~pre1_6233.zip" into "/var/snap/core/.snapshot733111384".
2019/01/11 14:03:13.157726 reader.go:292: DEBUG: Restoring "archive.tgz" from "/var/lib/snapd/snapshots/1_snappy-debug_0.31.7-snapd2.34_243.zip" into "/var/snap/snappy-debug/.snapshot261685207".
2019/01/11 14:03:13.159393 reader.go:184: Restore of snapshot "/var/lib/snapd/snapshots/1_rdplot_v1.2.0+git6.3c8a530_18.zip" failed (mkdir /home/mjcho/snap/rdplot/.snapshot093361994: permission denied); undoing.
2019/01/11 14:03:13.171509 reader.go:292: DEBUG: Restoring "user/root.tgz" from "/var/lib/snapd/snapshots/1_snappy-debug_0.31.7-snapd2.34_243.zip" into "/root/snap/snappy-debug/.snapshot419796513".
2019/01/11 14:03:13.176248 reader.go:184: Restore of snapshot "/var/lib/snapd/snapshots/1_snappy-debug_0.31.7-snapd2.34_243.zip" failed (mkdir /home/schneider/snap/snappy-debug/.snapshot524918028: permission denied); undoing.
2019/01/11 14:03:13.176282 restorestate.go:79: DEBUG: Removing "/var/snap/snappy-debug/common".
2019/01/11 14:03:13.176320 restorestate.go:79: DEBUG: Removing "/var/snap/snappy-debug/243".
2019/01/11 14:03:13.176337 restorestate.go:79: DEBUG: Removing "/root/snap/snappy-debug/common".
2019/01/11 14:03:13.176356 restorestate.go:79: DEBUG: Removing "/root/snap/snappy-debug/243".
2019/01/11 14:03:13.176384 restorestate.go:91: DEBUG: Restoring "/var/snap/snappy-debug/common.~WNB81f5M0~" to "/var/snap/snappy-debug/common".
2019/01/11 14:03:13.176408 restorestate.go:91: DEBUG: Restoring "/var/snap/snappy-debug/243.~5962SR0Xq~" to "/var/snap/snappy-debug/243".
2019/01/11 14:03:13.176425 restorestate.go:91: DEBUG: Restoring "/root/snap/snappy-debug/common.~lwR066T55~" to "/root/snap/snappy-debug/common".
2019/01/11 14:03:13.176440 restorestate.go:91: DEBUG: Restoring "/root/snap/snappy-debug/243.~0pRByVDmC~" to "/root/snap/snappy-debug/243".
2019/01/11 14:03:13.256722 task.go:303: DEBUG: 2019-01-11T14:03:13+01:00 ERROR mkdir /home/mjcho/snap/rdplot/.snapshot093361994: permission denied
2019/01/11 14:03:13.357722 task.go:303: DEBUG: 2019-01-11T14:03:13+01:00 ERROR mkdir /home/schneider/snap/snappy-debug/.snapshot524918028: permission denied
2019/01/11 14:03:13.684356 taskrunner.go:420: DEBUG: Running task 22964 on Undo: Restore data of snap "core" from snapshot set #1
2019/01/11 14:03:13.883845 restorestate.go:79: DEBUG: Removing "/var/snap/core/common".
2019/01/11 14:03:13.884002 restorestate.go:79: DEBUG: Removing "/var/snap/core/6233".
2019/01/11 14:03:13.884101 restorestate.go:91: DEBUG: Restoring "/var/snap/core/common.~Lqpft7lwH~" to "/var/snap/core/common".
2019/01/11 14:03:13.884178 restorestate.go:91: DEBUG: Restoring "/var/snap/core/6233.~bFMh2RYqy~" to "/var/snap/core/6233".
2019/01/11 14:03:14.087762 reader.go:184: Restore of snapshot "/var/lib/snapd/snapshots/1_snapcraft_2.42.1_1594.zip" failed (context canceled); undoing.
2019/01/11 14:03:14.087850 task.go:303: DEBUG: 2019-01-11T14:03:14+01:00 ERROR context canceled

I’m an idiot. I’d stashed my changes before building… give me a second.

can you try again? The updated URL is https://people.canonical.com/~john/snapd_2.37pre+drop-privs2

No problem

$  snap restore 1
error: cannot communicate with server: Get http://localhost/v2/changes/1094: dial unix /run/snapd.socket: connect: connection refused

and

2019/01/11 14:13:56.332471 daemon.go:296: DEBUG: pid=9036;uid=1459;socket=/run/snapd.socket;@ POST /v2/snapshots 3.817328703s 202
2019/01/11 14:13:56.334266 taskrunner.go:420: DEBUG: Running task 22965 on Do: Restore data of snap "snappy-debug" from snapshot set #1
2019/01/11 14:13:56.334351 taskrunner.go:420: DEBUG: Running task 22968 on Do: Restore data of snap "core" from snapshot set #1
2019/01/11 14:13:56.334412 taskrunner.go:420: DEBUG: Running task 22967 on Do: Restore data of snap "rdplot" from snapshot set #1
2019/01/11 14:13:56.334468 taskrunner.go:420: DEBUG: Running task 22966 on Do: Restore data of snap "snapcraft" from snapshot set #1
2019/01/11 14:13:56.455019 reader.go:277: DEBUG: Restoring "archive.tgz" from "/var/lib/snapd/snapshots/1_snappy-debug_0.31.7-snapd2.34_243.zip" into "/var/snap/snappy-debug/.snapshotJTieJl2F".
2019/01/11 14:13:56.456527 reader.go:277: DEBUG: Restoring "archive.tgz" from "/var/lib/snapd/snapshots/1_core_16-2.37~pre1_6233.zip" into "/var/snap/core/.snapshotQw9s8U2Z".
2019/01/11 14:13:56.458924 reader.go:277: DEBUG: Restoring "archive.tgz" from "/var/lib/snapd/snapshots/1_snapcraft_2.42.1_1594.zip" into "/var/snap/snapcraft/.snapshotovRh1eQ0".
2019/01/11 14:13:56.470875 reader.go:277: DEBUG: Restoring "user/schneider.tgz" from "/var/lib/snapd/snapshots/1_rdplot_v1.2.0+git6.3c8a530_18.zip" into "/home/schneider/snap/rdplot/.snapshotedBN6vH4".
2019/01/11 14:13:56.475608 reader.go:277: DEBUG: Restoring "user/root.tgz" from "/var/lib/snapd/snapshots/1_snappy-debug_0.31.7-snapd2.34_243.zip" into "/root/snap/snappy-debug/.snapshotIPWtkxdy".
2019/01/11 14:13:56.490530 reader.go:277: DEBUG: Restoring "user/schneider.tgz" from "/var/lib/snapd/snapshots/1_snappy-debug_0.31.7-snapd2.34_243.zip" into "/home/schneider/snap/snappy-debug/.snapshotoQNJ9TYw".
2019/01/11 14:13:56.498893 reader.go:277: DEBUG: Restoring "user/sauer.tgz" from "/var/lib/snapd/snapshots/1_snapcraft_2.42.1_1594.zip" into "/home/sauer/snap/snapcraft/.snapshotJ2sDZeFI".
2019/01/11 14:13:56.527612 reader.go:182: Restore of snapshot "/var/lib/snapd/snapshots/1_snappy-debug_0.31.7-snapd2.34_243.zip" failed (stat /home/schneider/snap/snappy-debug/.snapshotoQNJ9TYw/common: permission denied); undoing.
2019/01/11 14:13:56.527637 restorestate.go:79: DEBUG: Removing "/var/snap/snappy-debug/common".
2019/01/11 14:13:56.527663 restorestate.go:79: DEBUG: Removing "/var/snap/snappy-debug/243".
2019/01/11 14:13:56.527684 restorestate.go:79: DEBUG: Removing "/root/snap/snappy-debug/common".
2019/01/11 14:13:56.527706 restorestate.go:79: DEBUG: Removing "/root/snap/snappy-debug/243".
2019/01/11 14:13:56.527759 restorestate.go:91: DEBUG: Restoring "/var/snap/snappy-debug/common.~dyHCYrkNk~" to "/var/snap/snappy-debug/common".
2019/01/11 14:13:56.527780 restorestate.go:91: DEBUG: Restoring "/var/snap/snappy-debug/243.~L6qR9Tp8J~" to "/var/snap/snappy-debug/243".
2019/01/11 14:13:56.527793 restorestate.go:91: DEBUG: Restoring "/root/snap/snappy-debug/common.~DRsfN3btq~" to "/root/snap/snappy-debug/common".
2019/01/11 14:13:56.527808 restorestate.go:91: DEBUG: Restoring "/root/snap/snappy-debug/243.~n4xTKWvv8~" to "/root/snap/snappy-debug/243".
2019/01/11 14:13:56.534323 reader.go:182: Restore of snapshot "/var/lib/snapd/snapshots/1_snapcraft_2.42.1_1594.zip" failed (stat /home/sauer/snap/snapcraft/.snapshotJ2sDZeFI/common: permission denied); undoing.
2019/01/11 14:13:56.534360 restorestate.go:79: DEBUG: Removing "/var/snap/snapcraft/common".
2019/01/11 14:13:56.534383 restorestate.go:79: DEBUG: Removing "/var/snap/snapcraft/1594".
2019/01/11 14:13:56.534409 restorestate.go:91: DEBUG: Restoring "/var/snap/snapcraft/common.~pSBg7FVDN~" to "/var/snap/snapcraft/common".
2019/01/11 14:13:56.534426 restorestate.go:91: DEBUG: Restoring "/var/snap/snapcraft/1594.~2tHBvNnNH~" to "/var/snap/snapcraft/1594".
2019/01/11 14:13:56.580858 task.go:303: DEBUG: 2019-01-11T14:13:56+01:00 ERROR stat /home/schneider/snap/snappy-debug/.snapshotoQNJ9TYw/common: permission denied
2019/01/11 14:13:56.681674 task.go:303: DEBUG: 2019-01-11T14:13:56+01:00 ERROR stat /home/sauer/snap/snapcraft/.snapshotJ2sDZeFI/common: permission denied
2019/01/11 14:13:56.883687 taskrunner.go:420: DEBUG: Running task 22968 on Undo: Restore data of snap "core" from snapshot set #1
2019/01/11 14:13:56.967958 restorestate.go:79: DEBUG: Removing "/var/snap/core/common".
2019/01/11 14:13:56.968099 restorestate.go:79: DEBUG: Removing "/var/snap/core/6233".
2019/01/11 14:13:56.968194 restorestate.go:91: DEBUG: Restoring "/var/snap/core/common.~qfcDJrfHl~" to "/var/snap/core/common".
2019/01/11 14:13:56.968752 restorestate.go:91: DEBUG: Restoring "/var/snap/core/6233.~wD81VLs9y~" to "/var/snap/core/6233".
2019/01/11 14:13:58.878442 reader.go:182: Restore of snapshot "/var/lib/snapd/snapshots/1_rdplot_v1.2.0+git6.3c8a530_18.zip" failed (tar failed: context canceled); undoing.
panic: internal error: accessing state without lock

goroutine 55 [running]:
panic(0xc16a80, 0xc820307200)
	/usr/lib/go-1.6/src/runtime/panic.go:481 +0x3e6
github.com/snapcore/snapd/overlord/state.(*State).writing(0xc820276c80)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/overlord/state/state.go:151 +0x97
github.com/snapcore/snapd/overlord/state.(*Task).Logf(0xc820497440, 0xfc0ec0, 0x2b, 0xc8203cb740, 0x2, 0x2)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/overlord/state/task.go:324 +0x24
github.com/snapcore/snapd/overlord/state.(*Task).Logf-fm(0xfc0ec0, 0x2b, 0xc8203cb740, 0x2, 0x2)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/overlord/snapshotstate/snapshotmgr.go:182 +0x52
github.com/snapcore/snapd/overlord/snapshotstate/backend.(*Reader).Restore.func2(0x7fee8fe3f838, 0xc82037e380, 0xc8203d64e5, 0x9, 0xc8204bf890, 0x2d, 0xc8203558b0)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/overlord/snapshotstate/backend/reader.go:273 +0x1b9
github.com/snapcore/snapd/overlord/snapshotstate/backend.(*Reader).Restore(0xc8203809c0, 0x7fee8fe3f838, 0xc82037e380, 0x12, 0x0, 0x0, 0x0, 0xc8203558b0, 0x0, 0x7fee8fe79028, ...)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/overlord/snapshotstate/backend/reader.go:310 +0x1a1b
github.com/snapcore/snapd/overlord/snapshotstate.doRestore(0xc820497440, 0xc82029d180, 0x0, 0x0)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/overlord/snapshotstate/snapshotmgr.go:182 +0x1c2
github.com/snapcore/snapd/overlord/state.(*TaskRunner).run.func1(0x0, 0x0)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/overlord/state/taskrunner.go:191 +0x6f
github.com/snapcore/snapd/vendor/gopkg.in/tomb%2ev2.(*Tomb).run(0xc82029d180, 0xc820408300)
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x21
created by github.com/snapcore/snapd/vendor/gopkg.in/tomb%2ev2.(*Tomb).Go
	/home/john/canonical/snappy/src/github.com/snapcore/snapd/vendor/gopkg.in/tomb.v2/tomb.go:159 +0x131

Hm, that’s surprising. I need to dig a little bit. I’ll ping you.

Thank you again!

https://people.canonical.com/~john/snapd_2.37pre+drop-privs3 should address that bug