Bug 322494 - It's taking too long to show Main Window (slow start)
Summary: It's taking too long to show Main Window (slow start)
Status: RESOLVED INTENTIONAL
Alias: None
Product: solid
Classification: Frameworks and Libraries
Component: libsolid-upower (show other bugs)
Version: 4.10.5
Platform: Fedora RPMs Linux
: NOR normal
Target Milestone: ---
Assignee: Lukáš Tinkl
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2013-07-17 15:42 UTC by Przemysław Palacz
Modified: 2013-09-01 19:05 UTC (History)
5 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments
Dolphin's backtrace (24.65 KB, text/plain)
2013-07-19 00:37 UTC, Przemysław Palacz
Details
upowerd full backtrace (12.78 KB, text/plain)
2013-09-01 18:56 UTC, Przemysław Palacz
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Przemysław Palacz 2013-07-17 15:42:30 UTC
After using KDE for few hours apps like dolphin, gewnview and krusader are taking about 26 seconds to show main window.

Reproducible: Always




Normally those apps start in just 1-2 seconds. The problem doesn't go away until reboot.
That's probably not dolphin's bug but I couldn't figure out exact component responsible (could be kdelibs or QT).
All I've been able to find out about this bug is that app startup hangs somewhere in QInotifyFileSys thread.
PS. If you have any debugging tips that could help me provide better info I would be grateful (already reading debugging tutorial on techbase.kde.org).
Comment 1 Frank Reininghaus 2013-07-18 06:30:22 UTC
Thanks for the bug report. Unfortunately, I can neither reproduce the problem, nor do I have any idea what the cause might be. In any case, it seems very unlikely that it's a Dolphin bug.

(In reply to comment #0)
> All I've been able to find out about this bug is that app startup hangs
> somewhere in QInotifyFileSys thread.

But why should that freeze the GUI thread? 

> PS. If you have any debugging tips that could help me provide better info I
> would be grateful (already reading debugging tutorial on techbase.kde.org).

I assume that you tried to obtain a full backtrace with GDB already? If not, run "gdb dolphin", enter "run" at the gdb prompt, then press Ctrl+Z while it's frozen, and enter "thread apply all backtrace".

Thanks for your help.
Comment 2 Przemysław Palacz 2013-07-19 00:34:58 UTC
Yes, I was trying but not hard enough, still trying to learn gdb so thank you for the tips.
Yeah, you're write that second thread is not the problem, just assumed it was (or something near it), because app freezes just after this thread is started but that's just stupid.

Anyhow i got the full backtrace and it looks like main thread is waiting for dbus reply (q_dbus_connection_send_with_reply_and_block)?
Comment 3 Przemysław Palacz 2013-07-19 00:37:35 UTC
Created attachment 81191 [details]
Dolphin's backtrace
Comment 4 Yannick Kiekens 2013-07-19 07:30:16 UTC
I also have this issue on a Debian sid system.

4.10.4 had no issues
4.10.5  has slow startup time. At least 10 seconds slower than before.

No ideo on what to blame it yet.
Comment 5 Yannick Kiekens 2013-07-19 08:53:19 UTC
kdialog --getopenfilename *
shows the same behaviour (chrome, tortoisehg, ...)

so probably not a dolphin bug
Comment 6 Frank Reininghaus 2013-07-19 09:10:57 UTC
Thanks for the new info! The blocking D-Bus call is made by Solid's upower backend (Solid is the library that provides info about the available devices and some other things).

I'll reassign this report - maybe the Solid people know if anything changed between 4.10.4 and 4.10.5.

Thread 1 (Thread 0x7ffff7f9f8c0 (LWP 14792)):
#0  0x0000003a4c8eab6d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000003a50c2a948 in poll (__timeout=<optimized out>, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/bits/poll2.h:46
#2  _dbus_poll (fds=<optimized out>, n_fds=<optimized out>, timeout_milliseconds=<optimized out>) at dbus-sysdeps-unix.c:2531
#3  0x0000003a50c24528 in socket_do_iteration (transport=0xad1730, flags=6, timeout_milliseconds=<optimized out>) at dbus-transport-socket.c:1125
#4  0x0000003a50c2346f in _dbus_transport_do_iteration (transport=0xad1730, flags=1, flags@entry=6, timeout_milliseconds=timeout_milliseconds@entry=25000) at dbus-transport.c:976
#5  0x0000003a50c0da04 in _dbus_connection_do_iteration_unlocked (connection=connection@entry=0xad1d30, pending=pending@entry=0xad5850, flags=flags@entry=6, 
    timeout_milliseconds=timeout_milliseconds@entry=25000) at dbus-connection.c:1234
#6  0x0000003a50c0e3b9 in _dbus_connection_block_pending_call (pending=0xad5850) at dbus-connection.c:2415
#7  0x0000003a50c1d7aa in dbus_pending_call_block (pending=<optimized out>) at dbus-pending-call.c:748
#8  0x0000003a50c0e97d in dbus_connection_send_with_reply_and_block (connection=0xad1d30, message=0x81cfe0, timeout_milliseconds=-1, error=0x7fffffffd230) at dbus-connection.c:3530
#9  0x0000003a586286e0 in q_dbus_connection_send_with_reply_and_block (error=0x7fffffffd230, timeout_milliseconds=-1, message=0x81cfe0, connection=<optimized out>)
    at qdbus_symbols_p.h:135
#10 QDBusConnectionPrivate::sendWithReply (this=this@entry=0xac0510, message=..., sendMode=sendMode@entry=1, timeout=timeout@entry=-1) at qdbusintegrator.cpp:1907
#11 0x0000003a5862a472 in QDBusConnectionPrivate::findMetaObject (this=0xac0510, service=..., path=..., interface=..., error=...) at qdbusintegrator.cpp:2376
#12 0x0000003a586359ab in QDBusInterfacePrivate::QDBusInterfacePrivate (this=0xad5650, serv=..., p=..., iface=..., con=...) at qdbusinterface.cpp:158
#13 0x0000003a58635ad5 in QDBusInterface::QDBusInterface (this=0xac0408, service=..., path=..., interface=..., connection=..., parent=0x0) at qdbusinterface.cpp:220
#14 0x0000003f01e8f5ac in Solid::Backends::UPower::UPowerManager::UPowerManager (this=0xac03f0, parent=<optimized out>)
    at /usr/src/debug/kdelibs-4.10.5/solid/solid/backends/upower/upowermanager.cpp:41
#15 0x0000003f01e3f66c in Solid::ManagerBasePrivate::loadBackends (this=this@entry=0xabecf0) at /usr/src/debug/kdelibs-4.10.5/solid/solid/managerbase.cpp:95
#16 0x0000003f01e40e8c in Solid::DeviceManagerPrivate::DeviceManagerPrivate (this=0xabece0) at /usr/src/debug/kdelibs-4.10.5/solid/solid/devicemanager.cpp:38
#17 0x0000003f01e41015 in Solid::DeviceManagerStorage::ensureManagerCreated (this=this@entry=0x942fe0) at /usr/src/debug/kdelibs-4.10.5/solid/solid/devicemanager.cpp:287
#18 0x0000003f01e410cc in notifier (this=<optimized out>) at /usr/src/debug/kdelibs-4.10.5/solid/solid/devicemanager.cpp:280
#19 Solid::DeviceNotifier::instance () at /usr/src/debug/kdelibs-4.10.5/solid/solid/devicemanager.cpp:172
#20 0x0000003f01e3f8f8 in Solid::Device::Device (this=0xabd6a8, udi=...) at /usr/src/debug/kdelibs-4.10.5/solid/solid/device.cpp:78
#21 0x0000003f04e6107f in KFilePlacesItem::KFilePlacesItem (this=0xabd670, manager=0x8a73d0, address=..., udi=...) at /usr/src/debug/kdelibs-4.10.5/kfile/kfileplacesitem.cpp:42
#22 0x0000003f04e63911 in KFilePlacesModel::Private::loadBookmarkList (this=this@entry=0x8a71c0) at /usr/src/debug/kdelibs-4.10.5/kfile/kfileplacesmodel.cpp:453
#23 0x0000003f04e63ae3 in KFilePlacesModel::Private::_k_reloadBookmarks (this=0x8a71c0) at /usr/src/debug/kdelibs-4.10.5/kfile/kfileplacesmodel.cpp:362
#24 0x0000003f04e647a8 in KFilePlacesModel::KFilePlacesModel (this=0x8a6df0, parent=<optimized out>) at /usr/src/debug/kdelibs-4.10.5/kfile/kfileplacesmodel.cpp:174
#25 0x0000003516a4ae10 in DolphinViewContainer::DolphinViewContainer (this=0x8a64b0, url=..., parent=<optimized out>)
    at /usr/src/debug/kde-baseapps-4.10.5/dolphin/src/dolphinviewcontainer.cpp:82
Comment 7 Alex Fiestas 2013-07-28 22:57:45 UTC
UPower seems to be freezing on us lately and with that freezing libsolid since we perform sync calls.

There isn't much we can do since all our api is Sync, it is not until libsolid2 that we'll do all Async.

So, going to close the bug as WONTFIX since we can't have libsolid2 for at least 1 more year (we have to finish KDE Frameworks 5).

Also, we need to get UPower fixed.

To confirm  I'm not wrong, try executing:
qdbus --system org.freedesktop.UPower you should see how that command never ends.

Thanks and sorry :/
Comment 8 john Terragon 2013-07-29 06:58:05 UTC
(In reply to comment #7)
> UPower seems to be freezing on us lately and with that freezing libsolid
> since we perform sync calls.
> 
> There isn't much we can do since all our api is Sync, it is not until
> libsolid2 that we'll do all Async.
> 
> So, going to close the bug as WONTFIX since we can't have libsolid2 for at
> least 1 more year (we have to finish KDE Frameworks 5).
> 
> Also, we need to get UPower fixed.
> 
> To confirm  I'm not wrong, try executing:
> qdbus --system org.freedesktop.UPower you should see how that command never
> ends.
> 
> Thanks and sorry :/

OK, but since it's something that's been happening "lately", if it's all upower fault maybe there is a previous version of it that doesn't freeze and that you can recommend? I tried 0.9.17 (which i believe is more that a year old) and it still freezes sometimes (but it didn't freeze with kde 4.8 so maybe upower is not entirely the culprit?). And the dbus command you wrote above does not freeze at all (with 0.9.17, I haven't tried it with 0.9.20). 
Now the only way to have a functional kde (since the problem involves many base apps)
is to periodically kill upowerd.
Comment 9 Alex Fiestas 2013-07-29 12:48:56 UTC
I have to test 0.9.21 and see if it still happens, if not I will debug the issue and report it upstream.

The freezes happen from time to time, is not something that always happens.
Comment 10 john Terragon 2013-07-29 13:24:17 UTC
(In reply to comment #9)
> I have to test 0.9.21 and see if it still happens, if not I will debug the
> issue and report it upstream.

Thank you.

Does killing upowerd (as a workaround) cause any important side effects if you're not running on batteries? The only visible change I noticed is that I don't have sleep and hibernate buttons anymore (but I can use pm-tools directly so no big problem).
Comment 11 Alex Fiestas 2013-07-29 14:53:07 UTC
Not really, since upowerd will respawn and work well for nother... few minutes xD
Comment 12 S. Umar 2013-08-05 18:00:40 UTC
I have been experiencing this as well since the 4.10.5 updates (multiple users,
desktops and laptops, etc.). It gets to the point were X needs to be restarted
(session killed). 

On Fedora 19 upower has not beed updated since March 20 (0.9.20). So, this
suggests that KDE 4.10.5 changed something from KDE 4.10.4 to cause these
problems.
Comment 13 john Terragon 2013-08-08 21:26:18 UTC
(In reply to comment #12)
> I have been experiencing this as well since the 4.10.5 updates (multiple
> users,
> desktops and laptops, etc.). It gets to the point were X needs to be
> restarted
> (session killed). 
> 

When X gets stuck have you tried restarting kded4 (by invoking "kdeinit4 kded4" on a shell for example)?  That works for me and after that I just have to kill upowerd periodically. (I know, it's an ugly workaround but it makes kde usable again).
Comment 14 S. Umar 2013-08-09 13:11:01 UTC
Have you tested upower 0.9.21 yet? I installed it on our systems and some of
my colleagues tell me that they have not experienced the slowdown since.
Comment 15 john Terragon 2013-08-09 19:50:40 UTC
Just tried 0.9.21. No luck, same problem.
Comment 16 Alex Fiestas 2013-08-12 10:52:06 UTC
can you guys install the debug symbosl for upower (and all the library it uses), and once stuck do the folllowing?

as root:
gdb --pid XXXXX

where XXX is the pid of the process.

Once gdb stops outputing stuff, type "continue"

After a while, press Ctrl+C, and type
thread apply all bt full

Then grab all that output and attach it to this bug, I will talk with the upower maintainer // report a bug so he can fix it.
Comment 17 Przemysław Palacz 2013-09-01 18:56:14 UTC
Created attachment 82092 [details]
upowerd full backtrace
Comment 18 Przemysław Palacz 2013-09-01 19:05:46 UTC
Forgot to add I'm currently running KDE 4.11.0 and upower 0.9.20.