segmentation fault after rating couple of songs

Bug #1365708 reported by Thomas
18
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Mixxx
Fix Released
Critical
Owen Williams

Bug Description

mixxx crashes reproducible with "segmentation fault" message after rating of about 20 mp3 songs.

gdb output:
Program received signal SIGSEGV, Segmentation fault.
0x00000000008b73ef in unlink (n=..., this=<optimized out>) at /usr/include/qt4/QtCore/qcache.h:69
69 if (n.n) n.n->p = n.p;

Testing conditions:
- mixxx 1.11 stable and newest trunk r4593
- ubuntu studio with 3.13.0-34-lowlatency kernel
- Intel Core 2 Duo T9400 @ 2.53 GHz
- Intel Corporation Mobile 4 Series Chipset Integrated Graphics Controller using i915 kernel driver
- Intel Corporation 82801I (ICH9 Family) HD Audio Controller

Revision history for this message
Owen Williams (ywwg) wrote :

can you post the full gdb backtrace?

Revision history for this message
Thomas (jahthomas) wrote :
Download full text (63.4 KiB)

Strange, now the last line of error changed. I didn't change anything. But the rating is saved after restarting mixxx! Here is the full backtrace:

Starting program: /usr/bin/mixxx
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7fffdd492700 (LWP 2814)]
[New Thread 0x7fffdcc91700 (LWP 2815)]
[New Thread 0x7fffd7fff700 (LWP 2816)]
[New Thread 0x7fffd77fe700 (LWP 2817)]
Debug [Main]: Mixxx "1.12.0-alpha" "(git master r4593; built on: Sep 4 2014 @ 12:40:15; flags: autodjcrates bulk hid mad optimize=4 qdebug shoutcast vamp verbose vinylcontrol)" is starting...
Debug [Main]: Qt version is: 4.8.6
Debug [Main]: QDesktopServices::storageLocation(HomeLocation): "/home/thomas"
Debug [Main]: QDesktopServices::storageLocation(DataLocation): "/home/thomas/.local/share/data//Mixxx"
Debug [Main]: QCoreApplication::applicationDirPath() "/usr/bin"
Debug [Main]: Configuration file is at the current version 1.12.0-alpha
Debug [Main]: Loading translations for locale "de_DE" from translations folder "/usr/share/mixxx/translations/" : success
[New Thread 0x7fffd6ffd700 (LWP 2818)]
Debug [Main]: Compressor attack per frame: 0.000408163 decay per frame: 4.08163e-05
[New Thread 0x7fffd67fc700 (LWP 2819)]
Debug [Main]: PortAudio version: 1899 text: PortAudio V19-devel (built Feb 25 2014 21:09:53)
Debug [Main]: JACK client name set
ALSA lib pcm.c:2239:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2239:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2239:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
[New Thread 0x7fffc6f46700 (LWP 2820)]
[Thread 0x7fffc6f46700 (LWP 2820) exited]
[New Thread 0x7fffc6f46700 (LWP 2821)]
[Thread 0x7fffc6f46700 (LWP 2821) exited]
bt_audio_service_open: connect() failed: Verbindungsaufbau abgelehnt (111)
bt_audio_service_open: connect() failed: Verbindungsaufbau abgelehnt (111)
bt_audio_service_open: connect() failed: Verbindungsaufbau abgelehnt (111)
bt_audio_service_open: connect() failed: Verbindungsaufbau abgelehnt (111)
[New Thread 0x7fffc6f46700 (LWP 2822)]
[Thread 0x7fffc6f46700 (LWP 2822) exited]
[New Thread 0x7fffc6f46700 (LWP 2823)]
[Thread 0x7fffc6f46700 (LWP 2823) exited]
[New Thread 0x7fffc6f46700 (LWP 2828)]
[Thread 0x7fffc6f46700 (LWP 2828) exited]
[New Thread 0x7fffc6f46700 (LWP 2831)]
[New Thread 0x7fffc579c700 (LWP 2832)]
Debug [Main]: RubberBand version 1.8.1
Debug [Main]: WARNING: AudioInput already registered!
[New Thread 0x7fffbffff700 (LWP 2833)]
Debug [Main]: RubberBand version 1.8.1
Debug [Main]: WARNING: AudioInput already registered!
[New Thread 0x7fffbea25700 (LWP 2834)]
Debug [Main]: RubberBand version 1.8.1
Debug [Main]: WARNING: AudioInput already registered!
[New Thread 0x7fffbd36d700 (LWP 2835)]
Debug [Main]: RubberBand version 1.8.1
Debug [Main]: WARNING: AudioInput already registered!
[New Thread 0x7fffa7afe700 (LWP 2836)]
Debug [Main]: RubberBand version 1.8.1
[New Thread 0x7fffa65c1700 (LWP 2837)]
Debug [Main]: RubberBand version 1.8.1
[New Thread 0x7fffa4f09700 (LWP 2838)]
Debug [Main]: RubberBand version 1.8.1
[New Thread 0x7fff977ed700 (LWP 2839...

Revision history for this message
Daniel Schürmann (daschuer) wrote :

Thank you for the infos.
Please provide the call-stack that leads t o the error as well.
http://mixxx.org/wiki/doku.php/creating_backtraces

Revision history for this message
jus (jus) wrote :

As a side not, i noticed the following warnings in your logs, that indicate errors in the German translation.
"Warning [Main]: QString::arg: Argument missing: "Mikrofon % 1" and "Warning [Main]: QString::arg: Argument missing: Vorschau von Hotcue % 1"

Fixed in https://github.com/mixxxdj/mixxx/commit/89a3df0934d264eea03f4b0cf1ded0631b782686

Revision history for this message
Thomas (jahthomas) wrote :
Download full text (19.8 KiB)

So this should be the call stack:

(gdb) thread apply all bt

Thread 30 (Thread 0x7fff0393f700 (LWP 2442)):
#0 0x00007ffff1dfac6d in poll () at ../sysdeps/unix/syscall-template.S:81
#1 0x00007ffff0620fe4 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#2 0x00007ffff06210ec in g_main_context_iteration ()
   from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#3 0x00007ffff57ec7be in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#4 0x00007ffff57be0af in QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#5 0x00007ffff57be3a5 in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#6 0x00007ffff56bac5f in QThread::exec() ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#7 0x00007ffff579f823 in ?? () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#8 0x00007ffff56bd32f in ?? () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#9 0x00007ffff34a3182 in start_thread (arg=0x7fff0393f700)
    at pthread_create.c:312
#10 0x00007ffff1e07fbd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 29 (Thread 0x7fff84ac8700 (LWP 2436)):
#0 pthread_cond_wait@@GLIBC_2.3.2 ()
---Type <return> to continue, or q <return> to quit---
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007ffff5ff4ffb in ?? () from /usr/lib/x86_64-linux-gnu/libQtScript.so.4
#2 0x00007ffff5ff5039 in ?? () from /usr/lib/x86_64-linux-gnu/libQtScript.so.4
#3 0x00007ffff34a3182 in start_thread (arg=0x7fff84ac8700)
    at pthread_create.c:312
#4 0x00007ffff1e07fbd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 28 (Thread 0x7fff852c9700 (LWP 2435)):
#0 0x00007ffff1dfac6d in poll () at ../sysdeps/unix/syscall-template.S:81
#1 0x00007ffff7bbd9b8 in ?? ()
   from /usr/lib/x86_64-linux-gnu/libportaudio.so.2
#2 0x00007ffff7bbe5e0 in ?? ()
   from /usr/lib/x86_64-linux-gnu/libportaudio.so.2
#3 0x00007ffff34a3182 in start_thread (arg=0x7fff852c9700)
    at pthread_create.c:312
#4 0x00007ffff1e07fbd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 27 (Thread 0x7fff8a252700 (LWP 2434)):
#0 pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007ffff56bd816 in QWaitCondition::wait(QMutex*, unsigned long) ()
---Type <return> to continue, or q <return> to quit---
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#2 0x00007ffff56b995b in QSemaphore::acquire(int) ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#3 0x0000000000a69132 in VSyncThread::run (this=0x309f5f0)
    at src/waveform/vsyncthread.cpp:102
#4 0x00007ffff56bd32f in ?? () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#5 0x00007ffff34a3182 in start_thread (arg=0x7fff8a252700)
    at pthread_create.c:312
#6 0x00007ffff1e07fbd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 26 (Thread 0x7fff8b7fe700 (LWP 2433)):
#0 0x00007ffff1dfac6d in poll () at ../sysdeps/unix/syscall-template.S:81
#1 0x00007ffff0620fe4 in ?? () from /lib/x86_64-linux-gnu/libglib-2....

Revision history for this message
Owen Williams (ywwg) wrote :

Is that backtrace for 1.11 or trunk? Trunk would be more convenient.

My suspicion is a corrupt database

Revision history for this message
Thomas (jahthomas) wrote :

That is the backtrace for trunk 4593. How could i test if my database is corrupt?

Revision history for this message
Owen Williams (ywwg) wrote :

hm actually it looks like it could be a threading bug. It's crashing trying to remove an item from the cache, but by the time it gets there the item is already gone. So maybe there's another thread also trying to work with the cache at the same time.

Revision history for this message
Owen Williams (ywwg) wrote :

I can reproduce this too so I'll poke at it

Revision history for this message
Owen Williams (ywwg) wrote :

(it's not a corrupt database)

Revision history for this message
Owen Williams (ywwg) wrote :

OK so this happens because trackdao tries to call setKeyText if it doesn't find a valid key. It then marks the track as dirty.

But then a copy of the track is inserted into the track cache, and this somehow (??) triggers a delete of the track pointer that was just made. The track pointer is dirty, so it tries to save itself, and now it's trying to save itself while it's being deleted and all hell breaks loose.

Changed in mixxx:
status: New → Confirmed
importance: Undecided → Critical
milestone: none → 1.12.0
Revision history for this message
Owen Williams (ywwg) wrote :
Download full text (25.9 KiB)

Even after removing the dirty call I get the crash:

Debug [Main]: BaseTrackCache(0x2de50b0) updateIndexWithQuery took 1 ms

Program received signal SIGSEGV, Segmentation fault.
0x00000000008bf90a in unlink (n=..., this=<optimized out>) at /usr/include/qt4/QtCore/qcache.h:69
69 if (n.n) n.n->p = n.p;
(gdb) thread apply all bt

Thread 31 (Thread 0x7fff45ffe700 (LWP 31747)):
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007ffff5ff4ffb in ?? () from /usr/lib/x86_64-linux-gnu/libQtScript.so.4
#2 0x00007ffff5ff5039 in ?? () from /usr/lib/x86_64-linux-gnu/libQtScript.so.4
#3 0x00007ffff34a2182 in start_thread (arg=0x7fff45ffe700) at pthread_create.c:312
#4 0x00007ffff1e06fbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 30 (Thread 0x7fff4cf63700 (LWP 31744)):
#0 0x00007ffff1df9c6d in poll () at ../sysdeps/unix/syscall-template.S:81
#1 0x00007ffff7bbd9b8 in ?? () from /usr/lib/x86_64-linux-gnu/libportaudio.so.2
#2 0x00007ffff7bbe5e0 in ?? () from /usr/lib/x86_64-linux-gnu/libportaudio.so.2
#3 0x00007ffff34a2182 in start_thread (arg=0x7fff4cf63700) at pthread_create.c:312
#4 0x00007ffff1e06fbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 29 (Thread 0x7fff57fff700 (LWP 31743)):
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1 0x00007ffff56bd816 in QWaitCondition::wait(QMutex*, unsigned long) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#2 0x00007ffff56b995b in QSemaphore::acquire(int) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#3 0x0000000000a8a6f3 in VSyncThread::run (this=0x2f50600) at src/waveform/vsyncthread.cpp:102
#4 0x00007ffff56bd32f in ?? () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#5 0x00007ffff34a2182 in start_thread (arg=0x7fff57fff700) at pthread_create.c:312
#6 0x00007ffff1e06fbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 28 (Thread 0x7fff657fb700 (LWP 31742)):
#0 0x00007ffff1df9c6d in poll () at ../sysdeps/unix/syscall-template.S:81
#1 0x00007ffff061ffe4 in g_main_context_poll (priority=2147483647, n_fds=1, fds=0x7fff5c00b090, timeout=-1, context=0x7fff5c0009a0)
    at /build/buildd/glib2.0-2.40.0/./glib/gmain.c:4028
#2 g_main_context_iterate (context=context@entry=0x7fff5c0009a0, block=block@entry=1, dispatch=dispatch@entry=1, self=<optimized out>)
    at /build/buildd/glib2.0-2.40.0/./glib/gmain.c:3729
#3 0x00007ffff06200ec in g_main_context_iteration (context=0x7fff5c0009a0, may_block=1) at /build/buildd/glib2.0-2.40.0/./glib/gmain.c:3795
#4 0x00007ffff57ec7a1 in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#5 0x00007ffff57be0af in QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#6 0x00007ffff57be3a5 in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#7 0x00007ffff56bac5f in QThread::exec() () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#8 0x00007ffff56bd32f in ?? () from /usr/lib/x86_64-lin...

Revision history for this message
Owen Williams (ywwg) wrote :

(gdb) print n
$1 = (QCache<int, QSharedPointer<TrackInfoObject> >::Node &) @0x4e81c30: {keyPtr = 0x4e81c3a, t = 0x720061003a0000, c = 6881396,
  p = 0x10164e90, n = 0x40}
(gdb) print n.n
$2 = (QCache<int, QSharedPointer<TrackInfoObject> >::Node *) 0x40
(gdb) print n.n->p
Cannot access memory at address 0x58
(gdb) print n.p
$3 = (QCache<int, QSharedPointer<TrackInfoObject> >::Node *) 0x10164e90
(gdb)

Revision history for this message
Owen Williams (ywwg) wrote :

http://pastebin.com/wa91JJJh

http://pastebin.com/vn9ns1Mf

So the root cause is that QCache was removing an item from the cache, which triggered a track save, which triggered a UI update, which causes a read from the cache, which doesn't have the item, so it added an item to the cache... and then at that point QCache is in a corrupt state because it thought it was removing an item but it had just added it back. This didn't cause a crash right away, it just shrunk the cache size by 1. And then it would shrink again and again until the cache was empty, and then it crashed.

The near-term solution is to make sure the UI updates are not DirectConnections

Revision history for this message
Owen Williams (ywwg) wrote :

This is fixed, and I opened a bug to really fix the underlying problem. https://bugs.launchpad.net/mixxx/+bug/1366157

Changed in mixxx:
status: Confirmed → Fix Committed
assignee: nobody → Owen Williams (ywwg)
Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Signaling a ton of stuff when the refcount drops to 0 on a TrackPointer seems like it's cause more trouble these days then it helps. To help break this up I think we should switch to calling deleteLater on TIO when refcount drops to 0 and then doing the database / GUI updates on the next event cycle. I'll submit a PR.

RJ Skerry-Ryan (rryan)
Changed in mixxx:
status: Fix Committed → Fix Released
Revision history for this message
Swiftb0y (swiftb0y) wrote :

Mixxx now uses GitHub for bug tracking. This bug has been migrated to:
https://github.com/mixxxdj/mixxx/issues/7569

lock status: Metadata changes locked and limited to project staff
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.