search

mixxxdj / mixxx

Mixxx is Free DJ software that gives you everything you need to perform live mixes.
http://mixxx.org
Other
4.55k stars 1.29k forks source link

SIGSEGV on controller thread when enabling a MIDI controller on Mixxx 2.4 #12001

Closed napaalm closed 11 months ago

napaalm commented 1 year ago

Bug Description

A build of Mixxx from the 2.4 branch (at c10475209a0c22075f4f720aaf9a0aea89e62a0b) crashes during startup if my controller (an Hercules DJControl Starlight) is enabled. The same crash happens if the controller is disabled and then I enable it in the preferences menu.

The following is a backtrace from a debug build. Unfortunately the full backtrace exceeds the 65535 character limit, so I tried to omit the irrelevant parts. Let me know if you need something else.

$ gdb --args ./mixxx --debugAssertBreak --controllerDebug --developer
QML debugging is enabled. Only use this in a safe environment.
Using preferences ScaleFactor 1
Loading resources from  "/home/antonio/code/mixxx/res/"
Configuration file is at the current version "2.4.0-beta"
[...]
[New Thread 0x7ffecb02b6c0 (LWP 25537)]
 controller.djcontrolstarlightmidi1:info [Controller] PortMidiController: Opening DJControl Starlight MIDI 1 index 5 for input
 controller.djcontrolstarlightmidi1:info [Controller] PortMidiController: Opening DJControl Starlight MIDI 1 index 4 for output
 controller.djcontrolstarlightmidi1:info [Controller]   Starting engine
 controller.djcontrolstarlightmidi1:info [Controller] Applying controller mapping...
[New Thread 0x7ffeca82a6c0 (LWP 25538)]
[New Thread 0x7ffeca0296c0 (LWP 25539)]
[New Thread 0x7ffec94286c0 (LWP 25540)]

Thread 53 "Controller" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fff27fff6c0 (LWP 25513)]
0x00007ffff6aa7028 in WTF::OSAllocator::reserveUncommitted (usage=WTF::OSAllocator::JSGCHeapPages, writable=true, executable=false,
    bytes=4194304) at /usr/src/debug/qt5-declarative/qtdeclarative/src/3rdparty/masm/wtf/OSAllocatorPosix.cpp:113
113         CRASH();
(gdb) set height 0
(gdb) thread apply all bt full
[...]
Thread 53 (Thread 0x7fff27fff6c0 (LWP 25513) "Controller"):
#0  0x00007ffff6aa7028 in WTF::OSAllocator::reserveUncommitted(unsigned long, WTF::OSAllocator::Usage, bool, bool) (usage=WTF::OSAllocator::JSGCHeapPages, writable=true, executable=false, bytes=4194304) at /usr/src/debug/qt5-declarative/qtdeclarative/src/3rdparty/masm/wtf/OSAllocatorPosix.cpp:113
        fd = 96
        result = 0x7ffec9429000
        c = 0xbbadbeef
#1  WTF::PageReservation::reserve(unsigned long, WTF::OSAllocator::Usage, bool, bool) (usage=WTF::OSAllocator::JSGCHeapPages, writable=true, executable=false, size=4194304) at /usr/src/debug/qt5-declarative/qtdeclarative/src/3rdparty/masm/wtf/PageReservation.h:107
        c = 0xbbadbeef
#2  QV4::MemorySegment::MemorySegment(unsigned long) (size=4194304, this=<optimized out>) at /usr/src/debug/qt5-declarative/qtdeclarative/src/qml/memory/qv4mm.cpp:129
        c = 0xbbadbeef
#3  QV4::ChunkAllocator::allocate(unsigned long) (this=0x7fff1c06d2a0, size=65536, size@entry=0) at /usr/src/debug/qt5-declarative/qtdeclarative/src/qml/memory/qv4mm.cpp:264
        c = 0xbbadbeef
#4  0x00007ffff6ab01fe in QV4::BlockAllocator::allocate(unsigned long, bool) (this=0x7fff1c033ba8, size=<optimized out>, forceAllocation=<optimized out>) at /usr/src/debug/qt5-declarative/qtdeclarative/src/qml/memory/qv4mm.cpp:600
        newChunk = <optimized out>
        slotsRequired = 4
        last = <optimized out>
        m = 0x0
#5  0x00007ffff6b099b0 in QV4::MemoryManager::allocIC<QV4::InternalClass>() (this=<optimized out>) at ../../include/QtQml/5.15.10/QtQml/private/../../../../../../qtdeclarative/src/qml/memory/qv4mm_p.h:271
        b = <optimized out>
        scope = {engine = <optimized out>, mark = <optimized out>}
        ic = {ptr = 0x7fff1c00cc10}
        addProtoHasInstance = {<No data fields>}
        str = {ptr = 0x7ffff2ec7fec <QObject::QObject(QObjectPrivate&, QObject*)+220>}
        t = {ptr = <optimized out>}
        envMaxGCStackSize = <optimized out>
        ok = false
        envMaxJSStackSize = <optimized out>
        argsClass = {ptr = 0xfffffffffffffea8}
        index = 0x7fff1c000030
        global = <optimized out>
        numberObject = <optimized out>
        o = {ptr = <optimized out>}
        pd = {property = 0x7fff1c0389d0}
#6  QV4::ExecutionEngine::ExecutionEngine(QJSEngine*) (this=this@entry=0x7fff1c048c80, jsEngine=jsEngine@entry=0x7fff1c0389d0, this=<optimized out>, jsEngine=<optimized out>) at /usr/src/debug/qt5-declarative/qtdeclarative/src/qml/jsruntime/qv4engine.cpp:368
        scope = {engine = <optimized out>, mark = <optimized out>}
        ic = {ptr = 0x7fff1c00cc10}
        addProtoHasInstance = {<No data fields>}
        str = {ptr = 0x7ffff2ec7fec <QObject::QObject(QObjectPrivate&, QObject*)+220>}
        t = {ptr = <optimized out>}
        envMaxGCStackSize = <optimized out>
        ok = false
        envMaxJSStackSize = <optimized out>
        argsClass = {ptr = 0xfffffffffffffea8}
        index = 0x7fff1c000030
        global = <optimized out>
        numberObject = <optimized out>
        o = {ptr = <optimized out>}
        pd = {property = 0x7fff1c0389d0}
#7  0x00007ffff6b03e55 in QJSEngine::QJSEngine(QObject*) (this=0x7fff1c0389d0, parent=0x7fff1c022d50, this=<optimized out>, parent=<optimized out>) at /usr/src/debug/qt5-declarative/qtdeclarative/src/qml/jsapi/qjsengine.cpp:343
#8  0x0000555555ab410a in std::_Construct<QJSEngine, ControllerScriptEngineBase*>(QJSEngine*, ControllerScriptEngineBase*&&) (__p=0x7fff1c0389d0) at /usr/include/c++/13.2.1/bits/stl_construct.h:109
        __mem = 0x7fff1c0389c0
        __pi = <optimized out>
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#9  std::allocator_traits<std::allocator<void> >::construct<QJSEngine, ControllerScriptEngineBase*>(std::allocator<void>&, QJSEngine*, ControllerScriptEngineBase*&&) (__p=0x7fff1c0389d0) at /usr/include/c++/13.2.1/bits/alloc_traits.h:660
        __mem = 0x7fff1c0389c0
        __pi = <optimized out>
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#10 std::_Sp_counted_ptr_inplace<QJSEngine, std::allocator<void>, (__gnu_cxx::_Lock_policy)2>::_Sp_counted_ptr_inplace<ControllerScriptEngineBase*>(std::allocator<void>, ControllerScriptEngineBase*&&) (__a=..., this=0x7fff1c0389c0) at /usr/include/c++/13.2.1/bits/shared_ptr_base.h:604
        __mem = 0x7fff1c0389c0
        __pi = <optimized out>
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#11 std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count<QJSEngine, std::allocator<void>, ControllerScriptEngineBase*>(QJSEngine*&, std::_Sp_alloc_shared_tag<std::allocator<void> >, ControllerScriptEngineBase*&&) (__a=..., __p=<optimized out>, this=<optimized out>) at /usr/include/c++/13.2.1/bits/shared_ptr_base.h:971
        __mem = 0x7fff1c0389c0
        __pi = <optimized out>
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#12 std::__shared_ptr<QJSEngine, (__gnu_cxx::_Lock_policy)2>::__shared_ptr<std::allocator<void>, ControllerScriptEngineBase*>(std::_Sp_alloc_shared_tag<std::allocator<void> >, ControllerScriptEngineBase*&&) (__tag=..., this=<optimized out>) at /usr/include/c++/13.2.1/bits/shared_ptr_base.h:1712
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#13 std::shared_ptr<QJSEngine>::shared_ptr<std::allocator<void>, ControllerScriptEngineBase*>(std::_Sp_alloc_shared_tag<std::allocator<void> >, ControllerScriptEngineBase*&&) (__tag=..., this=<optimized out>) at /usr/include/c++/13.2.1/bits/shared_ptr.h:464
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#14 std::make_shared<QJSEngine, ControllerScriptEngineBase*>(ControllerScriptEngineBase*&&) () at /usr/include/c++/13.2.1/bits/shared_ptr.h:1010
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#15 ControllerScriptEngineBase::initialize() (this=this@entry=0x7fff1c022d50) at /home/antonio/code/mixxx/src/controllers/scripting/controllerscriptenginebase.cpp:31
        __PRETTY_FUNCTION__ = "virtual bool ControllerScriptEngineBase::initialize()"
        engineGlobalObject = {d = 18446744073709551216}
        mapper = {d = 0}
#16 0x0000555555abcd46 in ControllerScriptEngineLegacy::initialize() (this=0x7fff1c022d50) at /home/antonio/code/mixxx/src/controllers/scripting/legacy/controllerscriptenginelegacy.cpp:103
        engineGlobalObject = {d = 140733663694984}
        legacyScriptInterface = <optimized out>
        controllerName = {d = 0x7fff1c022d50}
        args = {<QListSpecialMethods<QJSValue>> = {<No data fields>}, {p = {static shared_null = {ref = {atomic = {_q_value = std::atomic<int> = { -1 }}}, alloc = 0, begin = 0, end = 0, array = {0x0}}, d = 0x7fff27ffdf28}, d = 0x7fff27ffdf28}}
#17 0x0000555555a3c617 in Controller::applyMapping() (this=this@entry=0x7fff1c134660) at /home/antonio/code/mixxx/src/controllers/controller.cpp:81
        __PRETTY_FUNCTION__ = "virtual bool Controller::applyMapping()"
        pMapping = std::shared_ptr<LegacyControllerMapping> (use count 1, weak count 0) = {get() = 0x7fff1c085060}
        scriptFiles = {<QListSpecialMethods<LegacyControllerMapping::ScriptFileInfo>> = {<No data fields>}, {p = {static shared_null = {ref = {atomic = {_q_value = std::atomic<int> = { -1 }}}, alloc = 0, begin = 0, end = 0, array = {0x0}}, d = 0x7fff1c1d2a00}, d = 0x7fff1c1d2a00}}
#18 0x0000555555ae910e in MidiController::applyMapping() (this=0x7fff1c134660) at /home/antonio/code/mixxx/src/controllers/midi/midicontroller.cpp:56
        result = <optimized out>
#19 0x0000555555a4cbcd in ControllerManager::slotSetUpDevices() (this=0x55555a79a290) at /home/antonio/code/mixxx/src/controllers/controllermanager.cpp:294
        mappingFilePath = {d = 0x555556adb440}
        pMapping = std::shared_ptr<LegacyControllerMapping> (use count 1, weak count 0) = {get() = 0x7fff1c076ca0}
        value = <optimized out>
        name = {d = 0x7fff1c1384b0}
        deviceName = {d = 0x7fff1c12da20}
        mappingFile = {d_ptr = {d = 0x7fff1c001940}}
        pController = 0x7fff1c134660
        __for_range = @0x7fff27ffe090: {<QListSpecialMethods<Controller*>> = {<No data fields>}, {p = {static shared_null = {ref = {atomic = {_q_value = std::atomic<int> = { -1 }}}, alloc = 0, begin = 0, end = 0, array = {0x0}}, d = 0x7fff1c01f210}, d = 0x7fff1c01f210}}
        __PRETTY_FUNCTION__ = "void ControllerManager::slotSetUpDevices()"
        deviceList = {<QListSpecialMethods<Controller*>> = {<No data fields>}, {p = {static shared_null = {ref = {atomic = {_q_value = std::atomic<int> = { -1 }}}, alloc = 0, begin = 0, end = 0, array = {0x0}}, d = 0x7fff1c01f210}, d = 0x7fff1c01f210}}
        mappingPaths = {<QList<QString>> = {<QListSpecialMethods<QString>> = {<No data fields>}, {p = {static shared_null = {ref = {atomic = {_q_value = std::atomic<int> = { -1 }}}, alloc = 0, begin = 0, end = 0, array = {0x0}}, d = 0x7fff1c0de590}, d = 0x7fff1c0de590}}, <No data fields>}
#20 0x00007ffff2ec4174 in QObject::event(QEvent*) (this=0x55555a79a290, e=0x55555a794a00) at kernel/qobject.cpp:1347
        mce = 0x55555a794a00
        sender = {previous = 0x0, receiver = 0x55555a79a290, sender = 0x55555a79a290, signal = 4}
#21 0x00007ffff637893f in QApplicationPrivate::notify_helper(QObject*, QEvent*) (this=<optimized out>, receiver=0x55555a79a290, e=0x55555a794a00) at kernel/qapplication.cpp:3640
        consumed = false
        filtered = false
#22 0x00007ffff2e9c6f8 in QCoreApplication::notifyInternal2(QObject*, QEvent*) (receiver=0x55555a79a290, event=0x55555a794a00) at kernel/qcoreapplication.cpp:1064
        selfRequired = true
        result = false
        cbdata = {0x55555a79a290, 0x55555a794a00, 0x7fff27ffe2af}
        d = <optimized out>
        threadData = 0x55555a78df10
        scopeLevelCounter = {threadData = 0x55555a78df10}
#23 0x00007ffff2ea165b in QCoreApplicationPrivate::sendPostedEvents(QObject*, int, QThreadData*) (receiver=0x0, event_type=0, data=0x55555a78df10) at kernel/qcoreapplication.cpp:1821
        e = 0x55555a794a00
        pe = <optimized out>
        r = <optimized out>
        event_deleter = {d = 0x55555a794a00}
        locker = {_M_device = 0x55555a78df40, _M_owns = false}
        startOffset = 0
        i = @0x55555a78df34: 1
        cleanup = {receiver = 0x0, event_type = 0, data = 0x55555a78df10, exceptionCaught = true}
#24 0x00007ffff2ee76d8 in postEventSourceDispatch(GSource*, GSourceFunc, gpointer) (s=0x7fff1c000ee0) at kernel/qeventdispatcher_glib.cpp:277
        source = 0x7fff1c000ee0
#25 0x00007ffff5810f19 in g_main_dispatch (context=0x7fff1c000c30) at ../glib/glib/gmain.c:3476
        dispatch = 0x7ffff2ee76c0 <postEventSourceDispatch(GSource*, GSourceFunc, gpointer)>
        prev_source = 0x0
        begin_time_nsec = 45009707718978
        was_in_call = 0
        user_data = 0x0
        callback = 0x0
        cb_funcs = 0x0
        cb_data = 0x0
        need_destroy = <optimized out>
        source = 0x7fff1c000ee0
        current = 0x7fff1c001410
        i = 0
        __func__ = "g_main_dispatch"
#26 0x00007ffff586f2b7 in g_main_context_dispatch_unlocked (context=0x7fff1c000c30) at ../glib/glib/gmain.c:4284
        max_priority = 0
        timeout = 0
        some_ready = 1
        nfds = 1
        allocated_nfds = 1
        fds = 0x7fff1c0013d0
        begin_time_nsec = 45009707696139
#27 g_main_context_iterate_unlocked.isra.0 (context=context@entry=0x7fff1c000c30, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>) at ../glib/glib/gmain.c:4349
        max_priority = 0
        timeout = 0
        some_ready = 1
        nfds = 1
        allocated_nfds = 1
        fds = 0x7fff1c0013d0
        begin_time_nsec = 45009707696139
#28 0x00007ffff580f112 in g_main_context_iteration (context=0x7fff1c000c30, may_block=1) at ../glib/glib/gmain.c:4414
        retval = <optimized out>
#29 0x00007ffff2eeb51c in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) (this=0x7fff1c000b70, flags=...) at kernel/qeventdispatcher_glib.cpp:423
        d = 0x7fff1c000b90
        canWait = true
        savedFlags = {i = 0}
        result = <optimized out>
#30 0x00007ffff2e9b404 in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) (this=0x7fff27ffe600, flags=...) at ../../include/QtCore/../../src/corelib/global/qflags.h:69
        d = 0x7fff1c001310
        threadData = <optimized out>
        locker = {val = 93825078516280}
        app = <optimized out>
#31 0x00007ffff2cf73b6 in QThread::exec() (this=<optimized out>) at ../../include/QtCore/../../src/corelib/global/qflags.h:121
        d = 0x55555a79d9e0
        locker = {val = 93825078516280}
        eventLoop = {<QObject> = {_vptr.QObject = 0x7ffff3126750 <vtable for QEventLoop+16>, static staticMetaObject = {d = {superdata = {direct = 0x0}, stringdata = 0x7ffff2f95b00 <_ZL26qt_meta_stringdata_QObject.lto_priv.0>, data = 0x7ffff2f959e0 <_ZL20qt_meta_data_QObject.lto_priv.0>, static_metacall = 0x7ffff2ed1ac0 <QObject::qt_static_metacall(QObject*, QMetaObject::Call, int, void**)>, relatedMetaObjects = 0x0, extradata = 0x0}}, d_ptr = {d = 0x7fff1c001310}, static staticQtMetaObject = {d = {superdata = {direct = 0x0}, stringdata = 0x7ffff2fc6720 <_ZL21qt_meta_stringdata_Qt.lto_priv.0>, data = 0x7ffff2fc38a0 <_ZL15qt_meta_data_Qt.lto_priv.0>, static_metacall = 0x0, relatedMetaObjects = 0x0, extradata = 0x0}}}, static staticMetaObject = {d = {superdata = {direct = 0x7ffff311f5a0 <QObject::staticMetaObject>}, stringdata = 0x7ffff2f914c0 <_ZL29qt_meta_stringdata_QEventLoop.lto_priv.0>, data = 0x7ffff2f91460 <_ZL23qt_meta_data_QEventLoop.lto_priv.0>, static_metacall = 0x7ffff2e99130 <QEventLoop::qt_static_metacall(QObject*, QMetaObject::Call, int, void**)>, relatedMetaObjects = 0x0, extradata = 0x0}}}
        returnCode = <optimized out>
#32 0x00007ffff2cf35da in operator() (__closure=<optimized out>) at thread/qthread_unix.cpp:350
        thr = 0x55555a71b290
        data = 0x55555a78df10
        __clframe = {__cancel_routine = <optimized out>, __cancel_arg = 0x55555a71b290, __do_it = 1, __cancel_type = <optimized out>}
#33 (anonymous namespace)::terminate_on_exception<QThreadPrivate::start(void*)::<lambda()> > (t=<optimized out>) at thread/qthread_unix.cpp:287
        __clframe = {__cancel_routine = <optimized out>, __cancel_arg = 0x55555a71b290, __do_it = 1, __cancel_type = <optimized out>}
#34 QThreadPrivate::start(void*) (arg=0x55555a71b290) at thread/qthread_unix.cpp:310
        __clframe = {__cancel_routine = <optimized out>, __cancel_arg = 0x55555a71b290, __do_it = 1, __cancel_type = <optimized out>}
#35 0x00007ffff248c9eb in start_thread (arg=<optimized out>) at pthread_create.c:444
        ret = <optimized out>
        pd = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140733864475864, 6908405128676704194, -400, 11, 140737488343120, 140733856083968, -6908000507571011646, -6908397251972366398}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
#36 0x00007ffff2510dfc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78
[...]

Version

2.4

OS

Arch Linux with Pipewire and Sway (Wayland)

Swiftb0y commented 1 year ago

Thats very strange. Are you able to compile from source? If so can you try the newest commit on the 2.4 branch and compile with -DSANITIZE_ADDRESS?

napaalm commented 1 year ago

@Swiftb0y I just tried and, strangely enough, with the sanitizers enabled the crash doesn't happen anymore and my controller works fine. I don't see any message on the logs either.

$ ./build/mixxx --debugAssertBreak --controllerDebug --developer
QML debugging is enabled. Only use this in a safe environment.
Using preferences ScaleFactor 1
Loading resources from  "/home/antonio/code/mixxx/res/"
Configuration file is at the current version "2.4.0-beta"
BroadcastSettings - Found 1 profile(s)
info [Main] Loaded skin "LateNight"
info [Main] SoundSourceFFmpeg - Disabling untested input formats: aa, aax, ac3, ace, acm, act, adf, adp, ads, adx, aea, afc, aix, alp, amr, amrnb, amrwb, anm, apac, apc, ape, apm, apng, aptx, aptx_hd, aqtitle, argo_asf, argo_brp, argo_cvg, asf, asf_o, ass, ast, au, av1, avi, avisynth, avr, avs, avs2, avs3, bethsoftvid, bfi, bin, bink, binka, bit, bitpacked, bmv, bfstm, brstm, boa, bonk, c93, caf, cavsvideo, cdg, cdxl, cine, codec2, codec2raw, concat, dash, data, daud, dcstr, derf, dfa, dfpwm, dhav, dirac, dnxhd, dsf, dsicin, dss, dts, dtshd, dv, dvbsub, dvbtxt, dxa, ea, ea_cdata, eac3, epaf, ffmetadata, filmstrip, fits, flac, flic, flv, live_flv, 4xm, frm, fsb, fwse, g722, g723_1, g726, g726le, g729, gdv, genh, gif, gsm, gxf, h261, h263, h264, hca, hcom, hevc, hls, hnm, ico, idcin, idf, iff, ifv, ilbc, image2, image2pipe, alias_pix, brender_pix, imf, ingenient, ipmovie, ipu, ircam, iss, iv8, ivf, ivr, jacosub, jv, kux, kvag, laf, lmlm4, loas, luodat, lrc, lvf, lxf, mca, mcc, matroska,webm, mgsts, microdvd, mjpeg, mjpeg_2000, mlp, mlv, mm, mmf, mods, moflex, mpc, mpc8, mpeg, mpegts, mpegtsraw, mpegvideo, mpjpeg, mpl2, mpsub, msf, msnwctcp, msp, mtaf, mtv, musx, mv, mvi, mxf, mxg, nc, nistsphere, nsp, nsv, nut, nuv, obu, ogg, oma, paf, alaw, mulaw, vidc, f64be, f64le, f32be, f32le, s32be, s32le, s24be, s24le, s16be, s16le, s8, u32be, u32le, u24be, u24le, u16be, u16le, u8, pjs, pmp, pp_bnk, pva, pvf, qcp, r3d, rawvideo, realtext, redspark, rka, rl2, rm, roq, rpl, rsd, rso, rtp, rtsp, s337m, sami, sap, sbc, sbg, scc, scd, sdns, sdp, sdr2, sds, sdx, film_cpk, ser, sga, shn, siff, simbiosis_imx, sln, smk, smjpeg, smush, sol, sox, spdif, srt, psxstr, stl, subviewer1, subviewer, sup, svag, svs, swf, tak, tedcaptions, thp, 3dostr, tiertexseq, tmv, truehd, tta, txd, tty, ty, v210, v210x, vag, vc1, vc1test, vividas, vivo, vmd, vobsub, voc, vpk, vplayer, vqf, w64, wady, wavarc, wc3movie, webm_dash_manifest, webvtt, wsaud, wsd, wsvqa, wtv, wve, xa, xbin, xmd, xmv, xvag, xwma, yop, yuv4mpegpipe, bmp_pipe, cri_pipe, dds_pipe, dpx_pipe, exr_pipe, gem_pipe, gif_pipe, hdr_pipe, j2k_pipe, jpeg_pipe, jpegls_pipe, jpegxl_pipe, pam_pipe, pbm_pipe, pcx_pipe, pfm_pipe, pgmyuv_pipe, pgm_pipe, pgx_pipe, phm_pipe, photocd_pipe, pictor_pipe, png_pipe, ppm_pipe, psd_pipe, qdraw_pipe, qoi_pipe, sgi_pipe, svg_pipe, sunrast_pipe, tiff_pipe, vbn_pipe, webp_pipe, xbm_pipe, xpm_pipe, xwd_pipe, libmodplug, libopenmpt
info [Main] faad2::LibLoader - Successfully loaded FAAD2 library "libfaad.so.2" version 2.10.1
info [Main] SoundSourceSndFile - Disabling OGG decoding for "libsndfile-1.2.2"
info [Main] SoundSourceProxy - SoundSource providers for file type "3g2"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "3gp"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "aac"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "aiff"
info [Main] SoundSourceProxy - 3 (default) : "libsndfile"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "caf"
info [Main] SoundSourceProxy - 2 (lower) : "libsndfile"
info [Main] SoundSourceProxy - SoundSource providers for file type "flac"
info [Main] SoundSourceProxy - 4 (higher) : "Xiph.org libFLAC"
info [Main] SoundSourceProxy - 2 (lower) : "libsndfile"
info [Main] SoundSourceProxy - SoundSource providers for file type "it"
info [Main] SoundSourceProxy - 3 (default) : "MODPlug"
info [Main] SoundSourceProxy - SoundSource providers for file type "m4a"
info [Main] SoundSourceProxy - 3 (default) : "Nero FAAD2"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "mj2"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "mod"
info [Main] SoundSourceProxy - 3 (default) : "MODPlug"
info [Main] SoundSourceProxy - SoundSource providers for file type "mov"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "mp3"
info [Main] SoundSourceProxy - 3 (default) : "MAD: MPEG Audio Decoder 0.15.1 (beta) FPM_64BIT"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "mp4"
info [Main] SoundSourceProxy - 3 (default) : "Nero FAAD2"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "ogg"
info [Main] SoundSourceProxy - 4 (higher) : "Xiph.org OggVorbis"
info [Main] SoundSourceProxy - SoundSource providers for file type "okt"
info [Main] SoundSourceProxy - 3 (default) : "MODPlug"
info [Main] SoundSourceProxy - SoundSource providers for file type "opus"
info [Main] SoundSourceProxy - 4 (higher) : "Xiph.org libopusfile"
info [Main] SoundSourceProxy - SoundSource providers for file type "s3m"
info [Main] SoundSourceProxy - 3 (default) : "MODPlug"
info [Main] SoundSourceProxy - SoundSource providers for file type "stm"
info [Main] SoundSourceProxy - 3 (default) : "MODPlug"
info [Main] SoundSourceProxy - SoundSource providers for file type "wav"
info [Main] SoundSourceProxy - 3 (default) : "libsndfile"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "wv"
info [Main] SoundSourceProxy - 4 (higher) : "WavPack"
info [Main] SoundSourceProxy - 1 (lowest) : "FFmpeg n6.0"
info [Main] SoundSourceProxy - SoundSource providers for file type "xm"
info [Main] SoundSourceProxy - 3 (default) : "MODPlug"
info [Main] DbConnection - Available drivers for database connections: ("QIBASE", "QSQLITE", "QMARIADB", "QMYSQL", "QMYSQL3", "QODBC", "QODBC3", "QPSQL", "QPSQL7", "QTDS", "QTDS7")
info [Main] DbConnectionPool - Cloned thread-local database connection "MIXXX-1" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [Main] CoreServices - Connecting to database
info [Main] CoreServices - Initializing or upgrading database schema
info [Main] SchemaManager - Database schema is up-to-date at version 39
ALSA lib pcm.c:2675:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2675:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2675:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
ALSA lib pcm_route.c:878:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:878:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:878:(find_matching_chmap) Found no matching channel map
ALSA lib pcm_route.c:878:(find_matching_chmap) Found no matching channel map
Expression 'alsa_snd_pcm_hw_params_set_buffer_size_near( pcm, hwParams, &alsaBufferFrames )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'alsa_snd_pcm_hw_params_set_buffer_size_near( pcm, hwParams, &alsaBufferFrames )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'alsa_snd_pcm_hw_params_set_buffer_size_near( pcm, hwParams, &alsaBufferFrames )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
ALSA lib pcm_oss.c:397:(_snd_pcm_oss_open) Cannot open device /dev/dsp
ALSA lib pcm_oss.c:397:(_snd_pcm_oss_open) Cannot open device /dev/dsp
ALSA lib pcm_a52.c:1001:(_snd_pcm_a52_open) a52 is only for playback
ALSA lib confmisc.c:160:(snd_config_get_card) Invalid field card
ALSA lib pcm_usb_stream.c:482:(_snd_pcm_usb_stream_open) Invalid card 'card'
ALSA lib confmisc.c:160:(snd_config_get_card) Invalid field card
ALSA lib pcm_usb_stream.c:482:(_snd_pcm_usb_stream_open) Invalid card 'card'
info [Main] GlobalTrackCache - Creating instance
info [Main] TrackCollection - Connecting database
info [Main] TrackCollectionManager - Starting library scanner thread
info [LibraryScanner 1] DbConnectionPool - Cloned thread-local database connection "MIXXX-2" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [Main] TrackCollection - Connecting track source
info [Main] Prepared deletion of 0 playlists of type 2 that contain fewer than 1 tracks
info [Main] Library - Access to directory QFileInfo(/home/antonio/Music/DJ/library/deezer) from sandbox granted
info [Main] Library - Access to directory QFileInfo(/home/antonio/Music/DJ/library/stems) from sandbox granted
info [Main] Library - Access to directory QFileInfo(/home/antonio/Music/DJ/library/bootlegs) from sandbox granted
info [AnalyzerThread 2 #5] DbConnectionPool - Cloned thread-local database connection "MIXXX-5" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [AnalyzerThread 0 #1] DbConnectionPool - Cloned thread-local database connection "MIXXX-3" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [AnalyzerThread 4 #3] DbConnectionPool - Cloned thread-local database connection "MIXXX-6" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [AnalyzerThread 3 #4] DbConnectionPool - Cloned thread-local database connection "MIXXX-4" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [AnalyzerThread 1 #2] DbConnectionPool - Cloned thread-local database connection "MIXXX-8" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [AnalyzerThread 5 #6] DbConnectionPool - Cloned thread-local database connection "MIXXX-7" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [AnalyzerThread 7 #7] DbConnectionPool - Cloned thread-local database connection "MIXXX-9" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [AnalyzerThread 6 #8] DbConnectionPool - Cloned thread-local database connection "MIXXX-10" QSqlDatabase(driver="QSQLITE", database="file:///home/antonio/.mixxx/mixxxdb.sqlite", host="", port=-1, user="mixxx", open=true)
info [LibraryScanner 1] LibraryScanner - Cleaning up database...
info [LibraryScanner 1] LibraryScanner - Finished database cleanup: 0 ms
info [LibraryScanner 1] LibraryScanner - Updating query planner statistics for database...
info [LibraryScanner 1] LibraryScanner - Finished updating query planner statistics for database: 3 ms
info [Main] MetadataSourceTagLib - No track metadata or cover art found in file "/home/antonio/Music/DJ/library/stems/barbie_girl_vocals.wav" with type 7
info [Main] Loaded skin "LateNight"
info [Main] Loaded skin "LateNight"
info [Controller] Scanning USB HID devices
info [Main] Loaded skin "LateNight"
info [Main] Creating skin control object: "[Skin],show_waveforms"
info [Main] Creating skin control object: "[Skin],timing_shift_buttons"
info [Main] Creating skin control object: "[Skin],show_4decks"
info [Main] Creating skin control object: "[Skin],show_hotcues"
info [Main] Creating skin control object: "[Skin],show_8_hotcues"
info [Main] Creating skin control object: "[Skin],show_intro_outro_cues"
info [Main] Creating skin control object: "[Skin],show_loop_controls"
info [Main] Creating skin control object: "[Skin],show_beatjump_controls"
info [Main] Creating skin control object: "[LateNight],deck_size_without_mixer"
info [Main] Creating skin control object: "[Skin],show_rate_controls"
info [Main] Creating skin control object: "[Skin],show_rate_control_buttons"
info [Main] Creating skin control object: "[Skin],show_beatgrid_controls"
info [Main] Creating skin control object: "[Skin],show_rate_controls_compact"
info [Main] Creating skin control object: "[Skin],show_loop_controls_compact"
info [Main] Creating skin control object: "[Skin],show_beatjump_controls_compact"
info [Main] Creating skin control object: "[Skin],show_sync_button_compact"
info [Main] Creating skin control object: "[Skin],show_key_controls"
info [Main] Creating skin control object: "[Skin],show_key_controls_compact"
info [Main] Creating skin control object: "[Skin],show_vumeters_compact"
info [Main] Creating skin control object: "[Skin],show_main_head_mixer"
info [Main] Creating skin control object: "[Skin],show_eq_knobs"
info [Main] Creating skin control object: "[Skin],show_eq_kill_buttons"
info [Main] Creating skin control object: "[Skin],show_xfader"
info [Main] Creating skin control object: "[LateNight],show_vumeters_compact"
info [Main] Creating skin control object: "[Skin],show_superknobs"
info [Main] Creating skin control object: "[LateNight],sampler_rows"
info [Main] Creating skin control object: "[LateNight],expand_samplers_1-4"
info [Main] Creating skin control object: "[LateNight],expand_samplers_1-8"
info [Main] Creating skin control object: "[LateNight],expand_samplers_9-16"
info [Main] Creating skin control object: "[LateNight],max_lib_show_decks"
[...]
 controller.djcontrolstarlightmidi1:info [Controller] PortMidiController: Opening DJControl Starlight MIDI 1 index 5 for input
 controller.djcontrolstarlightmidi1:info [Controller] PortMidiController: Opening DJControl Starlight MIDI 1 index 4 for output
 controller.djcontrolstarlightmidi1:info [Controller]   Starting engine
 controller.djcontrolstarlightmidi1:info [Controller] Applying controller mapping...
 controller.djcontrolstarlightmidi1:debug [Controller] Loading "/usr/share/mixxx/controllers/common-controller-scripts.js"
 controller.djcontrolstarlightmidi1:debug [Controller] Loading "/usr/share/mixxx/controllers/lodash.mixxx.js"
 controller.djcontrolstarlightmidi1:debug [Controller] Loading "/usr/share/mixxx/controllers/midi-components-0.0.js"
 controller.djcontrolstarlightmidi1:debug [Controller] Loading "/usr/share/mixxx/controllers/Hercules-DJControl-Starlight-scripts.js"
 controller.djcontrolstarlightmidi1:debug [Controller] Executing "DJCStarlight" . "init"
 controller.djcontrolstarlightmidi1.output:debug [Controller] "outgoing: " "DJControl Starlight MIDI 1:  status 0x90 (ch 1, opcode 0x9), ctrl 0x24, val 0x00"
 controller.djcontrolstarlightmidi1.output:debug [Controller] "outgoing: " "DJControl Starlight MIDI 1:  status 0x91 (ch 2, opcode 0x9), ctrl 0x03, val 0x7F"
 controller.djcontrolstarlightmidi1:warning [Controller] "Script tried to connect to ([Channel1], VuMeterL) using `connectControl` which is deprecated. Use `makeConnection` instead!"
 controller.djcontrolstarlightmidi1:debug [Controller] "Connected ([Channel1], VuMeterL) to connection {3ea4da4e-9e8e-461c-89bd-954052de0348}"
 controller.djcontrolstarlightmidi1:warning [Controller] "Script tried to connect to ([Channel2], VuMeterR) using `connectControl` which is deprecated. Use `makeConnection` instead!"
 controller.djcontrolstarlightmidi1:debug [Controller] "Connected ([Channel2], VuMeterR) to connection {90f57b4a-de41-4147-ac44-3035267878d3}"
 controller.djcontrolstarlightmidi1.output:debug [Controller] "outgoing: " "DJControl Starlight MIDI 1:  status 0xB0 (ch 1, opcode 0xB), ctrl 0x7F, val 0x7F"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],beatloop_4_enabled between 0.5 and 1 to MIDI out: 0x96 0x12, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],play_indicator between 0.5 and 1 to MIDI out: 0x91 0x07, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],sync_enabled between 0.5 and 1 to MIDI out: 0x91 0x05, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit1_Effect3],enabled between 0.5 and 1 to MIDI out: 0x96 0x22, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler1],play_indicator between 0.5 and 1 to MIDI out: 0x96 0x30, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit1_Effect1],enabled between 0.5 and 1 to MIDI out: 0x96 0x20, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],beatloop_8_enabled between 0.5 and 1 to MIDI out: 0x96 0x13, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler8],play_indicator between 0.5 and 1 to MIDI out: 0x97 0x33, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],sync_leader between 0.5 and 1 to MIDI out: 0x93 0x05, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler7],play_indicator between 0.5 and 1 to MIDI out: 0x97 0x32, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_4_enabled between 0.5 and 1 to MIDI out: 0x97 0x0B, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_4_enabled" - use "[Channel2]" "hotcue_4_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_4_enabled between 0.5 and 1 to MIDI out: 0x97 0x03, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_4_enabled" - use "[Channel2]" "hotcue_4_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_2_enabled between 0.5 and 1 to MIDI out: 0x97 0x09, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_2_enabled" - use "[Channel2]" "hotcue_2_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_2_enabled between 0.5 and 1 to MIDI out: 0x97 0x01, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_2_enabled" - use "[Channel2]" "hotcue_2_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit2_Effect3],enabled between 0.5 and 1 to MIDI out: 0x97 0x22, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],beatloop_1_enabled between 0.5 and 1 to MIDI out: 0x96 0x10, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],cue_indicator between 0.5 and 1 to MIDI out: 0x92 0x06, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],sync_enabled between 0.5 and 1 to MIDI out: 0x92 0x05, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler4],play_indicator between 0.5 and 1 to MIDI out: 0x96 0x33, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],beatloop_4_enabled between 0.5 and 1 to MIDI out: 0x97 0x12, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_4_enabled between 0.5 and 1 to MIDI out: 0x96 0x0B, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_4_enabled" - use "[Channel1]" "hotcue_4_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_4_enabled between 0.5 and 1 to MIDI out: 0x96 0x03, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_4_enabled" - use "[Channel1]" "hotcue_4_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_1_enabled between 0.5 and 1 to MIDI out: 0x96 0x08, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_1_enabled" - use "[Channel1]" "hotcue_1_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_1_enabled between 0.5 and 1 to MIDI out: 0x96 0x00, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_1_enabled" - use "[Channel1]" "hotcue_1_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit2_Effect2],enabled between 0.5 and 1 to MIDI out: 0x97 0x21, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],sync_leader between 0.5 and 1 to MIDI out: 0x94 0x05, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler2],play_indicator between 0.5 and 1 to MIDI out: 0x96 0x31, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],beatloop_2_enabled between 0.5 and 1 to MIDI out: 0x96 0x11, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_3_enabled between 0.5 and 1 to MIDI out: 0x96 0x0A, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_3_enabled" - use "[Channel1]" "hotcue_3_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_3_enabled between 0.5 and 1 to MIDI out: 0x96 0x02, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_3_enabled" - use "[Channel1]" "hotcue_3_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_2_enabled between 0.5 and 1 to MIDI out: 0x96 0x09, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_2_enabled" - use "[Channel1]" "hotcue_2_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],hotcue_2_enabled between 0.5 and 1 to MIDI out: 0x96 0x01, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel1]" "hotcue_2_enabled" - use "[Channel1]" "hotcue_2_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler5],play_indicator between 0.5 and 1 to MIDI out: 0x97 0x30, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler6],play_indicator between 0.5 and 1 to MIDI out: 0x97 0x31, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],beatloop_8_enabled between 0.5 and 1 to MIDI out: 0x97 0x13, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit2],group_[Channel2]_enable between 0.5 and 1 to MIDI out: 0x97 0x23, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],cue_indicator between 0.5 and 1 to MIDI out: 0x91 0x06, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_3_enabled between 0.5 and 1 to MIDI out: 0x97 0x0A, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_3_enabled" - use "[Channel2]" "hotcue_3_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_3_enabled between 0.5 and 1 to MIDI out: 0x97 0x02, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_3_enabled" - use "[Channel2]" "hotcue_3_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit2_Effect1],enabled between 0.5 and 1 to MIDI out: 0x97 0x20, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel1],pfl between 0.5 and 1 to MIDI out: 0x91 0x0C, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],beatloop_2_enabled between 0.5 and 1 to MIDI out: 0x97 0x11, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],play_indicator between 0.5 and 1 to MIDI out: 0x92 0x07, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],beatloop_1_enabled between 0.5 and 1 to MIDI out: 0x97 0x10, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],pfl between 0.5 and 1 to MIDI out: 0x92 0x0C, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Sampler3],play_indicator between 0.5 and 1 to MIDI out: 0x96 0x32, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit1],group_[Channel1]_enable between 0.5 and 1 to MIDI out: 0x96 0x23, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_1_enabled between 0.5 and 1 to MIDI out: 0x97 0x08, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_1_enabled" - use "[Channel2]" "hotcue_1_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [Channel2],hotcue_1_enabled between 0.5 and 1 to MIDI out: 0x97 0x00, on: 0x7E off: 0x00"
warning [Controller] ControlObject accessed via deprecated key "[Channel2]" "hotcue_1_enabled" - use "[Channel2]" "hotcue_1_status" instead
 controller.djcontrolstarlightmidi1:debug [Controller] "Creating output handler for [EffectRack1_EffectUnit1_Effect2],enabled between 0.5 and 1 to MIDI out: 0x96 0x21, on: 0x7F off: 0x00"
 controller.djcontrolstarlightmidi1.output:debug [Controller] sending MIDI bytes: 150 , 18 , 0
 controller.djcontrolstarlightmidi1.output:debug [Controller] "outgoing: " "DJControl Starlight MIDI 1:  status 0x96 (ch 7, opcode 0x9), ctrl 0x12, val 0x00"
[...]
 controller.djcontrolstarlightmidi1.output:debug [Controller] sending MIDI bytes: 150 , 33 , 0
 controller.djcontrolstarlightmidi1.output:debug [Controller] "outgoing: " "DJControl Starlight MIDI 1:  status 0x96 (ch 7, opcode 0x9), ctrl 0x21, val 0x00"
 controller.djcontrolstarlightmidi1.input:debug [Controller] "incoming: " "DJControl Starlight MIDI 1: t:77 ms status 0xB0 (ch 1, opcode 0xB), ctrl 0x00, val 0x3E"
[...]
 controller.djcontrolstarlightmidi1.input:debug [Controller] "incoming: " "DJControl Starlight MIDI 1: t:77 ms status 0xB2 (ch 3, opcode 0xB), ctrl 0x22, val 0x46"
info [Main] Creating skin control object: "[LateNight],show_sync_button_compact"
info [Main] Creating skin control object: "[LateNight],show_mini_deck"
info [Main] Creating skin control object: "[LateNight],show_compact_deck"
info [Main] Creating skin control object: "[LateNight],show_full_deck"
info [Main] Creating skin control object: "[Skin],show_sampler_fx"
info [Main] Creating skin control object: "[LateNight],show_4samplers"
info [Main] Creating skin control object: "[LateNight],show_8samplers"
info [Main] Creating skin control object: "[LateNight],show_16samplers"
napaalm commented 1 year ago

This is the code that ultimately causes the crash, from https://github.com/qt/qtdeclarative/blob/540c4e4a5def8c350a49bb68380b787ae62490c6/src/3rdparty/masm/wtf/OSAllocatorPosix.cpp#L105

#elif OS(LINUX)
    UNUSED_PARAM(writable);
    UNUSED_PARAM(executable);
    int fd = memfdForUsage(bytes, usage);

    void* result = mmap(0, bytes, PROT_NONE, MAP_NORESERVE | MAP_PRIVATE |
                        (fd == -1 ? MAP_ANON : 0), fd, 0);
    if (result == MAP_FAILED)
        CRASH();
napaalm commented 1 year ago

After going through the mmap man page I found out that when it returns MAP_FAILED it also sets the errno variable to indicate the error. In this case its value is EINVAL:

Thread 53 "Controller" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fff2effd6c0 (LWP 84405)]
0x00007ffff6aa7028 in WTF::OSAllocator::reserveUncommitted (usage=WTF::OSAllocator::JSGCHeapPages, writable=true, executable=false, bytes=4194304) at /usr/src/debug/qt5-declarative/qtdeclarative/src/3rdparty/masm/wtf/OSAllocatorPosix.cpp:113
113         CRASH();
(gdb) print errno
$1 = 22
(gdb) python import errno
(gdb) python print(errno.errorcode[22])
EINVAL

These are the possible meanings of EINVAL, from the same manpage:

Swiftb0y commented 1 year ago

The crash is miles away from our code. I fear this is some race condition that corrupts the stack somewhere else. Instead of -DSANITIZE_ADDRESS you can also try -DSANITIZE_THREAD. In general this is vrey hard to debug. Unless I can reproduce it locally, I don't see any way of figuring this out.

napaalm commented 1 year ago

@Swiftb0y ok, I'll try to continue debugging locally, and if you need more details on my setup to try to reproduce the issue, let me know.

Swiftb0y commented 1 year ago

It probably depends on circumstances I can't reproduce (processor speed, system usage, etc). But thank you for looking into it. Please share your findings and I'll try to help you as much as I can.

napaalm commented 1 year ago

@Swiftb0y after further testing it seems the bug occurs when I enable any MIDI controller. The HID ones do not trigger the crash. Can you try enabling a MIDI device with and let me know if you can reproduce it? It doesn't matter which device or what mapping you assign to it, as long as it's a MIDI device.

Swiftb0y commented 1 year ago

I can't reproduce it on my end unfortunately. Not in a debug build at least. Currently waiting for the release build to finish compiling.

Swiftb0y commented 1 year ago

Same for the release build...

daschuer commented 1 year ago

The last call under our control is here: https://github.com/mixxxdj/mixxx/blob/44a997258d490887eab95874ac9fe05080d34b00/src/controllers/scripting/controllerscriptenginebase.cpp#L31C36-L31C45

This seems a pretty independent call form our code.

This is pointer in this makes the object owned by the QObject tree. The double ownership is suspicious. I think we need to replace it with make_parented and remove the reset() call during destruction.

But that does not explain the crash .. :-/

napaalm commented 1 year ago

@daschuer @Swiftb0y I'm bisecting the bug, but at many older commits (like 36d92d268e044876ad05bbd9739c6c45a66f798b) I'm getting

[100%] Linking CXX executable mixxx
/usr/bin/ld: libmixxx-lib.a(keys.pb.cc.o): undefined reference to symbol '_ZN4absl12lts_2023080212log_internal17MakeCheckOpStringIllEEPNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEET_T0_PKc'
/usr/bin/ld: /usr/lib/libabsl_log_internal_check_op.so.2308.0.0: error adding symbols: DSO missing from command line
collect2: error: ld returned 1 exit status

It seems to be some kind of issue with protobuf, see https://github.com/protocolbuffers/protobuf/issues/14500. Unfortunately the workaround proposed there doesn't work for me. Do you have any idea?

P.S. To get the bisect going I also had to set -DENGINEPRIME=OFF because libdjinterop really doesn't want to build on older commits.

napaalm commented 1 year ago

@daschuer @Swiftb0y I just finished bisecting, and here are my results.

I find very amusing the fact that I get the same exact crash on every single build of mixxx from branch 2.4 since 2020, while on mixxx 2.3 it just works.

Swiftb0y commented 1 year ago

Thank you for going through the tedious bisecting work. So in 2.3 we changed from the then outdated and now removed QScriptEngine to QJSEngine. The commits you're referencing are the exact commits that committed the switch, so in short QJSEngine never worked on your system at all for some reason. So I'm pretty sure the issue is not related to Mixxx itself but rather QJSEngine in general. Can you try to build some minimal QJSEngine example and see whether that also crashes on your system? You can build one yourself or just use some random public code like https://github.com/tarcisiofischer/QJSEngine-playground

napaalm commented 1 year ago

So I'm pretty sure the issue is not related to Mixxx itself but rather QJSEngine in general.

@Swiftb0y does the 2.3 branch use it too? Because I get this crash only on branch 2.4. Release 2.3.6, for example, works perfectly for me.

napaalm commented 1 year ago

You can build one yourself or just use some random public code like https://github.com/tarcisiofischer/QJSEngine-playground

I just ran that simple test and it doesn't crash. I think there's something more subtle going on here.

Swiftb0y commented 1 year ago

does the 2.3 branch use it too? Because I get this crash only on branch 2.4. Release 2.3.6, for example, works perfectly for me.

It doesn't, 2.4 is the first release with QJSEngine.

I think there's something more subtle going on here.

Probably yeah, I forgot we already established that it doesn't crash under ASAN. I have no idea how to debug this further. Have you tried running mixxx on a different system? I'm afraid I don't have any better idea on how to work around the issue. I don't even know how to properly diagnose it. I guess you could try adding some arbitrary sleep calls during initialization. I'm guessing the problem is some data race causing memory corruption, and the slower execution during ASAN causes it to not occur. Maybe -DSANITIZE_THREAD will reveal something (maybe combine ASAN and TSAN (though I'm not sure if they're compatible))?

napaalm commented 1 year ago

@Swiftb0y with -DSANITIZE_THREAD it doesn't crash, but it outputs something that may be interesting.

debug [Controller] Searching for controller mapping "/home/antonio/code/mixxx/res/controllers/Hercules DJControl Starlight.midi.xml" in paths: "/home/antonio/.mixxx/controllers/,/home/antonio/code/mixxx/res/controllers/"
debug [Controller] Loading controller mapping from "/home/antonio/code/mixxx/res/controllers/Hercules DJControl Starlight.midi.xml"
debug [Controller] LegacyMidiControllerMappingFileHandler: Input mapping parsing complete.
debug [Controller] MidiMappingFileHandler: Output mapping parsing complete.
debug [Controller] Opening controller: "Scarlett 18i20 USB MIDI 1"
info [Controller] PortMidiController: Opening Scarlett 18i20 USB MIDI 1 index 3 for input
info [Controller] PortMidiController: Opening Scarlett 18i20 USB MIDI 1 index 2 for output
info [Controller]   Starting engine
info [Controller] Applying controller mapping...
==================
WARNING: ThreadSanitizer: data race (pid=39934)
  Write of size 8 at 0x7b04000023e0 by thread T54:
    #0 free /usr/src/debug/gcc/gcc/libsanitizer/tsan/tsan_interceptors_posix.cpp:740 (libtsan.so.2+0x437b0) (BuildId: 7e8fcb9ed0a63b98f2293e37c92ac955413efd9e)
    #1 <null> <null> (libc.so.6+0xcb699) (BuildId: 8bfe03f6bf9b6a6e2591babd0bbc266837d8f658)
    #2 ControllerScriptEngineLegacy::initialize() /home/antonio/code/mixxx/src/controllers/scripting/legacy/controllerscriptenginelegacy.cpp:103 (mixxx+0x69103b
) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #3 Controller::applyMapping() /home/antonio/code/mixxx/src/controllers/controller.cpp:81 (mixxx+0x5d584c) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #4 MidiController::applyMapping() /home/antonio/code/mixxx/src/controllers/midi/midicontroller.cpp:56 (mixxx+0x6d3d5e) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #5 ControllerManager::slotSetUpDevices() /home/antonio/code/mixxx/src/controllers/controllermanager.cpp:294 (mixxx+0x5edc7f) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #6 QtPrivate::FunctorCall<QtPrivate::IndexesList<>, QtPrivate::List<>, void, void (ControllerManager::*)()>::call(void (ControllerManager::*)(), ControllerManager*, void**) /usr/include/qt/QtCore/qobjectdefs_impl.h:152 (mixxx+0x5f0fb7) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #7 void QtPrivate::FunctionPointer<void (ControllerManager::*)()>::call<QtPrivate::List<>, void>(void (ControllerManager::*)(), ControllerManager*, void**) /usr/include/qt/QtCore/qobjectdefs_impl.h:185 (mixxx+0x5f0fb7)
    #8 QtPrivate::QSlotObject<void (ControllerManager::*)(), QtPrivate::List<>, void>::impl(int, QtPrivate::QSlotObjectBase*, QObject*, void**, bool*) /usr/include/qt/QtCore/qobjectdefs_impl.h:418 (mixxx+0x5f0fb7)
    #9 QObject::event(QEvent*) <null> (libQt5Core.so.5+0x2c3bd3) (BuildId: b7d92f8f8f7eea3410c75095ef7753f2fb9f139c)
    #10 QCoreApplication::notifyInternal2(QObject*, QEvent*) <null> (libQt5Core.so.5+0x29c167) (BuildId: b7d92f8f8f7eea3410c75095ef7753f2fb9f139c)

  Previous write of size 8 at 0x7b04000023e0 by main thread:
    #0 malloc /usr/src/debug/gcc/gcc/libsanitizer/tsan/tsan_interceptors_posix.cpp:681 (libtsan.so.2+0x4326b) (BuildId: 7e8fcb9ed0a63b98f2293e37c92ac955413efd9e)
    #1 __strdup <null> (libc.so.6+0xa33de) (BuildId: 8bfe03f6bf9b6a6e2591babd0bbc266837d8f658)
    #2 qMkTime(tm*) <null> (libQt5Core.so.5+0xe7782) (BuildId: b7d92f8f8f7eea3410c75095ef7753f2fb9f139c)
    #3 DlgPrefInterface::slotSetSkinPreview() /home/antonio/code/mixxx/src/preferences/dialog/dlgprefinterface.cpp:369 (mixxx+0xe59193) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #4 DlgPrefInterface::DlgPrefInterface(QWidget*, std::shared_ptr<mixxx::ScreensaverManager>, std::shared_ptr<mixxx::skin::SkinLoader>, QSharedPointer<ConfigObject<ConfigValue> >) /home/antonio/code/mixxx/src/preferences/dialog/dlgprefinterface.cpp:157 (mixxx+0xe5b499) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #5 DlgPreferences::DlgPreferences(std::shared_ptr<mixxx::ScreensaverManager>, std::shared_ptr<mixxx::skin::SkinLoader>, std::shared_ptr<SoundManager>, std::shared_ptr<ControllerManager>, std::shared_ptr<VinylControlManager>, std::shared_ptr<EffectsManager>, std::shared_ptr<SettingsManager>, std::shared_ptr<Library>) /home/antonio/code/mixxx/src/preferences/dialog/dlgpreferences.cpp:145 (mixxx+0xe4e5c9) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #6 MixxxMainWindow::initialize() /home/antonio/code/mixxx/src/mixxxmainwindow.cpp:299 (mixxx+0x1258dd6) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #7 QtPrivate::FunctorCall<QtPrivate::IndexesList<>, QtPrivate::List<>, void, void (MixxxMainWindow::*)()>::call(void (MixxxMainWindow::*)(), MixxxMainWindow*, void**) /usr/include/qt/QtCore/qobjectdefs_impl.h:152 (mixxx+0x125af47) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #8 void QtPrivate::FunctionPointer<void (MixxxMainWindow::*)()>::call<QtPrivate::List<>, void>(void (MixxxMainWindow::*)(), MixxxMainWindow*, void**) /usr/include/qt/QtCore/qobjectdefs_impl.h:185 (mixxx+0x125af47)
    #9 QtPrivate::QSlotObject<void (MixxxMainWindow::*)(), QtPrivate::List<>, void>::impl(int, QtPrivate::QSlotObjectBase*, QObject*, void**, bool*) /usr/include/qt/QtCore/qobjectdefs_impl.h:418 (mixxx+0x125af47)
    #10 <null> <null> (libQt5Core.so.5+0x2d1096) (BuildId: b7d92f8f8f7eea3410c75095ef7753f2fb9f139c)
    #11 OpenGLWindow::initializeGL() /home/antonio/code/mixxx/src/widget/openglwindow.cpp:23 (mixxx+0x131f504) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #12 QOpenGLWindow::resizeEvent(QResizeEvent*) <null> (libQt5Gui.so.5+0x190e89) (BuildId: 65c02d2d9ff8634661beff012f739adb80660f27)
    #13 QApplicationPrivate::notify_helper(QObject*, QEvent*) <null> (libQt5Widgets.so.5+0x1788fe) (BuildId: 8c259b382bf055179ba6fe47091ad6dfdcc3587b)
    #14 QCoreApplication::notifyInternal2(QObject*, QEvent*) <null> (libQt5Core.so.5+0x29c167) (BuildId: b7d92f8f8f7eea3410c75095ef7753f2fb9f139c)
    #15 QCoreApplication::notifyInternal2(QObject*, QEvent*) <null> (libQt5Core.so.5+0x29c167) (BuildId: b7d92f8f8f7eea3410c75095ef7753f2fb9f139c)
    #16 <null> <null> (libc.so.6+0x27ccf) (BuildId: 8bfe03f6bf9b6a6e2591babd0bbc266837d8f658)

  Thread T54 'Controller' (tid=40063, running) created by main thread at:
    #0 pthread_create /usr/src/debug/gcc/gcc/libsanitizer/tsan/tsan_interceptors_posix.cpp:1036 (libtsan.so.2+0x44219) (BuildId: 7e8fcb9ed0a63b98f2293e37c92ac955413efd9e)
    #1 QThread::start(QThread::Priority) <null> (libQt5Core.so.5+0xf1cc4) (BuildId: b7d92f8f8f7eea3410c75095ef7753f2fb9f139c)
    #2 void std::_Construct<ControllerManager, QSharedPointer<ConfigObject<ConfigValue> >&>(ControllerManager*, QSharedPointer<ConfigObject<ConfigValue> >&) /usr/include/c++/13.2.1/bits/stl_construct.h:119 (mixxx+0xd760fe) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #3 void std::allocator_traits<std::allocator<void> >::construct<ControllerManager, QSharedPointer<ConfigObject<ConfigValue> >&>(std::allocator<void>&, ControllerManager*, QSharedPointer<ConfigObject<ConfigValue> >&) /usr/include/c++/13.2.1/bits/alloc_traits.h:660 (mixxx+0xd760fe)
    #4 std::_Sp_counted_ptr_inplace<ControllerManager, std::allocator<void>, (__gnu_cxx::_Lock_policy)2>::_Sp_counted_ptr_inplace<QSharedPointer<ConfigObject<ConfigValue> >&>(std::allocator<void>, QSharedPointer<ConfigObject<ConfigValue> >&) /usr/include/c++/13.2.1/bits/shared_ptr_base.h:604 (mixxx+0xd760fe)
    #5 std::__shared_count<(__gnu_cxx::_Lock_policy)2>::__shared_count<ControllerManager, std::allocator<void>, QSharedPointer<ConfigObject<ConfigValue> >&>(ControllerManager*&, std::_Sp_alloc_shared_tag<std::allocator<void> >, QSharedPointer<ConfigObject<ConfigValue> >&) /usr/include/c++/13.2.1/bits/shared_ptr_base.h:971 (mixxx+0xd760fe)
    #6 std::__shared_ptr<ControllerManager, (__gnu_cxx::_Lock_policy)2>::__shared_ptr<std::allocator<void>, QSharedPointer<ConfigObject<ConfigValue> >&>(std::_Sp_alloc_shared_tag<std::allocator<void> >, QSharedPointer<ConfigObject<ConfigValue> >&) /usr/include/c++/13.2.1/bits/shared_ptr_base.h:1712 (mixxx+0xd760fe)
    #7 std::shared_ptr<ControllerManager>::shared_ptr<std::allocator<void>, QSharedPointer<ConfigObject<ConfigValue> >&>(std::_Sp_alloc_shared_tag<std::allocator<void> >, QSharedPointer<ConfigObject<ConfigValue> >&) /usr/include/c++/13.2.1/bits/shared_ptr.h:464 (mixxx+0xd760fe)
    #8 std::shared_ptr<ControllerManager> std::make_shared<ControllerManager, QSharedPointer<ConfigObject<ConfigValue> >&>(QSharedPointer<ConfigObject<ConfigValue> >&) /usr/include/c++/13.2.1/bits/shared_ptr.h:1010 (mixxx+0xd760fe)
    #9 mixxx::CoreServices::initialize(QApplication*) /home/antonio/code/mixxx/src/coreservices.cpp:381 (mixxx+0xd760fe)
    #10 runMixxx /home/antonio/code/mixxx/src/main.cpp:61 (mixxx+0x569fff) (BuildId: b4031b572df52062eb51386940ee375a37a0c564)
    #11 main /home/antonio/code/mixxx/src/main.cpp:213 (mixxx+0x569fff)
==================
debug [Controller] Controller in script engine is: "Scarlett 18i20 USB MIDI 1"
debug [Controller] Loading "/home/antonio/code/mixxx/res/controllers/common-controller-scripts.js"

This data race seems to be triggered at the exact point where normally it crashes. Maybe we have found it!

napaalm commented 1 year ago

@daschuer @Swiftb0y by using valgrind I got some more info on the crash.

debug [Controller] ControllerManager::getControllerList
debug [Controller] Searching for controller mapping "/home/antonio/code/mixxx/res/controllers/Hercules DJControl Starlight.midi.xml" in paths: "/home/antonio/.mixxx/controllers/,/home/antonio/code/mixxx/res/controllers/"
debug [Controller] Loading controller mapping from "/home/antonio/code/mixxx/res/controllers/Hercules DJControl Starlight.midi.xml"
debug [Controller] LegacyMidiControllerMappingFileHandler: Input mapping parsing complete.
debug [Controller] MidiMappingFileHandler: Output mapping parsing complete.
debug [Controller] Opening controller: "Scarlett 18i20 USB MIDI 1"
 controller.scarlett18i20usbmidi1:info [Controller] PortMidiController: Opening Scarlett 18i20 USB MIDI 1 index 3 for input
 controller.scarlett18i20usbmidi1:info [Controller] PortMidiController: Opening Scarlett 18i20 USB MIDI 1 index 2 for output
 controller.scarlett18i20usbmidi1:info [Controller]   Starting engine
 controller.scarlett18i20usbmidi1:info [Controller] Applying controller mapping...
==203357== Thread 39 Controller:
==203357== Invalid write of size 4
==203357==    at 0x5607028: UnknownInlinedFun (OSAllocatorPosix.cpp:113)
==203357==    by 0x5607028: UnknownInlinedFun (PageReservation.h:107)
==203357==    by 0x5607028: UnknownInlinedFun (qv4mm.cpp:129)
==203357==    by 0x5607028: QV4::ChunkAllocator::allocate(unsigned long) [clone .cold] (qv4mm.cpp:264)
==203357==    by 0x561020D: QV4::BlockAllocator::allocate(unsigned long, bool) (qv4mm.cpp:600)
==203357==    by 0x56699DA: UnknownInlinedFun (qv4mm_p.h:273)
==203357==    by 0x56699DA: QV4::ExecutionEngine::ExecutionEngine(QJSEngine*) (qv4engine.cpp:371)
==203357==    by 0x5663E24: QJSEngine::QJSEngine(QObject*) (qjsengine.cpp:343)
==203357==    by 0x6B0489: _Construct<QJSEngine, ControllerScriptEngineBase*> (stl_construct.h:119)
==203357==    by 0x6B0489: construct<QJSEngine, ControllerScriptEngineBase*> (alloc_traits.h:660)
==203357==    by 0x6B0489: _Sp_counted_ptr_inplace<ControllerScriptEngineBase*> (shared_ptr_base.h:604)
==203357==    by 0x6B0489: __shared_count<QJSEngine, std::allocator<void>, ControllerScriptEngineBase*> (shared_ptr_base.h:971)
==203357==    by 0x6B0489: __shared_ptr<std::allocator<void>, ControllerScriptEngineBase*> (shared_ptr_base.h:1712)
==203357==    by 0x6B0489: shared_ptr<std::allocator<void>, ControllerScriptEngineBase*> (shared_ptr.h:464)
==203357==    by 0x6B0489: make_shared<QJSEngine, ControllerScriptEngineBase*> (shared_ptr.h:1010)
==203357==    by 0x6B0489: ControllerScriptEngineBase::initialize() (controllerscriptenginebase.cpp:31)
==203357==    by 0x6B9355: ControllerScriptEngineLegacy::initialize() (controllerscriptenginelegacy.cpp:103)
==203357==    by 0x637D36: Controller::applyMapping() (controller.cpp:81)
==203357==    by 0x6E5CED: MidiController::applyMapping() (midicontroller.cpp:56)
==203357==    by 0x64862C: ControllerManager::slotSetUpDevices() (controllermanager.cpp:294)
==203357==    by 0x957ABD3: QObject::event(QEvent*) (qobject.cpp:1347)
==203357==    by 0x5D458FE: QApplicationPrivate::notify_helper(QObject*, QEvent*) (qapplication.cpp:3640)
==203357==    by 0x9553167: QCoreApplication::notifyInternal2(QObject*, QEvent*) (qcoreapplication.cpp:1064)
==203357==  Address 0xbbadbeef is not stack'd, malloc'd or (recently) free'd
==203357==
==203357==
==203357== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==203357==  Access not within mapped region at address 0xBBADBEEF
==203357==    at 0x5607028: UnknownInlinedFun (OSAllocatorPosix.cpp:113)
==203357==    by 0x5607028: UnknownInlinedFun (PageReservation.h:107)
==203357==    by 0x5607028: UnknownInlinedFun (qv4mm.cpp:129)
==203357==    by 0x5607028: QV4::ChunkAllocator::allocate(unsigned long) [clone .cold] (qv4mm.cpp:264)
==203357==    by 0x561020D: QV4::BlockAllocator::allocate(unsigned long, bool) (qv4mm.cpp:600)
==203357==    by 0x56699DA: UnknownInlinedFun (qv4mm_p.h:273)
==203357==    by 0x56699DA: QV4::ExecutionEngine::ExecutionEngine(QJSEngine*) (qv4engine.cpp:371)
==203357==    by 0x5663E24: QJSEngine::QJSEngine(QObject*) (qjsengine.cpp:343)
==203357==    by 0x6B0489: _Construct<QJSEngine, ControllerScriptEngineBase*> (stl_construct.h:119)
==203357==    by 0x6B0489: construct<QJSEngine, ControllerScriptEngineBase*> (alloc_traits.h:660)
==203357==    by 0x6B0489: _Sp_counted_ptr_inplace<ControllerScriptEngineBase*> (shared_ptr_base.h:604)
==203357==    by 0x6B0489: __shared_count<QJSEngine, std::allocator<void>, ControllerScriptEngineBase*> (shared_ptr_base.h:971)
==203357==    by 0x6B0489: __shared_ptr<std::allocator<void>, ControllerScriptEngineBase*> (shared_ptr_base.h:1712)
==203357==    by 0x6B0489: shared_ptr<std::allocator<void>, ControllerScriptEngineBase*> (shared_ptr.h:464)
==203357==    by 0x6B0489: make_shared<QJSEngine, ControllerScriptEngineBase*> (shared_ptr.h:1010)
==203357==    by 0x6B0489: ControllerScriptEngineBase::initialize() (controllerscriptenginebase.cpp:31)
==203357==    by 0x6B9355: ControllerScriptEngineLegacy::initialize() (controllerscriptenginelegacy.cpp:103)
==203357==    by 0x637D36: Controller::applyMapping() (controller.cpp:81)
==203357==    by 0x6E5CED: MidiController::applyMapping() (midicontroller.cpp:56)
==203357==    by 0x64862C: ControllerManager::slotSetUpDevices() (controllermanager.cpp:294)
==203357==    by 0x957ABD3: QObject::event(QEvent*) (qobject.cpp:1347)
==203357==    by 0x5D458FE: QApplicationPrivate::notify_helper(QObject*, QEvent*) (qapplication.cpp:3640)
==203357==    by 0x9553167: QCoreApplication::notifyInternal2(QObject*, QEvent*) (qcoreapplication.cpp:1064)
==203357==  If you believe this happened as a result of a stack
==203357==  overflow in your program's main thread (unlikely but
==203357==  possible), you can try to increase the size of the
==203357==  main thread stack using the --main-stacksize= flag.
==203357==  The main thread stack size used in this run was 8388608.
==203357==
==203357== HEAP SUMMARY:
==203357==     in use at exit: 491,938,701 bytes in 1,518,650 blocks
==203357==   total heap usage: 6,814,891 allocs, 5,296,241 frees, 1,019,406,960 bytes allocated
==203357==
==203357== LEAK SUMMARY:
==203357==    definitely lost: 11,371 bytes in 125 blocks
==203357==    indirectly lost: 7,925 bytes in 289 blocks
==203357==      possibly lost: 985,423 bytes in 12,886 blocks
==203357==    still reachable: 490,903,350 bytes in 1,505,098 blocks
==203357==                       of which reachable via heuristic:
==203357==                         newarray           : 4,488 bytes in 5 blocks
==203357==                         multipleinheritance: 5,312 bytes in 24 blocks
==203357==         suppressed: 0 bytes in 0 blocks
==203357== Rerun with --leak-check=full to see details of leaked memory
==203357==
==203357== Use --track-origins=yes to see where uninitialised values come from
==203357== For lists of detected and suppressed errors, rerun with: -s
==203357== ERROR SUMMARY: 793 errors from 793 contexts (suppressed: 0 from 0)
[1]    203357 segmentation fault (core dumped)  valgrind ./build/mixxx --developer
valgrind ./build/mixxx --developer  80,73s user 9,11s system 95% cpu 1:33,82 total
napaalm commented 1 year ago

And here's the output from helgrind: helgrind.log

daschuer commented 1 year ago

We have a write to the same memory here: DlgPrefInterface::slotSetSkinPreview() and ControllerScriptEngineLegacy::initialize() That looks unrelated. So I guess we suffer a dangling pointer access.

napaalm commented 1 year ago

We have a write to the same memory here: DlgPrefInterface::slotSetSkinPreview() and ControllerScriptEngineLegacy::initialize()

@daschuer TSAN changes the software behavior like ASAN did (in fact mixxx doesn't crash with it enabled), so this data race might not be the exact cause of the sigsegv. By using helgrind instead I still get the correct crash, so maybe you can find more pertinent information there.

I'm attaching again the full TSAN and helgrind logs for your convenience. tsan.log helgrind.log

napaalm commented 1 year ago

@daschuer @Swiftb0y I have one more piece of information: while running Mixxx with valgrind --track-origins=yes I saw a myriad of warnings about Conditional jump or move depends on uninitialised value(s) allocated by DlgPrefInterface, which is coincidentally involved in the data race we found with TSAN:

==46171== Conditional jump or move depends on uninitialised value(s)
==46171==    at 0x1C22B301: ???
==46171==    by 0x1A62BBC7: ???
==46171==  Uninitialised value was created by a heap allocation
==46171==    at 0x4841848: malloc (vg_replace_malloc.c:431)
==46171==    by 0x959E673: QArrayData::allocate(unsigned long, unsigned long, unsigned long, QFlags<QArrayData::AllocationOption>) (qarraydata.cpp:218)
==46171==    by 0x960EF23: UnknownInlinedFun (qarraydata.h:224)
==46171==    by 0x960EF23: QString::reallocData(unsigned int, bool) (qstring.cpp:2370)
==46171==    by 0x960F01C: QString::resize(int) (qstring.cpp:2287)
==46171==    by 0x96164F7: QString::setUnicode(QChar const*, int) (qstring.cpp:5696)
==46171==    by 0x97BB718: QTextStream::readLineInto(QString*, long long) (qtextstream.cpp:1725)
==46171==    by 0x97BB7E2: QTextStream::readLine(long long) (qtextstream.cpp:1676)
==46171==    by 0xC79078: mixxx::skin::legacy::LegacySkin::fitsScreenSize(QScreen const&) const (legacyskin.cpp:97)
==46171==    by 0xC0B548: DlgPrefInterface::DlgPrefInterface(QWidget*, std::shared_ptr<mixxx::ScreensaverManager>, std::shared_ptr<mixxx::skin::SkinLoader>, QSharedPointer<ConfigObject<ConfigValue> >) (dlgprefinterface.cpp:159)
==46171==    by 0xC02EF3: DlgPreferences::DlgPreferences(std::shared_ptr<mixxx::ScreensaverManager>, std::shared_ptr<mixxx::skin::SkinLoader>, std::shared_ptr<SoundManager>, std::shared_ptr<ControllerManager>, std::shared_ptr<VinylControlManager>, std::shared_ptr<EffectsManager>, std::shared_ptr<SettingsManager>, std::shared_ptr<Library>) (dlgpreferences.cpp:145)
==46171==    by 0xEE7237: MixxxMainWindow::initialize() (mixxxmainwindow.cpp:299)
==46171==    by 0x9775096: UnknownInlinedFun (qobjectdefs_impl.h:398)
==46171==    by 0x9775096: void doActivate<false>(QObject*, int, void**) (qobject.cpp:3925)

Does this have anything to do with my crash?

As always, here's the full log: valgrind.log

daschuer commented 1 year ago

It looks like the conditional jump happens in a library without debug information for 0x1C22B301 and 0x1A62BBC7. You may add a breakpoint at these addressed to get an idea where the point is.

The memory itself should be a short live time memory used in QTextStream: https://github.com/mixxxdj/mixxx/blob/c1665e50e9045cfe8fce70308d78fb002c5e41e5/src/skin/legacy/legacyskin.cpp#L97

I am afraid we cannot do much about it.

robbert-vdh commented 12 months ago

For more context, I created a thread about this on Zulip back in July: https://mixxx.zulipchat.com/#narrow/stream/109171-development/topic/QJSEngine.20segfaulting.20on.20initializing/near/375832083

I remember everything working fine with qt5-declarative version 5.15.9+kde+r26, and 5.15.10+kde+r26 was the first one that broke things. There's definitely a UB issue somewhere, but I'm still not entirely sure if it's on entirely Qt's side or if Mixxx is also doing something specific to trigger this. It also doesn't seem to be related to Arch's compilation settings. I built the latest qt6-declarative with -DCMAKE_BUILD_TYPE=Release and with LTO disabled and CFLAGS, CXXFLAGS, and LDFLAGS unset and the problem still occurs.

napaalm commented 11 months ago

I'd also add that mixxx build optimizations don't affect this bug: I tried with -O0, -O3 and -march=native and the crash still occurs.

napaalm commented 11 months ago

As we've just discussed on Zulip, it turns out that the crash is caused by a failed madvise(MADV_DONTNEED) with errno = EINVAL. Here's the relevant snippet from qt-declarative:

    while (madvise(result, bytes, MADV_DONTNEED)) {
        if (errno != EAGAIN)
            CRASH();
    }

The reason of the failure is that there's a previous call to mlockall(MCL_CURRENT|MCL_FUTURE) by pipewire-jack, which is configured to do so to reduce latency. In my system that option is specified in the file .config/pipewire/jack.conf.d/90-tunings.conf:

context.properties = {
    # ...
    mem.mlock-all   = true
    # ...
}

The reason of the madvise failure is explained in its man page:

SYNOPSIS
       #include <sys/mman.h>

       int madvise(void addr[.length], size_t length, int advice);

ERRORS
       EINVAL advice is MADV_DONTNEED or MADV_REMOVE and the specified address range in‐
              cludes locked, Huge TLB pages, or VM_PFNMAP pages.

@Swiftb0y then wrote a minimal example that I will now report to the Qt bug tracker

#include <sys/mman.h>

#include <QCoreApplication>
#include <QDebug>
#include <QJSEngine>

int main(int argc, char *argv[])
{
    QCoreApplication a(argc, argv);

    qDebug() << QT_VERSION_MAJOR << QT_VERSION_MINOR << QT_VERSION_PATCH;

    // lock memory (as done by for example Pipewire with a Pro-Audio config).
    mlockall(MCL_CURRENT|MCL_FUTURE);

    QJSEngine engine;
    // no need to do anything else, we've crashed by now.

    return a.exec();
}
napaalm commented 11 months ago

I just opened QTBUG-120450.

ronso0 commented 11 months ago

IIUC this is not a Mixxx issue (and we can't do much except wait for it being fixed upstream) so we can remove it from the 2.4 milestone, right?

m0dB commented 11 months ago

We should probably document the workaround somewhere (set mem.mlock-all to false in .config/pipewire/jack.conf.d/90-tunings.conf). At least, I assume that is the workaround, right @napaalm ?

Do we have a "known issues" document or section in the documentation?

ronso0 commented 11 months ago

Do we have a "known issues" document or section in the documentation?

None that I'm aware of unfortunately. We can add it to the release note (or add a link to a "known issues" list to be created).

napaalm commented 11 months ago

We should probably document the workaround somewhere (set mem.mlock-all to false in .config/pipewire/jack.conf.d/90-tunings.conf). At least, I assume that is the workaround, right @napaalm ?

Well, one's custom config file might be somewhere else or have a different name, and also by default it's false, so I would just write that it shouldn't be enabled.

ywwg commented 11 months ago

+1 removing this issue from the milestone / closing it as Not Our Bug

ywwg commented 11 months ago

(and adding something to our Known Issues / Release Notes)

ronso0 commented 11 months ago

Alright, I'll close it, leave it in 2.4 and add Changelog so we have some sort of reminder for the Known Issues list.

napaalm commented 10 months ago

The issue has been solved upstream for all currently maintained versions of Qt (5.15 included): https://bugreports.qt.io/browse/QTBUG-120450

daschuer commented 10 months ago

Perfect Thank you for taking care. I will update the Changelog accordingly.

daschuer commented 10 months ago

For my understanding it is a Linux regression introduced in v5.15.5-lts-lgpl https://github.com/qt/qtdeclarative/commit/f4a55f7633d5ee2534363fc45129c86a5fae5d6b Fixed by QTBUG-120450 in 5.15.17 https://github.com/qt/qtdeclarative/commit/524d260c5c135d193e06350e48357444ddb13ddb

napaalm commented 10 months ago

@daschuer yes, exactly

napaalm commented 9 months ago

@daschuer the fix has been merged in the KDE repo for Qt 5.15.

https://invent.kde.org/qt/qt/qtdeclarative/-/merge_requests/56

So, at least on Arch, it's fixed in qt5-declarative version 5.15.12+kde+r32-1 onwards.