[prev in list] [next in list] [prev in thread] [next in thread] 

List:       kde-bugs-dist
Subject:    [Akonadi] [Bug 343114] New: gets stuck on one request that times out, kmail and akonadiconsole do no
From:       Martin Steigerwald <ms () teamix ! de>
Date:       2015-01-21 12:25:33
Message-ID: bug-343114-17878 () http ! bugs ! kde ! org/
[Download RAW message or body]

https://bugs.kde.org/show_bug.cgi?id=343114

            Bug ID: 343114
           Summary: gets stuck on one request that times out, kmail and
                    akonadiconsole do not display any mail payloads
                    anymore, stuck waiting
           Product: Akonadi
           Version: 1.13.0
          Platform: Debian unstable
                OS: Linux
            Status: UNCONFIRMED
          Severity: major
          Priority: NOR
         Component: IMAP resource
          Assignee: chrigi_1@fastmail.fm
          Reporter: ms@teamix.de
                CC: kdepim-bugs@kde.org, vkrause@kde.org

In order to find out about why KMail sometimes seems to loose Akonadi I tried
what Dan suggested in:

http://lists.kde.org/?l=kde-pim&m=141501040507170&w=2

Re: [Kde-pim] KMail seems to loose connection to Akonadi at times

I did it for my work setup. Where I use a huge IMAP account hosted by Exchange.
Exchange seems to not reply in time on some requests or even drop connections,
but I ´d expect an IMAP client to recover from that condition. I recently
switched the account to "download all messages for offline use" after finding
out it Akonadi caches about 7 GiB of in in file_db_data anyway (see bug
#338402).



Reproducible: Sometimes

Steps to Reproduce:
It just happens after a while. I started KMail as follows for the debugging Dan
suggested:

ms@merkaba:~> export AKONADI_SESSION_LOGFILE=/var/tmp/akonadi.log
ms@merkaba:~> akonadictl stop
Akonadi is not running. 
ms@merkaba:~#4> ps aux | grep mysql
martin   23674  2.7  3.4 2766408 566452 ?      Sl   Jan20  19:55
/usr/sbin/mysqld --defaults-file=/home/martin/.local/share/akonadi/mysql.conf
--datadir=/home/martin/.local/share/akonadi/db_data/
--socket=/tmp/akonadi-martin.eQY0MM/mysql.socket
ms       27067  9.9  0.7 2297324 124212 ?      Sl   09:18  15:09
/usr/sbin/mysqld --defaults-file=/home/ms/.local/share/akonadi/mysql.conf
--datadir=/home/ms/.local/share/akonadi/db_data/
--socket=/tmp/akonadi-ms.g6IkT6/mysql.socket
ms       31987  0.0  0.0  12676  1684 pts/24   S+   11:49   0:00 grep mysql
ms@merkaba:~> kill 27067
ms@merkaba:~> kill 27067
ms@merkaba:~> kill 27067
ms@merkaba:~> kill 27067
ms@merkaba:~> kill 27067
ms@merkaba:~> kill 27067
kill: kill 27067 failed: kein passender Prozess gefunden
ms@merkaba:~#1> kmail

Actual Results:  
I get this on console output:




ms@merkaba:~> kmail2(31990)
MessageList::Core::ModelPrivate::viewItemJobStepInternalForJobPass1Fill:
Circular In-Reply-To reference loop detected in the message tree 
kmail2(31990) MessageList::Core::ModelPrivate::findMessageParent: Circular
In-Reply-To reference loop detected in the message tree



ms@merkaba:~> continuing 
request for item 1669405 "902" failed: "Unable to retrieve item from resource:
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." 
ItemRetrieverException :  Unable to retrieve item from resource: 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.
posting retrieval request for item 1669405  there are  1  queues and  0  items
in mine 
request for item 1669405 still pending - waiting 
processing retrieval request for item 1669405  parts: ("RFC822")  of resource:
"akonadi_imap_resource_0" 


ms@merkaba:~> continuing 
request for item 1669405 "902" failed: "Unable to retrieve item from resource:
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." 
ItemRetrieverException :  Unable to retrieve item from resource: 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.
posting retrieval request for item 1668979  there are  1  queues and  0  items
in mine 
request for item 1668979 still pending - waiting 
processing retrieval request for item 1668979  parts: ("RFC822")  of resource:
"akonadi_imap_resource_0"


It goes on like this. KMail even displays it in the status line at the bottom
of the window. In KMail I see:

- It won ´t display a single mail anymore. If just displays the blue background
loading contents of current folder message instead of the mail.

- Folder switching still works.

- KMail often shows "Synchronizing folder ext4-ml" with 97% and gets stuck
there. Its always 97%.


Expected Results:  
Expected results:

- Akonadi IMAP resource gives up on the time out IMAP request after some time.
That said, I don ´t understand why it doesn ´t succeed after some times, Exchange
isn ´t that unresponsive either. I may drop a connection, but re-requesting it
should eventually give a result.

- KMail would at least locally stored mails for offline usage if it can ´t get a
response from the IMAP server in time.

- KMail would display other mails stored on the IMAP server, which means that
Akonadi IMAP wouldn ´t block further IMAP requests, just cause one of them times
out. I.e. it would process some amount of requests in parallel.

I have KMail stuck here now and asked on #akonadi on freenode about which parts
of the Akonadi session log would be required for further diagnosing of the
issue. I certainly won ´t upload it all as it contains a ton of confidential
information including folder names but also *complete* mails.

At least according to

tail -f akonadi.log.32040.akonadi_imap_resource_0

There does not seem more data after:

ms@merkaba:/var/tmp> tail -f akonadi.log.32040.akonadi_imap_resource_0
S: 1472987 FETCH (UID 1472987 REV 0 REMOTEID "59" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4079 FLAGS ())
S: 1472986 FETCH (UID 1472986 REV 0 REMOTEID "58" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4389 FLAGS ())
S: 1472985 FETCH (UID 1472985 REV 0 REMOTEID "57" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4407 FLAGS ())
S: 1472984 FETCH (UID 1472984 REV 0 REMOTEID "56" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4200 FLAGS ())
S: 1472983 FETCH (UID 1472983 REV 0 REMOTEID "55" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4000 FLAGS ())
S: 1472982 FETCH (UID 1472982 REV 0 REMOTEID "54" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4025 FLAGS ())
S: 1472981 FETCH (UID 1472981 REV 0 REMOTEID "53" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4001 FLAGS ())
S: 1472980 FETCH (UID 1472980 REV 0 REMOTEID "52" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 3988 FLAGS ())
S: 1472979 FETCH (UID 1472979 REV 0 REMOTEID "51" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 3982 FLAGS ())
S: 1472978 FETCH (UID 1472978 REV 0 REMOTEID "50" MIMETYPE "message/rfc822"
COLLECTIONID 356 SIZE 4734 FLAGS ())


Also Akonadiconsole is not able to retrieve any payloads anymore. Lets see what
I can enable there:

Okay, in the job tracker I see "UID FETCH" some number. One running, rest is
waiting.

Akonadi IMAP resource in resource tracker is waiting on FetchItem.

When I click mails in KMail I also see "UID FETCH" as watiing in job tracker.

Well to me it seems Akonadi IMAP resource is stuck.

I am using Akonadi git with MySQL optimization, and Akonadi IMAP resource from
4.14.2 debian packages.

The IMAP resource also doesn ´t respond to a "Restart" or "Abort" request in
Akonadiconsole.


the Akonadi IMAP resource really seems stuck and Akonadi may serve the folder
switching from metadata in the MySQL database instead.

Okay, I will end this.

I will xz the logs:

ms@merkaba:/var/tmp> du -sh akonadi* | sort -rh | head -10
102M    akonadi.log.31990.KMail Kernel ETM
27M     akonadi.log.32040.akonadi_imap_resource_0
1,7M    akonadi.log.32036.akonadi_baloo_indexer
724K    akonadi.log.31990.kmail2-1339195199
168K    akonadi.log.32046.MailFilter Kernel ETM
168K    akonadi.log.32035.Archive Mail Kernel ETM
124K    akonadi.log.32046.akonadi_mailfilter_agent
56K     akonadi.log.32041.akonadi_imap_resource_1
24K     akonadi.log.32048.akonadi_newmailnotifier_agent
20K     akonadi.log.32049.KNotes Session

But as said, tell me what you need, I won ´t send it all due to confidentiality
issues.

tail -f "akonadi.log.31990.KMail Kernel ETM" also does not give any more
results. Seems all stuck. Last in there is:

S: 1667763 FETCH (UID 1667763 REV 0 MIMETYPE "message/rfc822" COLLECTIONID 415
SIZE 4651 FLAGS (\SEEN) ANCESTORS ((415 "/basket-devel-ml") (296 "/KDE") (276
"imap://[…]") (0 "")) PLD:ENVELOPE[1] {235}
("Sat, 26 Oct 2013 22:12:18 +0200" "[Basket-devel] Non-ASCII text storage\r"
(("Some name" NIL "some mail user name" "some domain")) NIL NIL ((NIL NIL
"basket-devel" "lists.sourceforge.net")) NIL NIL NIL
"<526C2222.1070603@gmail.com>" NIL))
S: OK FETCH completed
C: 120 FETCH 1:* COLLECTIONID 411  IGNOREERRORS ANCESTORS INF EXTERNALPAYLOAD
(UID COLLECTIONID FLAGS SIZE TAGS PLD:ENVELOPE ATR:entityannotations)

Even if I click mails in KMail, nothing more comes. Actually I am in the basket
folder now. So this may be the last it got.

Okay, interesting, when I switch folders in KMail I get somemore. Okay for
switching folders I get more output there. But not more in
"akonadi.log.32040.akonadi_imap_resource_0".

Okay, and now, after more of half an hour digging into thinks I got a kwallet
requester asking for my IMAP password again. But I didn ´t close the KDE session
or lock the screen. And the progress bar in KMail with Synchronizing ext4-ml at
97% disappeared.

Still I keep getting these:

ms@merkaba:~> continuing 
request for item 2039976 "6" failed: "Unable to retrieve item from resource:
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." 
ItemRetrieverException :  Unable to retrieve item from resource: 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.
processing retrieval request for item 1363436  parts: ("RFC822")  of resource:
"akonadi_imap_resource_0" 
continuing 
request for item 1363436 still pending - waiting 
continuing 
request for item 2520302 still pending - waiting 
posting retrieval request for item 2039977  there are  1  queues and  1  items
in mine 
request for item 2039977 still pending - waiting 

ms@merkaba:~>  list is empty 
continuing 
request for item 1363436 "9" failed: "Unable to retrieve item from resource:
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." 
processing retrieval request for item 2520302  parts: ("RFC822")  of resource:
"akonadi_imap_resource_0" 
ItemRetrieverException :  Unable to retrieve item from resource: 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.
continuing 
request for item 2520302 still pending - waiting 
continuing 
request for item 2039977 still pending - waiting 
posting retrieval request for item 1363439  there are  1  queues and  1  items
in mine 
request for item 1363439 still pending - waiting 
kmail2(31990) MessageList::Core::ModelPrivate::findMessageParent: Circular
reference loop detected in the message tree 
processing retrieval request for item 2039977  parts: ("RFC822")  of resource:
"akonadi_imap_resource_0" 
continuing 
continuing 
request for item 2520302 "49727" failed: "Unable to retrieve item from
resource: <html>Der Auftrag wurde abgebrochen</html>" 
continuing 
request for item 1363439 still pending - waiting 
request for item 2039977 still pending - waiting 
ItemRetrieverException :  Unable to retrieve item from resource: <html>Der
Auftrag wurde abgebrochen</html>
posting retrieval request for item 2520302  there are  1  queues and  1  items
in mine 
request for item 2520302 still pending - waiting 
kmail2(31990)
MessageList::Core::ModelPrivate::viewItemJobStepInternalForJobPass1Fill:
Circular In-Reply-To reference loop detected in the message tree 
kmail2(31990) MessageList::Core::ModelPrivate::findMessageParent: Circular
In-Reply-To reference loop detected in the message tree

-- 
You are receiving this mail because:
You are watching all bug changes.=
[prev in list] [next in list] [prev in thread] [next in thread]