[Solved] Boot delay due to Btrfs scan

[Tom739]

First of all I'd like to congratulate the entire team of Linux Mint to their excellent work. I have run different Linuxes for more than 15 years and the installation and upgrade of "Linux Mint 18.2/3 Mate" was by far the most straightforward and troublefree process I have experienced so far.

I am running:
- Lenovo Thinkpad T560
- Linux Mint 18.3 Mate
- 4.10.0-40-generic #44~16.04.1-Ubuntu SMP
- Filesystem = ext4 (except for swap)

Although I do not use Btrfs filesystems at all, each boot process is interrupted for a couple of seconds to scan for Btrfs filesystems. In the boot.log the following message is found (I have masked the number of files and blocks):

Scanning for Btrfs filesystems
/dev/sda5: clean, .../... files, .../... blocks

This may not be a very urgent issue, but I wonder if it is not possible to automatically drop this scan, when no Btrfs filesystem is used? As an alternative could you please let me know, how to manually disable this scan in a way that does not conflict with future kernel and OS updates?

Thanks & Regards
Tom

[thx-1138]

...fire up Synaptic, uninstall btrfs-tools. Since you don't use btrfs, there will be no ill side-effects whatsoever.
Just in case, (if it's not triggered automatically...), run afterwards:

Code: Select all

sudo update-initramfs -ukall

[Tom739]

I have uninstalled btrfs-tools as suggested and the notice "Scanning for Btrfs filesystems" went away during the boot procedure. Unfortunately, it did not speed-up the boot procedure as expected. Still there is a pause of about 5s. Probably it is caused by another process, maybe the frame buffer device (see kernel log section below)?

Any idea what causes that delay and if it can be reduced?

Thanks & Regards
Tom

...
kernel: [ 11.317546] Console: switching to colour frame buffer device 240x67
kernel: [ 11.337660] i915 0000:00:02.0: fb0: inteldrmfb frame buffer device
kernel: [ 16.475521] EXT4-fs (sda5): mounted filesystem with ordered data mode. Opts: (null)
kernel: [ 16.729407] lp: driver loaded but no devices found
...

[Pjotr]

What does this say:

Code: Select all

systemd-analyze blame

[Tom739]

Thanks Pjotr, here we go ... surprise:

Code: Select all

          5.338s NetworkManager-wait-online.service
           454ms lvm2-monitor.service
             ...

Well, does this suggest that the system wants to go online during the boot sequence?
If so, does that really makes sense and how can it be avoided?

Thanks & Regards
Tom

[thx-1138]

...you can disable 'NetworkManager-wait-online.service' (there's numerous threads in the forums about it as well...)

Code: Select all

sudo systemctl disable NetworkManager-wait-online.service

If you didn't install Mint using LVM / aren't using such, you can also safely disable the lvm* services...

Code: Select all

sudo systemctl disable lvm2-monitor.service

[Tom739]

Thanks thx-1138. I even masked the NetworkManager with

Code: Select all

systemctl mask NetworkManager-wait-online.service

As a result, the NetworkManager is no longer at the top of the "systemd-analyze blame" list. In fact, it is no longer listed at all. However, still this action did not have a significant effect on the observed speed of the boot process. I have configured grub to list the steps of the boot sequence on the screen while booting.

As the LVM (logical volume manager) is concerned, I think I cannot disable it because I used logical volumes when I set-up the partitions of my system (swap, /tmp, /, /usr/local, /home).

Regards
Tom

[thx-1138]

...Tom, what is the full (not truncated like above) output of systemd-analyze blame?
Can you post results from systemd-analyze critical-chain as well?

Those 2 that you disabled above are relatively well-known for their semi-buggy behavior,
and should certainly speed up the boot process a bit, but i wouldn't expect miracles as well...
Just how much time in total does it take to boot? Is it hd or ssd that you're using?
For example, i have a (slow) 5400rpm hd, not 7200rpm neither ssd,
and it usually takes around 38 seconds to boot (which is pretty logical / 'normal' behavior)...

[Tom739]

I do have an SSD and the boot procedure measured from the end of the grub menu to the appearance of the lightDM login screen is about 16s. So, as I mentioned in my original post, it is not an urgent issue. However, I compare the boot sequence with the one of my previous SuSE Linux 12.3 (also with SSD) and that one did not have this "pause". So, I wonder what is the reason.

Anyway, here is the full result of "systemd-analyze blame"

Code: Select all

           421ms dev-sda5.device
           316ms lvm2-monitor.service
           252ms networking.service
           193ms ModemManager.service
           188ms systemd-cryptsetup@cryptswap1.service
           157ms loadcpufreq.service
           148ms systemd-logind.service
           142ms accounts-daemon.service
           120ms virtualbox-guest-utils.service
           120ms grub-common.service
           119ms NetworkManager.service
           115ms irqbalance.service
           113ms console-kit-daemon.service
           112ms speech-dispatcher.service
           108ms ondemand.service
           104ms apparmor.service
           103ms thermald.service
            97ms console-setup.service
            94ms gpu-manager.service
            90ms console-kit-log-system-start.service
            86ms apport.service
            77ms upower.service
            69ms systemd-fsck@dev-disk-by\x2duuid-bca821f6\x2d07dc\x2d4114\x2d9a82\x2d796898208ee8.service
            69ms systemd-fsck@dev-disk-by\x2duuid-3186fb1a\x2dcedf\x2d4c94\x2d8a13\x2d74fabd0dc3e1.service
            61ms binfmt-support.service
            61ms alsa-restore.service
            54ms systemd-fsck@dev-disk-by\x2duuid-6ee1f63a\x2d427d\x2d440d\x2d8d4e\x2d59f9e47b7cbd.service
            53ms systemd-udev-trigger.service
            47ms iio-sensor-proxy.service
            47ms home.mount
            47ms rsyslog.service
            44ms keyboard-setup.service
            44ms dev-hugepages.mount
            44ms cpufrequtils.service
            43ms sys-kernel-debug.mount
            42ms xfstt.service
            39ms ntp.service
            37ms kmod-static-nodes.service
            37ms systemd-journald.service
            36ms udisks2.service
            33ms systemd-modules-load.service
            33ms ufw.service
            32ms lightdm.service
            32ms lm-sensors.service
            32ms bluetooth.service
            30ms pppd-dns.service
            28ms dev-mqueue.mount
            27ms usr-local.mount
            27ms systemd-tmpfiles-setup.service
            26ms systemd-update-utmp.service
            26ms avahi-daemon.service
            25ms hddtemp.service
            24ms user@500.service
            22ms systemd-backlight@leds:tpacpi::kbd_backlight.service
            21ms tmp.mount
            20ms dns-clean.service
            18ms polkitd.service
            18ms openvpn.service
            18ms plymouth-read-write.service
            17ms systemd-user-sessions.service
            16ms rc-local.service
            14ms systemd-udevd.service
            12ms flatpak-system-helper.service
            12ms systemd-journal-flush.service
            10ms resolvconf.service
             8ms systemd-tmpfiles-setup-dev.service
             7ms systemd-sysctl.service
             7ms sys-fs-fuse-connections.mount
             7ms proc-sys-fs-binfmt_misc.mount
             5ms dev-mapper-cryptswap1.swap
             5ms wpa_supplicant.service
             5ms plymouth-quit-wait.service
             4ms systemd-remount-fs.service
             4ms ureadahead-stop.service
             4ms systemd-random-seed.service
             4ms rtkit-daemon.service
             3ms systemd-update-utmp-runlevel.service
             2ms setvtrgb.service
             2ms systemd-backlight@backlight:intel_backlight.service
             1ms systemd-rfkill.service

and the result of systemd-analyze critical-chain:

Code: Select all

graphical.target @1.138s
└─multi-user.target @1.138s
  └─ntp.service @1.098s +39ms
    └─network-online.target @1.090s
      └─network.target @1.086s
        └─networking.service @821ms +252ms
          └─apparmor.service @713ms +104ms
            └─local-fs.target @703ms
              └─run-cgmanager-fs.mount @918ms
                └─local-fs-pre.target @503ms
                  └─lvm2-monitor.service @185ms +316ms
                    └─lvm2-lvmetad.service @212ms
                      └─lvm2-lvmetad.socket @182ms
                        └─-.mount @122ms
                          └─system.slice @144ms
                            └─-.slice @122ms

Thanks & Regards
Tom

[Tom739]

I have spend more time analyzing the issue and can rule out "systemd-fsck" as the root cause of the 5s time delay. I have set the sixth field for the partitions /dev/sda[5-7] to "0" in /ets/fstab and it did not have any effect.

This leaves the "inteldrmfb" frame buffer device, which interestingly is not reported by "systemd-analyze blame" at all. Probably it needs some time to initialize. Thanks to all, who helped to speed up my boot process.

Regards
Tom

[Tom739]

FYI, while uprading my system to LM Mate 19.3, I found the reason for the remaining delay in the boot procedure of LM Mate 18.3. After executing a premount-script that imho is required for encrypted home folders, LM tries to check the swap partition by having a look into

Code: Select all

/etc/initramfs-tools/resume

It immediately completes this step, provided the information in this file is really pointing to the swap partition. However, if the UUID in this file is incorrect, the boot process is delayed.

After having identified the UUID of my swap partition per

Code: Select all

# blkid

and replacing the wrong UUID in the resume file by the correct one and running

Code: Select all

# update-initramfs -u -k all

the problem was resolved .

Regards
Tom

[BG405]

Wish I'd read this thread properly the first time round .. I could have suggested that possibility as it seems to be a fairly common issue. Glad you fixed it.