search

mixxxdj / mixxx

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

Buffer underflow when adding a track #8693

Open mixxxbot opened 2 years ago

mixxxbot commented 2 years ago

Reported by: ronso0 Date: 2016-11-16T01:27:09Z Status: Confirmed Importance: High Launchpad Issue: lp1642105 Tags: engine Attachments: lshw

Imagine one deck is playing, then you load a track to another deck. That's where an audible buffer underflow happens.

Must admit, I set a pretty aggressive latency of 5.33ms but don't run into any underflows when playing two decks. Keylock/speed offset and massive effects don't have any impact on playback quality.

Loading a track shouldn't have such an apparently high priority because I suspect noone minds that 100ms more it takes to load and even to re-analyze a track.

mixxx rev5973 Linux 3.14.23-rt20 #⁠1 SMP PREEMPT RT x86_64

mixxxbot commented 2 years ago

Commented by: rryan Date: 2016-11-16T03:04:14Z

Mixxx doesn't get nearly as much testing as it ought to on rt kernels -- it's possible we have some kind of priority inversion problem that only shows up on rt. But this shouldn't happen in general (our audio processing thread runs at a higher priority than the rest of Mixxx's threads).

Do you see the same problem on a non-rt kernel?

Out of curiosity, what are your CPU specs?

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2016-11-16T04:56:44Z Attachments: lshw

I only run this sys (Ubuntu studio) with rt kernel. On vanilla Ubuntu on the same machine I experienced very lame (aka unsatisfiying) performance so I don't see a reason to install standard kernel. Should I, would the results help?

I'm running mixxx on a AMD A4-3300M @ 1900MHz, full lshw attached.

mixxxbot commented 2 years ago

Commented by: daschuer Date: 2016-11-16T07:00:38Z

What kind of hard disk do you have? Does the underflow counter in hardware preferences count when the audio dropout happens? Does you see the "real time scheduling disabled" hint in hardware preferences? Is there something suspicious in the log file when the underflow happens?

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2016-11-16T15:29:50Z

mixxxbot commented 2 years ago

Commented by: ywwg Date: 2016-11-16T16:04:48Z

Almost certainly the issue is the low latency setting. A lot happens during track loading and that's a common place to experience dropouts even if you don't get dropouts during playback. Try doubling it to 10ms and see if the problem goes away.

mixxxbot commented 2 years ago

Commented by: daschuer Date: 2016-11-16T21:30:58Z

From the scheduler theory, a real-time thread should not be suspended by any other thread. It should run very deterministic and independent from what else is going on in the machine.

Since this seams to be not the case, we may have still locking calls, or it is an CPU frequency scaling issue, or it is just some extra engine work wen loading a track.

Your AMD A4-3300M has a frequency scaling 1900 - 2500 MHz. If I read it right, it lowers the frequency to 1900 MHz if both cores are used. This is most likely the case if both cores are used.

This issue become worth when we consider hyper-threading (not the case here)

It could be interesting to lock the cpu clock on 1900 MHz and check how the issue behaves than.

mixxxbot commented 2 years ago

Commented by: rryan Date: 2016-11-16T22:02:17Z

Daniel's right -- the Mixxx RT thread (assuming it's actually getting marked RT, which it should by default on Ubuntu Studio) should never get pre-empted by another Mixxx thread, so this is likely priority inversion.

Our use of signals/slots in the engine means we're constantly locking global Qt mutexes (for example http://code.qt.io/cgit/qt/qt.git/tree/src/corelib/kernel/qcoreapplication.cpp#n1360 is locked on every emit() that is queued) and allocating memory (emitting a queued signal calls malloc). If any other thread is pre-empted while holding that mutex or allocating memory then the engine thread will block.

On Wed, Nov 16, 2016 at 1:41 PM Daniel Schürmann <email address hidden>
wrote:

From the scheduler theory, a real-time thread should not be suspended by any other thread. It should run very deterministic and independent from what else is going on in the machine.

Since this seams to be not the case, we may have still locking calls, or it is an CPU frequency scaling issue, or it is just some extra engine work wen loading a track.

Your AMD A4-3300M has a frequency scaling 1900 - 2500 MHz. If I read it right, it lowers the frequency to 1900 MHz if both cores are used. This is most likely the case if both cores are used.

This issue become worth when we consider hyper-threading (not the case here)

It could be interesting to lock the cpu clock on 1900 MHz and check how the issue behaves than.

-- You received this bug notification because you are a member of Mixxx Development Team, which is subscribed to Mixxx. https://bugs.launchpad.net/bugs/1642105

Title: Buffer underflow when adding a track

To manage notifications about this bug go to: https://bugs.launchpad.net/mixxx/+bug/1642105/+subscriptions

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2016-11-17T21:23:06Z

@Daniel: I already locked cpu when setting up for audio. http://wiki.linuxaudio.org/wiki/system_configuration cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_governor performance performance

@Owen: I set it to 20ms. So far it didn't happen, even when playing 3 decks (keylock/speed set off) and adding a track to the 4th.

Until now mixxx felt very responsive without dropouts, I'll see how it will do from now. Appreciate your attension.

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2016-11-18T11:27:48Z

I set latency back to 10ms to maybe catch some log output. Loaded a .m4a, et voilà, these were last lines after the dropout happened:

Warning [CachingReaderWorker 1]: Unable to determine the fixed sample duration of track 1 in file "file:///mnt/M_OOLI/audio/00__mu__iN/00__neo/DJ Shadow - Midnight In A Perfect World (Ben Gomori's Utopian Edit) xXx.m4a" 
Warning [CachingReaderWorker 1]: Fallback: Using a default sample duration of 1024 sample frames per block 
Warning [AnalyzerQueue 1]: Unable to determine the fixed sample duration of track 1 in file "file:///mnt/M_OOLI/audio/00__mu__iN/00__neo/DJ Shadow - Midnight In A Perfect World (Ben Gomori's Utopian Edit) xXx.m4a" 
Warning [AnalyzerQueue 1]: Fallback: Using a default sample duration of 1024 sample frames per block 
Warning [CachingReaderWorker 2]: Unable to determine the fixed sample duration of track 1 in file "file:///mnt/M_OOLI/audio/00__mu__iN/00__neo/Weaver Beats - Fall in love (ft. Multirex) xXx.m4a" 
Warning [CachingReaderWorker 2]: Fallback: Using a default sample duration of 1024 sample frames per block 
Warning [AnalyzerQueue 1]: Unable to determine the fixed sample duration of track 1 in file "file:///mnt/M_OOLI/audio/00__mu__iN/00__neo/Weaver Beats - Fall in love (ft. Multirex) xXx.m4a" 
Warning [AnalyzerQueue 1]: Fallback: Using a default sample duration of 1024 sample frames per block 
Warning [Engine]: SoundDevicePortAudio: Audio API provides invalid time stamps, syncing waveforms with a CPU Timer DacTime: 370.078 EntrytoDac: 0.0163333 TimeSinceLastCb: 0.0110719 diff: 0.00207285

File is an .m4a recoded from .wav with this command:
avconv -i "$file" -vn -acodec libfdk_aac -b 320k "${file%%.$ext}.m4a"

Still can't reproduce it, though. Neither when loading the same file, nor when also playing a .m4a (even a shitty one) on the other deck.

As next step I will build a more recent kernel with preempt patch, see if that makes a difference.

mixxxbot commented 2 years ago

Commented by: daschuer Date: 2016-11-18T18:40:03Z

The file encoding issues are probably unrelated, but 

Warning [Engine]: SoundDevicePortAudio: Audio API provides invalid time stamps, syncing waveforms with a CPU Timer DacTime: 370.078 EntrytoDac: 0.0163333 TimeSinceLastCb: 0.0110719 diff: 0.00207285

is suspicious.

This message is issued form the DAC timing validation code. If the DAC timing provided by your audio API is valid normally, this massage can happen if the Engine thread is suspended, before it enters the Mixxx audio callback.

The "Warning [Engine]" itself makes the issue worse since this concurrents with all the other messages, this can take loooong since ther might be an other lock at writing the mixxx.log to hdd.

This message will be displayed only once per Mixxx run so not that big issue here.

Do you have more [Engine] entries?

I think I will enable this message only in developer mode ...

mixxxbot commented 2 years ago

Commented by: daschuer Date: 2016-11-18T18:41:03Z

I think we should move the logging output to a thread.

mixxxbot commented 2 years ago

Commented by: daschuer Date: 2016-11-18T19:14:42Z

https://github.com/mixxxdj/mixxx/commit/ef6b8426c34e1e1cc3fc084e3025eeb205680a57

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2016-11-19T21:04:42Z

@Daniel: you're right, I found this Warning [Engine] once in each of the recent logs. No other occurence of [Engine]

mixxxbot commented 2 years ago

Commented by: Be-ing Date: 2016-12-06T17:04:09Z

I have noticed this occurring regularly when I first load a track to a deck. Have you? See https://bugs.launchpad.net/mixxx/+bug/1641360

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2016-12-06T21:22:06Z

Me? Anyway, my update: I've set latency to 10ms and notice the underflow only & mostly when adding the second track of a set while 1st track is playing. Like you describe in lp:1641360

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2016-12-18T12:33:58Z

I recently set pitch-bending to Rubberband and audible underflow is happening on almost any track load. Since playing track is not pitched, I'm wondering why pitch-bending engine has such an effect.

mixxxbot commented 2 years ago

Commented by: daschuer Date: 2016-12-18T21:03:34Z

Rubberband requires ages more CPU than Sounddouch.

If keylock is enabled the pitch-bending-engine is enabled as well even if it is not pitched. This is required for a click free transition. Otherwise it is bypassed and a very fast linear pitch engine is used for anything you could do with a real vinyl as well

mixxxbot commented 2 years ago

Commented by: uklotzde Date: 2018-10-22T06:36:07Z

The reason might not only be CPU utilization but also disk I/O. I experience buffer underflows while performing rsync operations on unrelated disks, CPU is not an issue here.

mixxxbot commented 2 years ago

Commented by: uklotzde Date: 2018-10-22T06:37:31Z

This bug is related or even a duplicate: https://bugs.launchpad.net/mixxx/+bug/1738253

We should decide which one is the master for tracking these issues.

mixxxbot commented 2 years ago

Commented by: ronso0 Date: 2018-10-22T15:21:52Z

I moved to Bionic and use 4.16.18-rt12 now. 2.3.0-alpha-pre (build master r6553) Issue didn't pop since then.

I could test with 3.18.7-rt1 if that's of any help.

mixxxbot commented 2 years ago

Commented by: rryan Date: 2018-10-22T15:40:16Z

The reason might not only be CPU utilization but also disk I/O. I experience buffer underflows while performing rsync operations on unrelated disks, CPU is not an issue here.

Uwe, did you check that it was a buffer underflow (Mixxx callback exceeds its deadline) or is it just a CachingReader cache miss? CachingReader is supposed to be able to cache miss and emit silence so that it doesn't block the rest of the callback. No file I/O should be happening in the callback so I don't see how disk I/O could cause xruns?

mixxxbot commented 2 years ago

Commented by: uklotzde Date: 2018-10-22T16:11:07Z

Buffer underflows in the engine with audible artefacts while the audio was playing continuously.

CachingReader is not affected. The audio file is located on an (internal) disk that contains only audio files and is neither affected by the rsync activities and nor used by any other application than Mixxx.

mixxxbot commented 2 years ago

Commented by: ywwg Date: 2018-10-24T02:27:01Z

I've noticed an uptick in underflows with keylock on, even on my new laptop (i7-8550U) at ~10ms. Not a ton, mind you, just one or two per set, but that's up from never. Rubberband has always used a lot of CPU but it surprises me that every time I upgrade my laptop it's the same deep red in the cpu meter. (Can't we lazily precache rubber-banded track data at the current BPM instead of trying to do it on the fly?)

In the past I've been able to get by with 10ms and two tracks on keylock... I'm not sure if the move to qt5 has caused a perf regression in general that has pushed me over the edge.

mixxxbot commented 2 years ago

Commented by: daschuer Date: 2018-10-24T06:23:44Z

Since we recently fighting some possible qt5 performance regression, it would be nice if you could verify it. Is there a difference between qt5 and qt4? Is this issue qt related?

You can either use the plain 2.1 branch or the 2.2 branch build with qt4 and this https://github.com/mixxxdj/mixxx/pull/1860 patch.

mixxxbot commented 2 years ago

Commented by: uklotzde Date: 2018-10-24T06:31:52Z

Caching of pre-computed audio data? Just NO! The caching is already complicated and error prone. This would introduce a whole new level of complexity.