Summary: | Face Detection crashes on folders containing videos | ||
---|---|---|---|
Product: | [Applications] digikam | Reporter: | Andrew Coles <andrew.i.coles> |
Component: | Faces-Detection | Assignee: | Digikam Developers <digikam-bugs-null> |
Status: | RESOLVED FIXED | ||
Severity: | crash | CC: | caulier.gilles |
Priority: | NOR | ||
Version: | 2.0.0 | ||
Target Milestone: | --- | ||
Platform: | Compiled Sources | ||
OS: | Linux | ||
Latest Commit: | Version Fixed In: | 2.0.0 | |
Attachments: | Patch to stop the same DynamicThread::run() function being called twice in parallel |
Description
Andrew Coles
2011-01-16 00:48:20 UTC
Can you generate a new backtrace because the is not digiKam crash hander entry here. Thanks in advance Gilles Caulier Oddly, the bug occurred for five or six of my folders containing videos last night, before reporting the bug; now I can't force it to happen at all. Will post a backtrace as soon as it happens again. Okay I have a set of photos and videos which trigger the crash every time, so I've been able to do some more testing. 1) If I run digikam as-is, it crashes part-way through face-recognition, printing out: pure virtual method called terminate called without an active exception Unable to start Dr. Konqi 2) If I run it through gdb, it gives the backtrace I gave when reporting the bug. 3) If I run it through valgrind, I get the output at the bottom of this comment. If there's anything else that would be helpful, let me know. ==3498== Thread 18: ==3498== Invalid read of size 4 ==3498== at 0x532ECD9: Digikam::LoadingCache::notifyNewLoadingProcess(Digikam::LoadingProcess*, Digikam::LoadingDescription) (loadingcache.cpp:171) ==3498== by 0x53394AC: Digikam::PreviewLoadingTask::execute() (previewtask.cpp:171) ==3498== by 0x5320BD2: Digikam::LoadSaveThread::run() (loadsavethread.cpp:116) ==3498== by 0x536E8ED: Digikam::DynamicThread::DynamicThreadPriv::run() (dynamicthread.cpp:324) ==3498== by 0x70B0522: QThreadPoolThread::run() (qthreadpool.cpp:106) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== Address 0x27eaa4c0 is 344 bytes inside a block of size 700 free'd ==3498== at 0x4025504: operator delete(void*) (vg_replace_malloc.c:387) ==3498== by 0x533A768: Digikam::PreviewLoadingTask::~PreviewLoadingTask() (previewtask.h:40) ==3498== by 0x5320B0E: Digikam::LoadSaveThread::run() (loadsavethread.cpp:94) ==3498== by 0x536E8ED: Digikam::DynamicThread::DynamicThreadPriv::run() (dynamicthread.cpp:324) ==3498== by 0x70B0522: QThreadPoolThread::run() (qthreadpool.cpp:106) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== pure virtual method called ==3498== Thread 16: ==3498== Invalid read of size 1 ==3498== at 0x5338B23: Digikam::PreviewLoadingTask::execute() (previewtask.cpp:219) ==3498== by 0x5320BD2: Digikam::LoadSaveThread::run() (loadsavethread.cpp:116) ==3498== by 0x536E8ED: Digikam::DynamicThread::DynamicThreadPriv::run() (dynamicthread.cpp:324) ==3498== by 0x70B0522: QThreadPoolThread::run() (qthreadpool.cpp:106) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== Address 0x27eaa49c is 308 bytes inside a block of size 700 free'd ==3498== at 0x4025504: operator delete(void*) (vg_replace_malloc.c:387) ==3498== by 0x533A768: Digikam::PreviewLoadingTask::~PreviewLoadingTask() (previewtask.h:40) ==3498== by 0x5320B0E: Digikam::LoadSaveThread::run() (loadsavethread.cpp:94) ==3498== by 0x536E8ED: Digikam::DynamicThread::DynamicThreadPriv::run() (dynamicthread.cpp:324) ==3498== by 0x70B0522: QThreadPoolThread::run() (qthreadpool.cpp:106) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== ==3498== Invalid read of size 4 ==3498== at 0x53399DB: Digikam::PreviewLoadingTask::execute() (previewtask.cpp:247) ==3498== by 0x5320BD2: Digikam::LoadSaveThread::run() (loadsavethread.cpp:116) ==3498== by 0x536E8ED: Digikam::DynamicThread::DynamicThreadPriv::run() (dynamicthread.cpp:324) ==3498== by 0x70B0522: QThreadPoolThread::run() (qthreadpool.cpp:106) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== Address 0x27eaa368 is 0 bytes inside a block of size 700 free'd ==3498== at 0x4025504: operator delete(void*) (vg_replace_malloc.c:387) ==3498== by 0x533A768: Digikam::PreviewLoadingTask::~PreviewLoadingTask() (previewtask.h:40) ==3498== by 0x5320B0E: Digikam::LoadSaveThread::run() (loadsavethread.cpp:94) ==3498== by 0x536E8ED: Digikam::DynamicThread::DynamicThreadPriv::run() (dynamicthread.cpp:324) ==3498== by 0x70B0522: QThreadPoolThread::run() (qthreadpool.cpp:106) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== ==3498== Invalid read of size 4 ==3498== at 0x54CD68B: ??? (in /home/amanda/tools/lib/libdigikamcore.so.2.0.0) ==3498== by 0x5320BD2: Digikam::LoadSaveThread::run() (loadsavethread.cpp:116) ==3498== by 0x536E8ED: Digikam::DynamicThread::DynamicThreadPriv::run() (dynamicthread.cpp:324) ==3498== by 0x70B0522: QThreadPoolThread::run() (qthreadpool.cpp:106) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== Address 0x68 is not stack'd, malloc'd or (recently) free'd ==3498== KCrash: Application 'digikam' crashing... KCrash: Attempting to start /usr/lib/kde4/libexec/drkonqi from kdeinit digikam: Fatal IO error: client killed QSocketNotifier: Invalid socket 17 and type 'Read', disabling... terminate called without an active exception sock_file=/home/amanda/.kde/socket-AmandaVaio/kdeinit4__0 ==3498== Thread 3: ==3498== Invalid read of size 2 ==3498== at 0x71ECA05: socketNotifierSourceCheck(_GSource*) (qeventdispatcher_glib.cpp:92) ==3498== by 0x941FB38: g_main_context_check (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x942045D: ??? (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x9420847: g_main_context_iteration (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x71EC564: QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventdispatcher_glib.cpp:415) ==3498== by 0x71BC608: QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:149) ==3498== by 0x71BCA89: QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:201) ==3498== by 0x70B8B7D: QThread::exec() (qthread.cpp:490) ==3498== by 0x719B35A: QInotifyFileSystemWatcherEngine::run() (qfilesystemwatcher_inotify.cpp:248) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== Address 0xe4dda6e is 6 bytes inside a block of size 12 free'd ==3498== at 0x4025504: operator delete(void*) (vg_replace_malloc.c:387) ==3498== by 0x71ED0B4: QEventDispatcherGlib::unregisterSocketNotifier(QSocketNotifier*) (qeventdispatcher_glib.cpp:496) ==3498== by 0x71DB1D9: QSocketNotifier::setEnabled(bool) (qsocketnotifier.cpp:298) ==3498== by 0x71ECA01: socketNotifierSourceCheck(_GSource*) (qeventdispatcher_glib.cpp:92) ==3498== by 0x941FB38: g_main_context_check (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x942045D: ??? (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x9420847: g_main_context_iteration (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x71EC564: QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventdispatcher_glib.cpp:415) ==3498== by 0x71BC608: QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:149) ==3498== by 0x71BCA89: QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:201) ==3498== by 0x70B8B7D: QThread::exec() (qthread.cpp:490) ==3498== by 0x719B35A: QInotifyFileSystemWatcherEngine::run() (qfilesystemwatcher_inotify.cpp:248) ==3498== ==3498== Invalid read of size 2 ==3498== at 0x71ECA09: socketNotifierSourceCheck(_GSource*) (qeventdispatcher_glib.cpp:83) ==3498== by 0x941FB38: g_main_context_check (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x942045D: ??? (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x9420847: g_main_context_iteration (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x71EC564: QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventdispatcher_glib.cpp:415) ==3498== by 0x71BC608: QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:149) ==3498== by 0x71BCA89: QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:201) ==3498== by 0x70B8B7D: QThread::exec() (qthread.cpp:490) ==3498== by 0x719B35A: QInotifyFileSystemWatcherEngine::run() (qfilesystemwatcher_inotify.cpp:248) ==3498== by 0x70BBDF8: QThreadPrivate::start(void*) (qthread_unix.cpp:266) ==3498== by 0x92D4CC8: start_thread (pthread_create.c:304) ==3498== by 0x766269D: clone (clone.S:130) ==3498== Address 0xe4dda6c is 4 bytes inside a block of size 12 free'd ==3498== at 0x4025504: operator delete(void*) (vg_replace_malloc.c:387) ==3498== by 0x71ED0B4: QEventDispatcherGlib::unregisterSocketNotifier(QSocketNotifier*) (qeventdispatcher_glib.cpp:496) ==3498== by 0x71DB1D9: QSocketNotifier::setEnabled(bool) (qsocketnotifier.cpp:298) ==3498== by 0x71ECA01: socketNotifierSourceCheck(_GSource*) (qeventdispatcher_glib.cpp:92) ==3498== by 0x941FB38: g_main_context_check (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x942045D: ??? (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x9420847: g_main_context_iteration (in /lib/libglib-2.0.so.0.2600.1) ==3498== by 0x71EC564: QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventdispatcher_glib.cpp:415) ==3498== by 0x71BC608: QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:149) ==3498== by 0x71BCA89: QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) (qeventloop.cpp:201) ==3498== by 0x70B8B7D: QThread::exec() (qthread.cpp:490) ==3498== by 0x719B35A: QInotifyFileSystemWatcherEngine::run() (qfilesystemwatcher_inotify.cpp:248) ==3498== QSocketNotifier: Invalid socket 30 and type 'Read', disabling... Unable to start Dr. Konqi Can you provide one of those files? To be sure it's really the file and not the context, try if such a file scanned in a different folder or a folder for itself also triggers the crash. It would be immensely helpful if I could reproduce! I assume you are using current SVN? It seems to be caused by having a directory with interleaved video and photo files. If the videos are all listed at the end of the directory, it passes over them quickly then declares that face recognition has finished. But, if it has to switch back and forth, between pictures it can load previews for and ones it cannot, it crashes. I can give you the test album I'm using, though it's 100Mb. It's nothing special, just a few JPGs, then a few AVIs, then a few JPGs, then a few AVIs. etc (And yes, I'm using the latest SVN.) MfG, Andrew I'm currently at a slow internet connection, this will have to wait until next week. I will see to prepare such a folder. Okay, some more hunting - I'm trying to see if I can work out what's going on here. Adding some debugging messages I get: * Started to execute PreviewLoadingTask (LoadingProcess 0xc3bd2b8) * Called LoadingCache::addLoadingProcess(0xc3bd2b8) for image /home/amanda/Pictures/Test/aa056.jpg-previewImage-1600 ... * Destroying LoadingProcess at 0xc3bd2b8 So, a PreviewLoadingTask is started, and then destroyed *before it has finished executing* and hence called LoadingCache::removeLoadingProcess. The crash itself arises when another PreviewLoadingTask is started: * Called LoadingCache::addLoadingProcess(0xc2dc290) for image /home/amanda/Pictures/Test/aa057.jpg-previewImage-1600 * In LoadingCache::notifyNewLoadingProcess: notifying 0xc3bd2b8 ...which attempts to call use the PreviewLoadingTask deleted above. So it's nothing to do with face recognition; just that face recognition stress-tests the multi-threaded image previewing code. Some more detective with: the problem is caused by two threads, running at the same time, calling LoadSaveThread::run() on the same LoadSaveThread object - and hence sharing the same memory location for m_currentTask. Thus: i) Thread A sets m_currentTask to a PreviewLoadingTask foo, and calls execute ii) Thread B starts, deleting m_currentTask (i.e. foo), sets m_currentTask to a different PreviewLoadingTask, calls execute iii) As part of PreviewLoadingTask::execute(), thread B calls notifyNewLoadingProcess, which tries to call notifyNewLoadingProcess on foo - which has since been deleted. Its step (iii) which leads to the error 'pure virtual method called', but the problem is somewhere in the code the same LoadSaveThread object is being used as the basis of two executing threads. I'll carry on working backwards, see if I can work out where that is. Ah. Damn, still this problem!! I have seen this in a few occasions, and fixed some loopholes, see also 261779. There must be something left. It's libs/threads/dynamicthreads.cpp. There is the d->threadRequested safeguard (mutex protected) to avoid requesting a thread twice from the pool. Additionally, transitionToRunning() (mutex protected) should return false for a second thread, avoiding to call q->run in ::run(). I must miss something, but I dont know where. Created attachment 56312 [details]
Patch to stop the same DynamicThread::run() function being called twice in parallel
Okay, I think I've cracked this now. In DynamicThread::DynamicThreadPriv::run() it used to do:
takingThread(); // change threadRequested to 'false', allowing this DynamicThreadPriv to be scheduled again
if (emitSignals)
{
emit q->started();
}
if (transitionToRunning()) // if the DynamicThread was not running, mark it as running (change the value of the variable state from Scheduled to Running)
{
q->run(); // ...then actually call the run function
}
The problem seems to be the gap, between:
i) threadRequested being set to false
ii) state being changed from Scheduled set to Running.
On some executions of the program, between (i) and (ii) another copy of the DynamicThreadPriv was scheduled and started. Then, both managed to make the transition to running, and q->run() was called twice at the same time on the same q.
A solution, as far as I can tell, is to move the call to takingThread() lower down:
if (emitSignals)
{
emit q->started();
}
if (transitionToRunning())
{
takingThread();
q->run();
}
else
{
takingThread();
}
Now, there is no longer the (i)-(ii) gap discussed above: the variable threadRequested is only set to false once the variable state records that the thread is now running (or in the case of the else, once it has been safely determined that the transition to running did not occur).
Patch attached: shall I commit or do you want to handle it?
Thanks a lot! Looking back, it's plain obvious, but I really didnt see that at first glance. We could also just remove the takingThread method and change the threadRequested flag in the second line of transitionToRunning I think. Please go forward and commit as you like. SVN commit 1216303 by coles: Moved the call to takingThread() so it definitely comes after the value of the the variable 'state' is updated in transitionToRunning(). This avoids two instances of the same DynamicThreadPriv being scheduled at the same time. BUG: 263272 M +5 -2 dynamicthread.cpp WebSVN link: http://websvn.kde.org/?view=rev&revision=1216303 |