Bug 360677

Summary: Krita constantly creates and removes native threads
Product: krita Reporter: Andrew Savonichev <andrew.savonichev>
Component: GeneralAssignee: Krita Bugs <krita-bugs-null>
Status: RESOLVED FIXED    
Severity: normal CC: andrew.savonichev, halla
Priority: NOR    
Version: git master (please specify the git hash!)   
Target Milestone: ---   
Platform: Compiled Sources   
OS: Linux   
Latest Commit: Version Fixed In:

Description Andrew Savonichev 2016-03-17 20:53:45 UTC
During normal work in krita gdb shows that threads are spawning and diying constantly (see the log at the end)
These threads belong to QThreadPool in KisUpdaterContext and they are destroyed after QThreadPool::waitForDone() call
on every idle checker tick (once in a few seconds I guess).

Here is a backtrace (2 frames less than needed):

#0  KisUpdaterContext::waitForDone (this=0x692b408) at /home/asavonic/dev/krita/src/krita/libs/image/kis_updater_context.cpp:189
#1  0x00007ffff6a4523d in KisUpdateScheduler::tryBarrierLock (this=0x692af50) at /home/asavonic/dev/krita/src/krita/libs/image/kis_update_scheduler.cpp:328
#2  0x00007ffff6a45126 in KisUpdateScheduler::isIdle (this=0x692af50) at /home/asavonic/dev/krita/src/krita/libs/image/kis_update_scheduler.cpp:306
#3  0x00007ffff6a59837 in KisImage::isIdle (this=0x6929ae0) at /home/asavonic/dev/krita/src/krita/libs/image/kis_image.cc:400
#4  0x00007ffff6b79b4e in KisIdleWatcher::isIdle (this=0x5ad7a48) at /home/asavonic/dev/krita/src/krita/libs/image/kis_idle_watcher.cpp:69
#5  0x00007ffff6b79f9a in KisIdleWatcher::slotIdleCheckTick (this=0x5ad7a48) at /home/asavonic/dev/krita/src/krita/libs/image/kis_idle_watcher.cpp:117
#6  0x00007ffff6bbf314 in KisIdleWatcher::qt_static_metacall (_o=0x5ad7a48, _c=QMetaObject::InvokeMetaMethod, _id=2, _a=0x7fffffffce20) at /home/asavonic/dev/krita/build/libs/image/moc_kis_idle_watcher.cpp:89
#7  0x00007ffff246cde4 in QMetaObject::activate(QObject*, int, int, void**) () from /usr/lib64/libQt5Core.so.5
#8  0x00007ffff2479ac8 in QTimer::timerEvent(QTimerEvent*) () from /usr/lib64/libQt5Core.so.5
#9  0x00007ffff246de53 in QObject::event(QEvent*) () from /usr/lib64/libQt5Core.so.5
#10 0x00007ffff2f2e69c in QApplicationPrivate::notify_helper(QObject*, QEvent*) () from /usr/lib64/libQt5Widgets.so.5
#11 0x00007ffff2f33b10 in QApplication::notify(QObject*, QEvent*) () from /usr/lib64/libQt5Widgets.so.5
#12 0x00007ffff7788e39 in KisApplication::notify (this=0x7fffffffd620, receiver=0x5ad8f88, event=0x7fffffffd230) at /home/asavonic/dev/krita/src/krita/libs/ui/KisApplication.cpp:522
#13 0x00007ffff2444b9d in QCoreApplication::notifyInternal(QObject*, QEvent*) () from /usr/lib64/libQt5Core.so.5
#14 0x00007ffff2491b7d in QTimerInfoList::activateTimers() () from /usr/lib64/libQt5Core.so.5
#15 0x00007ffff2492051 in timerSourceDispatch(_GSource*, int (*)(void*), void*) () from /usr/lib64/libQt5Core.so.5
#16 0x00007fffece91cad in g_main_context_dispatch () from /usr/lib64/libglib-2.0.so.0
#17 0x00007fffece91f90 in g_main_context_iterate.isra () from /usr/lib64/libglib-2.0.so.0
#18 0x00007fffece9203c in g_main_context_iteration () from /usr/lib64/libglib-2.0.so.0
#19 0x00007ffff2492597 in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib64/libQt5Core.so.5
#20 0x00007ffff24437ba in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib64/libQt5Core.so.5
#21 0x00007ffff244ab9c in QCoreApplication::exec() () from /usr/lib64/libQt5Core.so.5
#22 0x0000000000403fb8 in main (argc=1, argv=0x7fffffffd778) at /home/asavonic/dev/krita/src/krita/krita/main.cc:178

GDB log:

[Thread 0x7fffc128a700 (LWP 18161) exited]
[New Thread 0x7fffc128a700 (LWP 18553)]
[New Thread 0x7fff8f00a700 (LWP 18554)]
[New Thread 0x7fff8e809700 (LWP 18555)]
[New Thread 0x7fffc968a700 (LWP 18556)]
[New Thread 0x7fffc3fff700 (LWP 18557)]
[Thread 0x7fffc3fff700 (LWP 18557) exited]
[Thread 0x7fffc968a700 (LWP 18556) exited]
[Thread 0x7fff8e809700 (LWP 18555) exited]
[Thread 0x7fff8f00a700 (LWP 18554) exited]
[Thread 0x7fffc128a700 (LWP 18553) exited]
[New Thread 0x7fff8e809700 (LWP 18558)]
[New Thread 0x7fff8f00a700 (LWP 18559)]
[New Thread 0x7fffc968a700 (LWP 18560)]
[New Thread 0x7fffc128a700 (LWP 18561)]
[New Thread 0x7fffc3fff700 (LWP 18562)]
[New Thread 0x7fffc1a8b700 (LWP 18563)]
[New Thread 0x7fff8d7fb700 (LWP 18564)]
[New Thread 0x7fff8cffa700 (LWP 18565)]
[Thread 0x7fffc3fff700 (LWP 18562) exited]
[Thread 0x7fffc968a700 (LWP 18560) exited]
[Thread 0x7fff8d7fb700 (LWP 18564) exited]
[Thread 0x7fff8f00a700 (LWP 18559) exited]
[Thread 0x7fffc1a8b700 (LWP 18563) exited]
[Thread 0x7fffc128a700 (LWP 18561) exited]
[Thread 0x7fff8cffa700 (LWP 18565) exited]
[Thread 0x7fff8e809700 (LWP 18558) exited]
[New Thread 0x7fff8e809700 (LWP 18566)]
[New Thread 0x7fff8cffa700 (LWP 18567)]
[New Thread 0x7fffc128a700 (LWP 18568)]
[New Thread 0x7fffc1a8b700 (LWP 18569)]
[New Thread 0x7fffc968f700 (LWP 18570)]
[New Thread 0x7fffc3fff700 (LWP 18571)]
[New Thread 0x7fff8f00a700 (LWP 18572)]
[New Thread 0x7fff8d7fb700 (LWP 18573)]
[Thread 0x7fffc3fff700 (LWP 18571) exited]
[Thread 0x7fffc968f700 (LWP 18570) exited]
[Thread 0x7fff8f00a700 (LWP 18572) exited]
[Thread 0x7fff8d7fb700 (LWP 18573) exited]
[Thread 0x7fffc1a8b700 (LWP 18569) exited]
[Thread 0x7fffc128a700 (LWP 18568) exited]
[Thread 0x7fff8cffa700 (LWP 18567) exited]
[Thread 0x7fff8e809700 (LWP 18566) exited]


Reproducible: Always

Steps to Reproduce:
1. start krita under gdb
2. paint something

Actual Results:  
Long list of "New Thread" -> "Thread exited" in gdb output.

Expected Results:  
Create fixed number of threads and reuse them.

OS: Linux (Gentoo)
Revision: krita 3.0 from master: f037a59 Fix memleak: QPluginLoader objects need to be deleted

Does not reproduce on 2.9.11 from Gentoo portage.
Comment 1 Halla Rempt 2016-03-18 07:45:28 UTC
Weird... I cannot reproduce it with 3.0 on opensuse! Which version of Qt do you have?
Comment 2 Andrew Savonichev 2016-03-18 08:44:02 UTC
Qt 5.5.1-r1

proposed patch: https://phabricator.kde.org/D1166
Comment 3 Halla Rempt 2016-03-19 19:10:02 UTC
Okay -- let's ping dmitry on Monday and see what he thinks. The patch looks good to me, but this isn't quite my area of expertise.
Comment 4 Halla Rempt 2016-04-16 13:35:41 UTC
Hi Andrew,

Did you investigate further? What were your findings.
Comment 5 Halla Rempt 2016-06-16 12:39:24 UTC
Any news?
Comment 6 Andrew Savonichev 2016-07-07 19:42:05 UTC
Hi Boud,

Sorry, was not able to finish it for a long time.
I'll make an appropriate fix and update the review request.
Comment 7 Halla Rempt 2016-07-07 19:49:54 UTC
That would be awesome, thanks!
Comment 8 Dmitry Kazakov 2016-08-18 07:00:28 UTC
Git commit 9c34fef3320983c8e0542363121035eab225cd29 by Dmitry Kazakov, on behalf of Andrew Savonichev.
Committed on 18/08/2016 at 06:59.
Pushed by dkazakov into branch 'master'.

Summary:
KisUpdaterContext::waitForDone() method must lock context and wait
untill all threads finish their current tasks.
We cannot call QThreadPool.waitForDone() to do this, because after
waiting it removes all threads from the pool.

Test Plan:
Verified that no extra threads created: 8 for global thread pool and 8 for
KisUpdaterContext

(gdb) info threads
  Id   Target Id         Frame
  22   Thread 0x7fff8cff9700 (LWP 18481) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  21   Thread 0x7fff8d7fa700 (LWP 18480) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  20   Thread 0x7fff8dffb700 (LWP 18479) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  19   Thread 0x7fff8e7fc700 (LWP 18478) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  18   Thread 0x7fff8effd700 (LWP 18477) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  17   Thread 0x7fff8f7fe700 (LWP 18476) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  16   Thread 0x7fff8ffff700 (LWP 18475) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  15   Thread 0x7fff9bfff700 (LWP 18474) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  13   Thread 0x7fffb8ff9700 (LWP 18471) "QFileInfoGather" 0x00007fffef6e291f in pthread_cond_wait () from /lib64/libpthread.so.0
  12   Thread 0x7fffb97fa700 (LWP 18470) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  11   Thread 0x7fffb9ffb700 (LWP 18469) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  10   Thread 0x7fffba7fc700 (LWP 18468) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  9    Thread 0x7fffbaffd700 (LWP 18467) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  8    Thread 0x7fffbb7fe700 (LWP 18466) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  7    Thread 0x7fffbbfff700 (LWP 18465) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  6    Thread 0x7fffc8f8a700 (LWP 18464) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  5    Thread 0x7fffc978b700 (LWP 18463) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  4    Thread 0x7fffca38d700 (LWP 18462) "KisTileDataSwap" 0x00007fffef6e291f in pthread_cond_wait () from /lib64/libpthread.so.0
  3    Thread 0x7fffcab8e700 (LWP 18461) "KisTileDataPool" 0x00007fffef6e291f in pthread_cond_wait () from /lib64/libpthread.so.0
  2    Thread 0x7fffe0843700 (LWP 18460) "QXcbEventReader" 0x00007ffff16a33ed in poll () from /lib64/libc.so.6
* 1    Thread 0x7fffe7f3f7c0 (LWP 18456) "krita" 0x00007ffff16a33ed in poll () from /lib64/libc.so.6

Reviewers: dkazakov

Reviewed By: dkazakov

Subscribers: fazek
Differential Revision: https://phabricator.kde.org/D1166

M  +10   -2    libs/image/kis_update_scheduler.cpp
M  +89   -14   libs/image/kis_updater_context.cpp
M  +14   -0    libs/image/kis_updater_context.h
M  +14   -0    libs/image/tests/kis_strokes_queue_test.cpp
M  +2    -0    libs/image/tests/kis_updater_context_test.cpp

http://commits.kde.org/krita/9c34fef3320983c8e0542363121035eab225cd29
Comment 9 Dmitry Kazakov 2016-08-18 07:00:28 UTC
Git commit 9c34fef3320983c8e0542363121035eab225cd29 by Dmitry Kazakov, on behalf of Andrew Savonichev.
Committed on 18/08/2016 at 06:59.
Pushed by dkazakov into branch 'master'.

Summary:
KisUpdaterContext::waitForDone() method must lock context and wait
untill all threads finish their current tasks.
We cannot call QThreadPool.waitForDone() to do this, because after
waiting it removes all threads from the pool.

Test Plan:
Verified that no extra threads created: 8 for global thread pool and 8 for
KisUpdaterContext

(gdb) info threads
  Id   Target Id         Frame
  22   Thread 0x7fff8cff9700 (LWP 18481) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  21   Thread 0x7fff8d7fa700 (LWP 18480) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  20   Thread 0x7fff8dffb700 (LWP 18479) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  19   Thread 0x7fff8e7fc700 (LWP 18478) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  18   Thread 0x7fff8effd700 (LWP 18477) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  17   Thread 0x7fff8f7fe700 (LWP 18476) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  16   Thread 0x7fff8ffff700 (LWP 18475) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  15   Thread 0x7fff9bfff700 (LWP 18474) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  13   Thread 0x7fffb8ff9700 (LWP 18471) "QFileInfoGather" 0x00007fffef6e291f in pthread_cond_wait () from /lib64/libpthread.so.0
  12   Thread 0x7fffb97fa700 (LWP 18470) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  11   Thread 0x7fffb9ffb700 (LWP 18469) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  10   Thread 0x7fffba7fc700 (LWP 18468) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  9    Thread 0x7fffbaffd700 (LWP 18467) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  8    Thread 0x7fffbb7fe700 (LWP 18466) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  7    Thread 0x7fffbbfff700 (LWP 18465) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  6    Thread 0x7fffc8f8a700 (LWP 18464) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  5    Thread 0x7fffc978b700 (LWP 18463) "Thread (pooled)" 0x00007fffef6e2cc8 in pthread_cond_timedwait () from /lib64/libpthread.so.0
  4    Thread 0x7fffca38d700 (LWP 18462) "KisTileDataSwap" 0x00007fffef6e291f in pthread_cond_wait () from /lib64/libpthread.so.0
  3    Thread 0x7fffcab8e700 (LWP 18461) "KisTileDataPool" 0x00007fffef6e291f in pthread_cond_wait () from /lib64/libpthread.so.0
  2    Thread 0x7fffe0843700 (LWP 18460) "QXcbEventReader" 0x00007ffff16a33ed in poll () from /lib64/libc.so.6
* 1    Thread 0x7fffe7f3f7c0 (LWP 18456) "krita" 0x00007ffff16a33ed in poll () from /lib64/libc.so.6

Reviewers: dkazakov

Reviewed By: dkazakov

Subscribers: fazek
Differential Revision: https://phabricator.kde.org/D1166

M  +10   -2    libs/image/kis_update_scheduler.cpp
M  +89   -14   libs/image/kis_updater_context.cpp
M  +14   -0    libs/image/kis_updater_context.h
M  +14   -0    libs/image/tests/kis_strokes_queue_test.cpp
M  +2    -0    libs/image/tests/kis_updater_context_test.cpp

http://commits.kde.org/krita/9c34fef3320983c8e0542363121035eab225cd29
Comment 10 Dmitry Kazakov 2022-01-29 11:47:41 UTC
Git commit 39fcfac8281d4d0bf100d4c15460fa2a2bc998ab by Dmitry Kazakov.
Committed on 29/01/2022 at 11:47.
Pushed by dkazakov into branch 'master'.

Fix Krita discarding native threads every couple of seconds

For years Krita has been spawning native threads carelessly. It
happened because of the implementation of QThreadPool::waitForDone(),
which discards threads on every successful call.

We once had a patch for that (9c34fef3320983c8e0542363121035eab225cd29),
but it has been reverted due to deadlock regressions it introduced.

This patch adds a bit different implementation of the waiting strategy,
so (I hope) it won't cause any deadlocks.
Related: bug 367901

M  +13   -0    libs/image/kis_update_job_item.h
M  +29   -4    libs/image/kis_updater_context.cpp
M  +7    -0    libs/image/kis_updater_context.h

https://invent.kde.org/graphics/krita/commit/39fcfac8281d4d0bf100d4c15460fa2a2bc998ab
Comment 11 Dmitry Kazakov 2022-02-23 08:49:29 UTC
Git commit 8b9ac2512e9ec12f52411c86f299ea3550936a0a by Dmitry Kazakov.
Committed on 23/02/2022 at 08:48.
Pushed by dkazakov into branch 'krita/5.0'.

Fix Krita discarding native threads every couple of seconds

For years Krita has been spawning native threads carelessly. It
happened because of the implementation of QThreadPool::waitForDone(),
which discards threads on every successful call.

We once had a patch for that (9c34fef3320983c8e0542363121035eab225cd29),
but it has been reverted due to deadlock regressions it introduced.

This patch adds a bit different implementation of the waiting strategy,
so (I hope) it won't cause any deadlocks.
Related: bug 367901

M  +13   -0    libs/image/kis_update_job_item.h
M  +29   -4    libs/image/kis_updater_context.cpp
M  +7    -0    libs/image/kis_updater_context.h

https://invent.kde.org/graphics/krita/commit/8b9ac2512e9ec12f52411c86f299ea3550936a0a