Dolphin takes more than 30 seconds to open

English Applications
1

Tumbleweed, up-to-date


time dolphin 
kf.xmlgui: KActionCollection::setComponentName does not work on a KActionCollection containing actions! "dolphin" 
kf.dbusaddons: 'kdeinit5' is taking more than 30 seconds to start. 
^C 

real    0m33,896s 
user    0m0,917s 
sys     0m0,179s

In emacs, the command M-x dired fires dired up in split seconds with all file names in the current directory.

Any ideas why dolphin and all other file manager windows take so long to open? Same for okular, C-o needs more than 30 seconds to open the file window. Nautilus opens really quickly.

Oh, funny, just noticed: opening Yast takes as well about 30 seconds until the demand for the root password appears.

2

That “kf.xmlgui:” message I see also on Tumbleweed so that is very likely not related to the problem.

As multiple applications have the problem it has likely something to do with file/network access.

You can run:

strace -t -f -o /tmp/dolphin.strace dolphin

That will create a huge text file containing all OS calls including file/network access. Have a look at the time stamps and check if you see large gaps. If so, try to see what is the root cause for these gaps.
You can consider sharing the part file via https://susepaste.org/, keep in mind it contains all files/network locations that you might want to keep private.

For your reference dolphin takes about 3 seconds for me and closing it immediately gives my (only things > 5%):

> strace -c dolphin                                                  
kf.xmlgui: KActionCollection::setComponentName does not work on a KActionCollection containing actions! "dolphin" 
% time     seconds  usecs/call     calls    errors syscall 
------ ----------- ----------- --------- --------- ------------------- 
 17.94    0.011093           0     13307        35 newfstatat 
 12.00    0.007418           4      1516       185 futex 
 11.98    0.007410           0      8744      3169 statx 
  8.71    0.005386           1      5254           read 
  8.41    0.005198           1      3590       101 openat 
  7.77    0.004806           1      4218      3196 access 
  5.57    0.003444           1      2379      2288 readlink 
  5.37    0.003320           1      3317           write 
  5.18    0.003205           0      3514           close
<snip>
------ ----------- ----------- --------- --------- ------------------- 
100.00    0.061828           1     50529      9017 total
3

Good advice, I found something:


25550 22:34:17 read(21, "2510bcd4-4334-4e2d-8e8a-0f4694c1"..., 36) = 36 
25550 22:34:17 close(21)                = 0 
25550 22:34:17 openat(AT_FDCWD, "/tmp/startkdeinitlock", O_WRONLY|O_CLOEXEC) = -1 EACCES (Permission denied) 
25550 22:34:17 close(20)                = 0 
25550 22:34:17 unlink("/tmp/startkdeinitlock.rmlock") = 0 
25550 22:34:17 clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=6, tv_nsec=400000000},  <unfinished ...> 
25552 22:34:17 <... pselect6 resumed>)  = 0 (Timeout) 
25552 22:34:17 pselect6(12, [11], NULL, NULL, {tv_sec=1, tv_nsec=0}, {sigmask=NULL, sigsetsize=8}) = 0 (Timeout) 
25552 22:34:18 pselect6(12, [11], NULL, NULL, {tv_sec=1, tv_nsec=0}, {sigmask=NULL, sigsetsize=8}) = 0 (Timeout) 
25552 22:34:19 pselect6(12, [11], NULL, NULL, {tv_sec=1, tv_nsec=0}, {sigmask=NULL, sigsetsize=8}) = 0 (Timeout) 
25552 22:34:20 pselect6(12, [11], NULL, NULL, {tv_sec=1, tv_nsec=0}, {sigmask=NULL, sigsetsize=8}) = 0 (Timeout) 
25552 22:34:21 pselect6(12, [11], NULL, NULL, {tv_sec=1, tv_nsec=0}, {sigmask=NULL, sigsetsize=8}) = 0 (Timeout) 
25552 22:34:22 pselect6(12, [11], NULL, NULL, {tv_sec=1, tv_nsec=0}, {sigmask=NULL, sigsetsize=8}) = 0 (Timeout) 
25552 22:34:23 pselect6(12, [11], NULL, NULL, {tv_sec=1, tv_nsec=0}, {sigmask=NULL, sigsetsize=8} <unfinished ...> 
25550 22:34:24 <... clock_nanosleep resumed>0x7fffff198540) = 0 
25550 22:34:24 openat(AT_FDCWD, "/tmp/startkdeinitlock", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = -1 EEXIST (File exists) 
25550 22:34:24 openat(AT_FDCWD, "/tmp/startkdeinitlock", O_RDONLY|O_CLOEXEC) = 20 
25550 22:34:24 statx(20, "", AT_STATX_SYNC_AS_STAT|AT_EMPTY_PATH, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=105, ...}) = 0 
25550 22:34:24 statx(20, "", AT_STATX_SYNC_AS_STAT|AT_EMPTY_PATH, STATX_ALL, {stx_mask=STATX_ALL|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=105, ...}) = 0 
25550 22:34:24 read(20, "11765
kdeinit5_shutdown
linux-iz"..., 16384) = 105

There are some more of these clusters with pselect6.

What does this mean?

4

https://linux.die.net/man/2/pselect6

It are timeout of 1 second on file descriptor 12.

I am not seeing this in my log.

Do you have ~/.kde4/share/apps/dolphin? If so, try deleting that, it has dolphone settings and maybe something is messed up.

5

I renamed the whole .kde4 branch, but no result. Timeout still there. However, thank you!

6

Maybe I found the cause:

I searched the file dolphin.strace for »something new« in the lines shortly before one second only consisted of some dozen of lines, instead of hundreds or thousands. Found:

openat(AT_FDCWD, "/tmp/startkdeinitlock", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = -1 EEXIST (File exists)

But /tmp/startkdeinitlock belonged to another user! After deleting it, everything is back to normal. It seems that kde tried to write something into that file, but because had no ownership, it failed.

Let’s see whether it works after the next reboot. If yes, I’ll write a bug report.

7

Good you took the time to do a deep dive on the strace log file.

Yes, let’s hope it is fixed with deleting /tmp/startkdeinitlock

Did may KDE crash during the start-up of that user?

8

https://bugs.kde.org/show_bug.cgi?id=439606