Boot time optimization - LUKS encrypted install takes 47 Seconds with SSDs?

Hi there,

I wonder if anyone could help me optimize the boot time on this Asus N750JV laptop of my wife. I think it was much better before but now it takes almost a minute although it runs on SSDs only.

Here's my systemd-analyze plot > /tmp/bootchart.svg:
https://bruga.ddns.net/misc/Asus_N750JV_Manjaro_KDE_Boottime_2019-06-06.svg

And

$ systemd-analyze blame
          2.426s dev-disk-by\x2duuid-e8926249\x2d9576\x2d49ac\x2d8744\x2d8b261c38e125.swap
          1.800s udisks2.service
          1.115s lvm2-monitor.service
          1.070s systemd-logind.service
           856ms dev-mapper-luks\x2d464e5311\x2def28\x2d4f45\x2d9ec1\x2d68605f0a3ded.device
           418ms systemd-udevd.service
           389ms tlp.service
           331ms systemd-journal-flush.service
           274ms systemd-fsck@dev-disk-by\x2duuid-BF3B\x2d1665.service
           238ms systemd-journald.service
           217ms systemd-timesyncd.service
           208ms upower.service
           179ms ModemManager.service
           170ms org.cups.cupsd.service
           132ms rtkit-daemon.service
            99ms user@1000.service
            91ms systemd-remount-fs.service
            88ms polkit.service
            80ms NetworkManager.service
            79ms systemd-udev-trigger.service
            72ms avahi-daemon.service
            60ms bluetooth.service
            31ms systemd-cryptsetup@luks\x2d464e5311\x2def28\x2d4f45\x2d9ec1\x2d68605f0a3ded.service
            27ms systemd-binfmt.service
            27ms systemd-rfkill.service
            24ms dev-hugepages.mount
            24ms dev-mqueue.mount
            24ms systemd-modules-load.service
            22ms boot-efi.mount
            19ms kmod-static-nodes.service
            19ms systemd-tmpfiles-setup.service
            18ms colord.service
            15ms grub-boot-indeterminate.service
            13ms systemd-backlight@leds:asus::kbd_backlight.service
            12ms systemd-tmpfiles-setup-dev.service
            12ms sys-kernel-debug.mount
            11ms wpa_supplicant.service
            10ms haveged.service
             9ms systemd-update-utmp.service
             8ms user-runtime-dir@1000.service
             7ms systemd-user-sessions.service
             6ms systemd-backlight@backlight:intel_backlight.service
             5ms systemd-random-seed.service
             5ms systemd-sysctl.service
             4ms proc-sys-fs-binfmt_misc.mount
             3ms sys-fs-fuse-connections.mount
             2ms sys-kernel-config.mount
             2ms tmp.mount

And

$ 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 @5.756s
└─multi-user.target @5.748s
  └─systemd-logind.service @4.671s +1.070s
    └─basic.target @4.660s
      └─sockets.target @4.660s
        └─avahi-daemon.socket @4.660s
          └─sysinit.target @4.657s
            └─systemd-timesyncd.service @4.439s +217ms
              └─systemd-tmpfiles-setup.service @4.416s +19ms
                └─local-fs.target @4.415s
                  └─tmp.mount @4.412s +2ms
                    └─swap.target @4.412s
                      └─dev-disk-by\x2duuid-e8926249\x2d9576\x2d49ac\x2d8744\x2d8b261c38e125.swap @1.984s +2.426s
                        └─dev-disk-by\x2duuid-e8926249\x2d9576\x2d49ac\x2d8744\x2d8b261c38e125.device @1.900s

And

$ inxi -Fxz
System:    Host: Blumenmonster Kernel: 5.1.4-1-MANJARO x86_64 bits: 64 compiler: gcc v: 8.3.0 Desktop: KDE Plasma 5.15.5 
           Distro: Manjaro Linux 
Machine:   Type: Laptop System: ASUSTeK product: N750JV v: 1.0 serial: <filter> 
           Mobo: ASUSTeK model: N750JV v: 1.0 serial: <filter> UEFI: American Megatrends v: N750JV.207 date: 08/07/2013 
Battery:   ID-1: BAT0 charge: 43.4 Wh condition: 43.4/69.5 Wh (62%) model: ASUSTeK N750-62 status: Full 
CPU:       Topology: Quad Core model: Intel Core i7-4700HQ bits: 64 type: MT MCP arch: Haswell rev: 3 L2 cache: 6144 KiB 
           flags: avx avx2 lm nx pae sse sse2 sse3 sse4_1 sse4_2 ssse3 vmx bogomips: 38333 
           Speed: 2454 MHz min/max: 800/3400 MHz Core speeds (MHz): 1: 2454 2: 1854 3: 1887 4: 2067 5: 1830 6: 2285 7: 2878 
           8: 2501 
Graphics:  Device-1: Intel 4th Gen Core Processor Integrated Graphics vendor: ASUSTeK driver: i915 v: kernel bus ID: 00:02.0 
           Device-2: NVIDIA GK107M [GeForce GT 750M] driver: N/A bus ID: 01:00.0 
           Display: x11 server: X.Org 1.20.4 driver: intel resolution: 1920x1080~60Hz 
           OpenGL: renderer: Mesa DRI Intel Haswell Mobile v: 4.5 Mesa 19.0.4 direct render: Yes 
Audio:     Device-1: Intel Xeon E3-1200 v3/4th Gen Core Processor HD Audio driver: snd_hda_intel v: kernel bus ID: 00:03.0 
           Device-2: Intel 8 Series/C220 Series High Definition Audio vendor: ASUSTeK driver: snd_hda_intel v: kernel 
           bus ID: 00:1b.0 
           Sound Server: ALSA v: k5.1.4-1-MANJARO 
Network:   Device-1: Intel Centrino Advanced-N 6235 driver: iwlwifi v: kernel port: f040 bus ID: 03:00.0 
           IF: wlp3s0 state: up mac: <filter> 
           Device-2: Realtek RTL8111/8168/8411 PCI Express Gigabit Ethernet vendor: ASUSTeK driver: r8168 v: 8.047.01-NAPI 
           port: d000 bus ID: 04:00.0 
           IF: enp4s0 state: up speed: 1000 Mbps duplex: full mac: <filter> 
Drives:    Local Storage: total: 704.24 GiB used: 269.28 GiB (38.2%) 
           ID-1: /dev/sda vendor: LITE-ON IT model: LCS-256M6S size: 238.47 GiB 
           ID-2: /dev/sdb vendor: Samsung model: SSD 840 EVO 500GB size: 465.76 GiB 
Partition: ID-1: / size: 465.66 GiB used: 269.28 GiB (57.8%) fs: btrfs dev: /dev/dm-0 
           ID-2: swap-1 size: 111.33 GiB used: 0 KiB (0.0%) fs: swap dev: /dev/sda6 
Sensors:   System Temperatures: cpu: 61.0 C mobo: N/A 
           Fan Speeds (RPM): cpu: 2600 
Info:      Processes: 271 Uptime: 12m Memory: 15.55 GiB used: 2.33 GiB (15.0%) Init: systemd Compilers: gcc: 8.3.0 Shell: bash 
           v: 5.0.7 inxi: 3.0.34

There's quite a few threads on this topic on the forum.

Did you test going back to older kernels to see if this goes away. Older hardware is often happier on an older kernel. I would test back to 4.14.

1 Like

thanks for the reply. I tried 5.1.4-1 and 4.19.45-1. Both are quite slow, the 5.1 seems to be a little bit faster.

Which Kernel would you suggest I try? Those are all that I have installed at the moment.

Try 4.14, I have found it better for older hardware than the more recent ones.

Here's a similar post that was still active today:

1 Like

systemd-analyze blame looks fine to me, you could mask / disable a few things but you wouldn't gain much from that, have a look at dmesg see if you can see anything in their that's holding it up? also see if you have any errors with sudo journalctl -p 3 -xb

To negate the delay try starting the software based entropy daemon. you can always revert this if it makes no difference

sudo systemctl enable haveged --now

1 Like

Thanks for your reply!

journalctl gave me "no entries".

dmesg gives a lot ouf output, though I couldn't spot anything standing out. Any of you maybe?
https://pastebin.com/ZyPqZDLx

I think I stumbled upon this while reading the preexisting threads with similar topics. Didn't make any noticable differences though.

All of the boot time is in firmware and loader. Manjaro boot time is five seconds.

No tweaks you make to Manjaro will affect that.

Check for BIOS updates and check your BIOS/UEFI settings.

2 Likes

In addition to Jonathon's recommendation also check for SSD firmware updates in case there are any bug fixes specific to linux.

Thanks everyone for your ton's of replies and suggestions!

I've tried to (manually) document what the boot process looks like to me using libreoffice calc on a second laptop. This doesn't look to me as if Manjaro would only take 5 seconds to boot and the rest is BIOS / firmware problems:

2019-06-07 09:25:25 press power button
2019-06-07 09:25:29 bios password entry available
2019-06-07 09:25:31 bios password entry finished
2019-06-07 09:25:33 LUKS password entry available
2019-06-07 09:25:38 LUKS password entry finished
2019-06-07 09:25:49 GRUB choice available
2019-06-07 09:25:51 GRUB pressed enter for default (autboot would take 5 seconds)
2019-06-07 09:25:57 Boot console messages started
2019-06-07 09:26:00 Welcome to Manjaro console message
2019-06-07 09:26:16 Graphical Login Manager visible (autologin configured)
2019-06-07 09:26:46 Desktop available

Seems that unlocking the LUKS takes quite a lot of time...
Maybe during installation the number of iterations chosen were too high?

Just for reference, check that the hardware accelerated AES is enabled (which it normally is): lsmod | grep aes, and whether they're available at early boot.

It also takes quite a lot of time to reach the graphical login.

In any case though, you're right that it takes way too long, and it's probably not just a firmware issue.

1 Like
$ lsmod | grep aes
aesni_intel           372736  8
aes_x86_64             20480  1 aesni_intel
crypto_simd            16384  1 aesni_intel
cryptd                 28672  4 crypto_simd,ghash_clmulni_intel,aesni_intel
glue_helper            16384  1 aesni_intel

How do I check if it's available at early boot?

I did this whole manual boot procedure documentation again to check if it's stays the same mostly, which it seems to me it does:

2019-06-07 09:38:47 press power button
2019-06-07 09:38:50 bios password entry available
2019-06-07 09:38:52 bios password entry finished
2019-06-07 09:38:53 LUKS password entry available
2019-06-07 09:38:58 LUKS password entry finished
2019-06-07 09:39:07 LUKS slot 0 opened
2019-06-07 09:39:09 GRUB choice available
2019-06-07 09:39:10 GRUB pressed enter for default (autboot would take 5 seconds)
2019-06-07 09:39:12 Boot console messages started
2019-06-07 09:39:20 Welcome to Manjaro console message
2019-06-07 09:39:36 Graphical Login Manager visible (autologin configured)
2019-06-07 09:40:06 Desktop available

Hmm, I think I just ticked the checkbox for the whole disk encryption in the installer. No manual config was involved as far as I remember.

How do I check the LUKS config? Although I guess this is hardly changeable without doing a fresh install (or backup to a different disk and reinitialize LUKS..

I'm more concerned with the ~54 seconds from pressing enter in GRUB till I can use my desktop environment...

Output looks fine to me.
I don't think it will make a difference if added to the initram, but you could check with this command: lsinitcpio /boot/initramfs-4.19-x86_64.img | grep -i aes (that's for 4.19 kernel, adjust filename for the one that you want to check).

Yes, that's right. You cannot manually control it, it's the -i parameter used with cryptsetup. I don't know what the default is. Also I don't know if it is related to your issue. Just assumptions from my side, sorry...

$ uname -a
Linux Blumenmonster 5.1.4-1-MANJARO #1 SMP PREEMPT Wed May 22 17:56:21 UTC 2019 x86_64 GNU/Linux

$ lsinitcpio /boot/initramfs-5.1-x86_64.img | grep -i aes
usr/lib/modules/5.1.4-1-MANJARO/kernel/aegis256-aesni.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/camellia-aesni-avx-x86_64.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/aes_ti.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/aes-x86_64.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/aesni-intel.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/aegis128l-aesni.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/camellia-aesni-avx2.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/padlock-aes.ko
usr/lib/modules/5.1.4-1-MANJARO/kernel/aegis128-aesni.ko

Okay that's also fine.
So maybe we should investigate other things...

Try running sudo dmesg -HL, and then check carefully each step, and try to find those steps that take the most time (it's the first number printed each line).
Don't post everything, it's a lot of output.

Example from this VM installation:
[ +1,439690] random: crng init done

okey. I sorted the output and got 15 lines that have more than half a second:

[  +0,641885] Adding 116735996k swap on /dev/sda6.  Priority:-2 extents:1 across:116735996k SSDscFS
[  +0,879443] RAPL PMU: API unit is 2^-32 Joules, 4 fixed counters, 655360 ms ovfl timer
[  +0,949516] audit: type=1130 audit(1559893169.166:31): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=ModemManager comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[  +2,035120] NET: Registered protocol family 38
[  +2,128761] random: cryptsetup: uninitialized urandom read (2 bytes read)
[  +2,284166] Bluetooth: RFCOMM TTY layer initialized
[  +2,847603] systemd[1]: Listening on udev Kernel Socket.
[  +3,154030] fuse init (API version 7.29)
[  +3,224888] systemd[1]: systemd 242.29-1-manjaro running in system mode. (+PAM +AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid)
[  +3,368034] iwlwifi 0000:03:00.0: Radio type=0x2-0x1-0x0
[  +3,492533] iwlwifi 0000:03:00.0: Radio type=0x2-0x1-0x0
[  +5,254838] audit: type=1131 audit(1559893198.136:45): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hostnamed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[  +8,273341] wlp3s0: authenticate with f8:1a:67:5a:55:89
[  +8,303120] audit: type=1130 audit(1559893189.726:44): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=udisks2 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[  +9,969017] audit: type=1131 audit(1559893223.603:47): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

It seems that the network related stuff takes quite a lot of time.
If you don't use a modem, you could for example simply remove ModemManager package.
For the WiFi thing, I don't know...

Interesting. Those times don't tally at all with your systemd-analyze plot which says it takes 35 seconds to reach the kernel, then seven seconds to load the kernel (i.e. read it from disk), then ~6 seconds to actually boot the OS to graphical target (i.e. DM/login screen).

You can't really count "time to desktop" in "time to boot" as it's down to the DE and which applications you're loading on startup.

I suspect you need to focus on why your LUKS is slow rather than it being a general "boot time" issue.

1 Like

Forum kindly sponsored by