waveform thread goes unresponsive, gets caught in loop

[Mark Glines]

Occasionally, the waveform thread in mixxx 1.6.0 goes autistic and stops rendering waveforms for newly loaded tracks. Tracks loaded after this point are not displayed in the main waveform view window, and that thread's CPU usage goes to 100%. I am seeing this on linux x86-64. It is unpredictable, it occurs anywhere from 30min to 4+ hours after program start.

In the following dump, thread 18 (LWP 8270) is the offending thread:

Program received signal SIGTSTP, Stopped (user).
[Switching to Thread 0x7fc338e1e750 (LWP 8212)]
0x00007fc33280b6b6 in poll () from /lib/libc.so.6
(gdb) thread apply all bt

Thread 24 (Thread 0x454ac950 (LWP 8279)):
#0 0x00007fc33280b6b6 in poll () from /lib/libc.so.6
#1 0x00007fc333f3482b in PaAlsaStream_WaitForFrames ()
   from /usr/lib/libportaudio.so.2
#2 0x00007fc333f3607f in CallbackThreadFunc () from /usr/lib/libportaudio.so.2
#3 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#4 0x00007fc332813fdd in clone () from /lib/libc.so.6
#5 0x0000000000000000 in ?? ()

Thread 23 (Thread 0x44cab950 (LWP 8277)):
#0 0x00007fc333d16d89 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1 0x00007fc334f551d0 in QWaitCondition::wait ()
   from /usr/lib/qt4/libQtCore.so.4
#2 0x00000000005a28e2 in VinylControlXwax::run (this=0x34b7fc0)
    at src/vinylcontrolxwax.cpp:138
#3 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#4 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#5 0x00007fc332813fdd in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

---Type <return> to continue, or q <return> to quit---
Thread 22 (Thread 0x444aa950 (LWP 8276)):
#0 0x00007fc333d16d89 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1 0x00007fc334f551d0 in QWaitCondition::wait ()
   from /usr/lib/qt4/libQtCore.so.4
#2 0x00000000005a28e2 in VinylControlXwax::run (this=0x34b10a0)
    at src/vinylcontrolxwax.cpp:138
#3 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#4 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#5 0x00007fc332813fdd in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 20 (Thread 0x43ca9950 (LWP 8272)):
#0 0x00007fc33280b6b6 in poll () from /lib/libc.so.6
#1 0x0000000000556910 in MidiObjectALSASeq::run (this=0x27c6130)
    at src/midiobjectalsaseq.cpp:262
#2 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#3 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#4 0x00007fc332813fdd in clone () from /lib/libc.so.6
#5 0x0000000000000000 in ?? ()

Thread 19 (Thread 0x434a8950 (LWP 8271)):
#0 0x00007fc333d16d89 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1 0x00007fc334f551d0 in QWaitCondition::wait ()
   from /usr/lib/qt4/libQtCore.so.4
#2 0x0000000000513694 in BpmDetector::run (this=0x27311e0)
    at src/bpmdetector.cpp:359
#3 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#4 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#5 0x00007fc332813fdd in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 18 (Thread 0x42ca7950 (LWP 8270)):
#0 0x000000000050fd98 in WaveSummary::visualWaveformGen (
    this=<value optimized out>, pTrackInfoObject=0x7fc32880a270,
    pSoundSource=0x374c440) at src/wavesummary.cpp:226
#1 0x0000000000510dde in WaveSummary::run (this=0x33d7190)
    at src/wavesummary.cpp:94
#2 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#3 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#4 0x00007fc332813fdd in clone () from /lib/libc.so.6
#5 0x0000000000000000 in ?? ()

Thread 17 (Thread 0x424a6950 (LWP 8268)):
#0 0x00007fc33280d732 in select () from /lib/libc.so.6
#1 0x00007fc334fde48a in QProcessManager::run ()
   from /usr/lib/qt4/libQtCore.so.4
#2 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#3 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#4 0x00007fc332813fdd in clone () from /lib/libc.so.6
#5 0x0000000000000000 in ?? ()

Thread 4 (Thread 0x41ca5950 (LWP 8215)):
#0 0x00007fc333d16d89 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1 0x00007fc334f551d0 in QWaitCondition::wait ()
   from /usr/lib/qt4/libQtCore.so.4
#2 0x000000000054d889 in EngineSideChain::run (this=0x26ed750)
    at src/enginesidechain.cpp:149
#3 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#4 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#5 0x00007fc332813fdd in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 3 (Thread 0x414a4950 (LWP 8214)):
#0 0x00007fc333d16d89 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1 0x00007fc334f551d0 in QWaitCondition::wait ()
   from /usr/lib/qt4/libQtCore.so.4
#2 0x00000000004d5fc3 in Reader::run (this=0x26bc230) at src/reader.cpp:250
#3 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#4 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#5 0x00007fc332813fdd in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x40ca3950 (LWP 8213)):
#0 0x00007fc333d16d89 in pthread_cond_wait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1 0x00007fc334f551d0 in QWaitCondition::wait ()
   from /usr/lib/qt4/libQtCore.so.4
#2 0x00000000004d5fc3 in Reader::run (this=0x26942e0) at src/reader.cpp:250
#3 0x00007fc334f5474f in QThreadPrivate::start ()
   from /usr/lib/qt4/libQtCore.so.4
#4 0x00007fc333d13017 in start_thread () from /lib/libpthread.so.0
#5 0x00007fc332813fdd in clone () from /lib/libc.so.6
#6 0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7fc338e1e750 (LWP 8212)):
#0 0x00007fc33280b6b6 in poll () from /lib/libc.so.6
#1 0x00007fc334649b05 in g_main_context_iterate ()
   from /usr/lib/libglib-2.0.so.0
#2 0x00007fc334649e07 in g_main_context_iteration ()
   from /usr/lib/libglib-2.0.so.0
#3 0x00007fc335017999 in QEventDispatcherGlib::processEvents ()
   from /usr/lib/qt4/libQtCore.so.4
#4 0x00007fc336ecc28c in QGuiEventDispatcherGlib::processEvents ()
   from /usr/lib/qt4/libQtGui.so.4
#5 0x00007fc334ff792e in QEventLoop::processEvents ()
   from /usr/lib/qt4/libQtCore.so.4
#6 0x00007fc334ff7a9d in QEventLoop::exec () from /usr/lib/qt4/libQtCore.so.4
#7 0x00007fc334ffa29d in QCoreApplication::exec ()
   from /usr/lib/qt4/libQtCore.so.4
#8 0x0000000000495e89 in main (argc=1, argv=0x7fff40f66dd8)
    at src/main.cpp:220
(gdb)

[Switching to thread 18 (Thread 0x42ca7950 (LWP 8270))]
#0 0x000000000050fd98 in WaveSummary::visualWaveformGen (this=<value optimized out>,
    pTrackInfoObject=0x7fc32880a270, pSoundSource=0x374c440)
    at src/wavesummary.cpp:226
226 while(filePos < numSamples && (j+2) < numDownsamples) {
(gdb) print filePos
$1 = 20694528
(gdb) print numSamples
$2 = 20696832
(gdb) print j
$3 = 188132
(gdb)

I've single-stepped through this and diagnosed it as best I can (not knowing more about mixxx's internals or C++ in general).

There's a commented out debugging message about this case (src/soundsourcemp3.cpp line 432), but apparently it isn't handled correctly. Stream.error is set to MAD_ERROR_BUFLEN, and SoundSourceMp3::read() repeatedly returns 0. This is called from WaveSummary::visualWaveformGen() (src/wavesummary.cpp line 251), but that code does not handle this error case correctly, the loop never advances, and the thread just spins forever.

[Albert Santoni (gamegod)]

Thanks for the thorough bug report Mark. Patches are most definitely welcome for this, otherwise someone will try to fix this before 1.6.1 (no date for it yet, but not likely before the middle of September).

[Mark Glines (infinoid)]

On Saturday 16 August 2008 10:11:21 Albert Santoni wrote:
> Thanks for the thorough bug report Mark. Patches are most definitely
> welcome for this, otherwise someone will try to fix this before 1.6.1
> (no date for it yet, but not likely before the middle of September).

Quick question: could it be related to cmetrics? I was originally
building with cmetrics=1 among other things, but I turned that flag off
to fix some weirdness when you close mixxx. (The process would keep
running for another 5 seconds or so, and then die with a message about
SIGKILL.) It just now occurred to me to ask, could changing that have
affected this bug?

I made a patch at around the same time I changed cmetrics, which in
hindsight was silly of me, because that means I might not have been
testing it effectively...

Either way, I haven't seen the hang since then, so either the attached
patch was effective, or it was really cmetrics's fault and my patch
didn't do diddly squat. (I'm not sure yet, because I haven't managed
to catch the new message in the debug log.)

--
Mark

[Albert Santoni (gamegod)]

Patch committed in r2257. Let's keep a close eye on this over the next few weeks, and if there's no more reports of it and we can't reproduce it anymore, we'll consider it fixed and close the bug.

Thanks again Mark,
Albert

[Albert Santoni (gamegod)]

Packages for Mixxx 1.6.1 are showing up here: http://downloads.mixxx.org/mixxx-1.6.1/

If someone could please confirm that the problem is fixed, we'd appreciate it.

Thanks,
Albert

[RJ Skerry-Ryan (rryan)]

Can anybody give this a try with Mixxx 1.6.1 and confirm whether or not the problem is fixed?

[Swiftb0y (swiftb0y)]

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