did your ubuntu-image command finish without any errors when you built the image btw ?
i’d actually expect snap prepare-image which is the function ubuntu-image calls internally to seed the snaps to fall over if it cant set a revision …
Well, I do get warnings about my snaps being installed from local snaps, but other than that, no.
WARNING: "kernel", "gadget", "base-files", "device-config" installed from local snaps disconnected from a store cannot be refreshed subsequently!
Copying "kernel/kernel_5.4_armhf.snap" (kernel)
Copying "gadget/gadget_0.1_armhf.snap" (gadget)
Copying "base-files/base-files_0.1_armhf.snap" (base-files)
Copying "device-config/device-config_0.1_armhf.snap" (device-config)
The command I use to build is ubuntu-image snap. What does snap prepare-image do differently?
yeah, the warnings look pretty normal, nothing special in there …
snap prepare-image it is an internally used command by ubuntu-image.
IIRC (@ijohnson may correct me) it creates the initial seed file that is then used when installing the snaps on first boot.
mmm the unset kernel revision may be a red herring here, see this message:
Jun 12 13:06:40 localhost snapd[3180]: devicestate.go:177: installing unasserted kernel "kernel"
which implies that snapd is installing the kernel snap fine. I have seen the prior message show up on successful boots, so that is possibly not your issue. Probably it’s a bug that that message shows up on the working installs I’ve seen, so it could be a bug that this message is showing up on your system when you have a perfectly fine working kernel snap in the seed. This message is very interesting though:
Jun 12 13:07:42 localhost snapd[3180]: udevmon.go:149: udev event error: Unable to parse uevent, err: no buffer space available
That may actually be the cause of your issue.
Can you try the following:
- unsquashfs the core18 snap again
- edit squashfs-root/etc/environment to add SNAPD_DEBUG=1
- re-squashfs the core18 snap
- build a fresh image with this core18 snap
- boot the image and get snapd logs again
1 Like
Sorry this took so long, I was in a meeting.
Here’s what I got:
Sorry for asking a dumb question but what exactly is the problem we are solving here again? Is it just that there is a message about “cannot find installed snap …” ? I don’t see any problems in your snapd log except maybe a network issue at the end with:
Jun 12 19:22:33 awesomedevicecore18 snapd[3176]: retry.go:61: DEBUG: The retry loop for https://api.snapcraft.io/api/v1/snaps/names?confinement=strict finished after 1 retries, elapsed time=1.115604133s, status: too many requests
which actually may be normal with a catalog refresh, I’m not sure.
It takes 10 minutes for this box to boot up for the first time, and that is seemingly due to serial-getty timing out 8 times. I don’t know why that happens, but I figured it was related to the error in the title of this thread, so I asked about it. I think I have another forum post about specifically the serial-getty errors, which, though I thought I fixed them by updating the kernel, they simply occur later in boot.
By boot up do you mean it takes 10 minutes for console-conf to run? Or something else?
Also can you get a root shell again and after the 10 minutes do snap debug timings 1 and snap debug timings 2?
I mean it takes 10 minutes or so for me to land on the Press enter to configure... menu over serial.
Please hold for commands…
Here are the debug timings.
You have quite a ton of snaps pre-installed … if this is an arm CPU from the slower category then a few minutes for the initial snap seeding are not actually unusual …
a pi2/3 with only the three default snaps (kernel, gaget, core18) can easily take up to 1.5-2min for the firstboot seeding … each subsequent additional snap will add to this because checksums are processed here … less cores and slower speed will add to this …
I understand that, of course, but considering the errors we’re getting, something has got to be amiss. Why does serial getty time out over and over again? Why does snapd try to pull from a nonexistent config file and then crash? Why is netplan spewing garbage unless I intervene with an iron fist?
On Core16, initial boot took 2 maybe 3 minutes and had none of these issues.
From your debug timings, it seems that your device on UC18 took about 3 minutes (198102 milliseconds to be exact) to seed and do other first boot things. So if you’re saying that console-conf doesn’t show up until the 10 minute mark, then likely there is some other bug causing the additional 7 minute delay.
1 Like
Can you run systemd-analyze critical-chain serial-getty@ttyS0.service ? or whatever serial port you have at the 10 minute mark when it is available ?
serial-getty@ttymxc1.service @3min 24.304s
└─systemd-user-sessions.service @20.533s +58ms
└─network.target @20.488s
└─wpa_supplicant.service @19.218s +1.233s
└─dbus.service @18.768s
└─basic.target @18.727s
└─sockets.target @18.697s
└─snapd.socket @1min 10.089s +39ms
└─sysinit.target @18.603s
└─systemd-timesyncd.service @17.956s +567ms
└─systemd-tmpfiles-setup.service @12.161s +668ms
└─local-fs.target @12.062s
└─run-snapd-ns-awesomedevice\x2ddevice\x2dconfig.mnt.mount @4min 49.099s
└─run-snapd-ns.mount @2min 47.404s
└─local-fs-pre.target @3.831s
└─systemd-tmpfiles-setup-dev.service @3.558s +194ms
└─kmod-static-nodes.service @3.208s +290ms
└─systemd-journald.socket @2.558s
└─system.slice @2.529s
└─-.slice @2.138s
I won’t pretend like I know what this means, but I’m seeing a few 2m, 3m, and 4m entries in here…
note that the @ values mean “the point where it was attempted to start it”, the second value is actually the startup time the process took to start then …
1 Like
what about running
systemctl list-dependencies serial-getty@ttymxc1.service
?
serial-getty@ttymxc1.service
● ├─dev-ttymxc1.device
● ├─system-serial\x2dgetty.slice
● └─sysinit.target
● ├─apparmor.service
● ├─dev-hugepages.mount
● ├─dev-mqueue.mount
● ├─kmod-static-nodes.service
● ├─proc-sys-fs-binfmt_misc.automount
● ├─sys-fs-fuse-connections.mount
● ├─sys-kernel-config.mount
● ├─sys-kernel-debug.mount
● ├─systemd-ask-password-console.path
● ├─systemd-binfmt.service
● ├─systemd-hwdb-update.service
● ├─systemd-journal-flush.service
● ├─systemd-journald.service
● ├─systemd-machine-id-commit.service
● ├─systemd-modules-load.service
● ├─systemd-random-seed.service
● ├─systemd-sysctl.service
● ├─systemd-timesyncd.service
● ├─systemd-tmpfiles-setup-dev.service
● ├─systemd-tmpfiles-setup.service
● ├─systemd-udev-trigger.service
● ├─systemd-udevd.service
● ├─systemd-update-utmp.service
● ├─cryptsetup.target
● ├─local-fs.target
● │ ├─-.mount
● │ ├─boot-uboot.mount
● │ ├─home.mount
● │ ├─media.mount
● │ ├─mnt.mount
● │ ├─root.mount
● │ ├─snap.mount
● │ ├─systemd-remount-fs.service
● │ ├─tmp.mount
● │ ├─var-cache.mount
● │ ├─var-lib-cloud.mount
● │ ├─var-lib-console\x2dconf.mount
● │ ├─var-lib-dbus.mount
● │ ├─var-lib-dhcp.mount
● │ ├─var-lib-extrausers.mount
● │ ├─var-lib-misc.mount
● │ ├─var-lib-private-systemd.mount
● │ ├─var-lib-snapd.mount
● │ ├─var-lib-sudo.mount
● │ ├─var-lib-systemd.mount
● │ ├─var-log.mount
● │ ├─var-snap.mount
● │ ├─var-tmp.mount
● │ └─writable.mount
● └─swap.target
could you upload somewhere the full svg of systemd-analyze plot ? it seems something not in the direct dependencies of console-conf is being slow. What I do is:
systemd-analyze plot > file.svg
and then upload file.svg in it’s entirety. If you convert to a jpeg or something then all the little details will be lost 
alternatively (and since you pre-install the device-confg snap anyway) you could try building an image with console-conf disabled by handing the --disable-console-conf option to ubuntu-image
1 Like