qhash.h:790 ASSERT on multiple MIDI messages in quick succession #13940

mxmilkiib · 2024-11-27T04:37:22Z

Bug Description

When my script sends multiple MIDI sysex messages in quick succession, it often makes Mixxx trigger an assert;

 [Controller] fatal /usr/include/qt6/QtCore/qhash.h:790 ASSERT: "!isUnused()" in file /usr/include/qt6/QtCore/qhash.h, line 790

Version

No response

OS

No response

The text was updated successfully, but these errors were encountered:

Swiftb0y · 2024-11-27T09:01:54Z

Thank you for reporting your issue. Please understand that in order for us to be able to properly debug this, we need a backtrace. Have a look at the wiki for finding out how to create one: https://github.com/mixxxdj/mixxx/wiki/Creating%20Backtraces

mxmilkiib · 2024-11-29T06:19:45Z

https://gist.github.com/mxmilkiib/9bee33b0ed7113243c9e1a3a14d5ae01
https://gist.github.com/mxmilkiib/6fe50aeaee3200dd1ff2d346f1b2f978#file-launchpadpromk3-js

daschuer · 2024-11-29T08:07:15Z

The assertion violation happens here:
https://github.com/qt/qtbase/blob/4059ea60e52291ca7e2c9086663c3c3e10839090/src/corelib/tools/qhash.h#L790

Probably a race condition?

daschuer · 2024-11-29T08:15:29Z

Which version of Mixxx is affected?

Please create a Backtraces:
https://github.com/mixxxdj/mixxx/wiki/Creating-Backtraces

Does Mixxx crash?

mxmilkiib · 2024-11-29T10:28:15Z

I should have said, the first link in the last post is what I got from following those instructions (which fwiw could mention gdb -ex "set height 0")

n yes, crashes

I pulled n built before testing, r2.6-alpha-138-g0eccb1b2db (main)

daschuer · 2024-11-29T15:31:25Z

https://github.com/daschuer/mixxx/blob/8b81a37302b68e3b072c96cc1539fe578c34976e/src/controllers/midi/midicontroller.cpp#L290

So the race may happen around: LegacyMidiControllerMapping::m_inputMappings
However, there is noting obvious.

Is this only a side effect and we are using a dangling pointer, because the m_pMapping is already down?
Or is m_pMapping still null?

Al least there are a couple of race conditions happening possible with m_pMapping.
std::shared_ptr is thread safe, but the pointer may change between two calls.

This means m_pMapping->getInputMappings().constEnd() point to a new mapping while it still points to the old.
The function needs to become an shared owner first before using the m_pMappings.

Please try to alter the code to:

    // Function becomes temorary shared owner 
    std::shared_ptr<LegacyMidiControllerMapping> pMapping = m_pMapping; 
    if (!pMapping) {
        return; 
    }
    auto it = pMapping->getInputMappings().constFind(mappingKey.key);
    for (; it != pMapping->getInputMappings().constEnd() && it.key() == mappingKey.key; ++it) {

mxmilkiib · 2024-11-29T23:21:19Z

Yes, that change seems to solve the problem, thank you!

edit; what exactly is/was the problem? what part of the process is tripping up?

daschuer · 2024-12-04T23:35:19Z

I have created a PR that aims to fix the issue:
#13980
Please test, and report your results at the PR.
Thank you.

daschuer · 2024-12-04T23:38:58Z

what exactly is/was the problem? what part of the process is tripping up?

The problem is that the crashing function is called from the controller thread, before the mapping is fully loaded. In the moment where the mapping is changed, the code starts to iterate on the old mapping, but tries to finish on the new one which fails.
The solution is to keep the old mapping valid until all users use the new one.

mxmilkiib · 2024-12-05T23:21:05Z

[Controller] fatal /usr/include/qt6/QtCore/qhash.h:1928 ASSERT: "e && *e" in file /usr/include/qt6/QtCore/qhash.h, line 1928

daschuer · 2024-12-06T05:50:28Z

Does this happen with #13980
For my understanding this shall fully fix the issue.
Is the backtrace different now?

mxmilkiib · 2024-12-07T02:41:04Z

yup, trace

daschuer · 2024-12-09T06:45:28Z

I have added more null checks to #13980 Does that make a difference?

mxmilkiib · 2024-12-11T03:07:00Z

still there

I've figured it can be reproduced when the Mixxx window is not the active window

trace https://gist.github.com/mxmilkiib/11c5b4e91faa9fb8d092a3e7978cf8d2

daschuer · 2024-12-11T18:39:04Z

It looks like you don't use my latest branch. At least the line numbers in the backtrace do not correspond to my PR. You can receive my changes into a new branch by

git checkout -b daschuer-gh13940 2.5
git pull [email protected]:daschuer/mixxx.git gh13940

mxmilkiib · 2024-12-12T01:30:25Z

01:21:16 milk@red:~/src/mixxx main ± git checkout -b daschuer-gh13940 2.5
Alias tip: gco -b daschuer-gh13940 2.5
fatal: '2.5' is not a commit and a branch 'daschuer-gh13940' cannot be created from it

01:25:15 milk@red:~/src/mixxx main 130 ± git pull [email protected]:daschuer/mixxx.git gh13940
Alias tip: gpl [email protected]:daschuer/mixxx.git gh13940
From github.com:daschuer/mixxx
 * branch                  gh13940    -> FETCH_HEAD
hint: You have divergent branches and need to specify how to reconcile them.
hint: You can do so by running one of the following commands sometime before
hint: your next pull:
hint:
hint:   git config pull.rebase false  # merge
hint:   git config pull.rebase true   # rebase
hint:   git config pull.ff only       # fast-forward only
hint:
hint: You can replace "git config" with "git config --global" to set a default
hint: preference for all repositories. You can also pass --rebase, --no-rebase,
hint: or --ff-only on the command line to override the configured default per
hint: invocation.
fatal: Need to specify how to reconcile divergent branches.

01:25:18 milk@red:~/src/mixxx main 128 ± gco gh13940
Switched to branch 'gh13940'

01:26:17 milk@red:~/src/mixxx gh13940 ± git pull [email protected]:daschuer/mixxx.git gh13940
Alias tip: gpl [email protected]:daschuer/mixxx.git gh13940
From github.com:daschuer/mixxx
 * branch                  gh13940    -> FETCH_HEAD
Already up to date.

01:26:56 milk@red:~/src/mixxx gh13940 127 ± gl
commit 3d045698e42db3cec38dc037039eff4b4de81e59 (HEAD -> gh13940)
Author: Daniel Schürmann <[email protected]>
Date:   Mon Dec 9 07:44:01 2024 +0100

    Add more null checks
...

daschuer · 2024-12-12T06:27:42Z

Your checkout looks correct.

The most interesting entry in your recent backtrace is this:

#10 MidiController::receivedShortMessage (this=<optimized out>, status=<optimized out>, control=<optimized out>, value=127 '\177', timestamp=...) at /home/milk/src/mixxx/src/controllers/midi/midicontroller.cpp:308
        channel = <optimized out>
        opCode = <optimized out>
        __PRETTY_FUNCTION__ = "virtual void MidiController::receivedShortMessage(unsigned char, unsigned char, unsigned char, mixxx::Duration)"
        mappingKey = {{key = 27824, {status = 176 '\260', control = 108 'l'}}}
        pMapping = std::shared_ptr<LegacyMidiControllerMapping> (use count 130, weak count 0) = {get() = <optimized out>}
        it = {i = {d = <optimized out>, bucket = <optimized out>}, e = 0x7fff2c60a558}

A reference count of 130 does not look reasonable.
So my guess is that the smart pointer is dangling.

At this line, we have a return statement not a crashing call.

mixxx/src/controllers/midi/midicontroller.cpp

Line 308 in 3d04569

return;

So can you try to build again and reproduce the crash?

daschuer · 2024-12-12T06:44:01Z

Ah, got it, you have probably posted the same backtrace again. At least I can see no difference.

mxmilkiib · 2024-12-12T13:53:56Z

hmm, I copied straight from the terminal as it output (clicked and held and waited for the output and let it do the dragging n made sure it got all then middle click pasted as a second file to the same gist entry, though the link above should have been just to the new log not to both of them)

thanks, I'll try again in a while

mxmilkiib · 2024-12-12T22:20:43Z

done, trace

daschuer · 2024-12-13T13:33:50Z

Ah now it fits, thank you ... but still crashing :-(

#10 MidiController::receivedShortMessage (this=<optimized out>, status=<optimized out>, control=<optimized out>, value=127 '\177', timestamp=...) at /home/milk/src/mixxx/src/controllers/midi/midicontroller.cpp:311
        channel = <optimized out>
        opCode = <optimized out>
        __PRETTY_FUNCTION__ = "virtual void MidiController::receivedShortMessage(unsigned char, unsigned char, unsigned char, mixxx::Duration)"
        mappingKey = {{key = 27824, {status = 176 '\260', control = 108 'l'}}}
        pMapping = std::shared_ptr<LegacyMidiControllerMapping> (use count 123, weak count 0) = {get() = <optimized out>}
        it = {i = {d = <optimized out>, bucket = <optimized out>}, e = 0x7fff2c6cd028}

use count =123 is obviously in correct. It starts with use count = 1, asserted here:

mixxx/src/controllers/controller.h

Line 121 in 24a84b9

VERIFY_OR_DEBUG_ASSERT(pMapping.use_count() == 1) {

and there are not 123 owners.

Maybe ControllerManager::updateControllerList() is called while the controlle is still receiving messages?
I have added an assertion. Maybe you hit it?
Please try.

mxmilkiib · 2024-12-13T20:46:16Z

https://gist.github.com/mxmilkiib/22a21982511fdbf36d5169699a99615e

mxmilkiib · 2024-12-18T02:31:38Z

might there be anything further I could do to help diagnose this?

mxmilkiib · 2025-01-04T08:26:37Z

possible this could get another look?

daschuer · 2025-01-04T11:26:50Z

This is the significant part of the backtrace

#8  0x00007ffff0091604 in qt_assert (assertion=assertion@entry=0x555555706de4 "e && *e", file=file@entry=0x5555556b2b90 "/usr/include/qt6/QtCore/qhash.h", line=line@entry=1928) at /usr/src/debug/qt6-base/qtbase/src/corelib/global/qassert.cpp:105
#9  0x000055555615f22a in QMultiHash<unsigned short, MidiInputMapping>::const_iterator::operator++ (this=<synthetic pointer>) at /usr/include/qt6/QtCore/qhash.h:1928
#10 MidiController::receivedShortMessage (this=<optimized out>, status=<optimized out>, control=<optimized out>, value=127 '\177', timestamp=...) at /home/milk/src/mixxx/src/controllers/midi/midicontroller.cpp:311
        channel = <optimized out>
        opCode = <optimized out>
        __PRETTY_FUNCTION__ = "virtual void MidiController::receivedShortMessage(unsigned char, unsigned char, unsigned char, mixxx::Duration)"
        mappingKey = {{key = 27824, {status = 176 '\260', control = 108 'l'}}}
        pMapping = std::shared_ptr<LegacyMidiControllerMapping> (use count 123, weak count 0) = {get() = <optimized out>}
        it = {i = {d = <optimized out>, bucket = <optimized out>}, e = 0x7fff2c0411e8}
#11 0x00005555566f10c5 in PortMidiController::poll (this=0x7fff2c0b5fc0) at /home/milk/src/mixxx/src/controllers/midi/portmidicontroller.cpp:153
        note = <optimized out>
        velocity = <optimized out>
        status = 176 '\260'
        timestamp = {<mixxx::DurationBase> = {static kMillisPerSecond = 1000, static kMicrosPerSecond = 1000000, static kNanosPerSecond = 1000000000, static kNanosPerMilli = 1000000, static kNanosPerMicro = 1000, m_durationNanos = <optimized out>}, <No data fields>}
        i = <optimized out>
        numEvents = 1
        __PRETTY_FUNCTION__ = "virtual bool PortMidiController::poll()"
#12 0x0000555555a4a865 in ControllerManager::pollDevices (this=0x5555869ff800) at /home/milk/src/mixxx/src/controllers/controllermanager.cpp:377
        pDevice = 0x7fff2c0b5fc0
        __for_range = <optimized out>
        __for_begin = {i = <optimized out>}
        __for_end = {i = <optimized out>}
        start = {<mixxx::DurationBase> = {static kMillisPerSecond = 1000, static kMicrosPerSecond = 1000000, static kNanosPerSecond = 1000000000, static kNanosPerMilli = 1000000, static kNanosPerMicro = 1000, m_durationNanos = 21469449942}, <No data fields>}
        duration = {<mixxx::DurationBase> = {static kMillisPerSecond = 1000, static kMicrosPerSecond = 1000000, static kNanosPerSecond = 1000000000, static kNanosPerMilli = 1000000, static kNanosPerMicro = 1000, m_durationNanos = <optimized out>}, <No data fields>}
#13 0x00007ffff01b1b29 in QtPrivate::QSlotObjectBase::call (this=0x555586a12160, r=0x5555869ff800, a=0x7fffa3ff5d00, this=<optimized out>, r=<optimized out>, a=<optimized out>) at /usr/src/debug/qt6-base/qtbase/src/corelib/kernel/qobjectdefs_impl.h:486
#14 doActivate<false> (sender=<optimized out>, signal_index=<optimized out>, argv=<optimized out>) at /usr/src/debug/qt6-base/qtbase/src/corelib/kernel/qobject.cpp:4124
        obj = {m_slotObject = std::unique_ptr<QtPrivate::QSlotObjectBase> = {get() = 0x555586a12160}}
        receiver = 0x5555869ff800
        td = <optimized out>
        receiverInSameThread = <optimized out>
        senderData = {previous = 0x0, receiver = 0x5555869ff800, sender = 0x5555869ff828, signal = 3}
        c = 0x7fff38013b70
        connections = {d = <optimized out>}
        list = <optimized out>
        inSenderThread = <optimized out>
        highestConnectionId = <optimized out>
        signalVector = 0x555586a12540
        currentThreadId = <optimized out>
        sp = <optimized out>
        signal_spy_set = 0x0
        empty_argv = {0x0}
        senderDeleted = false
#15 0x00007ffff01bab35 in QTimer::timeout (this=0x5555869ff828, _t1=...) at /usr/src/debug/qt6-base/build/src/corelib/Core_autogen/include/moc_qtimer.cpp:223
        _a = {0x0, 0x7fffa3ff5cf8}

daschuer · 2025-01-04T20:06:50Z

I have added more assertions regarding use_count() to #13980
Please reproduce the crash and provide the mixxx.log from the carshing run.

daschuer · 2025-01-04T20:59:40Z

Wait, test is failing which is good.

mxmilkiib · 2025-01-05T20:41:38Z

https://gist.github.com/mxmilkiib/c03f40ffa554341178bfe238cbff3155

daschuer · 2025-01-10T12:54:29Z

I have created #14159 which may fix the issue. Please test.

mxmilkiib added the bug label Nov 27, 2024

daschuer mentioned this issue Dec 4, 2024

Fix crash due to concurrent access in MidiController #13980

Draft

daschuer mentioned this issue Dec 13, 2024

(fix) Controller: clear mapping pointer when unloading a mapping #13907

Merged

daschuer added a commit to daschuer/mixxx that referenced this issue Jan 10, 2025

Use a mutex as a last resort for fixing mixxxdj#13940

fc7fdf0

daschuer linked a pull request Jan 10, 2025 that will close this issue

Fix crash due to concurrent access in MidiController (Alternative) #14159

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

qhash.h:790 ASSERT on multiple MIDI messages in quick succession #13940

qhash.h:790 ASSERT on multiple MIDI messages in quick succession #13940

mxmilkiib commented Nov 27, 2024 •

edited

Loading

Swiftb0y commented Nov 27, 2024

mxmilkiib commented Nov 29, 2024

daschuer commented Nov 29, 2024

daschuer commented Nov 29, 2024

mxmilkiib commented Nov 29, 2024

daschuer commented Nov 29, 2024

mxmilkiib commented Nov 29, 2024 •

edited

Loading

daschuer commented Dec 4, 2024

daschuer commented Dec 4, 2024

mxmilkiib commented Dec 5, 2024

daschuer commented Dec 6, 2024

mxmilkiib commented Dec 7, 2024

daschuer commented Dec 9, 2024

mxmilkiib commented Dec 11, 2024 •

edited

Loading

daschuer commented Dec 11, 2024 •

edited

Loading

mxmilkiib commented Dec 12, 2024

daschuer commented Dec 12, 2024

daschuer commented Dec 12, 2024

mxmilkiib commented Dec 12, 2024

mxmilkiib commented Dec 12, 2024

daschuer commented Dec 13, 2024

mxmilkiib commented Dec 13, 2024

mxmilkiib commented Dec 18, 2024

mxmilkiib commented Jan 4, 2025

daschuer commented Jan 4, 2025

daschuer commented Jan 4, 2025

daschuer commented Jan 4, 2025

mxmilkiib commented Jan 5, 2025

daschuer commented Jan 10, 2025

qhash.h:790 ASSERT on multiple MIDI messages in quick succession #13940

qhash.h:790 ASSERT on multiple MIDI messages in quick succession #13940

Comments

mxmilkiib commented Nov 27, 2024 • edited Loading

Bug Description

Version

OS

Swiftb0y commented Nov 27, 2024

mxmilkiib commented Nov 29, 2024

daschuer commented Nov 29, 2024

daschuer commented Nov 29, 2024

mxmilkiib commented Nov 29, 2024

daschuer commented Nov 29, 2024

mxmilkiib commented Nov 29, 2024 • edited Loading

daschuer commented Dec 4, 2024

daschuer commented Dec 4, 2024

mxmilkiib commented Dec 5, 2024

daschuer commented Dec 6, 2024

mxmilkiib commented Dec 7, 2024

daschuer commented Dec 9, 2024

mxmilkiib commented Dec 11, 2024 • edited Loading

daschuer commented Dec 11, 2024 • edited Loading

mxmilkiib commented Dec 12, 2024

daschuer commented Dec 12, 2024

daschuer commented Dec 12, 2024

mxmilkiib commented Dec 12, 2024

mxmilkiib commented Dec 12, 2024

daschuer commented Dec 13, 2024

mxmilkiib commented Dec 13, 2024

mxmilkiib commented Dec 18, 2024

mxmilkiib commented Jan 4, 2025

daschuer commented Jan 4, 2025

daschuer commented Jan 4, 2025

daschuer commented Jan 4, 2025

mxmilkiib commented Jan 5, 2025

daschuer commented Jan 10, 2025

mxmilkiib commented Nov 27, 2024 •

edited

Loading

mxmilkiib commented Nov 29, 2024 •

edited

Loading

mxmilkiib commented Dec 11, 2024 •

edited

Loading

daschuer commented Dec 11, 2024 •

edited

Loading