Bug 1396788 - plasmashell requires ~15 minute to boot (after upgrade from fedora 24 testing to fedora 25 testing)
Summary: plasmashell requires ~15 minute to boot (after upgrade from fedora 24 testing...
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: plasma-workspace
Version: 25
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: KDE SIG
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-11-20 06:58 UTC by Maciej Mrozowski
Modified: 2017-12-12 10:29 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-12-12 10:29:33 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
coredumpctl list (2.41 KB, text/plain)
2016-11-20 06:58 UTC, Maciej Mrozowski
no flags Details
drkonqui backtrace (2.22 KB, application/octet-stream)
2016-11-20 06:59 UTC, Maciej Mrozowski
no flags Details
kaccess backtrace (2.20 KB, application/octet-stream)
2016-11-20 06:59 UTC, Maciej Mrozowski
no flags Details
kactivitymanagerd backtrace (6.81 KB, application/octet-stream)
2016-11-20 07:00 UTC, Maciej Mrozowski
no flags Details
backtraces (17.92 KB, text/plain)
2016-11-20 07:03 UTC, Maciej Mrozowski
no flags Details
.xsession-errors (774 bytes, text/plain)
2016-11-20 07:03 UTC, Maciej Mrozowski
no flags Details

Description Maciej Mrozowski 2016-11-20 06:58:07 UTC
Created attachment 1222180 [details]
coredumpctl list

Description of the problem:
Sorry for vague description yet reporting this under plasma-workspace component but it's indeed whole KDE Plasma that inhibits various "doesn't work" behaviours.
Those include (in loose order):

- occasionally multiple application crashes during plasma startup (kglobalacceld, klauncher, kactivitymanagerd, kded5...)
Details in attached backtraces

- general plasma startup lockups and weird behaviour (caused by above crashes and/or dbus hangs?)
I will elaborate on this:
1. After login, it takes over 30 seconds for the "desktop" to show up (SSD, 2 or 3 seconds before upgrade with the same plasma).
"desktop", because empty plasma desktop shows up, just with wallpaper (the right one) but with no plasmoids (in ex folderview as main desktop containment) or panels.
Neither plasma toolbox nor context menu works (plasma does not respond to any mouse clicks, luckily I have yakuake in autostart so I'm not entirely caught off).
2. What is interesting, it takes a couple of minutes (sic!, just it happened while filling bug report now and once earlier) for plasma to 'unstuck' itself and actually draw remaining containments (panel, folderview etc). It just happened twice to me, I don't know how reliably reproducible this 'unstuck' actually is. Perhaps even some plasmoid (like plasma-nm?) update event caused this unstuck.
3. From this moment everything appears to behave nominal (ie no crashes, lockups)

- for some reason .xsession-errors contains just kwin output, making all of this weird behaviour much harder to diagnose
File attached.

Version-Release number of selected component (if applicable):
plasma-desktop-5.8.3-1.fc25.x86_64
plasma-workspace-5.8.3-1.fc25.x86_64
kf5-kglobalaccel-5.27.0-1.fc25.x86_64
kf5-kded-5.27.0-1.fc25.x86_64

How reproducible:
Every clean Plasma session startup, re-login - it depends, it might be that just 1st lockup is there but second is not (so desktop is drawn properly). I might get some more reproduction info.

Other information:
This is Fedora 25 (beta) just after upgrade from Fedora 24 (with testing, testing updates, testing and updates of rpmfusion, no rawhide). Due to this, Plasma and KF5 packages are roughly in the same version as before the upgrade (KF5-5.27.0, plasma-5.8.1) so smooth upgrade path expected.
Plasma launched from sddm (no issues with sddm itself).
HW is HP Probook 640 G1 with i5-4300M, using built-in Intel GMA, no 3rd party kernel modules, etc.
Display server is xorg-x11 (not using wayland)
Tested for existing user as well us for newly created user.
No such problems ever occured for my on Fedora 24 (this laptop) or on my Gentoo (other desktop PC) with the same upstream plasma/kf5 packages.

Comment 1 Maciej Mrozowski 2016-11-20 06:59:03 UTC
Created attachment 1222181 [details]
drkonqui backtrace

Comment 2 Maciej Mrozowski 2016-11-20 06:59:38 UTC
Created attachment 1222182 [details]
kaccess backtrace

Comment 3 Maciej Mrozowski 2016-11-20 07:00:06 UTC
Created attachment 1222183 [details]
kactivitymanagerd backtrace

Comment 4 Maciej Mrozowski 2016-11-20 07:03:15 UTC
Created attachment 1222184 [details]
backtraces

Comment 5 Maciej Mrozowski 2016-11-20 07:03:42 UTC
Created attachment 1222185 [details]
.xsession-errors

Comment 6 Maciej Mrozowski 2016-11-20 07:42:32 UTC
Ok, I timed it.

Lockup no 1: (between sddm to plasma showing up)
Reproducible always. It is split to two parts:
- exactly 30 seconds between sddm accepts paassword and before splashs screen icon stop spinning
- between 15-20 seconds until plasma background shows up.

Lockup no 2 (plasma starts dysfunctional - just background, becomes functional after some time)
Reproducible always with clean startup (after machine restart). Not happening (plasma starts normally) on re-login - likely tied to /tmp being volatile.
- unlocks itself around 15 minutes - this is effectively total Plasma startup time

During lockup no 2, not only plasma is "locked", but some kcm modules hang as well (in ex Settings->Cache). Which brings idea that plasma is just a victim, and lockup must be somewhere in KDE IPC (kded5?).

Comment 7 Maciej Mrozowski 2016-11-20 07:53:58 UTC
(In reply to Maciej Mrozowski from comment #6)

> During lockup no 2, not only plasma is "locked", but some kcm modules hang
> as well (in ex Settings->Cache).

This not always happens..
Something is very racey here...

Comment 8 Jan Grulich 2016-11-22 11:01:16 UTC
1) Have you tried loging in with a new user (fresh configuration)?
2) Try whether we get some useful debug output using "QT_LOGGING_RULES=qt.qpa*.debug=true some_app"
3) Install debug symbols so we get a better backtrace → "dnf debuginfo-install qt5-qtbase"

Comment 9 Maciej Mrozowski 2016-11-22 12:06:15 UTC
Ad 1)
As I wrote, it happens for existing user as well us for newly created user.

Ad 2)
Will try that

Ad 3)
As for backtraces. They might not be needed, at least of crashes analysis.
After a couple of reproductions, I checked that there are actually no crashes during startkde. Or if there are, they are not intercepted by kernel (I will need to make sure there's passthrough and no drkonqui kicks in). There are crashes reported by kernel, of kactivitymanagerd that are somewhat frequent (as I see in coredumpctl list), but those are happening after the startup (maybe even during shutdown).

Comment 10 Maciej Mrozowski 2016-11-22 12:26:20 UTC
During lockup no, when I mentioned certain apps hang as well. This is backtrace from "hanging" systemsettings5:

(gdb) 
#0  0x00007f0c7caf1460 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00007f0c8062909a in QWaitConditionPrivate::wait (time=18446744073709551615, this=0x55711f022b10) at thread/qwaitcondition_unix.cpp:143
#2  QWaitCondition::wait (this=this@entry=0x55711ef4c390, mutex=mutex@entry=0x55711ef4c388, time=time@entry=18446744073709551615) at thread/qwaitcondition_unix.cpp:215
#3  0x00007f0c80f6a973 in QDBusPendingCallPrivate::waitForFinished (this=this@entry=0x55711ef4c350) at qdbuspendingcall.cpp:240
#4  0x00007f0c80f2669c in QDBusConnectionPrivate::sendWithReply (this=this@entry=0x7f0c580030f0, message=..., sendMode=sendMode@entry=1, timeout=timeout@entry=-1) at qdbusintegrator.cpp:2044
#5  0x00007f0c80f26ea5 in QDBusConnectionPrivate::findMetaObject (this=0x7f0c580030f0, service=..., path=..., interface=..., error=...) at qdbusintegrator.cpp:2537
#6  0x00007f0c80f32e8d in QDBusInterfacePrivate::QDBusInterfacePrivate (this=0x55711f00f200, serv=..., p=..., iface=..., con=...) at qdbusinterface.cpp:156
#7  0x00007f0c80f33005 in QDBusInterface::QDBusInterface (this=0x7ffc95c57350, service=..., path=..., interface=..., connection=..., parent=0x0) at qdbusinterface.cpp:218
#8  0x00007f0c56d6547d in KCookiesManagement::on_reloadButton_clicked() () from /usr/lib64/qt5/plugins/kcm_kio.so
#9  0x00007f0c83389369 in KCModule::qt_static_metacall(QObject*, QMetaObject::Call, int, void**) () from /lib64/libKF5ConfigWidgets.so.5
#10 0x00007f0c807f00d9 in QObject::event (this=this@entry=0x55711ef3db20, e=e@entry=0x55711eff96b0) at kernel/qobject.cpp:1263
#11 0x00007f0c81ce1e2b in QWidget::event (this=0x55711ef3db20, event=0x55711eff96b0) at kernel/qwidget.cpp:9208
#12 0x00007f0c81c9a96c in QApplicationPrivate::notify_helper (this=<optimized out>, receiver=0x55711ef3db20, e=0x55711eff96b0) at kernel/qapplication.cpp:3799
#13 0x00007f0c81ca2111 in QApplication::notify (this=0x7ffc95c57b80, receiver=0x55711ef3db20, e=0x55711eff96b0) at kernel/qapplication.cpp:3556
#14 0x00007f0c807c812a in QCoreApplication::notifyInternal2 (receiver=0x55711ef3db20, event=event@entry=0x55711eff96b0) at kernel/qcoreapplication.cpp:988
#15 0x00007f0c807ca800 in QCoreApplication::sendEvent (event=0x55711eff96b0, receiver=<optimized out>) at kernel/qcoreapplication.h:231
#16 QCoreApplicationPrivate::sendPostedEvents (receiver=receiver@entry=0x0, event_type=event_type@entry=0, data=0x55711ea87350) at kernel/qcoreapplication.cpp:1649
#17 0x00007f0c807cacd8 in QCoreApplication::sendPostedEvents (receiver=receiver@entry=0x0, event_type=event_type@entry=0) at kernel/qcoreapplication.cpp:1503
#18 0x00007f0c80815cf3 in postEventSourceDispatch (s=0x55711eae7da0) at kernel/qeventdispatcher_glib.cpp:276
#19 0x00007f0c788a1e42 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0
#20 0x00007f0c788a21c0 in g_main_context_iterate.isra () from /lib64/libglib-2.0.so.0
#21 0x00007f0c788a226c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
#22 0x00007f0c80815d6f in QEventDispatcherGlib::processEvents (this=0x55711eade280, flags=...) at kernel/qeventdispatcher_glib.cpp:423
#23 0x00007f0c807c70ba in QEventLoop::exec (this=this@entry=0x7ffc95c57a60, flags=..., flags@entry=...) at kernel/qeventloop.cpp:210
#24 0x00007f0c807cebac in QCoreApplication::exec () at kernel/qcoreapplication.cpp:1261
#25 0x000055711e70c230 in main ()

Comment 11 Maciej Mrozowski 2016-11-22 12:28:23 UTC
*during lockup no 2 ^^ (after startkde). I might try to get some backtraces from during startkde, but not sure what processes to monitor, I'm not expect on kdeinit5 or KDE internals in general.

Comment 12 Jan Grulich 2016-11-22 12:43:10 UTC
(In reply to Maciej Mrozowski from comment #6)
> Ok, I timed it.
> 
> Lockup no 1: (between sddm to plasma showing up)
> Reproducible always. It is split to two parts:
> - exactly 30 seconds between sddm accepts paassword and before splashs
This looks like a DBus timeout

Also from the backtrace in comment 10 it looks like some DBus related issue. I see that in KCookiesManagement::on_reloadButton_clicked() it does a DBus call.

Comment 13 Maciej Mrozowski 2016-11-23 18:16:18 UTC
Well, indeed something is dbus related, as multiple pulseaudio clients are started in this session (likely as a result of retry) and when session "unlocks itself", just one will remain.

I checked gnome-shell and it starts fine (at least its desktop shows up without problems).

I tried downgrading dbus (and its immediate libs, via dnf --releasever=24 downgrade dbus --allowremove) but it didn't help.

Then I gave up (I need working desktop, this is my work laptop) and downgraded all packages to fc24 (dnf --releasever=24 distro-sync, resolving some conflicts was needed, I did via either explicit downgrade on particular package or rpm -e) and dbus behavior is back to normal.

I don't have any problems with Fedora 25 KDE live. (though it contains older packages than my problematic Fedora 25 Testing or my currently working Fedora 24 Testing).

Comment 14 Maciej Mrozowski 2016-12-29 18:41:29 UTC
I found root cause (while experiencing issue on other Fedora machine after upgrade, there were additional symptoms that allow narrowing it down).

Please attach that bug to other "problems with "/var/tmp -> /tmp symlink" bugs (maybe 1339989 but symptoms are entirely different there)

Strangely enough I do have /var/tmp as symlink to /tmp (zramfs as opposed to tmpfs which is default otherwise) on my Gentoo (with systemd) and never had any problems with that.

Comment 15 Fedora End Of Life 2017-11-16 18:58:19 UTC
This message is a reminder that Fedora 25 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 25. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '25'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 25 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 16 Fedora End Of Life 2017-12-12 10:29:33 UTC
Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.