I noticed my boot times almost doubled (55s~) as I installed more snap programs. How can I troubleshoot this?
Output from systemd-analyze critical-chain and systemd-analyze --user critical-chain https://termbin.com/52ci
Snap version: snap 2.51.7 snapd 2.51.7 series 16 ubuntu 20.04 kernel 5.4.0-88-generic
snapd should not hold back any other services from starting (not even snaps) so even the fact that snapd takes 21s to start should not affect your boot speed … I see another 20s for journal-flush service, that indicates you got rather huge logs … is your disk filled with giant logs (in /var/log/journal) by chance ?
journalctl --disk-usage outputs 120.0M
does sudo du -hcs /var/log/ agree ?
I tried cleaning up with journalctl --vacuum-time=1d, now my boot time has decreased to 42s, but still far from what I used to get before, 28s
output from sudo du -hcs
/var/log/ 23M /var/log 23M total
new output from systemd-analyze critical-chain
I guess from here on we need someone from the snapd team to give more debugging hints, pushing the output of journalcl -b to termbin might be helpful …
24s to start snapd is very long indeed. Can you provide the output of the following commands:
snap debug timings --all --startup ifacemgrsnap changessystemd-analyze blamesnap debug timings --all --startup ifacemgr
2021/10/05 18:11:22.964576 main.go:176: description of prepare-image's "<target-dir>" is lowercase in locale "pt_BR": "o directório de destino"
erro: cannot find startup: ifacemgr
snap changes
2021/10/05 18:08:26.575087 main.go:176: description of prepare-image's "<target-dir>" is lowercase in locale "pt_BR": "o directório de destino"
ID Estado Gerado Pronto Resumo
132 Done ontem às 22:49 -03 ontem às 22:49 -03 Reverter o snap "citra-emu"
133 Done ontem às 22:55 -03 ontem às 22:55 -03 Actualizar o snap "citra-emu"
134 Done hoje às 10:56 -03 hoje às 10:57 -03 Remover o snap "citra-emu"
135 Done hoje às 10:58 -03 hoje às 10:59 -03 Instalar snap "citra-emu"
136 Done hoje às 12:30 -03 hoje às 12:32 -03 Instalar snap "kdenlive" from "candidate" channel
137 Done hoje às 12:37 -03 hoje às 12:37 -03 Actualizar o snap "kdenlive" do canal "latest/edge"
138 Done hoje às 12:41 -03 hoje às 12:41 -03 Remover o snap "kdenlive"
and systemd-analyze blame
28.377s dev-sda5.device
24.963s snapd.service
19.862s udisks2.service
17.109s dev-loop28.device
16.798s dev-loop20.device
16.748s dev-loop16.device
16.667s dev-loop27.device
16.497s dev-loop24.device
16.440s dev-loop25.device
16.222s dev-loop22.device
15.736s dev-loop18.device
15.691s NetworkManager.service
15.514s dev-loop21.device
15.407s dev-loop26.device
15.342s polkit.service
15.290s dev-loop13.device
15.289s dev-loop12.device
15.288s dev-loop19.device
15.283s dev-loop17.device
15.282s dev-loop15.device
15.238s dev-loop23.device
14.700s systemd-logind.service
13.321s dev-loop3.device
12.953s dev-loop14.device
12.825s dev-loop8.device
12.521s dev-loop2.device
11.434s dev-loop10.device
11.005s dev-loop1.device
10.788s smartmontools.service
10.665s dev-loop9.device
10.440s dev-loop7.device
10.119s dev-loop11.device
9.055s dev-loop6.device
7.118s dev-loop5.device
7.039s dev-loop4.device
6.602s ModemManager.service
6.038s dev-loop0.device
4.445s systemd-udevd.service
4.369s rsyslog.service
3.997s systemd-modules-load.service
3.995s ufw.service
3.933s e2scrub_reap.service
3.810s systemd-journal-flush.service
3.373s packagekit.service
3.312s alsa-restore.service
2.639s apparmor.service
2.354s systemd-resolved.service
2.190s snapd.seeded.service
2.181s grub-common.service
2.002s snap-bare-5.mount
1.941s snap-citra\x2demu-134.mount
1.769s kerneloops.service
1.694s snap-core-11606.mount
1.653s snap-core-11743.mount
1.507s snap-core18-2074.mount
1.477s snap-core18-2128.mount
1.446s snapd.apparmor.service
1.261s snap-core20-1026.mount
1.224s snap-core20-1081.mount
1.133s snap-dolphin\x2demulator-507.mount
1.112s grub-initrd-fallback.service
1.095s snap-dolphin\x2demulator-526.mount
1.042s snap-ffsend-47.mount
1.025s snap-ffsend-48.mount
935ms colord.service
838ms snap-freecad-22.mount
828ms systemd-sysusers.service
801ms snap-gnome\x2d3\x2d28\x2d1804-145.mount
796ms systemd-tmpfiles-setup-dev.service
775ms snap-gnome\x2d3\x2d28\x2d1804-161.mount
729ms snap-gnome\x2d3\x2d34\x2d1804-72.mount
695ms snap-gnome\x2d3\x2d38\x2d2004-76.mount
682ms ua-messaging.service
680ms systemd-tmpfiles-setup.service
672ms plymouth-read-write.service
655ms systemd-sysctl.service
626ms snap-gtk\x2dcommon\x2dthemes-1515.mount
624ms sysstat.service
563ms swapfile.swap
546ms snap-gtk\x2dcommon\x2dthemes-1519.mount
538ms systemd-random-seed.service
471ms snap-kde\x2dframeworks\x2d5-27.mount
437ms snap-snapd-13170.mount
411ms snap-snapd-12883.mount
403ms snap-telegram\x2ddesktop-3119.mount
370ms snap-riseup\x2dvpn-172.mount
361ms snap-telegram\x2ddesktop-3149.mount
351ms snap-kde\x2dframeworks\x2d5\x2dqt\x2d5\x2d15\x2d3\x2dcore20-4.mount
350ms keyboard-setup.service
349ms systemd-udev-trigger.service
344ms systemd-timesyncd.service
315ms snap-riseup\x2dvpn-168.mount
296ms snap-kde\x2dframeworks\x2d5\x2dqt\x2d5\x2d15\x2d3\x2dcore20-5.mount
247ms snap-kde\x2dframeworks\x2d5\x2dqt\x2d5\x2d15\x2dcore20-14.mount
245ms upower.service
243ms console-setup.service
192ms user@1000.service
143ms systemd-journald.service
125ms dev-hugepages.mount
125ms dev-mqueue.mount
124ms sys-kernel-debug.mount
124ms kmod-static-nodes.service
124ms sys-kernel-tracing.mount
101ms systemd-remount-fs.service
99ms sddm.service
89ms plymouth-start.service
86ms rtkit-daemon.service
81ms systemd-update-utmp.service
63ms setvtrgb.service
41ms plymouth-quit.service
34ms systemd-user-sessions.service
12ms user-runtime-dir@1000.service
5ms sys-fs-fuse-connections.mount
5ms sys-kernel-config.mount
5ms systemd-update-utmp-runlevel.service
1ms snapd.socketI see, the loopback device setup takes very long for some reason. I’ve tried to analyze it a while ago in another topic Snapd causing lengthy boot time? but it looked like the problem is in the kernel. This is probably running from a spinning hard disk drive, isn’t it? Anyway, I don’t think that’s a fair justification for this being slow.
Another observation is that on my Arch and openSUSE boxes, snapd.service does not appear in the critical chain. In fact, it’s not really wanted by the multi-user.target. While on 20.04 cloud image, it’s clearly enabled and in the critical path. You can try running systemctl disable snapd.service snapd.seeded.service, which will prevent snapd from being started during boot, but will keep the snapd.socket around, so snap commands will work normally. A downside is that automatic updates will not be applied until the snapd daemon has been started.
doing that really improved my boot time to what i used to get, yes it’s a wd hdd; despite the downside, this really sort things out
thanks