You are not logged in.

Pages: 1

#1 2024-05-02 11:15:15

rogueai
Member
Registered: 2024-05-02
Posts: 2

Slow boot loader time

Hi all,

I've been investigating a boot issue, I'm not entirely sure it's a laptop-specific issue, but it seems to get worse on battery so I decided to post it here.

The issue being: I get a 8-15s delay between the time I hit the boot menu entry and the kernel/initrd actually starting with the usual "Welcome to Arch Linux" message. On battery, the delay goes up to 20-30s.
During this delay I see absolutely nothing: complete black screen. 

❯ systemd-analyze time
Startup finished in 9.821s (firmware) + 13.328s (loader) + 927ms (kernel) + 4.293s (initrd) + 3.985s (userspace) = 32.356s
graphical.target reached after 3.795s in userspace.

I'll try to put as much information as possible.

System Info

  • Lenovo ThinkPad P53, 32gb RAM, Intel i7-9750H, NVIDIA Quadro T1000 Mobile

  • Kernel: Linux arch-linux 6.8.7-arch1-2

  • thinkpad_acpi module loaded

  • proprietary nvidia drivers

  • bios and firmware are up-to-date with fwupd + proprietary samsung ssd software

Boot Info

  • Boot loader: systemd-boot

  • UEFI + Secure Boot, UKI generated via mkinitcpio

  • I have 2 NVME disks: the first one is a WDC PC SN730 SDBQNTY-1T00-1001 and contains the /efi partition, Windows and a NixOS install. The second disk is a Samsung 970 EVO Plus 1TB and has my Arch install with LUKS + FIDO unlock. The nixos installation has a relatively similar setup: UEFI + Secure Boot + FIDO2 and it boots immediately, although admittedly it uses lanzaboote to generate the UKI so there might be some differences in that sense.

/etc/mkinitcpio.conf
Posting only relevant information here

MODULES=(nvidia nvidia_modeset nvidia_uvm nvidia_drm)
HOOKS=(systemd microcode autodetect modconf kms keyboard sd-vconsole block sd-encrypt filesystems)

/etc/kernel/cmdline

rd.luks.name=<UUID>=root rd.luks.options=fido2-device=auto root=/dev/mapper/root rootflags=subvol=@ rw nvidia-drm.modeset=1 lsm=landlock,lockdown,yama,integrity,apparmor,bpf

What I've tried so far

  • adding rd.debug rd.log=all to kernel parameters: I'm not sure if those args are working, it doesn't output anything to console during that "black screen" phase, and nothing on /run/initramfs either

  • dmesg/journalctl and systemd-analyze blame show nothing of interest as logs seem to start only after this initial delay

  • changed bootloader: I've tried refind and plain UEFI Shell with shellx64.efi, same issue

  • changed UKI generator: tried both systemd-ukify and dracut, no difference

  • tried to remove kms, modconf, and other hooks

  • removed apparmor and nvidia modeset parameters from kernel cmdline

At this point I'm a bit lost, the main issue being I'm not able to get any logging whatsoever from that early stage, I hope I've been clear enough to at least give you an idea of what's going on.
Let me know if there's anything else you'd need, thanks!

Edit: added a few more details on ssd and firmware

Last edited by rogueai (2024-05-02 11:32:04)

Offline

#2 2024-05-09 10:29:15

ua4000
Member
Registered: 2015-10-14
Posts: 540

Re: Slow boot loader time

$ systemd-analyze  blame

will give you more details. Can you post it here ?

Offline

#3 2024-05-09 10:36:01

damjan
Member
Registered: 2006-05-30
Posts: 462

Re: Slow boot loader time

how big is your UKI?

❯ sudo systemd-analyze
Startup finished in 8.784s (firmware) + 2.483s (loader) + 616ms (kernel) + 3.330s (initrd) + 4.542s (userspace) = 19.756s 
graphical.target reached after 4.373s in userspace.

my /boot/EFI/Linux/archlinux-linux.efi is 29M - but I don't have nvidia.

Offline

#4 2024-05-13 10:57:56

rep_movsd
Member
Registered: 2013-08-24
Posts: 148

Re: Slow boot loader time

Can you test with no non-essential kernel params and "rescue" for single user mode?

If it doesn't hang then you have some clue

Last edited by rep_movsd (2024-05-13 10:58:15)

Offline

#5 2024-05-16 07:07:16

rogueai
Member
Registered: 2024-05-02
Posts: 2

Re: Slow boot loader time

ua4000 wrote:

$ systemd-analyze  blame

will give you more details. Can you post it here ?

Here it is:

8.551s sys-module-fuse.device
8.551s dev-ttyS0.device
8.551s sys-devices-platform-serial8250-serial8250:0-serial8250:0.0-tty-ttyS0.device
8.550s sys-module-configfs.device
8.549s sys-devices-platform-serial8250-serial8250:0-serial8250:0.1-tty-ttyS1.device
8.548s dev-ttyS1.device
8.547s sys-devices-platform-serial8250-serial8250:0-serial8250:0.10-tty-ttyS10.device
8.547s dev-ttyS10.device
8.545s sys-devices-platform-serial8250-serial8250:0-serial8250:0.11-tty-ttyS11.device
8.545s dev-ttyS11.device
8.543s sys-devices-platform-serial8250-serial8250:0-serial8250:0.12-tty-ttyS12.device
8.543s dev-ttyS12.device
8.542s sys-devices-platform-serial8250-serial8250:0-serial8250:0.13-tty-ttyS13.device
8.542s dev-ttyS13.device
8.542s dev-ttyS14.device
8.542s sys-devices-platform-serial8250-serial8250:0-serial8250:0.14-tty-ttyS14.device
8.540s sys-devices-platform-serial8250-serial8250:0-serial8250:0.15-tty-ttyS15.device
8.540s dev-ttyS15.device
8.539s sys-devices-platform-serial8250-serial8250:0-serial8250:0.16-tty-ttyS16.device
8.539s dev-ttyS16.device
8.538s sys-devices-platform-serial8250-serial8250:0-serial8250:0.17-tty-ttyS17.device
8.538s dev-ttyS17.device
8.536s dev-ttyS18.device
8.536s sys-devices-platform-serial8250-serial8250:0-serial8250:0.18-tty-ttyS18.device
8.534s sys-devices-platform-serial8250-serial8250:0-serial8250:0.19-tty-ttyS19.device
8.533s dev-ttyS19.device
8.533s sys-devices-platform-serial8250-serial8250:0-serial8250:0.2-tty-ttyS2.device
8.533s dev-ttyS2.device
8.532s sys-devices-platform-serial8250-serial8250:0-serial8250:0.21-tty-ttyS21.device
8.532s dev-ttyS21.device
8.531s dev-ttyS20.device
8.531s sys-devices-platform-serial8250-serial8250:0-serial8250:0.24-tty-ttyS24.device
8.531s dev-ttyS24.device
8.531s sys-devices-platform-serial8250-serial8250:0-serial8250:0.20-tty-ttyS20.device
8.530s dev-ttyS22.device
8.530s sys-devices-platform-serial8250-serial8250:0-serial8250:0.22-tty-ttyS22.device
8.529s dev-ttyS23.device
8.528s sys-devices-platform-serial8250-serial8250:0-serial8250:0.23-tty-ttyS23.device
8.527s sys-devices-platform-serial8250-serial8250:0-serial8250:0.27-tty-ttyS27.device
8.527s dev-ttyS27.device
8.527s dev-ttyS25.device
8.526s sys-devices-platform-serial8250-serial8250:0-serial8250:0.25-tty-ttyS25.device
8.526s sys-devices-platform-serial8250-serial8250:0-serial8250:0.26-tty-ttyS26.device
8.526s dev-ttyS26.device
8.525s dev-ttyS28.device
8.525s sys-devices-platform-serial8250-serial8250:0-serial8250:0.28-tty-ttyS28.device
8.521s sys-devices-platform-serial8250-serial8250:0-serial8250:0.3-tty-ttyS3.device
8.521s dev-ttyS3.device
8.520s dev-ttyS29.device
8.520s sys-devices-platform-serial8250-serial8250:0-serial8250:0.29-tty-ttyS29.device
8.516s sys-devices-platform-serial8250-serial8250:0-serial8250:0.30-tty-ttyS30.device
8.516s dev-ttyS30.device
8.512s dev-ttyS31.device
8.512s sys-devices-platform-serial8250-serial8250:0-serial8250:0.31-tty-ttyS31.device
8.510s dev-ttyS5.device
8.510s sys-devices-platform-serial8250-serial8250:0-serial8250:0.5-tty-ttyS5.device
8.509s dev-ttyS7.device
8.508s sys-devices-platform-serial8250-serial8250:0-serial8250:0.7-tty-ttyS7.device
8.508s sys-devices-platform-serial8250-serial8250:0-serial8250:0.8-tty-ttyS8.device
8.508s dev-ttyS8.device
8.508s sys-devices-platform-serial8250-serial8250:0-serial8250:0.6-tty-ttyS6.device
8.508s dev-ttyS6.device
8.507s sys-devices-platform-serial8250-serial8250:0-serial8250:0.9-tty-ttyS9.device
8.507s dev-ttyS9.device
8.360s sys-devices-virtual-misc-rfkill.device
8.360s dev-rfkill.device
8.231s sys-devices-platform-thinkpad_acpi-leds-tpacpi::kbd_backlight.device
8.062s sys-devices-pci0000:00-0000:00:1b.0-0000:02:00.0-nvme-nvme0-nvme0n1-nvme0n1p3.device
8.062s dev-nvme0n1p3.device
8.062s dev-disk-by\x2dpartuuid-77757704\x2da498\x2d41fb\x2db3ab\x2dd17cc172d384.device
8.062s dev-disk-by\x2dpath-pci\x2d0000:02:00.0\x2dnvme\x2d1\x2dpart3.device
8.062s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893_1\x2dpart3.device
8.062s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893\x2dpart3.device
8.062s dev-disk-by\x2ddiskseq-1\x2dpart3.device
8.062s dev-disk-by\x2did-nvme\x2deui.001b448b4625607c\x2dpart3.device
8.057s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893_1.device
8.057s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893.device
8.057s sys-devices-pci0000:00-0000:00:1b.0-0000:02:00.0-nvme-nvme0-nvme0n1.device
8.057s dev-nvme0n1.device
8.057s dev-disk-by\x2ddiskseq-1.device
8.057s dev-disk-by\x2dpath-pci\x2d0000:02:00.0\x2dnvme\x2d1.device
8.057s dev-disk-by\x2did-nvme\x2deui.001b448b4625607c.device
8.054s dev-disk-by\x2dpartlabel-Basic\x5cx20data\x5cx20partition.device
8.051s sys-devices-pci0000:00-0000:00:1b.0-0000:02:00.0-nvme-nvme0-nvme0n1-nvme0n1p6.device
8.051s dev-disk-by\x2dpath-pci\x2d0000:02:00.0\x2dnvme\x2d1\x2dpart6.device
8.051s dev-disk-by\x2dpartlabel-Arch.device
8.051s dev-disk-by\x2did-nvme\x2deui.001b448b4625607c\x2dpart6.device
8.051s dev-disk-by\x2ddiskseq-1\x2dpart6.device
8.051s dev-nvme0n1p6.device
8.051s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893_1\x2dpart6.device
8.051s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893\x2dpart6.device
8.051s dev-disk-by\x2duuid-edca3e81\x2dfc06\x2d438a\x2d9865\x2d33f42744c257.device
8.051s dev-disk-by\x2dpartuuid-74ae2d38\x2d4edc\x2dc645\x2da9a1\x2dd48f2dce41b5.device
8.042s dev-nvme0n1p2.device
8.042s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893\x2dpart2.device
8.042s dev-disk-by\x2dpartlabel-Microsoft\x5cx20reserved\x5cx20partition.device
8.042s dev-disk-by\x2dpartuuid-26dd9d75\x2d265e\x2d4d8e\x2d9c56\x2dd5eb16ec6ae3.device
8.042s dev-disk-by\x2dpath-pci\x2d0000:02:00.0\x2dnvme\x2d1\x2dpart2.device
8.042s sys-devices-pci0000:00-0000:00:1b.0-0000:02:00.0-nvme-nvme0-nvme0n1-nvme0n1p2.device
8.042s dev-disk-by\x2ddiskseq-1\x2dpart2.device
8.042s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893_1\x2dpart2.device
8.042s dev-disk-by\x2did-nvme\x2deui.001b448b4625607c\x2dpart2.device
8.041s dev-disk-by\x2did-nvme\x2deui.0025385121403387.device
8.040s dev-disk-by\x2dpath-pci\x2d0000:55:00.0\x2dnvme\x2d1.device
8.040s dev-disk-by\x2did-nvme\x2dSamsung_SSD_970_EVO_Plus_1TB_S6P7NJ0T104006L_1.device
8.040s dev-nvme1n1.device
8.040s sys-devices-pci0000:00-0000:00:1d.0-0000:55:00.0-nvme-nvme1-nvme1n1.device
8.040s dev-disk-by\x2did-nvme\x2dSamsung_SSD_970_EVO_Plus_1TB_S6P7NJ0T104006L.device
8.040s dev-disk-by\x2ddiskseq-2.device
8.036s dev-disk-by\x2duuid-f7bb9927\x2d0b19\x2d4f9b\x2d93a1\x2d66d69100c867.device
8.035s dev-nvme1n1p1.device
8.035s dev-disk-by\x2ddiskseq-2\x2dpart1.device
8.035s dev-disk-by\x2dpath-pci\x2d0000:55:00.0\x2dnvme\x2d1\x2dpart1.device
8.035s sys-devices-pci0000:00-0000:00:1d.0-0000:55:00.0-nvme-nvme1-nvme1n1-nvme1n1p1.device
8.035s dev-disk-by\x2dpartuuid-9b3156c3\x2dadc6\x2d0d49\x2d97ab\x2de42f9defffda.device
8.035s dev-disk-by\x2did-nvme\x2dSamsung_SSD_970_EVO_Plus_1TB_S6P7NJ0T104006L_1\x2dpart1.device
8.035s dev-disk-by\x2did-nvme\x2deui.0025385121403387\x2dpart1.device
8.035s dev-disk-by\x2did-nvme\x2dSamsung_SSD_970_EVO_Plus_1TB_S6P7NJ0T104006L\x2dpart1.device
8.035s dev-disk-by\x2dpartuuid-35c57c56\x2da6ab\x2d4f18\x2d9c61\x2ddccdc91f429c.device
8.035s dev-disk-by\x2dpath-pci\x2d0000:02:00.0\x2dnvme\x2d1\x2dpart1.device
8.035s dev-disk-by\x2dlabel-SYSTEM.device
8.035s dev-nvme0n1p1.device
8.035s sys-devices-pci0000:00-0000:00:1b.0-0000:02:00.0-nvme-nvme0-nvme0n1-nvme0n1p1.device
8.035s dev-disk-by\x2did-nvme\x2deui.001b448b4625607c\x2dpart1.device
8.035s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893_1\x2dpart1.device
8.035s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893\x2dpart1.device
8.035s dev-disk-by\x2ddiskseq-1\x2dpart1.device
8.035s dev-disk-by\x2duuid-168C\x2d3F80.device
8.035s dev-disk-by\x2dpartlabel-EFI\x5cx20system\x5cx20partition.device
8.029s dev-disk-by\x2dpartuuid-1d6bbd8d\x2d527d\x2d4ba9\x2d9178\x2d9c9792ff6d0c.device
8.029s dev-disk-by\x2duuid-D2468F8B468F6F53.device
8.029s dev-disk-by\x2dlabel-WinRE_DRV.device
8.029s dev-nvme0n1p4.device
8.029s sys-devices-pci0000:00-0000:00:1b.0-0000:02:00.0-nvme-nvme0-nvme0n1-nvme0n1p4.device
8.029s dev-disk-by\x2ddiskseq-1\x2dpart4.device
8.029s dev-disk-by\x2dpath-pci\x2d0000:02:00.0\x2dnvme\x2d1\x2dpart4.device
8.029s dev-disk-by\x2did-nvme\x2deui.001b448b4625607c\x2dpart4.device
8.029s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893\x2dpart4.device
8.029s dev-disk-by\x2did-nvme\x2dWDC_PC_SN730_SDBQNTY\x2d1T00\x2d1001_20199C801893_1\x2dpart4.device
6.588s dev-bus-usb-001-002.device
6.588s sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d1.device
6.582s sys-devices-pci0000:00-0000:00:02.0-drm-card0-card0\x2deDP\x2d1-intel_backlight.device
1.356s initrd-switch-root.service
 968ms NetworkManager.service
 749ms systemd-journal-flush.service
 659ms systemd-tmpfiles-setup-dev-early.service
 637ms systemd-remount-fs.service
 625ms systemd-userdbd.service
 440ms ldconfig.service
 241ms udisks2.service
 216ms systemd-udev-trigger.service
 177ms user@1000.service
 175ms accounts-daemon.service
 121ms ufw.service
 117ms lvm2-monitor.service
 110ms systemd-tmpfiles-setup.service
 100ms systemd-pcrmachine.service
  97ms systemd-tpm2-setup-early.service
  96ms systemd-logind.service
  88ms systemd-journald.service
  83ms efi.mount
  78ms systemd-modules-load.service
  71ms systemd-tpm2-setup.service
  56ms initrd-parse-etc.service
  53ms systemd-backlight@backlight:intel_backlight.service
  50ms systemd-timesyncd.service
  50ms systemd-pcrphase.service
  49ms systemd-pcrphase-sysinit.service
  49ms polkit.service
  47ms systemd-udevd.service
  43ms systemd-pcrphase-initrd.service
  43ms initrd-cleanup.service
  33ms cups.service
  33ms systemd-tmpfiles-setup-dev.service
  32ms systemd-sysusers.service
  32ms systemd-vconsole-setup.service
  32ms systemd-boot-random-seed.service
  30ms systemd-homed.service
  24ms systemd-journal-catalog-update.service
  23ms avahi-daemon.service
  22ms dbus-broker.service
  21ms srv.mount
  21ms var-cache.mount
  21ms dev-hugepages.mount
  21ms opt.mount
  21ms home.mount
  20ms dev-mqueue.mount
  20ms sys-kernel-debug.mount
  20ms sys-kernel-tracing.mount
  19ms tmp.mount
  19ms kmod-static-nodes.service
  19ms var-lib-docker.mount
  18ms modprobe@drm.service
  18ms \x2esnapshots.mount
  18ms alsa-restore.service
  16ms var-log.mount
  16ms rtkit-daemon.service
  16ms nvidia-persistenced.service
  16ms lightdm.service
  16ms wpa_supplicant.service
  14ms systemd-random-seed.service
  13ms systemd-rfkill.service
  12ms systemd-backlight@leds:tpacpi::kbd_backlight.service
  11ms initrd-udevadm-cleanup-db.service
  10ms user-runtime-dir@1000.service
  10ms systemd-user-sessions.service
  10ms systemd-sysctl.service
   9ms systemd-update-utmp.service
   8ms modprobe@loop.service
   7ms modprobe@fuse.service
   7ms modprobe@dm_mod.service
   7ms systemd-battery-check.service
   7ms modprobe@configfs.service
   6ms systemd-update-done.service
   6ms sys-kernel-config.mount
   6ms sys-fs-fuse-connections.mount
 126us systemd-homed-activate.service

Note, however, that blame might not be relevant in this case, as it only shows timings after the kernel is loaded. Here's a plot instead, that shows the actual loader time
plot.png

damjan wrote:

how big is your UKI?

It's 166MB, but I wouldn't expect a modern ssd to take 10-30s to load it?

rep_movsd wrote:

Can you test with no non-essential kernel params and "rescue" for single user mode?

I'm going to try soon and report back!

Last edited by rogueai (2024-05-16 07:13:50)

Offline

#6 2024-05-17 23:39:46

user7z
Member
Registered: 2024-02-26
Posts: 35

Re: Slow boot loader time

your uki is 166MB , i would say from what i know to configure mkinitcpio.con and uncomment zstd option and a decompressor set to yes

Offline

Pages: 1

Board footer

Powered by FluxBB