Mail check often hangs until restart

[bugzy]

Often the mail check on my exchange accounts hang, and sometimes cause at crash. The following information is what I have been able to gather from akonadi logs (not sure it it will help at all):

AKONADI LOG:
Connecting to deprecated signal QDBusConnectionInterface::serviceOwnerChanged(QString,QString,QString)Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot pause an inactive timerCannot pause an inactive timerCannot pause an inactive timerCannot pause an inactive timer"Cannot connect to agent instance with identifier 'akonadi_ews_resource_1', error message: ''"ItemRetrieverException : Unable to contact resourceCannot pause an inactive timerCannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.Cannot resume a timer that is not paused.invalid query "{\n "cond": 0,\n "key": "",\n "limit": -1,\n "negated": false,\n "value": null\n}\n"invalid query "{\n "cond": 0,\n "key": "",\n "limit": -1,\n "negated": false,\n "value": null\n}\n"

KDE CRASH REPORTER:
Application: akonadi_ews_resource (akonadi_ews_resource), signal: Segmentation fault
Using host libthread_db library "/lib64/libthread_db.so.1".
[Current thread is 1 (Thread 0x7fe7c1997f00 (LWP 12378))]

Thread 6 (Thread 0x7fe7a747d700 (LWP 12408)):
#0 0x00007fe7c80981e7 in g_source_iter_next () from /lib64/libglib-2.0.so.0
#1 0x00007fe7c809a63b in g_main_context_prepare () from /lib64/libglib-2.0.so.0
#2 0x00007fe7c809b07b in g_main_context_iterate.isra () from /lib64/libglib-2.0.so.0
#3 0x00007fe7c809b26c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
#4 0x00007fe7d015d73b in QEventDispatcherGlib::processEvents(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#5 0x00007fe7d010e73a in QEventLoop::exec(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#6 0x00007fe7cff6b5f3 in QThread::exec() () from /lib64/libQt5Core.so.5
#7 0x00007fe7cff6f9da in QThreadPrivate::start(void*) () from /lib64/libQt5Core.so.5
#8 0x00007fe7cd63b6ca in start_thread () from /lib64/libpthread.so.0
#9 0x00007fe7cf362f7f in clone () from /lib64/libc.so.6

Thread 5 (Thread 0x7fe7b4b14700 (LWP 12391)):
#0 0x00007fe7cf352bed in read () from /lib64/libc.so.6
#1 0x00007fe7c80df450 in g_wakeup_acknowledge () from /lib64/libglib-2.0.so.0
#2 0x00007fe7c809ac60 in g_main_context_check () from /lib64/libglib-2.0.so.0
#3 0x00007fe7c809b0f4 in g_main_context_iterate.isra () from /lib64/libglib-2.0.so.0
#4 0x00007fe7c809b26c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
#5 0x00007fe7d015d73b in QEventDispatcherGlib::processEvents(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#6 0x00007fe7d010e73a in QEventLoop::exec(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#7 0x00007fe7cff6b5f3 in QThread::exec() () from /lib64/libQt5Core.so.5
#8 0x00007fe7cff6f9da in QThreadPrivate::start(void*) () from /lib64/libQt5Core.so.5
#9 0x00007fe7cd63b6ca in start_thread () from /lib64/libpthread.so.0
#10 0x00007fe7cf362f7f in clone () from /lib64/libc.so.6

Thread 4 (Thread 0x7fe7b5315700 (LWP 12389)):
#0 0x00007fe7cf35701d in poll () from /lib64/libc.so.6
#1 0x00007fe7c809b156 in g_main_context_iterate.isra () from /lib64/libglib-2.0.so.0
#2 0x00007fe7c809b26c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
#3 0x00007fe7d015d73b in QEventDispatcherGlib::processEvents(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#4 0x00007fe7d010e73a in QEventLoop::exec(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#5 0x00007fe7cff6b5f3 in QThread::exec() () from /lib64/libQt5Core.so.5
#6 0x00007fe7cff6f9da in QThreadPrivate::start(void*) () from /lib64/libQt5Core.so.5
#7 0x00007fe7cd63b6ca in start_thread () from /lib64/libpthread.so.0
#8 0x00007fe7cf362f7f in clone () from /lib64/libc.so.6

Thread 3 (Thread 0x7fe7b5b16700 (LWP 12388)):
#0 0x00007fe7cf35701d in poll () from /lib64/libc.so.6
#1 0x00007fe7c809b156 in g_main_context_iterate.isra () from /lib64/libglib-2.0.so.0
#2 0x00007fe7c809b26c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
#3 0x00007fe7d015d73b in QEventDispatcherGlib::processEvents(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#4 0x00007fe7d010e73a in QEventLoop::exec(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#5 0x00007fe7cff6b5f3 in QThread::exec() () from /lib64/libQt5Core.so.5
#6 0x00007fe7d7329739 in QDBusConnectionManager::run() () from /lib64/libQt5DBus.so.5
#7 0x00007fe7cff6f9da in QThreadPrivate::start(void*) () from /lib64/libQt5Core.so.5
#8 0x00007fe7cd63b6ca in start_thread () from /lib64/libpthread.so.0
#9 0x00007fe7cf362f7f in clone () from /lib64/libc.so.6

Thread 2 (Thread 0x7fe7b6e97700 (LWP 12386)):
#0 0x00007fe7cf35701d in poll () from /lib64/libc.so.6
#1 0x00007fe7cbe64d10 in _xcb_conn_wait () from /lib64/libxcb.so.1
#2 0x00007fe7cbe66aa9 in xcb_wait_for_event () from /lib64/libxcb.so.1
#3 0x00007fe7bad07d69 in QXcbEventReader::run() () from /lib64/libQt5XcbQpa.so.5
#4 0x00007fe7cff6f9da in QThreadPrivate::start(void*) () from /lib64/libQt5Core.so.5
#5 0x00007fe7cd63b6ca in start_thread () from /lib64/libpthread.so.0
#6 0x00007fe7cf362f7f in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x7fe7c1997f00 (LWP 12378)):
[KCrash Handler]
#6 0x000055dfaf9053e9 in QString::QString (other=..., this=0x7ffffabb4080) at /usr/include/qt5/QtCore/qstring.h:898
#7 EwsRequest::Response::responseCode (this=0x55df80000000) at /usr/src/debug/akonadi-ews-0.8.1/ewsclient/ewsrequest.h:46
#8 EwsSubscriptionManager::getEventsRequestFinished (this=0x55dfb18e8590, job=0x55dfb1917dc0) at /usr/src/debug/akonadi-ews-0.8.1/ewssubscriptionmanager.cpp:205
#9 0x00007fe7d0136ae6 in QMetaObject::activate(QObject*, int, int, void**) () from /lib64/libQt5Core.so.5
#10 0x00007fe7d05c98f2 in KJob::result(KJob*, KJob::QPrivateSignal) () from /lib64/libKF5CoreAddons.so.5
#11 0x00007fe7d05cb231 in KJob::finishJob(bool) () from /lib64/libKF5CoreAddons.so.5
#12 0x000055dfaf92306f in EwsGetStreamingEventsRequest::requestDataTimeout (this=0x55dfb1917dc0) at /usr/src/debug/akonadi-ews-0.8.1/ewsclient/ewsgetstreamingeventsrequest.cpp:107
#13 0x00007fe7d0136ae6 in QMetaObject::activate(QObject*, int, int, void**) () from /lib64/libQt5Core.so.5
#14 0x00007fe7d0142c98 in QTimer::timerEvent(QTimerEvent*) () from /lib64/libQt5Core.so.5
#15 0x00007fe7d013782b in QObject::event(QEvent*) () from /lib64/libQt5Core.so.5
#16 0x00007fe7d1023ecc in QApplicationPrivate::notify_helper(QObject*, QEvent*) () from /lib64/libQt5Widgets.so.5
#17 0x00007fe7d102b671 in QApplication::notify(QObject*, QEvent*) () from /lib64/libQt5Widgets.so.5
#18 0x00007fe7d010f7aa in QCoreApplication::notifyInternal2(QObject*, QEvent*) () from /lib64/libQt5Core.so.5
#19 0x00007fe7d015cd3b in QTimerInfoList::activateTimers() () from /lib64/libQt5Core.so.5
#20 0x00007fe7d015d291 in timerSourceDispatch(_GSource*, int ()(void), void*) () from /lib64/libQt5Core.so.5
#21 0x00007fe7c809ae42 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0
#22 0x00007fe7c809b1c0 in g_main_context_iterate.isra () from /lib64/libglib-2.0.so.0
#23 0x00007fe7c809b26c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
#24 0x00007fe7d015d71f in QEventDispatcherGlib::processEvents(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#25 0x00007fe7d010e73a in QEventLoop::exec(QFlagsQEventLoop::ProcessEventsFlag) () from /lib64/libQt5Core.so.5
#26 0x00007fe7d011623c in QCoreApplication::exec() () from /lib64/libQt5Core.so.5
#27 0x00007fe7d7031aee in Akonadi::ResourceBase::init(Akonadi::ResourceBase*) () from /lib64/libKF5AkonadiAgentBase.so.5
#28 0x000055dfaf901527 in Akonadi::ResourceBase::init (argc=, argv=) at /usr/include/KF5/AkonadiAgentBase/resourcebase.h:196
#29 0x00007fe7cf27b401 in __libc_start_main () from /lib64/libc.so.6
#30 0x000055dfaf8ab7ca in _start ()

[michaelhofer]

I see similar issues. Which logs do you need to have a look at this?

[KrissN]

I have seen such behaviour occasionally. I am not sure, but I have the feeling it started happening after upgrading to KDE Applications 16.12. I have checked the logs, but it looked like akonadi-ews was idle and was not receiving new requests from the Akonadi server. I'll have to investigate further when I have some time.

As for the crash - this is a known bug in 0.8.1 which has already been fixed in master.

[KrissN]

I'm not sure if it was related but I have found and fixed a bug in akonadi core (https://phabricator.kde.org/D8133).

The problem was that when an item retrieval failed on Exchange side the EWS resource would call the cancelTask() method to tell Akonadi, that the retrieval failed. Unfortunately when Akonadi ported from single item retrieval (ResourceBase::retrieveItem) in 16.08 to multi-item retrieval (ResourceBase::retrieveItems) in 16.12 the cancelTask() functionality wasn't ported correctly effectively becoming a NOP. This caused the state machine to break, as the resource would tell Akonadi about the error and consider the retrieval completed, but Akonadi wasn't receiving the cancellation causing it to keep waiting for the resource to finish.