Long Login Time, 30+ seconds from login to desktop

Hello!

I'm on KDE Dragonized, see garuda-inxi below for more info. Need some help reading a log. It takes about 30 seconds total to log in, and there seems to be a 15 second hangtime at these two lines in the middle line here:

May 24 19:02:17 dragonfruit systemd[6936]: Started KScreen.
[...]
May 24 19:02:15 dragonfruit systemd[6936]: Reloading requested from client PID 6960 ('startplasma-x11')...
May 24 19:02:01 dragonfruit systemd[1]: systemd-hostnamed.service: Deactivated successfully.
[...]
May 24 19:01:45 dragonfruit (systemd)[6936]: pam_unix(systemd-user:session): session opened for user meredith(uid=1000) by meredith(uid=0)

A total of 32 seconds from login to when the desktop renderer/screen manager, etc. starts launching. Linked is the privatebin of the full journalctl -r output run right after login:

garuda-inxi
╭─[email protected] in ~ via  v11.0.19
╰─λ garuda-inxi
System:
Kernel: 6.3.3-zen1-1-zen arch: x86_64 bits: 64 compiler: gcc v: 13.1.1
parameters: BOOT_IMAGE=/@/boot/vmlinuz-linux-zen
root=UUID=f6cccf9c-8580-435e-8f33-927e3e31bb2d rw [email protected]
rd.driver.pre=vfio-pci amd_iommu=on quiet splash rd.udev.log_priority=3
vt.global_cursor_default=0
resume=UUID=2e9cba84-8fd3-4884-995e-6ac1c54716ad loglevel=3
vfio-pci.ids=10de:17c8,10de:0fb0 nvidia-drm.modeset=1 ibt=off
Desktop: KDE Plasma v: 5.27.5 tk: Qt v: 5.15.9 wm: kwin_x11 vt: 1 dm: SDDM
Distro: Garuda Linux base: Arch Linux
Machine:
Type: Desktop System: Gigabyte product: X570 AORUS ELITE v: -CF
serial: <superuser required>
Mobo: Gigabyte model: X570 AORUS ELITE v: x.x serial: <superuser required>
UEFI: American Megatrends LLC. v: F34 date: 06/10/2021
Battery:
ID-1: hidpp_battery_0 charge: 52% condition: N/A volts: 3.8 min: N/A
model: Logitech G502 LIGHTSPEED Wireless Gaming Mouse type: N/A
serial: <filter> status: discharging
CPU:
Info: model: AMD Ryzen 9 3950X bits: 64 type: MT MCP arch: Zen 2 gen: 3
level: v3 note: check built: 2020-22 process: TSMC n7 (7nm)
family: 0x17 (23) model-id: 0x71 (113) stepping: 0 microcode: 0x8701021
Topology: cpus: 1x cores: 16 tpc: 2 threads: 32 smt: enabled cache:
L1: 1024 KiB desc: d-16x32 KiB; i-16x32 KiB L2: 8 MiB desc: 16x512 KiB
L3: 64 MiB desc: 4x16 MiB
Speed (MHz): avg: 3529 high: 3959 min/max: 2200/4761 boost: enabled
scaling: driver: acpi-cpufreq governor: performance cores: 1: 3500 2: 3500
3: 3500 4: 3500 5: 3500 6: 3959 7: 3500 8: 3733 9: 3500 10: 3500 11: 3500
12: 3594 13: 3500 14: 3500 15: 3500 16: 3500 17: 3654 18: 3500 19: 3500
20: 3500 21: 3500 22: 3500 23: 3500 24: 3500 25: 3500 26: 3500 27: 3500
28: 3500 29: 3500 30: 3500 31: 3500 32: 3500 bogomips: 223576
Flags: avx avx2 ht lm nx pae sse sse2 sse3 sse4_1 sse4_2 sse4a ssse3 svm
Vulnerabilities: <filter>
Graphics:
Device-1: NVIDIA GM200 [GeForce GTX 980 Ti] vendor: Micro-Star MSI
driver: vfio-pci v: N/A alternate: nouveau,nvidia_drm,nvidia
non-free: 530.xx+ status: current (as of 2023-05) arch: Maxwell
code: GMxxx process: TSMC 28nm built: 2014-19 pcie: gen: 3 speed: 8 GT/s
lanes: 4 link-max: lanes: 16 bus-ID: 05:00.0 chip-ID: 10de:17c8
class-ID: 0300
Device-2: NVIDIA TU104 [GeForce RTX 2070 SUPER] vendor: Micro-Star MSI
driver: nvidia v: 530.41.03 alternate: nouveau,nvidia_drm non-free: 530.xx+
status: current (as of 2023-05) arch: Turing code: TUxxx
process: TSMC 12nm FF built: 2018-22 pcie: gen: 3 speed: 8 GT/s lanes: 16
ports: active: none off: DP-1,DP-2 empty: DP-3,HDMI-A-1 bus-ID: 0b:00.0
chip-ID: 10de:1e84 class-ID: 0300
Device-3: Logitech C922 Pro Stream Webcam driver: snd-usb-audio,uvcvideo
type: USB rev: 2.0 speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 1-3.2.3:9
chip-ID: 046d:085c class-ID: 0102 serial: <filter>
Device-4: Focusrite-Novation Scarlett 2i2 Camera driver: snd-usb-audio
type: USB rev: 2.0 speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 7-2:2
chip-ID: 1235:8210 class-ID: 0102 serial: <filter>
Display: x11 server: X.Org v: 21.1.8 with: Xwayland v: 23.1.1
compositor: kwin_x11 driver: X: loaded: nvidia unloaded: modesetting
alternate: fbdev,nouveau,nv,vesa gpu: nvidia,nvidia-nvswitch
display-ID: :0 screens: 1
Screen-1: 0 s-res: 5119x1440 s-dpi: 96 s-size: 1354x381mm (53.31x15.00")
s-diag: 1407mm (55.38")
Monitor-1: DP-1 mapped: DP-0 note: disabled pos: left model: Dell S2716DG
serial: <filter> built: 2016 res: 2560x1440 dpi: 109 gamma: 1.2
size: 598x336mm (23.54x13.23") diag: 686mm (27") ratio: 16:9 modes:
max: 2560x1440 min: 640x480
Monitor-2: DP-2 note: disabled pos: primary,right model: VG27A
serial: <filter> built: 2020 res: 2560x1440 dpi: 109 gamma: 1.2
size: 597x336mm (23.5x13.23") diag: 685mm (27") ratio: 16:9 modes:
max: 2560x1440 min: 640x480
API: OpenGL v: 4.6.0 NVIDIA 530.41.03 renderer: NVIDIA GeForce RTX 2070
SUPER/PCIe/SSE2 direct-render: Yes
Audio:
Device-1: NVIDIA GM200 High Definition Audio vendor: Micro-Star MSI
driver: vfio-pci alternate: snd_hda_intel pcie: speed: Unknown lanes: 63
link-max: gen: 6 speed: 64 GT/s bus-ID: 05:00.1 chip-ID: 10de:0fb0
class-ID: 0403
Device-2: NVIDIA TU104 HD Audio vendor: Micro-Star MSI
driver: snd_hda_intel v: kernel pcie: gen: 3 speed: 8 GT/s lanes: 16
bus-ID: 0b:00.1 chip-ID: 10de:10f8 class-ID: 0403
Device-3: AMD Starship/Matisse HD Audio vendor: Gigabyte
driver: snd_hda_intel v: kernel pcie: gen: 4 speed: 16 GT/s lanes: 16
bus-ID: 0d:00.4 chip-ID: 1022:1487 class-ID: 0403
Device-4: Logitech C922 Pro Stream Webcam driver: snd-usb-audio,uvcvideo
type: USB rev: 2.0 speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 1-3.2.3:9
chip-ID: 046d:085c class-ID: 0102 serial: <filter>
Device-5: Texas Instruments ATH-G1WL
driver: hid-generic,snd-usb-audio,usbhid type: USB rev: 2.0 speed: 12 Mb/s
lanes: 1 mode: 1.1 bus-ID: 1-3.2.4:10 chip-ID: 0451:16ba class-ID: 0300
serial: <filter>
Device-6: Focusrite-Novation Scarlett 2i2 Camera driver: snd-usb-audio
type: USB rev: 2.0 speed: 480 Mb/s lanes: 1 mode: 2.0 bus-ID: 7-2:2
chip-ID: 1235:8210 class-ID: 0102 serial: <filter>
API: ALSA v: k6.3.3-zen1-1-zen status: kernel-api with: aoss
type: oss-emulator tools: alsactl,alsamixer,amixer
Server-1: PipeWire v: 0.3.71 status: active with: 1: pipewire-pulse
status: active 2: wireplumber status: active 3: pipewire-alsa type: plugin
4: pw-jack type: plugin tools: pactl,pw-cat,pw-cli,wpctl
Network:
Device-1: Intel I211 Gigabit Network vendor: Gigabyte driver: igb v: kernel
pcie: gen: 1 speed: 2.5 GT/s lanes: 1 port: d000 bus-ID: 06:00.0
chip-ID: 8086:1539 class-ID: 0200
IF: enp6s0 state: up speed: 1000 Mbps duplex: full mac: <filter>
Device-2: Intel 82575EB Gigabit Network driver: igb v: kernel pcie: gen: 1
speed: 2.5 GT/s lanes: 1 link-max: lanes: 4 port: c020 bus-ID: 07:00.0
chip-ID: 8086:10a7 class-ID: 0200
IF: enp7s0f0 state: down mac: <filter>
Device-3: Intel 82575EB Gigabit Network driver: igb v: kernel pcie: gen: 1
speed: 2.5 GT/s lanes: 1 link-max: lanes: 4 port: c000 bus-ID: 07:00.1
chip-ID: 8086:10a7 class-ID: 0200
IF: enp7s0f1 state: up speed: 1000 Mbps duplex: full mac: <filter>
Bluetooth:
Device-1: TP-Link UB500 Adapter driver: btusb v: 0.8 type: USB rev: 1.1
speed: 12 Mb/s lanes: 1 mode: 1.1 bus-ID: 7-4:3 chip-ID: 2357:0604
class-ID: e001 serial: <filter>
Report: bt-adapter ID: hci0 rfk-id: 0 state: up address: <filter>
Drives:
Local Storage: total: 4.57 TiB used: 1.12 TiB (24.5%)
SMART Message: Unable to run smartctl. Root privileges required.
ID-1: /dev/nvme0n1 maj-min: 259:2 vendor: SanDisk model: ADATA SX6000PNP
size: 953.87 GiB block-size: physical: 512 B logical: 512 B speed: 31.6 Gb/s
lanes: 4 tech: SSD serial: <filter> fw-rev: V9002s85 temp: 37.9 C
scheme: GPT
ID-2: /dev/nvme1n1 maj-min: 259:0 vendor: Western Digital
model: WDS100T1XHE-00AFY0 size: 931.51 GiB block-size: physical: 512 B
logical: 512 B speed: 63.2 Gb/s lanes: 4 tech: SSD serial: <filter>
fw-rev: 614600WD temp: 40.9 C scheme: GPT
ID-3: /dev/sda maj-min: 8:0 vendor: Samsung model: SSD 860 EVO 1TB
size: 931.51 GiB block-size: physical: 512 B logical: 512 B speed: 6.0 Gb/s
tech: SSD serial: <filter> fw-rev: 4B6Q scheme: GPT
ID-4: /dev/sdb maj-min: 8:16 vendor: Western Digital
model: WD20EARX-00ZUDB0 size: 1.82 TiB block-size: physical: 4096 B
logical: 512 B speed: 6.0 Gb/s tech: HDD rpm: 5400 serial: <filter>
fw-rev: 0A80 scheme: GPT
Partition:
ID-1: / raw-size: 896.73 GiB size: 896.73 GiB (100.00%)
used: 647.07 GiB (72.2%) fs: btrfs dev: /dev/sda2 maj-min: 8:2
ID-2: /boot/efi raw-size: 300 MiB size: 299.4 MiB (99.80%)
used: 576 KiB (0.2%) fs: vfat dev: /dev/sda1 maj-min: 8:1
ID-3: /home raw-size: 896.73 GiB size: 896.73 GiB (100.00%)
used: 647.07 GiB (72.2%) fs: btrfs dev: /dev/sda2 maj-min: 8:2
ID-4: /var/log raw-size: 896.73 GiB size: 896.73 GiB (100.00%)
used: 647.07 GiB (72.2%) fs: btrfs dev: /dev/sda2 maj-min: 8:2
ID-5: /var/tmp raw-size: 896.73 GiB size: 896.73 GiB (100.00%)
used: 647.07 GiB (72.2%) fs: btrfs dev: /dev/sda2 maj-min: 8:2
Swap:
Kernel: swappiness: 133 (default 60) cache-pressure: 100 (default)
ID-1: swap-1 type: zram size: 31.28 GiB used: 786.8 MiB (2.5%)
priority: 100 dev: /dev/zram0
ID-2: swap-2 type: partition size: 34.49 GiB used: 0 KiB (0.0%)
priority: -2 dev: /dev/sda3 maj-min: 8:3
Sensors:
System Temperatures: cpu: 61.4 C mobo: 34.0 C gpu: nvidia temp: 51 C
Fan Speeds (RPM): N/A gpu: nvidia fan: 23%
Info:
Processes: 580 Uptime: 13m wakeups: 3 Memory: available: 31.28 GiB
used: 8.67 GiB (27.7%) Init: systemd v: 253 default: graphical
tool: systemctl Compilers: gcc: 13.1.1 alt: 11/12 clang: 15.0.7 Packages:
pm: pacman pkgs: 2631 libs: 586 tools: octopi,pamac,paru Shell: fish
v: 3.6.1 default: Bash v: 5.1.16 running-in: konsole inxi: 3.3.27
Garuda (2.6.16-1):
System install date:     2022-01-22
Last full system update: 2023-05-24
Is partially upgraded:   No
Relevant software:       snapper NetworkManager mkinitcpio nvidia-dkms
Windows dual boot:       Probably (Run as root to verify)
Failed units:

Any help is SO MUCH appreciated. I have no idea after reading the log why it's taking so long...

Please post in and output from

systemd-analyze 
systemd-analyze blame
systemd-analyze critical-chain
3 Likes
systemd-analyze
6.280s NetworkManager-wait-online.service
2.247s linux-modules-cleanup.service
1.325s xrdp.service
1.125s grub-btrfs-snapper.service
 765ms dev-sda2.device
 532ms systemd-journal-flush.service
 458ms mnt-nfs.mount
 445ms mullvad-early-boot-blocking.service
 393ms systemd-networkd-wait-online.service
 313ms NetworkManager.service
 302ms mnt-win.mount
 296ms smb.service
 274ms lvm2-monitor.service
 266ms systemd-tmpfiles-setup.service
 217ms systemd-udev-trigger.service
 189ms systemd-modules-load.service
 170ms plymouth-quit.service
 168ms mnt-fruitsalad.mount
 166ms systemd-remount-fs.service
 159ms [email protected]
 157ms plymouth-quit-wait.service
 150ms xrdp-sesman.service
 145ms systemd-network-generator.service
 131ms plymouth-start.service
 130ms systemd-vconsole-setup.service
 127ms systemd-networkd.service
 124ms dev-zram0.swap
 111ms systemd-tmpfiles-setup-dev.service
 106ms [email protected]\x2duuid-A4AA\x2dCD67.service
 105ms lm_sensors.service
  97ms [email protected]
  97ms systemd-journald.service
  94ms nmb.service
  94ms [email protected]
  91ms plymouth-read-write.service
  88ms avahi-daemon.service
  87ms bluetooth.service
  85ms [email protected]
  80ms polkit.service
  76ms systemd-random-seed.service
  75ms systemd-machined.service
  74ms [email protected]
  70ms udisks2.service
  69ms systemd-guest-user.service
  66ms ModemManager.service
  61ms dbus.service
  58ms systemd-udevd.service
  56ms colord.service
  55ms upower.service
  50ms systemd-timesyncd.service
  49ms systemd-update-utmp.service
  41ms garuda-pacman-snapshot-reject.service
  32ms systemd-logind.service
  32ms logrotate.service
  31ms libvirtd.service
  31ms systemd-sysctl.service
  30ms alsa-restore.service
  28ms systemd-oomd.service
  27ms garuda-pacman-lock.service
  24ms dev-hugepages.mount
  24ms dev-mqueue.mount
  23ms sys-kernel-debug.mount
  23ms sys-kernel-tracing.mount
  22ms systemd-binfmt.service
  21ms kmod-static-nodes.service
  21ms [email protected]
  19ms systemd-user-sessions.service
  19ms rpc-statd.service
  19ms [email protected]
  18ms cups.service
  18ms sys-fs-fuse-connections.mount
  17ms sys-kernel-config.mount
  17ms home.mount
  16ms dev-disk-by\x2duuid-2e9cba84\x2d8fd3\x2d4884\x2d995e\x2d6ac1c54716ad.swap
  15ms rpc-statd-notify.service
  15ms root.mount
  15ms [email protected]
  14ms srv.mount
  14ms systemd-tmpfiles-clean.service
  14ms var-cache.mount
  13ms var-log.mount
  13ms rpcbind.service
  12ms var-tmp.mount
  12ms systemd-guest-config.service
  10ms boot-efi.mount
   8ms docker.socket
   6ms uresourced.service
   4ms systemd-rfkill.service
   3ms home-guest.mount
   3ms fail2ban.service
   3ms tmp.mount
   2ms proc-sys-fs-binfmt_misc.mount
   1ms rtkit-daemon.service
   1ms [email protected]_mod.service
systemd-analyze blame
╭─[email protected] in ~ via  v11.0.19
╰─λ systemd-analyze
Startup finished in 17.913s (firmware) + 8.038s (loader) + 5.999s (kernel) + 9.611s (userspace) = 41.562s
graphical.target reached after 9.610s in userspace.
systemd-analyze critical-chain
╭─[email protected] in ~ via  v11.0.19 took 30s
╰─[🧱] × 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 @9.610s
└─sddm.service @9.610s
└─plymouth-quit.service @9.439s +170ms
└─systemd-user-sessions.service @9.417s +19ms
└─remote-fs.target @9.389s
└─mnt-nfs.mount @8.931s +458ms
└─network-online.target @8.908s
└─NetworkManager-wait-online.service @2.626s +6.280s
└─NetworkManager.service @2.292s +313ms
└─dbus.service @2.206s +61ms
└─basic.target @2.201s
└─sockets.target @2.201s
└─docker.socket @2.192s +8ms
└─sysinit.target @2.190s
└─systemd-timesyncd.service @2.139s +50ms
└─systemd-tmpfiles-setup.service @1.862s +266ms
└─systemd-journal-flush.service @1.318s +532ms
└─var-log.mount @1.229s +13ms
└─dev-sda2.device @378ms +765ms
2 Likes

I don't quite know how to interpret Reloading requested from client PID correctly, but maybe it has something to do with a daemon reload, as suggested from this issue

Could you try time sudo systemctl daemon-reload?
This is my output for that: sudo systemctl daemon-reload 0,01s user 0,02s system 8% cpu 0,325 total

In case it takes much longer than mine, run it with SYSTEMD_LOG_LEVEL=debug

________________________________________________________
Executed in    4.25 secs      fish           external
usr time    9.93 millis  265.00 micros    9.66 millis
sys time    7.99 millis    0.00 micros    7.99 millis

Hm..

Out of curiosity, could you run id 962? I'm confused why the user is being shut down shortly before you are logged in.

Could you also try disabling samba? it seems to be the last active thing before the lag.

I'm also interested in sudo dmesg -T. Please also append the previously mentioned log again, so I can look at the timestamps. Maybe the kernel knows more.

Edit: Have you even tried another kernel yet?

1 Like

Another kernel? Yes, i tried LTS to same effect.
I'll try disabling samba.

id 962

uid=962(sddm) gid=962(sddm) groups=962(sddm),985(video)

sudo dmesg -T

disabling samba did nothing. :frowning:

Did you check /etc/fstab? Missing volumes by any chance?

I'm going through something similar; it takes-20-30 secs before my mouse & keyboard are released to SDDM my login manager. This is following an Archinstall + Plasma procedure & multiple reboots.

It has affected me following Archinstall 2.5.6. and I suppose I should be hunting down that bug following tomorrow's github run.

Long/short -- a reinstall tomorrow followed by an analysis of systemd output. I'll let users know if I find anything of significance.

In the meantime, if you are booted in and everything works...

regards

4 Likes

If you are using USB hubs or external drives that are powered over the USB bus, try disconnecting them and see if the boot time is impacted. If the boot time is significantly reduced, you may be running into a bottleneck with getting power to the devices.

USB has an over-current protection that gets triggered when power consumption from the port is too high.Interestingly, turning off your computer does not cut power to these devices, so they can get "stuck" with the over-current protection tripped.

The tried-and-true way to reset the USB over-current protection is to unplug all USB devices from the PC, power off the PC, some people even unplug the PC itself, and wait a couple minutes. Then plug everything back in and power it all back up, you should be good to go.

3 Likes

I've disabled several lines in my fstab and rebooted. Still same 30s wait.

I'll try this and report back, editing this reply...

Edit:
Same thing, still 30s. Unplugged everything including my keyboard. Plugged KB back in before shutting down.

would you be willing to try another login manger for a test?

Just because it's easy to use and quick to install, try ly (sudo pacman -S ly && sudo systemctl enable --force ly). To revert, just run sudo systemctl enable --force sddm and uninstall ly)

1 Like

that one hangs at loading garuda linux, the black terminal at boot.

What?? It hangs at the very beginning of the boot kernel log? That can't be related to the login manager...

Are you able to switch TTYs?

If you can, try to log in and run sudo systemctl restart ly. If that does not work, please show the output of systemctl status ly

Does this mean anything? I have nothing nVidia.

[Sun May 28 21:18:40 2023] nvidia: loading out-of-tree module taints kernel.
[Sun May 28 21:18:40 2023] nvidia: module license 'NVIDIA' taints kernel.
[Sun May 28 21:18:40 2023] Disabling lock debugging due to kernel taint
[Sun May 28 21:18:40 2023] nvidia: module verification failed: signature and/or required key missing - tainting kernel
[Sun May 28 21:18:40 2023] nvidia-nvlink: Nvlink Core is being initialized, major device number 236

[Sun May 28 21:18:40 2023] nvidia 0000:0b:00.0: vgaarb: changed VGA decodes: olddecodes=io+mem,decodes=none:owns=io+mem
[Sun May 28 21:18:40 2023] NVRM: The NVIDIA probe routine was not called for 1 device(s).
[Sun May 28 21:18:40 2023] NVRM: This can occur when a driver such as: 
                           NVRM: nouveau, rivafb, nvidiafb or rivatv 
                           NVRM: was loaded and obtained ownership of the NVIDIA device(s).
[Sun May 28 21:18:40 2023] NVRM: Try unloading the conflicting kernel module (and/or
                           NVRM: reconfigure your kernel without the conflicting
                           NVRM: driver(s)), then try loading the NVIDIA kernel module
                           NVRM: again.

Can't access the virtual terminals from the part where the boot log hangs.

Very weird. All LY does is replace SDDM in this case. I don't understand why it would suddenly break.

Could you try re-enabling SDDM from a live-usb?

1 Like

In case the login manager is the issue, you could try whether skipping it completely has an effect ?

4 Likes

Hangs at the boot log again. Something else must be going on, this is curious.