snapd slow to seed firefox on Pi 400

Oh good grief, not 10 seconds after submitting this, snapd apparently got itself sorted out and firefox appeared (bear in mind this is a good 10 minutes after the first boot). Will investigate a bit further ...

This bug has been reported on the Ubuntu ISO testing tracker.

A list of all reports related to this bug can be found here:
http://iso.qa.ubuntu.com/qatracker/reports/bugs/1969529

Hi Dave, and thanks for reporting this. As you wrote about the "10 minutes", a bell rang in my head. :-)

Could it be the same issue as https://bugs.launchpad.net/ubuntu/+source/snapd/+bug/1969162? The problem is that I don't think this should happen on a fresh install -- but on the other hand, I don't know exactly what operations happen on a newly installed system, so it may be that's related.

Unfortunately I don't have access to the OOPS pages so I can't see the error details, but maybe you can have a look at the other bug and report back in case you notice some common patterns?

I've semi-replicated this, but it seems extremely variable and I haven't managed to come up with a working theory as to why. To be clear, the pattern of behaviour (from the perspective of the user) is:

* After initial setup, the login screen appears
* Users logs in
* Desktop appears with Firefox icon at the top of the launcher
* Shortly after this, the Firefox icon disappears (presumably as the snap refreshes?)
* ... long/short delay depending on ... something?
* Firefox icon re-appears

The delay doesn't seem to depend on RAM size: I didn't notice more than 4 minutes delay on a Pi4 2GB I tested the desktop image upon, whilst on a Pi4 8GB it took nearly 5 minutes. The longest delay I've seen subsequently was again on a Pi 400 (though I suspect at this point that was coincidence): ~6.5 minutes after login. It seems to generate a good number of OOPS reports while it's working too (for various things from firefox to core20, to snap-store):

https://errors.ubuntu.com/oops/5282dabd-c09e-11ec-8aed-fa163e993415
https://errors.ubuntu.com/oops/5e1cb50a-c09e-11ec-a3ba-fa163ef35206
https://errors.ubuntu.com/oops/6a1c1232-c09e-11ec-8aed-fa163e993415
https://errors.ubuntu.com/oops/6ed94b82-c09e-11ec-8aed-fa163e993415
https://errors.ubuntu.com/oops/78595ebe-c09e-11ec-8aed-fa163e993415
https://errors.ubuntu.com/oops/79c2d416-c09e-11ec-8aed-fa163e993415
https://errors.ubuntu.com/oops/7c5eeb47-c09e-11ec-9915-fa163e55efd0
https://errors.ubuntu.com/oops/80a0df66-c09e-11ec-a3ba-fa163ef35206

@mardy I've granted you access to the Error Tracker.

Thanks Brian! :-)

Hello again, Dave! Looking at the logs, it doesn't seem that your problem is related to bug 1969162.

What I'm left to suspect is a storage issue, since there are many errors about files failing to load in the logs. I've had similar issues with a RPi3, where I had to flash the same Ubuntu image over the SD card a couple of times before the boot succeeded. Would you mind trying the same?
That is, just reflash the image a couple of times, and only afterwards you try booting.

Changing the title to "slow" instead of "fails" as it appears this always resolves in practice, but the length of time to initialize is certainly a sub-optimal user experience.

@mardy I would be very surprised if SD card corruption was the issue here. The cards I'm using for test have had no issues booting any of the images so far (and typically whenever I've seen SD corruption before it's usually pretty obvious from boot time).

Which I/O errors in the logs have caught your attention, particularly? Some are "expected" unfortunately. For example:

Apr 20 12:23:25 localhost.localdomain systemd-modules-load[318]: Failed to find module 'ipmi-devintf'

This is because that modules is not included in the stripped down linux-modules package from linux-raspi.

Apr 20 12:23:29 localhost.localdomain kernel: brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43456-sdio.raspberrypi,400.bin failed with error -2

This one is because the wifi firmware blob first tries to load a device-specific configuration (the "raspberrypi,400" bit in the filename) and falls back to a generic configuration if no device-specific one is found (unfortunately it falls back rather noisily!).

Apr 20 12:25:02 localhost.localdomain pulseaudio[832]: Failed to load module "module-alsa-card" (argument: "device_id="1" name="platform-fef05700.hdmi" card_name="alsa_card.platform-fef05700.hdmi" namereg_fail=false tsched=yes fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes avoid_resampling=no card_properties="module-udev-detect.discovered=1""): initialization failed.

I forget the reason for this one, but it's another of "expected" errors we see on the Pi (but audio still works happily so cleaning the false report up hasn't been a high priority).

Anyway, I'll try another replication later today and see if I can gather any more info. Thanks for you attention!

Hi Dave, I did not see any I/O errors from the kernel, but in your first boot log (https://errors.ubuntu.com/oops/fa9433d0-c022-11ec-8ae0-fa163e993415) there are plenty of errors which might be related to missing files:

=======
Apr 19 21:46:38 localhost.localdomain pulseaudio[841]: Failed to load module "module-alsa-card" (argument: "device_id="1" name="platform-fef05700.hdmi" card_name="alsa_card.platform-fef05700.hdmi" namereg_fail=false tsched=yes fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes avoid_resampling=no card_properties="module-udev-detect.discovered=1""): initialization failed.
...
Apr 19 21:46:42 localhost.localdomain udisksd[985]: failed to load module mdraid: libbd_mdraid.so.2: cannot open shared object file: No such file or directory
...
Apr 19 21:53:20 miss-piggy pipewire-media-session[840]: ms.core: error id:0 seq:701 res:-32 (Broken pipe): connection error
Apr 19 21:53:21 miss-piggy accounts-daemon[934]: failed to check if user 'oem' in cache dir is present on system: No such file or directory
Apr 19 21:53:21 miss-piggy tracker-miner-f[970]: Could not delete '.meta.isrunning': No such file or directory
...
Apr 19 21:53:31 miss-piggy pulseaudio[34513]: Failed to open cookie file '/var/lib/gdm3/.config/pulse/cookie': No such file or directory
=======

plus plenty of driver initialization errors; but on the other hand, it may be that all of that is normal -- I just wanted to make sure that we don't have to deal with a corrupted image.

Ubuntu 22.10 (Kinetic Kudu) has reached end of life, so this bug will not be fixed for that specific release.