RubberBand Stretcher gets out of sync with original (when using keylock)

[Eve00000]

Bug Description

Something my 11th sense told me before but now I took the time to test, on different PCs & OSs

test:
take a (very) long track (eg Kraftwerk's - Autobahn, Katalog version, Rare Earth's - Get Ready, Stravinsky's L'oiseau de feu ...
To have no other processes influencing the experiment:

• disable waveforms
• don't use fx
• don't use equalizer

load the track in Deck1, no keylock, set slider at eg +8%, in another app eg FooBar with DSP manager -> Playback Rate Shift to +8% -> Play (you can user a higher setting but that makes it all crap)
Use a stopwatch and time the start point
try to sync FooBar & Mixxx Deck1
clone deck1 to deck2 -> perfect sync

start playing with keylock on both decks in Mixxx, there is a (in the beginning not hearable) speedshift, only after 20minutes you more or less start to hear the shift/flanger effect

-> using 4 decks (cloning without keylock activated) and switching the keylock on the different decks repeatedly speeds up the whole experiment
-> If you try this test with stemcontainers you'll hear it earlier: mute the same stems on all decks

-> as extra benchmark: both decks are out of sync with foobar (hearable) after 20minutes
if you use a multichannel app like voicemeter you can assign the decks different outputs, record multichannel and compare the streams in eg audacity

compare the elapsed time +8 % with the stopwatch and the playing track in FooBar

I did try with RB2 & 3
-> soundcard and network card as engine clock
-> audio buffer from 5.3 to 92.9
-> sample rate from 44.1 to 96
-> played track from 16 44.1 to 24 192
-> asio & alsa
-> main mix outbut or per deck output
-> using slipmode can accelerate the behaviour too

-> the buffers and the RB workers loose sync
-> soundtouch stays in sync, with keylock and compared to foobar

Version

2.7 latest main

OS

win & linux

[Eve00000]

Some extra tests:

Q-BR original 16b 44.1 ALAC m4a, no stems
Played from very first sample to the very last (no itro start/ouutro end)
duration at 0% rateshift: 5:56.01

stopwatch timed = confirmed by checking the recording (recorded with voicemeter on the output and checked in audacity)

Rubberband without keylock -> stopwatch timed 5:56:10
Rubberband with keylock -> stopwatch timed 5:56:48

-> speed -8% -> expected stopwatch duration: 6:24 (356 * 1.08 = 384.48)

Rubberband without keylock -> stopwatch timed 6:27.04 -> (387.04 / 356 = 1.087191) -> actual rate = +8.7..%
Rubberband with keylock -> stopwatch timed 6:27.68 -> (387.68 / 356 = 1.00889887) -> actual rate = +8.9%
Soundtouch without keylock -> stopwatch timed 6:27.02 -> (387.02 / 356 = 1.087078) -> actual rate = +8.7..%
Soundtouch with keylock -> stopwatch timed 6:26.87 -> (386.87 / 356 = 1.008671) -> actual rate = +8.67..%

-> speed +8% -> expected stopwatch duration: 5:27 (356 * 0.92 = 327.52)

Soundtouch without keylock -> stopwatch timed 5:29:73 -> (329.73 / 356 = 0.926207) -> actual rate = -7.73%
Soundtouch with keylock -> stopwatch timed : 5:29.10 -> (329.1 / 356 = 0.924438) -> actual rate = -7.55%
Rubberband without keylock -> stopwatch timed 5:30.02 -> (330.02 / 356 = 0.9270224) -> actual rate = -7.29%
Rubberband with keylock -> stopwatch timed 5:29.71 -> (329.71 / 356 = 0.9261516) -> actual rate = -7.38%

[FaithfulSparrow]

I think there's a bug in the common frame-accounting and play-position path, I'm looking now.

[Eve00000]

thanks, I'm tired of searching atm.
Did uou stopwatch some tracks too?
Can you confirm the issue?
Which OS are you using?

[FaithfulSparrow]

I'm on debian. The frame accounting looks good too, though I did find an unrelated bug in flanger frame counting I'll push a fix for later.

And, yeah, I'm struggling to reproduce this too. So far the frame count lines up perfectly. I'll start hooking in logging and see if I can reproduce this in the live app itself.

[FaithfulSparrow]

Okay, that took a lot of hacking away at but my working theory is that it's caused by a cache miss... basically any cache miss will silently cause desynchronization, not of the frame posirioninf (which remain apparently consistent) but rather of the audio itself, which is no longer synchronized to the tracked frames. Things using more CPU like keylock (rubberband) have a higher probability of dropping frames, ergo more likely to introduce this phasing effect as repeated cache misses cause progressive desyncing.

This is my working theory anyway, it might be wrong... I made a branch with a new test to demonstrate it here:
https://github.com/FaithfulSparrow/mixxx/tree/poc/16542-cache-miss-content-drop
FaithfulSparrow@4acb650de3

The test forces a cache miss though, so you'd have to put an inline log to see if it's what's actually causing the desynchronization during your plays.

edit: I kept going on this, running two streams, one with and one without drops. Even with the cache drops, they don't desync.... so I'm at a loss. I pushed to that branch, but, yeah, I'm perplexed.