After I have missed some certain core revisions on my device, it was time for an update. Unfortunately, now no of my self-built snaps will start after reboot (simple daemon), but on initial installation all works fine, the daemon starts. Strange thing: It was working with older core revisions (last verified revision 3700).
also any snap gives this error (every snap is installed during image creation with ubuntu-image):
$ sudo stress-ng
cannot change profile for the next exec call: No such file or directory
snap-update-ns failed with code 1: File exists
Here is also some debug output
user@localhost:~$ sudo SNAPD_DEBUG=1 SNAP_DEBUG_CONFINE=1 stress-ng
DEBUG: security tag: snap.stress-ng.stress-ng
DEBUG: executable: /usr/lib/snapd/snap-exec
DEBUG: confinement: non-classic
DEBUG: base snap: core
DEBUG: ruid: 0, euid: 0, suid: 0
DEBUG: rgid: 0, egid: 0, sgid: 0
DEBUG: apparmor label on snap-confine is: unconfined
DEBUG: apparmor mode is: (null)
DEBUG: checking if the current process shares mount namespace with the init process
DEBUG: re-associating is not required
DEBUG: creating lock directory /run/snapd/lock (if missing)
DEBUG: opening lock directory /run/snapd/lock
DEBUG: opening lock file: /run/snapd/lock/.lock
DEBUG: sanity timeout initialized and set for three 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: creating namespace group directory /run/snapd/ns
DEBUG: namespace group directory does not require intialization
DEBUG: releasing lock 4
DEBUG: snap-update-ns executable: /usr/lib/snapd/snap-update-ns
DEBUG: opened snap-update-ns executable as file descriptor 3
DEBUG: creating lock directory /run/snapd/lock (if missing)
DEBUG: opening lock directory /run/snapd/lock
DEBUG: opening lock file: /run/snapd/lock/stress-ng.lock
DEBUG: sanity timeout initialized and set for three seconds
DEBUG: acquiring exclusive lock (scope stress-ng, uid 0)
DEBUG: sanity timeout reset and disabled
DEBUG: initializing mount namespace: stress-ng
DEBUG: opening namespace group directory /run/snapd/ns
DEBUG: initializing new namespace group stress-ng
DEBUG: forking support process for mount namespace capture
DEBUG: forked support process has pid 2873
DEBUG: unsharing the mount namespace
DEBUG: forked support process has pid 0
DEBUG: DEBUG: scratch directory for constructing namespace: /tmp/snap.rootfs_7MABPc
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
changing apparmor hat of the support process for mount namespace capture
DEBUG: ensuring that parent process is still alive
DEBUG: waiting for a eventfd data from the parent process to continue
DEBUG: sanity timeout initialized and set for three seconds
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: pivot_root /tmp/snap.rootfs_7MABPc /tmp/snap.rootfs_7MABPc//var/lib/snapd/hostfs
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: rmdir /var/lib/snapd/hostfs//tmp/snap.rootfs_7MABPc
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: performing operation: (disabled) use debug build to see details
DEBUG: calling snap-update-ns to initialize mount namespace
DEBUG: waiting for snap-update-ns to finish...
DEBUG: launching snap-update-ns under per-snap profile snap-update-ns.stress-ng
DEBUG: requesting changing of apparmor profile on next exec to snap-update-ns.stress-ng
cannot change profile for the next exec call: No such file or directory
snap-update-ns failed with code 1: File exists
I have a self compiled kernel 4.14.44, before it was 4.4 but no change. It was working with the older revision. I tried with stable core snap and edge core snap, also no change.
There might be an AppArmor issue, but I can’t find a solution, and don’t know what has changed recently in core snap. I appreciate your help. Thanks in advance
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'.
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
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.
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.
@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.