Bug 170993 - Switching calendar views takes more than 20 seconds eating 100% CPU
Summary: Switching calendar views takes more than 20 seconds eating 100% CPU
Status: RESOLVED FIXED
Alias: None
Product: korganizer
Classification: Applications
Component: general (show other bugs)
Version: unspecified
Platform: Compiled Sources Linux
: NOR normal
Target Milestone: ---
Assignee: kdepim bugs
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2008-09-13 18:34 UTC by Eduardo Habkost
Modified: 2009-01-02 05:56 UTC (History)
3 users (show)

See Also:
Latest Commit:
Version Fixed In:
Sentry Crash Report:


Attachments
Patch to speed up size calculation of rich text delegate (2.01 KB, patch)
2008-11-14 08:39 UTC, Thomas Thrainer
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Eduardo Habkost 2008-09-13 18:34:19 UTC
Version:           SVN trunk, revision 860448 (using Devel)
OS:                Linux
Installed from:    Compiled sources

When using my calendar, KOrganizer takes more than 20 seconds to respond when I click on any of the calendar view buttons (day, week, month, etc). This happens even if I click on the button corresponding to the view I am currently looking at.

Debugging has shown it is taking lots of time inside KOTodoModel::reloadTodos(), at the emit dataChanged loop. When using my calendar data, each reloadTodos() call emits 1539 signals, taking up to 17 seconds (sometimes even more: I have seen it taking 40 seconds) to run the loop.

Profiling and randomly interrupting KOrganizer during the busy loop has shown it is spending most of time inside this call trace:

(gdb) bt full
#0  0x00ab7231 in QCoreApplicationPrivate::removePostedEvents_unlocked (receiver=<value optimized out>, eventType=<value optimized out>, data=<value optimized out>)
    at kernel/qcoreapplication.cpp:1302
        i = <value optimized out>
        n = 2780
        j = 2103
#1  0x00ace612 in ~QObject (this=<value optimized out>) at kernel/qobject.cpp:877
No locals.
#2  0x070ec408 in ~QTextDocument (this=Could not find the frame base for "~QTextDocument".
) at text/qtextdocument.cpp:344
No locals.
#3  0x010aaa49 in KOTodoRichTextDelegate::sizeHint (this=0x9dd06a0, option=@0xbfc1ca84, index=@0xbfc1cb04)
    at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/views/todoview/kotododelegates.cpp:469
        tmp = {<QObject> = {_vptr.QObject = 0xb9c9a8, static staticMetaObject = {d = {superdata = 0x0, stringdata = 0xb46880 "QObject", data = 0xb46900,
        extradata = 0x0}}, d_ptr = 0xa4c3568, static staticQtMetaObject = {d = {superdata = 0x0, stringdata = 0xb4f960 "Qt", data = 0xb51600, extradata = 0x0}}},
  static staticMetaObject = {d = {superdata = 0xb99458, stringdata = 0x75109e0 "QTextDocument", data = 0x7510c00, extradata = 0x0}}}
        ret = {wd = 4, ht = 23}
        ret = {wd = 162133928, ht = -1077818872}
#4  0x073cf8e9 in QTreeView::indexRowSizeHint (this=<value optimized out>, index=<value optimized out>) at itemviews/qtreeview.cpp:2720
        editor = <value optimized out>
        logicalColumn = <value optimized out>
        idx = Could not find the frame base for "QTreeView::indexRowSizeHint(QModelIndex const&) const".
(gdb) bt
#0  0x00ab7231 in QCoreApplicationPrivate::removePostedEvents_unlocked (receiver=<value optimized out>, eventType=<value optimized out>, data=<value optimized out>)
    at kernel/qcoreapplication.cpp:1302
#1  0x00ace612 in ~QObject (this=<value optimized out>) at kernel/qobject.cpp:877
#2  0x070ec408 in ~QTextDocument (this=Could not find the frame base for "~QTextDocument".
) at text/qtextdocument.cpp:344
#3  0x010aaa49 in KOTodoRichTextDelegate::sizeHint (this=0x9dd06a0, option=@0xbfc1ca84, index=@0xbfc1cb04)
    at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/views/todoview/kotododelegates.cpp:469
#4  0x073cf8e9 in QTreeView::indexRowSizeHint (this=<value optimized out>, index=<value optimized out>) at itemviews/qtreeview.cpp:2720
#5  0x073cfc62 in QTreeViewPrivate::itemHeight (this=<value optimized out>, item=<value optimized out>) at itemviews/qtreeview.cpp:3100
#6  0x073cff2e in QTreeViewPrivate::updateScrollBars (this=<value optimized out>) at itemviews/qtreeview.cpp:3405
#7  0x073d02b2 in QTreeView::updateGeometries (this=<value optimized out>) at itemviews/qtreeview.cpp:2616
#8  0x0738e989 in QAbstractItemView::doItemsLayout (this=Could not find the frame base for "QAbstractItemView::doItemsLayout()".
) at itemviews/qabstractitemview.cpp:1002
#9  0x073db832 in QTreeView::doItemsLayout (this=<value optimized out>) at itemviews/qtreeview.cpp:1949
#10 0x073cb4df in QTreeView::resizeColumnToContents (this=<value optimized out>, column=<value optimized out>) at ../../src/gui/itemviews/qabstractitemview_p.h:179
#11 0x073cb5ce in QTreeViewPrivate::_q_forceColumnResizeToFitContents (this=<value optimized out>) at itemviews/qtreeview.cpp:2982
#12 0x073db29c in QTreeView::qt_metacall (this=<value optimized out>, _c=<value optimized out>, _id=<value optimized out>, _a=<value optimized out>)
    at .moc/release-shared/moc_qtreeview.cpp:149
#13 0x010ae5f6 in KOTodoViewView::qt_metacall (this=0x9db2590, _c=QMetaObject::InvokeMetaMethod, _id=91, _a=0xbfc1ce08)
    at /mnt/common/code/kde/build/trunk/KDE/kdepim/korganizer/kotodoviewview.moc:61
#14 0x00acc3e0 in QMetaObject::activate (sender=<value optimized out>, from_signal_index=<value optimized out>, to_signal_index=<value optimized out>,
    argv=<value optimized out>) at kernel/qobject.cpp:3016
#15 0x00acd162 in QMetaObject::activate (sender=<value optimized out>, m=<value optimized out>, local_signal_index=<value optimized out>, argv=Could not find the frame base for "QMetaObject::activate(QObject*, QMetaObject const*, int, void**)".
)
    at kernel/qobject.cpp:3086
#16 0x00b065b7 in QAbstractItemModel::layoutChanged (this=Could not find the frame base for "QAbstractItemModel::layoutChanged()".
) at .moc/release-shared/moc_qabstractitemmodel.cpp:137
#17 0x0741f282 in QSortFilterProxyModelPrivate::_q_sourceDataChanged (this=<value optimized out>, source_top_left=<value optimized out>,
    source_bottom_right=<value optimized out>) at itemviews/qsortfilterproxymodel.cpp:1011
#18 0x0741fd5f in QSortFilterProxyModel::qt_metacall (this=<value optimized out>, _c=<value optimized out>, _id=<value optimized out>, _a=<value optimized out>)
    at .moc/release-shared/moc_qsortfilterproxymodel.cpp:119
#19 0x010ad268 in KOTodoViewSortFilterProxyModel::qt_metacall (this=0x9dba190, _c=QMetaObject::InvokeMetaMethod, _id=26, _a=0xbfc1d038)
    at /mnt/common/code/kde/build/trunk/KDE/kdepim/korganizer/kotodoviewsortfilterproxymodel.moc:61
#20 0x00acc3e0 in QMetaObject::activate (sender=<value optimized out>, from_signal_index=<value optimized out>, to_signal_index=<value optimized out>,
    argv=<value optimized out>) at kernel/qobject.cpp:3016
#21 0x00acd162 in QMetaObject::activate (sender=<value optimized out>, m=<value optimized out>, local_signal_index=<value optimized out>, argv=Could not find the frame base for "QMetaObject::activate(QObject*, QMetaObject const*, int, void**)".
)
    at kernel/qobject.cpp:3086
#22 0x00b06669 in QAbstractItemModel::dataChanged (this=Could not find the frame base for "QAbstractItemModel::dataChanged(QModelIndex const&, QModelIndex const&)".
) at .moc/release-shared/moc_qabstractitemmodel.cpp:124
#23 0x010a7c37 in KOTodoModel::reloadTodos (this=0x9d91228) at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/views/todoview/kotodomodel.cpp:258
#24 0x010b11fe in KOTodoView::updateView (this=0x9dc6f68) at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/views/todoview/kotodoview.cpp:346


It looks like multiple problems are being multiplied:

- Changing the calendar view trigger reloadTodos() multiple times (two or more, on my tests), even if I am not seeing the TODO-list treeview on the screen
- reloadTodos() trigger many dataChanged() signals
- Each dataChanged() signal trigges style recalculation on the todo tree view
- Each style recalculation trigger multiple size hint recalculations, for each todo item
- Each size hint recalculation for a tree view row creates a short-lived QTextDocument object, that will trigger an expensive loop at QCoreApplicationPrivate::removePostedEvents_unlocked() when destroyed
Comment 1 Eduardo Habkost 2008-09-13 21:41:00 UTC
I've noticed reloadTodos() is being called twice because there are two TodoView objects, so it is expected anyway.

The interesting part is: the first reloadTodos() is "quick": it takes two seconds to complete. The second reloadTodos() call is the one that takes almost 20 seconds. However, both are emitting 1539 dataChanged signals.

Completing the backtrace I've sent previously, this is the continuation of the call path to  the reloadTodos() call that is taking longer:

#23 0x010a7c37 in KOTodoModel::reloadTodos (this=0x9d91228) at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/views/todoview/kotodomodel.cpp:258
#24 0x010b11fe in KOTodoView::updateView (this=0x9dc6f68) at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/views/todoview/kotodoview.cpp:346
#25 0x010d60c2 in KOViewManager::updateView (this=0x9ba14e8, start=@0xa5d1dac, end=@0xa5d1dc4)
    at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/koviewmanager.cpp:197
#26 0x010cc27a in CalendarView::updateView (this=0x9ba0fb8, start=@0xa5d1dac, end=@0xa5d1dc4)
    at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/calendarview.cpp:795
#27 0x010cc2e3 in CalendarView::showDates (this=0x9ba0fb8, selectedDates=@0x9ae3518) at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/calendarview.cpp:1653
#28 0x010d1cba in CalendarView::qt_metacall (this=0x9ba0fb8, _c=QMetaObject::InvokeMetaMethod, _id=175, _a=0xbfc1d2ec)



(Yes, I have more than 1500 TODO items on my calendar. I keep them around, as a history of the tasks I've completed in the past. I usually set up filters to hide the completed items, so I don't see all of them.   8)
Comment 2 Thomas Thrainer 2008-11-14 08:39:50 UTC
Created attachment 28566 [details]
Patch to speed up size calculation of rich text delegate

This patch speeds up the calculation of the size hint for rich text delegates by introducing a new QTextDocument member variable which avoids creating a temporary QTextDocument for each call of sizeHint().
Eduardo, would you mind to test it to see if it improves performance? The patch should be applied in korganizer/views/todoview.
Comment 3 Thomas Thrainer 2008-11-14 08:48:41 UTC
Further information:
reloadTodo() is called twice, because there are two todo views around in KOrganizer. The first one is the big on in the main window, the second one the small one in the sidepane. I guess the small one is hidden in your case, so Qt manages to avoid calling sizeHint() for hidden columns / views.

Another point is that the todo view should in theory almost never be forced to reload itself, as it should adapt incrementally to all changes in the calendar. However, I couldn't manage to get rid of the call to reloadTodos() in KOTodoView::updateView(), because otherwise the view wont load at all.
I tried to reload the view only when setCalendar() is called, but apparently this method is called before items get added to the calendar. Furthermore, during initialisation of the calendar no change signals are emitted, so the todoview can't change one todo after the other.
I think there is a problem somewhere else, but as Akonadi is around the corner, which will change the way todos (and anything else) are loaded completely, I guess the only thing I could do regarding this bug is the already attached patch.

Anyway, thanks a lot for your detailed analysis.

Thomas
Comment 4 Dotan Cohen 2008-12-02 17:59:09 UTC
It seems that this issue has been known since August in Ubuntu:
https://bugs.launchpad.net/ubuntu/+source/kdepim/+bug/258611

It has been confirmed by several people there, myself included (OP).
Comment 5 Eduardo Habkost 2008-12-29 02:47:50 UTC
(In reply to comment #2)
> Created an attachment (id=28566) [details]
> Patch to speed up size calculation of rich text delegate
> 
> This patch speeds up the calculation of the size hint for rich text delegates
> by introducing a new QTextDocument member variable which avoids creating a
> temporary QTextDocument for each call of sizeHint().
> Eduardo, would you mind to test it to see if it improves performance? The patch
> should be applied in korganizer/views/todoview.

Hi,

Sorry for taking so long to reply. I've tested the patch and the situation improved, but it is not perfect yet.

Now instead of taking up to 40 seconds, it takes around 1.6 seconds on the first reloadTodos() call, and around 12 seconds on the second reloadTodos() call.

I've seen it spending time destroying QTextObject objects on the loop (see backtrace below), but I didn't profile it (yet) to check if this is really the main place where it is eating CPU, now.

#0  0x06bdc6a4 in QObjectPrivate::removePendingChildInsertedEvents () from /usr/lib/libQtCore.so.4
#1  0x03cb9f2f in QApplication::notify () from /usr/lib/libQtGui.so.4
#2  0x0032492f in KApplication::notify (this=0xbfe7aae4, receiver=0x960bfe0, event=0xbfe78f18)
    at /mnt/common/code/kde/svn/trunk/KDE/kdelibs/kdeui/kernel/kapplication.cpp:307
#3  0x06bce2f1 in QCoreApplication::notifyInternal () from /usr/lib/libQtCore.so.4
#4  0x06be5fae in QCoreApplication::sendEvent () from /usr/lib/libQtCore.so.4
#5  0x06bdcb64 in QObjectPrivate::setParent_helper () from /usr/lib/libQtCore.so.4
#6  0x06be5208 in QObject::~QObject () from /usr/lib/libQtCore.so.4
#7  0x03ecdbd8 in QTextObject::~QTextObject () from /usr/lib/libQtGui.so.4
#8  0x03ecdc22 in QTextFrame::~QTextFrame () from /usr/lib/libQtGui.so.4
#9  0x03ee5d8b in ?? () from /usr/lib/libQtGui.so.4
#10 0x03ed5542 in QTextDocument::setHtml () from /usr/lib/libQtGui.so.4
#11 0x0089ef3c in KOTodoRichTextDelegate::sizeHint (this=0x8dc0e40, option=@0xbfe79234, index=@0xbfe792b4)
    at /mnt/common/code/kde/svn/trunk/KDE/kdepim/korganizer/views/todoview/kotododelegates.cpp:467
Comment 6 Sergio Martins 2008-12-29 03:12:41 UTC
If someone attaches/makes an example resource file, I can have a look at the problem.
Comment 7 Sergio Martins 2008-12-30 15:59:35 UTC
SVN commit 903450 by smartins:

Thomas Thrainer's patch to speed up size calculation of rich text delegate.

CCBUG: 170993



 M  +6 -7      kotododelegates.cpp  
 M  +3 -0      kotododelegates.h  


WebSVN link: http://websvn.kde.org/?view=rev&revision=903450
Comment 8 Sergio Martins 2008-12-30 16:59:12 UTC
SVN commit 903468 by smartins:

Don't call mTodoList->updateView() when switching between agenda/monthview.

CCBUG: 170993


 M  +5 -3      calendarview.cpp  
 M  +1 -1      calendarview.h  


WebSVN link: http://websvn.kde.org/?view=rev&revision=903468
Comment 9 Sergio Martins 2008-12-30 17:01:10 UTC
Eduardo, can you update your trunk and try again?

Thanks
Comment 10 Dotan Cohen 2009-01-02 05:55:44 UTC
I cannot reproduce in current Trunk. The problem seems fixed.