Merge pull request #27426 from peppy/disallow-backwards-seeks-gameplay

Fix gameplay seeking backwards for a single frame for some users

osu.Game.Rulesets.Mania.Tests/TestSceneTimingBasedNoteColouring.cs

@@ -34,16 +34,21 @@ namespace osu.Game.Rulesets.Mania.Tests
         [SetUpSteps]
         public void SetUpSteps()
         {
-            AddStep("setup hierarchy", () => Child = new Container
+            AddStep("setup hierarchy", () =>
             {
-                Clock = new FramedClock(clock = new ManualClock()),
-                RelativeSizeAxes = Axes.Both,
-                Anchor = Anchor.Centre,
-                Origin = Anchor.Centre,
-                Children = new[]
+                Child = new Container
                 {
-                    drawableRuleset = (DrawableManiaRuleset)Ruleset.Value.CreateInstance().CreateDrawableRulesetWith(createTestBeatmap())
-                }
+                    Clock = new FramedClock(clock = new ManualClock()),
+                    RelativeSizeAxes = Axes.Both,
+                    Anchor = Anchor.Centre,
+                    Origin = Anchor.Centre,
+                    Children = new[]
+                    {
+                        drawableRuleset = (DrawableManiaRuleset)Ruleset.Value.CreateInstance().CreateDrawableRulesetWith(createTestBeatmap())
+                    }
+                };
+
+                drawableRuleset.AllowBackwardsSeeks = true;
             });
             AddStep("retrieve config bindable", () =>
             {

osu.Game.Tests/NonVisual/FirstAvailableHitWindowsTest.cs

@@ -100,6 +100,7 @@ namespace osu.Game.Tests.NonVisual
             public override Container FrameStableComponents { get; }
             public override IFrameStableClock FrameStableClock { get; }
             internal override bool FrameStablePlayback { get; set; }
+            public override bool AllowBackwardsSeeks { get; set; }
             public override IReadOnlyList<Mod> Mods { get; }
 
             public override double GameplayStartTime { get; }

osu.Game.Tests/Visual/Gameplay/TestSceneCompletionCancellation.cs

@@ -29,6 +29,8 @@ namespace osu.Game.Tests.Visual.Gameplay
 
         protected override bool AllowFail => false;
 
+        protected override bool AllowBackwardsSeeks => true;
+
         [SetUpSteps]
         public override void SetUpSteps()
         {

osu.Game.Tests/Visual/Gameplay/TestSceneFrameStabilityContainer.cs

@@ -130,8 +130,12 @@ namespace osu.Game.Tests.Visual.Gameplay
         }
 
         private void createStabilityContainer(double gameplayStartTime = double.MinValue) => AddStep("create container", () =>
+        {
             mainContainer.Child = new FrameStabilityContainer(gameplayStartTime)
-                .WithChild(consumer = new ClockConsumingChild()));
+            {
+                AllowBackwardsSeeks = true,
+            }.WithChild(consumer = new ClockConsumingChild());
+        });
 
         private void seekManualTo(double time) => AddStep($"seek manual clock to {time}", () => manualClock.CurrentTime = time);
 

osu.Game.Tests/Visual/Gameplay/TestSceneGameplaySamplePlayback.cs

@@ -16,6 +16,8 @@ namespace osu.Game.Tests.Visual.Gameplay
 {
     public partial class TestSceneGameplaySamplePlayback : PlayerTestScene
     {
+        protected override bool AllowBackwardsSeeks => true;
+
         [Test]
         public void TestAllSamplesStopDuringSeek()
         {

osu.Game.Tests/Visual/Gameplay/TestSceneGameplaySampleTriggerSource.cs

@@ -28,6 +28,8 @@ namespace osu.Game.Tests.Visual.Gameplay
 {
     public partial class TestSceneGameplaySampleTriggerSource : PlayerTestScene
     {
+        protected override bool AllowBackwardsSeeks => true;
+
         private TestGameplaySampleTriggerSource sampleTriggerSource = null!;
         protected override Ruleset CreatePlayerRuleset() => new OsuRuleset();
 

osu.Game.Tests/Visual/Gameplay/TestSceneHitErrorMeter.cs

@@ -288,6 +288,7 @@ namespace osu.Game.Tests.Visual.Gameplay
             public override Container FrameStableComponents { get; }
             public override IFrameStableClock FrameStableClock { get; }
             internal override bool FrameStablePlayback { get; set; }
+            public override bool AllowBackwardsSeeks { get; set; }
             public override IReadOnlyList<Mod> Mods { get; }
 
             public override double GameplayStartTime { get; }

osu.Game.Tests/Visual/Gameplay/TestScenePause.cs

@@ -16,6 +16,7 @@ using osu.Game.Configuration;
 using osu.Game.Graphics.Containers;
 using osu.Game.Graphics.Cursor;
 using osu.Game.Rulesets;
+using osu.Game.Rulesets.UI;
 using osu.Game.Screens.Play;
 using osu.Game.Skinning;
 using osuTK;
@@ -31,6 +32,9 @@ namespace osu.Game.Tests.Visual.Gameplay
 
         protected override Container<Drawable> Content => content;
 
+        private bool gameplayClockAlwaysGoingForward = true;
+        private double lastForwardCheckTime;
+
         public TestScenePause()
         {
             base.Content.Add(content = new GlobalCursorDisplay { RelativeSizeAxes = Axes.Both });
@@ -67,12 +71,20 @@ namespace osu.Game.Tests.Visual.Gameplay
             confirmPausedWithNoOverlay();
         }
 
+        [Test]
+        public void TestForwardPlaybackGuarantee()
+        {
+            hookForwardPlaybackCheck();
+
+            AddUntilStep("wait for forward playback", () => Player.GameplayClockContainer.CurrentTime > 1000);
+            AddStep("seek before gameplay", () => Player.GameplayClockContainer.Seek(-5000));
+
+            checkForwardPlayback();
+        }
+
         [Test]
         public void TestPauseWithLargeOffset()
         {
-            double lastStopTime;
-            bool alwaysGoingForward = true;
-
             AddStep("force large offset", () =>
             {
                 var offset = (BindableDouble)LocalConfig.GetBindable<double>(OsuSetting.AudioOffset);
@@ -82,25 +94,7 @@ namespace osu.Game.Tests.Visual.Gameplay
                 offset.Value = -5000;
             });
 
-            AddStep("add time forward check hook", () =>
-            {
-                lastStopTime = double.MinValue;
-                alwaysGoingForward = true;
-
-                Player.OnUpdate += _ =>
-                {
-                    var masterClock = (MasterGameplayClockContainer)Player.GameplayClockContainer;
-
-                    double currentTime = masterClock.CurrentTime;
-
-                    bool goingForward = currentTime >= lastStopTime;
-
-                    alwaysGoingForward &= goingForward;
-
-                    if (!goingForward)
-                        Logger.Log($"Went too far backwards (last stop: {lastStopTime:N1} current: {currentTime:N1})");
-                };
-            });
+            hookForwardPlaybackCheck();
 
             AddStep("move cursor outside", () => InputManager.MoveMouseTo(Player.ScreenSpaceDrawQuad.TopLeft - new Vector2(10)));
 
@@ -108,11 +102,37 @@ namespace osu.Game.Tests.Visual.Gameplay
 
             resumeAndConfirm();
 
-            AddAssert("time didn't go too far backwards", () => alwaysGoingForward);
+            checkForwardPlayback();
 
             AddStep("reset offset", () => LocalConfig.SetValue(OsuSetting.AudioOffset, 0.0));
         }
 
+        private void checkForwardPlayback() => AddAssert("time didn't go too far backwards", () => gameplayClockAlwaysGoingForward);
+
+        private void hookForwardPlaybackCheck()
+        {
+            AddStep("add time forward check hook", () =>
+            {
+                lastForwardCheckTime = double.MinValue;
+                gameplayClockAlwaysGoingForward = true;
+
+                Player.OnUpdate += _ =>
+                {
+                    var frameStableClock = Player.ChildrenOfType<FrameStabilityContainer>().Single().Clock;
+
+                    double currentTime = frameStableClock.CurrentTime;
+
+                    bool goingForward = currentTime >= lastForwardCheckTime;
+                    lastForwardCheckTime = currentTime;
+
+                    gameplayClockAlwaysGoingForward &= goingForward;
+
+                    if (!goingForward)
+                        Logger.Log($"Went too far backwards (last stop: {lastForwardCheckTime:N1} current: {currentTime:N1})");
+                };
+            });
+        }
+
         [Test]
         public void TestPauseResume()
         {

osu.Game.Tests/Visual/Gameplay/TestScenePoolingRuleset.cs

@@ -269,6 +269,7 @@ namespace osu.Game.Tests.Visual.Gameplay
 
                 drawableRuleset = (TestDrawablePoolingRuleset)ruleset.CreateDrawableRulesetWith(CreateWorkingBeatmap(beatmap).GetPlayableBeatmap(ruleset.RulesetInfo));
                 drawableRuleset.FrameStablePlayback = true;
+                drawableRuleset.AllowBackwardsSeeks = true;
                 drawableRuleset.PoolSize = poolSize;
 
                 Child = new Container

osu.Game.Tests/Visual/Gameplay/TestSceneStoryboardWithOutro.cs

@@ -31,6 +31,8 @@ namespace osu.Game.Tests.Visual.Gameplay
     {
         protected override bool HasCustomSteps => true;
 
+        protected override bool AllowBackwardsSeeks => true;
+
         protected new OutroPlayer Player => (OutroPlayer)base.Player;
 
         private double currentBeatmapDuration;

osu.Game/Beatmaps/FramedBeatmapClock.cs

@@ -38,6 +38,7 @@ namespace osu.Game.Beatmaps
         private IDisposable? beatmapOffsetSubscription;
 
         private readonly DecouplingFramedClock decoupledTrack;
+        private readonly InterpolatingFramedClock interpolatedTrack;
 
         [Resolved]
         private OsuConfigManager config { get; set; } = null!;
@@ -58,7 +59,7 @@ namespace osu.Game.Beatmaps
 
             // An interpolating clock is used to ensure precise time values even when the host audio subsystem is not reporting
             // high precision times (on windows there's generally only 5-10ms reporting intervals, as an example).
-            var interpolatedTrack = new InterpolatingFramedClock(decoupledTrack);
+            interpolatedTrack = new InterpolatingFramedClock(decoupledTrack);
 
             if (applyOffsets)
             {
@@ -190,5 +191,28 @@ namespace osu.Game.Beatmaps
             base.Dispose(isDisposing);
             beatmapOffsetSubscription?.Dispose();
         }
+
+        public string GetSnapshot()
+        {
+            return
+                $"originalSource: {output(Source)}\n" +
+                $"userGlobalOffsetClock: {output(userGlobalOffsetClock)}\n" +
+                $"platformOffsetClock: {output(platformOffsetClock)}\n" +
+                $"userBeatmapOffsetClock: {output(userBeatmapOffsetClock)}\n" +
+                $"interpolatedTrack: {output(interpolatedTrack)}\n" +
+                $"decoupledTrack: {output(decoupledTrack)}\n" +
+                $"finalClockSource: {output(finalClockSource)}\n";
+
+            string output(IClock? clock)
+            {
+                if (clock == null)
+                    return "null";
+
+                if (clock is IFrameBasedClock framed)
+                    return $"current: {clock.CurrentTime:N2} running: {clock.IsRunning} rate: {clock.Rate} elapsed: {framed.ElapsedFrameTime:N2}";
+
+                return $"current: {clock.CurrentTime:N2} running: {clock.IsRunning} rate: {clock.Rate}";
+            }
+        }
     }
 }

osu.Game/OsuGame.cs

@@ -1190,6 +1190,9 @@ namespace osu.Game
             {
                 if (entry.Level < LogLevel.Important || entry.Target > LoggingTarget.Database || entry.Target == null) return;
 
+                if (entry.Exception is SentryOnlyDiagnosticsException)
+                    return;
+
                 const int short_term_display_limit = 3;
 
                 if (recentLogCount < short_term_display_limit)

osu.Game/Rulesets/UI/DrawableRuleset.cs

@@ -81,6 +81,19 @@ namespace osu.Game.Rulesets.UI
 
         public override IFrameStableClock FrameStableClock => frameStabilityContainer;
 
+        private bool allowBackwardsSeeks;
+
+        public override bool AllowBackwardsSeeks
+        {
+            get => allowBackwardsSeeks;
+            set
+            {
+                allowBackwardsSeeks = value;
+                if (frameStabilityContainer != null)
+                    frameStabilityContainer.AllowBackwardsSeeks = value;
+            }
+        }
+
         private bool frameStablePlayback = true;
 
         internal override bool FrameStablePlayback
@@ -178,6 +191,7 @@ namespace osu.Game.Rulesets.UI
             InternalChild = frameStabilityContainer = new FrameStabilityContainer(GameplayStartTime)
             {
                 FrameStablePlayback = FrameStablePlayback,
+                AllowBackwardsSeeks = AllowBackwardsSeeks,
                 Children = new Drawable[]
                 {
                     FrameStableComponents,
@@ -463,6 +477,12 @@ namespace osu.Game.Rulesets.UI
         /// </summary>
         internal abstract bool FrameStablePlayback { get; set; }
 
+        /// <summary>
+        /// When a replay is not attached, we usually block any backwards seeks.
+        /// This will bypass the check. Should only be used for tests.
+        /// </summary>
+        public abstract bool AllowBackwardsSeeks { get; set; }
+
         /// <summary>
         /// The mods which are to be applied.
         /// </summary>

osu.Game/Rulesets/UI/FrameStabilityContainer.cs

@@ -3,14 +3,19 @@
 
 using System;
 using System.Diagnostics;
+using System.Linq;
 using osu.Framework.Allocation;
 using osu.Framework.Audio;
 using osu.Framework.Bindables;
 using osu.Framework.Graphics;
 using osu.Framework.Graphics.Containers;
+using osu.Framework.Logging;
+using osu.Framework.Testing;
 using osu.Framework.Timing;
+using osu.Game.Beatmaps;
 using osu.Game.Input.Handlers;
 using osu.Game.Screens.Play;
+using osu.Game.Utils;
 
 namespace osu.Game.Rulesets.UI
 {
@@ -24,6 +29,9 @@ namespace osu.Game.Rulesets.UI
     {
         public ReplayInputHandler? ReplayInputHandler { get; set; }
 
+        public bool AllowBackwardsSeeks { get; set; }
+        private double? lastBackwardsSeekLogTime;
+
         /// <summary>
         /// The number of CPU milliseconds to spend at most during seek catch-up.
         /// </summary>
@@ -150,6 +158,29 @@ namespace osu.Game.Rulesets.UI
                     state = PlaybackState.NotValid;
             }
 
+            // This is a hotfix for https://github.com/ppy/osu/issues/26879 while we figure how the hell time is seeking
+            // backwards by 11,850 ms for some users during gameplay.
+            //
+            // It basically says that "while we're running in frame stable mode, and don't have a replay attached,
+            // time should never go backwards". If it does, we stop running gameplay until it returns to normal.
+            if (!hasReplayAttached && FrameStablePlayback && proposedTime > referenceClock.CurrentTime && !AllowBackwardsSeeks)
+            {
+                if (lastBackwardsSeekLogTime == null || Math.Abs(Clock.CurrentTime - lastBackwardsSeekLogTime.Value) > 1000)
+                {
+                    lastBackwardsSeekLogTime = Clock.CurrentTime;
+
+                    string loggableContent = $"Denying backwards seek during gameplay (reference: {referenceClock.CurrentTime:N2} stable: {proposedTime:N2})";
+
+                    if (parentGameplayClock is GameplayClockContainer gcc)
+                        loggableContent += $"\n{gcc.ChildrenOfType<FramedBeatmapClock>().Single().GetSnapshot()}";
+
+                    Logger.Error(new SentryOnlyDiagnosticsException("backwards seek"), loggableContent);
+                }
+
+                state = PlaybackState.NotValid;
+                return;
+            }
+
             // if the proposed time is the same as the current time, assume that the clock will continue progressing in the same direction as previously.
             // this avoids spurious flips in direction from -1 to 1 during rewinds.
             if (state == PlaybackState.Valid && proposedTime != manualClock.CurrentTime)

osu.Game/Tests/Visual/PlayerTestScene.cs

@@ -70,10 +70,20 @@ namespace osu.Game.Tests.Visual
 
             AddStep($"Load player for {CreatePlayerRuleset().Description}", LoadPlayer);
             AddUntilStep("player loaded", () => Player.IsLoaded && Player.Alpha == 1);
+
+            if (AllowBackwardsSeeks)
+            {
+                AddStep("allow backwards seeking", () =>
+                {
+                    Player.DrawableRuleset.AllowBackwardsSeeks = AllowBackwardsSeeks;
+                });
+            }
         }
 
         protected virtual bool AllowFail => false;
 
+        protected virtual bool AllowBackwardsSeeks => false;
+
         protected virtual bool Autoplay => false;
 
         protected void LoadPlayer() => LoadPlayer(Array.Empty<Mod>());
@@ -126,6 +136,6 @@ namespace osu.Game.Tests.Visual
 
         protected sealed override Ruleset CreateRuleset() => CreatePlayerRuleset();
 
-        protected virtual TestPlayer CreatePlayer(Ruleset ruleset) => new TestPlayer(false, false);
+        protected virtual TestPlayer CreatePlayer(Ruleset ruleset) => new TestPlayer(false, false, AllowBackwardsSeeks);
     }
 }

osu.Game/Utils/SentryOnlyDiagnosticsException.cs

@@ -0,0 +1,21 @@
+// Copyright (c) ppy Pty Ltd <contact@ppy.sh>. Licensed under the MIT Licence.
+// See the LICENCE file in the repository root for full licence text.
+
+using System;
+
+namespace osu.Game.Utils
+{
+    /// <summary>
+    /// Log to sentry without showing an error notification to the user.
+    /// </summary>
+    /// <remarks>
+    /// This can be used to convey important diagnostics to us developers without
+    /// getting in the user's way. Should be used sparingly.</remarks>
+    internal class SentryOnlyDiagnosticsException : Exception
+    {
+        public SentryOnlyDiagnosticsException(string message)
+            : base(message)
+        {
+        }
+    }
+}