Bug 193249 - Akonadi server with protocol version 12 consumes 100% CPU using ICAL resources
Summary: Akonadi server with protocol version 12 consumes 100% CPU using ICAL resources
Status: RESOLVED FIXED
Alias: None
Product: Akonadi
Classification: Frameworks and Libraries
Component: server (show other bugs)
Version: unspecified
Platform: openSUSE Linux
: NOR normal
Target Milestone: ---
Assignee: Volker Krause
URL:
Keywords:
: 194238 (view as bug list)
Depends on:
Blocks:
 
Reported: 2009-05-19 16:10 UTC by René Krell
Modified: 2009-05-27 00:20 UTC (History)
7 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description René Krell 2009-05-19 16:10:47 UTC
Version:           1.1.85 + branch diff from 18.05.2009 (using KDE 4.2.85)
Compiler:          gcc 
OS:                Linux
Installed from:    SuSE RPMs

After starting KDE 4.3 Beta 1 (OpenSUSE 11.1 KDE 4 Factory repository) with the latest upstream packages comes up Akonadi "eats" 100% of CPU. korgac doesn't show any icon even after a few minutes in systray, KOrganizer hangs. Akonadi restart doesn't help. Using the supported mysql packages from OpenSuSE 11.1, nothing special here:

akonadi-runtime-1.1.85-23.1
libakonadiprotocolinternals1-1.1.85-23.1
kde4-akonadi-4.2.85-116.5
mysql-5.0.67-12.11
libmysqlclient15-5.0.67-12.11
libqt4-sql-mysql-4.5.1-46.1
mysql-client-5.0.67-12.11
libmysqlclient_r15-5.0.67-12.11

Akonadi protocol 12 is announced by the Akonadi server now.

The problem occurs for me only with KOrganizer resources, even with small ones. If I delete all my ICS-Resources (calendar files) from the Akonadi console, and quit korgac and korganizer, followed by an Akonadi server restart it runs normally.

Akonadi takes 100% CPU either on launching korgac or KOrganizer, or starting Akonadi server with at least one calendar (ICS or birthdays) resource.

Removing the Akonadi config files unter $HOME/.config/akonadi didn't help.
Comment 1 Christian Trippe 2009-05-19 19:52:58 UTC
I had the same problem when I enabled the Akonadi resource for my imap-account in kaddressbook.
Comment 2 Alin M Elena 2009-05-20 10:41:26 UTC
A memory leak can be observed very easy.
Comment 3 Tom Albers 2009-05-20 10:51:28 UTC
Thanks for the useless comment. Please provide details. a mem leak leads to 100% memory usage and not to 100% CPU. So please open a new bug report with the details.
Comment 4 Alin M Elena 2009-05-20 11:01:24 UTC
that was a simple hint of what happens when you encounter the bug. Instead of wasting your time being sarcastic you could have tried to reproduce the bug.

Alin
Comment 5 Christophe Marin 2009-05-20 11:07:56 UTC
Confirmed in trunk. When adding the birthday resource (via the kcm or akonadiconsole), the akonadiserver process goes mad.

Akonadiconsole is then filled with : 
NotificationManager::notify ( Item (6, b2) in collection 4 modified )
NotificationManager::notify ( Item (6, b2) in collection 4 modified )
NotificationManager::notify ( Item (6, b2) in collection 4 modified )
NotificationManager::notify ( Item (6, b2) in collection 4 modified )
NotificationManager::notify ( Item (6, b2) in collection 4 modified )
NotificationManager::notify ( Item (6, b2) in collection 4 modified )
NotificationManager::notify ( Item (6, b2) in collection 4 modified )

//

0x96e4840 7570 UID FETCH 6 FULLPAYLOAD EXTERNALPAYLOAD (UID REMOTEID COLLECTIONID FLAGS SIZE DATETIME) 
0x96db9b8 13879 UID FETCH 6 FULLPAYLOAD EXTERNALPAYLOAD (UID REMOTEID COLLECTIONID FLAGS SIZE DATETIME) 
0x9805438 2022 UID FETCH 2 FULLPAYLOAD EXTERNALPAYLOAD (UID REMOTEID COLLECTIONID FLAGS SIZE DATETIME) 
0x9805438 * 2 FETCH (UID 2 REV 2 REMOTEID "WyDwPsvqxH" MIMETYPE "text/directory" COLLECTIONID "3" SIZE 0 DATETIME "19-May-2009 22:43:48 +0000" FLAGS () PLD:RFC822 {405} BEGIN:VCARD BDAY:2009-02-19T00:00:00 CLASS:PUBLIC EMAIL:myemail@domain.tld FN:Christophe Giboudeaux GEO:48.866669;2.333333 N:Giboudeaux;Christophe;;; NAME:Christophe Giboudeaux REV:2009-03-31T16:48:30 UID:WyDwPsvqxH VERSION:3.0 X-KADDRESSBOOK-CRYPTOPROTOPREF:openpgp/mime X-KADDRESSBOOK-CRYPTOSIGNPREF:always X-KADDRESSBOOK-OPENPGPFP:F0A097B86D953712E6187511C4DE32AC1AE3A833 END:VCARD ) 
0x9805438 2022 OK UID FETCH completed 
0x9805438 2023 UID STORE 6 NOREV SIZE 0 (REMOTEID.SILENT "b2" PLD:RFC822.SILENT NIL) 
0x9805438 2023 OK DATETIME "20-May-2009 09:00:38 +0000" STORE completed 
0x96e4840 * 6 FETCH (UID 6 REV 669 REMOTEID "b2" MIMETYPE "application/x-vnd.akonadi.calendar.event" COLLECTIONID "4" SIZE 0 DATETIME "20-May-2009 09:00:38 +0000" FLAGS () PLD:RFC822 NIL) 
0x96db9b8 * 6 FETCH (UID 6 REV 669 REMOTEID "b2" MIMETYPE "application/x-vnd.akonadi.calendar.event" COLLECTIONID "4" SIZE 0 DATETIME "20-May-2009 09:00:38 +0000" FLAGS () PLD:RFC822 NIL) 
0x96e4840 7570 OK UID FETCH completed 
0x96db9b8 13879 OK UID FETCH completed 
0x96e4840 7571 UID FETCH 6 FULLPAYLOAD EXTERNALPAYLOAD (UID REMOTEID COLLECTIONID FLAGS SIZE DATETIME) 
0x96db9b8 13880 UID FETCH 6 FULLPAYLOAD EXTERNALPAYLOAD (UID REMOTEID COLLECTIONID FLAGS SIZE DATETIME) 
0x9805438 2025 UID FETCH 2 FULLPAYLOAD EXTERNALPAYLOAD (UID REMOTEID COLLECTIONID FLAGS SIZE DATETIME) 

---

gdb attached to the birthday process :

#0  0xb80b3424 in __kernel_vsyscall ()
#1  0xb64f566b in poll () from /lib/libc.so.6
#2  0xb5e75f12 in ?? () from /usr/lib/libglib-2.0.so.0
#3  0xb5e76241 in g_main_context_iteration () from /usr/lib/libglib-2.0.so.0
#4  0xb684c558 in QEventDispatcherGlib::processEvents (this=0x96d2c88, flags={i = -1073939272}) at kernel/qeventdispatcher_glib.cpp:324
#5  0xb6dc1975 in QGuiEventDispatcherGlib::processEvents (this=0x96d2c88, flags={i = -1073939224}) at kernel/qguieventdispatcher_glib.cpp:202
#6  0xb681f0fa in QEventLoop::processEvents (this=0xbffcfd60, flags={i = -1073939160}) at kernel/qeventloop.cpp:149
#7  0xb681f53a in QEventLoop::exec (this=0xbffcfd60, flags={i = -1073939096}) at kernel/qeventloop.cpp:200
#8  0xb68219e9 in QCoreApplication::exec () at kernel/qcoreapplication.cpp:888
#9  0xb6d21517 in QApplication::exec () at kernel/qapplication.cpp:3526
#10 0xb7d8c273 in Akonadi::ResourceBase::init (r=0x977f630) at /home/krop/kde/src/KDE/kdepimlibs/akonadi/resourcebase.cpp:223
#11 0x080543b5 in Akonadi::ResourceBase::init<BirthdaysResource> (argc=3, argv=0xbffcfeb4) at /opt/kde4/kdepimlibs/include/akonadi/resourcebase.h:185
#12 0x08051afb in main (argc=3, argv=0xbffcfeb4) at /home/krop/kde/src/KDE/kdepim/akonadi/resources/birthdays/birthdaysresource.cpp:320

---

and the akonadiserver.error is filled with : 
WTF: processRequest() called but no request queued!?
WTF: processRequest() called but no request queued!?
Comment 6 Christophe Marin 2009-05-20 11:11:49 UTC
(In reply to comment #4)
> that was a simple hint of what happens when you encounter the bug. Instead of
> wasting your time being sarcastic you could have tried to reproduce the bug.
> 


Your hint is false, the used ram is still ridiculous. (less than 4K for the akonadi_birthday_resource and ~2K for the akonadiserver process.)
Comment 7 Tom Albers 2009-05-20 11:12:53 UTC
@alin Instead of providing useless and obvious comments you better give a step-by-step description on how we can reproduce it, for example like Christophe did.
Comment 8 Christophe Marin 2009-05-20 11:29:10 UTC
The akonadiserver log :


[akonadiserver] posting retrieval request for item 6                                                                                                   
[akonadiserver] checking if request for item 6 has been processed...                                                                                   
[akonadiserver] request for item 6 still pending - waiting                                                                                             
[akonadiserver] someone else requested item 6 as well, marking as processed                                                                            
[akonadiserver] processRequest() - current thread: Akonadi::ItemRetrievalThread(0x96bd308)  retrieval thread: Akonadi::ItemRetrievalThread(0x96bd308)  
[akonadiserver] WTF: processRequest() called but no request queued!?                                                                                   
[akonadiserver] continuing                                                                                                                             
[akonadiserver] checking if request for item 6 has been processed...                                                                                   
[akonadiserver] request for item 6 processed, error: "Unable to retrieve item from resource: The name org.freedesktop.Akonadi.Resource.akonadi_birthdays_resource was not provided by any .service files"                                                                                                     
[akonadiserver] ItemRetrieverException :  Unable to retrieve item from resource: The name org.freedesktop.Akonadi.Resource.akonadi_birthdays_resource was not provided by any .service files                                                                                                                  
[akonadiserver] continuing                                                                                                                             
[akonadiserver] checking if request for item 6 has been processed...                                                                                   
[akonadiserver] request for item 6 processed, error: "Unable to retrieve item from resource: The name org.freedesktop.Akonadi.Resource.akonadi_birthdays_resource was not provided by any .service files"                                                                                                     
[akonadiserver] ItemRetrieverException :  Unable to retrieve item from resource: The name org.freedesktop.Akonadi.Resource.akonadi_birthdays_resource was not provided by any .service files                                                                                                                  
[akonadiserver] requestItemDelivery() - current thread: Akonadi::AkonadiConnection(0x96db9b8)  retrieval thread: Akonadi::ItemRetrievalThread(0x96bd308)
Comment 9 Alin M Elena 2009-05-20 11:39:58 UTC
here is my memory usage by kontact when activating the akonadi resources (I have around )

  PID TTY      STAT   TIME  MAJFL   TRS   DRS   RSS %MEM COMMAND
 4948 ?        Sl     0:40     23    21 556090 65232  1.6 /usr/bin/kontact  
 4948 ?        Sl     0:40     23    21 556090 65232  1.6 /usr/bin/kontact  
 4948 ?        Sl     0:55     26    21 617938 97604  2.4 /usr/bin/kontact  
 4948 ?        Sl     0:56     26    21 618626 98332  2.4 /usr/bin/kontact  
 4948 ?        Rl     0:57     26    21 619462 99248  2.4 /usr/bin/kontact  
 4948 ?        Sl     0:58     26    21 620062 99848  2.4 /usr/bin/kontact  
 4948 ?        Sl     0:59     26    21 620642 100412  2.4 /usr/bin/kontact  
 4948 ?        Rl     0:59     26    21 620998 100744  2.4 /usr/bin/kontact  
 4948 ?        Sl     1:00     26    21 621226 101012  2.4 /usr/bin/kontact  
 4948 ?        Sl     1:00     26    21 621566 101420  2.5 /usr/bin/kontact  
 4948 ?        Sl     1:01     26    21 622286 102088  2.5 /usr/bin/kontact  
 4948 ?        Rl     1:02     26    21 622650 102440  2.5 /usr/bin/kontact  
 4948 ?        Rl     1:02     26    21 622902 102764  2.5 /usr/bin/kontact  
 4948 ?        Rl     1:03     26    21 623154 103040  2.5 /usr/bin/kontact  
 4948 ?        Sl     1:03     26    21 623526 103372  2.5 /usr/bin/kontact  
 4948 ?        Sl     1:04     26    21 623890 103784  2.5 /usr/bin/kontact  
 4948 ?        Rl     1:04     26    21 624214 104072  2.5 /usr/bin/kontact  
 4948 ?        Rl     1:05     26    21 624666 104508  2.5 /usr/bin/kontact  
 4948 ?        Sl     1:05     26    21 625290 104796  2.5 /usr/bin/kontact  
 4948 ?        Sl     1:06     26    21 625630 105200  2.5 /usr/bin/kontact  
 4948 ?        Rl     1:07     26    21 625994 105512  2.6 /usr/bin/kontact  
 4948 ?        Sl     1:07     26    21 626362 105956  2.6 /usr/bin/kontact  
 4948 ?        Rl     1:08     26    21 626962 106480  2.6 /usr/bin/kontact  
 4948 ?        Rl     1:09     26    21 627198 106808  2.6 /usr/bin/kontact  
 4948 ?        Rl     1:10     26    21 627666 107188  2.6 /usr/bin/kontact  
 4948 ?        Sl     1:10     26    21 628002 107632  2.6 /usr/bin/kontact  
 4948 ?        Sl     1:11     26    21 628354 107948  2.6 /usr/bin/kontact  
 4948 ?        Rl     1:33     26    21 638838 118140  2.9 /usr/bin/kontact  
 4948 ?        Sl     1:54     26    21 646318 125892  3.1 /usr/bin/kontact  
 4948 ?        Sl     2:09     26    21 651374 131024  3.2 /usr/bin/kontact  
 4948 ?        Sl     2:10     26    21 651606 131280  3.2 /usr/bin/kontact  
 4948 ?        Rl     2:11     26    21 651830 131484  3.2 /usr/bin/kontact  
 4948 ?        Rl     2:12     26    21 652082 131712  3.2 /usr/bin/kontact
Comment 10 Thomas McGuire 2009-05-20 12:04:14 UTC
I have the same problem, if I have time in the next weeks I'll try to look at it. Not sure how to reproduce, happens after migration for me, when I select an item in akonadiconsole.
Comment 11 Peter Nixon 2009-05-21 22:28:58 UTC
I can confirm that I see this bug also. I would like to thank krop on #kontact who provided the following proceedure to allow me to continue using my email until this gets fixed:
Type "akonadictl stop" then go to "KDE System Settings/Advanced/KDE Resources", select Calendar from the dropdown and unselect (disable) the "Birthdays resource"
Comment 12 Bernd Paysan 2009-05-22 18:38:48 UTC
I see the same problem with KDE 4.2.3 (OpenSuSE build service).
Comment 13 Volker Krause 2009-05-23 17:26:38 UTC
SVN commit 971894 by vkrause:

Revert revision 965717 for now. Adding the default serializer plugin to
the map of known plugins caused it to be found sometimes even if there
was a more specific plugin which didn't match the requested mimetype
exactly. This especially affected items with KCal payloads and mimetypes
application/x-vnd.akonadi.*, such as those created by the iCal file
resource.

This still needs a real fix, as the problem is not limited to the
default serializer, but for now it should cover all relevant cases.

BUG: 193249


 M  +2 -1      itemserializer.cpp  


WebSVN link: http://websvn.kde.org/?view=rev&revision=971894
Comment 14 Christophe Marin 2009-05-27 00:20:59 UTC
*** Bug 194238 has been marked as a duplicate of this bug. ***