Slow Startup Pop_OS! 20.04

I believe Snapd is the culprit for my slow starts on my SSD-based 20.04 install.

    systemd-analyze critical-chain
    The time when unit became active or started is printed after the "@" character.
    The time the unit took to start is printed after the "+" character.

    graphical.target @1min 37.472s
    └─multi-user.target @1min 37.472s
      └─snapd.seeded.service @1min 32.099s +28ms
        └─snapd.service @1min 30.687s +1.410s
          └─basic.target @1min 30.640s
            └─sockets.target @1min 30.640s
              └─snapd.socket @1min 30.640s +584us
                └─sysinit.target @1min 30.631s
                  └─systemd-timesyncd.service @3.280s +446ms
                    └─systemd-tmpfiles-setup.service @3.208s +62ms
                      └─local-fs.target @3.190s
                        └─run-user-110-gvfs.mount @1min 32.192s
                          └─run-user-110.mount @1min 31.677s
                            └─local-fs-pre.target @584ms
                              └─lvm2-monitor.service @489ms +95ms
                                └─systemd-journald.socket @481ms
                                  └─system.slice @478ms
                                    └─-.slice @478ms

apt list snapd
Listing... Done
snapd/focal,now 2.44.3+20.04 amd64 [installed]

snap version
snap    2.45
snapd   2.45
series  16
pop     20.04
kernel  5.4.0-7634-generic


systemd-detect-virt
none

Apologies for my ignorance (this stuff confuses me), but doesn’t that say that snapd took about 1 and a half seconds to start?

Confused too. Perhaps I read this wrong.

You read it correctly.

I don’t know how anything can take a 1min to start on SSD even if that drive isn’t the fastest one. Also not only snap related services take more than one minute on your install. Maybe the problem lies in something else than snap.

Take a look for example at “run-user-110-gvfs.mount @1min 32.192s” and “run-user-110.mount @1min 31.677s” they both take as much time as the snap services.

On my installation of Ubuntu 20.04 LTS started today it looks like this:

$ systemd-analyze critical-chain
The time when unit became active or started is printed after the "@" character.
The time the unit took to start is printed after the "+" character.

graphical.target @4.879s
└─multi-user.target @4.879s
  └─snapd.seeded.service @3.170s +15ms
    └─snapd.service @1.965s +1.203s
      └─basic.target @1.909s
        └─sockets.target @1.909s
          └─snapd.socket @1.908s +553us
            └─sysinit.target @1.903s
              └─systemd-timesyncd.service @1.692s +210ms
                └─systemd-tmpfiles-setup.service @1.658s +32ms
                  └─local-fs.target @1.653s
                    └─run-snapd-ns-canonical\x2dlivepatch.mnt.mount @3.042s
                      └─run-snapd-ns.mount @2.924s
                        └─swap.target @302ms
                          └─swapfile.swap @226ms +75ms
                            └─systemd-remount-fs.service @217ms +8ms
                              └─systemd-journald.socket @209ms
                                └─-.mount @206ms
                                  └─system.slice @206ms
                                    └─-.slice @206ms

And the whole startup:

$ systemd-analyze
Startup finished in 3.230s (kernel) + 12.323s (userspace) = 15.553s 
graphical.target reached after 4.879s in userspace

And I have 27 snaps currently installed.

The help text states that those services start at that time, not that they take that time to start. The text suggests it is the time after the “+” which shows the time a service takes to start. I’ve been doing a bit of searching and haven’t found anything which contradicts this, but the documentation is horribly vague.

Yes you are right I didn’t pay enough attention to that text.

Anyway it still means that graphical target is reached after 1 and half minute and that’s awfully long on SSD.

So does that mean that services which don’t have anything printed with “+” take that long to start. If so than the problem definitely doesn’t come from snapd.

@kendoori Could you also post what sytemd-analyze and systemd-analyze blame show.

I am now of the opinion that this is NOT snap related… but the comments here have helped and if you guys are willing to help me further sherlock this, I appreciate it.

systemd-analyze
Startup finished in 11.606s (firmware) + 608ms (loader) + 7.354s (kernel) + 1min 37.694s (userspace) = 1min 57.264s
graphical.target reached after 1min 37.472s in userspace

systemd-analyze blame
9.488s apt-daily.service
6.338s plymouth-quit-wait.service
3.310s fwupd.service
2.659s dev-sda3.device
1.743s bolt.service
1.410s snapd.service
953ms upower.service
915ms accounts-daemon.service
758ms dev-loop3.device
734ms dev-loop2.device
731ms systemd-logind.service
729ms motd-news.service
699ms dev-loop5.device
689ms dev-loop6.device
683ms snap-snapd-7777.mount
669ms networkd-dispatcher.service
654ms dev-loop4.device
641ms snap-snapd-7264.mount
637ms snap-video\x2ddownloader-403.mount
636ms dev-loop8.device
624ms udisks2.service
595ms snap-scrcpy-221.mount
592ms dev-loop7.device
585ms dev-loop9.device
577ms dev-loop10.device
552ms snap-scrcpy-230.mount
520ms man-db.service
511ms vboxdrv.service
506ms dev-loop11.device
504ms apt-daily-upgrade.service
479ms dev-loop1.device
477ms dev-loop0.device
476ms systemd-resolved.service
461ms dev-loop13.device
454ms NetworkManager.service
446ms systemd-timesyncd.service
445ms dev-loop14.device
441ms dev-loop12.device
435ms systemd-journald.service
421ms snap-snap\x2dstore-415.mount
404ms snap-gtk2\x2dcommon\x2dthemes-9.mount
392ms avahi-daemon.service
387ms snap-video\x2ddownloader-397.mount
387ms bluetooth.service
360ms system76-power.service
349ms switcheroo-control.service
341ms thermald.service
340ms wpa_supplicant.service
276ms snap-core-9066.mount
272ms gpu-manager.service
266ms snap-gnome\x2d3\x2d28\x2d1804-128.mount
246ms systemd-cryptsetup@cryptswap.service
220ms secureboot-db.service
216ms snap-core-9289.mount
215ms tlp.service
193ms snap-breaktimer-23.mount
184ms user@110.service
180ms rsyslog.service
179ms snap-gnome\x2d3\x2d28\x2d1804-116.mount
174ms snap-gtk\x2dcommon\x2dthemes-1506.mount
160ms networking.service
154ms snap-core18-1754.mount
144ms logrotate.service
142ms apport.service
139ms systemd-udev-trigger.service
128ms systemd-udevd.service
120ms e2scrub_reap.service
116ms user@1000.service
113ms apparmor.service
106ms colord.service
95ms lvm2-monitor.service
83ms keyboard-setup.service
82ms media-kenny-T480\x2dPOP\x2dBACKUP.mount
75ms lm-sensors.service
74ms snapd.apparmor.service
65ms ssh.service
65ms gdm.service
62ms systemd-tmpfiles-setup.service
58ms systemd-modules-load.service
51ms systemd-tmpfiles-clean.service
50ms geoclue.service
49ms binfmt-support.service
43ms fwupd-refresh.service
32ms polkit.service
29ms systemd-backlight@backlight:intel_backlight.service
28ms snapd.seeded.service
27ms boot-efi.mount
27ms hddtemp.service
26ms systemd-backlight@leds:tpacpi::kbd_backlight.service
26ms systemd-tmpfiles-setup-dev.service
26ms recovery.mount
26ms systemd-sysusers.service
24ms systemd-sysctl.service
24ms pppd-dns.service
22ms proc-sys-fs-binfmt_misc.mount
22ms systemd-random-seed.service
17ms systemd-remount-fs.service
17ms user-runtime-dir@1000.service
16ms dev-hugepages.mount
16ms dev-mqueue.mount
15ms sys-kernel-debug.mount
15ms systemd-update-utmp.service
15ms sys-kernel-tracing.mount
14ms plymouth-start.service
14ms kmod-static-nodes.service
13ms user-runtime-dir@110.service
13ms blk-availability.service
12ms console-setup.service
11ms systemd-update-utmp-runlevel.service
11ms plymouth-read-write.service
10ms systemd-journal-flush.service
9ms ufw.service
9ms systemd-user-sessions.service
9ms resolvconf-pull-resolved.service
8ms alsa-restore.service
8ms rtkit-daemon.service
7ms openvpn.service
6ms setvtrgb.service
5ms vboxballoonctrl-service.service
5ms vboxautostart-service.service
5ms ifupdown-pre.service
5ms finalrd.service
3ms sys-fs-fuse-connections.mount
3ms sys-kernel-config.mount
3ms e2scrub_all.service
584us snapd.socket

I tried searching for that problem and I’ve found this on Stack Exchange.

https://unix.stackexchange.com/questions/551542/how-can-i-triage-slow-userspace-boot-time

It looks like the problem for this user was related to external USB devices.

Also I wonder if the realtime is really that long. I mean does the time when you start your computer and reach a graphical environment is really 1min 30sec. Maybe those services take time to start in the background and you can actually use your system earlier.

graphical.target reached after 1min 37.472s in userspace

1min 30sec is default time to wait for service to start-up in systemd. My graphical.target is 9.265s. To me this looks like something is blocking boot until it times out.

I believe this is solved. I had another SSD of similar size and cloned to the other drive to eliminate the drive being the problem. The side effect of the cloning is that UUID for the swap didn’t properly match the fstab or crypttab entries. I turned swap off, deleted the swap partition, and removed the entries fstab and crypttab and now we are booting in under 11 seconds!

graphical.target reached after 10.391s in userspace

It is possible the fstab etc… were problems before, but not looking back at this point. Definitely NOT a Snap issue.

1 Like