Very long boot time, systemd-analyze indicates linux-modules-cleanup.service with longest run time

Hey y'all,

Been reading through other's long boot time and I read somewhere that linux-modules-cleanup.service is only supposed to run when the kernel has updates. Well, I can confirm that linux-modules-cleanup.service runs at every boot and has a time range between 1min 39s - 3m 40s (whenever I run systemd-analyze blame it's at the top of the list with those numbers so far).

The rest of the services then load in relatively quick order, from about 50s and less. For example, here's my latest output:

1min 39.466s linux-modules-cleanup.service
     53.111s man-db.service
     47.181s cpupower-gui.service
     47.160s pacman-files.service
     43.969s updatedb.service
     40.391s nmb.service
     27.152s dev-sdb2.device
     19.958s cpupower-gui-helper.service
     18.372s systemd-remount-fs.service
     16.313s grub-btrfs-snapper.service
     14.208s smb.service
     11.772s NetworkManager-wait-online.service
     10.863s vmware-networks.service
      9.382s polkit.service
      7.071s logrotate.service
      5.888s ufw.service
      5.176s avahi-daemon.service
      5.171s bluetooth.service
      5.161s NetworkManager.service
      5.158s iio-sensor-proxy.service
      5.146s ldconfig.service
      5.126s thermald.service
      5.124s systemd-logind.service
      5.121s systemd-machined.service
      4.395s tlp.service
      3.646s systemd-modules-load.service
      3.486s dev-hugepages.mount
      3.483s dev-mqueue.mount
      3.482s sys-kernel-debug.mount

If anyone can shed some light on this service and what I might be able to do to optimize its load time? I only have 3 kernels installed: linux-zen (default and current running kernel), linux-lts, and linux (the last two for fallback purposes, JUST IN CASE). I do have some DKMS modules that load during boot, but not sure if that plays into it.

Anyway, thanks in advance to anyone who can help or provide advice!

1 Like

This service cleans up modules from old kernels. Garuda employs a nice service which makes sure that no reboot is needed after upgrading the kernel, which keeps the modules of the currently booted kernel available after system upgrades. The service you are looking at removes the backed up modules of the old kernel.
What kind of storage do you have?

1 Like

1TB HDD. Unfortunately, it's running off an external drive via USB 3.1 connection, so I understand that there's a performance hit from that, but 1:39 - 3:40 seems excessive even for the performance hit.....

For me it usually takes seconds, also this should only happen after a kernel upgrade rather than every reboot. But I agree, that's indeed a quite heavy hit :eyes:

2 Likes

That's what I thought....but it 100% runs every time I boot, and it's always the longest loading service.

Here's my inxi -Faz in case this helps....

Summary
❯ inxi -Faz
System:    Kernel: 5.14.8-zen1-1-zen x86_64 bits: 64 compiler: gcc v: 11.1.0
           parameters: BOOT_IMAGE=/@/boot/vmlinuz-linux-zen root=UUID=12979374-b0c5-4bc8-8f21-3b53bd02741b rw
           [email protected] quiet splash rd.udev.log_priority=3 vt.global_cursor_default=0
           systemd.unified_cgroup_hierarchy=1 resume=UUID=334332cc-a79e-45e2-b657-65270e259a03 loglevel=3
           sysrq_always_enabled=1 intel_iommu=on iommu=pt acpi_backlight=vendor delayacct
           Desktop: KDE Plasma 5.22.5 tk: Qt 5.15.2 info: latte-dock wm: kwin_x11 vt: 1 dm: SDDM
           Distro: Garuda Linux base: Arch Linux
Machine:   Type: Laptop System: LENOVO product: 20175 v: Lenovo IdeaPad Yoga 13 serial: <filter> Chassis:
           type: 10 v: Lenovo IdeaPad Yoga 13 serial: <filter>
           Mobo: LENOVO model: INVALID v: 31900003WIN8 STD MLT serial: <filter> UEFI: LENOVO v: 66CN55WW
           date: 02/28/2013
Battery:   ID-1: BAT1 charge: 37.7 Wh (98.2%) condition: 38.4/49.3 Wh (78.0%) volts: 16.0 min: 14.8
           model: Lenovo IdeaPad Mocca2 type: Unknown serial: <filter> status: Unknown
CPU:       Info: Dual Core model: Intel Core i7-3537U bits: 64 type: MT MCP arch: Ivy Bridge family: 6
           model-id: 3A (58) stepping: 9 microcode: 21 cache: L2: 4 MiB
           flags: avx lm nx pae sse sse2 sse3 sse4_1 sse4_2 ssse3 vmx bogomips: 19954
           Speed: 2817 MHz min/max: 800/3100 MHz Core speeds (MHz): 1: 2817 2: 2827 3: 2818 4: 2824
           Vulnerabilities: Type: itlb_multihit status: KVM: VMX disabled
           Type: l1tf mitigation: PTE Inversion; VMX: conditional cache flushes, SMT vulnerable
           Type: mds mitigation: Clear CPU buffers; SMT vulnerable
           Type: meltdown mitigation: PTI
           Type: spec_store_bypass mitigation: Speculative Store Bypass disabled via prctl and seccomp
           Type: spectre_v1 mitigation: usercopy/swapgs barriers and __user pointer sanitization
           Type: spectre_v2
           mitigation: Full generic retpoline, IBPB: conditional, IBRS_FW, STIBP: conditional, RSB filling
           Type: srbds status: Vulnerable: No microcode
           Type: tsx_async_abort status: Not affected
Graphics:  Device-1: Intel 3rd Gen Core processor Graphics vendor: Lenovo driver: i915 v: kernel
           bus-ID: 00:02.0 chip-ID: 8086:0166 class-ID: 0300
           Device-2: Chicony Lenovo EasyCamera type: USB driver: uvcvideo bus-ID: 2-1.7:4 chip-ID: 04f2:b322
           class-ID: 0e02
           Display: x11 server: X.Org 1.20.13 compositor: kwin_x11 driver: loaded: intel unloaded: modesetting
           alternate: fbdev,vesa display-ID: :0 screens: 1
           Screen-1: 0 s-res: 1600x900 s-dpi: 96 s-size: 423x238mm (16.7x9.4") s-diag: 485mm (19.1")
           Monitor-1: LVDS1 res: 1600x900 hz: 60 dpi: 140 size: 290x170mm (11.4x6.7") diag: 336mm (13.2")
           OpenGL: renderer: Mesa DRI Intel HD Graphics 4000 (IVB GT2) v: 4.2 Mesa 21.2.2 compat-v: 3.0
           direct render: Yes
Audio:     Device-1: Intel 7 Series/C216 Family High Definition Audio vendor: Lenovo driver: snd_hda_intel
           v: kernel bus-ID: 00:1b.0 chip-ID: 8086:1e20 class-ID: 0403
           Device-2: DisplayLink Kensington SD4000 USB Dock type: USB driver: cdc_ncm,snd-usb-audio
           bus-ID: 4-2.1:3 chip-ID: 17e9:4344 class-ID: 0a00 serial: <filter>
           Sound Server-1: ALSA v: k5.14.8-zen1-1-zen running: yes
           Sound Server-2: JACK v: 1.9.19 running: no
           Sound Server-3: PulseAudio v: 15.0 running: no
           Sound Server-4: PipeWire v: 0.3.37 running: yes
Network:   Message: No device data found.
           IF-ID-1: enp0s20u2u1i5 state: down mac: <filter>
           IF-ID-2: vmnet1 state: unknown speed: N/A duplex: N/A mac: <filter>
           IF-ID-3: vmnet8 state: unknown speed: N/A duplex: N/A mac: <filter>
           IF-ID-4: wlp0s26u1u4i2 state: up mac: <filter>
Bluetooth: Device-1: Realtek RTL8723AU 802.11n WLAN Adapter type: USB driver: btusb,rtl8723au bus-ID: 1-1.4:4
           chip-ID: 0bda:1724 class-ID: e001 serial: <filter>
           Report: bt-adapter ID: hci0 rfk-id: 0 state: down bt-service: enabled,running rfk-block:
           hardware: no software: yes address: <filter>
Drives:    Local Storage: total: 1.14 TiB used: 420.72 GiB (36.0%)
           SMART Message: Unable to run smartctl. Root privileges required.
           ID-1: /dev/sda maj-min: 8:0 vendor: Samsung model: MZMTD256HAGM-000L1 size: 238.47 GiB block-size:
           physical: 512 B logical: 512 B speed: 3.0 Gb/s type: SSD serial: <filter> rev: 2L0Q scheme: GPT
           ID-2: /dev/sdb maj-min: 8:16 type: USB vendor: Western Digital model: WD My Passport 0820
           size: 931.48 GiB block-size: physical: 512 B logical: 512 B type: N/A serial: <filter> rev: 1007
           scheme: GPT
Partition: ID-1: / raw-size: 922.42 GiB size: 922.42 GiB (100.00%) used: 226.85 GiB (24.6%) fs: btrfs
           dev: /dev/sdb2 maj-min: 8:18
           ID-2: /boot/efi raw-size: 260 MiB size: 256 MiB (98.45%) used: 562 KiB (0.2%) fs: vfat
           dev: /dev/sdb1 maj-min: 8:17
           ID-3: /home raw-size: 922.42 GiB size: 922.42 GiB (100.00%) used: 226.85 GiB (24.6%) fs: btrfs
           dev: /dev/sdb2 maj-min: 8:18
           ID-4: /var/log raw-size: 922.42 GiB size: 922.42 GiB (100.00%) used: 226.85 GiB (24.6%) fs: btrfs
           dev: /dev/sdb2 maj-min: 8:18
           ID-5: /var/tmp raw-size: 922.42 GiB size: 922.42 GiB (100.00%) used: 226.85 GiB (24.6%) fs: btrfs
           dev: /dev/sdb2 maj-min: 8:18
Swap:      Kernel: swappiness: 133 (default 60) cache-pressure: 100 (default)
           ID-1: swap-1 type: zram size: 7.64 GiB used: 5.83 GiB (76.3%) priority: 100 dev: /dev/zram0
           ID-2: swap-2 type: partition size: 8.8 GiB used: 0 KiB (0.0%) priority: -2 dev: /dev/sdb3
           maj-min: 8:19
Sensors:   System Temperatures: cpu: 65.0 C mobo: N/A
           Fan Speeds (RPM): N/A
Info:      Processes: 294 Uptime: 18h 30m wakeups: 1 Memory: 7.64 GiB used: 5.08 GiB (66.4%) Init: systemd
           v: 249 tool: systemctl Compilers: gcc: 11.1.0 clang: 12.0.1 Packages: 1778 pacman: 1769 lib: 535
           flatpak: 9 Shell: Zsh v: 5.8 running-in: alacritty inxi: 3.3.06

I tried to include an upload of systemd-analyze plot as a converted png from the svg output, but it was WAY too large for it to be useful here.

i am having the same issue, did you ever find a solution?

Nope....consistently long run times during boot. Every time. It's helped since I've switched over to the linux-xanmod-cacule kernel, but just means it's processing a little faster.

To have a true image of the potential issue, use

systemd-analyze critical-chain

which gives the real bottleneck.
The clean-up should not block the rest of the boot normally.
If there is an issue, post a bug report upstream (the github link is posted in a previous post).

4 Likes

Hmmm....here's my output:

systemd-analyze
❯ systemd-analyze
Startup finished in 9.383s (firmware) + 11.454s (loader) + 17.335s (kernel) + 3min 19.623s (userspace) = 3min 57.795s
graphical.target reached after 1min 47.482s in userspace
systemd-analyze blame
❯ systemd-analyze blame
2min 33.353s linux-modules-cleanup.service
     34.150s nmb.service
     27.839s dev-sdb2.device
     21.598s systemd-remount-fs.service
     15.189s smb.service
     11.543s polkit.service
     10.623s teamviewerd.service
     10.244s ModemManager.service
      9.466s vmware-networks.service
      7.901s ldconfig.service
      6.297s NetworkManager-wait-online.service
      5.316s avahi-daemon.service
      5.312s bluetooth.service
      5.307s NetworkManager.service
      5.303s iio-sensor-proxy.service
      5.262s systemd-logind.service
      5.259s systemd-machined.service
      4.045s home-shaya-Network-LC_homes_archive.mount
      3.636s home-shaya-Network-Shaya.mount
      3.311s home-shaya-Network-Public.mount
      3.263s grub-btrfs-snapper.service
      2.253s lm_sensors.service
      2.146s ufw.service
      1.719s wpa_supplicant.service
      1.342s systemd-vconsole-setup.service
      1.338s systemd-sysusers.service
      1.232s systemd-modules-load.service
      1.203s Windows8_OS.mount
      1.116s systemd-udevd.service
systemd-analyze critical-chain
❯ 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 @1min 47.482s
└─multi-user.target @1min 47.482s
  └─smb.service @1min 32.292s +15.189s
    └─nmb.service @58.138s +34.150s
      └─network-online.target @57.866s
        └─NetworkManager-wait-online.service @51.567s +6.297s
          └─NetworkManager.service @46.257s +5.307s
            └─dbus.service @46.249s
              └─basic.target @46.237s
                └─sockets.target @46.237s
                  └─nordvpnd.socket @46.193s +43ms
                    └─sysinit.target @46.116s
                      └─systemd-update-done.service @46.061s +54ms
                        └─ldconfig.service @38.158s +7.901s
                          └─local-fs.target @38.156s
                            └─boot-efi.mount @38.065s +91ms
                              └─[email protected]\x2duuid-1562\x2d3E70.service @37.223s +840ms
                                └─dev-disk-by\x2duuid-1562\x2d3E70.device @37.221s

You can see in the blame output, it states that linux-modules-cleanup.service (which runs during EVERY boot - is there a way to find out why? even when there aren't kernel updates?) took 2min 33.353s to complete. I understand that you're saying that while it took that long to complete, the system's not waiting for it to complete to execute on the chain.

However, you'll notice in the basic systemd-analyze output, it's indicating 3min 19.623s (userspace) = 3min 57.795 - which concurs with my manual stopwatch timing to when sddm's login screen rendered and was user-accessible.

critical-chain indicates that the graphical target was 1min 47.482s but that's not true based on IRL stopwatch timing.

Not really sure where to go from here.....and not even sure what bug I'm submitting to the github repo...

EDIT: I'm realizing now that of the total userspace time, it's indicating that 1min 47.482s was the graphical target portion.....I think....

I don't think the system understands its role the same way as humans... :slightly_smiling_face:
It receives an order, to find a target (graphical.target, in this case).
It does the job in (the shortest) time :man_shrugging:
Your stopwatch needs syncing to systemd :grinning_face_with_smiling_eyes:

Apart from joking, if you want knowledge, you have to seek for it.
Start from this:

systemctl cat display-manager.service
systemctl cat  linux-modules-cleanup.service
systemctl status display-manager.service
man systemd.unit

Get into journal and find when your graphical.target is reached and when display manager starts. Then find what's in between them (if any).

linux-modules-cleanup.service starts on every boot, by design and runs ascript.
Study the script (it's just terminal commands, that you may already know, or are useful to know) and experiment:

  • Disable the service (linux-modules-cleanup.service) and reboot.
  • Get analyze status.
  • Run the script's commands one-by-one to see what 's happening and if there is any mysterious, not useful delay.

Go get them!! :grinning_face_with_smiling_eyes:

5 Likes

Thank you so much for this guidance! I'd consider myself an "advanced beginner" or "beginner intermediate" linux user (enough to seriously get into trouble) - so I'm pretty sure I can follow along your suggested approach here and see if I can come to any conclusions (or culprits).

Hopefully I'll have time to perform this forensic analysis before this thread closes and I can provide an update LOL.

1 Like

:neutral_face: Y'all..... I think I figured it out.... it just boils down to the linux-modules-cleanup.service actually just taking THAT long to run. From what I understand in the script, It enumerates through /usr/lib/modules/* and then rsync's backups into /usr/lib/modules/.old/. As I mentioned in an earlier post, I'm running Garuda off a 1TB external HDD connected via USB 3.0, and it's just slow - and I'm bottle-necked by this hardware for now. I currently have 3 kernels installed, along with their headers:

  • linux
  • linux-lts
  • linux-zen
  • linux-xanmod-cacule [current default kernel]

And it just takes THAT much time to enumerate through those paths, and make rsync backups..... I'd be too nervous to disable this permanently, since it seems like it's important to run, and I'm not sure I'd trust myself to remember to turn it back on....I'll have to read up more on how systemd works and see if I can have it execute on every 5th boot or something....

1 Like

It's not that important. 99% of the arch users don't have it. You'll have a pleasant life without it. You'll need to reboot every time a kernel gets updated. Otherwise, modules that didn't load until the update will fail to load when needed.

I've been using arch since 2012, and never cared about installing it :sweat_smile:

2 Likes

Wait....hold up....you're saying I can just execute this script after I install a kernel update, and just keep it disabled during boot?

This specific script's usefulness is questionable and theoretical.
Nobody has it installed except those who do.

And IMHO its logic is not exactly filling the reason it supposes to solve.
But it's my personal opinion.
As loli said, we can live without it, unless proven to fix a problem (which currently is not proven, apart from theories).

2 Likes