EDIT: I thought that snap mounts were causing the slow boot, but looking at systemd-analyze critical-chain I was wrong about that. As such, I’ve edited this post.
I’ve had slow boots on my fast system with SSD and finally got around to running systemd-analyze blame and while I learned that snap mounts were not in the critical-chain of boot, I found that for each snap revision that is mounted, many are adding >500ms to mount. Eg:
$ systemd-analyze blame --no-pager|grep dev-loop
652ms dev-loop37.device
642ms dev-loop42.device
640ms dev-loop36.device
624ms dev-loop29.device
621ms dev-loop44.device
615ms dev-loop47.device
610ms dev-loop40.device
608ms dev-loop52.device
607ms dev-loop48.device
604ms dev-loop43.device
602ms dev-loop38.device
600ms dev-loop41.device
593ms dev-loop33.device
592ms dev-loop34.device
590ms dev-loop28.device
590ms dev-loop51.device
586ms dev-loop53.device
585ms dev-loop31.device
585ms dev-loop35.device
584ms dev-loop46.device
583ms dev-loop49.device
580ms dev-loop45.device
579ms dev-loop39.device
578ms dev-loop54.device
566ms dev-loop56.device
565ms dev-loop22.device
554ms dev-loop50.device
553ms dev-loop21.device
553ms dev-loop32.device
551ms dev-loop55.device
549ms dev-loop30.device
548ms dev-loop26.device
544ms dev-loop27.device
536ms dev-loop25.device
533ms dev-loop58.device
525ms dev-loop23.device
525ms dev-loop57.device
160ms dev-loop16.device
147ms dev-loop12.device
143ms dev-loop18.device
135ms dev-loop13.device
132ms dev-loop11.device
127ms dev-loop15.device
118ms dev-loop14.device
117ms dev-loop17.device
106ms dev-loop20.device
98ms dev-loop19.device
75ms dev-loop8.device
72ms dev-loop10.device
70ms dev-loop9.device
41ms dev-loop59.device
28ms dev-loop4.device
28ms dev-loop5.device
28ms dev-loop2.device
26ms dev-loop1.device
23ms dev-loop6.device
18ms dev-loop7.device
10ms dev-loop3.device
8ms dev-loop0.device
If I look at df output, I can see all these correspond to snaps:
$ df|grep loop
/dev/loop0 238720 238720 0 100% /snap/chromium/9
/dev/loop3 128 128 0 100% /snap/test-policy-app/x10
/dev/loop2 182016 182016 0 100% <redacted>
/dev/loop1 3456 3456 0 100% /snap/test-seccomp-compat/1
/dev/loop4 107136 107136 0 100% /snap/gnome-3-24/3
/dev/loop5 128 128 0 100% /snap/snappy-debug/32
/dev/loop6 128 128 0 100% /snap/test-sandbox/x23
/dev/loop7 83456 83456 0 100% /snap/core/2898
/dev/loop9 20608 20608 0 100% /snap/gnome-clocks/13
/dev/loop8 256 256 0 100% /snap/test-hello-dbus-service-system/2
/dev/loop10 117888 117888 0 100% /snap/vlc/4
/dev/loop11 6144 6144 0 100% /snap/gnome-clocks/21
/dev/loop14 896 896 0 100% /snap/godd/2
/dev/loop13 156544 156544 0 100% <redacted>
/dev/loop12 147712 147712 0 100% <redacted>
/dev/loop15 40832 40832 0 100% /snap/lxd/4168
/dev/loop16 117632 117632 0 100% /snap/musescore/1
/dev/loop18 146688 146688 0 100% <redacted>
/dev/loop17 8704 8704 0 100% /snap/snappy-debug/70
/dev/loop19 128 128 0 100% /snap/test-sandbox/x22
/dev/loop20 11648 11648 0 100% /snap/ubuntu-image/64
/dev/loop22 29568 29568 0 100% /snap/test-snapd-wayland/1
/dev/loop21 65152 65152 0 100% /snap/git-ubuntu/251
/dev/loop23 14080 14080 0 100% /snap/ubuntu-image/66
/dev/loop25 128 128 0 100% /snap/test-policy-app/x12
/dev/loop27 26752 26752 0 100% /snap/review-tools/171
/dev/loop28 35584 35584 0 100% /snap/gradio/11
/dev/loop26 35584 35584 0 100% /snap/gradio/9
/dev/loop29 238208 238208 0 100% /snap/chromium/13
/dev/loop30 8704 8704 0 100% /snap/snappy-debug/75
/dev/loop31 40832 40832 0 100% /snap/lxd/4197
/dev/loop33 11136 11136 0 100% /snap/debug-tools/x1
/dev/loop34 256 256 0 100% /snap/test-hello-dbus-service-session/2
/dev/loop36 640 640 0 100% /snap/test-snapd-syscall/x8
/dev/loop35 11136 11136 0 100% /snap/debug-tools/x2
/dev/loop32 83456 83456 0 100% /snap/core/2774
/dev/loop37 40832 40832 0 100% /snap/lxd/4279
/dev/loop38 65280 65280 0 100% /snap/git-ubuntu/268
/dev/loop39 128 128 0 100% /snap/devmode/x1
/dev/loop40 35584 35584 0 100% /snap/gradio/13
/dev/loop41 236288 236288 0 100% /snap/chromium/46
/dev/loop42 65280 65280 0 100% /snap/git-ubuntu/271
/dev/loop43 21376 21376 0 100% /snap/gnome-clocks/19
/dev/loop44 128 128 0 100% /snap/test-policy-app/x11
/dev/loop45 640 640 0 100% /snap/test-snapd-syscall/x7
/dev/loop46 165888 165888 0 100% <redacted>
/dev/loop47 640 640 0 100% /snap/test-snapd-syscall/x9
/dev/loop48 128 128 0 100% /snap/strict/x1
/dev/loop49 83456 83456 0 100% /snap/core/2844
/dev/loop51 128 128 0 100% /snap/hello-world/x1
/dev/loop50 26752 26752 0 100% /snap/review-tools/168
/dev/loop52 118272 118272 0 100% /snap/musescore/3
/dev/loop53 11648 11648 0 100% /snap/ubuntu-image/62
/dev/loop54 128 128 0 100% /snap/test-sandbox/x21
/dev/loop55 256 256 0 100% /snap/test-hello-dbus-client-system/2
/dev/loop56 256 256 0 100% /snap/test-hello-dbus-client-session/2
/dev/loop57 2176 2176 0 100% /snap/what-snap/8
/dev/loop58 128 128 0 100% /snap/hello-world/27
/dev/loop59 26752 26752 0 100% /snap/review-tools/174
The longer times seem to correspond to the size of the snap. Here are the sizes of the snaps:
$ ls -l /var/lib/snapd/snaps/*.snap
-rw-r--r-- 1 root root 243847168 Sep 1 11:23 chromium_13.snap
-rw-r--r-- 1 root root 241881088 Sep 27 22:00 chromium_46.snap
-rw-r--r-- 1 root root 244436992 Sep 1 11:15 chromium_9.snap
-rw-r--r-- 1 root root 85385216 Sep 5 17:24 core_2774.snap
-rw-r--r-- 1 root root 85348352 Sep 11 21:26 core_2844.snap
-rw-r--r-- 1 root root 85348352 Sep 18 23:10 core_2898.snap
-rw------- 1 root root 11350016 Feb 22 2017 debug-tools_x1.snap
-rw------- 1 root root 11350016 Feb 22 2017 debug-tools_x2.snap
-rw------- 1 root root 4096 Nov 29 2016 devmode_x1.snap
-rw-r--r-- 1 root root 66609152 Sep 18 23:10 git-ubuntu_251.snap
-rw-r--r-- 1 root root 66768896 Sep 20 16:30 git-ubuntu_268.snap
-rw-r--r-- 1 root root 66768896 Sep 21 05:48 git-ubuntu_271.snap
-rw-r--r-- 1 root root 109633536 Jul 14 13:25 gnome-3-24_3.snap
-rw-r--r-- 1 root root 21053440 Sep 1 00:41 gnome-clocks_13.snap
-rw-r--r-- 1 root root 21778432 Sep 21 17:48 gnome-clocks_19.snap
-rw-r--r-- 1 root root 6225920 Sep 26 22:48 gnome-clocks_21.snap
-rw------- 1 root root 827392 Oct 27 2016 godd_2.snap
-rw-r--r-- 1 root root 36315136 Sep 14 09:49 gradio_11.snap
-rw-r--r-- 1 root root 36315136 Sep 17 17:20 gradio_13.snap
-rw-r--r-- 1 root root 36315136 Sep 13 14:56 gradio_9.snap
-rw-r--r-- 1 root root 20480 Aug 11 08:33 hello-world_27.snap
-rw------- 1 root root 20480 Sep 25 16:46 hello-world_x1.snap
-rw-r--r-- 1 root root 41697280 Sep 20 04:48 lxd_4168.snap
-rw-r--r-- 1 root root 41730048 Sep 20 18:18 lxd_4197.snap
-rw-r--r-- 1 root root 41746432 Sep 27 07:47 lxd_4279.snap
-rw-r--r-- 1 root root 120352768 Jun 12 10:11 musescore_1.snap
-rw-r--r-- 1 root root 121090048 Jun 16 16:24 musescore_3.snap
-rw-r--r-- 1 root root 27377664 Sep 21 22:13 review-tools_168.snap
-rw-r--r-- 1 root root 27377664 Sep 25 17:18 review-tools_171.snap
-rw-r--r-- 1 root root 27381760 Sep 28 14:37 review-tools_174.snap
-rw-r--r-- 1 root root 28672 Jun 13 17:29 snappy-debug_32.snap
-rw-r--r-- 1 root root 8888320 Jul 13 18:08 snappy-debug_70.snap
-rw-r--r-- 1 root root 8888320 Jul 14 08:38 snappy-debug_75.snap
-rw-r--r-- 1 root root 2297856 Jul 6 18:12 spread_28.snap
-rw------- 1 root root 4096 May 9 10:24 strict_x1.snap
-rw-r--r-- 1 root root 217088 Sep 7 14:29 test-hello-dbus-client-session_2.snap
-rw-r--r-- 1 root root 217088 Sep 7 14:29 test-hello-dbus-client-system_2.snap
-rw-r--r-- 1 root root 217088 Sep 7 14:29 test-hello-dbus-service-session_2.snap
-rw-r--r-- 1 root root 217088 Sep 7 14:30 test-hello-dbus-service-system_2.snap
-rw------- 1 root root 4096 Mar 23 2017 test-policy-app_x10.snap
-rw------- 1 root root 4096 Mar 28 2017 test-policy-app_x11.snap
-rw------- 1 root root 4096 May 18 13:34 test-policy-app_x12.snap
-rw------- 1 root root 4096 Jan 20 2017 test-sandbox_x21.snap
-rw------- 1 root root 4096 Jan 20 2017 test-sandbox_x22.snap
-rw------- 1 root root 4096 Jan 20 2017 test-sandbox_x23.snap
-rw-r--r-- 1 root root 3465216 Aug 25 12:23 test-seccomp-compat_1.snap
-rw------- 1 root root 602112 Sep 26 23:48 test-snapd-syscall_x7.snap
-rw------- 1 root root 602112 Sep 26 23:55 test-snapd-syscall_x8.snap
-rw------- 1 root root 626688 Sep 27 08:23 test-snapd-syscall_x9.snap
-rw-r--r-- 1 root root 30224384 Aug 25 09:59 test-snapd-wayland_1.snap
-rw-r--r-- 1 root root 11907072 Jul 7 15:05 ubuntu-image_62.snap
-rw-r--r-- 1 root root 11907072 Jul 10 08:35 ubuntu-image_64.snap
-rw-r--r-- 1 root root 14290944 Jul 12 15:45 ubuntu-image_66.snap
-rw-r--r-- 1 root root 120627200 Aug 1 09:45 vlc_4.snap
-rw-r--r-- 1 root root 2170880 Aug 17 16:46 what-snap_8.snap
This exercise reminded me that a relatively cheap way to make things a bit better is to only mount the active snap.
