[Development] QML instantiation performance
Gunnar Roth
gunnar.roth at gmx.de
Thu Dec 4 13:42:07 CET 2014
Hi Chris, i can give you a callstack, but that will take some time.
But what about the "QQml_removeValueTypeProvider: was asked to remove provider 0x2b4c2ac but it was not found"
messages? Don't you get that with 5.4? Did you change something in your patch for 5.4?
Gesendet: Donnerstag, 04. Dezember 2014 um 05:46 Uhr
Von: "Chris Adams" <chris.adams at qinetic.com.au>
An: "Gunnar Roth" <gunnar.roth at gmx.de>
Cc: "Simon Hausmann" <simon.hausmann at theqtcompany.com>, "development at qt-project.org" <development at qt-project.org>
Betreff: Re: Re: [Development] QML instantiation performance
Hi Gunnar,
Can you get a backtrace which might help pinpoint what's causing it?I've integrated the patch to 5.4, and it passed CI, so at least in the CI environments it's not crashing, I think.I don't have a windows 5.4 build to test against, currently, so I'm not sure what could cause the problem.
Cheers,
Chris.
www.qinetic.com.au[http://www.qinetic.com.au] - Qt And QML User Experience Specialists
On Tue, Dec 2, 2014 at 8:26 PM, Gunnar Roth <gunnar.roth at gmx.de[gunnar.roth at gmx.de]> wrote:
Hi Chris,
i tried your patch with 5.4rc1 as i am working on that.
i get erros like
nfig: Using QtTest library 5.4.0, Qt 5.4.0 (i386-little_endian-ilp32 shared (dynamic) release build; by MSVC 2012)
PASS : tst_librarymetrics_performance::initTestCase()
QWARN : tst_librarymetrics_performance::compilation(001) item - empty) QQml_removeValueTypeProvider: was asked to remove provider 0x2b4c2ac but it was not found
on each test case until it crashes after
tst_librarymetrics_performance::instantiation_cached(014) item - initialised Item prop (with child)) QQml_removeValueTypeProvider: was asked to remove provider 0xf82c2ac but it was not found
the patch i used is this:
diff -r -U 5 -N -x doc -x test -x 'qquickrectangle*' D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/imports/qtquick2/plugin.cpp qtdeclarative\src/imports/qtquick2/plugin.cpp
--- D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/imports/qtquick2/plugin.cpp 2014-11-24 16:01:09.000000000 +0100
+++ qtdeclarative\src/imports/qtquick2/plugin.cpp 2014-12-01 17:28:57.174986000 +0100
@@ -47,10 +47,15 @@
{
Q_ASSERT(QLatin1String(uri) == QLatin1String("QtQuick"));
Q_UNUSED(uri);
QQmlQtQuick2Module::defineModule();
}
+
+ ~QtQuick2Plugin()
+ {
+ QQmlQtQuick2Module::undefineModule();
+ }
};
//![class decl]
QT_END_NAMESPACE
diff -r -U 5 -N -x doc -x test -x 'qquickrectangle*' D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/qml/compiler/qqmltypecompiler.cpp qtdeclarative\src/qml/compiler/qqmltypecompiler.cpp
--- D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/qml/compiler/qqmltypecompiler.cpp 2014-11-24 16:01:06.000000000 +0100
+++ qtdeclarative\src/qml/compiler/qqmltypecompiler.cpp 2014-12-01 17:30:40.223986000 +0100
@@ -1387,11 +1387,11 @@
}
if (!mo)
continue;
- static QQmlType *componentType = QQmlMetaType::qmlType(&QQmlComponent::staticMetaObject);
+ QQmlType *componentType = QQmlMetaType::qmlType(&QQmlComponent::staticMetaObject);
Q_ASSERT(componentType);
QmlIR::Object *syntheticComponent = pool->New<QmlIR::Object>();
syntheticComponent->init(pool, compiler->registerString(QString::fromUtf8(componentType->typeName())), compiler->registerString(QString()));
syntheticComponent->location = binding->valueLocation;
diff -r -U 5 -N -x doc -x test -x 'qquickrectangle*' D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/qtquick2.cpp qtdeclarative\src/quick/qtquick2.cpp
--- D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/qtquick2.cpp 2014-11-24 16:01:08.000000000 +0100
+++ qtdeclarative\src/quick/qtquick2.cpp 2014-12-01 17:32:06.715986000 +0100
@@ -192,7 +192,12 @@
new QQmlQtQuick2DebugStatesDelegate);
QQuickProfiler::initialize();
}
}
+void QQmlQtQuick2Module::undefineModule()
+{
+ QQuick_deinitializeProviders();
+}
+
QT_END_NAMESPACE
diff -r -U 5 -N -x doc -x test -x 'qquickrectangle*' D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/qtquick2_p.h qtdeclarative\src/quick/qtquick2_p.h
--- D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/qtquick2_p.h 2014-11-24 16:01:07.000000000 +0100
+++ qtdeclarative\src/quick/qtquick2_p.h 2014-12-01 17:32:46.839986000 +0100
@@ -40,10 +40,11 @@
class Q_QUICK_PRIVATE_EXPORT QQmlQtQuick2Module
{
public:
static void defineModule();
+ static void undefineModule();
};
QT_END_NAMESPACE
#endif // QTQUICK2_P_H
diff -r -U 5 -N -x doc -x test -x 'qquickrectangle*' D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/qtquickglobal_p.h qtdeclarative\src/quick/qtquickglobal_p.h
--- D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/qtquickglobal_p.h 2014-11-24 16:01:08.000000000 +0100
+++ qtdeclarative\src/quick/qtquickglobal_p.h 2014-12-01 17:33:21.893986000 +0100
@@ -52,10 +52,11 @@
#define Q_QUICK_PRIVATE_EXPORT Q_QUICK_EXPORT
QT_BEGIN_NAMESPACE
void QQuick_initializeProviders();
+void QQuick_deinitializeProviders();
Q_DECLARE_LOGGING_CATEGORY(DBG_TOUCH)
Q_DECLARE_LOGGING_CATEGORY(DBG_MOUSE)
Q_DECLARE_LOGGING_CATEGORY(DBG_FOCUS)
Q_DECLARE_LOGGING_CATEGORY(DBG_DIRTY)
diff -r -U 5 -N -x doc -x test -x 'qquickrectangle*' D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/util/qquickglobal.cpp qtdeclarative\src/quick/util/qquickglobal.cpp
--- D:\Temp\qt-everywhere-opensource-src-5.4.0-rc\qtdeclarative\src/quick/util/qquickglobal.cpp 2014-11-24 16:01:08.000000000 +0100
+++ qtdeclarative\src/quick/util/qquickglobal.cpp 2014-12-01 17:44:37.800986000 +0100
@@ -980,6 +980,13 @@
QQml_addValueTypeProvider(getValueTypeProvider());
QQml_setColorProvider(getColorProvider());
QQml_setGuiProvider(getGuiProvider());
}
+void QQuick_deinitializeProviders()
+{
+ QQml_removeValueTypeProvider(getValueTypeProvider());
+ QQml_setColorProvider(0); // the only accessor is Q_AUTOTEST_EXPORT, so....
+ QQml_setGuiProvider(0);
+}
+
QT_END_NAMESPACE
Gesendet: Montag, 01. Dezember 2014 um 05:51 Uhr
Von: "Chris Adams" <chris.adams at qinetic.com.au[chris.adams at qinetic.com.au]>
An: "Simon Hausmann" <simon.hausmann at theqtcompany.com[simon.hausmann at theqtcompany.com]>
Cc: "development at qt-project.org[development at qt-project.org]" <development at qt-project.org[development at qt-project.org]>
Betreff: Re: [Development] QML instantiation performance
See https://codereview.qt-project.org/#/c/101048/[https://codereview.qt-project.org/#/c/101048/] - huge thanks to Matt Vogt for his help with debugging and fixing the issues.Juha, does that resolve the issues for you? Gunnar Roth, does that fix the issues on Windows? I haven't tested there.
www.qinetic.com.au[http://www.qinetic.com.au] - Qt And QML User Experience Specialists
On Mon, Dec 1, 2014 at 2:16 PM, Chris Adams <chris.adams at qinetic.com.au[http://chris.adams@qinetic.com.au]> wrote:
The loop was due to the QtQuick2 plugin's defineModule() code initializing the value type providers on load, but not deinitializing them on dtor, resulting in future loads of that plugin adding the same ptr to the linked list as the head's next ptr (so, cycle).The attached diff fixes that issue, but has unmasked at least one further crash which also seems related to the qmlClearTypeRegistrations function.
I'll see if I can trace it further, and push something to Gerrit later in the week.
Cheers,
Chris.
www.qinetic.com.au[http://www.qinetic.com.au] - Qt And QML User Experience Specialists
On Fri, Nov 28, 2014 at 5:39 PM, Simon Hausmann <simon.hausmann at theqtcompany.com[http://simon.hausmann@theqtcompany.com]> wrote:
On Friday 28. November 2014 12.20.29 Chris Adams wrote:
> Hi,
>
> No worries. Interestingly, when I ran the benchmark against 5.3, I found
> that it hangs after performing several tests.
>
> Before each test, the benchmark will clear the QML type registrations to
> ensure that the cached compiled type data isn't re-used during the run,
> tainting the results. It appears that if the call to
> qmlClearTypeRegistrations() is commented out, the benchmark runs all the
> way through (but obviously, with tainted / useless results). With that
> call left in, it hangs, with CPU spinning at 100%, while trying to load a
> component:
>
> (gdb) t a a bt
>
> Thread 290 (Thread 0x7fffee1ba700 (LWP 14829)):
> #0 0x00007fffec1f7c56 in QQuickValueTypeProvider::create
> (this=0x7fffec7b3980 <getValueTypeProvider()::valueTypeProvider>,
> type=1037, v=
> @0x7fffee1b9080: 0x0) at util/qquickglobal.cpp:404
> #1 0x00007ffff795813f in QQmlValueTypeProvider::createValueType
> (this=0x7fffec7b3980 <getValueTypeProvider()::valueTypeProvider>, type=1037)
> at qml/qqmlglobal.cpp:67
> #2 0x00007ffff7914d41 in (anonymous
> namespace)::QQmlValueTypeFactoryImpl::createValueType (
> this=0x7ffff7dd7340 <(anonymous
> namespace)::Q_QGS_factoryImpl::innerFunction()::holder>, t=1037) at
> qml/qqmlvaluetype.cpp:121
> #3 0x00007ffff7914e21 in (anonymous
> namespace)::QQmlValueTypeFactoryImpl::valueType (
> this=0x7ffff7dd7340 <(anonymous
> namespace)::Q_QGS_factoryImpl::innerFunction()::holder>, idx=1037) at
> qml/qqmlvaluetype.cpp:137
> #4 0x00007ffff7915006 in QQmlValueTypeFactory::valueType (idx=1037) at
> qml/qqmlvaluetype.cpp:169
> #5 0x00007ffff7767d09 in QQmlPropertyValidator::validateObject
> (this=0x7fffee1b9580, objectIndex=0, instantiatingBinding=0x0,
> populatingValueTypeGroupProperty=false) at
> compiler/qqmltypecompiler.cpp:1912
> #6 0x00007ffff7766c6f in QQmlPropertyValidator::validate
> (this=0x7fffee1b9580) at compiler/qqmltypecompiler.cpp:1730
> #7 0x00007ffff775f676 in QQmlTypeCompiler::compile (this=0x7fffee1b96f0)
> at compiler/qqmltypecompiler.cpp:265
> #8 0x00007ffff7904370 in QQmlTypeData::compile (this=0x7dc4b0) at
> qml/qqmltypeloader.cpp:2341
> #9 0x00007ffff7903081 in QQmlTypeData::done (this=0x7dc4b0) at
> qml/qqmltypeloader.cpp:2164
> #10 0x00007ffff78fc2b0 in QQmlDataBlob::tryDone (this=0x7dc4b0) at
> qml/qqmltypeloader.cpp:615
> #11 0x00007ffff78fdf56 in QQmlDataLoader::setData (this=0x7d5b48,
> blob=0x7dc4b0, d=...) at qml/qqmltypeloader.cpp:1208
> #12 0x00007ffff78fde44 in QQmlDataLoader::setData (this=0x7d5b48,
> blob=0x7dc4b0, file=0x7fffee1b9910) at qml/qqmltypeloader.cpp:1190
> #13 0x00007ffff78fd683 in QQmlDataLoader::loadThread (this=0x7d5b48,
> blob=0x7dc4b0) at qml/qqmltypeloader.cpp:1068
> #14 0x00007ffff78fcb03 in QQmlDataLoaderThread::loadThread (this=0x751b90,
> b=0x7dc4b0) at qml/qqmltypeloader.cpp:816
> #15 0x00007ffff7908121 in void
> QQmlThread::callMethodInThread<QQmlDataBlob*, QQmlDataBlob*,
> QQmlDataLoaderThread>(void (QQmlDataLoaderThread::*)(QQmlDataBlob*),
> QQmlDataBlob* const&)::I::call(QQmlThread*) (this=0x7dc7b0, thread=0x751b90)
> at
> /home/chriadam/Code/qt/qt5/qtbase/include/QtQml/5.3.2/QtQml/private/../../..
> /../../../qtdeclarative/src/qml/qml/ftw/qqmlthread_p.h:160 #16
> 0x00007ffff7973eee in QQmlThreadPrivate::threadEvent (this=0x729cd0) at
> qml/ftw/qqmlthread.cpp:198
> #17 0x00007ffff7973c76 in QQmlThreadPrivate::event (this=0x729cd0,
> e=0x7dc7e0) at qml/ftw/qqmlthread.cpp:136
> #18 0x00007ffff6619936 in QCoreApplicationPrivate::notify_helper
> (this=0x60be80, receiver=0x729cd0, event=0x7dc7e0) at
> kernel/qcoreapplication.cpp:1052
> #19 0x00007ffff6619618 in QCoreApplication::notify (this=0x7fffffffdd10,
> receiver=0x729cd0, event=0x7dc7e0) at kernel/qcoreapplication.cpp:997
> #20 0x00007ffff6c7a83c in QGuiApplication::notify (this=0x7fffffffdd10,
> object=0x729cd0, event=0x7dc7e0) at kernel/qguiapplication.cpp:1477
> #21 0x00007ffff6619522 in QCoreApplication::notifyInternal
> (this=0x7fffffffdd10, receiver=0x729cd0, event=0x7dc7e0) at
> kernel/qcoreapplication.cpp:935
> #22 0x00007ffff661d0af in QCoreApplication::sendEvent (receiver=0x729cd0,
> event=0x7dc7e0)
> at ../../include/QtCore/../../src/corelib/kernel/qcoreapplication.h:237
> #23 0x00007ffff661a7ed in QCoreApplicationPrivate::sendPostedEvents
> (receiver=0x0, event_type=0, data=0x6ce920) at
> kernel/qcoreapplication.cpp:1539
> #24 0x00007ffff668bf85 in QEventDispatcherUNIX::processEvents
> (this=0x7fffe0183690, flags=...) at kernel/qeventdispatcher_unix.cpp:587
> #25 0x00007ffff66162c2 in QEventLoop::processEvents (this=0x7fffee1b9dd0,
> flags=...) at kernel/qeventloop.cpp:136
> #26 0x00007ffff6616583 in QEventLoop::exec (this=0x7fffee1b9dd0, flags=...)
> at kernel/qeventloop.cpp:212
> #27 0x00007ffff63a46ce in QThread::exec (this=0x729cd0) at
> thread/qthread.cpp:511
> #28 0x00007ffff7973ce7 in QQmlThreadPrivate::run (this=0x729cd0) at
> qml/ftw/qqmlthread.cpp:149
> #29 0x00007ffff63ab9c9 in QThreadPrivate::start (arg=0x729cd0) at
> thread/qthread_unix.cpp:345
> ---Type <return> to continue, or q <return> to quit---
> #30 0x00007ffff54aa182 in start_thread (arg=0x7fffee1ba700) at
> pthread_create.c:312
> #31 0x00007ffff5b1530d in clone () at
> ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
>
> Thread 2 (Thread 0x7fffef01f700 (LWP 14532)):
> #0 0x00007ffff5b07fbd in poll () at ../sysdeps/unix/syscall-template.S:81
> #1 0x00007ffff16d6b72 in poll (__timeout=-1, __nfds=1,
> __fds=0x7fffef01ecc0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
> #2 _xcb_conn_wait (c=c at entry=0x658740, cond=cond at entry=0x658780,
> vector=vector at entry=0x0, count=count at entry=0x0) at ../../src/xcb_conn.c:447
> #3 0x00007ffff16d864f in xcb_wait_for_event (c=0x658740) at
> ../../src/xcb_in.c:622
> #4 0x00007ffff0cb5a79 in QXcbEventReader::run (this=0x6663a0) at
> qxcbconnection.cpp:1043
> #5 0x00007ffff63ab9c9 in QThreadPrivate::start (arg=0x6663a0) at
> thread/qthread_unix.cpp:345
> #6 0x00007ffff54aa182 in start_thread (arg=0x7fffef01f700) at
> pthread_create.c:312
> #7 0x00007ffff5b1530d in clone () at
> ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
>
> Thread 1 (Thread 0x7ffff7fca7c0 (LWP 14524)):
> #0 pthread_cond_wait@@GLIBC_2.3.2 () at
> ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
> #1 0x00007ffff63ad096 in QWaitConditionPrivate::wait (this=0x6b6d00,
> time=18446744073709551615) at thread/qwaitcondition_unix.cpp:136
> #2 0x00007ffff63ace69 in QWaitCondition::wait (this=0x729d48,
> mutex=0x729d40, time=18446744073709551615) at
> thread/qwaitcondition_unix.cpp:208
> #3 0x00007ffff79747ba in QQmlThreadPrivate::wait (this=0x729cd0) at
> qml/ftw/qqmlthread.cpp:64
> #4 0x00007ffff7974409 in QQmlThread::internalCallMethodInThread
> (this=0x751b90, message=0x7dc7b0) at qml/ftw/qqmlthread.cpp:319
> #5 0x00007ffff790817c in QQmlThread::callMethodInThread<QQmlDataBlob*,
> QQmlDataBlob*, QQmlDataLoaderThread> (this=0x751b90, Member=
> (void (QQmlDataLoaderThread::*)(QQmlDataLoaderThread * const,
> QQmlDataBlob *)) 0x7ffff78fcadc
> <QQmlDataLoaderThread::loadThread(QQmlDataBlob*)>,
> arg=@0x7fffffffce00: 0x7dc4b0)
> at
> /home/chriadam/Code/qt/qt5/qtbase/include/QtQml/5.3.2/QtQml/private/../../..
> /../../../qtdeclarative/src/qml/qml/ftw/qqmlthread_p.h:163 #6
> 0x00007ffff78fc7ab in QQmlDataLoaderThread::load (this=0x751b90,
> b=0x7dc4b0) at qml/qqmltypeloader.cpp:761
> #7 0x00007ffff78fcebb in QQmlDataLoader::load (this=0x7d5b48,
> blob=0x7dc4b0, mode=QQmlDataLoader::PreferSynchronous) at
> qml/qqmltypeloader.cpp:936
> #8 0x00007ffff78ffe95 in QQmlTypeLoader::getType (this=0x7d5b48, url=...,
> mode=QQmlDataLoader::PreferSynchronous) at qml/qqmltypeloader.cpp:1606
> #9 0x00007ffff78dedb0 in QQmlComponentPrivate::loadUrl (this=0x7cb9b0,
> newUrl=..., mode=QQmlComponent::PreferSynchronous) at
> qml/qqmlcomponent.cpp:691
> #10 0x00007ffff78deaba in QQmlComponent::loadUrl (this=0x7fffffffd0a0,
> url=...) at qml/qqmlcomponent.cpp:648
> #11 0x00000000004040e0 in tst_librarymetrics_performance::compilation() ()
> #12 0x00007ffff66256c1 in QMetaMethod::invoke (this=0x7fffffffd3b0,
> object=0x7fffffffdd20, connectionType=Qt::DirectConnection,
> returnValue=...,
> val0=..., val1=..., val2=..., val3=..., val4=..., val5=..., val6=...,
> val7=..., val8=..., val9=...) at kernel/qmetaobject.cpp:2169
> #13 0x00007ffff6624b99 in QMetaObject::invokeMethod (obj=0x7fffffffdd20,
> member=0x7a3ba0 "compilation", type=Qt::DirectConnection, ret=...,
> val0=...,
> val1=..., val2=..., val3=..., val4=..., val5=..., val6=..., val7=...,
> val8=..., val9=...) at kernel/qmetaobject.cpp:1464
> #14 0x00007ffff73d6c21 in QMetaObject::invokeMethod (obj=0x7fffffffdd20,
> member=0x7a3ba0 "compilation", type=Qt::DirectConnection, val0=...,
> val1=...,
> val2=..., val3=..., val4=..., val5=..., val6=..., val7=..., val8=...,
> val9=...) at ../../include/QtCore/../../src/corelib/kernel/qobjectdefs.h:399
> #15 0x00007ffff73d26d4 in QTest::qInvokeTestMethodDataEntry (slot=0x7a3ba0
> "compilation") at qtestcase.cpp:1890
> #16 0x00007ffff73d2f64 in QTest::qInvokeTestMethod (slotName=0x7a4d48
> "compilation()", data=0x0) at qtestcase.cpp:2015
> #17 0x00007ffff73d3a81 in QTest::qInvokeTestMethods
> (testObject=0x7fffffffdd20) at qtestcase.cpp:2242
> #18 0x00007ffff73d4047 in QTest::qExec (testObject=0x7fffffffdd20, argc=1,
> argv=0x7fffffffde38) at qtestcase.cpp:2475
> #19 0x00000000004025c4 in main ()
>
> It appears that the QQuickValueTypeProvider instances are continuously
> recreated (spinning at 100% and locking the incubator thread, which the
> main thread is waiting on). Lars or Simon, are you able to guess what
> might cause this issue? The implementation of qmlClearTypeRegistrations
> seems fairly straightforward, but my memory of the complexities of value
> type providers is hazy.
Something looks fishy there :)
The backtrace makes sense, but it shouldn't repeatedly end up in there. The
last line number in question is a return statement for me. What is it in your
source tree?
Can you try to step and see where the loop header is?
Simon_______________________________________________ Development mailing list Development at qt-project.org[Development at qt-project.org] http://lists.qt-project.org/mailman/listinfo/development
More information about the Development
mailing list