Bug 321093 - feeder crashed
Summary: feeder crashed
Status: RESOLVED FIXED
Alias: None
Product: Akonadi
Classification: Unclassified
Component: Nepomuk Feeder Agents (show other bugs)
Version: GIT (master)
Platform: Ubuntu Packages Linux
: NOR crash (vote)
Target Milestone: ---
Assignee: kdepim bugs
URL:
Keywords: drkonqi
Depends on:
Blocks:
 
Reported: 2013-06-13 09:09 UTC by Blackpaw
Modified: 2013-06-19 12:48 UTC (History)
3 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments
New crash information added by DrKonqi (5.02 KB, text/plain)
2013-06-16 01:59 UTC, Blackpaw
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Blackpaw 2013-06-13 09:09:04 UTC
Application: akonadi_nepomuk_feeder (4.10)
KDE Platform Version: 4.10.4
Qt Version: 4.8.4
Operating System: Linux 3.8.0-23-generic x86_64
Distribution: Ubuntu 13.04

-- Information about the crash:
- What I was doing when the application crashed:

Just letting the desktop sit after I restored it from hibernate. Indexer was still indexing the backlog of mails I have from it being disabled due to the (now fixed) assert() bug

Built from master:

shared-desktop-ontologies
nepomuk-core
nepomuk-widgets
nepomukcontroller-qml
libkgapi
kactivities
akonadi
kdepimlibs
kdepim-runtime
kdepim

-- Backtrace:
Application: Akonadi Nepomuk Feeder (akonadi_nepomuk_feeder), signal: Aborted
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[KCrash Handler]
#5  0x00007f0fd2ac6037 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#6  0x00007f0fd2ac9698 in abort () from /lib/x86_64-linux-gnu/libc.so.6
#7  0x00007f0fd4b1b5c2 in qt_message_output (msgType=msgType@entry=QtFatalMsg, buf=0x27442a8 "ASSERT: \"mRunningJobs == 0\" in file /home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/itemqueue.cpp, line 113") at global/qglobal.cpp:2347
#8  0x00007f0fd4b1b938 in qt_message(QtMsgType, const char *, typedef __va_list_tag __va_list_tag *) (msgType=msgType@entry=QtFatalMsg, msg=msg@entry=0x7f0fd4c85548 "ASSERT: \"%s\" in file %s, line %d", ap=ap@entry=0x7fff5ea33a48) at global/qglobal.cpp:2393
#9  0x00007f0fd4b1bac4 in qFatal (msg=msg@entry=0x7f0fd4c85548 "ASSERT: \"%s\" in file %s, line %d") at global/qglobal.cpp:2576
#10 0x00007f0fd4b1bb06 in qt_assert (assertion=assertion@entry=0x426554 "mRunningJobs == 0", file=file@entry=0x426330 "/home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/itemqueue.cpp", line=line@entry=113) at global/qglobal.cpp:2021
#11 0x00000000004167fa in ItemQueue::processBatch (this=this@entry=0x206acf8) at /home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/itemqueue.cpp:113
#12 0x00000000004129a0 in IndexScheduler::processItemQueue (this=this@entry=0x206abd0) at /home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/indexscheduler.cpp:252
#13 0x0000000000413408 in IndexScheduler::qt_static_metacall (_o=0x206abd0, _c=<optimized out>, _id=3, _a=0x7fff5ea33d50) at /home/lindsay/Projects/akonadi/kdepim-runtime/build/agents/nepomukfeeder/indexscheduler.moc:67
#14 0x00007f0fd4c370ef in QMetaObject::activate (sender=0x206abe8, m=<optimized out>, local_signal_index=<optimized out>, argv=0x0) at kernel/qobject.cpp:3539
#15 0x00007f0fd4c3c3ec in QObject::event (this=0x206abe8, e=<optimized out>) at kernel/qobject.cpp:1156
#16 0x00007f0fd353b8ec in QApplicationPrivate::notify_helper (this=this@entry=0x1ef4090, receiver=receiver@entry=0x206abe8, e=e@entry=0x7fff5ea34440) at kernel/qapplication.cpp:4567
#17 0x00007f0fd353e25b in QApplication::notify (this=0x7fff5ea34730, receiver=0x206abe8, e=0x7fff5ea34440) at kernel/qapplication.cpp:4428
#18 0x00007f0fd5ae2af6 in KApplication::notify(QObject*, QEvent*) () from /usr/lib/libkdeui.so.5
#19 0x00007f0fd4c2263e in QCoreApplication::notifyInternal (this=0x7fff5ea34730, receiver=0x206abe8, event=event@entry=0x7fff5ea34440) at kernel/qcoreapplication.cpp:946
#20 0x00007f0fd4c53b72 in sendEvent (event=0x7fff5ea34440, receiver=<optimized out>) at ../../include/QtCore/../../src/corelib/kernel/qcoreapplication.h:231
#21 QTimerInfoList::activateTimers (this=0x1eeb160) at kernel/qeventdispatcher_unix.cpp:622
#22 0x00007f0fd4c509a4 in timerSourceDispatch (source=<optimized out>) at kernel/qeventdispatcher_glib.cpp:186
#23 timerSourceDispatch (source=<optimized out>) at kernel/qeventdispatcher_glib.cpp:180
#24 0x00007f0fcf719f05 in g_main_context_dispatch () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#25 0x00007f0fcf71a248 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#26 0x00007f0fcf71a304 in g_main_context_iteration () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#27 0x00007f0fd4c51016 in QEventDispatcherGlib::processEvents (this=0x1eb77e0, flags=...) at kernel/qeventdispatcher_glib.cpp:424
#28 0x00007f0fd35e11ae in QGuiEventDispatcherGlib::processEvents (this=<optimized out>, flags=...) at kernel/qguieventdispatcher_glib.cpp:204
#29 0x00007f0fd4c2138f in QEventLoop::processEvents (this=this@entry=0x7fff5ea346b0, flags=...) at kernel/qeventloop.cpp:149
#30 0x00007f0fd4c21618 in QEventLoop::exec (this=this@entry=0x7fff5ea346b0, flags=...) at kernel/qeventloop.cpp:204
#31 0x00007f0fd4c26cf6 in QCoreApplication::exec () at kernel/qcoreapplication.cpp:1218
#32 0x00007f0fd3539ffc in QApplication::exec () at kernel/qapplication.cpp:3828
#33 0x00007f0fd5012765 in Akonadi::AgentBase::init (r=r@entry=0x206aba0) at /home/lindsay/Projects/akonadi/kdepimlibs/akonadi/agentbase.cpp:706
#34 0x000000000040fea8 in Akonadi::AgentBase::init<Akonadi::NepomukFeederAgent> (argc=<optimized out>, argv=<optimized out>) at /usr/include/akonadi/agentbase.h:407
#35 0x00007f0fd2ab0ea5 in __libc_start_main () from /lib/x86_64-linux-gnu/libc.so.6
#36 0x000000000040c4f1 in _start ()

Reported using DrKonqi
Comment 1 Blackpaw 2013-06-13 09:36:01 UTC
It repeated itself three times now since the original crash.
Comment 2 Blackpaw 2013-06-16 01:59:00 UTC
Created attachment 80544 [details]
New crash information added by DrKonqi

akonadi_nepomuk_feeder (4.10) on KDE Platform 4.10.4 using Qt 4.8.4

- What I was doing when the application crashed:

Same as before, letting the feeder index my mails. This happens 100% of time when I reactivate the feeder and from the approx progress of the index I would guess its barfing on the same email every time.

-- Backtrace (Reduced):
#10 0x00007ffd65478b06 in qt_assert (assertion=assertion@entry=0x426554 "mRunningJobs == 0", file=file@entry=0x426330 "/home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/itemqueue.cpp", line=line@entry=113) at global/qglobal.cpp:2021
#11 0x00000000004167fa in ItemQueue::processBatch (this=this@entry=0x1c60cf8) at /home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/itemqueue.cpp:113
#12 0x00000000004129a0 in IndexScheduler::processItemQueue (this=this@entry=0x1c60bd0) at /home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/indexscheduler.cpp:252
#13 0x0000000000413408 in IndexScheduler::qt_static_metacall (_o=0x1c60bd0, _c=<optimized out>, _id=3, _a=0x7fff02651f20) at /home/lindsay/Projects/akonadi/kdepim-runtime/build/agents/nepomukfeeder/indexscheduler.moc:67
[...]
#15 0x00007ffd655993ec in QObject::event (this=0x1c60be8, e=<optimized out>) at kernel/qobject.cpp:1156
Comment 3 Blackpaw 2013-06-17 06:26:51 UTC
I realise this is of no interest to the developer but I added some extra logging to itemqueue.cpp to see what was happening:
--------------------------------------------------------------------------------------------------------
bool ItemQueue::processBatch()
{
  kDebug() << "pipline size: " << mItemPipeline.size() << mFetchedItemList.size();
  if ( mRunningJobs > 0 ) {//wait until the old graph has been saved
    kDebug() << "blocked: " << mRunningJobs;
    return false;
  }
  if ( mRunningJobs != 0 ) {
    // added by me
    kDebug() << "mRunningJobs == " << mRunningJobs << "!!!!!";
  }
  Q_ASSERT( mRunningJobs == 0 );
  mRunningJobs = 0;
--------------------------------------------------------------------------------------------------------
.xsession-errors
akonadi_nepomuk_feeder(13953) ItemQueue::processBatch: mRunningJobs ==  -1 !!!!!
ASSERT: "mRunningJobs == 0" in file /home/lindsay/Projects/akonadi/kdepim-runtime/agents/nepomukfeeder/itemqueue.cpp, line 116
--------------------------------------------------------------------------------------------------------

So for some reason mRunningJobs is actually -1, which I presume should never happen.

How thread safe is this stuff? I don't see any use of thread sync primitives.
Comment 4 Blackpaw 2013-06-17 06:59:03 UTC
Added more debug info to Item::QueueClear()

void ItemQueue::clear()
{
  if (mRunningJobs > 0)
    kDebug() << "CLEAR:mRunningJobs > 0!!!!";
  mRunningJobs = 0;
  mItemPipeline.clear();
  mFetchedItemList.clear();
}


The debug output showed that clear() is being called while jobs are outstanding. Presumably they finish after clear is called and mRunningJobs is decremented to -1.
Comment 5 Blackpaw 2013-06-17 07:58:57 UTC
Have developed a fix and testing it now.
Comment 6 Blackpaw 2013-06-19 12:48:57 UTC
Git commit ecf676853e27dbddd07ca2c76d87b5fe5971e740 by Lindsay Mathieson.
Committed on 19/06/2013 at 12:30.
Pushed by mathieson into branch 'master'.

Fix bug in running job count

Fixes problem where the count of running jobs becomes less than zero
(-1), causing an assert in itemqueue.cpp at line 113 to trigger. This
was happening because ItemQueue::clear() was setting the running job
count to zero when there was unfinished jobs, when the jobs actually did
finish the running job count was decremented to below zero.
The batch fixes this by keeping a QList<KJob *> of running jobs, adding
them when created and removing when the job finishes (via the result
signal). When ItemQueue::clear() is called any outstanding jobs are
silently killed and the list cleared.
REVIEW: 111089

M  +43   -12   agents/nepomukfeeder/itemqueue.cpp
M  +11   -1    agents/nepomukfeeder/itemqueue.h

http://commits.kde.org/kdepim-runtime/ecf676853e27dbddd07ca2c76d87b5fe5971e740