Akonadi errors with GMail account

[Daniel Vrátil]

Hi,

answers inline.

On Thursday, 3 January 2019 11:03:38 CET Szőts Ákos wrote:
> Hi,
> 
> Please, see the answers inline.
> 
> Daniel Vrátil a következőt írtad ekkor: 2018. december 21., péntek 0:29
> 
> > > > > - I can only refresh a folder only once until “akonadictl restart”
> > > > 
> > > > Sounds like something gets stuck in the IMAP resource, probably the
> > > > internal task scheduler. When you refresh a folder, open Akonadi
> > > > Console,
> > > > right-click the IMAP resource and select "Show task list". What tasks
> > > > does
> > > > it list?
> > > > 
> > > > > - Some mails I cannot move to another folder failing with a dialogue
> > > > > stating
> > > > 
> > > > this ("cannot move item" or "Unable to execute query")
> > > > 
> > > > Hmm, weird  Any logs from Akonadi Server that coincide with you
> > > > triggering
> > > > this event?
> > > 
> > > I enabled logging on the “Logging” tab but I cannot choose anything from
> > > the “Programs:” drop-down and it’s not writable. And (perhaps without
> > > that) no logs appear.The other tabs give so much information that I
> > > don’t
> > > know how to filter them to consider only the useful messages.
> > 
> > The comboboxes should populate automatically as processes started
> > producing
> > log messages. Weird that it doesn't happen for you. Can you make sure that
> > in kdebusettings utility the Akonadi and other logging categories with
> > "PIM" in the name are enabled?
> 
> It must be an unfortunate typo but I cannot figure out what is the correct
> utility to run to enable the logging. It's not that important now that I
> have Akonadi compiled from sources but still curious :).

Sorry, it's called kdebugsettings

Alternatively, just export the following env variable:

QT_LOGGING_RULES="*=true;qt.*=false"

This enables all logging except for Qt itself (which is very noisy and not 
that useful in this case). You may end up selectively disabling some more 
noisy KDE categories.

> 
> > > > > The errors are from console (from about a 30-minute run):
> > > > > - org.kde.pim.akonadicore: Error during ItemSync:  "Multiple merge
> > > > > candidates, aborting"
> > > > 
> > > > This one  has been haunting us for a long time. No fix yet, I haven't
> > > > observer a reliable way to get a folder into this inconsistent state.
> > > 
> > > How can I determine which e-mails are causing this? I suspect there is a
> > > connection with mails containing multiple labels but I cannot confirm it
> > > yet. But if I could find out which letter we talking about I could
> > > perhaps
> > > create a test case.
> > 
> > If you ran Akonadi from terminal (run "akonadictl restart"), when this
> > happens you should see a message like "Multiple merge candidates:" with a
> > list of the duplicated entries.
> 
> During resyncing all mails it happened to me three times so far.
> I’ll share the link to the mails (with full headers) in the first two cases
> privately but feel free to draw any conclusions on the list (I just want to
> hide the very details).
> 
> ID: 351505 , RID: "178497" , GID: "" , Collection: "Todos" ( 95 )
> ID: 351534 , RID: "178497" , GID: "" , Collection: "Todos" ( 95 )
> 
> ID: 351845 , RID: "2274" , GID: "" , Collection: "Értesítések" ( 101 )
> ID: 351903 , RID: "2274" , GID: "" , Collection: "Értesítések" ( 101 )
> 
> ID: 352206 , RID: "15080" , GID: "" , Collection: "MorroHun" ( 92 )
> ID: 352675 , RID: "15080" , GID: "" , Collection: "MorroHun" ( 92 )


One interesting thing is that in all those cases the GID is empty. GID is 
generated from Message-ID header. The fact that it is missing everywhere is 
suspicious. Still, the IMAP resource performs only RID-based merging, so it 
should not have any effect on the merging.

> The first case is the textbook case. They are two identical mails with the
> same size but they cannot be merged. They have the same MessageID. The mail
> is part of a conversation, archived, and has no label attached to it.

I'm clueless...does that mean that we've seen the same message twice? But why 
didn't the RID merging handle it then? 


> The second case is a bit more interesting. Both the sizes and even the
> number of parts differ in this case and the two letters are not the same.
> However, the same script generated them (so they came from the same sender
> on the same machine) with 45 minutes difference. In GMail they are assigned
> the same labels automatically along with the same category (notifications).
> Both e-mails are read by me.
> They are archived and have only one label attached to them.
> 
> The third case is the most strange for me. In this case the first message
> seems empty (zero data sizes except a row with “version=2” in parttable),
> but the second message is a full message. If you want, I can upload its
> headers.
> 
> If you can draw any conclusions from the data above or have any idea where
> to go next, I’d gladly continue the bug hunting.

Hmmmmmmmmmmmm, I wonder if the culprit could be that we don't scan the folder 
atomatically - we get the folder metadata and then we ask for it's content in 
batches...if something changes in the folder in the mean time it could mess up 
the sync.

We should probably just do a single super-fast listing of all UIDs in the 
folder and then constraint the rest of the sync to those UIDs so that any 
potential changes in the folder don't affect us (except for an email being 
deleted, but that's easy to handle).

We need to do this anyway for the proper Gmail sync support, so I should 
probably try to look into it soon.

> 
> If you think it’s of interest, I can describe how I manage labels in my
> GMail account.
> 

<snip>
> > 
> > Should be in ~/.local/share/akonadi/file_lost+found.
> 
> Strange that the directory doesn’t exist. I had to re-run fsck again and it
> said that it "Moved 300260 unreferenced files to lost+found.” But the
> directory must be somewhere else or it didn’t create it.

Could be related to https://phabricator.kde.org/D17879

> 
> > > > > - org.kde.pim.akonadiserver: Protocol exception: Failed to write
> > > > > data
> > > > > to
> > > > 
> > > > stream
> > > > 
> > > > > -org.kde.pim.akonadicontrol: ProcessControl: Application "/usr/bin/
> > > > 
> > > > akonadi_imap_resource" stopped unexpectedly ( “The process has
> > > > crashed”
> > > > )
> > > > 
> > > > > - org.kde.pim.akonadicontrol: Application
> > > > > '/usr/bin/akonadi_imap_resource'
> > > > > crashed. No restart!
> > > > 
> > > > The protocol exception is probably caused by the resource crashing and
> > > > suddenly disconnecting from the Akonadi Server. You should see DrKonqi
> > > > popping up when it crashes. Could you get a backtrace?
> > > 
> > > I happens when I stop Akonadi and probably when a folder sync is in
> > > progress. I could not reproduce it in idle state.
> > > 
> > > It turns out it’s hard to get a backtrace from it because after a crash
> > > GDB
> > > tell me “no such process” when I try to print it but once I succeeded.
> > > Here
> > > is the full one from akonadi_imap_resource:
> > > https://paste.opensuse.org/view/simple/1567434
> > 
> > Hmmm, looks like something goes awry during the shutdown. This should also
> > be solved by my new AgentBase code.
> 
> Since I have master now I can test your patches. I also saw some random
> crashes during akonadi shutdown but I don’t know if your patches already
> landed.

Not yet. It's a rather big change that I hoped to write over the Christmas but 
did not really manage to do it. No telling when I get around to finish it now 
:/

> 
> > > > > - !org.kde.pim.imapresource: Called item() while state holds
> > > > > multiple
> > > > > items!
> > > > 
<snip>
> 
> I could reproduce it: when Akonadi was syncing my whole [All mail] folder I
> was moving some mails to an other folder when this struck.
> 
> I copy a short backtrace for future reference here but I put the full one
> here: https://paste.opensuse.org/view/simple/24060361
> 
> I’ve also created a core dump. I don’t know exactly how much personal
> information it contains but if you need I can share it with you privately.
> 
> The short backtrace for archiving:
> 
> #0  0x000000000042bcbc in ResourceState::item() const (this=0x169fd30) at /
> home/aki/Programok/kde/src/kde/pim/kdepim-runtime/resources/imap/
> resourcestate.cpp:118
> #1  0x00000000004535fe in ResourceTask::item() const (this=<optimized out>)
> at /usr/include/qt5/QtCore/qsharedpointer_impl.h:312
> #2  0x000000000044af79 in MoveItemsTask::doStart(KIMAP::Session*)
> (this=0x169fdd0, session=0x1607200) at /home/aki/Programok/kde/src/kde/pim/
> kdepim-runtime/resources/imap/moveitemstask.cpp:52
<snip>

Nice, thanks a lot. Looks like it's just a simple sanity check calling item() 
instead of items(), so nothing serious. I'll push a fix for it soon.

> 
> I also noticed a Qt error message during Akonadi shutdown while the [All
> Mails] folder was syncing:
> 
> Qt has caught an exception thrown from an event handler. Throwing
> exceptions from an event handler is not supported in Qt.
> You must not let any exception whatsoever propagate through Qt code.
> If that is not possible, in Qt 5 you must at least reimplement
> QCoreApplication::notify() and catch all exceptions there

Yeah, this is an exception thrown from the Protocol stream code at an 
unexpected time during shutdown - the handler is waiting for more data to 
arrive when we close the socket which ends up firing an exception.

I need to clean up the error handling at some point...:)


Cheers,
Dan

> 
> Thank you and all the best,
> 
> Ákos


-- 
Daniel Vrátil
www.dvratil.cz | dvratil at kde.org
IRC: dvratil on Freenode (#kde, #kontact, #akonadi, #fedora-kde)

GPG Key: 0x4D69557AECB13683
Fingerprint: 0ABD FA55 A4E6 BEA9 9A83 EA97 4D69 557A ECB1 3683
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: This is a digitally signed message part.
URL: <http://mail.kde.org/pipermail/kde-pim/attachments/20190107/4a197a8b/attachment.sig>