Quantised HotCues sometimes miss the beat

[mixxxbot]

Reported by: kazakore
Date: 2018-06-18T16:20:46Z
Status: Fix Released
Importance: Medium
Launchpad Issue: lp1777480

---

I'd experienced it a few times for ages but as I generally have Quantise off and am most preparing tracks for the future (not real DJing and using Mixxx to its fullest) I'd never got around to confirming this bug until it was reported in the forum at:
https://mixxx.org/forums/viewtopic.php?f=3&t=11899

In short Mixxx occasionally delays the triggering of a HotCue when Quantise is enabled (separate to the bug with 2.1.1 when HotCues are always Quantised.)

When I was testing the HotCue Always Quantised bug I was getting the offset HotCue about once every 10-15 presses. Just now I was testing to confirm whether the offset is visual only or really affecting the audio I only had it do it once in about 10 minutes of repeatedly bashing the HotCue buttons. Therefore it can be quite hard to test for.

But I did confirm it definitely affects the audio, not only the waveforms!

I believe (but not conclusive) that the HotCue is always triggered a little late, so possibly something is causing a delay and the command is not running exactly on time as it should.

Tested and seen on Ubuntu Studio 18.04 with Mixxx 2.1.1 and 2.1.0.

[mixxxbot]

Commented by: daschuer
Date: 2018-06-18T21:14:12Z

---

I cannot confirm the bug. Is quantized CUE and Play also effected?
What is your audio buffer size?
Did you enable constant beat grids?

[mixxxbot]

Commented by: daschuer
Date: 2018-06-18T21:15:04Z

---

The only thing that I can confirm it that the CUE respects quantize when the track is paused but not hot cues.

[mixxxbot]

Commented by: kazakore
Date: 2018-06-19T06:12:30Z

---

"The only thing that I can confirm it that the CUE respects quantize when the track is paused but not hot cues."

Not sure what you mean about this, both Cue and HotCues respect Quantise when on and are only triggered or set on the beatmarker when activated from Pause here....

"I cannot confirm the bug."

The fact it is intermittent and I'd never got a grasp on exact characteristics, yet alone a way to easily recreate the issue, is part of why I hadn't reported the bug before another user posted the same issue on the forum (along with the fact I stopped pretty much ever using Quantise anyway so it doesn't overly affect me most of the time.)

"Is quantized CUE and Play also effected?"

Yes Play is also affected sometimes, I never use the standard Cue button.

"What is your audio buffer size?"

Mixxx reports the 23.2ms buffer and this is not possible to be changed from Preferences. Jack is set to 44.1kHz, 128 frames, 3 buffers to give a latency of 8.71ms.

"Did you enable constant beat grids?"

Some people think I'm weird but I always analyse with Assume Constant Tempo enabled. I like to have a consistent beatgrid and know if a track varies from a solid tempo and manually adjest, rather than getting to try and keep tracks with a drifting tempo in time using Master Sync.

[mixxxbot]

Commented by: kazakore
Date: 2018-06-19T06:16:08Z

---

Yesterday when I was trying to confirm the audio really lags as well and waveforms I got one instance in ten minutes of near constant triggering. This morning double-checking I had really seen it with Play and again playing with HotCues a little and I got an occurrence rate of probably 30-40% of the time. So sometimes it really can be very prevalent! Probably not in the slightest related but both times it's occurred with high regularity in last couple of days the laptop has only been fairly recently switched on......

[mixxxbot]

Commented by: kazakore
Date: 2018-06-19T10:41:04Z

---

OK this does seem to affect every way of changing (or starting) PlayPos but by far the one that shows the behaviour the most often on my system is dropping the cursor on the overview waveform view to seek to a random new location.

Could it be related to flushing and refilling the audio buffer? Or some other kind of track buffer?

[mixxxbot]

Commented by: kazakore
Date: 2018-06-20T07:04:43Z

---

I know you've not managed to recreate this but I still see it on PR1716, which fixes this other issue with Quantise and I hoped may have been in some way related.

https://bugs.launchpad.net/mixxx/+bug/1777667

[mixxxbot]

Commented by: daschuer
Date: 2018-06-20T12:49:39Z

---

Yes, if you click on the overview waveform, cache misses are likely because Mixxx cannot predict where you click.

I am not sure if I get the issue correct here.
You play one track in deck A and you have a track in deck B cued at a hot cue. Quantize is on. Now you press and hold the hot cue, or play and the track does not perfectly allign with the track in deck A, right?

How big is the offset in percent of a beat?
Does the offset change if you try the same thing again? Is the visalisation offset of the alougned brats constant, when moving out of the waveform view?
Does sync enabled make any difference? Does the track shift to be synced when sync is enabled?
Does the issue accour if you load the same track to both decks? Does it accour if the rate slider is at unity?

[mixxxbot]

Commented by: daschuer
Date: 2018-06-20T12:50:29Z

---

Can you add a step by step guide how to reproduce the issue?

[mixxxbot]

Commented by: kazakore
Date: 2018-06-20T13:17:22Z

---

"Yes, if you click on the overview waveform, cache misses are likely because Mixxx cannot predict where you click."

I think the issue is the same as this but I don't only get in on clicking the waveform.

I generally have experienced it (and test) by playing two tracks and jumping hotcues while playing. As said I did see the behaviour on a Play though, and that would have been from a paused state so not only while jumping audio that would be buffered. Often get it from repeated trigger of same hotcue.

Percentage is small, best to have maximum zoom to see it, and is audible in a slightly clipity-clop beat. Yes it happens at unity pitch. The rest of the questions I can try and test in a few days time and get back....

"Can you add a step by step guide how to reproduce the issue?"

Unfortunately it has always been intermittent so this is hard. Part of the reason I let myself forget about it until another user posted it in the forum and has downgraded to 2.0 because of it.

[mixxxbot]

Commented by: kazakore
Date: 2018-06-20T13:23:38Z

---

"Yes, if you click on the overview waveform, cache misses are likely because Mixxx cannot predict where you click."

Would it be possible to add a check if the buffered audio has come from the sections by the triggered position and if not delay trigger for a buffer while you flush and refil it? A slight delay in trigger would be better than the sync going out of time.

[mixxxbot]

Commented by: kazakore
Date: 2018-06-24T18:08:58Z

---

I find it hard to believe nobody else can recreate this. I have a fairly fast laptop with an i7 5500U and 16BG of RAM so shouldn't be an issue with resources.

We did a chill event a couple of days ago and I accidentally opened 2.1.1 rather than the GIT version I have built so had the forced quantise on hotcue bug mentioned above and I would say this offset trigger occurred 30% plus of the time when triggering hotcues and occasionally on Play from pause in a normal DJ set. Mostly I would fix it by hitting Sync after triggering if I see it....

[mixxxbot]

Commented by: kazakore
Date: 2018-06-24T18:10:46Z

---

Have you tested with Xubuntu or Ubuntu Studio (which is Xubuntu based)? That OS seems to be a common denominator between me and the OP in the forum thread....

[mixxxbot]

Commented by: kazakore
Date: 2018-07-07T15:08:58Z

---

OK happening a lot but as just been working on my mapping had all the terminal debug information being written. Hopefully the messages here can help you find the source of the issue.

Three presses of a HotCue with no issue below. Note there is a "BpmControl::getNearestPositionInPhase out of date" for each which is not related (at first thought it might be.) 
Debug [Controller]: "Twitch MIDI 1: t:1442560 ms status 0x97 (ch 8, opcode 0x9), ctrl 0x60, val 0x7F" 
Debug [Engine]: BpmControl::getNearestPositionInPhase out of date 2.40989e+06 6.57266e+06 6.50659e+06 
Debug [Engine]: 2.41033e+06 2.4764e+06 66068 2.40989e+06 
Debug [Engine]: 3.59043e+06 3.65658e+06 66150 0.0896145 
Debug [Engine]: -0.134422 0.0099896 0.0896145 2.41625e+06 
Debug [CachingReaderWorker 1]: SoundSourceMP3 - restartDecoding @ 1178496 
Debug [CachingReaderWorker 1]: SoundSourceMP3 - Retry decoding MP3 frame @ 1178496 
Debug [Controller]: "Twitch MIDI 1: t:1442596 ms status 0x97 (ch 8, opcode 0x9), ctrl 0x60, val 0x00" 
Debug [Controller]: "Twitch MIDI 1: t:1443440 ms status 0x97 (ch 8, opcode 0x9), ctrl 0x64, val 0x7F" 
Debug [Engine]: BpmControl::getNearestPositionInPhase out of date -34648 2.87281e+06 2.80675e+06 
Debug [Engine]: -34208 31862 66070 -34648 
Debug [Engine]: 3.98733e+06 4.05348e+06 66150 0.188723 
Debug [Engine]: -0.283084 0.0099896 0.188723 -21739.3 
Debug [CachingReaderWorker 1]: SoundSourceMP3 - restartDecoding @ 0 
Debug [CachingReaderWorker 1]: SoundSourceMP3 - Retry decoding MP3 frame @ 0 
Debug [Controller]: "Twitch MIDI 1: t:1443480 ms status 0x97 (ch 8, opcode 0x9), ctrl 0x64, val 0x00" 
Debug [Engine]: CachingReader - Prepending 642 frames of silence 

Then the fourth press I had the issue apparent. Very clearly a cache error, as shown in the two Debug lines.
Debug [Controller]: "Twitch MIDI 1: t:1443648 ms status 0x97 (ch 8, opcode 0x9), ctrl 0x60, val 0x7F" 
Debug [Engine]: BpmControl::getNearestPositionInPhase out of date 2.40989e+06 97930 31862 
Debug [Engine]: 2.41033e+06 2.4764e+06 66068 2.40989e+06 
Debug [Engine]: 4.05348e+06 4.11963e+06 66150 0.64384 
Debug [Engine]: 0.53424 0.0099896 0.64384 2.3868e+06 
Debug [Engine]: CachingReader - Cache miss for chunk with index 145 
Debug [Engine]: didn't get what we wanted 0 2044 
Debug [Engine]: CachingReader - Cache miss for chunk with index 145 
Debug [Engine]: didn't get what we wanted 0 2044 
Debug [CachingReaderWorker 1]: SoundSourceMP3 - restartDecoding @ 1154304 
Debug [CachingReaderWorker 1]: SoundSourceMP3 - Retry decoding MP3 frame @ 1154304 

I was only alternating between HC1 and HC5, so this area had been recently (but not last) played.

I think all audio should be decoded and buffered in RAM on track load, in a background process so this does not need to complete before you can start to play a track. I think the realtime decoding is likely at least exasperating this issue.

[mixxxbot]

Commented by: daschuer
Date: 2018-07-07T16:20:58Z

---

Is
BpmControl::getNearestPositionInPhase
or the
CachingReader - Cache miss for chunk with index the issue?

Is sync enabled? Maybe you see
https://bugs.launchpad.net/mixxx/+bug/1777667
fixed here:
#1716

[mixxxbot]

Commented by: kazakore
Date: 2018-07-07T16:51:19Z

---

I'm using #⁠1716 which fixes the sync issue (and Master Sync wasn't enabled at the time anyway.)

The issue only occurred when the CachingReader lines were printed so I highly suspect those are the related ones. (I realise how unclear the above can be with no formatting on here now.)

[mixxxbot]

Commented by: daschuer
Date: 2018-07-07T20:17:16Z

---

So this bug happens with #⁠1716, everytime we have a cache miss?

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T07:28:19Z

---

A cache miss happens every time this fault occurs, I couldn't say for certain the other way around (but it seems likely from what I've seen.)

I have only tested with mp3 files. I will try with some wav files later today to rule out it being when decoding kicks back in etc.

Still I was surprised to see the decoding done live! Thought the entire track would be cached in RAM as PCM data upon loading. Surely it would make this kind of thing a lot quicker and less likely....

[mixxxbot]

Commented by: uklotzde
Date: 2018-07-08T08:28:17Z

---

If the caching reader is not able to provide the requested samples in time the only consequence should be a short moment of silence produced by 0 samples. Subsequent samples should arrive in time as the reader catches up. This caching issue shouldn't affect the timing in any way, i.e. play time in the engine should pass regardless of which samples are actually provided by the reader at a certain position. The reason why the engine only polls twice for the sample range (non-blocking) and then continues processing to stay in time.

Of course, by jumping around within the track you will very likely see those cache misses. But I suppose it is unlikely that there is any direct causal relationship between those cache misses and the timing issues. There actually would be timing issues only if the engine decided to block and wait for those samples indefinitely.

I've never noticed any audible artifacts caused by cache misses.

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T08:38:17Z

---

Managed to get it to occur with two wav files.

Debug [Main]: keyboard press:  "C" 
Debug [Engine]: BpmControl::getNearestPositionInPhase out of date 1.45671e+07 5.57023e+06 5.53243e+06 
Debug [Engine]: 1.45666e+07 1.46044e+07 37800 1.45671e+07 
Debug [Engine]: 413176 454318 41142 0.939304 
Debug [Engine]: 0.0520244 -0.0101587 0.939304 1.45643e+07 
Debug [Engine]: CachingReader - Cache miss for chunk with index 888 
Debug [Engine]: didn't get what we wanted 0 2048 
Debug [Engine]: CachingReader - Cache miss for chunk with index 888 
Debug [Engine]: didn't get what we wanted 0 2048 

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T08:42:44Z

---

"I've never noticed any audible artifacts caused by cache misses."

I can definitely hear it. It's not so far out to sound like a train wreck clashing mix but you do get a clip-clop kinda beat where you can hear they're not quite aligned.

"If the caching reader is not able to provide the requested samples in time the only consequence should be a short moment of silence produced by 0 samples. Subsequent samples should arrive in time as the reader catches up. This caching issue shouldn't affect the timing in any way,"

I think playing the contents of the old buffer (so it would be like hitting the hotcue a fraction of a second later audibly) would be better but either would be better than the current method.

[mixxxbot]

Commented by: daschuer
Date: 2018-07-08T08:49:00Z

---

I cannot reprepeoduce the issue, nor the cache misses. But cues are held in cache.

The original reporter has four decks playing, all decks sync enabled and jumps around using hot cues. It sound like a race condition.

How much is the deck off after jumping to a hot cue?

Dale, can you reproduce this original issue with #⁠1716?

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T09:42:28Z

---

Just been recording some videos with it happening with wav files and then went to edit them and KDenLive has broken itself....

But as I said it happens to me regularly on #⁠1716 using only two decks whether Master Sync is enabled or not. But yes, jumping around hotcues is what most often triggers it (but I have also experienced it on pressing Play from pause.)

I'll upload the videos anyway unedited. The issue wasn't happening as often as it sometimes does (especially the second video where I have same track in both decks to try and emphasise the audible effect which I wanted to trim the beginning off it) so at least you can see and hear for yourself what happens here.

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T09:48:19Z

---

http://www.deaddogdisko.co.uk/Stuff/mixxxHCQ.mkv
About three times over the two minutes, end of the file I leave it playing for a little the hit 1 to bring the beats together so you can (hopefully) hear the difference but not the best tracks to demonstrate it.

http://www.deaddogdisko.co.uk/Stuff/mixxxHCQ2.mkv
Same track in both decks, doesn't happen for quite some time at the start but when it does hopefully it's easier to hear.

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T09:50:54Z

---

Second file jump to about 1m20s to hear it.

[mixxxbot]

Commented by: uklotzde
Date: 2018-07-08T11:13:19Z

---

We should check what actually happens on a cache miss. Your screen recording shows that this might in fact be an issue.

[mixxxbot]

Commented by: uklotzde
Date: 2018-07-08T13:22:43Z

---

@dale: Could you please try if the following changes fix the timing issues on a cache miss?
#1745

[mixxxbot]

Commented by: daschuer
Date: 2018-07-08T19:42:23Z

---

Thank you for the videos. Interesting, unfortunately I still cannot reproduce the cache misses using hot cues. @uwe: do you have an idea why this happens on dale device.

I have an SSD :-/ mmm maybe I should try with my USB HDD.

[mixxxbot]

Commented by: daschuer
Date: 2018-07-08T19:50:20Z

---

With the USB drive I have Cache misses during analyse, but not with hot cues.
I am using the 2.1 branch.

So it looks like we have two issues:

• Cache misses when jumping to hot cues.
• Phase shift due to cache misses

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T21:09:07Z

---

"I have an SSD :-/ mmm maybe I should try with my USB HDD."

I use an SSD, plus another sat around with 16.04 installed on it I could just plug in for direct testing which I recently replaced (when I installed 18.04.) Pretty sure that isn't the issue.

[mixxxbot]

Commented by: kazakore
Date: 2018-07-08T21:10:29Z

---

This is a HP Elitebook 840 G2 with i7 and 16GB of RAM. I'm not running a low spec machine here, which is what has made it all the more surprising to me I see it and you don't.

[mixxxbot]

Commented by: uklotzde
Date: 2018-07-08T21:14:12Z

---

The occurrence of cache misses depends on both the distance between the hot cues and the speed of the storage media. I can easily reproduce those cache misses by jumping randomly within any track stored on a HDD!

[mixxxbot]

Commented by: daschuer
Date: 2018-07-08T22:40:23Z

---

I can confirm the cache misses with random jumps.
Hot-Cues are normally held in the cache, so there must be an issue with this feature in the video.

[mixxxbot]

Commented by: kazakore
Date: 2018-08-09T18:23:02Z

---

Again thanks for fixing this. Just a note as to why I still don't believe read/write/access speeds is my issue here. It would be nice to know why I get this issue and you could only recreate it when using a slow HDD with your library on it.

$ sudo hdparm -Tt /dev/sda
[sudo] password for dale: 

/dev/sda:
Timing cached reads: 10756 MB in 2.00 seconds = 5388.74 MB/sec
Timing buffered disk reads: 1592 MB in 3.00 seconds = 530.21 MB/sec

That's my Samsung Evo 850 SSD I currently use. I used to get the same issue on my Crucial MX200 SSD before I upgraded it for more space. I tried every available i/o scheduler and they made no different to cache misses.

[mixxxbot]

Issue closed with status Fix Released.