Description: After upgrading to kservice 5.14.3 from 5.13.0 I experienced an extra delay (with pause) of 20+ seconds when logging in from sddm to kde. In that pause the system has no activity (disk or cpu) it just waits. Reproducible: Always Steps to Reproduce: 1. Login 2. count the time it takes for the desktop to appear Actual Results: more than 2-25 seconds delay Expected Results: 2-3 seconds delay
Created attachment 94724 [details] syslog Notice the 20+ seconds delay in the log at line 156 and how meanwhile nothing was happening.
I assume kbuildsycoca5 is running all the time during that time? It would then be the same as https://bugs.kde.org/show_bug.cgi?id=353036 probably.
Can you try the patch at https://git.reviewboard.kde.org/r/125497/ ?
The latest kservice package in Arch is 5.14.3 and the patch doesn't work against that code. I can't use the git version because I have to reinstall and recompile many KDE packages for this. So nope I can't sorry.
You could use the git version of just kservice and hack KF5_DEP_VERSION (in the toplevel CMakeLists.txt) back to 5.14 (actually it was like that until 1h ago).
I managed to compile and install it. I had to also change the find_package(ECM 5.15.0 NO_MODULE) to find_package(ECM 5.14.0 NO_MODULE) to compile. I tried it and unfortunately the 20 seconds delay is still happening with the patch too. I can provide more detailed info and logs if you want me to.
There's still one pending patch (in case you have directories with a modification time in the future), it's the one at https://git.reviewboard.kde.org/r/125497/ You could try applying it. Otherwise, then I don't know at all what the issue is. The logs don't say much. Can you use kdebugsettings to enable all areas, especially those containing kf5? Another idea is, during the 20 seconds where nothing seems to be happening, to inspect the processes (e.g. is one using 100% cpu or I/O? is kbuildsycoca5 running?) by running top and iotop from a ssh session.
I just tried the new patch and still get the delay. I have everything enabled and set to "All" in kdebugsettings. Also I used ssh to monitor with top while I was loggin in but it was completely 0% cpu and no activity with disks that I could tell (I have an SSD so even if it was disk seeking it shouldn't take near as much as 20 seconds). I'll add the new log. Notice that it always stops after this line: Οκτ 05 01:07:09 nekhomeworkstation dbus-daemon[838]: Successfully activated service 'org.gnome.GConf' Maybe there's some kind of compatibility issue with gconf?
Created attachment 94846 [details] new log with updated patch
I did a manual git bisection and managed to find the exact commit that introduces this bug. It's the commit 1d7eb96791ae385b05c0fa5c2363902741489e1b. I tested it thoroughly with multiple reboots per commit to make sure. Note that it needs at least 2 reboots for the bug to manifest. From the commit's comments I understand and guess that probably the issue is with the new code for Ksycoca that checks the directories. I hope I have helped. I can further help by doing some debugging if you would need it. Just show me how.
Several fedora users experienced similar symptoms of delayed login too (including me). Seems the problem went away us (2 users so far), by : 1. end plasma session 2. delete any existing ksysoca5 cache (rm -f ~/.cache/ksycoca5* ) 3. re-login Speculation: upgrading to kservice 5.13 -> 5.14 while an active plasma session is already running may have caused kbuildsycoca5 to create a bad/invalid ~/.cache/ksycoca5 and/or ~/.cache/ksysoca5stamp , that wasn't fixed by simply re-runing kbuidsycoca5 (I even tried, kbuildsycoca5 --noincremental previously without success)
Dang, just occurred to me I had also tested downgrading/upgrading kservice 5.14->5.13->5.14, which may also inadvertantly bumped directory timestamps, which may have played a role in the problem going away. (The 2nd user I referenced only did the steps I outlined in my prior comment though)
I'm affected too on Archlinux. I'm using BTRFS, but I doubt that this could be causing the KService problem. I tried to downgrade to kservice-5.13.0-1, bug still there. I also tried to remove '~/.cache/ksycoca5*', bug still there. @RexDieter, Could you specify the url of the thread of fedora users affected by this bug? @DavidFaure, I think the bug affects Fedora users too, so 'Platform:Archlinux Packages Linux' can be changed.
Can someone try with karchive git, or the v5.15.0-rc2 tag? There is a bugfix in there (the last commit in v5.15.0-rc2) which might very well fix this.
I assume you mean kservice (not karchive), I don't see any relevant commits in karchive
(In reply to raphael.cazenave from comment #13) > I tried to downgrade to kservice-5.13.0-1, bug still there. Are you absolutely certain that downgrade didn't fix the problem? Because I did a thorough test and found the exact commit that causes this bug for me. Can you double check?
Created attachment 94896 [details] journalctl Freeze from 16:36:08 to 16:36:30 (22 seconds)
(In reply to empire@adslgr.com from comment #16) >Are you absolutely certain that downgrade didn't fix the problem? Because I did a thorough test and found the exact commit that causes this bug for me. Can you double check? I just did it again. From Arch Rollback Machine, at http://seblu.net/a/arm/2015/08/25/extra/os/x86_64/, I downloaded and installed the following packages: ``` [2015-10-08 16:29] [ALPM] transaction started [2015-10-08 16:29] [ALPM] downgraded kservice (5.14.3-1 -> 5.13.0-1) [2015-10-08 16:29] [ALPM] downgraded kdesu (5.14.0-1 -> 5.13.0-1) [2015-10-08 16:29] [ALPM] downgraded kemoticons (5.14.0-1 -> 5.13.0-1) [2015-10-08 16:29] [ALPM] downgraded kpeople (5.14.0-1 -> 5.13.0-1) [2015-10-08 16:29] [ALPM] downgraded ktextwidgets (5.14.0-1 -> 5.13.0-1) [2015-10-08 16:29] [ALPM] downgraded kwallet (5.14.0-1 -> 5.13.0-4) [2015-10-08 16:29] [ALPM] downgraded telepathy-kde-approver (15.08.1-1 -> 15.08.0-1) [2015-10-08 16:29] [ALPM] transaction completed ``` After that plasma got unresponsible, I had go to TTY, closed the sddm, and 'rm ~/.cache/ksycoca5*' to be sure. After multiples reboot, the bug is still present, as you can see in journalctl logs : https://bugsfiles.kde.org/attachment.cgi?id=94896 (freeze from 16:36:08 to 16:36:30)
(In reply to David Faure from comment #14) > Can someone try with karchive git, or the v5.15.0-rc2 tag? There is a bugfix > in there (the last commit in v5.15.0-rc2) which might very well fix this. I just installed kservice-git (r408.0a39ba6-1), and the issue still exist. :( The version I tried is * commit a39ba6ec01600efeb9e334fa457dd725e2e3749 | Author: Xuetian Weng >wengxt@gmail.com> | Date: Tue Oct 6 23:36:39 2015 +0200 Are we sure that kservice is the cause of this issue ?
For me, to fix this issue i downgraded in Fedora these packages: plasma-desktop 5.4.1-2 plasma-workspace 5.4.1-3 to their downgrade version which are: plasma-desktop-5.3.0-5 plasma-workspace-5.3.0-4 in this downgrade the following dependencies are also downgraded: kf5-baloo-5.9.0-1 kf5-baloo-file-5.9.0-1 polkit-0.112-9 polkit-kde-5.3.0-1 polkit-libs-0.112-9 However, to test if the problem was solved I've installed plasma-workspace-5.4.2-1 (from 5.4.1 to 5.4.2) and the bug was still present. However, with a full 5.4.2 plasma-desktop installed I had to perform just one downgrade to fix all the delays, even without downgrading from plasma-desktop 5.4.2 to 5.3.0. I've downgraded kf5-kservice-5.14.3-1 to kf5-kservice-5.9.0-1 and the problem was completely solved. No hangs at all when loading the session. What I cant make a connection is why downgrading plasma-workstation solved the problem, but so did kf5-kservice did. For anyone testing, be careful perform kbuildsycoca (with noincremental), because it can crash after downgrading and introduce new variables to the tests.
(sorry, I meant kservice instead of karchive indeed). journalctl doesn't tell us much, I would suggest to look at ~/.xsession-errors* instead. To get timing information in there, create a file like ~/.config/plasma-workspace/env/debug.sh (the base filename doesn't matter, the extension does matter) and put this line into it : export QT_MESSAGE_PATTERN='%{time} %{appname}(%{pid})/%{category} %{function}: %{message}'
Created attachment 94932 [details] ~/.xsession-errors with export QT_MESSAGE_PATTERN='%{time} %{appname}(%{pid})/%{category} %{function}: %{message}'
(In reply to David Faure from comment #21) > (sorry, I meant kservice instead of karchive indeed). > > journalctl doesn't tell us much, I would suggest to look at > ~/.xsession-errors* instead. > > To get timing information in there, create a file like > ~/.config/plasma-workspace/env/debug.sh (the base filename doesn't matter, > the extension does matter) and put this line into it : > > export QT_MESSAGE_PATTERN='%{time} %{appname}(%{pid})/%{category} > %{function}: %{message}' In the https://bugsfiles.kde.org/attachment.cgi?id=94932 attachment, sadly the logging start after the ~20-30sec delay. '2015-10-10T16:14:21' in my logs is the moment when the delay end.
I think it can be usefull to see if the bug occurs on a fresh install of Archlinux. To exclude malfunction originating from a bad update of KService / kbuildsycoka.
Fixed for me by updating to 5.15.
Git commit 0f816ab3fada9f57e836da78470003dd24d26a27 by David Faure. Committed on 27/10/2015 at 07:40. Pushed by dfaure into branch 'master'. KBuildSycoca: always save, even if no change in .desktop file was noticed. This fixes the case where a directory is "touched", so when KSycoca compares directory timestamps it decides to rebuild, but then KBuildSycoca doesn't find any real change and doesn't save. This can then happen all over again at the next timestamp check. REVIEW: 125803 M +3 -0 autotests/ksycocatest.cpp M +5 -7 src/sycoca/kbuildsycoca.cpp M +1 -1 src/sycoca/ksycoca.cpp http://commits.kde.org/kservice/0f816ab3fada9f57e836da78470003dd24d26a27
@AnAkkk, I still have the issue after upgrading to 5.15 (on Archlinux) :/ I tried on a fresh Archlinux, the problem is the same. @David Faure, this bug may be related to https://bugs.kde.org/show_bug.cgi?id=352779
Does this bug still happen, with commit 0f816ab3fada9f mentionned above? This commit will be in KF 5.16. (but if someone with the bug can test before the 5.16 release, then we can be sure 5.16 will fix it...)
The mentioned commit does NOT fix the delay on my machine, the login animation still freezes for ~25 seconds and the PC does seemingly nothing...
I just did a fresh install of archlinux, opensuse 42.1 LEAP in virtualbox and I noticed an interesting fact. With the same virtual machine, in relatively close load state, I got openSUSE 42.1 login time: 9seconds Archlinux login time: 28seconds openSUSE 42.1 uses kservice 5.15.0-2.1 Archlinux uses kservices 5.15.0-1 So it seems to only affect Archlinux packages. @David Faure, like @Mister Ypsilon, I can confirm that the mentioned commit does NOT fix the delay on my machine :/
Hi, I am also using Arch Linux and SDDM has delay on startup. Approx. 30 seconds. After upgrade to extra/kservice 5.15.0-1 problem still exists. Regards.
Raphael, thanks for your testing. Could you do an additional test, bringing the exact same version of kservice on both systems? If you can see a difference with the exact same version of KService, then the problem isn't in KService at all. (Also your .xsession-errors has very little in it, you need to enable all debug output with kdebugsettings for this to be useful)
@David Faure, Yesterday, in my quest to return to plasma after several weeks (happily) spent on gnome-shell, I just tried everything to understand the source of this annoying login delay. It turns out that akonadi is the origin of the delay. On previous tests, those who produce consistently a login duration of 28 seconds, I installed plasma and kde-meta-meta-applications. And comparing it with openSUSE 42.1 LEAP, I compared processes after login: On openSUSE 42.1 LEAP, akonadi is not running when we arrive on the Plasma desktop. It is launched on demand, if it launches an application that requires akonadi. On a fresh Archlinux with plasma-meta-meta packages and meta-kde-applications installed, akonadi launches automatically. For two reasons. 1 / ~ / .config / akonadi / akonadiserverrc contains `StartServer =true` (whereas openSUSE set it to` false`). 2 / Too many services are launched. I notice also that in the default configuration, Akonadi is trowing a lot of errors about mariaDB, maybe the actual version of mairaDB conflict with the akonadi API ? So I decided to try again on a clean Arch virtual machine, I just installed `plasma-desktop` and sddm`, akonadi not installed, but I'll have probably need later, so I' specify `StartServer = false` in ~/.config/akonadi/akonadiserverrc. The result is clear: ~ 2 seconds after pressing the button login, I have a functional plasma desktop. So I really doubt that the concerns which many people speak either on KService, although it must be completely sure before concluding. Sorry for the lack of brevity.
I'm using Kubuntu 15.10. "StartServer = false" didn't help.
"StartServer = false" also didn't help here, neither did uninstalling akonadi. As nobody else mentioned this yet: Does the login animation also freeze for the other affected persons? It seems like whatever is causing the delay is also locking some rendering thread on my system...
For me: login screen bar goes to 100% (~3 seconds), then long pause (~20 seconds) with freezed login screen, then desktop appears. But strange: during login screen freeze I can Alt+Tab -> Empty desktop is showed for me as possibility to switch in (when I do that I get same freezed login screen). After I upgraded to Kubuntu 15.10 I experience graphical glitches: screen often fails to update ("ghosts" from past, "where that application's window which I started?",...), then I must Alt+Tab twice to get correct picture (Asus N56VZ notebook with Intel graphics on i7).
How many of you are using Nvidia GPUs with Nouveau drivers? I was also experiencing a long delay between the login screen and desktop appearance on two different machines with fully upgraded Fedora 22 (kernel 4.2.5-201) with KDE/Plasma 5, SDDM display manager. I tried some of the solutions here, but none worked. However, I installed Nvidia's proprietary drivers via dnf from RPMFusion (akmod-nvidia-340xx / GeForce 210) and the delay went away. I don't know enough about the inner-workings of KDE to know if the Nouveau driver could be the culprit, but hopefully this information is of some use.
FWIW, this is happening also Fedora 23. I am using kf5-plasma-5.16.0-4. Symptoms are, It's down to a matter of luck whether plasma shows me my panel with icons and the icons on the desktop. It has gone on for at least two minutes sometimes. After that I usually give up and reboot Sometimes everything will show up after a couple minutes, and sometimes it will not. Sometimes if I let it go long enough, things will show up little by little. Like he said, about 50/50 chance I am getting the "autoStart2Done timedout, this is a BUG!" message in /~.xsession-errors. I am using Intel onboard graphics and only one monitor on my tower system. So whatever it is, it is probably not limited to Nvidia graphics. I could post copies of this stuff, but it is rather long. This is a rather serious problem and costs a lot of time. Hope this helps.
This problem seems to be fixed after the updates Sat. Dec. 12. Login is very quick. About 6 seconds. I am no longer getting the "autoStart2Done timedout, this is a BUG!" message in /~.xsession-errors. Seems the update to 5.5 packages fixed it. Thank you.
@David V, i use on both computer the driver for Intel. Your observation seems disburting. @ Tom Canavan, good to see the issue is gone for you :), you mention an update. To be useful for other distros, can you tell more about wich packages got updated on your Fedora and the from to version ? Thanks
Created attachment 96023 [details] Diff to show fedora packages that were updated after the update on Dec 12, 2015 Output of diff -y --suppress-common-lines to show fedora packages updated by the update on Dec. 12, 2015
@raphael.cazenave I think I spoke too soon. The update helped, but it didn't solve the problem completely. After the update, I rebooted and logged in 3 times and each time, it logged me in in about 6-10 seconds. Then I went away for awhile and came back. booted and it took 2:30 to log in and I got that "autoStart2Done timedout, this is a BUG!" message in /~.xsession-errors again. This last time, it logged me in in 1:50 seconds and I did NOT get the error. Strange. It seems to happen a little differently each time I log in. But at least it doesn't seem to hang completely like it did before. (knock on wood). I'm posting a file to show the fedora packages that were updated. Hope this helps.
After upgrading Frameworks to version 5.17, the problem went away for me. Login is super fast now, like 3-5 seconds.
I can not confirm that completely. While it seems to be true that the login is faster (but no guarantees for now ;-) ), a lot of autostarted programs (be it by explicit autostart or by session restoration) now take this time to finally start up. The desktop/plasmashell is (partly?) there and seems to be useable, but a lot of the programs are just starting much later (and in case of programs showing dialogs, pop up all together - like a restored kontact with open mails or the CopyAgent from copy.com).
guys, the exact reason is in startkde dbus-update-activation-environment --systemd --all this line. blocks 25~ and then print dbus-update-activation-environment: warning: error sending to systemd: org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
microcai, can you create a different bug report for this, and assign it to jan.steffens@gmail.com who introduced the use of dbus-update-activation-environment in commit 90081cb0483ffc3ad46af3b99de171ed38716ac0 (plasma-workspace git repo) ? Everyone else: if you comment out the call to dbus-update-activation-environment from your startkde, does the issue go away? If yes, we can close this, if not, then there are two separate issues.
If I comment in "startkde" like this: <snip> # At this point all environment variables are set, let's send it to the DBus session server to update the activation environment #if which dbus-update-activation-environment >/dev/null 2>/dev/null ; then # dbus-update-activation-environment --systemd --all #else /usr/lib/x86_64-linux-gnu/libexec/ksyncdbusenv #fi </snip> then issue remains. I must mention: during that pause I can "Alt+F2" then type "firefox" with following Enter and then with "Alt+Tab" I can see started Firefox window in Application switcher visualization.
I'm on Ubuntu 15.10 and startkde does not contain a call to dbus-update-activation-environment - there is only a call to ksyncdbusenv. So I don't think that this is the root cause of the delay on startup :(
you should not remove dbus-update-activation-environment --systemd --all just remove --systemd leave it as dbus-update-activation-environment --all the all problem solved. if you delete the call to dbus-update-activation-environment then it will still delay 25 seconds.
If I remove "--systemd" then after login screen I get graphical window (like messagebox) with text "Could not sync environment to dbus.", and if click "OK" then graphics freezes and KDE not loads (but I still can switch in to text console by Alt+Ctrl+F1).
Removing dbus-update-activation-environment from startkde did not solve it or me. skipping "--systemd" was no luck either. Interestingly enough, the first login running completely without dbus-update-activation-environment but with /usr/lib/x86_64-linux-gnu/libexec/ksyncdbusenv instead work well for ONE login. After that it made no difference.
This bug has - for kubuntu 16.04 - been completely solved until a few days ago. Can anyone confirm that?
if you have problem with dbus-update-activation-environment, then you must be using ArchLinux and you must have dbus-daemon activated by systemd user instance. please check if you had once refer to the Arch wiki and tweaked the dbus user daemon activation mechanism. revert to upstream method then dbus-update-activation-environment won't block anymore.
My findings: I'm freshly installed Kubuntu 16.04 and I was experienced no delay in login until I was paired system with my phone (using Bluetooth). Now that delay comes back. Maybe my experience related to another bug?
This issue seems to have become a catch-all for all sorts of different issues on different systems with different KF5 versions for different reasons, over many different years... The problems with KService, which is what this issue was supposed to be about, ar fixed by now (for quite some time). Please open different bug reports for different issues.