$ snap version
snap 2.30
snapd 2.30
series 16
kernel 4.15.17-xm4x_test+
I get the same error after an automatic snap refresh attempt for my snap wpe-webkit-mir-kiosk
.
snap version
:
snap 2.41
snapd 2.41
series 16
kernel 4.4.0-1120-raspi2
This is the output of snap logs wpe-webkit-mir-kiosk.browser
:
2019-09-17T09:07:08Z wpe-webkit-mir-kiosk.browser[6941]: snap-update-ns failed with code 1: File exists
2019-09-17T09:07:08Z systemd[1]: snap.wpe-webkit-mir-kiosk.browser.service: Main process exited, code=exited, status=1/FAILURE
2019-09-17T09:07:08Z systemd[1]: snap.wpe-webkit-mir-kiosk.browser.service: Unit entered failed state.
2019-09-17T09:07:08Z systemd[1]: snap.wpe-webkit-mir-kiosk.browser.service: Failed with result 'exit-code'.
2019-09-17T09:07:08Z systemd[1]: snap.wpe-webkit-mir-kiosk.browser.service: Service hold-off time over, scheduling restart.
2019-09-17T09:07:08Z systemd[1]: Stopped Service for snap application wpe-webkit-mir-kiosk.browser.
2019-09-17T09:07:08Z systemd[1]: snap.wpe-webkit-mir-kiosk.browser.service: Start request repeated too quickly.
2019-09-17T09:07:08Z systemd[1]: Failed to start Service for snap application wpe-webkit-mir-kiosk.browser.
2019-09-17T09:07:08Z systemd[1]: snap.wpe-webkit-mir-kiosk.browser.service: Unit entered failed state.
2019-09-17T09:07:08Z systemd[1]: snap.wpe-webkit-mir-kiosk.browser.service: Failed with result 'start-limit-hit'.
dmesg | grep AppArmor
:
[504978.659153] audit: type=1400 audit(1568711443.466:158): apparmor="DENIED" operation="rmdir" profile="snap.wpe-webkit-mir-kiosk.browser" name="/root/snap/wpe-webkit-mir-kiosk/25/" pid=14358 comm="rmdir" requested_mask="d" denied_mask="d" fsuid=0 ouid=0
sudo cat /sys/kernel/security/apparmor/profiles
:
glancr@glancr:~$ sudo cat /sys/kernel/security/apparmor/profiles
snap.wpe-webkit-mir-kiosk.hook.install (enforce)
[…]
snap.wpe-webkit-mir-kiosk.browser (enforce)
snap.wpe-webkit-mir-kiosk.hook.configure (enforce)
[…]
snap-update-ns.wpe-webkit-mir-kiosk (enforce)
[…]
ls -lah /var/lib/snapd/apparmor/profiles
:
-rw-r--r-- 1 root root 54K Sep 13 14:55 /var/lib/snapd/apparmor/profiles/snap-update-ns.wpe-webkit-mir-kiosk
Looks like the profile exists and is loaded, so it seems to be something else.
What’s the output from snap changes wpe-webkit-mir-kiosk
and then snap tasks $NUM
for each change number from snap changes
above?
Changes:
ID Status Spawn Ready Summary
35 Error today at 05:04 CEST today at 05:05 CEST Auto-refresh snaps "wpe-webkit-mir-kiosk", "mir-kiosk"
46 Done today at 11:07 CEST today at 11:07 CEST Running service command
49 Done today at 11:24 CEST today at 11:24 CEST Disable "wpe-webkit-mir-kiosk" snap
51 Done today at 11:26 CEST today at 11:26 CEST Enable "wpe-webkit-mir-kiosk" snap
The last three were initiated manually by the affected user upon request.
snap tasks 35 output
Status Spawn Ready Summary
Done today at 05:04 CEST today at 05:05 CEST Ensure prerequisites for "wpe-webkit-mir-kiosk" are available
Undone today at 05:04 CEST today at 05:05 CEST Download snap "wpe-webkit-mir-kiosk" (25) from channel "stable"
Done today at 05:04 CEST today at 05:05 CEST Fetch and check assertions for snap "wpe-webkit-mir-kiosk" (25)
Undone today at 05:04 CEST today at 05:05 CEST Mount snap "wpe-webkit-mir-kiosk" (25)
Undone today at 05:04 CEST today at 05:05 CEST Run pre-refresh hook of "wpe-webkit-mir-kiosk" snap if present
Undone today at 05:04 CEST today at 05:05 CEST Stop snap "wpe-webkit-mir-kiosk" services
Undone today at 05:04 CEST today at 05:05 CEST Remove aliases for snap "wpe-webkit-mir-kiosk"
Undone today at 05:04 CEST today at 05:05 CEST Make current revision for snap "wpe-webkit-mir-kiosk" unavailable
Undone today at 05:04 CEST today at 05:05 CEST Copy snap "wpe-webkit-mir-kiosk" data
Error today at 05:04 CEST today at 05:05 CEST Setup snap "wpe-webkit-mir-kiosk" (25) security profiles
Hold today at 05:04 CEST today at 05:05 CEST Make snap "wpe-webkit-mir-kiosk" (25) available to the system
Hold today at 05:04 CEST today at 05:05 CEST Automatically connect eligible plugs and slots of snap "wpe-webkit-mir-kiosk"
Hold today at 05:04 CEST today at 05:05 CEST Set automatic aliases for snap "wpe-webkit-mir-kiosk"
Hold today at 05:04 CEST today at 05:05 CEST Setup snap "wpe-webkit-mir-kiosk" aliases
Hold today at 05:04 CEST today at 05:05 CEST Run post-refresh hook of "wpe-webkit-mir-kiosk" snap if present
Hold today at 05:04 CEST today at 05:05 CEST Start snap "wpe-webkit-mir-kiosk" (25) services
Hold today at 05:04 CEST today at 05:05 CEST Clean up "wpe-webkit-mir-kiosk" (25) install
Hold today at 05:04 CEST today at 05:05 CEST Run configure hook of "wpe-webkit-mir-kiosk" snap if present
Hold today at 05:04 CEST today at 05:05 CEST Run health check of "wpe-webkit-mir-kiosk" snap
Done today at 05:04 CEST today at 05:04 CEST Ensure prerequisites for "mir-kiosk" are available
Done today at 05:04 CEST today at 05:04 CEST Download snap "mir-kiosk" (2132) from channel "stable"
Done today at 05:04 CEST today at 05:04 CEST Fetch and check assertions for snap "mir-kiosk" (2132)
Done today at 05:04 CEST today at 05:04 CEST Mount snap "mir-kiosk" (2132)
Done today at 05:04 CEST today at 05:04 CEST Run pre-refresh hook of "mir-kiosk" snap if present
Done today at 05:04 CEST today at 05:04 CEST Stop snap "mir-kiosk" services
Done today at 05:04 CEST today at 05:04 CEST Remove aliases for snap "mir-kiosk"
Done today at 05:04 CEST today at 05:04 CEST Make current revision for snap "mir-kiosk" unavailable
Done today at 05:04 CEST today at 05:04 CEST Copy snap "mir-kiosk" data
Done today at 05:04 CEST today at 05:05 CEST Setup snap "mir-kiosk" (2132) security profiles
Done today at 05:04 CEST today at 05:05 CEST Make snap "mir-kiosk" (2132) available to the system
Done today at 05:04 CEST today at 05:05 CEST Automatically connect eligible plugs and slots of snap "mir-kiosk"
Done today at 05:04 CEST today at 05:05 CEST Set automatic aliases for snap "mir-kiosk"
Done today at 05:04 CEST today at 05:05 CEST Setup snap "mir-kiosk" aliases
Done today at 05:04 CEST today at 05:05 CEST Run post-refresh hook of "mir-kiosk" snap if present
Done today at 05:04 CEST today at 05:05 CEST Start snap "mir-kiosk" (2132) services
Done today at 05:04 CEST today at 05:05 CEST Clean up "mir-kiosk" (2132) install
Done today at 05:04 CEST today at 05:05 CEST Run configure hook of "mir-kiosk" snap if present
Done today at 05:04 CEST today at 05:05 CEST Run health check of "mir-kiosk" snap
Done today at 05:04 CEST today at 05:05 CEST Consider re-refresh of "wpe-webkit-mir-kiosk", "mir-kiosk"
......................................................................
Setup snap "wpe-webkit-mir-kiosk" (25) security profiles
2019-09-17T05:05:19+02:00 ERROR cannot setup mount for snap "wpe-webkit-mir-kiosk": cannot update mount namespace of snap "wpe-webkit-mir-kiosk": cannot update preserved namespace of snap "wpe-webkit-mir-kiosk": cannot update snap namespace: device or resource busy
2019-09-17T05:05:19+02:00 ERROR cannot update mount namespace of snap "wpe-webkit-mir-kiosk": cannot update preserved namespace of snap "wpe-webkit-mir-kiosk": cannot update snap namespace: device or resource busy
......................................................................
Consider re-refresh of "wpe-webkit-mir-kiosk", "mir-kiosk"
2019-09-17T05:05:28+02:00 INFO No re-refreshes found.
snap tasks 46 output
Status Spawn Ready Summary
Done today at 11:07 CEST today at 11:07 CEST restart of [wpe-webkit-mir-kiosk.browser]
snap tasks 49 output
Status Spawn Ready Summary
Done today at 11:24 CEST today at 11:24 CEST Stop snap “wpe-webkit-mir-kiosk” (19) services
Done today at 11:24 CEST today at 11:24 CEST Remove aliases for snap “wpe-webkit-mir-kiosk”
Done today at 11:24 CEST today at 11:24 CEST Make snap “wpe-webkit-mir-kiosk” (19) unavailable to the system
Done today at 11:24 CEST today at 11:24 CEST Remove security profiles of snap “wpe-webkit-mir-kiosk”
snap tasks 51 output
Status Spawn Ready Summary
Done today at 11:26 CEST today at 11:26 CEST Prepare snap “wpe-webkit-mir-kiosk” (19)
Done today at 11:26 CEST today at 11:26 CEST Setup snap “wpe-webkit-mir-kiosk” (19) security profiles
Done today at 11:26 CEST today at 11:26 CEST Make snap “wpe-webkit-mir-kiosk” (19) available to the system
Done today at 11:26 CEST today at 11:26 CEST Setup snap “wpe-webkit-mir-kiosk” aliases
Done today at 11:26 CEST today at 11:26 CEST Start snap “wpe-webkit-mir-kiosk” (19) services
Done today at 11:26 CEST today at 11:26 CEST Automatically connect eligible plugs and slots of snap “wpe-webkit-mir-kiosk”
…
Make snap “wpe-webkit-mir-kiosk” (19) available to the system
2019-09-17T11:26:30+02:00 INFO added auto-connect task
@zyga-snapd we have mount namespace updating issues from above. Unclear if it’s a dup or not however, I seem to remember EBUSY being mentioned by you recently…
2019-09-17T05:05:19+02:00 ERROR cannot setup mount for snap "wpe-webkit-mir-kiosk": cannot update mount namespace of snap "wpe-webkit-mir-kiosk": cannot update preserved namespace of snap "wpe-webkit-mir-kiosk": cannot update snap namespace: device or resource busy
2019-09-17T05:05:19+02:00 ERROR cannot update mount namespace of snap "wpe-webkit-mir-kiosk": cannot update preserved namespace of snap "wpe-webkit-mir-kiosk": cannot update snap namespace: device or resource busy
As requested by @zyga-snapd on IRC, here’s the snap.yaml
for wpe-webkit-mir-kiosk
. I’ll put together a test snap with the same layouts ASAP.
name: wpe-webkit-mir-kiosk
version: 2.24.3
summary: *snip*
description: |
*snip*
base: core18
architectures:
- armhf
confinement: strict
grade: stable
layout:
/etc/fonts/conf.avail:
bind: $SNAP/etc/fonts/conf.avail
/etc/ssl/certs/ca-certificates.crt:
bind-file: $SNAP/etc/ssl/certs/ca-certificates.crt
/usr/lib/arm-linux-gnueabihf/wpe-webkit-1.0:
bind: $SNAP/usr/lib/arm-linux-gnueabihf/wpe-webkit-1.0
/usr/libexec/wpe-webkit-1.0:
bind: $SNAP/usr/wpe-webkit-1.0
/usr/local/share/fonts:
bind: $SNAP/usr/share/fonts
/usr/share/fonts:
bind: $SNAP/usr/share/fonts
slots:
dbus-cogctl:
bus: system
interface: dbus
name: com.igalia.Cog
apps:
browser:
command: snap/command-chain/snapcraft-runner $SNAP/command-browser.wrapper
daemon: simple
environment:
FONTCONFIG_FILE: ${SNAP}/etc/fonts/fonts.conf
FONTCONFIG_PATH: ${SNAP}/etc/fonts/conf.d
LIBGL_DRIVERS_PATH: ${SNAP}/usr/lib/arm-linux-gnueabihf/dri
XDG_CACHE_HOME: $SNAP_COMMON/cache
XDG_CONFIG_DIRS: ${SNAP}/etc/xdg:$XDG_CONFIG_DIRS
XDG_DATA_DIRS: ${SNAP}/usr/share:$XDG_DATA_DIRS
XDG_DATA_HOME: ${SNAP}/usr/share
XKB_CONFIG_ROOT: ${SNAP}/usr/share/X11/xkb
__EGL_VENDOR_LIBRARY_DIRS: $SNAP/etc/glvnd/egl_vendor.d:$SNAP/usr/share/glvnd/egl_vendor.d
plugs:
- wayland
- opengl
- network
- network-bind
- upower-observe
- avahi-observe
- network-manager
- hostname-control
- process-control
restart-condition: always
slots:
- dbus-cogctl
@zyga-snapd Had a few minutes this morning to identify the layout which causes this error:
layout:
/usr/lib/$SNAPCRAFT_ARCH_TRIPLET/wpe-webkit-1.0:
bind: $SNAP/usr/lib/$SNAPCRAFT_ARCH_TRIPLET/wpe-webkit-1.0
I guess it has something to do with the $SNAPCRAFT_ARCH_TRIPLET
variable in the mount point, but I’ll leave that up to your knowledge of snapd’s inner workings
For reference, this is the full snapcraft.yaml I ran my tests on.
expand snapcraft.yaml
name: snapd-layouts-test
base: core18
version: "0.1"
summary: A test to debug snap-update-ns issues.
description: see above
grade: stable
confinement: strict
layout:
/usr/libexec/wpe-webkit-1.0:
bind: $SNAP/usr/wpe-webkit-1.0
/usr/lib/$SNAPCRAFT_ARCH_TRIPLET/wpe-webkit-1.0:
bind: $SNAP/usr/lib/$SNAPCRAFT_ARCH_TRIPLET/wpe-webkit-1.0
/etc/fonts/conf.avail:
bind: $SNAP/etc/fonts/conf.avail
/etc/ssl/certs/ca-certificates.crt:
bind-file: $SNAP/etc/ssl/certs/ca-certificates.crt
/usr/share/fonts:
bind: $SNAP/usr/share/fonts
/usr/local/share/fonts: # wpe-webkit: Search ALL the fonts!
bind: $SNAP/usr/share/fonts
parts:
mypart:
plugin: nil
source: .
apps:
browser:
command: pwd
daemon: simple
restart-condition: always
To test which layout causes the error, I followed this procedure:
- Build the snap locally (amd64, snapcraft 3.8)
- Install it with
--dangerous
- Attempt to refresh with the same snap file (
snap install --dangerous snapd-layouts-test_0.1_amd64.snap
), which produced the expected error:
error: cannot perform the following tasks:
- Setup snap "snapd-layouts-test" (unset) security profiles (cannot setup mount for snap "snapd-layouts-test": cannot update mount namespace of snap "snapd-layouts-test": cannot update preserved namespace of snap "snapd-layouts-test": cannot update snap namespace: device or resource busy)
- Setup snap "snapd-layouts-test" (unset) security profiles (cannot update mount namespace of snap "snapd-layouts-test": cannot update preserved namespace of snap "snapd-layouts-test": cannot update snap namespace: device or resource busy)
Once I commented the one layout mentioned above, the refresh went through fine.
Hope that helps to pin down the issue
Thank you, I may conver this to a bug report on launchpad so that I get a number for a regression test. I am sprinting this week but if I manage to I will start by writing a regression test.
Can you please clarify one thing: which of the bases did you use? core or core18? EDIT: I see core18 above so I think that settles it.
I can open an issue on LP myself if it helps to reduce your workload, just not sure if that belongs to snapd or somewhere else.
Yes, snapd
please.
Done, let me know if you need additional details there. Thanks in advance! Layouts still rock
I’m trying to reproduce this but I’m failing with
snap 2.42~pre1.1
snapd 2.42~pre1.1
series 16
ubuntu 19.10
kernel 5.3.0-10-generic
Perhaps this bug is fixed in the 2.42 pre already?
@zyga-snapd is this related to the pair of bugs I discovered a few weeks ago with layouts causing a snap to fail to install/refresh? I recall there was an issue with situations where the mount namespace transition was getting in a wonky state specifically on snaps that were already set-up.
I just tested against core snap from edge (2.42~pre.1.1) on the same 19.04/kernel 5.0.0-29-generic machine as before, and the error still occurs. I also set up a daily:19.10
multipass VM, refreshed core from edge
channel (now 16-2.42~pre1.1, rev 7831) – but the error still occurs when I install the snap and then “refresh” it through a second installation attempt.
In that case the trigger is more complex and may involve an application holding a reference to an open file (e.g. a library). I will expand my test and see what I can get.
It seems like a different case because of the EBUSY error that is returned from the kernel.
I managed to reproduce the issue and I am investigating the details now.
EDIT: This is the log from a failed installation. I will attempt to reduce the number of layout entries to get the minimal reproducer. https://pastebin.ubuntu.com/p/vNGKk3pCS9/
The actual error is on remove of the directory:
2019/09/19 12:03:01.191050 change.go:329: DEBUG: THIS IS THE PATCHED COPY
2019/09/19 12:03:01.191067 change.go:341: DEBUG: mount --make-rprivate "/usr/lib/x86_64-linux-gnu/wpe-webkit-1.0" (error: <nil>)
2019/09/19 12:03:01.191133 change.go:347: DEBUG: umount "/usr/lib/x86_64-linux-gnu/wpe-webkit-1.0" (error: <nil>)
2019/09/19 12:03:01.191200 change.go:358: DEBUG: openPath "/usr/lib/x86_64-linux-gnu/wpe-webkit-1.0" (error: <nil>)
2019/09/19 12:03:01.191219 change.go:367: DEBUG: fstatfs 11 (error: <nil>)
2019/09/19 12:03:01.191283 change.go:393: DEBUG: remove "/usr/lib/x86_64-linux-gnu/wpe-webkit-1.0" (error: remove /usr/lib/x86_64-linux-gnu/wpe-webkit-1.0: device or resource busy)
The directory that failed to unmount is a self-mount-point:
root@x240:/# cat /proc/self/mountinfo | grep /usr/lib/x86_64-linux-gnu/wpe-webkit-1.0
707 708 7:16 /usr/lib/x86_64-linux-gnu/wpe-webkit-1.0 /usr/lib/x86_64-linux-gnu/wpe-webkit-1.0 ro,nodev,relatime master:361 - squashfs /dev/loop16 ro
I’m looking at untangling this state now. It may be a composition of two separate errors.