no, this is an internal feature of snapd i think … you need to find out where your kernel snap or model assertion are wrong providing the necessary info snapd bases this behaviour on …
Okay, then. Lemme do some digging. Thanks so much for your help!
if you’re able to configure the kernel command line while booting, you could add systemd.debug-shell=1 to the kernel command line and then switch to the debug shell (on a real hw system) with ALT+F9. If you can do this, then the output of ls /snap and /snap/snapd/current/usr/bin/snap debug state /var/lib/snapd/state.json would be helpful. If /snap/snapd/current doesn’t exist but /snap/snapd/<number> does, just replace current with that. If you don’t have anything in /snap/snapd/ then we can go from there to have you mount the snapd snap to run the snap debug command.
I believe my options for accessing the shell on this particular box are over serial and over ssh, and it’s U-Boot, so I’m not sure how to add command line args. Any advice on that front?
in your gadget … since you need to ship a uboot.env{.in} you should be able to do all hardware specific bits and overrides in there (including the cmdline)…
Fair point, I was looking for a way to avoid that, though, since that takes a few minutes longer 
Hmm, if you only have a serial port and you’re hacking anyways, what you could do is unsquashfs the core18 snap and replace /usr/share/subiquity/console-conf-wrapper with a shell script like this:
#!/bin/sh
exec /bin/bash
That will give you a root shell over serial to run the commands I had above.
I do have root SSH, and I managed to drop the debug env variable in there, now I just need to access the debug shell. Which I’m not entirely sure how to do over ssh. Are you saying we can get what we need specifically via serial?
This probably isn’t helpful, but over a non-debug shell, I got
root@core18device:/home/core18device# ls /snap
README bin core18 base-files gadget kernel modem-manager network-manager node-red snapd device-config
and
ID Status Spawn Ready Label Summary
1 Done today at 18:15 UTC today at 18:19 UTC seed Initialize system state
2 Doing today at 18:19 UTC 0001-01-01 become-operational Initialize device
ah perfect, can you show the output of
/snap/snapd/current/usr/bin/snap debug state --change=2 /var/lib/snapd/state.json0 140 Done today at 18:19 UTC today at 18:19 UTC run-hook Run prepare-device hook
0 141 Done today at 18:19 UTC today at 18:20 UTC generate-device-key Generate device key
0 142 Doing today at 18:19 UTC 0001-01-01 request-serial Request device serial
Hmm, actually can show the output from --change=1 ?
It’s just hanging. No output. 
This command should not actually hang, if it’s taking a while with no output it’s probably just very slow. This command has a few performance issues so it will most likely take a few minutes for it to run unfortunately.
1 Like
We are now 35 minutes deep into this command. What is it doing? 
I’m really confused how it could be stuck, but bugs are a possibility here I suppose…
What is the size of the /var/lib/snapd/state.json file?
120K reported by du -h.
Weather Update:
I tried unpacking the snap, manually dropping the snap.yaml into kernel/unset/meta/snap.yaml and repacking it (like this), but it had no effect, because I noticed that for some reason, snapd was looking for the file, not in /snap/kernel/x1/ or /snap/kernel/current, but just in the /snap/kernel/ directory, which (and this is an uneducated guess) would never contain that file. Though, things might be different on initial boot.
There’s no way this is a bug, is it?
well, since all other images work it is unlikely to be a bug …
it could be an issue with your model assertion, the kernel itself or the gadget …
Since you have a root shell could you get journal logs for snapd and paste them here as well? i.e. journalctl -e --no-pager -u snapd ?
-- Logs begin at Fri 2020-06-12 13:04:39 UTC, end at Fri 2020-06-12 15:22:45 UTC. --
Jun 12 13:06:15 localhost systemd[1]: Starting Snap Daemon...
Jun 12 13:06:15 localhost snapd[3144]: AppArmor status: apparmor not enabled
Jun 12 13:06:15 localhost snapd[3144]: patch.go:64: Patching system state level 6 to sublevel 1...
Jun 12 13:06:15 localhost snapd[3144]: patch.go:64: Patching system state level 6 to sublevel 2...
Jun 12 13:06:15 localhost snapd[3144]: patch.go:64: Patching system state level 6 to sublevel 3...
Jun 12 13:06:15 localhost snapd[3144]: daemon.go:343: started snapd/2.45 (series 16; devmode) ubuntu-core/18 (armhf) linux/5.4.45-dirty.
Jun 12 13:06:16 localhost snapd[3144]: daemon.go:436: adjusting startup timeout by 30s (pessimistic estimate of 30s plus 5s per snap)
Jun 12 13:06:16 localhost snapd[3144]: helpers.go:961: cannot retrieve info for snap "kernel": cannot find installed snap "kernel" at revision unset: missing file /snap/kernel/unset/meta/snap.yaml
Jun 12 13:06:16 localhost systemd[1]: Started Snap Daemon.
Jun 12 13:06:19 localhost snapd[3144]: daemon.go:542: gracefully waiting for running hooks
Jun 12 13:06:19 localhost snapd[3144]: daemon.go:544: done waiting for running hooks
Jun 12 13:06:29 localhost systemd[1]: snapd.service: Service hold-off time over, scheduling restart.
Jun 12 13:06:29 localhost systemd[1]: snapd.service: Scheduled restart job, restart counter is at 1.
Jun 12 13:06:29 localhost systemd[1]: Stopped Snap Daemon.
Jun 12 13:06:29 localhost systemd[1]: Starting Snap Daemon...
Jun 12 13:06:29 localhost snapd[3180]: AppArmor status: apparmor not enabled
Jun 12 13:06:29 localhost snapd[3180]: daemon.go:343: started snapd/2.45 (series 16; devmode) ubuntu-core/18 (armhf) linux/5.4.45-dirty.
Jun 12 13:06:29 localhost snapd[3180]: daemon.go:436: adjusting startup timeout by 35s (pessimistic estimate of 30s plus 5s per snap)
Jun 12 13:06:29 localhost snapd[3180]: helpers.go:961: cannot retrieve info for snap "kernel": cannot find installed snap "kernel" at revision unset: missing file /snap/kernel/unset/meta/snap.yaml
Jun 12 13:06:30 localhost systemd[1]: Started Snap Daemon.
Jun 12 13:06:40 localhost snapd[3180]: devicestate.go:177: installing unasserted kernel "kernel"
Jun 12 13:07:10 localhost snapd[3180]: devicestate.go:177: installing unasserted gadget "gadget"
Jun 12 13:07:42 localhost snapd[3180]: udevmon.go:149: udev event error: Unable to parse uevent, err: no buffer space available
Jun 12 13:08:20 localhost snapd[3180]: udevmon.go:149: udev event error: Unable to parse uevent, err: no buffer space available
Jun 12 13:08:37 localhost modprobe[3720]: FATAL: Module arp_tables not found in directory /lib/modules/5.4.45-dirty
Jun 12 13:09:27 localhost snapd[3180]: udevmon.go:149: udev event error: Unable to parse uevent, err: no buffer space available
Jun 12 13:11:03 localhost sudo[5889]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm /etc/netplan/00-snapd-config.yaml
Jun 12 13:11:03 localhost sudo[5889]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jun 12 13:11:03 localhost sudo[5889]: pam_unix(sudo:session): session closed for user root
Jun 12 13:11:03 localhost sudo[5891]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/cat
Jun 12 13:11:03 localhost sudo[5891]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jun 12 13:11:03 localhost sudo[5891]: pam_unix(sudo:session): session closed for user root
Jun 12 13:11:03 localhost sudo[5893]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/netplan apply
Jun 12 13:11:03 localhost sudo[5893]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jun 12 13:11:20 localhost.localdomain sudo[5893]: pam_unix(sudo:session): session closed for user root
Jun 12 13:11:20 localhost.localdomain sudo[6053]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/su -c useradd --extrausers testuserboi -s /bin/bash -m
Jun 12 13:11:20 localhost.localdomain sudo[6053]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jun 12 13:11:21 localhost.localdomain su[6059]: Successful su for root by root
Also, I had the idea of looking into the source code to see where the error is being thrown.
So I went and had a look at the snapd source code, and found the line that prints the error message Jun 12 13:06:16 localhost snapd[3144]: helpers.go:961: cannot retrieve info for snap... // yada yada yada and it looks like the function that prints it is snapsWithSecurityProfiles(). There’s a comment at the top that says,
// snapsWithSecurityProfiles returns all snaps that have active
// security profiles: these are either snaps that are active, or about
// to be active (pending link-snap) with a done setup-profiles
IDK if this’ll lead to anything but I guess it’s another thing to learn about.