Yocto Rocko - "core" snap panic

PSGXerus · December 20, 2017, 10:55am

Hi all,
I currently work on an update to the meta-snappy layer of Yocto.
The layer should run on Yocto Rocko and use snapd 2.30 .
I updated the recipes and the example image provided by meta-snappy builds fine.
When I launch qemu, snap is able to run.

root@qemux86:~# snap --version
snap    2.30
snapd   2.30
series  16
poky    2.4
kernel  4.12.12-yocto-standard

But when I try to install a snap, mounting fails.

root@qemux86:~# snap install hello-world
error: cannot perform the following tasks:
- Mount snap "core" (3602) (exit status 127)

Squashfs mounting works fine.

journalctl -xe shows:

Dec 20 09:58:47 qemux86 snapd[175]: 2017/12/20 09:58:47.570681 api.go:959: Installing snap "hello-world" revision unset
Dec 20 09:58:53 qemux86 systemd-timesyncd[137]: Synchronized to time server 216.239.35.8:123 (time3.google.com).
Dec 20 10:00:10 qemux86 snapd[175]: panic: runtime error: invalid memory address or nil pointer dereference
Dec 20 10:00:10 qemux86 snapd[175]: [signal SIGSEGV: segmentation violation code=0x1 addr=0xe6b pc=0x825cbca]
Dec 20 10:00:10 qemux86 snapd[175]: goroutine 41 [running]:
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/overlord/state.(*State).writing(0xe3f)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/overlord/state/state.go:140 +0x1a
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/overlord/state.(*Task).SetProgress(0xb76a26fc, 0x966ca248, 0x4, 0x4f7a000, 0x4f7a000)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/overlord/state/task.go:249 +0x163
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/overlord/snapstate.(*taskProgressAdapter).Finished(0x9625a140)
Dec 20 10:00:10 qemux86 snapd[175]:        ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/overlord/snapstate/progress.go:73 +0x75
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/store.glob..func1(0x84dcfef0, 0x9625a160, 0x966ca248, 0x4, 0x964e20c0, 0x60, 0x964e2000, 0x59, 0x0, 0x965a6960, ...)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/store/store.go:1590 +0x8b0
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/store.(*Store).Download(0x965a6960, 0x84dcfef0, 0x9625a160, 0x966ca248, 0x4, 0x96630150, 0x23, 0x9626a120, 0x86a4d00, 0x9625a140, ...)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/store/store.go:1473 +0x34b
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/overlord/snapstate.(*SnapManager).doDownloadSnap(0x9659f590, 0x96294460, 0x9623b860, 0x0, 0x831dde5)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/overlord/snapstate/handlers.go:349 +0x2b6
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/overlord/snapstate.(*SnapManager).(github.com/snapcore/snapd/overlord/snapstate.doDownloadSnap)-fm(0x96294460, 0x9623b860, 0x9644aa20, 0x1)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/overlord/snapstate/snapmgr.go:297 +0x3c
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/overlord/state.(*TaskRunner).run.func1(0x0, 0x0)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/overlord/state/taskrunner.go:146 +0x58
Dec 20 10:00:10 qemux86 snapd[175]: github.com/snapcore/snapd/vendor/gopkg.in/tomb%2ev2.(*Tomb).run(0x9623b860, 0x9625a420)
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x22
Dec 20 10:00:10 qemux86 snapd[175]: created by github.com/snapcore/snapd/vendor/gopkg.in/tomb%2ev2.(*Tomb).Go
Dec 20 10:00:10 qemux86 snapd[175]:         ~/workspace/yocto-rocko/eldk/build/qemux86/tmp/work/i586-poky-linux/snapd/2.30-r0/build/src/github.com/snapcore/snapd/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xe4
Dec 20 10:00:10 qemux86 systemd[1]: [[0;1;39msnapd.service: Main process exited, code=exited, status=2/INVALIDARGUMENT[[0m
Dec 20 10:00:10 qemux86 systemd[1]: [[0;1;39msnapd.service: Unit entered failed state.[[0m
Dec 20 10:00:10 qemux86 systemd[1]: [[0;1;39msnapd.service: Failed with result 'exit-code'.[[0m
Dec 20 10:00:10 qemux86 systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Dec 20 10:00:10 qemux86 systemd[1]: Stopped Snappy daemon.
-- Subject: Unit snapd.service has finished shutting down
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit snapd.service has finished shutting down.
Dec 20 10:00:10 qemux86 systemd[1]: Starting Snappy daemon...
-- Subject: Unit snapd.service has begun start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit snapd.service has begun starting up.
Dec 20 10:00:11 qemux86 snapd[211]: AppArmor status: apparmor not enabled
Dec 20 10:00:11 qemux86 snapd[211]: 2017/12/20 10:00:11.353047 daemon.go:306: st
arted snapd/2.30 (series 16; classic; devmode) poky/2.4 (i386) linux/4.12.12-yocto-standard.
Dec 20 10:00:11 qemux86 systemd[1]: Started Snappy daemon.
-- Subject: Unit snapd.service has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit snapd.service has finished starting up.
-- 
-- The start-up result is done.
Dec 20 10:01:11 qemux86 snapd[211]: 2017/12/20 10:01:11.126427 handlers.go:305: 
Reported install problem for "core" as b4946dea-e56c-11e7-9a05-fa163eec78fa OOPSID
Dec 20 10:13:43 qemux86 systemd[1]: Starting Cleanup of Temporary Directories...

-- Subject: Unit systemd-tmpfiles-clean.service has begun start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit systemd-tmpfiles-clean.service has begun starting up.
Dec 20 10:13:44 qemux86 systemd[1]: Started Cleanup of Temporary Directories.
-- Subject: Unit systemd-tmpfiles-clean.service has finished start-up
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit systemd-tmpfiles-clean.service has finished starting up.
-- 
-- The start-up result is done.

Does anybody know, what I did wrong? Could a missing feature in Yocto Rocko or wrong settings for qemu result in this?
And how could I get more debug information?

Thanks for any help,
PSGXerus

mborzecki · December 20, 2017, 11:39am

Is it possible for you to upload the image somewhere?

mborzecki · December 20, 2017, 1:58pm

Some questions that may help us investigate this further:

are you using Go from OE-core? which version (I see 1.9 is in Rocko)?
can you share the recipe or the layer that provides snapd? (meta-snappy is a outdated and carries own version of Go, I assume you’re not using this layer)

PSGXerus · December 20, 2017, 2:49pm

Yes I use Go from oe and the meta-snappy layer.
(not the master branch with own go version!)
I took the most recent pyro commit and added a few commits.
Github link

I currently try to provide you with an ISO image, but with iso, snapd.service is not even able to start.

mborzecki · December 20, 2017, 3:04pm

You don’t have to prepare an ISO. The default qemu image as created by wic will be just fine (i.e. the one that usually runs when you do runqemu).

PSGXerus · December 20, 2017, 4:59pm

This is a link to a onedrive, where you can find the wic image.
download

mborzecki · December 21, 2017, 7:28am

Thanks for the image. Can you push your patches as well? I’d like to be able to rebuild it here locally if possible.

mborzecki · December 21, 2017, 8:35am

Tried to run the image but it failed with some issues. The exact command I used is:

qemu-system-i386 -enable-kvm -snapshot -m 1500 \
                 -net nic -net user,hostfwd=tcp:127.0.0.1:59468-:22 \
                 -serial telnet:127.0.0.1:59475,server,nowait \
                 -monitor telnet:127.0.0.1:59422,server,nowait \
                 mkefidisk-201712201712-sda.direct \
                 -drive if=pflash,format=raw,readonly,file=/usr/share/ovmf/ovmf_code_ia32.bin \
                 -drive if=pflash,format=raw,file=/usr/share/ovmf/ovmf_vars_ia32.bin \
                 -bios /usr/share/ovmf/ovmf_code_ia32.bin \
                 -vga std

I’ve pulled ovmf from Arch packages.

While starting, the system drops to maintenance shell, looks like the following jobs failed:

sh-4.4# systemctl --no-pager --failed -l
  UNIT                           LOAD   ACTIVE SUB    DESCRIPTION                          
● dev-mqueue.mount               loaded failed failed POSIX Message Queue File System      
● sys-kernel-config.mount        loaded failed failed Kernel Configuration File System     
● sys-kernel-debug.mount         loaded failed failed Kernel Debug File System             
● tmp.mount                      loaded failed failed Temporary Directory (/tmp)           
● var-volatile.mount             loaded failed failed /var/volatile                        
● systemd-remount-fs.service     loaded failed failed Remount Root and Kernel File Systems 
● systemd-tmpfiles-setup.service loaded failed failed Create Volatile Files and Directories

LOAD   = Reflects whether the unit definition was properly loaded.
ACTIVE = The high-level unit activation state, i.e. generalization of SUB.
SUB    = The low-level unit activation state, values depend on unit type.

7 loaded units listed. Pass --all to see loaded but inactive units, too.
To show all installed unit files use 'systemctl list-unit-files'.

The exact issue in systemd-remount-fs is:

sh-4.4# systemctl status --no-pager -l systemd-remount-fs.service
● systemd-remount-fs.service - Remount Root and Kernel File Systems
   Loaded: loaded (/lib/systemd/system/systemd-remount-fs.service; static; vendor preset: enabled)
   Active: failed (Result: exit-code) since Thu 2017-12-21 07:57:42 UTC; 21min ago
     Docs: man:systemd-remount-fs.service(8)
           https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
  Process: 115 ExecStart=/lib/systemd/systemd-remount-fs (code=exited, status=1/FAILURE)
 Main PID: 115 (code=exited, status=1/FAILURE)

Dec 21 07:57:42 qemux86 systemd-remount-fs[115]: only root can use "--options" option (effective UID is 1000)
Dec 21 07:57:42 qemux86 systemd-remount-fs[115]: /bin/mount for /proc exited with exit status 1.
Dec 21 07:57:42 qemux86 systemd-remount-fs[115]: only root can use "--options" option (effective UID is 1000)
Dec 21 07:57:42 qemux86 systemd-remount-fs[115]: /bin/mount for /dev/pts exited with exit status 1.
Dec 21 07:57:42 qemux86 systemd-remount-fs[115]: mount: only root can use "--options" option (effective UID is 1000)
Dec 21 07:57:42 qemux86 systemd-remount-fs[115]: /bin/mount for / exited with exit status 1.
Dec 21 07:57:42 qemux86 systemd[1]: systemd-remount-fs.service: Main process exited, code=exited, status=1/FAILURE
Dec 21 07:57:42 qemux86 systemd[1]: Failed to start Remount Root and Kernel File Systems.
Dec 21 07:57:42 qemux86 systemd[1]: systemd-remount-fs.service: Unit entered failed state.
Dec 21 07:57:42 qemux86 systemd[1]: systemd-remount-fs.service: Failed with result 'exit-code'.

Also observed this:

sh-4.4# id   
uid=0(root) gid=0(root)
sh-4.4# ls -l /lib/systemd/systemd
-rwxr-xr-x    1 1000     1000       1148876 Dec 14 10:23 /lib/systemd/systemd

mborzecki · December 21, 2017, 9:14am

As last resort I tried passing init=/bin/sh to kernel command line. Got pretty much the same, id reports I’m root, but mounting anything fails:

sh-4.4# remount -o remount,rw /
mount: only root can use "--options" option (effective UID is 1000)

PSGXerus · December 22, 2017, 7:47am

Ok, I’ll fix that. Image will follow soon.

mborzecki · December 22, 2017, 7:59am

I’ve rebuilt rocko locally. I’ve also pulled in your fork of meta-snappy too. If you could push your patches updating snapd to 2.30, I’ll give it a spin here.

PSGXerus · December 22, 2017, 5:39pm

Checkout js/devel/rocko. Thanks for building it locally.

mborzecki · December 22, 2017, 6:00pm

Thanks for pushing the changes. I’m on vacation until the 2nd of January. I’ll take a look once I get back.

PSGXerus · December 22, 2017, 8:00pm

Thank you and have a good vacation!

mborzecki · January 2, 2018, 10:13am

I’ve finally built the image with your changes and added some of my own on top. I’ve pushed everything to bboozzoo/snapd-2.30-rocko in my fork right here:

The changes are:

pulled in libseccomp from meta-security and enabled a static build (needed for snap-seccomp)
added snap-seccomp and snap-update-ns to the list of built binaries
split the build into Go binaries that can be linked dynamically (snap, snapctl, snapd, snap-seccomp) and ones that must be linked statically (snap-exec, snap-update-ns)
some minor cleanups: being more explicit about snap mount dir in configure flags, setting up configuration for data/systemd
snapd.service EnvironmentFile is now /etc/default/snapd to be more in line with the other services

For all the builds I’ve used core-image mininal. My local.conf can be found here: https://paste.ubuntu.com/26305269/

Code revisions:

--- meta-openembedded
* 6e3fc5b8d (HEAD -> rocko, origin/rocko) python-cffi: update to version 1.11.2
--- meta-snappy
* 51797b9 (HEAD -> bboozzoo/snapd-2.30-rocko, github/bboozzoo/snapd-2.30-rocko) recipes-support/snapd: pass full system configuration when building support files
--- poky
* 16e22f3e37 (HEAD -> rocko, origin/rocko) documentation: Prepped manual set for a 2.4.1 point release

I was able to install hello, nmap and dash-shell snaps successfully. Running with SNAPD_DEBUG=1 there was no red flags.

Minor issues:

/root is assumed to exist in snap-confine, as a workaround just mkdir /root if it doesn’t exist, before running anything from snaps

Can you try to build with changes from the branch I pushed and the latest rocko?

There are 2 commits that in OE-core that might be of interest regarding the backtrace that you got: https://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/meta/recipes-devtools/go?h=rocko&id=001f8ee0adf703f0a9f90ae9e8f3674935a18c2c and https://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/meta/classes?h=rocko&id=68e77cfb8ac40926eb09f982cc835a0378ad029a Both are already included in rocko branch already.

PSGXerus · January 2, 2018, 11:42pm

Works also fine for me.
Could you merge the changes with Simon Fels’ original project?

This patch would resolve the /root issue.

diff --git a/recipes-support/snapd/snapd_2.30.bb b/recipes-support/snapd/snapd_2.30.bb
index 7ac5364..a9421f7 100644
--- a/recipes-support/snapd/snapd_2.30.bb
+++ b/recipes-support/snapd/snapd_2.30.bb
@@ -91,6 +91,7 @@ do_install() {
        install -d ${D}/var/lib/snapd/environment
        install -d ${D}/var/snap
        install -d ${D}${sysconfdir}/profile.d
+       install -d ${D}/root
 
        oe_runmake -C ${B} install DESTDIR=${D}
        oe_runmake -C ${S}/data/systemd install \
@@ -117,6 +118,7 @@ FILES_${PN} += "                    \
        /var/lib/snapd                  \
        /var/snap                       \
        ${baselib}/udev/snappy-app-dev  \
+       /root                           \
 "
 
 # ERROR: snapd-2.23.5-r0 do_package_qa: QA Issue: No GNU_HASH in the elf binary:

mborzecki · January 3, 2018, 6:36am

Glad to hear that it works for you now.

I’ll see what I can do about updating @morphis’ repo .

morphis · January 5, 2018, 4:06pm

@mborzecki If you send a PR I am happy to review and merge

mborzecki · January 15, 2018, 7:43am

I’ve finally opened a PR right here:
https://github.com/morphis/meta-snappy/pull/14

PSGXerus · January 16, 2018, 2:35pm

Thanks for the effort!