PyOtherSide crashes with Qt 5.4 & Python 3 on Fedora 21 when starting modRana

[M4rtinK]

The crash manifests as a qmlscene segfault ( Segmentation fault (core dumped) ) during modRana startup. It appears to be caused by some sort of a race condition as it does not appear consistently (sometime modRana does survive the startup) and seems to be influenced by the speed of the computer it is running on. On fast modern computers it crashes in about 80% cases, on older PC-class hardware the crashes happen much less often (about 1-2 crashes in 10 starts). So even though I have not yet seen this happen on Sailfish OS, it might very well just be prevented by the longer time modRana takes to start on the Jolla.

I've reproduced the issues on different Fedora 21 versions to exclude the chance that some stuff specific to my computer is influencing the crashes. This includes a fresh baremetal Fedora 21 installation.

The following steps can be used to reproduce the issue:

sudo dnf install python3-devel qt5-qtdeclarative qt5-qtcontrols qt5-qtsensors git  (if starting on a fresh F21 install) 
git clone https://github.com/thp/pyotherside
git clone https://github.com/M4rtinK/modrana
cd pyotherside
git checkout 5b76536332f6b442f6e3d6310c72e7ab2c63451c
qmake-qt5
make
make install
cd ../modrana/run
git checkout 2021c12d2973ad9321e3d8f45727dfd00256f005
./qt5.sh

It might be needed to start modRana a few times to trigger the crash, especially on slower hardware. :)

Additional information

This shows up in the log:

led 20 21:40:13 hostname kernel: qmlscene-qt5[4694]: segfault at 0 ip 0000003f26eb09e8 sp 00007ffff1c67470 error 4 in libQt5Qml.so.5.4.0[3f26c00000+408000]

And this is the core_backtrace as generated by abrt for one if these crashes: http://paste.fedoraproject.org/172171/14217874

Please let me know if you need any more information to debug this. :)

UPDATE 10. 2. 2015 Added checkout of a specific commits for PyOtherSide and modRana to make sure that the reproducer is deterministic.

[danvratil]

I think we managed to trace the problem to QVariantConverter::type(), because when extracting the QJSValue from QVariant (v.value()) and then converting it to QVariant, this can actually call some internals of QML engine:

#0  0x00000032474348c7 in raise () at /lib64/libc.so.6
#1  0x000000324743652a in abort () at /lib64/libc.so.6
#2  0x00007ffff5e56db9 in qt_message_fatal(QtMsgType, QMessageLogContext const&, QString const&) (context=..., message="ASSERT: \"o\" in file /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/qml/v8/qv8engine.cpp, line 243") at /home/dvratil/devel/Qt/qt5/qtbase/src/corelib/global/qlogging.cpp:1411
#3  0x00007ffff5e537e8 in QMessageLogger::fatal(char const*, ...) const (this=0x7fffe0f72020, msg=0x7ffff6166210 "ASSERT: \"%s\" in file %s, line %d")
at /home/dvratil/devel/Qt/qt5/qtbase/src/corelib/global/qlogging.cpp:636
#4  0x00007ffff5e4d7b2 in qt_assert(char const*, char const*, int) (assertion=0x7ffff6a32898 "o", file=0x7ffff6a32840 "/home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/qml/v8/qv8engine.cpp", line=243)
at /home/dvratil/devel/Qt/qt5/qtbase/src/corelib/global/qglobal.cpp:2810
#5  0x00007ffff68f32aa in QV8Engine::toVariant(QV4::ValueRef, int, bool, QSet<QV4::Object*>*) (this=0xdd0b50, value=..., typeHint=-1, createJSValueForObjects=false, visitedObjects=0x7fffe0f72760)
at /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/qml/v8/qv8engine.cpp:243
#6  0x00007ffff68f3678 in QV8Engine::objectToVariant(QV4::Object*, QSet<QV4::Object*>*) (this=0xdd0b50, o=0x7fffec02bae0, visitedObjects=0x7fffe0f72760)
at /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/qml/v8/qv8engine.cpp:282
#7  0x00007ffff68f33ae in QV8Engine::toVariant(QV4::ValueRef, int, bool, QSet<QV4::Object*>*) (this=0xdd0b50, value=..., typeHint=-1, createJSValueForObjects=false, visitedObjects=0x7fffe0f72760)
at /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/qml/v8/qv8engine.cpp:251
#8  0x00007ffff68f3678 in QV8Engine::objectToVariant(QV4::Object*, QSet<QV4::Object*>*) (this=0xdd0b50, o=0x7fffec02bb00, visitedObjects=0x7fffe0f72760)
at /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/qml/v8/qv8engine.cpp:282
#9  0x00007ffff68f33ae in QV8Engine::toVariant(QV4::ValueRef, int, bool, QSet<QV4::Object*>*) (this=0xdd0b50, value=..., typeHint=-1, createJSValueForObjects=false, visitedObjects=0x0)
at /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/qml/v8/qv8engine.cpp:251
#10 0x00007ffff67cca0a in QV4::VariantObject::toVariant(QV4::ValueRef) (v=...) at /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/jsruntime/qv4variantobject.cpp:62
#11 0x00007ffff66ec280 in QJSValue::toVariant() const (this=0x7fffe0f72ad0) at /home/dvratil/devel/Qt/qt5/qtdeclarative/src/qml/jsapi/qjsvalue.cpp:523
#12 0x00007fffe19d0601 in QVariantConverter::list(QVariant&) (this=0x7fffe0f72b70, v=...) at qvariant_converter.h:165
#13 0x00007fffe19d1e59 in convert<QVariant, _object*, QVariantConverter, PyObjectConverter>(QVariant) (from=...) at converter.h:162
#14 0x00007fffe19d0edc in convertQVariantToPyObject(QVariant) (v=...) at qml_python_bridge.h:28
#15 0x00007fffe19d8c5a in QPythonPriv::call(_object*, QString, QVariant, QVariant*) (this=0xee5250, callable=0x7fffe01c39d8, name="modrana.start", args=..., v=0x7fffe0f72e10) at qpython_priv.cpp:701
#16 0x00007fffe19ccff6 in QPython::call_sync(QVariant, QVariant) (this=0xddb840, func=..., args=...) at qpython.cpp:279
#17 0x00007fffe19d56a3 in QPythonWorker::process(QVariant, QVariant, QJSValue*) (this=0xeddaa0, func=..., args=..., callback=0x29360a0) at qpython_worker.cpp:37
...
...

Since the QVariantConverter is being executed in QPythonWorker thread context, the code ends up touching QML engine from non-GUI thread and thus messing things up, leading to crash.

We tried to move the conversion to the GUI thread and pass the PyObjectRef to QPythonWorker, unfortunately that causes crash in Python, probably because we are calling Python from different thread than QPythonWorker.

[thp]

This should be fixed with the unboxing patch merged.