From kde-kimageshop Wed Sep 16 06:25:02 2009 From: Boudewijn Rempt Date: Wed, 16 Sep 2009 06:25:02 +0000 To: kde-kimageshop Subject: playing with mutrace Message-Id: <200909160825.02847.boud () valdyas ! org> X-MARC-Message: https://marc.info/?l=kde-kimageshop&m=125308566102470 Hi! Lennart Poettering recently made a new tool, mutrace -- see http://0pointer.de/blog/projects/mutrace.html. Initially it didn't work with KDE apps but Lennart made it work, so I'm presenting here the first bit of mutrace output for Krita! A bit of drawing, a gradient, the blur filter a second layer and a bit of drawing. boud@valdiesalie:~/kde/src/svn/kdelibs/kdeui/icons> mutrace --hash-size=40000 krita mutrace: 0.1 sucessfully initialized for process krita (pid 9802). X Error: BadAtom (invalid Atom parameter) 5 Major opcode: 20 (X_GetProperty) Resource id: 0x0 Enchant dict for "en_US" 0x8f16d98 Enchant dict for "en_US" 0x8f16d98 Enchant dict for "en_US" 0x8f16d98 Enchant dict for "en_US" 0x8f16d98 Enchant dict for "en_US" 0x8f16d98 QLayout: Attempting to add QLayout "" to QWidget "KritaShape/KisToolBrushoption widget", which already has a layout Object::connect: No such signal KoSliderCombo::valueChanged(int,bool) Object::connect: (receiver name: 'KritaFill/KisToolGradient') QLayout: Attempting to add QLayout "" to QWidget "KritaShape/KisToolLine", which already has a layout QObject::connect: Cannot connect KoMainWindow::restoringDone() to (null)::removeUnusedOptionWidgets() ** (process:9802): WARNING **: 1 dictionaries weren't free'd. mutrace: Showing statistics for process krita (pid 9802). mutrace: 2756 mutexes used. Mutex #289 (0x0x87fa018) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_init+0x124) [0xb80a42a4] /usr/lib/libQtCore.so.4 [0xb7eadd63] /usr/lib/libQtCore.so.4(_ZN6QMutexC1ENS_13RecursionModeE+0x37) [0xb7ea92c7] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisTileManagerC1Ev+0x71) [0xb7a99b91] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisTileManager8instanceEv+0x4e) [0xb7a9a0ae] /home/boud/kde/inst/lib/libkritaimage.so.6 [0xb7a96523] /home/boud/kde/inst/lib/libkritaimage.so.6 [0xb7a96974] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN19KisTiledDataManagerC2EjPKh+0x81) [0xb7a92ae1] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisPaintDeviceC1E16KisWeakSharedPtrI7KisNodeEPK12KoColorSpaceRK7QString+0x1b6) [0xb7b1a806] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN13KisGroupLayerC1E16KisWeakSharedPtrI8KisImageERK7QStringh+0x24f) [0xb7aef9df] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN8KisImage4initEP14KisUndoAdapteriiPK12KoColorSpace+0xee) [0xb7af5f3e] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN8KisImageC1EP14KisUndoAdapteriiPK12KoColorSpaceRK7QString+0xea) [0xb7af62ca] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d72071] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN7KisDoc27loadXMLERK13KoXmlDocumentP7KoStore+0x375) [0xb7cc1da5] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument33loadNativeFormatFromStoreInternalEP7KoStore+0x38a) [0xb76d023a] Mutex #1354 (0x0x808f92c) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_lock+0x58) [0xb80a4108] /usr/lib/libglib-2.0.so.0(g_source_attach+0x97) [0xb56c3ae7] /usr/lib/libQtCore.so.4(_ZN27QEventDispatcherGlibPrivateC2EP13_GMainContext+0xc8) [0xb7fcedf8] /usr/lib/libQtGui.so.4 [0xb5bc0f3d] /usr/lib/libQtGui.so.4 [0xb5bc1023] /usr/lib/libQtGui.so.4(_ZN19QApplicationPrivate21createEventDispatcherEv+0x90) [0xb5b87640] /usr/lib/libQtCore.so.4(_ZN16QCoreApplication4initEv+0xac) [0xb7fa64dc] /usr/lib/libQtCore.so.4(_ZN16QCoreApplicationC2ER23QCoreApplicationPrivate+0x47) [0xb7fa65e7] /usr/lib/libQtGui.so.4(_ZN12QApplicationC2ERiPPcbi+0x5a) [0xb5b25b7a] /usr/lib/libkdeui.so.5(_ZN12KApplicationC2Eb+0x4e) [0xb69e0cbe] /home/boud/kde/inst/lib/libkomain.so.6(_ZN13KoApplicationC1Ev+0x2e) [0xb76b3d5e] /home/boud/kde/inst/lib/libkdeinit4_krita.so(kdemain+0x16d) [0xb809f9ed] krita [0x80488b2] Mutex #1002 (0x0x8804180) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_init+0x124) [0xb80a42a4] /usr/lib/libQtCore.so.4 [0xb7eadd63] /usr/lib/libQtCore.so.4(_ZN6QMutexC1ENS_13RecursionModeE+0x37) [0xb7ea92c7] /home/boud/kde/inst/lib/libkritaimage.so.6 [0xb7a9693f] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN19KisTiledDataManagerC2EjPKh+0x81) [0xb7a92ae1] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisPaintDeviceC1E16KisWeakSharedPtrI7KisNodeEPK12KoColorSpaceRK7QString+0x1b6) [0xb7b1a806] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN13KisPaintLayerC1E12KisSharedPtrI8KisImageERK7QStringhPK12KoColorSpace+0x158) [0xb7b234c8] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6c66d] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6f9b7] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d70d81] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d7212a] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN7KisDoc27loadXMLERK13KoXmlDocumentP7KoStore+0x375) [0xb7cc1da5] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument33loadNativeFormatFromStoreInternalEP7KoStore+0x38a) [0xb76d023a] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument25loadNativeFormatFromStoreERK7QString+0xa6) [0xb76d0d46] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument16loadNativeFormatERK7QString+0x1a1) [0xb76d1071] Mutex #83 (0x0x9368274) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_lock+0x58) [0xb80a4108] /usr/lib/libglib-2.0.so.0(g_source_attach+0x97) [0xb56c3ae7] /usr/lib/libQtCore.so.4(_ZN27QEventDispatcherGlibPrivateC1EP13_GMainContext+0xc8) [0xb7fcf098] /usr/lib/libQtCore.so.4(_ZN20QEventDispatcherGlibC1EP7QObject+0x3b) [0xb7fcf3ab] /usr/lib/libQtCore.so.4 [0xb7eae3a4] /usr/lib/libQtCore.so.4 [0xb7eae549] /lib/libpthread.so.0 [0xb7e4c1b5] /lib/libc.so.6(clone+0x5e) [0xb58493be] Mutex #1968 (0x0x8505f50) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_init+0x124) [0xb80a42a4] /usr/lib/libQtCore.so.4 [0xb7eadd63] /usr/lib/libQtCore.so.4(_ZN6QMutexC1ENS_13RecursionModeE+0x37) [0xb7ea92c7] /home/boud/kde/inst/lib/libkritaimage.so.6 [0xb7a9693f] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN19KisTiledDataManager4readEP7KoStore+0x15b) [0xb7a9219b] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisPaintDevice4readEP7KoStore+0x37) [0xb7b19c37] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6902e] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6ab8b] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN13KisPaintLayer6acceptER14KisNodeVisitor+0x18) [0xb7b20d38] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisNodeVisitor8visitAllEP7KisNodeb+0x57) [0xb7b18a87] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d68529] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN13KisGroupLayer6acceptER14KisNodeVisitor+0x18) [0xb7aece68] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6d2a2] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN7KisDoc215completeLoadingEP7KoStore+0xcd) [0xb7cc27fd] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument33loadNativeFormatFromStoreInternalEP7KoStore+0x140) [0xb76cfff0] Mutex #798 (0x0x88c40c8) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_init+0x124) [0xb80a42a4] /usr/lib/libQtCore.so.4 [0xb7eadd63] /usr/lib/libQtCore.so.4(_ZN6QMutexC1ENS_13RecursionModeE+0x37) [0xb7ea92c7] /home/boud/kde/inst/lib/libkoresources.so.6(_ZN24KoResourceServerProviderC1Ev+0x6be) [0xb732831e] /home/boud/kde/inst/lib/libkoresources.so.6(_ZN24KoResourceServerProvider8instanceEv+0x4e) [0xb732859e] /home/boud/kde/inst/lib/kde4/karbondockersplugin.so [0xb12f7055] /home/boud/kde/inst/lib/kde4/karbondockersplugin.so [0xb12fc43b] /home/boud/kde/inst/lib/libkomain.so.6(_ZN12KoMainWindow16createDockWidgetEP13KoDockFactory+0x56f) [0xb76ecf9f] /home/boud/kde/inst/lib/libkomain.so.6(_ZN6KoView16createDockWidgetEP13KoDockFactory+0x3f) [0xb771289f] /home/boud/kde/inst/lib/libkomain.so.6(_ZN6KoViewC2EP10KoDocumentP7QWidget+0x448) [0xb7714528] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN8KisView2C1EP7KisDoc2P7QWidget+0x4b) [0xb7d409cb] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN7KisDoc218createViewInstanceEP7QWidget+0x3e) [0xb7cc0abe] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument10createViewEP7QWidget+0x21) [0xb76c1081] /home/boud/kde/inst/lib/libkomain.so.6(_ZN12KoMainWindow15setRootDocumentEP10KoDocument+0x353) [0xb76eed53] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument17showStartUpWidgetEP12KoMainWindowb+0x27c) [0xb76cbc9c] Mutex #2002 (0x0x8506688) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_init+0x124) [0xb80a42a4] /usr/lib/libQtCore.so.4 [0xb7eadd63] /usr/lib/libQtCore.so.4(_ZN6QMutexC1ENS_13RecursionModeE+0x37) [0xb7ea92c7] /home/boud/kde/inst/lib/libkritaimage.so.6 [0xb7a9693f] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN19KisTiledDataManager4readEP7KoStore+0x15b) [0xb7a9219b] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisPaintDevice4readEP7KoStore+0x37) [0xb7b19c37] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6902e] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6ab8b] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN13KisPaintLayer6acceptER14KisNodeVisitor+0x18) [0xb7b20d38] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN14KisNodeVisitor8visitAllEP7KisNodeb+0x57) [0xb7b18a87] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d68529] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN13KisGroupLayer6acceptER14KisNodeVisitor+0x18) [0xb7aece68] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7d6d2a2] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN7KisDoc215completeLoadingEP7KoStore+0xcd) [0xb7cc27fd] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument33loadNativeFormatFromStoreInternalEP7KoStore+0x140) [0xb76cfff0] Mutex #2583 (0x0x8051c18) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_lock+0x58) [0xb80a4108] /usr/lib/libQtCore.so.4 [0xb7eadad7] /usr/lib/libQtCore.so.4(_ZN6QMutex4lockEv+0x165) [0xb7ea91f5] /usr/lib/libQtCore.so.4(_ZN11QMetaObject7connectEPK7QObjectiS2_iiPi+0x61) [0xb7fb4fc1] /usr/lib/libQtCore.so.4(_ZN7QObject7connectEPKS_PKcS1_S3_N2Qt14ConnectionTypeE+0x3a2) [0xb7fb5472] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN12KisCmbIDListC1EP7QWidgetPKc+0xbb) [0xb7da557b] /home/boud/kde/inst/lib/libkritalibpaintop.so.6(_ZN17KisSensorSelectorC1EP7QWidget+0x14b) [0xb212e72b] /home/boud/kde/inst/lib/libkritalibpaintop.so.6(_ZN14KisCurveOptionC2ERK7QStringS2_b+0x1a5) [0xb2121805] /home/boud/kde/inst/lib/libkritalibpaintop.so.6(_ZN24KisPressureOpacityOptionC1Ev+0x7d) [0xb212c55d] /home/boud/kde/inst/lib/kde4/kritacomplexbrush.so [0xb20cd0ce] /home/boud/kde/inst/lib/kde4/kritacomplexbrush.so [0xb20cd4db] /home/boud/kde/inst/lib/kde4/kritacomplexbrush.so [0xb20ca1e9] /home/boud/kde/inst/lib/kde4/kritacomplexbrush.so [0xb20ca70c] Mutex #176 (0x0x9083570) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_init+0x124) [0xb80a42a4] /usr/lib/libQtCore.so.4 [0xb7eadd63] /usr/lib/libQtCore.so.4(_ZN6QMutexC1ENS_13RecursionModeE+0x37) [0xb7ea92c7] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN25KisResourceServerProviderC1Ev+0x317) [0xb7d23147] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN25KisResourceServerProvider8instanceEv+0x4e) [0xb7d2363e] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7dc53b6] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7cb263d] /home/boud/kde/inst/lib/libkritaui.so.6 [0xb7cb3067] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN8KisView29createGUIEv+0x1fd) [0xb7d3d07d] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN8KisView2C1EP7KisDoc2P7QWidget+0x4e8) [0xb7d40e68] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN7KisDoc218createViewInstanceEP7QWidget+0x3e) [0xb7cc0abe] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument10createViewEP7QWidget+0x21) [0xb76c1081] /home/boud/kde/inst/lib/libkomain.so.6(_ZN12KoMainWindow15setRootDocumentEP10KoDocument+0x353) [0xb76eed53] /home/boud/kde/inst/lib/libkomain.so.6(_ZN10KoDocument17showStartUpWidgetEP12KoMainWindowb+0x27c) [0xb76cbc9c] /home/boud/kde/inst/lib/libkomain.so.6(_ZN13KoApplication5startEv+0xcc2) [0xb76b4c52] Mutex #2229 (0x0x804dea8) first referenced by: /usr/local/lib/libmutrace.so(pthread_mutex_lock+0x58) [0xb80a4108] /usr/lib/libQtCore.so.4 [0xb7eadad7] /usr/lib/libQtCore.so.4(_ZN6QMutex4lockEv+0xfd) [0xb7ea918d] /usr/lib/libQtCore.so.4(_ZN19QAbstractFileEngine6createERK7QString+0x248) [0xb7f245d8] /usr/lib/libQtCore.so.4 [0xb7f39510] /usr/lib/libkdecore.so.5 [0xb6742246] /usr/lib/libkdecore.so.5 [0xb673b7a0] /usr/lib/libkdecore.so.5(_ZN8KLibraryC1ERK7QStringRK14KComponentDataP7QObject+0x36) [0xb673bb96] /usr/lib/libkdecore.so.5(_ZN10KLibLoader7libraryERK7QString6QFlagsIN8QLibrary8LoadHintEE+0x68) [0xb673afc8] /home/boud/kde/inst/lib/libkoplugin.so.6(_ZN14KoPluginLoader4loadERK7QStringS2_RKNS_13PluginsConfigE+0x1383) [0xb70c3703] /home/boud/kde/inst/lib/libkritaimage.so.6(_ZN18KisPaintOpRegistry8instanceEv+0xc6) [0xb7aae8a6] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN11KisFactory213componentDataEv+0x225) [0xb7cc8475] /home/boud/kde/inst/lib/libkritaui.so.6(_ZN11KisFactory2C1EP7QObject+0x51) [0xb7cc8d61] mutrace: Showing 10 most contended mutexes: Mutex # Locked Changed Cont. tot.Time[ms] avg.Time[ms] max.Time[ms] Flag 289 2728870 222349 143464 5590.908 0.002 5.469 x.-- 1354 2445278 1009 315 5576.579 0.002 12.141 -.-- 1002 4812 464 259 9.827 0.002 0.134 -.-- 83 2743 110 46 6.286 0.002 0.022 -.-- 1968 817 136 27 1.725 0.002 0.012 -.-- 798 249 174 12 1.235 0.005 0.056 -.-- 2002 2079 110 10 4.077 0.002 0.007 -.-- 2583 341 219 8 1.198 0.004 0.060 -.-- 176 41 31 5 0.157 0.004 0.011 -.-- 2229 11 8 4 0.034 0.003 0.007 -.-- ... ... ... ... ... ... ... |||| /||| State: x = dead, ! = inconsistent /|| Use: R = used in realtime thread /| Type: r = RECURSIVE, e = ERRRORCHECK, a = ADAPTIVE / Protocol: i = INHERIT, p = PROTECT mutrace: Note that the flags column R is only valid in --track-rt mode! mutrace: Total runtime is 61917.355 ms. mutrace: WARNING: 99 internal hash collisions detected. Results might not be as reliable as they could be. mutrace: Try to increase --hash-size=, which is currently at 40000. I think this tool should be able to help us a lot! This is with the old tile engine, and as you can see the contention for the Great Big Krita Lock is really high and completely kills us. We knew it was bad of course, but now we've been able to measure it! I'm going to retry with the new tile engine now. -- Boudewijn Rempt | http://www.valdyas.org _______________________________________________ kimageshop mailing list kimageshop@kde.org https://mail.kde.org/mailman/listinfo/kimageshop