`BeatSyncedContainer` randomly stops animating itself

[smoogipoo]

Discussed in https://github.com/ppy/osu/discussions/21062

^{Originally posted by **Feodor0090** November 2, 2022} It happens with all beatmaps randomly. Just switch them and at some point of time it will stop animating. Notice not blinking search textbox cursor on 0:03 and that beat samples are not played when i hover osu! logo. Running 2022.1031.0, but it can be reproduces in older versions. Debian 11 with PulseAudio, if it matters. https://user-images.githubusercontent.com/53872073/199286065-cefa96e6-3f03-4139-a218-f6d58052f27a.mp4

[peppy]

Can't repro. No idea how to. Would appreciate some kind of repro instructions.

[Feodor0090]

As i said, there is no such. I happens randomly. Both in single/multithread, at all limiters, etc. It takes for me 2-3 BMS switches via left/right keys to trigger this. In actions below i use latest master branch.

I have tried to log some info from the container with Logger.Log($"{(ReferenceEquals(timingPoint, lastTimingPoint) ? @"Points eq" : @"Not eq")}, {(beatIndex == lastBeat ? "ret" : "Fire")}, bi={beatIndex}, li={lastBeat}, ctt={Math.Round(currentTrackTime)}, tpt={timingPoint.Time}, diff={Math.Round(currentTrackTime - timingPoint.Time)} bl={beatLength}").

Output of this when this bug occurs:

[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58768, tpt=1561, diff=57207 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58768, tpt=1561, diff=57207 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58708, tpt=1561, diff=57147 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58768, tpt=1561, diff=57207 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58768, tpt=1561, diff=57207 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58708, tpt=1561, diff=57147 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58768, tpt=1561, diff=57207 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58768, tpt=1561, diff=57207 bl=384,615384615385
[runtime] 2022-11-02 10:00:18 [verbose]: Points eq, ret, bi=148, li=148, ctt=58708, tpt=1561, diff=57147 bl=384,615384615385

TL;DR track time does not really change, just jumps back-forward on 60ms.

When i tried to log BeatSyncSource.Clock.CurrentTime in if (IsBeatSyncedWithTrack), it really gives me equal values (there are probably logs from several containers, but time did not change for ~20 seconds):

[runtime] 2022-11-02 10:08:26 [verbose]: CTT from BSS: 59595,510204081635
[runtime] 2022-11-02 10:08:26 [verbose]: CTT from BSS: 59595,510204081635
[runtime] 2022-11-02 10:08:26 [verbose]: CTT from BSS: 59595,510204081635
[runtime] 2022-11-02 10:08:27 [verbose]: CTT from BSS: 59595,510204081635
[runtime] 2022-11-02 10:08:27 [verbose]: CTT from BSS: 59595,510204081635

My suspicion here is that IBeatSyncProvider somehow gives the container an old track as clock after changing BMSes. In song select, IBeatSyncProvider is OsuGameDesktop. Any hints what i can investigate further?

[peppy]

Thanks for the extra investigation. You're definitely on the right path, but I'm also not sure how this could happen yet. It's likely something to do with the local FramedBeatmapClock thought.

My suspicion here is that IBeatSyncProvider somehow gives the container an old track as clock after changing BMSes. In song select, IBeatSyncProvider is OsuGameDesktop.

It's actually OsuGameBase to be more specific:

https://github.com/ppy/osu/blob/71d87489abe501ebe5aabcb931302040a054f35f/osu.Game/OsuGameBase.cs#L659-L661

You could try dropping a breakpoint on line 660 here and checking what state this local clock is in.

Or more specifically, check on this condition, which is 99% going to be where things are going wrong:

https://github.com/ppy/osu/blob/d6748d6921117a65846da635a45e0c6d04a5eef8/osu.Game/Beatmaps/FramedBeatmapClock.cs#L125