Custom build image - snap not found error

Hi,
I build custom ubuntu core 18 with my gadget and my kiosk application. Built image I used to dd to a terminal host and it was working fine. But I built a new image yesterday and I have a problem running it now. It boots, but snapd fails to start properly. So there is no snap command available

root@localhost:/var/log# snap list
-su: /usr/bin/snap: No such file or directory

In snap dir, there are no snaps mounted

root@localhost:/snap# ls -l
drwxr-xr-x 2 root root 4096 Dec 24 09:40 bin
-r--r--r-- 1 root root  548 Dec 24 09:40 README

Logs for snapd shows:

-- Logs begin at Tue 2019-12-24 09:40:29 UTC, end at Tue 2019-12-24 10:14:15 UTC. --
Dec 24 09:40:40 localhost systemd[1]: Starting Snappy daemon...
Dec 24 09:40:40 localhost snapd[1280]: AppArmor status: apparmor is enabled and all features are available
Dec 24 09:40:41 localhost snapd[1280]: patch.go:64: Patching system state level 6 to sublevel 1...
Dec 24 09:40:41 localhost snapd[1280]: patch.go:64: Patching system state level 6 to sublevel 2...
Dec 24 09:40:41 localhost snapd[1280]: daemon.go:346: started snapd/2.42.5 (series 16) ubuntu-core/18 (amd64) linux/4.15.0-72-generic.
Dec 24 09:40:41 localhost snapd[1280]: daemon.go:439: adjusting startup timeout by 30s (pessimistic estimate of 30s plus 5s per snap)
Dec 24 09:40:41 localhost snapd[1280]: helpers.go:712: cannot retrieve info for snap "pc-kernel": cannot find installed snap "pc-kernel" at revision 346: missing file /snap/pc-kernel/346/meta/snap.yaml
Dec 24 09:40:41 localhost systemd[1]: Started Snappy daemon.
Dec 24 09:40:41 localhost snapd[1280]: daemon.go:540: gracefully waiting for running hooks
Dec 24 09:40:41 localhost snapd[1280]: daemon.go:542: done waiting for running hooks
Dec 24 09:40:41 localhost snapd[1280]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Dec 24 09:40:41 localhost systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Dec 24 09:40:41 localhost systemd[1]: snapd.service: Scheduled restart job, restart counter is at 1.
Dec 24 09:40:41 localhost systemd[1]: Stopped Snappy daemon.
Dec 24 09:40:41 localhost systemd[1]: Starting Snappy daemon...
Dec 24 09:40:41 localhost snapd[1336]: AppArmor status: apparmor is enabled and all features are available
Dec 24 09:40:41 localhost snapd[1336]: daemon.go:346: started snapd/2.42.5 (series 16) ubuntu-core/18 (amd64) linux/4.15.0-72-generic.
Dec 24 09:40:41 localhost snapd[1336]: daemon.go:439: adjusting startup timeout by 35s (pessimistic estimate of 30s plus 5s per snap)
Dec 24 09:40:41 localhost snapd[1336]: helpers.go:712: cannot retrieve info for snap "pc-kernel": cannot find installed snap "pc-kernel" at revision 346: missing file /snap/pc-kernel/346/meta/snap.yaml
Dec 24 09:40:41 localhost systemd[1]: Started Snappy daemon.
Dec 24 09:40:41 localhost snapd[1336]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Dec 24 09:40:43 localhost snapd[1336]: devicestate.go:176: installing unasserted gadget "terminal-device"
Dec 24 09:40:46 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:46 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:46 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:46 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:46 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:47 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:47 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:47 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:47 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:47 localhost snapd[1336]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:40:50 localhost snapd[1336]: handlers.go:460: Reported install problem for "terminal-app" as 77cd3416-2631-11ea-b1b5-fa163e983629 OOPSID
Dec 24 09:40:51 localhost snapd[1336]: handlers.go:460: Reported install problem for "terminal-device" as 78a9bf58-2631-11ea-a98b-fa163e6cac46 OOPSID
Dec 24 09:40:52 localhost snapd[1336]: handlers.go:460: Reported install problem for "core18" as 79525208-2631-11ea-a749-fa163ee63de6 OOPSID
Dec 24 09:40:53 localhost snapd[1336]: handlers.go:460: Reported install problem for "pc-kernel" as 794d96f2-2631-11ea-a98b-fa163e6cac46 OOPSID
Dec 24 09:40:54 localhost snapd[1336]: handlers.go:460: Reported install problem for "snapd" as 7a773554-2631-11ea-b1b5-fa163e983629 OOPSID
Dec 24 09:45:57 localhost snapd[1336]: daemon.go:540: gracefully waiting for running hooks
Dec 24 09:45:57 localhost snapd[1336]: daemon.go:542: done waiting for running hooks
Dec 24 09:45:57 localhost systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Dec 24 09:45:57 localhost systemd[1]: snapd.service: Scheduled restart job, restart counter is at 2.
Dec 24 09:45:57 localhost systemd[1]: Stopped Snappy daemon.
Dec 24 09:45:57 localhost systemd[1]: Starting Snappy daemon...
Dec 24 09:45:57 localhost snapd[2409]: AppArmor status: apparmor is enabled and all features are available
Dec 24 09:45:58 localhost snapd[2409]: daemon.go:346: started snapd/2.42.5 (series 16) ubuntu-core/18 (amd64) linux/4.15.0-72-generic.
Dec 24 09:45:58 localhost snapd[2409]: daemon.go:439: adjusting startup timeout by 35s (pessimistic estimate of 30s plus 5s per snap)
Dec 24 09:45:58 localhost snapd[2409]: helpers.go:712: cannot retrieve info for snap "pc-kernel": cannot find installed snap "pc-kernel" at revision 346: missing file /snap/pc-kernel/346/meta/snap.yaml
Dec 24 09:45:58 localhost systemd[1]: Started Snappy daemon.
Dec 24 09:45:58 localhost snapd[2409]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Dec 24 09:45:59 localhost snapd[2409]: devicestate.go:176: installing unasserted gadget "terminal-device"
Dec 24 09:46:02 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:02 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:02 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:02 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:02 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:03 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:03 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:03 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:03 localhost snapd[2409]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:46:05 localhost snapd[2409]: handlers.go:460: Reported install problem for "terminal-app" as already-reported
Dec 24 09:46:05 localhost snapd[2409]: handlers.go:460: Reported install problem for "terminal-device" as already-reported
Dec 24 09:46:06 localhost snapd[2409]: handlers.go:460: Reported install problem for "core18" as already-reported
Dec 24 09:46:06 localhost snapd[2409]: handlers.go:460: Reported install problem for "pc-kernel" as already-reported
Dec 24 09:46:07 localhost snapd[2409]: handlers.go:460: Reported install problem for "snapd" as already-reported
Dec 24 09:51:10 localhost snapd[2409]: daemon.go:540: gracefully waiting for running hooks
Dec 24 09:51:10 localhost snapd[2409]: daemon.go:542: done waiting for running hooks
Dec 24 09:51:10 localhost systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Dec 24 09:51:10 localhost systemd[1]: snapd.service: Scheduled restart job, restart counter is at 3.
Dec 24 09:51:10 localhost systemd[1]: Stopped Snappy daemon.
Dec 24 09:51:10 localhost systemd[1]: Starting Snappy daemon...
Dec 24 09:51:10 localhost snapd[3381]: AppArmor status: apparmor is enabled and all features are available
Dec 24 09:51:11 localhost snapd[3381]: daemon.go:346: started snapd/2.42.5 (series 16) ubuntu-core/18 (amd64) linux/4.15.0-72-generic.
Dec 24 09:51:11 localhost snapd[3381]: daemon.go:439: adjusting startup timeout by 35s (pessimistic estimate of 30s plus 5s per snap)
Dec 24 09:51:11 localhost snapd[3381]: helpers.go:712: cannot retrieve info for snap "pc-kernel": cannot find installed snap "pc-kernel" at revision 346: missing file /snap/pc-kernel/346/meta/snap.yaml
Dec 24 09:51:11 localhost systemd[1]: Started Snappy daemon.
Dec 24 09:51:11 localhost snapd[3381]: hotplug.go:199: hotplug device add event ignored, enable experimental.hotplug
Dec 24 09:51:12 localhost snapd[3381]: devicestate.go:176: installing unasserted gadget "terminal-device"
Dec 24 09:51:15 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:15 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:15 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:15 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:16 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:16 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:16 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:16 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:16 localhost snapd[3381]: udevmon.go:146: udev event error: Unable to parse uevent, err: cannot parse libudev event: invalid env data
Dec 24 09:51:18 localhost snapd[3381]: handlers.go:460: Reported install problem for "terminal-app" as already-reported
Dec 24 09:51:19 localhost snapd[3381]: handlers.go:460: Reported install problem for "terminal-device" as already-reported
Dec 24 09:51:19 localhost snapd[3381]: handlers.go:460: Reported install problem for "core18" as already-reported
Dec 24 09:51:20 localhost snapd[3381]: handlers.go:460: Reported install problem for "pc-kernel" as already-reported
Dec 24 09:51:20 localhost snapd[3381]: handlers.go:460: Reported install problem for "snapd" as already-reported
Dec 24 09:56:23 localhost snapd[3381]: daemon.go:540: gracefully waiting for running hooks
Dec 24 09:56:23 localhost snapd[3381]: daemon.go:542: done waiting for running hooks
Dec 24 09:56:24 localhost systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Dec 24 09:56:24 localhost systemd[1]: snapd.service: Scheduled restart job, restart counter is at 4.

When I restarted snapd with systemctl I get these logs:

Dec 24 10:14:04 localhost systemd[7921]: snapd.service: Failed to execute command: No such file or directory
Dec 24 10:14:04 localhost systemd[7921]: snapd.service: Failed at step EXEC spawning /snap/snapd/5754/usr/lib/snapd/snapd: No such file or directory
Dec 24 10:14:04 localhost systemd[1]: snapd.service: Main process exited, code=exited, status=203/EXEC
Dec 24 10:14:04 localhost systemd[1]: snapd.service: Failed with result 'exit-code'.
Dec 24 10:14:04 localhost systemd[1]: Failed to start Snappy daemon.
Dec 24 10:14:04 localhost systemd[1]: snapd.service: Triggering OnFailure= dependencies.
Dec 24 10:14:04 localhost systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Dec 24 10:14:04 localhost systemd[1]: snapd.service: Scheduled restart job, restart counter is at 1.
Dec 24 10:14:04 localhost systemd[1]: Stopped Snappy daemon.
Dec 24 10:14:04 localhost systemd[1]: Starting Snappy daemon...

What changed ? Two weeks ago it run flawlesslly, but now it seems that ubuntu image is broken.
FYI, I updated my gadget with latest commits to branch 18.

Ok, I found what was an issue here. One of attached snaps had an error with a hook, but it was not really shown anywhere. Therefore, I think you can close this topic :slight_smile:

Yes, if snapd fails to seed due to an issue with one of the snaps in your image, then the snap command will not be on the $PATH. I do think it would be good to have better logging or otherwise bubbling up to the user from snapd about what failed/went wrong when this kind of thing happens.

1 Like