EACCES error trying to access /var/lib/snapd/void in node snap with classic confinement

Bug #1981858 reported by Lucy Llewellyn
14
This bug affects 3 people
Affects Status Importance Assigned to Milestone
snapd
New
Undecided
Unassigned

Bug Description

Running `node init` or `node install` is failing on my system with an EACCES error while trying to access `/var/lib/snapd/void`.

I'm posting the logs below, but the important bits from the `SNAP_DEBUG=1` run are:

- There are two execve calls in succession, invoking snap-confine, one for `node.npm install` and the second for `node npm install`
- The first execve call succeeds in restoring the working directory
- The second execve call fails to restore the working directory because it has lost the `/home` prefix from the path it is trying to restore into

```
DEBUG: execv(/snap/snapd/16292/usr/lib/snapd/snap-exec, /snap/snapd/16292/usr/lib/snapd/snap-exec...)
DEBUG: argv[1] = node.npm
DEBUG: argv[2] = install
DEBUG: umask restored to 02
DEBUG: working directory restored to /home/dani/Development/sites/isitoutyet-svelte
...
DEBUG: execv(/snap/snapd/16292/usr/lib/snapd/snap-exec, /snap/snapd/16292/usr/lib/snapd/snap-exec...)
DEBUG: argv[1] = node
DEBUG: argv[2] = /snap/node/6512/bin/npm
DEBUG: argv[3] = install
DEBUG: umask restored to 02
DEBUG: cannot open path of the original working directory /dani/Development/sites/isitoutyet-svelte
DEBUG: the process has been placed in the special void directory
```

Logs and info:

```
$ snap version
snap 2.56.2
snapd 2.56.2
series 16
ubuntu 22.04
kernel 5.15.0-40-generic

$ snap info node
name: node
summary: Node.js
publisher: OpenJS Foundation (iojs✓)
store-url: https://snapcraft.io/node
contact: https://github.com/nodejs/snap
license: unset
description: |
  A JavaScript runtime built on Chrome's V8 JavaScript engine. Node.js uses an event-driven,
  non-blocking I/O model that makes it lightweight and efficient. Node.js' package ecosystem, npm,
  is the largest ecosystem of open source libraries in the world. https://nodejs.org/
commands:
  - node
  - node.npm
  - node.npx
  - node.yarn
  - node.yarnpkg
snap-id: MEd4V4HHFkCXBSz6UzVmKF2D2PmWcVwR
tracking: 18/stable
refresh-date: today at 18:07 BST
channels:
   *** snipped ***
installed: 18.6.0 (6512) 32MB classic
```

Running `npm install`:

```
$ npm install
npm ERR! code EACCES
npm ERR! syscall open
npm ERR! path /var/lib/snapd/void/package-lock.json
npm ERR! errno -13
npm ERR! Error: EACCES: permission denied, open '/var/lib/snapd/void/package-lock.json'
npm ERR! [Error: EACCES: permission denied, open '/var/lib/snapd/void/package-lock.json'] {
npm ERR! errno: -13,
npm ERR! code: 'EACCES',
npm ERR! syscall: 'open',
npm ERR! path: '/var/lib/snapd/void/package-lock.json'
npm ERR! }
npm ERR!
npm ERR! The operation was rejected by your operating system.
npm ERR! It is likely you do not have the permissions to access this file as the current user
npm ERR!
npm ERR! If you believe this might be a permissions issue, please double-check the
npm ERR! permissions of the file and its containing directories, or try running
npm ERR! the command again as root/Administrator.

npm ERR! A complete log of this run can be found in:
npm ERR! /home/dani/.npm/_logs/2022-07-15T17_06_43_575Z-debug-0.log
```

Running with debug:

```
$ SNAPD_DEBUG=1 snap run node.npm install
2022/07/15 19:18:43.137670 tool_linux.go:204: DEBUG: restarting into "/snap/snapd/current/usr/bin/snap"
2022/07/15 19:18:43.298296 cmd_run.go:1035: DEBUG: executing snap-confine from /snap/snapd/16292/usr/lib/snapd/snap-confine
2022/07/15 19:18:43.299937 cmd_run.go:438: DEBUG: SELinux not enabled
2022/07/15 19:18:43.300051 tracking.go:46: DEBUG: creating transient scope snap.node.npm
2022/07/15 19:18:43.300875 tracking.go:186: DEBUG: using session bus
2022/07/15 19:18:43.302107 tracking.go:319: DEBUG: create transient scope job: /org/freedesktop/systemd1/job/2788
2022/07/15 19:18:43.302867 tracking.go:419: DEBUG: job result is "done"
2022/07/15 19:18:43.302880 tracking.go:426: DEBUG: transient scope snap.node.npm.6ace7a0b-79a4-48b4-ae88-de438ad65cbe.scope created
2022/07/15 19:18:43.303110 tracking.go:146: DEBUG: waited 2.147245ms for tracking
DEBUG: umask reset, old umask was 02
DEBUG: security tag: snap.node.npm
DEBUG: executable: /snap/snapd/16292/usr/lib/snapd/snap-exec
DEBUG: confinement: classic
DEBUG: base snap: core20
DEBUG: ruid: 1000, euid: 0, suid: 0
DEBUG: rgid: 1000, egid: 1000, sgid: 1000
DEBUG: apparmor label on snap-confine is: /snap/snapd/16292/usr/lib/snapd/snap-confine
DEBUG: apparmor mode is: enforce
DEBUG: creating lock directory /run/snapd/lock (if missing)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: opening lock directory /run/snapd/lock
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: opening lock file: /run/snapd/lock/.lock
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: acquiring exclusive lock (scope (global), uid 0)
DEBUG: sanity timeout reset and disabled
DEBUG: ensuring that snap mount directory is shared
DEBUG: unsharing snap namespace directory
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: (experimental) ensuring snap mount and data directories are mount points
DEBUG: releasing lock 5
DEBUG: preparing classic execution environment
DEBUG: (experimental) unsharing the mount namespace (per-classic-snap)
DEBUG: set_effective_identity uid:1000 (change: yes), gid:1000 (change: yes)
DEBUG: creating user data directory: /home/dani/snap/node/6512
DEBUG: requesting changing of apparmor profile on next exec to snap.node.npm
DEBUG: ruid: 1000, euid: 1000, suid: 0
DEBUG: setting capabilities bounding set
DEBUG: regaining SYS_ADMIN
DEBUG: loading bpf program for security tag snap.node.npm
DEBUG: read 14 bytes from /var/lib/snapd/seccomp/bpf//snap.node.npm.bin
DEBUG: clearing SYS_ADMIN
DEBUG: execv(/snap/snapd/16292/usr/lib/snapd/snap-exec, /snap/snapd/16292/usr/lib/snapd/snap-exec...)
DEBUG: argv[1] = node.npm
DEBUG: argv[2] = install
DEBUG: umask restored to 02
DEBUG: working directory restored to /home/dani/Development/sites/isitoutyet-svelte
2022/07/15 19:18:43.452950 tool_linux.go:204: DEBUG: restarting into "/snap/snapd/current/usr/bin/snap"
2022/07/15 19:18:43.465268 cmd_run.go:1035: DEBUG: executing snap-confine from /snap/snapd/16292/usr/lib/snapd/snap-confine
2022/07/15 19:18:43.466442 cmd_run.go:438: DEBUG: SELinux not enabled
2022/07/15 19:18:43.466515 tracking.go:46: DEBUG: creating transient scope snap.node.node
2022/07/15 19:18:43.467222 tracking.go:186: DEBUG: using session bus
2022/07/15 19:18:43.468140 tracking.go:319: DEBUG: create transient scope job: /org/freedesktop/systemd1/job/2792
2022/07/15 19:18:43.468717 tracking.go:419: DEBUG: job result is "done"
2022/07/15 19:18:43.468727 tracking.go:426: DEBUG: transient scope snap.node.node.b34799bd-fdc3-4c9f-93fd-4ae261c8a1e5.scope created
2022/07/15 19:18:43.468996 tracking.go:146: DEBUG: waited 1.72604ms for tracking
DEBUG: umask reset, old umask was 02
DEBUG: security tag: snap.node.node
DEBUG: executable: /snap/snapd/16292/usr/lib/snapd/snap-exec
DEBUG: confinement: classic
DEBUG: base snap: core20
DEBUG: ruid: 1000, euid: 0, suid: 0
DEBUG: rgid: 1000, egid: 1000, sgid: 1000
DEBUG: apparmor label on snap-confine is: /snap/snapd/16292/usr/lib/snapd/snap-confine
DEBUG: apparmor mode is: enforce
DEBUG: moving to mount namespace of pid 1
DEBUG: creating lock directory /run/snapd/lock (if missing)
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: opening lock directory /run/snapd/lock
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: opening lock file: /run/snapd/lock/.lock
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: sanity timeout initialized and set for 30 seconds
DEBUG: acquiring exclusive lock (scope (global), uid 0)
DEBUG: sanity timeout reset and disabled
DEBUG: ensuring that snap mount directory is shared
DEBUG: unsharing snap namespace directory
DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
DEBUG: (experimental) ensuring snap mount and data directories are mount points
DEBUG: releasing lock 5
DEBUG: preparing classic execution environment
DEBUG: (experimental) unsharing the mount namespace (per-classic-snap)
DEBUG: set_effective_identity uid:1000 (change: yes), gid:1000 (change: yes)
DEBUG: creating user data directory: /home/dani/snap/node/6512
DEBUG: requesting changing of apparmor profile on next exec to snap.node.node
DEBUG: ruid: 1000, euid: 1000, suid: 0
DEBUG: setting capabilities bounding set
DEBUG: regaining SYS_ADMIN
DEBUG: loading bpf program for security tag snap.node.node
DEBUG: read 14 bytes from /var/lib/snapd/seccomp/bpf//snap.node.node.bin
DEBUG: clearing SYS_ADMIN
DEBUG: execv(/snap/snapd/16292/usr/lib/snapd/snap-exec, /snap/snapd/16292/usr/lib/snapd/snap-exec...)
DEBUG: argv[1] = node
DEBUG: argv[2] = /snap/node/6512/bin/npm
DEBUG: argv[3] = install
DEBUG: umask restored to 02
DEBUG: cannot open path of the original working directory /dani/Development/sites/isitoutyet-svelte
DEBUG: the process has been placed in the special void directory
```

Revision history for this message
Yanosh Kunsh (o-pe-g) wrote :

I had the same problem while using node (any of the 16/stable, 18/sable, 20/sable). I started having this issue after enabling snap parallel instances (running more than one version of a package). After I've disable the option everything was working as expected. Note that you might need to remove the parallel versions of packages that you have already installed.

Check if this option is enabled on your end:

```
sudo snap get system experimental.parallel-instances
```

and disable it:

```
sudo snap set system experimental.parallel-instances=false
```

Revision history for this message
Maciej Borzecki (maciek-borzecki) wrote :

Not being able to access /var/lib/snapd/void is expected and intentional. When the old $PWD is no longer accessible inside the snap's mount namespace, the process will be moved to the void directory.

I think the actual issue is why the node snap cannot access a location you're originally executing from. Parallel instances for classic snaps do not get a a sandbox like for the confined snaps, however a snap is executed in a new mount namespace where its <name>_<key> is remapped to <name>. In detail, /var/snap/foo_bar is transparently made to be /var/snap/foo and /snap/foo_bar becomes /snap/foo, such that snap devs do not have to implement any special handling as long as they keep using $SNAP_{DATA,USER_DATA,COMMON,DATA} consistently.

Can you share which location you are in when running the node commands? Is it your $HOME? Is the location mounted from a different storage?

Revision history for this message
Zygmunt Krynicki (zyga) wrote :

Hello. Can you tell me if /dani is a real mount point on your system? Do you have some symlink or bind mount to /home/dani? Thanks!

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.