Issues with kms and /tmp on boot.

sauceguy · 2025-02-25 08:44:10

Hello everyone.

I am using Arch Linux on Lenovo IdeaPad 15ACH6, with Ryzen 5500H, RTX 2050, with 16GB RAM. Recently I've been trying to decrease my boot times. It used to be around 18-19s, but by using EFIstub, and a few other tweaks, I was able to get it down to around 12-13s.

$ systemd-analyze

Startup finished in 5.086s (firmware) + 92ms (loader) + 1.489s (kernel) + 4.770s (userspace) = 11.439s 
graphical.target reached after 4.754s in userspace.

My current setup is:

$ cat /etc/mkinitcpio.conf # only the non commented part

MODULES=()
BINARIES=()
FILES=()
HOOKS=(base udev autodetect microcode modconf block filesystems fsck)
COMPRESSION="lz4"

$ cat /etc/fstab

# /dev/nvme0n1p6
UUID=4924bd89-385c-423c-af6a-ab32d319c451	/         	ext4      	rw,relatime	0 1

# /dev/nvme0n1p1
UUID=8DB4-7552      	/boot     	vfat      	rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro,x-systemd.automount	0 2

# /dev/nvme0n1p3
UUID=717e4ed3-45c6-4c23-9f4d-37e3100ee246	none      	swap      	defaults  	0 0

# /tmp
tmpfs                   /tmp            tmpfs            defaults,noatime,nosuid,nodev,mode=1777            0 0

$ efibootmgr

BootNext: 0000
BootCurrent: 0000
Timeout: 2 seconds
BootOrder: 0000,0004,2001,2002,2003
Boot0000* Arch EFISTUB	HD(1,GPT,8ec51c20-1d0a-4442-ab8f-3c7f01d7d951,0x800,0x800000)/\vmlinuz-linux-lts72006f006f0074003d0055005500490044003d00340039003200340062006400380039002d0033003800350063002d0034003200330063002d0061006600360061002d00610062003300320064003300310039006300340035003100200072007700200069006e0069007400720064003d005c0061006d0064002d00750063006f00640065002e0069006d006700200069006e0069007400720064003d005c0069006e0069007400720061006d00660073002d006c0069006e00750078002d006c00740073002e0069006d006700
Boot0004* GRUB	HD(1,GPT,8ec51c20-1d0a-4442-ab8f-3c7f01d7d951,0x800,0x800000)/\EFI\GRUB\grubx64.efi
Boot2001* EFI USB Device	RC
Boot2002* EFI DVD/CDROM	RC
Boot2003* EFI Network	RC

I've also removed a bunch of udev rules. Here are only the removed ones:

$ find /usr/lib/udev/rules.d | grep '.bak'

77-mm-ericsson-mbm.rules.bak
77-mm-fibocom-port-types.rules.bak
77-mm-telit-port-types.rules.bak
77-mm-broadmobi-port-types.rules.bak
66-saned.rules.bak
80-mm-candidate.rules.bak
70-joystick.rules.bak
77-mm-foxconn-port-types.rules.bak
77-mm-dlink-port-types.rules.bak
60-cdrom_id.rules.bak
77-mm-ublox-port-types.rules.bak
77-mm-zte-port-types.rules.bak
77-mm-linktop-port-types.rules.bak
70-infrared.rules.bak
77-mm-simtech-port-types.rules.bak
95-cd-devices.rules.bak
40-gphoto.rules.bak
77-mm-quectel-port-types.rules.bak
64-btrfs.rules.bak
77-mm-huawei-net-port-types.rules.bak
77-mm-longcheer-port-types.rules.bak
65-libwacom.rules.bak
77-mm-dell-port-types.rules.bak
77-mm-gosuncn-port-types.rules.bak
69-md-clustered-confirm-device.rules.bak
77-mm-tplink-port-types.rules.bak
77-mm-qcom-soc.rules.bak
77-mm-haier-port-types.rules.bak
64-md-raid-assembly.rules.bak
77-mm-mtk-port-types.rules.bak
65-sane.rules.bak
60-infiniband.rules.bak
77-mm-x22x-port-types.rules.bak
77-mm-cinterion-port-types.rules.bak
77-mm-sierra.rules.bak
77-mm-nokia-port-types.rules.bak

My kernel time used to be around 8s and userspace time used to be around 2.5s. Now, although the kernel time has decreased a lot as I used to have MODULES=(nvidia nvidia_uvm nvidia_modeset nvidia_drm) and HOOK=(... kms ...), the userspace time now has increased by a lot. Here are the current culprits:

$ systemd-analyze blame | head -n 3

1.477s systemd-tmpfiles-setup.service
1.436s systemd-binfmt.service
 828ms NetworkManager.service

Here is the journal data from the current and previous boot, the previous boot had the following setup:

$ cat /etc/mkinitcpio.conf

HOOKS=(base udev autodetect microcode modconf block filesystems fsck)
COMPRESSION="lz4"
MODULES=()
BINARIES=()
FILES=()

$ cat /etc/fstab

# /dev/nvme0n1p6
UUID=4924bd89-385c-423c-af6a-ab32d319c451	/         	ext4      	rw,relatime	0 1

# /dev/nvme0n1p1
UUID=8DB4-7552      	/boot     	vfat      	rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro,x-systemd.automount	0 2

# /dev/nvme0n1p3
UUID=717e4ed3-45c6-4c23-9f4d-37e3100ee246	none      	swap      	defaults  	0 0

# /tmp
tmpfs                   /tmp            tmpfs            defaults,noatime,nosuid,nodev,mode=1777            0 0

$ systemd-analyze blame | head -n 3

501ms systemd-journal-flush.service
396ms dev-nvme0n1p6.device
376ms NetworkManager.service

$ journalctl -u systemd-binfmt.service --no-pager | tail -n 9

-- Boot d62557759dd24f4cb82751b3a8469f8c --
Feb 25 12:51:54 sus systemd[1]: Starting Set Up Additional Binary Formats...
Feb 25 12:51:54 sus systemd[1]: Finished Set Up Additional Binary Formats.
Feb 25 12:57:52 sus systemd[1]: Stopping Set Up Additional Binary Formats...
Feb 25 12:57:52 sus systemd[1]: systemd-binfmt.service: Deactivated successfully.
Feb 25 12:57:52 sus systemd[1]: Stopped Set Up Additional Binary Formats.
-- Boot 0da380068f8545699e18d9903da458d7 --
Feb 25 12:58:01 sus systemd[1]: Starting Set Up Additional Binary Formats...
Feb 25 12:58:03 sus systemd[1]: Finished Set Up Additional Binary Formats.

$ journalctl -u systemd-tmpfiles-setup.service --no-pager | tail -n 9

-- Boot d62557759dd24f4cb82751b3a8469f8c --
Feb 25 12:51:54 sus systemd[1]: Starting Create System Files and Directories...trigger condition checks were met.

Feb 25 12:51:54 sus systemd-tmpfiles[456]: /etc/tmpfiles.d/systemd-resolve.conf:10: Duplicate line for path "/etc/resolv.conf", ignoring.
Feb 25 12:51:54 sus systemd[1]: Finished Create System Files and Directories.
Feb 25 12:57:52 sus systemd[1]: systemd-tmpfiles-setup.service: Deactivated successfully.
Feb 25 12:57:52 sus systemd[1]: Stopped Create System Files and Directories.
-- Boot 0da380068f8545699e18d9903da458d7 --
Feb 25 12:58:01 sus systemd[1]: Starting Create System Files and Directories...
Feb 25 12:58:03 sus systemd[1]: Finished Create System Files and Directories.

$ journalctl -u NetworkManager.service --no-pager | tail -n 148

-- Boot 0da380068f8545699e18d9903da458d7 --
Feb 25 12:58:03 sus systemd[1]: Starting Network Manager...
Feb 25 12:58:03 sus NetworkManager[545]: <info>  [1740468483.6299] NetworkManager (version 1.50.2-1) is starting... (boot:0da38006-8f85-4569-9e18-d9903da458d7)
Feb 25 12:58:03 sus NetworkManager[545]: <info>  [1740468483.6299] Read config: /etc/NetworkManager/NetworkManager.conf (lib: 20-connectivity.conf, 30-wifi-backend.conf) (etc: wifi_backend.conf)
Feb 25 12:58:03 sus NetworkManager[545]: <warn>  [1740468483.6300] config: unknown key 'wifi_backend' in section [device] of file '/etc/NetworkManager/conf.d/wifi_backend.conf'
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.1714] manager[0x59cc887fbcd0]: monitoring kernel firmware directory '/lib/firmware'.
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.1732] hostname: hostname: using hostnamed
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.1732] hostname: static hostname changed from (none) to "sus"
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.1734] dns-mgr: init: dns=default,systemd-resolved rc-manager=symlink
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.1749] rfkill3: found Wi-Fi radio killswitch (at /sys/devices/pci0000:00/0000:00:01.3/0000:03:00.0/ieee80211/phy0/rfkill3) (driver mt7921e)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.1751] rfkill1: found Wi-Fi radio killswitch (at /sys/devices/pci0000:00/0000:00:14.3/PNP0C09:00/VPC2004:00/rfkill/rfkill1) (platform driver ideapad_acpi)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2043] manager[0x59cc887fbcd0]: rfkill: Wi-Fi hardware radio set enabled
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2044] manager[0x59cc887fbcd0]: rfkill: WWAN hardware radio set enabled
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2315] Loaded device plugin: NMTeamFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-team.so)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2326] Loaded device plugin: NMWifiFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-wifi.so)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2354] Loaded device plugin: NMBluezManager (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-bluetooth.so)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2357] Loaded device plugin: NMWwanFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-wwan.so)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2363] Loaded device plugin: NMOvsFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-ovs.so)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2368] Loaded device plugin: NMAtmManager (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-adsl.so)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2369] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2370] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2370] manager: Networking is enabled by state file
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2376] settings: Loaded settings plugin: keyfile (internal)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2441] dhcp: init: Using DHCP client 'internal'
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2442] manager: (lo): new Loopback device (/org/freedesktop/NetworkManager/Devices/1)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2448] device (lo): state change: unmanaged -> unavailable (reason 'connection-assumed', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2452] device (lo): state change: unavailable -> disconnected (reason 'connection-assumed', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2455] device (lo): Activation: starting connection 'lo' (c0fe14e2-56eb-410a-b20f-855df8c29142)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2459] manager: (enp2s0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2463] settings: (enp2s0): created default wired connection 'Wired connection 1'
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.2464] device (enp2s0): state change: unmanaged -> unavailable (reason 'managed', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4490] manager: (wlan0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/3)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4492] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', managed-type: 'external')
Feb 25 12:58:04 sus systemd[1]: Started Network Manager.
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4527] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4540] device (wlan0): new IWD device state is disconnected
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4541] ovsdb: disconnected from ovsdb
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4542] device (lo): state change: disconnected -> prepare (reason 'none', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4543] device (lo): state change: prepare -> config (reason 'none', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4544] device (lo): state change: config -> ip-config (reason 'none', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4548] device (lo): state change: ip-config -> ip-check (reason 'none', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4550] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-available', managed-type: 'full')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4553] manager: (AC:39:71:9F:39:B2): new Bluetooth device (/org/freedesktop/NetworkManager/Devices/4)
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4554] device (AC:39:71:9F:39:B2): state change: unmanaged -> unavailable (reason 'managed', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4556] device (lo): state change: ip-check -> secondaries (reason 'none', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4557] device (AC:39:71:9F:39:B2): state change: unavailable -> disconnected (reason 'none', managed-type: 'full')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4558] device (lo): state change: secondaries -> activated (reason 'none', managed-type: 'external')
Feb 25 12:58:04 sus NetworkManager[545]: <info>  [1740468484.4559] device (lo): Activation: successful, device activated.
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.1469] device (wlan0): new IWD device state is connecting
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.1472] device (wlan0): Activation: starting connection 'Hriom_4g' (cb181995-6436-4e48-accf-64bb03b06953)
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.1477] device (wlan0): state change: disconnected -> prepare (reason 'none', managed-type: 'full')
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.1478] manager: NetworkManager state is now CONNECTING
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.1479] device (wlan0): state change: prepare -> config (reason 'none', managed-type: 'full')
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.3701] device (wlan0): new IWD device state is connected
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.3702] device (wlan0): state change: config -> ip-config (reason 'none', managed-type: 'full')
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.3707] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.3976] dhcp4 (wlan0): state changed new lease, address=192.168.1.14, acd pending
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.6310] dhcp4 (wlan0): state changed new lease, address=192.168.1.14
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.6315] policy: set 'Hriom_4g' (wlan0) as default for IPv4 routing and DNS
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.6382] device (wlan0): state change: ip-config -> ip-check (reason 'none', managed-type: 'full')
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.6389] device (wlan0): state change: ip-check -> secondaries (reason 'none', managed-type: 'full')
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.6390] device (wlan0): state change: secondaries -> activated (reason 'none', managed-type: 'full')
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.6391] manager: NetworkManager state is now CONNECTED_SITE
Feb 25 12:58:05 sus NetworkManager[545]: <info>  [1740468485.6392] device (wlan0): Activation: successful, device activated.
Feb 25 12:58:06 sus NetworkManager[545]: <info>  [1740468486.0157] manager: NetworkManager state is now CONNECTED_GLOBAL
Feb 25 12:58:10 sus NetworkManager[545]: <info>  [1740468490.4487] manager: startup complete
Feb 25 13:01:31 sus NetworkManager[545]: <info>  [1740468691.9621] agent-manager: agent[b79d7462a3493c6c,:1.31/org.freedesktop.nm-applet/1000]: agent registered
Feb 25 13:27:46 sus NetworkManager[545]: <info>  [1740470266.6785] device (AC:39:71:9F:39:B2): state change: disconnected -> unmanaged (reason 'unmanaged-link-not-init', managed-type: 'removed')
Feb 25 13:27:47 sus systemd[1]: Stopping Network Manager...
Feb 25 13:27:47 sus NetworkManager[545]: <info>  [1740470267.1346] caught SIGTERM, shutting down normally.
Feb 25 13:27:47 sus NetworkManager[545]: <info>  [1740470267.1354] device (wlan0): state change: activated -> deactivating (reason 'unmanaged', managed-type: 'full')
Feb 25 13:27:47 sus NetworkManager[545]: <info>  [1740470267.1355] manager: NetworkManager state is now DISCONNECTING
Feb 25 13:27:47 sus NetworkManager[545]: <warn>  [1740470267.1370] dispatcher: (10) failed (after 0.002 sec): Could not activate remote peer 'org.freedesktop.nm_dispatcher': activation request failed: unit is invalid
Feb 25 13:27:47 sus NetworkManager[545]: <info>  [1740470267.1373] device (wlan0): state change: deactivating -> unmanaged (reason 'unmanaged-quitting', managed-type: 'full')
Feb 25 13:27:47 sus NetworkManager[545]: <info>  [1740470267.1373] dhcp4 (wlan0): canceled DHCP transaction
Feb 25 13:27:47 sus NetworkManager[545]: <info>  [1740470267.1373] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Feb 25 13:27:47 sus NetworkManager[545]: <info>  [1740470267.1373] dhcp4 (wlan0): state changed no lease
Feb 25 13:27:48 sus NetworkManager[545]: <info>  [1740470268.8663] manager: NetworkManager state is now DISCONNECTED
Feb 25 13:27:48 sus NetworkManager[545]: <info>  [1740470268.8774] exiting (success)
Feb 25 13:27:48 sus systemd[1]: NetworkManager.service: Deactivated successfully.
Feb 25 13:27:48 sus systemd[1]: Stopped Network Manager.
-- Boot e9f10d50cd87447780ba1e17e9b37628 --
Feb 25 13:28:01 sus systemd[1]: Starting Network Manager...
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.4968] NetworkManager (version 1.50.2-1) is starting... (boot:e9f10d50-cd87-4477-80ba-1e17e9b37628)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.4969] Read config: /etc/NetworkManager/NetworkManager.conf (lib: 20-connectivity.conf, 30-wifi-backend.conf)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5013] manager[0x6226ef55eb40]: monitoring kernel firmware directory '/lib/firmware'.
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5031] hostname: hostname: using hostnamed
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5031] hostname: static hostname changed from (none) to "sus"
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5033] dns-mgr: init: dns=default,systemd-resolved rc-manager=symlink
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5048] rfkill3: found Wi-Fi radio killswitch (at /sys/devices/pci0000:00/0000:00:01.3/0000:03:00.0/ieee80211/phy0/rfkill3) (driver mt7921e)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5050] rfkill0: found Wi-Fi radio killswitch (at /sys/devices/pci0000:00/0000:00:14.3/PNP0C09:00/VPC2004:00/rfkill/rfkill0) (platform driver ideapad_acpi)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5781] manager[0x6226ef55eb40]: rfkill: Wi-Fi hardware radio set enabled
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.5781] manager[0x6226ef55eb40]: rfkill: WWAN hardware radio set enabled
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6057] Loaded device plugin: NMTeamFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-team.so)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6068] Loaded device plugin: NMWifiFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-wifi.so)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6097] Loaded device plugin: NMBluezManager (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-bluetooth.so)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6101] Loaded device plugin: NMWwanFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-wwan.so)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6107] Loaded device plugin: NMOvsFactory (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-ovs.so)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6111] Loaded device plugin: NMAtmManager (/usr/lib/NetworkManager/1.50.2-1/libnm-device-plugin-adsl.so)
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6113] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6114] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6115] manager: Networking is enabled by state file
Feb 25 13:28:01 sus NetworkManager[537]: <info>  [1740470281.6120] settings: Loaded settings plugin: keyfile (internal)
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0512] dhcp: init: Using DHCP client 'internal'
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0514] manager: (lo): new Loopback device (/org/freedesktop/NetworkManager/Devices/1)
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0521] device (lo): state change: unmanaged -> unavailable (reason 'connection-assumed', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0525] device (lo): state change: unavailable -> disconnected (reason 'connection-assumed', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0529] device (lo): Activation: starting connection 'lo' (ff5d1c68-79a1-4538-85e4-b5650cade43e)
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0533] manager: (enp2s0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2)
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0539] settings: (enp2s0): created default wired connection 'Wired connection 1'
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.0539] device (enp2s0): state change: unmanaged -> unavailable (reason 'managed', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2430] manager: (wlan0): new 802.11 Wi-Fi device (/org/freedesktop/NetworkManager/Devices/3)
Feb 25 13:28:02 sus systemd[1]: Started Network Manager.
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2460] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2472] device (wlan0): new IWD device state is disconnected
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2474] ovsdb: disconnected from ovsdb
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2474] device (lo): state change: disconnected -> prepare (reason 'none', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2476] device (lo): state change: prepare -> config (reason 'none', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2477] device (lo): state change: config -> ip-config (reason 'none', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2482] device (lo): state change: ip-config -> ip-check (reason 'none', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2485] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2490] device (lo): state change: ip-check -> secondaries (reason 'none', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2491] device (wlan0): state change: unavailable -> disconnected (reason 'none', managed-type: 'full')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2493] device (lo): state change: secondaries -> activated (reason 'none', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2496] device (lo): Activation: successful, device activated.
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2499] manager: (AC:39:71:9F:39:B2): new Bluetooth device (/org/freedesktop/NetworkManager/Devices/4)
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2501] device (AC:39:71:9F:39:B2): state change: unmanaged -> unavailable (reason 'managed', managed-type: 'external')
Feb 25 13:28:02 sus NetworkManager[537]: <info>  [1740470282.2504] device (AC:39:71:9F:39:B2): state change: unavailable -> disconnected (reason 'none', managed-type: 'full')
Feb 25 13:28:03 sus NetworkManager[537]: <info>  [1740470283.0392] device (wlan0): new IWD device state is connecting
Feb 25 13:28:03 sus NetworkManager[537]: <info>  [1740470283.0394] device (wlan0): Activation: starting connection 'Hriom_4g' (cb181995-6436-4e48-accf-64bb03b06953)
Feb 25 13:28:03 sus NetworkManager[537]: <info>  [1740470283.0396] device (wlan0): state change: disconnected -> prepare (reason 'none', managed-type: 'full')
Feb 25 13:28:03 sus NetworkManager[537]: <info>  [1740470283.0397] manager: NetworkManager state is now CONNECTING
Feb 25 13:28:03 sus NetworkManager[537]: <info>  [1740470283.0398] device (wlan0): state change: prepare -> config (reason 'none', managed-type: 'full')
Feb 25 13:28:04 sus NetworkManager[537]: <info>  [1740470284.1641] device (wlan0): new IWD device state is connected
Feb 25 13:28:04 sus NetworkManager[537]: <info>  [1740470284.1642] device (wlan0): state change: config -> ip-config (reason 'none', managed-type: 'full')
Feb 25 13:28:04 sus NetworkManager[537]: <info>  [1740470284.1647] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Feb 25 13:28:10 sus NetworkManager[537]: <info>  [1740470290.1586] device (wlan0): state change: ip-config -> ip-check (reason 'none', managed-type: 'full')
Feb 25 13:28:10 sus NetworkManager[537]: <info>  [1740470290.1593] device (wlan0): state change: ip-check -> secondaries (reason 'none', managed-type: 'full')
Feb 25 13:28:10 sus NetworkManager[537]: <info>  [1740470290.1594] device (wlan0): state change: secondaries -> activated (reason 'none', managed-type: 'full')
Feb 25 13:28:10 sus NetworkManager[537]: <info>  [1740470290.1596] manager: NetworkManager state is now CONNECTED_LOCAL
Feb 25 13:28:10 sus NetworkManager[537]: <info>  [1740470290.1598] device (wlan0): Activation: successful, device activated.
Feb 25 13:28:10 sus NetworkManager[537]: <info>  [1740470290.1601] manager: startup complete
Feb 25 13:28:11 sus NetworkManager[537]: <info>  [1740470291.2962] agent-manager: agent[23e2b5fd40292ec2,:1.30/org.freedesktop.nm-applet/1000]: agent registered
Feb 25 13:28:13 sus NetworkManager[537]: <info>  [1740470293.6487] dhcp4 (wlan0): state changed new lease, address=192.168.1.14, acd pending
Feb 25 13:28:13 sus NetworkManager[537]: <info>  [1740470293.8214] dhcp4 (wlan0): state changed new lease, address=192.168.1.14
Feb 25 13:28:13 sus NetworkManager[537]: <info>  [1740470293.8216] manager: NetworkManager state is now CONNECTED_SITE
Feb 25 13:28:13 sus NetworkManager[537]: <info>  [1740470293.8217] policy: set 'Hriom_4g' (wlan0) as default for IPv4 routing and DNS
Feb 25 13:28:20 sus NetworkManager[537]: <info>  [1740470300.4262] manager: NetworkManager state is now CONNECTED_GLOBAL

I have basically no idea what is going. The wiki for mkinitcpio says that the HOOk kms is related to graphics, so I don't understand how that results in the tmp services getting slow. During the boot process, it seems to get stuck on the following:

[  OK  ] Listening on Disk Image Download Service Socket.
[  OK  ] Listening on System Extension Image Management.
         Starting Set Up Additional Binary Formats...
         Starting Create System Files and Directories...

It doesn't get stuck on the first one. It used to, when I had the following setup.

$ cat /etc/mkinitcpio.conf

HOOKS=(base udev autodetect microcode modconf block filesystems fsck)
COMPRESSION="lz4"
MODULES=()
BINARIES=()
FILES=()

$ cat /etc/fstab

# /dev/nvme0n1p6
UUID=4924bd89-385c-423c-af6a-ab32d319c451	/         	ext4      	rw,relatime	0 1

# /dev/nvme0n1p1
UUID=8DB4-7552      	/boot     	vfat      	rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,utf8,errors=remount-ro,x-systemd.automount	0 2

# /dev/nvme0n1p3
UUID=717e4ed3-45c6-4c23-9f4d-37e3100ee246	none      	swap      	defaults  	0 0

$ systemd-analyze blame | head -n 2

1.670s tmp.mount
1.371 NetworkManager.service

And another variant of this setup, perhaps with an entry for tmpfs in fstab with x-systemd.automount.

Now the Disk Image.. issue is gone, but System Extension.. is up. I didn't findthing in the wiki for "System Extension Image Management". I also checked the page for systemd-tmpfiles, though that didn't have much on systemd-tmpfiles-setup.service and systemd-binfmt.service either. There was a page on Manjaro Linux form, which although didn't help, mentioned that there aren't many documented cases in systemd-tmpfiles-setup.service.

The funny thing is that including kms in the hooks basically solves everything. Then I don't have the systemd-.. slowing down boot, or boot.mount, or tmp.mount. kms itself makes the boot slow enough though.

Any suggestions to fix these issues, without including kms?

Edit: maybe this is relevant:

$ fuser -vm /tmp

                     USER        PID ACCESS COMMAND
/tmp:                root     kernel mount /tmp
                     sauceguy    616 F.... zsh
                     sauceguy    685 f.... zsh
                     sauceguy    704 f.... zsh
                     sauceguy    707 f.... gitstatusd-linu
                     sauceguy    752 F.... hyprland
                     sauceguy    970 F.... Xwayland
                     sauceguy  10084 F.... zsh
                     sauceguy  10113 f.... zsh
                     sauceguy  10128 f.... zsh
                     sauceguy  10131 f.... gitstatusd-linu
                     root      10176 F.... zsh
                     root      10179 f.... zsh
                     root      10217 f.... zsh
                     root      10220 f.... gitstatusd-linu

Last edited by sauceguy (2025-02-25 11:09:26)

V1del · 2025-02-25 10:51:44

I don't really see anything to fix here. Systemd generally runs things in parallel, if you brought down general boot enough so that the userspace component that needs to run (systemd-tmpfiles is expected to finish before properly moving to multi-user as it sets up tmpfiles that userspace can be expecting) is becoming the "limiting" factor then that's how it is. /tmp has btw no inherent relation to systemd-tmpfiles, systemd-tmpfiles mostly concerns itself with setting up necessary runtime files under /run.

Also please edit your post and use [ code ] not [ quote ] tags.

sauceguy · 2025-02-25 12:14:53

So, what you are saying is that it's not systemd-tmpfiles the one which is causing issues, something from the userspace is causing it slow down? If so, how can I check what that is? I can think of systemd-analyze critical-chain systemd-tmpfiles-setup.service, but that only shows how much time systemd-tmpfiles took.

1. With kms

$ systemd-analyze critical-chain systemd-tmpfiles-setup.service

systemd-tmpfiles-setup.service +85ms
└─local-fs.target @1.429s
  └─boot.automount @571ms
    └─local-fs-pre.target @570ms
      └─systemd-tmpfiles-setup-dev.service @496ms +73ms
        └─systemd-tmpfiles-setup-dev-early.service @435ms +57ms
          └─kmod-static-nodes.service @419ms +12ms
            └─systemd-journald.socket @413ms
              └─-.mount @373ms
                └─-.slice @372ms

2. Without kms

$ systemd-analyze critical-chain systemd-tmpfiles-setup.service

systemd-tmpfiles-setup.service +1.557s
└─local-fs.target @1.454s
  └─boot.automount @572ms
    └─local-fs-pre.target @571ms
      └─systemd-tmpfiles-setup-dev.service @545ms +24ms
        └─systemd-tmpfiles-setup-dev-early.service @462ms +78ms
          └─kmod-static-nodes.service @442ms +14ms
            └─systemd-journald.socket @436ms
              └─-.mount @397ms
                └─-.slice @397ms

Clearly the execution takes a lot more time without the slow down from kms.

Last edited by sauceguy (2025-02-25 12:15:26)

V1del · 2025-02-25 18:03:52

Yes this is what I'm suggesting, kms delays kernel bringup enough that tmpfiles becomes a factor only later in the boot process. Since you don't have the implied kms slowdown, systemd-tmpfiles becomes the "limitting" factor, because boot can only continue once tmpfiles are set up. If you want to microoptimize this you could check out configuration of tmpfiles and see whether there are some you could shave off, but doing so requires a very good understanding of how the system interacts with these and I'd strongly suggest you don't haphazardly mess around there just to shave off a second. see https://wiki.archlinux.org/title/System … rary_files

Last edited by V1del (2025-02-25 18:06:24)

sauceguy · 2025-02-25 18:11:41

Hm..Looks like I finally hit a bigger hurdle. Although I don't know if I'll be going further down this path, maybe I'll get to it sometimes later. Anyways, thanks for the replies.

Arch Linux

#1 2025-02-25 08:44:10

Issues with kms and /tmp on boot.

#2 2025-02-25 10:51:44

Re: Issues with kms and /tmp on boot.

#3 2025-02-25 12:14:53

Re: Issues with kms and /tmp on boot.

#4 2025-02-25 18:03:52

Re: Issues with kms and /tmp on boot.

#5 2025-02-25 18:11:41

Re: Issues with kms and /tmp on boot.

Board footer