"error: cannot assert" - container build on Arch Linux fails

bartoszek · August 3, 2018, 2:59pm

I have a working snapd:2.34.3-1 on Arch-Linux, I can install and run snaps.

Now, I’ve tried to get snapcraft working.

Arch-Linux follows strictly FSH those putting /snap directory in /var/lib snapd@arch-wiki. To be able to install snapcraft I have to symlink those dirs.
sudo ln -s /var/lib/snapd/snap /snap

Then I’ve installed snapcraft successfully. Next, I’ve got lxd, add new group lxd. Finally initialize lxd and test it without any error.
But when trying to test container build I’ve got following error message:

Setting up squashfuse (0.1.100-0ubuntu1~ubuntu16.04.1) ...
error: cannot communicate with server: Get http://localhost/v2/changes?select=all: dial unix /run/snapd.socket: connect: connection refused
Looking up assertion ['account-key', 'public-key-sha3-384=BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul']
Looking up assertion ['snap-declaration', 'snap-name=core']
Looking up assertion ['snap-revision', 'snap-revision=4917', 'snap-id=99T7MUlRhtI3U0QFgl5mXXESAiSwt776']
Adding assertion core_4917.assert
error: cannot assert: cannot communicate with server: Post http://localhost/v2/assertions: dial unix /run/snapd.socket: connect: connection refused
Stopping local:snapcraft-unthievishly-unskirted-tomika
The following command failed to run: 'snap ack /run/core_4917.assert' exited with 1

snapcraft journalctl log: https://pastebin.com/u2CqAUmW
How to debug the server connection for assertion ?

bartoszek · August 5, 2018, 11:38am

I have pinpointed the problematic code line: https://github.com/snapcore/snapcraft/blob/master/snapcraft/internal/lxd/_containerbuild.py#L465 Things to consider: if there is a problem with lxd snap

ogra · August 5, 2018, 12:45pm

there is no snapd running inside the container so the snap command can not talk to it to ack the core snap.

bartoszek · August 6, 2018, 2:28pm

I’ve heard from lxd maintainers there is a kernel compatibility issue involving running snapd inside a container.

Installing snaps in containers is pretty tricky and at least on Ubuntu required quite a number of kernel modifications to get it working (apparmor, nested apparmor and unprivileged fuse mounts), it’s likely that Arch is missing some of those bits.

@ogra If you can confirm, this is the issue or have I misconfigured snapcrafts build environment.

bartoszek · August 6, 2018, 8:47pm

Yep, I’ve got this form snapcraft lxd container console.log

[FAILED] Failed to start Snappy daemon.
See 'systemctl status snapd.service' for details.
[  OK  ] Stopped Snappy daemon

how to get access to snapcraft container journal ?

mborzecki · August 8, 2018, 6:55am

I started a regularr LXC container based on Ubuntu 16.04 and was unable to do anything snap related because snapd kept restarting:

Aug 08 06:23:22 up-ghoul systemd[1]: Starting Snappy daemon...
Aug 08 06:23:22 up-ghoul snapd[462]: AppArmor status: apparmor not enabled
Aug 08 06:23:22 up-ghoul snapd[462]: error: cannot start snapd: cannot mount squashfs image using "fuse.snapfuse": fusermount: mount failed: Operation not permitted
Aug 08 06:23:22 up-ghoul systemd[1]: snapd.service: Main process exited, code=exited, status=1/FAILURE
Aug 08 06:23:22 up-ghoul systemd[1]: Failed to start Snappy daemon.
Aug 08 06:23:22 up-ghoul systemd[1]: snapd.service: Unit entered failed state.
Aug 08 06:23:22 up-ghoul systemd[1]: snapd.service: Failed with result 'exit-code'.
Aug 08 06:23:22 up-ghoul systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Aug 08 06:23:22 up-ghoul systemd[1]: Stopped Snappy daemon.

Well, CONFIG_USER_NS in Arch is not the same as in Ubuntu. See https://bugs.archlinux.org/index.php?do=details&task_id=36969 for discussion.

Starting a privileged container makes snapd work again. Just launch lxc launch ubuntu:16.04 -e -c security.privileged=true and one should be able to use snaps. I have not looked too much for a way to pass container configuration to snapcraft cleanbuild, so instead I just edited the default container profile lxc profile edit default and added:

config:
  security.privileged: "true"

Now I got as far as:

error: no changes of type "auto-refresh" found
Looking up assertion ['account-key', 'public-key-sha3-384=BWDEoaqyr25nF5SNCvEv2v7QnM9QsfCc0PBMYD_i2NGSQ32EF2d4D0hqUel3m8ul']                                             
Looking up assertion ['snap-declaration', 'snap-name=core']
Looking up assertion ['snap-revision', 'snap-revision=5145', 'snap-id=99T7MUlRhtI3U0QFgl5mXXESAiSwt776']                                                                 
Adding assertion core_5145.assert
Installing /run/core_5145.snap
error: cannot perform the following tasks:
- Setup snap "core" (5145) security profiles (cannot setup udev for snap "core": cannot reload udev rules: exit status 2                                                 
udev output:
)
- Setup snap "core" (5145) security profiles (cannot reload udev rules: exit status 2                                                                                    
udev output:
)

I’ll keep on investigating the problem with udev.

Edit:

Taken in a pristine LXC container of Ubuntu 16.04:

root@funny-werewolf:~# snap install hello-world
error: cannot perform the following tasks:
- Setup snap "core" (5145) security profiles (cannot setup udev for snap "core": cannot reload udev rules: exit status 2
udev output:
)
- Setup snap "core" (5145) security profiles (cannot reload udev rules: exit status 2
udev output:
)

root@funny-werewolf:~# snap change 2
Status  Spawn               Ready               Summary
Done    today at 06:58 UTC  today at 06:59 UTC  Ensure prerequisites for "hello-world" are available
Hold    today at 06:58 UTC  today at 06:59 UTC  Download snap "hello-world" (27) from channel "stable"
Hold    today at 06:58 UTC  today at 06:59 UTC  Fetch and check assertions for snap "hello-world" (27)
Hold    today at 06:58 UTC  today at 06:59 UTC  Mount snap "hello-world" (27)
Hold    today at 06:58 UTC  today at 06:59 UTC  Copy snap "hello-world" data
Hold    today at 06:58 UTC  today at 06:59 UTC  Setup snap "hello-world" (27) security profiles
Hold    today at 06:58 UTC  today at 06:59 UTC  Make snap "hello-world" (27) available to the system
Hold    today at 06:58 UTC  today at 06:59 UTC  Automatically connect eligible plugs and slots of snap "hello-world"
Hold    today at 06:58 UTC  today at 06:59 UTC  Set automatic aliases for snap "hello-world"
Hold    today at 06:58 UTC  today at 06:59 UTC  Setup snap "hello-world" aliases
Hold    today at 06:58 UTC  today at 06:59 UTC  Run install hook of "hello-world" snap if present
Hold    today at 06:58 UTC  today at 06:59 UTC  Start snap "hello-world" (27) services
Hold    today at 06:58 UTC  today at 06:59 UTC  Run configure hook of "hello-world" snap if present
Done    today at 06:58 UTC  today at 06:59 UTC  Ensure prerequisites for "core" are available
Undone  today at 06:58 UTC  today at 06:59 UTC  Download snap "core" (5145) from channel "stable"
Done    today at 06:58 UTC  today at 06:59 UTC  Fetch and check assertions for snap "core" (5145)
Undone  today at 06:58 UTC  today at 06:59 UTC  Mount snap "core" (5145)
Undone  today at 06:58 UTC  today at 06:59 UTC  Copy snap "core" data
Error   today at 06:58 UTC  today at 06:59 UTC  Setup snap "core" (5145) security profiles
Hold    today at 06:58 UTC  today at 06:59 UTC  Make snap "core" (5145) available to the system
Hold    today at 06:58 UTC  today at 06:59 UTC  Automatically connect eligible plugs and slots of snap "core"
Hold    today at 06:58 UTC  today at 06:59 UTC  Set automatic aliases for snap "core"
Hold    today at 06:58 UTC  today at 06:59 UTC  Setup snap "core" aliases
Hold    today at 06:58 UTC  today at 06:59 UTC  Run install hook of "core" snap if present
Hold    today at 06:58 UTC  today at 06:59 UTC  Start snap "core" (5145) services
Hold    today at 06:58 UTC  today at 06:59 UTC  Run configure hook of "core" snap if present

......................................................................
Setup snap "core" (5145) security profiles

2018-08-08T06:59:37Z ERROR cannot setup udev for snap "core": cannot reload udev rules: exit status 2
udev output:

2018-08-08T06:59:37Z ERROR cannot reload udev rules: exit status 2
udev output:

root@funny-werewolf:~# snap changes
ID   Status  Spawn               Ready               Summary
1    Done    today at 06:57 UTC  today at 06:57 UTC  Initialize system state
2    Error   today at 06:58 UTC  today at 06:59 UTC  Install "hello-world" snap
3    Done    today at 06:58 UTC  today at 06:58 UTC  Initialize device

Installation of core snap succeeds if I try it again, but I guess it’s caused by some cleanup code not being right and core being special and non-removable.
Installing any other snaps that trigger reloading udev rules (eg. ohmygiraffe) fails consistently.

mborzecki · August 8, 2018, 7:56am

Some related bug reports:

And a fix in the charm: https://git.openstack.org/cgit/openstack/charm-ceph-osd/commit/?id=dd426903471f28eff8e357bac2ca0889ffcff4b9
The apparent fix there is to not reload udev rules when running in a container. Maybe we should do the same in snapd?

bartoszek · August 8, 2018, 2:48pm

Arch provides user namespaces since kernel 4.14 {linux@aps}/config
Also Apparmor is provided with linux-hardened package. {linux-hardened@aps}/config.x86_64
After enabling privilageed container, congruen error message to @mborzecki shows.

Installing /run/core_4917.snap
error: cannot perform the following tasks:
- Setup snap "core" (4917) security profiles (cannot setup udev for snap "core": cannot reload udev rules: exit status 2
udev output:
)
- Setup snap "core" (4917) security profiles (cannot reload udev rules: exit status 2
udev output:
)
Stopping local:snapcraft-decently-unliked-jenine
The following command failed to run: 'snap install /run/core_4917.snap' exited with 1

snaps are working fine (eg. ohmygiraffe)

mborzecki · August 8, 2018, 3:22pm

Yeah, but the last time I checked you need to be root to use it due to security concerns. In that sense, Arch support is/was the same as Fedora. Supposedly, this works for regular users on Ubuntu.

It would be an interesting exercise if someone wanted to try linux-hardened + apparmor from AUR and report back with the results. It’d probably need some tweaking like we did for openSUSE Tumbleweed recently.

bartoszek · August 8, 2018, 7:39pm

Hold my beer

bartoszek · August 11, 2018, 11:08pm

No success here, got snapd instlled but stuck on this error:
cannot load apparmor profile: exit status 243

Unprivileged container

apt install shapd

Aug 11 22:51:02 ubuntu systemd[1]: Failed to start Snappy daemon.
Aug 11 22:51:02 ubuntu systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Aug 11 22:51:02 ubuntu systemd[1]: snapd.service: Scheduled restart job, restart counter is at 3.
Aug 11 22:51:02 ubuntu systemd[1]: Stopped Snappy daemon.
Aug 11 22:51:02 ubuntu systemd[1]: Starting Snappy daemon...
Aug 11 22:51:02 ubuntu snapd[102]: AppArmor status: apparmor is enabled but some features are missing: dbus, network
Aug 11 22:51:02 ubuntu snapd[102]: error: cannot start snapd: cannot mount squashfs image using "squashfs": mount: /tmp/selftest-mountpoint-017662230: mount failed: Operation not permitted.
Aug 11 22:51:02 ubuntu systemd[1]: snapd.service: Main process exited, code=exited, status=1/FAILURE
Aug 11 22:51:02 ubuntu systemd[1]: snapd.service: Failed with result 'exit-code'.
Aug 11 22:51:02 ubuntu systemd[1]: Failed to start Snappy daemon.

apt install squashfuse

~/.local/share/lxc/ubuntu/config
lxc.mount.entry = /dev/fuse dev/fuse none bind,create=file,optional

Aug 11 22:58:59 ubuntu systemd[1]: Failed to start Snappy daemon.
Aug 11 22:58:59 ubuntu systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Aug 11 22:58:59 ubuntu systemd[1]: snapd.service: Scheduled restart job, restart counter is at 3.
Aug 11 22:58:59 ubuntu systemd[1]: Stopped Snappy daemon.
Aug 11 22:58:59 ubuntu systemd[1]: Starting Snappy daemon...
Aug 11 22:58:59 ubuntu snapd[108]: AppArmor status: apparmor is enabled but some features are missing: dbus, network
Aug 11 22:58:59 ubuntu snapd[108]: error: cannot start snapd: cannot mount squashfs image using "fuse.squashfuse": mount: /tmp/selftest-mountpoint-597828511: permission denied.
Aug 11 22:58:59 ubuntu systemd[1]: snapd.service: Main process exited, code=exited, status=1/FAILURE
Aug 11 22:58:59 ubuntu systemd[1]: snapd.service: Failed with result 'exit-code'.
Aug 11 22:58:59 ubuntu systemd[1]: Failed to start Snappy daemo

apt install fuse

Aug 11 22:59:51 ubuntu systemd[1]: Failed to start Snappy daemon.
Aug 11 22:59:51 ubuntu systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Aug 11 22:59:51 ubuntu systemd[1]: snapd.service: Scheduled restart job, restart counter is at 3.
Aug 11 22:59:51 ubuntu systemd[1]: Stopped Snappy daemon.
Aug 11 22:59:51 ubuntu systemd[1]: Starting Snappy daemon...
Aug 11 22:59:52 ubuntu snapd[120]: AppArmor status: apparmor is enabled but some features are missing: dbus, network
Aug 11 22:59:52 ubuntu snapd[120]: error: cannot start snapd: cannot mount squashfs image using "fuse.squashfuse": fusermount: mount failed: Operation not permitted
Aug 11 22:59:52 ubuntu systemd[1]: snapd.service: Main process exited, code=exited, status=1/FAILURE
Aug 11 22:59:52 ubuntu systemd[1]: snapd.service: Failed with result 'exit-code'.
Aug 11 22:59:52 ubuntu systemd[1]: Failed to start Snappy daemon.

Privileged container

sudo apt install snapd

snapd.snap-repair.service is a disabled or a static unit, not starting it.
Job for snapd.service failed because the control process exited with error code.
See "systemctl status snapd.service" and "journalctl -xe" for details.
Job for snapd.seeded.service failed because the control process exited with error code.
See "systemctl status snapd.seeded.service" and "journalctl -xe" for details.
apparmor_parser: Unable to replace "mount-namespace-capture-helper".  Permission denied; attempted to load a profile while confined?
apparmor_parser: Unable to replace "/usr/lib/snapd/snap-confine".  Permission denied; attempted to load a profile while confined?

journalctl -u snapd

Aug 11 22:34:47 ubuntu systemd[1]: Failed to start Snappy daemon.
Aug 11 22:34:47 ubuntu systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Aug 11 22:34:47 ubuntu systemd[1]: snapd.service: Scheduled restart job, restart counter is at 3.
Aug 11 22:34:47 ubuntu systemd[1]: Stopped Snappy daemon.
Aug 11 22:34:47 ubuntu systemd[1]: snapd.service: Failed to reset devices.list: Operation not permitted
Aug 11 22:34:48 ubuntu systemd[1]: Starting Snappy daemon...
Aug 11 22:34:48 ubuntu snapd[99]: AppArmor status: apparmor is enabled but some features are missing: dbus, network
Aug 11 22:34:48 ubuntu snapd[99]: error: cannot start snapd: cannot mount squashfs image using "squashfs": mount: /tmp/selftest-mountpoint-561094199: mount failed: Operation not permitted.
Aug 11 22:34:48 ubuntu systemd[1]: snapd.service: Main process exited, code=exited, status=1/FAILURE
Aug 11 22:34:48 ubuntu systemd[1]: snapd.service: Failed with result 'exit-code'.
Aug 11 22:34:48 ubuntu systemd[1]: Failed to start Snappy daemon.

apt install squashfuse

/var/lib/lxc/ubuntu/config
::
lxc.mount.entry = /dev/fuse dev/fuse none bind,create=file,optional
lxc.mount.entry = tmpfs tmp tmpfs defaults

Aug 11 22:36:15 ubuntu systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Aug 11 22:36:15 ubuntu systemd[1]: snapd.service: Scheduled restart job, restart counter is at 4.
Aug 11 22:36:15 ubuntu systemd[1]: Stopped Snappy daemon.
Aug 11 22:36:15 ubuntu systemd[1]: snapd.service: Failed to reset devices.list: Operation not permitted
Aug 11 22:36:16 ubuntu systemd[1]: Starting Snappy daemon...
Aug 11 22:36:16 ubuntu snapd[114]: AppArmor status: apparmor is enabled but some features are missing: dbus, network
Aug 11 22:36:16 ubuntu snapd[114]: error: cannot start snapd: cannot mount squashfs image using "fuse.squashfuse": mount: /tmp/selftest-mountpoint-925318772: wrong fs type, bad option, bad superblock on /tmp/self
Aug 11 22:36:16 ubuntu systemd[1]: snapd.service: Main process exited, code=exited, status=1/FAILURE
Aug 11 22:36:16 ubuntu systemd[1]: snapd.service: Failed with result 'exit-code'.
Aug 11 22:36:16 ubuntu systemd[1]: Failed to start Snappy daemon.

apt install fuse

Aug 11 22:39:34 ubuntu systemd[1]: Starting Snappy daemon...
Aug 11 22:39:34 ubuntu snapd[60]: AppArmor status: apparmor is enabled but some features are missing: dbus, network
Aug 11 22:39:34 ubuntu snapd[60]: 2018/08/11 22:39:34.696989 helpers.go:119: error trying to compare the snap system key: system-key missing on disk
Aug 11 22:39:34 ubuntu snapd[60]: 2018/08/11 22:39:34.702135 daemon.go:343: started snapd/2.34.2+18.04 (series 16; classic; devmode) ubuntu/18.04 (amd64) linux/4.17.14.a-1-hardened.
Aug 11 22:39:34 ubuntu systemd[1]: Started Snappy daemon.
Aug 11 22:39:34 ubuntu snapd[60]: 2018/08/11 22:39:34.711943 stateengine.go:101: state ensure error: Get https://api.snapcraft.io/api/v1/snaps/sections: dial tcp: lookup api.snapcraft.io on [::1]:53: read udp [::

snap install hello-world

error: cannot perform the following tasks:
- Setup snap "core" (5145) security profiles (cannot setup apparmor for snap "core": cannot load apparmor profile "snap-update-ns.core": cannot load apparmor profile: exit status 243
apparmor_parser output:
apparmor_parser: Unable to replace "snap-update-ns.core".  Permission denied; attempted to load a profile while confined?
)
- Setup snap "core" (5145) security profiles (cannot load apparmor profile "snap-update-ns.core": cannot load apparmor profile: exit status 243
apparmor_parser output:
apparmor_parser: Unable to replace "snap-update-ns.core".  Permission denied; attempted to load a profile while confined?
)

journalctl -u snapd

Aug 11 23:16:49 ubuntu systemd[1]: Starting Snappy daemon...
Aug 11 23:16:49 ubuntu snapd[63]: AppArmor status: apparmor is enabled but some features are missing: dbus, network
Aug 11 23:16:49 ubuntu snapd[63]: 2018/08/11 23:16:49.379751 daemon.go:343: started snapd/2.34.2+18.04 (series 16; classic; devmode) ubuntu/18.04 (amd64) linux/4.17.14.a-1-hardened.
Aug 11 23:16:49 ubuntu systemd[1]: Started Snappy daemon.
Aug 11 23:16:49 ubuntu snapd[63]: 2018/08/11 23:16:49.381077 stateengine.go:101: state ensure error: Get https://api.snapcraft.io/api/v1/snaps/sections: dial tcp: lookup api.snapcraft.io on [::1]:53: read udp [::1]:58379->[::1]:53: read: connection refused
Aug 11 23:17:29 ubuntu snapd[63]: 2018/08/11 23:17:29.961795 daemon.go:180: polkit error: The name org.freedesktop.PolicyKit1 was not provided by any .service files
Aug 11 23:17:44 ubuntu snapd[63]: 2018/08/11 23:17:44.541358 api.go:1046: Installing snap "hello-world" revision unset
Aug 11 23:17:45 ubuntu systemd[1]: snapd.service: Failed to reset devices.list: Operation not permitted
Aug 11 23:17:46 ubuntu snapd[63]: 2018/08/11 23:17:46.187553 backend.go:303: cannot create host snap-confine apparmor configuration: cannot reload snap-confine apparmor profile: cannot load apparmor profile "snap-confine.core.5145": cannot load apparmor profile: exit status 243
Aug 11 23:17:46 ubuntu snapd[63]: apparmor_parser output:
Aug 11 23:17:46 ubuntu snapd[63]: apparmor_parser: Unable to replace "mount-namespace-capture-helper".  Permission denied; attempted to load a profile while confined?
Aug 11 23:17:46 ubuntu snapd[63]: apparmor_parser: Unable to replace "/snap/core/5145/usr/lib/snapd/snap-confine".  Permission denied; attempted to load a profile while confined?
Aug 11 23:17:46 ubuntu systemd[1]: snapd.service: Failed to reset devices.list: Operation not permitted
Aug 11 23:17:46 ubuntu snapd[63]: 2018/08/11 23:17:46.632363 handlers.go:388: Reported install problem for "core" as already-reported