snapd.seeded.service taking over 2 minutes to initialise (kernel crng regression?)

[Broadsworde]

Following a regular dist-upgrade on Ubuntu 18.04 this morning, reboot and further reboots were hanging for minutes rather than seconds on the Ubuntu splash screen before getting to login.

Initial system analysis:
$ sudo systemd-analyze blame
3min 53.073s plymouth-quit-wait.service
    2min 20.699s snapd.seeded.service
         49.949s snapd.service
          6.186s NetworkManager-wait-online.service
          1.148s dev-sda2.device
          1.098s plymouth-start.service

Drill down on snapd.seeded.service
$ journalctl -u snapd.seeded.service --since today
-- Logs begin at Fri 2018-04-27 13:01:30 BST, end at Tue 2018-07-03 12:42:14 BST. --
(BEFORE UPGRADE)
Jul 03 04:15:43 user-laptop systemd[1]: Starting Wait until snapd is fully seeded...
Jul 03 04:15:43 user-laptop systemd[1]: Started Wait until snapd is fully seeded.
Jul 03 04:21:03 user-laptop systemd[1]: Stopped Wait until snapd is fully seeded.
(/BEFORE UPGRADE)
-- Reboot --
(AFTER UPGRADE)
Jul 03 04:22:47 user-laptop systemd[1]: Starting Wait until snapd is fully seeded...
Jul 03 04:24:49 user-laptop systemd[1]: Started Wait until snapd is fully seeded.
Jul 03 04:26:23 user-laptop systemd[1]: Stopped Wait until snapd is fully seeded.
-- Reboot --
Jul 03 04:28:17 user-laptop systemd[1]: Starting Wait until snapd is fully seeded...
Jul 03 04:30:44 user-laptop systemd[1]: Started Wait until snapd is fully seeded.
Jul 03 10:23:14 user-laptop systemd[1]: Stopped Wait until snapd is fully seeded.
-- Reboot --
Jul 03 10:29:30 user-laptop systemd[1]: Starting Wait until snapd is fully seeded...
Jul 03 10:31:50 user-laptop systemd[1]: Started Wait until snapd is fully seeded.
(/AFTER UPGRADE)

I reported this issue on AskUbuntu, and it was suggested to me to report a possible snapd bug due to the extended seeding time compared to before the upgrade.

The dist-upgrade installed/upgraded:

Install: linux-headers-4.15.0-24:amd64 (4.15.0-24.26, automatic), linux-headers-4.15.0-24-generic:amd64 (4.15.0-24.26, automatic), linux-modules-extra-4.15.0-24-generic:amd64 (4.15.0-24.26, automatic), linux-modules-4.15.0-24-generic:amd64 (4.15.0-24.26, automatic), linux-image-4.15.0-24-generic:amd64 (4.15.0-24.26, automatic)
Upgrade: gnome-control-center-data:amd64 (1:3.28.1-0ubuntu1.18.04.1, 1:3.28.1-0ubuntu1.18.04.2), linux-headers-generic:amd64 (4.15.0.23.25, 4.15.0.24.26), gnome-control-center:amd64 (1:3.28.1-0ubuntu1.18.04.1, 1:3.28.1-0ubuntu1.18.04.2), linux-image-generic:amd64 (4.15.0.23.25, 4.15.0.24.26), linux-signed-generic:amd64 (4.15.0.23.25, 4.15.0.24.26), gnome-control-center-faces:amd64 (1:3.28.1-0ubuntu1.18.04.1, 1:3.28.1-0ubuntu1.18.04.2), linux-generic:amd64 (4.15.0.23.25, 4.15.0.24.26)

UPDATE (2018-07-05)

This morning's Boot:
$ sudo systemd-analyze blame
         14.161s apt-daily.service
          6.177s NetworkManager-wait-online.service
          3.452s plymouth-quit-wait.service
          1.252s dev-sda2.device
          1.091s plymouth-start.service
          .
          .
          .
          24ms snapd.seeded.service

[Craig (craigtlandry)]

I had this problem this morning as well after a reboot following a kernel upgrade to 4.15.0-24-generic on an existing 18.04 fresh install.

[Nicolás Martín (nikomartn2)]

Same problem here, systemd-analyze blame returns:
10min 796ms plymouth-quit-wait.service
    8min 31.010s snapd.seeded.service

[keypey (krzysztof-pastor)]

Same problem:
$ uname -a

Linux X220 4.15.0-24-generic #26-Ubuntu SMP Wed Jun 13 08:44:47 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

$ systemd-analyze blame

    2min 32.751s snapd.seeded.service
     1min 2.002s snapd.service
          4.821s NetworkManager-wait-online.service

[Juan Manuel Vicente (juanma-v82)]

Here the same:

> uname -a
Linux 4.15.0-24-generic #26-Ubuntu SMP Wed Jun 13 08:44:47 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

> sudo systemd-analyze blame
    4min 35.945s plymouth-quit-wait.service
    1min 36.522s snapd.seeded.service
         21.630s NetworkManager-wait-online.service
          5.770s snapd.service
          1.424s plymouth-start.service
           994ms dev-sda2.device

[David Spoelstra (davids-mediamachine)]

Same problem:

$ uname -a
Linux 4.15.0-24-generic #26-Ubuntu SMP Wed Jun 13 08:44:47 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

$ systemd-analyze blame
    5min 27.825s plymouth-quit-wait.service
    3min 58.262s snapd.seeded.service
         57.012s snapd.service
          4.868s NetworkManager-wait-online.service

[Konstantinos Papadopoulos (konstantinos.papadopoulos)]

I confirm the same problem

uname -a

Linux thinkPad-t410 4.15.0-24-generic #26-Ubuntu SMP Wed Jun 13 08:44:47 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

systemd-analyze time

Startup finished in 3.690s (kernel) + 2min 11.086s (userspace) = 2min 14.776s
graphical.target reached after 2min 11.076s in userspace

         39.283s snapd.seeded.service
         39.031s snapd.service
          6.432s NetworkManager-wait-online.service
          6.140s apt-daily-upgrade.service
          1.210s dev-sda6.device

[gnoom (seb-gnoom)]

I cofirm with 2 computers (laptop & desktop).
temporary, I boot on 4.15.0-20-generic (thanks to grub-customizer) and I've remove 4.15.0-24-generic with : sudo apt purge linux-image-4.15.0-24-generic linux-headers-4.15.0-24*

PS : the problem persist with 4.15.0-25-generic.

seb.

[sudodus (nio-wiklund)]

This bug affected my Ubuntu 18.04 LTS system the first time I booted after upgrading the kernel. But the second and third times I booted, it no longer affected my Ubuntu.

The computer is a Dell Precision M4800, and I run a rather basic system, of fully up to date after

sudo apt update
sudo apt full-upgrade

with only a few added program packages (the 'most intrusive' maybe Oracle VirtualBox).

[Angelo Giacomini Ribas (angelo-ribas-adv)]

user@machine:~$ sudo systemd-analyze blame
    7min 50.750s plymouth-quit-wait.service
    6min 17.955s snapd.seeded.service
         15.700s snapd.service
          6.253s NetworkManager-wait-online.service
          1.502s dev-mapper-ubuntu\x2d\x2dvg\x2droot.device
          1.231s dev-loop0.device
          1.223s dev-loop1.device
          1.203s dev-loop2.device
          1.182s dev-loop3.device
           737ms fwupd.service
           265ms networkd-dispatcher.service
           253ms NetworkManager.service
           244ms plymouth-start.service
           230ms apparmor.service
           223ms udisks2.service
           199ms ModemManager.service
           190ms keyboard-setup.service
           182ms systemd-logind.service
           177ms systemd-journal-flush.service
           173ms accounts-daemon.service
           168ms systemd-udev-trigger.service
           149ms systemd-rfkill.service
           132ms speech-dispatcher.service
           127ms apport.service
           125ms systemd-timesyncd.service
           123ms avahi-daemon.service
           122ms systemd-resolved.service
           112ms bluetooth.service
           109ms packagekit.service
           109ms systemd-journald.service
           106ms grub-common.service
            99ms lvm2-pvscan@8:1.service
            95ms lvm2-monitor.service
            93ms wpa_supplicant.service
            89ms upower.service
            85ms thermald.service
            81ms networking.service
            81ms pppd-dns.service
lines 1-38

However, interestingly, if I move mouse while booting, the output differs greatly:

user@machine:~$ sudo systemd-analyze blame
          6.294s NetworkManager-wait-online.service
          4.453s plymouth-quit-wait.service
          1.474s dev-mapper-ubuntu\x2d\x2dvg\x2droot.device
          1.257s dev-loop0.device
          1.246s dev-loop1.device
          1.227s dev-loop2.device
          1.204s dev-loop3.device
          1.060s snapd.service
           749ms fwupd.service
           410ms apparmor.service
           333ms networkd-dispatcher.service
           327ms udisks2.service
           255ms NetworkManager.service
           247ms plymouth-start.service
           216ms ModemManager.service
           199ms systemd-rfkill.service
           195ms accounts-daemon.service
           190ms systemd-journal-flush.service
           168ms systemd-logind.service
           157ms systemd-timesyncd.service
           154ms keyboard-setup.service
           150ms systemd-resolved.service
           137ms systemd-udev-trigger.service
           122ms thermald.service
           110ms grub-common.service
           109ms avahi-daemon.service
           106ms wpa_supplicant.service
           103ms systemd-journald.service
           102ms apport.service
           102ms bluetooth.service
            97ms packagekit.service
            94ms networking.service
            93ms upower.service
            90ms lvm2-pvscan@8:1.service
            90ms lvm2-monitor.service
            83ms gpu-manager.service

[David Longe (david-longe)]

Also getting the same long boot times since installing a system update 2 days ago. A fresh install didn't correct the issue.

sudo systemd-analyze blame

    3min 39.439s plymouth-quit-wait.service
    2min 10.237s snapd.seeded.service
         39.485s snapd.service
          6.305s NetworkManager-wait-online.service
          2.247s dev-sda1.device
          1.760s dev-loop5.device
          1.757s dev-loop2.device
          1.755s dev-loop3.device
          1.747s dev-loop6.device
          1.745s dev-loop1.device
          1.743s dev-loop7.device
          1.711s dev-loop0.device
          1.705s dev-loop4.device
          1.671s dev-loop10.device
          1.657s dev-loop8.device
          1.654s dev-loop9.device
          1.648s dev-loop11.device
          1.608s systemd-rfkill.service
          1.578s dev-loop12.device
          1.066s udisks2.service
           908ms NetworkManager.service
           878ms fwupd.service
           527ms systemd-journal-flush.service

[Robin (r-ehl)]

Same problem but possible workaround: Following this advice (https://askubuntu.com/a/1052042/94570) that some process is waiting for random numbers, I pressed multiple keys and the startup process was terminated almost instantly.
Perhaps it works for you, too in the meantime.

[Guilherme G. Piccoli (gpiccoli)]

This issue seems fixed in the new Ubuntu 18.04 kernel, version "4.15.0-26".
It's available now in the -proposed repo.

See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed.

Any tests with this new kernel would be appreciated.
Thanks,

Guilherme

[Xaositek (applewiz)]

Confirmed - I just testing on Ubuntu 18.04, prior boot times were 10+ minutes or until a couple keys were pressed on the keyboard. Boot times are now under 10 seconds.

Thank you!

[Gábor Udvari (gabor-udvari)]

@Guilherme, I can confirm that the proposed kernel version "4.15.0-26" fixes the issue.

With 4.15.0-24:
sudo systemd-analyze blame
         3min 3.733s plymouth-quit-wait.service
        1min 28.476s snapd.seeded.service
        1min 28.225s snapd.service
              6.280s NetworkManager-wait-online.service
              1.134s apt-daily.service

With 4.15.0-26:
sudo systemd-analyze blame
              6.298s NetworkManager-wait-online.service
              5.914s plymouth-quit-wait.service
              1.151s dev-sda2.device
               803ms fwupd.service
               623ms systemd-journal-flush.service

[Guilherme G. Piccoli (gpiccoli)]

Thanks for all testing done here.

@Broadsworde, you've updated the description in 2018-07-05 saying the system seems to be booting fine, so can you check your kernel version?

Ubuntu kernel team downgraded the kernel to 4.15.0-23 in the regular repos and released the 4.15.0-26 in the -proposed repo (which will be available in the regular -updates repo soon, after more testing - expectation is to be there July/30th).

[Guilherme G. Piccoli (gpiccoli)]

The fix is available in the current kernel, according to this mailing-list thread: https://lists.ubuntu.com/archives/ubuntu-security-announce/2018-July/004503.html

Kernel version was bumped and now the correct version with the fix is: 4.15.0-29

Cheers,

Guilherme

[David Spoelstra (davids-mediamachine)]

The new kernel fixes it for me!

[Matthew Eaton (meaton)]

Fixed for me as well in 4.15.0-29.

[Stu (stu-axon)]

Still seems to be taking quite a bit longer than I'd expect (this is off an SSD)

systemd-analyze blame | head
         15.141s snapd.service
          7.942s NetworkManager-wait-online.service
          7.882s [e-mail]
          4.161s plymouth-quit-wait.service
          3.791s apparmor.service
          1.638s apt-daily.service
          1.367s systemd-udev-settle.service
          1.045s winbind.service
           725ms snap-gnome\x2d3\x2d26\x2d1604-62.mount
           628ms snap-core-5624.mount

[Guilherme G. Piccoli (gpiccoli)]

What kernel version are you using Stu?