PermissionError: [Errno 13] Permission denied: '/var/lib/snapd/void/awspub.log'

[toabctl]

Hi,

I have a snap installed with snap install --dangerous (because its not yet on the snapstore) but when I run the snap from within a Jenkins jobs (Jenkins worker running on Focal) I get:

13:50:13 + which awspub
13:50:13 /snap/bin/awspub
13:50:13 ++ awspub --log-file awspub.log create --group daily --config-mapping cpc-awspub-config/base-amd64-focal.yaml.mapping cpc-awspub-config/base-amd64-focal.yaml
13:50:15 Traceback (most recent call last):
13:50:15   File "/snap/awspub/x7/bin/awspub", line 8, in <module>
13:50:15     sys.exit(main())
13:50:15   File "/snap/awspub/x7/lib/python3.10/site-packages/awspub/cli/__init__.py", line 144, in main
13:50:15     logging.basicConfig(filename=args.log_file, encoding="utf-8", format=logformat, level=loglevel)
13:50:15   File "/usr/lib/python3.10/logging/__init__.py", line 2040, in basicConfig
13:50:15     h = FileHandler(filename, mode,
13:50:15   File "/usr/lib/python3.10/logging/__init__.py", line 1169, in __init__
13:50:15     StreamHandler.__init__(self, self._open())
13:50:15   File "/usr/lib/python3.10/logging/__init__.py", line 1201, in _open
13:50:15     return open_func(self.baseFilename, self.mode,
13:50:15 PermissionError: [Errno 13] Permission denied: '/var/lib/snapd/void/awspub.log'

But when I run the same command (as jenkins user from the same worker node) manually, it works:

jenkins@ip-172-31-7-209:~$ awspub --log-file awspub.log create --group daily --config-mapping cpc-awspub-config/base-amd64-focal.yaml.mapping cpc-awspub-config/base-amd64-focal.yaml
{
    "images": {}
}jenkins@ip-172-31-7-209:~$ echo $?
0

Any hints where to look further to get this fixed?

[toabctl]

More debugging logs:

14:36:16 + snap run --debug-log awspub.awspub --log-file awspub.log create --group daily --config-mapping cpc-awspub-config/base-amd64-focal.yaml.mapping cpc-awspub-config/base-amd64-focal.yaml
14:36:16 logger.go:93: DEBUG: enabled debug logging of early snap startup
14:36:16 logger.go:93: DEBUG: executing snap-confine from /snap/snapd/20671/usr/lib/snapd/snap-confine
14:36:16 logger.go:93: DEBUG: SELinux not enabled
14:36:16 logger.go:93: DEBUG: creating transient scope snap.awspub.awspub
14:36:16 logger.go:93: DEBUG: session bus is not available: cannot find session bus
14:36:16 logger.go:93: DEBUG: snapd cannot track the started application
14:36:16 logger.go:93: DEBUG: snap refreshes will not be postponed by this process
14:36:16 logger.go:93: DEBUG: -- snap startup {"stage":"snap to snap-confine", "time":"1706103376.597496"}
14:36:16 DEBUG: -- snap startup {"stage":"snap-confine enter", "time":"1706103376.599519"}
14:36:16 DEBUG: umask reset, old umask was  022
14:36:16 DEBUG: security tag: snap.awspub.awspub
14:36:16 DEBUG: executable:   /usr/lib/snapd/snap-exec
14:36:16 DEBUG: confinement:  non-classic
14:36:16 DEBUG: base snap:    core22
14:36:16 DEBUG: ruid: 1000, euid: 0, suid: 0
14:36:16 DEBUG: rgid: 1000, egid: 1000, sgid: 1000
14:36:16 DEBUG: apparmor label on snap-confine is: /snap/snapd/20671/usr/lib/snapd/snap-confine
14:36:16 DEBUG: apparmor mode is: enforce
14:36:16 DEBUG: -- snap startup {"stage":"snap-confine mount namespace start", "time":"1706103376.600564"}
14:36:16 DEBUG: creating lock directory /run/snapd/lock (if missing)
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
14:36:16 DEBUG: opening lock directory /run/snapd/lock
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
14:36:16 DEBUG: opening lock file: /run/snapd/lock/.lock
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
14:36:16 DEBUG: sanity timeout initialized and set for 30 seconds
14:36:16 DEBUG: acquiring exclusive lock (scope (global), uid 0)
14:36:16 DEBUG: sanity timeout reset and disabled
14:36:16 DEBUG: ensuring that snap mount directory is shared
14:36:16 DEBUG: unsharing snap namespace directory
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
14:36:16 DEBUG: releasing lock 5
14:36:16 DEBUG: opened snap-update-ns executable as file descriptor 5
14:36:16 DEBUG: opened snap-discard-ns executable as file descriptor 6
14:36:16 DEBUG: creating lock directory /run/snapd/lock (if missing)
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
14:36:16 DEBUG: opening lock directory /run/snapd/lock
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
14:36:16 DEBUG: opening lock file: /run/snapd/lock/awspub.lock
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
14:36:16 DEBUG: sanity timeout initialized and set for 30 seconds
14:36:16 DEBUG: acquiring exclusive lock (scope awspub, uid 0)
14:36:16 DEBUG: sanity timeout reset and disabled
14:36:16 DEBUG: initializing mount namespace: awspub
14:36:16 DEBUG: setting up device cgroup
14:36:16 DEBUG: cannot find current tags symbol: /lib/x86_64-linux-gnu/libudev.so.1: undefined symbol: udev_device_has_current_tag
14:36:16 DEBUG: no current tags support present
14:36:16 DEBUG: no devices tagged with snap_awspub_awspub, skipping device cgroup setup
14:36:16 DEBUG: forked support process 507404
14:36:16 DEBUG: block device of snap core22, revision 1033 is 7:23
14:36:16 DEBUG: sanity timeout initialized and set for 30 seconds
14:36:16 DEBUG: changing apparmor hat to mount-namespace-capture-helper
14:36:16 DEBUG: helper process waiting for command
14:36:16 DEBUG: sanity timeout initialized and set for 30 seconds
14:36:16 DEBUG: joining preserved mount namespace for inspection
14:36:16 DEBUG: found base snap device 7:23 on /usr
14:36:16 DEBUG: sanity timeout reset and disabled
14:36:16 DEBUG: preserved mount is not stale, reusing
14:36:16 DEBUG: joined preserved mount namespace awspub
14:36:16 DEBUG: joining preserved per-user mount namespace
14:36:16 DEBUG: unsharing the mount namespace (per-user)
14:36:16 DEBUG: sc_setup_user_mounts: awspub
14:36:16 DEBUG: NOT preserving per-user mount namespace
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:0 (change: yes)
14:36:16 DEBUG: set_effective_identity uid:0 (change: no), gid:1000 (change: yes)
14:36:16 DEBUG: moved process 507387 to cgroup hierarchy /sys/fs/cgroup/freezer/snap.awspub
14:36:16 DEBUG: releasing lock 7
14:36:16 DEBUG: sending command 0 to helper process (pid: 507404)
14:36:16 DEBUG: waiting for response from helper
14:36:16 DEBUG: sanity timeout reset and disabled
14:36:16 DEBUG: helper process received command 0
14:36:16 DEBUG: waiting for the helper process to exit
14:36:16 DEBUG: helper process exiting
14:36:16 DEBUG: helper process exited normally
14:36:16 DEBUG: resetting PATH to values in sync with core snap
14:36:16 DEBUG: -- snap startup {"stage":"snap-confine mount namespace finish", "time":"1706103376.617059"}
14:36:16 DEBUG: set_effective_identity uid:1000 (change: yes), gid:1000 (change: yes)
14:36:16 DEBUG: creating user data directory: /home/jenkins/snap/awspub/x9
14:36:16 DEBUG: requesting changing of apparmor profile on next exec to snap.awspub.awspub
14:36:16 DEBUG: ruid: 1000, euid: 1000, suid: 0
14:36:16 DEBUG: setting capabilities bounding set
14:36:16 DEBUG: regaining SYS_ADMIN
14:36:16 DEBUG: loading bpf program for security tag snap.awspub.awspub
14:36:16 DEBUG: read 6568 bytes from /var/lib/snapd/seccomp/bpf//snap.awspub.awspub.bin
14:36:16 DEBUG: read 152 bytes from /var/lib/snapd/seccomp/bpf/global.bin
14:36:16 DEBUG: clearing SYS_ADMIN
14:36:16 DEBUG: execv(/usr/lib/snapd/snap-exec, /usr/lib/snapd/snap-exec...)
14:36:16 DEBUG:  argv[1] = awspub.awspub
14:36:16 DEBUG:  argv[2] = --log-file
14:36:16 DEBUG:  argv[3] = awspub.log
14:36:16 DEBUG:  argv[4] = create
14:36:16 DEBUG:  argv[5] = --group
14:36:16 DEBUG:  argv[6] = daily
14:36:16 DEBUG:  argv[7] = --config-mapping
14:36:16 DEBUG:  argv[8] = cpc-awspub-config/base-amd64-focal.yaml.mapping
14:36:16 DEBUG:  argv[9] = cpc-awspub-config/base-amd64-focal.yaml
14:36:16 DEBUG: umask restored to  022
14:36:16 DEBUG: cannot open path of the original working directory /var/lib/jenkins/workspace/20.04-Base-AWS-Ubuntu-Register-Daily/ARCH/amd64
14:36:16 DEBUG: the process has been placed in the special void directory
14:36:16 DEBUG: -- snap startup {"stage":"snap-confine to snap-exec", "time":"1706103376.619805"}
14:36:16 logger.go:93: DEBUG: -- snap startup {"stage":"snap-exec to app", "time":"1706103376.625667"}
14:36:17 Traceback (most recent call last):
14:36:17   File "/snap/awspub/x9/bin/awspub", line 8, in <module>
14:36:17     sys.exit(main())
14:36:17   File "/snap/awspub/x9/lib/python3.10/site-packages/awspub/cli/__init__.py", line 144, in main
14:36:17     logging.basicConfig(filename=args.log_file, encoding="utf-8", format=logformat, level=loglevel)
14:36:17   File "/usr/lib/python3.10/logging/__init__.py", line 2040, in basicConfig
14:36:17     h = FileHandler(filename, mode,
14:36:17   File "/usr/lib/python3.10/logging/__init__.py", line 1169, in __init__
14:36:17     StreamHandler.__init__(self, self._open())
14:36:17   File "/usr/lib/python3.10/logging/__init__.py", line 1201, in _open
14:36:17     return open_func(self.baseFilename, self.mode,
14:36:17 PermissionError: [Errno 13] Permission denied: '/var/lib/snapd/void/awspub.log'

[toabctl]

So the problem is only there if the current working directory is /var/lib/jenkins:

$ cd /var/lib/jenkins
$ pwd
/var/lib/jenkins
$ awspub --log-file awspub.log create --group daily --config-mapping cpc-awspub-config/base-amd64-focal.yaml.mapping cpc-awspub-config/base-amd64-focal.yaml
Traceback (most recent call last):
  File "/snap/awspub/x9/bin/awspub", line 8, in <module>
    sys.exit(main())
  File "/snap/awspub/x9/lib/python3.10/site-packages/awspub/cli/__init__.py", line 144, in main
    logging.basicConfig(filename=args.log_file, encoding="utf-8", format=logformat, level=loglevel)
  File "/usr/lib/python3.10/logging/__init__.py", line 2040, in basicConfig
    h = FileHandler(filename, mode,
  File "/usr/lib/python3.10/logging/__init__.py", line 1169, in __init__
    StreamHandler.__init__(self, self._open())
  File "/usr/lib/python3.10/logging/__init__.py", line 1201, in _open
    return open_func(self.baseFilename, self.mode,
PermissionError: [Errno 13] Permission denied: '/var/lib/snapd/void/awspub.log'

When I run the same command from /home/jenkins, I get:

$ cd /home/jenkins
$ pwd
/home/jenkins
$ awspub --log-file awspub.log create --group daily --config-mapping cpc-awspub-config/base-amd64-focal.yaml.mapping cpc-awspub-config/base-amd64-focal.yaml
{
    "images": {}
}$ 

Note that on this Jenkins worker, /home/jenkins is a bind mount to /var/lib/jenkins:

$ findmnt /home/jenkins/
TARGET        SOURCE                           FSTYPE OPTIONS
/home/jenkins /dev/nvme0n1p1[/var/lib/jenkins] ext4   rw,relatime,discard

[ogra]

sounds familiar …

Resolved - Home Directory Issue - Jenkins DockerHub

Hi All, Apologize if this is already discussed in the forum earlier but unable to find a satisfactory resolution or easy explanation to resolve the below issue. I am trying to build an application using DockerHub, Jenkins (latest) hosted on Ubuntu - 20.10 (Groovy Gorilla) and snap version - 2.47.1+20.10.1. My home directory is located in /home/ubuntu. I always get the below error in Jenkins and the build does not proceed ahead. (Detailed error code posted at the end for reference.) “Sorry…

[toabctl]

sudo snap set system homedirs=/var/lib

that helped.