Akonadi errors with GMail account

Thu Jan 3 10:03:38 GMT 2019

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 :).

> > > > 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 )

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.

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. 

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

> > > > - org.kde.pim.akonadiprivate: Error: failed to remove part file
> > > > “/home/
> > > 
> > > aki/.local/share/akonadi/file_db_data/79/1051679_r0” [with 100+
> > > 
> > > > different files, access rights are ok]
> > > 
> > > Do the files actually exist? I wonder if this is because when the
> > > payload
> > > is supposed to be expired from the cache it's removed the disk, but the
> > > SQL query to update the database fails, leading to this inconsistency.
> > > 
> > > Anyway, runing "akonadictl fsck" should fix these problems.
> > 
> > Yes, those files existed. Ran fsck (thank you for the tip) and it moved
> > around 100 000 files into lost+found. I don’t know where lost+found is
> > located (it’s not in ~/.local/share according to find) but anyhow, it
> > fixed
> > those errors.
> 
> 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.

> > > > - 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.

> > > > - !org.kde.pim.imapresource: Called item() while state holds multiple
> > > > items!
> > > 
> > > I see this occasionally too, it's hard to reproduce and I have no clue
> > > where the call is happening from. Attaching GDB to the Resource and
> > > setting a breakpoint to the line that prints this message might help. If
> > > you are able to do it yourself it would be awesome.
> > 
> > Sure thing. Could you please tell me where can I find this line? I looked
> > in https://github.com/KDE but it seems the sentence string is not
> > anywhere in KDE hosted repos.
> 
> The code lives in kdepim-runtime repository, namely this message is in
> ResourceState::item() method in resources/imap/resourcestate.cpp - attaching
> GDB to the IMAP resource and setting a breakpoint at the method should do
> the trick, although unless you can reproduce this reliably, you will
> probably get a tons of false positives. Figuring out on which line the
> message exactly is in the file (depends on which exact version you have)
> and setting the breakpoint there should do the trick.

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
#3  0x0000000000453343 in ResourceTask::onSessionRequested(long long, 
KIMAP::Session*, int, QString const&) (this=0x169fdd0, requestId=<optimized 
out>, session=<optimized out>, errorCode=0, errorString=...) at /home/aki/
Programok/kde/src/kde/pim/kdepim-runtime/resources/imap/resourcetask.cpp:121
#4  0x00007fb78a515200 in QtPrivate::QSlotObjectBase::call(QObject*, void**) 
(a=0x7ffddae0ea80, r=0x169fdd0, this=0x169fa90) at ../../include/QtCore/../../
src/corelib/kernel/qobjectdefs_impl.h:394
#5  0x00007fb78a515200 in QMetaObject::activate(QObject*, int, int, void**) 
(sender=0x1521aa0, signalOffset=<optimized out>, local_signal_index=<optimized 
out>, argv=<optimized out>) at kernel/qobject.cpp:3759
#6  0x0000000000481984 in SessionPool::sessionRequestDone(long long, 
KIMAP::Session*, int, QString const&) (this=this at entry=0x1521aa0, 
_t1=<optimized out>, _t1 at entry=15, _t2=<optimized out>, _t2 at entry=0x1607200, 
_t3=<optimized out>, _t3 at entry=0, _t4=...) at /home/aki/Programok/kde/build/
kde/pim/kdepim-runtime/resources/imap/imapresource_autogen/EWIEGA46WW/
moc_sessionpool.cpp:294
#7  0x000000000046de6d in SessionPool::processPendingRequests() 
(this=0x1521aa0) at /usr/include/qt5/QtCore/qlist.h:235
#8  0x00007fb78a520ea6 in QtPrivate::QSlotObjectBase::call(QObject*, void**) 
(a=0x7ffddae0eb10, r=<optimized out>, this=<optimized out>) at ../../include/
QtCore/../../src/corelib/kernel/qobjectdefs_impl.h:394
#9  0x00007fb78a520ea6 in QSingleShotTimer::timerEvent(QTimerEvent*) 
(this=0x16b4360) at kernel/qtimer.cpp:318
#10 0x00007fb78a51591b in QObject::event(QEvent*) (this=0x16b4360, 
e=<optimized out>) at kernel/qobject.cpp:1230
#11 0x00007fb78b099591 in QApplicationPrivate::notify_helper(QObject*, 
QEvent*) (this=this at entry=0x10a0f70, receiver=receiver at entry=0x16b4360, 
e=e at entry=0x7ffddae0ee30) at kernel/qapplication.cpp:3753
#12 0x00007fb78b0a0b50 in QApplication::notify(QObject*, QEvent*) 
(this=0x7ffddae0f130, receiver=0x16b4360, e=0x7ffddae0ee30) at kernel/
qapplication.cpp:3500
#13 0x00007fb78a4eb359 in QCoreApplication::notifyInternal2(QObject*, QEvent*) 
(receiver=0x16b4360, event=0x7ffddae0ee30) at ../../include/QtCore/5.12.0/
QtCore/private/../../../../../src/corelib/thread/qthread_p.h:322
#14 0x00007fb78a53ec83 in QTimerInfoList::activateTimers() (this=0x1155b00) at 
kernel/qtimerinfo_unix.cpp:643
#15 0x00007fb78a53f50c in timerSourceDispatch (source=<optimized out>) at 
kernel/qeventdispatcher_glib.cpp:182
#16 0x00007fb78a53f50c in idleTimerSourceDispatch(GSource*, GSourceFunc, 
gpointer) (source=<optimized out>) at kernel/qeventdispatcher_glib.cpp:229
#17 0x00007fb77f46cc15 in g_main_dispatch (context=0x7fb770004ff0) at gmain.c:
3182
#18 0x00007fb77f46cc15 in g_main_context_dispatch 
(context=context at entry=0x7fb770004ff0) at gmain.c:3847
#19 0x00007fb77f46cfd8 in g_main_context_iterate 
(context=context at entry=0x7fb770004ff0, block=block at entry=1, 
dispatch=dispatch at entry=1, self=<optimized out>) at gmain.c:3920
#20 0x00007fb77f46d06c in g_main_context_iteration (context=0x7fb770004ff0, 
may_block=may_block at entry=1) at gmain.c:3981
#21 0x00007fb78a53f873 in 
QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) 
(this=0x116cb90, flags=...) at kernel/qeventdispatcher_glib.cpp:422
#22 0x00007fb78a4ea02b in 
QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) 
(this=this at entry=0x7ffddae0f090, flags=..., flags at entry=...) at ../../include/
QtCore/../../src/corelib/global/qflags.h:140
#23 0x00007fb78a4f2192 in QCoreApplication::exec() () at ../../include/
QtCore/../../src/corelib/global/qflags.h:120
#24 0x00007fb78aa86adc in QGuiApplication::exec() () at kernel/
qguiapplication.cpp:1779
#25 0x00007fb78b099505 in QApplication::exec() () at kernel/qapplication.cpp:
2910
#26 0x00007fb78c42d7be in Akonadi::ResourceBase::init(Akonadi::ResourceBase*) 
(r=r at entry=0x151c3b0) at /usr/include/qt5/QtCore/qcoreapplication.h:116
#27 0x000000000042a711 in Akonadi::ResourceBase::init<ImapResource>(int, 
char**) (argc=<optimized out>, argv=<optimized out>) at /home/aki/Programok/
kde/include/KF5/AkonadiAgentBase/resourcebase.h:181
#28 0x00007fb789994feb in __libc_start_main (main=0x42a5a0 <main(int, 
char**)>, argc=3, argv=0x7ffddae0f238, init=<optimized out>, fini=<optimized 
out>, rtld_fini=<optimized out>, stack_end=0x7ffddae0f228) at ../csu/libc-
start.c:308
#29 0x000000000042a5da in _start () at ../sysdeps/x86_64/start.S:120

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

Thank you and all the best,

Ákos
-------------- 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/20190103/ba1eb8d6/attachment.sig>