Sluggish program startup since last update

Support Software & Applications
21

What happens in your case near those calls? Mine does something like this, where it queries the same fd a couple of times.

openat(AT_FDCWD, "/usr/share/icons/Papirus-Dark/48x48/places", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=98304, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x564f7eff51f0 /* 679 entries */, 32768) = 32752
brk(0x564f7f069000)                     = 0x564f7f069000
getdents64(5, 0x564f7eff51f0 /* 678 entries */, 32768) = 32736
getdents64(5, 0x564f7eff51f0 /* 597 entries */, 32768) = 28664
getdents64(5, 0x564f7eff51f0 /* 0 entries */, 32768) = 0
close(5)
22 
↳ grep -3 dents /tmp/strace
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/16x16/apps", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=804, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a93a240 /* 19 entries */, 32768) = 816
getdents64(5, 0x555b3a93a240 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/16x16@2/apps", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/16x16/categories", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
--
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/24x24/apps", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=40, ...}, AT_EMPTY_PATH) = 0
brk(0x555b3a96a000)                     = 0x555b3a96a000
getdents64(5, 0x555b3a941430 /* 3 entries */, 32768) = 88
getdents64(5, 0x555b3a941430 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/24x24@2/apps", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/24x24/categories", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
--
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/32x32/apps", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=804, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a9494a0 /* 19 entries */, 32768) = 816
getdents64(5, 0x555b3a9494a0 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/32x32@2/apps", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/32x32/categories", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
--
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/48x48/apps", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=552, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a9522a0 /* 15 entries */, 32768) = 608
getdents64(5, 0x555b3a9522a0 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/48x48@2/apps", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/48x48/categories", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
--
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/64x64/apps", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=40, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a95a5b0 /* 3 entries */, 32768) = 88
getdents64(5, 0x555b3a95a5b0 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/64x64@2/apps", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/64x64/categories", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
--
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/256x256/apps", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0700, st_size=538, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a972a00 /* 15 entries */, 32768) = 600
getdents64(5, 0x555b3a972a00 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/256x256@2/apps", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/256x256/categories", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
--
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/256x256/mimetypes", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0700, st_size=70, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a97ad50 /* 4 entries */, 32768) = 128
getdents64(5, 0x555b3a97ad50 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/256x256@2/mimetypes", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons/hicolor/256x256/places", 0x7ffce0f3dcc0, 0) = -1 ENOENT (No such file or directory)
--
openat(AT_FDCWD, "/home/sour/.icons/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.icons", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=50, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a9804e0 /* 4 entries */, 32768) = 120
getdents64(5, 0x555b3a9804e0 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons", {st_mode=S_IFDIR|0700, st_size=14, ...}, 0) = 0
newfstatat(AT_FDCWD, "/home/sour/.local/share/icons", {st_mode=S_IFDIR|0700, st_size=14, ...}, 0) = 0
openat(AT_FDCWD, "/home/sour/.local/share/icons/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/home/sour/.local/share/icons", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0700, st_size=14, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a9804e0 /* 3 entries */, 32768) = 80
getdents64(5, 0x555b3a9804e0 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/usr/local/share/icons", 0x7ffce0f3e070, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/share/icons", {st_mode=S_IFDIR|0755, st_size=752, ...}, 0) = 0
--
openat(AT_FDCWD, "/usr/share/icons/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/icons", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=752, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a9804e0 /* 29 entries */, 32768) = 1072
getdents64(5, 0x555b3a9804e0 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/usr/local/share/pixmaps", 0x7ffce0f3e070, 0) = -1 ENOENT (No such file or directory)
newfstatat(AT_FDCWD, "/usr/share/pixmaps", {st_mode=S_IFDIR|0755, st_size=818, ...}, 0) = 0
--
openat(AT_FDCWD, "/usr/share/pixmaps/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/pixmaps", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=818, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a9804e0 /* 34 entries */, 32768) = 1224
getdents64(5, 0x555b3a9804e0 /* 0 entries */, 32768) = 0
close(5)                                = 0
newfstatat(AT_FDCWD, "/usr/share/viewnior/pixmaps/", {st_mode=S_IFDIR|0755, st_size=190, ...}, 0) = 0
newfstatat(AT_FDCWD, "/usr/share/viewnior/pixmaps/", {st_mode=S_IFDIR|0755, st_size=190, ...}, 0) = 0
openat(AT_FDCWD, "/usr/share/viewnior/pixmaps/icon-theme.cache", O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/viewnior/pixmaps/", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=190, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x555b3a9804e0 /* 6 entries */, 32768) = 240
getdents64(5, 0x555b3a9804e0 /* 0 entries */, 32768) = 0
close(5)                                = 0
futex(0x7f4f59063068, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f4f59063068, FUTEX_WAKE_PRIVATE, 2147483647) = 0
--
newfstatat(6, "", {st_mode=S_IFREG|0644, st_size=365, ...}, AT_EMPTY_PATH) = 0
read(6, "libdconfsettings.so: gsettings-b"..., 365) = 365
close(6)                                = 0
getdents64(5, 0x555b3a9b8920 /* 11 entries */, 32768) = 440
futex(0x7f4f59063068, FUTEX_WAKE_PRIVATE, 2147483647) = 0
newfstatat(AT_FDCWD, "/usr/lib/gio/modules/libdconfsettings.so", {st_mode=S_IFREG|0755, st_size=55048, ...}, 0) = 0
newfstatat(AT_FDCWD, "/usr/lib/gio/modules/libgiognomeproxy.so", {st_mode=S_IFREG|0755, st_size=22200, ...}, 0) = 0
--
newfstatat(AT_FDCWD, "/usr/lib/gio/modules/libgsettingsgconfbackend.so", {st_mode=S_IFREG|0755, st_size=26296, ...}, 0) = 0
newfstatat(AT_FDCWD, "/usr/lib/gio/modules/libgioremote-volume-monitor.so", {st_mode=S_IFREG|0755, st_size=104200, ...}, 0) = 0
newfstatat(AT_FDCWD, "/usr/lib/gio/modules/libgvfsdbus.so", {st_mode=S_IFREG|0755, st_size=198688, ...}, 0) = 0
getdents64(5, 0x555b3a9b8920 /* 0 entries */, 32768) = 0
close(5)                                = 0
futex(0x7f4f59063068, FUTEX_WAKE_PRIVATE, 2147483647) = 0
futex(0x7f4f59063068, FUTEX_WAKE_PRIVATE, 2147483647) = 0

This is all of them in my strace.

23

On my end it definitely makes more getdents64 calls. I do think this is a lead, but I’m also not sure what to do about it. It’s weird that it only came up after the update. I think I’m going to try an older kernel and see if it’s a kernel issue.

24

please check the output of
‘systemd-analyze critical-chain’
i bet the nvidia-driver is sluggish

25 
graphical.target @2.534s
└─multi-user.target @2.534s
  └─ModemManager.service @2.460s +73ms
    └─polkit.service @2.351s +107ms
      └─basic.target @2.337s
        └─sockets.target @2.337s
          └─dbus.socket @2.337s
            └─sysinit.target @2.335s
              └─ufw.service @2.150s +185ms
                └─systemd-sysctl.service @2.142s +6ms
                  └─systemd-modules-load.service @365ms +1.776s
                    └─systemd-journald.socket @355ms
                      └─-.mount @343ms
                        └─blockdev@dev-mapper-luks\??\??\??\??\??.target @742ms
                          └─systemd-cryptsetup@luks\??\??\??\??\??.service @728ms +14ms
                            └─dev-disk-by\??\??\??\??\??.device @727ms

?? the hex from my luks.

26

are you using a crypted device ?

27

Yes, I use full disk encryption because it’s a laptop, in case it gets stolen. Could this be a sudden problem?

28

not a problem but if you are using crypted devices everything must be encrypted. this takes time and i recommend that you check settings of encryption and optimize them.
a better solution is to split to a non-crypted partition for the os and a crypted partition for the vulnerable data. it’s as safe but a way faster.

29

I just downgraded to kernel 5.4 LTS and it feels a little faster to start the system, but once logged in things still take a long time to start up.

30

What happens if you run the app from a root term?

31

Still takes a while, additionally I get these complaints:

[laptop redactedusr]# viewnior

** (viewnior:2417): WARNING **: 13:17:34.608: Loading config file: No such file or directory. All preferences are set to their default values. Saving ...
[laptop redactedusr]# thunar
thunar: Failed to initialize Xfconf: Error spawning command line ?dbus-launch --autolaunch=576c9f5a779548db9b44719f8b50daf8 --binary-syntax --close-stderr?: Child process exited with code 1


(thunar:2425): thunar-WARNING **: 13:17:40.793: Name 'org.xfce.FileManager' lost on the message dbus.

(thunar:2425): thunar-WARNING **: 13:17:40.793: Name 'org.freedesktop.FileManager1' lost on the message dbus.
ThunarThumbnailer: failed to create proxy: Error spawning command line “dbus-launch --autolaunch=576c9f5a779548db9b44719f8b50daf8 --binary-syntax --close-stderr”: Child process exited with code 1[laptop redactedusr]# gnome-calculator 

(gnome-calculator:2452): dconf-WARNING **: 13:18:05.321: failed to commit changes to dconf: Error spawning command line “dbus-launch --autolaunch=576c9f5a779548db9b44719f8b50daf8 --binary-syntax --close-stderr”: Child process exited with code 1
32

Is this supposed to be so slow? Ctrl+c’ed as soon as thunar popped up.

$ time dbus-launch thunar
^C

real	0m29,497s
user	0m1,041s
sys	0m0,978s

$ strace -c dbus-launch thunar
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ------------------
 87,69    0,539219          95      5636           getdents64

hmmm

I tried to profile dbus launch to check if it was maybe getting stuck in a loop somewhere, but I get this

$ gprof /usr/bin/dbus-launch thunar
gprof: file `/usr/bin/dbus-launch' has no symbols

cpu usage is low during dbus-launch.

33 
↳ time dbus-launch thunar
^C
dbus-launch thunar  0.22s user 0.02s system 23% cpu 1.017 total

Mine is instant, I don’t have time to swap to term for ctrl+c. Although my computer is a quite fast i7.

34

Yeah, I’m running a somewhat light Ryzen 5 3550H. But it should be plenty fast, I mean it’s not a pentium or celeron.

35

‘cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor’
what’s the output

36 
$ cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor
schedutil
schedutil
schedutil
schedutil
schedutil
schedutil
schedutil
schedutil
37

That’s curious, your cpu-speed is set by a timer/schedule and not by the demand of applications. you have to dig in this problem.
https://wiki.archlinux.org/title/CPU_frequency_scaling#Scaling_governors

38
  • powersave (for Linux < 5.10) or schedutil (since Linux 5.10) for CPUs using the acpi-cpufreq driver.
39

When setting the governor to performance, I get a slight speedup

$ sudo cpupower frequency-set -g performance
[sudo] password: 
Setting cpu: 0
Setting cpu: 1
Setting cpu: 2
Setting cpu: 3
Setting cpu: 4
Setting cpu: 5
Setting cpu: 6
Setting cpu: 7
$ cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor
performance
performance
performance
performance
performance
performance
performance
performance
$ time dbus-launch thunar
^C

real	0m28,512s
user	0m1,003s
sys	0m0,835s

Launching programs from the gui still feels sluggish. I really don’t know why launching something from the terminal via dbus is such an outlier, though.

40

I found this while doing basic issue searches, no idea if relevant.