Errors reporting while installing kernel snap after reset

device
1

Ubuntu core is running over Olimex Lime2 platform and system was booted successfully. But after reset I checked syslog there were errors reporting from snapd related to installing kernel snap. Please find below snippet from “/var/log/syslog”

==================================================================================

Jul 7 09:47:25 localhost /usr/lib/snapd/snapd[1013]: daemon.go:250: DEBUG: init done in 25.82075ms
Jul 7 09:47:25 localhost /usr/lib/snapd/snapd[1013]: daemon.go:251: started snapd/2.26.8 (series 16; devmode) ubuntu-core/16 (armhf) linux/4.10.10-sunxi.
Jul 7 09:47:25 localhost snapd[1013]: 2017/07/07 09:47:25.805844 daemon.go:251: started snapd/2.26.8 (series 16; devmode) ubuntu-core/16 (armhf) linux/4.10.10-sunxi.
Jul 7 09:47:26 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 278 on Doing: Setup snap “core” (2331) security profiles (phase 2)
Jul 7 09:47:26 localhost systemd-timesyncd[876]: Timed out waiting for reply from 91.189.91.157:123 (ntp.ubuntu.com).
Jul 7 09:47:27 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 279 on Do: Set automatic aliases for snap “core”
Jul 7 09:47:27 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 280 on Do: Setup snap “core” aliases
Jul 7 09:47:28 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 281 on Do: Start snap “core” (2331) services
Jul 7 09:47:28 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 282 on Do: Run configure hook of “core” snap if present
Jul 7 09:47:31 localhost /usr/lib/snapd/snapd[1013]: hookmgr.go:378: Reported hook failure from “configure” for snap “core” as 3d3c6b68-6794-11e7-be53-fa163e839e11 OOPSID
Jul 7 09:47:31 localhost snapd[1013]: 2017/07/07 09:47:31.137734 hookmgr.go:378: Reported hook failure from “configure” for snap “core” as 3d3c6b68-6794-11e7-be53-fa163e839e11 OOPSID
Jul 7 09:47:31 localhost /usr/lib/snapd/snapd[1013]: task.go:303: DEBUG: 2017-07-07T09:47:31Z ERROR ignoring failure in hook “configure”: cannot change profile for the next exec call: No such file or directory
Jul 7 09:47:31 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 283 on Do: Prepare snap “/var/lib/snapd/seed/snaps/olimex-a20-olinuxino-lime2_x1.snap” (unset)
Jul 7 09:47:31 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 284 on Do: Mount snap “olimex-a20-olinuxino-lime2” (unset)
Jul 7 09:47:32 localhost /usr/lib/snapd/snapd[1013]: devicestate.go:166: installing unasserted gadget “olimex-a20-olinuxino-lime2”
Jul 7 09:47:32 localhost snapd[1013]: 2017/07/07 09:47:32.102209 devicestate.go:166: installing unasserted gadget "olimex-a20-olinuxino-lime2"
Jul 7 09:47:32 localhost systemd[1]: Reloading.
Jul 7 09:47:33 localhost systemd[1]: snapd.refresh.timer: Adding 5h 6min 41.801196s random time.
Jul 7 09:47:33 localhost systemd[1]: snapd.refresh.timer: Adding 4h 50min 24.780728s random time.
Jul 7 09:47:34 localhost systemd[1]: Reloading.
Jul 7 09:47:35 localhost systemd[1]: snapd.refresh.timer: Adding 1h 3min 36.161363s random time.
Jul 7 09:47:35 localhost systemd[1]: snapd.refresh.timer: Adding 1h 4min 30.820223s random time.
Jul 7 09:47:35 localhost systemd[1]: Mounting Mount unit for olimex-a20-olinuxino-lime2…
Jul 7 09:47:35 localhost systemd-udevd[530]: Network interface NamePolicy= disabled on kernel command line, ignoring.
Jul 7 09:47:35 localhost systemd[1]: Mounted Mount unit for olimex-a20-olinuxino-lime2.
Jul 7 09:47:35 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 285 on Do: Copy snap “olimex-a20-olinuxino-lime2” data
Jul 7 09:47:35 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 286 on Do: Setup snap “olimex-a20-olinuxino-lime2” (unset) security profiles
Jul 7 09:47:36 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 287 on Do: Make snap “olimex-a20-olinuxino-lime2” (unset) available to the system
Jul 7 09:47:36 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 288 on Do: Setup snap “olimex-a20-olinuxino-lime2” (unset) security profiles (phase 2)
Jul 7 09:47:37 localhost kernel: [ 44.251084] random: crng init done
Jul 7 09:47:37 localhost systemd-timesyncd[876]: Timed out waiting for reply from 91.189.89.199:123 (ntp.ubuntu.com).
Jul 7 09:47:37 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 303 on Do: Generate device key
Jul 7 09:47:38 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 289 on Do: Set automatic aliases for snap “olimex-a20-olinuxino-lime2”
Jul 7 09:47:38 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 304 on Do: Request device serial
Jul 7 09:47:39 localhost systemd[1]: Created slice User Slice of arunmakkar.
Jul 7 09:47:39 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 290 on Do: Setup snap “olimex-a20-olinuxino-lime2” aliases
Jul 7 09:47:39 localhost systemd[1]: Started Session 1 of user arunmakkar.
Jul 7 09:47:39 localhost systemd[1]: Starting User Manager for UID 1000…
Jul 7 09:47:40 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 291 on Do: Start snap “olimex-a20-olinuxino-lime2” (unset) services
Jul 7 09:47:40 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 292 on Do: Run configure hook of “olimex-a20-olinuxino-lime2” snap if present
Jul 7 09:47:40 localhost systemd[1178]: Reached target Sockets.
Jul 7 09:47:40 localhost systemd[1178]: Reached target Timers.
Jul 7 09:47:40 localhost systemd[1178]: Reached target Paths.
Jul 7 09:47:40 localhost systemd[1178]: Reached target Basic System.
Jul 7 09:47:40 localhost systemd[1178]: Reached target Default.
Jul 7 09:47:40 localhost systemd[1178]: Startup finished in 1.231s.
Jul 7 09:47:40 localhost systemd[1]: Started User Manager for UID 1000.
Jul 7 09:47:41 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 293 on Do: Prepare snap “/var/lib/snapd/seed/snaps/olimex-a20-olinuxino-lime2-linux_x1.snap” (unset)
Jul 7 09:47:41 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 294 on Do: Mount snap “olimex-a20-olinuxino-lime2-linux” (unset)
Jul 7 09:47:42 localhost /usr/lib/snapd/snapd[1013]: devicestate.go:166: installing unasserted kernel "olimex-a20-olinuxino-lime2-linux"
Jul 7 09:47:42 localhost snapd[1013]: 2017/07/07 09:47:42.121438 devicestate.go:166: installing unasserted kernel “olimex-a20-olinuxino-lime2-linux”
Jul 7 09:47:47 localhost systemd-timesyncd[876]: Timed out waiting for reply from 91.189.89.198:123 (ntp.ubuntu.com).
Jul 7 09:47:55 localhost /usr/lib/snapd/snapd[1013]: task.go:303: DEBUG: 2017-07-07T09:47:55Z ERROR cannot install kernel “olimex-a20-olinuxino-lime2-linux”, model assertion requests "olimex-a20-olinuxino-lime2"
Jul 7 09:47:55 localhost rsyslogd-2007: action ‘action 10’ suspended, next retry is Fri Jul 7 09:48:25 2017 [v8.16.0 try http://www.rsyslog.com/e/2007 ]
Jul 7 09:47:55 localhost /usr/lib/snapd/snapd[1013]: daemon.go:176: DEBUG: uid=1000;@ GET /v2/snaps 7.744545421s 200
Jul 7 09:47:56 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 293 on Undo: Prepare snap “/var/lib/snapd/seed/snaps/olimex-a20-olinuxino-lime2-linux_x1.snap” (unset)
Jul 7 09:47:57 localhost /usr/lib/snapd/snapd[1013]: task.go:303: DEBUG: 2017-07-07T09:47:57Z ERROR cannot deliver device serial request: Cannot process serial request for device with brand “JBnNNIwM0UkIctEoX5NQZYvef4rFeUc2”, store can sign serial only for brand “canonical”
Jul 7 09:47:58 localhost /usr/lib/snapd/snapd[1013]: handlers.go:204: Reported install problem for “olimex-a20-olinuxino-lime2-linux” as 4dc8e60a-6794-11e7-8f31-fa163e839e11 OOPSID
Jul 7 09:47:58 localhost snapd[1013]: 2017/07/07 09:47:58.932618 handlers.go:204: Reported install problem for “olimex-a20-olinuxino-lime2-linux” as 4dc8e60a-6794-11e7-8f31-fa163e839e11 OOPSID
Jul 7 09:47:59 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 291 on Undo: Start snap “olimex-a20-olinuxino-lime2” (unset) services
Jul 7 09:48:00 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 290 on Undo: Setup snap “olimex-a20-olinuxino-lime2” aliases
Jul 7 09:48:00 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 289 on Undo: Set automatic aliases for snap “olimex-a20-olinuxino-lime2”
Jul 7 09:48:00 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 288 on Undo: Setup snap “olimex-a20-olinuxino-lime2” (unset) security profiles (phase 2)
Jul 7 09:48:01 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 287 on Undo: Make snap “olimex-a20-olinuxino-lime2” (unset) available to the system
Jul 7 09:48:01 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 286 on Undo: Setup snap “olimex-a20-olinuxino-lime2” (unset) security profiles
Jul 7 09:48:01 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 285 on Undo: Copy snap “olimex-a20-olinuxino-lime2” data
Jul 7 09:48:01 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 284 on Undo: Mount snap “olimex-a20-olinuxino-lime2” (unset)
Jul 7 09:48:02 localhost systemd[1]: Unmounted Mount unit for olimex-a20-olinuxino-lime2.
Jul 7 09:48:02 localhost systemd[1]: Reloading.
Jul 7 09:48:03 localhost /usr/lib/snapd/snapd[1013]: daemon.go:176: DEBUG: uid=1000;@ GET /v2/changes?select=all 93.09575ms 200
Jul 7 09:48:04 localhost systemd[1]: snapd.refresh.timer: Adding 2h 3.000568s random time.
Jul 7 09:48:04 localhost systemd[1]: snapd.refresh.timer: Adding 29min 14.111528s random time.
Jul 7 09:48:04 localhost systemd[1]: Reloading.
Jul 7 09:48:05 localhost systemd[1]: snapd.refresh.timer: Adding 3h 16min 25.458769s random time.
Jul 7 09:48:05 localhost systemd[1]: snapd.refresh.timer: Adding 4h 24min 30.498523s random time.
Jul 7 09:48:05 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 283 on Undo: Prepare snap “/var/lib/snapd/seed/snaps/olimex-a20-olinuxino-lime2_x1.snap” (unset)
Jul 7 09:48:07 localhost /usr/lib/snapd/snapd[1013]: handlers.go:204: Reported install problem for “olimex-a20-olinuxino-lime2” as 531a7542-6794-11e7-8d1a-fa163ef911dc OOPSID
Jul 7 09:48:07 localhost snapd[1013]: 2017/07/07 09:48:07.801409 handlers.go:204: Reported install problem for “olimex-a20-olinuxino-lime2” as 531a7542-6794-11e7-8d1a-fa163ef911dc OOPSID
Jul 7 09:48:08 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 281 on Undo: Start snap “core” (2331) services
Jul 7 09:48:08 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 280 on Undo: Setup snap “core” aliases
Jul 7 09:48:09 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 279 on Undo: Set automatic aliases for snap “core”
Jul 7 09:48:09 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 278 on Undo: Setup snap “core” (2331) security profiles (phase 2)
Jul 7 09:48:10 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 277 on Undo: Make snap “core” (2331) available to the system
Jul 7 09:48:11 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 276 on Undo: Setup snap “core” (2331) security profiles
Jul 7 09:48:11 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 275 on Undo: Copy snap “core” data
Jul 7 09:48:11 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 274 on Undo: Mount snap “core” (2331)
Jul 7 09:48:12 localhost systemd-udevd[530]: Network interface NamePolicy= disabled on kernel command line, ignoring.
Jul 7 09:48:12 localhost systemd[1]: Unmounted Mount unit for core.
Jul 7 09:48:12 localhost systemd[1]: Reloading.
Jul 7 09:48:13 localhost systemd[1]: snapd.refresh.timer: Adding 3h 28min 59.460504s random time.
Jul 7 09:48:13 localhost systemd[1]: snapd.refresh.timer: Adding 4h 50min 58.750769s random time.
Jul 7 09:48:13 localhost systemd[1]: Reloading.
Jul 7 09:48:14 localhost systemd[1]: snapd.refresh.timer: Adding 2h 44min 32.063787s random time.
Jul 7 09:48:14 localhost systemd[1]: snapd.refresh.timer: Adding 3h 39min 39.516399s random time.
Jul 7 09:48:15 localhost /usr/lib/snapd/snapd[1013]: taskrunner.go:367: DEBUG: Running task 273 on Undo: Prepare snap “/var/lib/snapd/seed/snaps/core_2331.snap” (2331)
Jul 7 09:48:17 localhost /usr/lib/snapd/snapd[1013]: handlers.go:204: Reported install problem for “core” as 58b0c3c6-6794-11e7-9650-fa163ebeb28a OOPSID
Jul 7 09:48:17 localhost snapd[1013]: 2017/07/07 09:48:17.465341 handlers.go:204: Reported install problem for “core” as 58b0c3c6-6794-11e7-9650-fa163ebeb28a OOPSID
Jul 7 09:48:29 localhost systemd-timesyncd[876]: Timed out waiting for reply from 91.189.91.157:123 (ntp.ubuntu.com).

Do I have made some mistake while creating Ubuntu-Core image? Please provide help to determine why these errors are coming.
Appreciate your support here.

2

make sure to have the proper package names in your model assertion :wink:

3

@Ogra : Thanks for quick support. In order to build ubuntu-core image I am using “–extra-snap” option in “Ubuntu-image” command. What name should I keep in “.json” file for kernel and gadget attribute?

Command to Build Image: ubuntu-image -c beta -O imagefile --extra-snaps olimex-a20-olinuxino-lime2-linux_4.10.10_armhf.snap --extra-snaps olimex-a20-olinuxino-lime2_16-0.1_armhf.snap model/Olimex-lime2.model

Kernel and Gadget Attribute in lime2_model.json file: “kernel”: “olimex-a20-olinuxino-lime2”, “gadget”: “olimex-a20-olinuxino-lime2”,

Appreciate your support here.

4

your kernel snap package is obviously called “olimex-a20-olinuxino-lime2-linux” … while your model assertion has “olimex-a20-olinuxino-lime2”, fix that line and re-sign the model assertion …

this sounds like a bug in ubuntu-image btw … it should really not allow you to specify the same name for kernel and gadget in the assertion. it might makes sense to file it here so the ubuntu-image developers can take action.

5

@ogra: Thanks for your support. After doing modifications as suggested above now kernel snap is installing successfully without any error.

Even the problem (system stuck at "initrd: mounting /run" state) after reset is not observed. I have also modified channel to stable while building Ubuntu-Core image using “ubuntu-image” tool.

1 Like
6

@Ogra: I have small queries related to file-system mounted when ubuntu-core image comes up
a) When system came up then root file system is mounted on /dev/loop0 and type squashfs? Is it done from ubuntu-core-rootfs script?
b) From my snap application, I am trying to create a file in /etc directory which I am unable to do so because rootfs is mounted as squashfs type and it is readonly? Do we have a way to create file in /etc directory?

Appreciate your support here.

7

yup, in the “do_root_mounting()” function in that script, right after the “# mount OS snap” comment.

If this is for an app, you need to adjust your app to use its own config directory, /etc is reserved for the OS…

That said, there are a few interfaces that allow writable access to some limited files or directories under /etc.
For example the ppp snap interface allows access to everything underneath /etc/ppp for creating dialup configurations.

So for b) the answer is: it depends what exactly you want to do and for what purpose…

(it might be possible that an interface already exists for your use case or one could be created if the use case is valid for wider use or it might not make sense at all for your app to access /etc and it should be changed, this really depends on the context)