1
0
mirror of https://github.com/ppy/osu.git synced 2024-12-17 13:02:56 +08:00
osu-lazer/osu.Game/Screens/Play/SubmittingPlayer.cs

Ignoring revisions in .git-blame-ignore-revs. Click here to bypass and see the normal blame view.

308 lines
11 KiB
C#
Raw Normal View History

// 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.
2022-06-17 15:37:17 +08:00
#nullable disable
using System;
using System.Linq;
using System.Threading.Tasks;
using JetBrains.Annotations;
using osu.Framework.Allocation;
using osu.Framework.Graphics;
using osu.Framework.Logging;
using osu.Framework.Screens;
using osu.Game.Beatmaps;
using osu.Game.Configuration;
using osu.Game.Database;
using osu.Game.Online.API;
Ensure score submission attempt completion before notifying spectator server when exiting play early When a `SubmittingPlayer` gameplay session ends with the successful completion of a beatmap, `PrepareScoreForResultsAsync()` ensures that the score submission request is sent to and responded to by osu-web before calling `ISpectatorClient.EndPlaying()`. While previously this was mostly an implementation detail, this becomes important when considering that more and more server-side flows (replay upload, notifying about score processing completion) hook into `EndPlaying()`, and assume that by the point that message arrives at osu-spectator-server, the score has already been submitted and has been assigned a score ID that corresponds to the score submission token. As it turns out, in the early-exit path (when the user exits the play midway through, retries, or just fails), the same ordering guarantees were not provided. The score's submission ran concurrently to the spectator client `EndPlaying()` call, therefore creating a network race. osu-server-spectator components that implciitly relied on the ordering provided by the happy path, could therefore fail to unmap the score submission token to a score ID. Note that as written, the osu-server-spectator replay upload flow is not really affected by this, as it self-corrects by essentially polling the database and trying to unmap the score submission token to a score ID for up to 30 seconds. However, this change would have the benefit of reducing the polls required in such cases to just one DB retrieval.
2022-12-22 04:59:46 +08:00
using osu.Game.Online.Multiplayer;
using osu.Game.Online.Rooms;
using osu.Game.Online.Solo;
using osu.Game.Online.Spectator;
using osu.Game.Rulesets.Scoring;
using osu.Game.Scoring;
namespace osu.Game.Screens.Play
{
/// <summary>
/// A player instance which supports submitting scores to an online store.
/// </summary>
public abstract partial class SubmittingPlayer : Player
{
2021-03-24 12:02:17 +08:00
/// <summary>
/// The token to be used for the current submission. This is fetched via a request created by <see cref="CreateTokenRequest"/>.
2021-03-24 12:02:17 +08:00
/// </summary>
2021-03-24 12:20:44 +08:00
private long? token;
[Resolved]
private IAPIProvider api { get; set; }
[Resolved]
private SpectatorClient spectatorClient { get; set; }
[Resolved]
private SessionStatics statics { get; set; }
[Resolved(canBeNull: true)]
[CanBeNull]
private SoloStatisticsWatcher soloStatisticsWatcher { get; set; }
Fix possible double score submission when auto-retrying via perfect mod Closes https://github.com/ppy/osu/issues/26035. `submitOnFailOrQuit()`, as the name suggests, can be called both when the player has failed, or when the player screen is being exited from. Notably, when perfect mod with auto-retry is active, the two happen almost simultaneously. This double call exposes a data race in `submitScore()` concerning the handling of `scoreSubmissionSource`. The race could be experimentally confirmed by applying the following patch: diff --git a/osu.Game/Screens/Play/SubmittingPlayer.cs b/osu.Game/Screens/Play/SubmittingPlayer.cs index 83adf1f960..76dd29bbdb 100644 --- a/osu.Game/Screens/Play/SubmittingPlayer.cs +++ b/osu.Game/Screens/Play/SubmittingPlayer.cs @@ -228,6 +228,7 @@ private Task submitScore(Score score) return Task.CompletedTask; } + Logger.Log($"{nameof(scoreSubmissionSource)} is {(scoreSubmissionSource == null ? "null" : "not null")}"); if (scoreSubmissionSource != null) return scoreSubmissionSource.Task; @@ -237,6 +238,7 @@ private Task submitScore(Score score) Logger.Log($"Beginning score submission (token:{token.Value})..."); + Logger.Log($"creating new {nameof(scoreSubmissionSource)}"); scoreSubmissionSource = new TaskCompletionSource<bool>(); var request = CreateSubmissionRequest(score, token.Value); which would result in the following log output: [runtime] 2024-01-02 09:54:13 [verbose]: scoreSubmissionSource is null [runtime] 2024-01-02 09:54:13 [verbose]: scoreSubmissionSource is null [runtime] 2024-01-02 09:54:13 [verbose]: Beginning score submission (token:36780)... [runtime] 2024-01-02 09:54:13 [verbose]: creating new scoreSubmissionSource [runtime] 2024-01-02 09:54:13 [verbose]: Beginning score submission (token:36780)... [runtime] 2024-01-02 09:54:13 [verbose]: creating new scoreSubmissionSource [network] 2024-01-02 09:54:13 [verbose]: Performing request osu.Game.Online.Solo.SubmitSoloScoreRequest [network] 2024-01-02 09:54:14 [verbose]: Request to https://dev.ppy.sh/api/v2/beatmaps/869310/solo/scores/36780 successfully completed! [network] 2024-01-02 09:54:14 [verbose]: SubmitSoloScoreRequest finished with response size of 639 bytes [network] 2024-01-02 09:54:14 [verbose]: Performing request osu.Game.Online.Solo.SubmitSoloScoreRequest [runtime] 2024-01-02 09:54:14 [verbose]: Score submission completed! (token:36780 id:20247) [network] 2024-01-02 09:54:14 [verbose]: Request to https://dev.ppy.sh/api/v2/beatmaps/869310/solo/scores/36780 successfully completed! [network] 2024-01-02 09:54:14 [verbose]: SubmitSoloScoreRequest finished with response size of 639 bytes [runtime] 2024-01-02 09:54:14 [error]: An unhandled error has occurred. [runtime] 2024-01-02 09:54:14 [error]: System.InvalidOperationException: An attempt was made to transition a task to a final state when it had already completed. [runtime] 2024-01-02 09:54:14 [error]: at osu.Game.Screens.Play.SubmittingPlayer.<>c__DisplayClass30_0.<submitScore>b__0(MultiplayerScore s) in /home/dachb/Documents/opensource/osu/osu.Game/Screens/Play/SubmittingPlayer.cs:line 250 The intention of the submission logic was to only ever create one `scoreSubmissionSource`, and then reuse this one if a redundant submission request was made. However, because of the temporal proximity of fail and quit in this particular case, combined with the fact that the calls to `submitScore()` are taking place on TPL threads, means that there is a read-write data race on `scoreSubmissionSource`, wherein the source can be actually created twice. This leads to two concurrent score submission requests, which, upon completion, attempt to transition only _the second_ `scoreSubmissionSource` to a final state (this is because the API success/failure request callbacks capture `this`, i.e. the entire `SubmittingPlayer` instance, rather than the `scoreSubmissionSource` reference specifically). To fix, ensure correct synchronisation on the read-write critical section, which should prevent the `scoreSubmissionSource` from being created multiple times.
2024-01-02 17:49:09 +08:00
private readonly object scoreSubmissionLock = new object();
private TaskCompletionSource<bool> scoreSubmissionSource;
protected SubmittingPlayer(PlayerConfiguration configuration = null)
: base(configuration)
{
}
[BackgroundDependencyLoader]
private void load()
{
2023-11-03 06:44:40 +08:00
if (DrawableRuleset == null)
{
// base load must have failed (e.g. due to an unknown mod); bail.
return;
}
AddInternal(new PlayerTouchInputDetector());
// We probably want to move this display to something more global.
// Probably using the OSD somehow.
AddInternal(new GameplayOffsetControl
{
Margin = new MarginPadding(20),
Anchor = Anchor.CentreRight,
Origin = Anchor.CentreRight,
});
}
protected override GameplayClockContainer CreateGameplayClockContainer(WorkingBeatmap beatmap, double gameplayStart) => new MasterGameplayClockContainer(beatmap, gameplayStart)
{
ShouldValidatePlaybackRate = true,
};
protected override void LoadAsyncComplete()
{
base.LoadAsyncComplete();
handleTokenRetrieval();
}
private bool handleTokenRetrieval()
{
// Token request construction should happen post-load to allow derived classes to potentially prepare DI backings that are used to create the request.
var tcs = new TaskCompletionSource<bool>();
if (Mods.Value.Any(m => !m.UserPlayable))
{
handleTokenFailure(new InvalidOperationException("Non-user playable mod selected."));
return false;
}
if (!api.IsLoggedIn)
{
2021-03-24 12:20:44 +08:00
handleTokenFailure(new InvalidOperationException("API is not online."));
return false;
}
var req = CreateTokenRequest();
if (req == null)
{
2021-03-24 12:20:44 +08:00
handleTokenFailure(new InvalidOperationException("Request could not be constructed."));
return false;
}
req.Success += r =>
{
Logger.Log($"Score submission token retrieved ({r.ID})");
2021-03-24 12:20:44 +08:00
token = r.ID;
tcs.SetResult(true);
};
req.Failure += ex => handleTokenFailure(ex, displayNotification: true);
api.Queue(req);
// Generally a timeout would not happen here as APIAccess will timeout first.
if (!tcs.Task.Wait(30000))
req.TriggerFailure(new InvalidOperationException("Token retrieval timed out (request never run)"));
return true;
2021-03-24 12:20:44 +08:00
void handleTokenFailure(Exception exception, bool displayNotification = false)
{
tcs.SetResult(false);
bool shouldExit = ShouldExitOnTokenRetrievalFailure(exception);
if (displayNotification || shouldExit)
{
string whatWillHappen = shouldExit
2024-02-19 20:56:21 +08:00
? "Play in this state is not permitted."
: "Your score will not be submitted.";
if (string.IsNullOrEmpty(exception.Message))
2024-02-19 20:56:21 +08:00
Logger.Error(exception, $"Failed to retrieve a score submission token.\n\n{whatWillHappen}");
else
{
switch (exception.Message)
{
case @"missing token header":
case @"invalid client hash":
case @"invalid verification hash":
2024-02-19 20:56:21 +08:00
Logger.Log($"Please ensure that you are using the latest version of the official game releases.\n\n{whatWillHappen}", level: LogLevel.Important);
break;
case @"expired token":
2024-02-19 20:56:21 +08:00
Logger.Log($"Your system clock is set incorrectly. Please check your system time, date and timezone.\n\n{whatWillHappen}", level: LogLevel.Important);
break;
default:
Logger.Log($"{whatWillHappen} {exception.Message}", level: LogLevel.Important);
break;
}
}
}
if (shouldExit)
{
Schedule(() =>
{
ValidForResume = false;
this.Exit();
});
}
}
}
/// <summary>
/// Called when a token could not be retrieved for submission.
/// </summary>
/// <param name="exception">The error causing the failure.</param>
/// <returns>Whether gameplay should be immediately exited as a result. Returning false allows the gameplay session to continue. Defaults to true.</returns>
protected virtual bool ShouldExitOnTokenRetrievalFailure(Exception exception) => true;
protected override async Task PrepareScoreForResultsAsync(Score score)
{
await base.PrepareScoreForResultsAsync(score).ConfigureAwait(false);
score.ScoreInfo.Date = DateTimeOffset.Now;
await submitScore(score).ConfigureAwait(false);
spectatorClient.EndPlaying(GameplayState);
soloStatisticsWatcher?.RegisterForStatisticsUpdateAfter(score.ScoreInfo);
}
[Resolved]
private RealmAccess realm { get; set; }
protected override void StartGameplay()
{
base.StartGameplay();
// User expectation is that last played should be updated when entering the gameplay loop
2022-07-13 21:37:20 +08:00
// from multiplayer / playlists / solo.
realm.WriteAsync(r =>
{
var realmBeatmap = r.Find<BeatmapInfo>(Beatmap.Value.BeatmapInfo.ID);
if (realmBeatmap != null)
realmBeatmap.LastPlayed = DateTimeOffset.Now;
});
2022-12-12 12:59:27 +08:00
spectatorClient.BeginPlaying(token, GameplayState, Score);
}
protected override void OnFail()
{
base.OnFail();
submitFromFailOrQuit();
}
public override bool OnExiting(ScreenExitEvent e)
2021-06-30 19:23:48 +08:00
{
bool exiting = base.OnExiting(e);
submitFromFailOrQuit();
statics.SetValue(Static.LastLocalUserScore, Score?.ScoreInfo.DeepClone());
return exiting;
}
2021-07-01 16:38:28 +08:00
private void submitFromFailOrQuit()
{
if (LoadedBeatmapSuccessfully)
{
Ensure score submission attempt completion before notifying spectator server when exiting play early When a `SubmittingPlayer` gameplay session ends with the successful completion of a beatmap, `PrepareScoreForResultsAsync()` ensures that the score submission request is sent to and responded to by osu-web before calling `ISpectatorClient.EndPlaying()`. While previously this was mostly an implementation detail, this becomes important when considering that more and more server-side flows (replay upload, notifying about score processing completion) hook into `EndPlaying()`, and assume that by the point that message arrives at osu-spectator-server, the score has already been submitted and has been assigned a score ID that corresponds to the score submission token. As it turns out, in the early-exit path (when the user exits the play midway through, retries, or just fails), the same ordering guarantees were not provided. The score's submission ran concurrently to the spectator client `EndPlaying()` call, therefore creating a network race. osu-server-spectator components that implciitly relied on the ordering provided by the happy path, could therefore fail to unmap the score submission token to a score ID. Note that as written, the osu-server-spectator replay upload flow is not really affected by this, as it self-corrects by essentially polling the database and trying to unmap the score submission token to a score ID for up to 30 seconds. However, this change would have the benefit of reducing the polls required in such cases to just one DB retrieval.
2022-12-22 04:59:46 +08:00
Task.Run(async () =>
{
await submitScore(Score.DeepClone()).ConfigureAwait(false);
spectatorClient.EndPlaying(GameplayState);
}).FireAndForget();
}
2021-06-30 19:23:48 +08:00
}
/// <summary>
/// Construct a request to be used for retrieval of the score token.
/// Can return null, at which point <see cref="ShouldExitOnTokenRetrievalFailure"/> will be fired.
/// </summary>
[CanBeNull]
protected abstract APIRequest<APIScoreToken> CreateTokenRequest();
/// <summary>
/// Construct a request to submit the score.
/// Will only be invoked if the request constructed via <see cref="CreateTokenRequest"/> was successful.
/// </summary>
/// <param name="score">The score to be submitted.</param>
/// <param name="token">The submission token.</param>
protected abstract APIRequest<MultiplayerScore> CreateSubmissionRequest(Score score, long token);
private Task submitScore(Score score)
{
var masterClock = GameplayClockContainer as MasterGameplayClockContainer;
if (masterClock?.PlaybackRateValid.Value != true)
{
Logger.Log("Score submission cancelled due to audio playback rate discrepancy.");
return Task.CompletedTask;
}
// token may be null if the request failed but gameplay was still allowed (see HandleTokenRetrievalFailure).
2021-03-24 12:20:44 +08:00
if (token == null)
{
Logger.Log("No token, skipping score submission");
return Task.CompletedTask;
}
Fix possible double score submission when auto-retrying via perfect mod Closes https://github.com/ppy/osu/issues/26035. `submitOnFailOrQuit()`, as the name suggests, can be called both when the player has failed, or when the player screen is being exited from. Notably, when perfect mod with auto-retry is active, the two happen almost simultaneously. This double call exposes a data race in `submitScore()` concerning the handling of `scoreSubmissionSource`. The race could be experimentally confirmed by applying the following patch: diff --git a/osu.Game/Screens/Play/SubmittingPlayer.cs b/osu.Game/Screens/Play/SubmittingPlayer.cs index 83adf1f960..76dd29bbdb 100644 --- a/osu.Game/Screens/Play/SubmittingPlayer.cs +++ b/osu.Game/Screens/Play/SubmittingPlayer.cs @@ -228,6 +228,7 @@ private Task submitScore(Score score) return Task.CompletedTask; } + Logger.Log($"{nameof(scoreSubmissionSource)} is {(scoreSubmissionSource == null ? "null" : "not null")}"); if (scoreSubmissionSource != null) return scoreSubmissionSource.Task; @@ -237,6 +238,7 @@ private Task submitScore(Score score) Logger.Log($"Beginning score submission (token:{token.Value})..."); + Logger.Log($"creating new {nameof(scoreSubmissionSource)}"); scoreSubmissionSource = new TaskCompletionSource<bool>(); var request = CreateSubmissionRequest(score, token.Value); which would result in the following log output: [runtime] 2024-01-02 09:54:13 [verbose]: scoreSubmissionSource is null [runtime] 2024-01-02 09:54:13 [verbose]: scoreSubmissionSource is null [runtime] 2024-01-02 09:54:13 [verbose]: Beginning score submission (token:36780)... [runtime] 2024-01-02 09:54:13 [verbose]: creating new scoreSubmissionSource [runtime] 2024-01-02 09:54:13 [verbose]: Beginning score submission (token:36780)... [runtime] 2024-01-02 09:54:13 [verbose]: creating new scoreSubmissionSource [network] 2024-01-02 09:54:13 [verbose]: Performing request osu.Game.Online.Solo.SubmitSoloScoreRequest [network] 2024-01-02 09:54:14 [verbose]: Request to https://dev.ppy.sh/api/v2/beatmaps/869310/solo/scores/36780 successfully completed! [network] 2024-01-02 09:54:14 [verbose]: SubmitSoloScoreRequest finished with response size of 639 bytes [network] 2024-01-02 09:54:14 [verbose]: Performing request osu.Game.Online.Solo.SubmitSoloScoreRequest [runtime] 2024-01-02 09:54:14 [verbose]: Score submission completed! (token:36780 id:20247) [network] 2024-01-02 09:54:14 [verbose]: Request to https://dev.ppy.sh/api/v2/beatmaps/869310/solo/scores/36780 successfully completed! [network] 2024-01-02 09:54:14 [verbose]: SubmitSoloScoreRequest finished with response size of 639 bytes [runtime] 2024-01-02 09:54:14 [error]: An unhandled error has occurred. [runtime] 2024-01-02 09:54:14 [error]: System.InvalidOperationException: An attempt was made to transition a task to a final state when it had already completed. [runtime] 2024-01-02 09:54:14 [error]: at osu.Game.Screens.Play.SubmittingPlayer.<>c__DisplayClass30_0.<submitScore>b__0(MultiplayerScore s) in /home/dachb/Documents/opensource/osu/osu.Game/Screens/Play/SubmittingPlayer.cs:line 250 The intention of the submission logic was to only ever create one `scoreSubmissionSource`, and then reuse this one if a redundant submission request was made. However, because of the temporal proximity of fail and quit in this particular case, combined with the fact that the calls to `submitScore()` are taking place on TPL threads, means that there is a read-write data race on `scoreSubmissionSource`, wherein the source can be actually created twice. This leads to two concurrent score submission requests, which, upon completion, attempt to transition only _the second_ `scoreSubmissionSource` to a final state (this is because the API success/failure request callbacks capture `this`, i.e. the entire `SubmittingPlayer` instance, rather than the `scoreSubmissionSource` reference specifically). To fix, ensure correct synchronisation on the read-write critical section, which should prevent the `scoreSubmissionSource` from being created multiple times.
2024-01-02 17:49:09 +08:00
lock (scoreSubmissionLock)
{
if (scoreSubmissionSource != null)
return scoreSubmissionSource.Task;
scoreSubmissionSource = new TaskCompletionSource<bool>();
}
// if the user never hit anything, this score should not be counted in any way.
if (!score.ScoreInfo.Statistics.Any(s => s.Key.IsHit() && s.Value > 0))
return Task.CompletedTask;
Logger.Log($"Beginning score submission (token:{token.Value})...");
2021-03-24 12:20:44 +08:00
var request = CreateSubmissionRequest(score, token.Value);
request.Success += s =>
{
2021-12-10 14:37:12 +08:00
score.ScoreInfo.OnlineID = s.ID;
score.ScoreInfo.Position = s.Position;
scoreSubmissionSource.SetResult(true);
Logger.Log($"Score submission completed! (token:{token.Value} id:{s.ID})");
};
request.Failure += e =>
{
Logger.Error(e, $"Failed to submit score (token:{token.Value}): {e.Message}");
scoreSubmissionSource.SetResult(false);
};
api.Queue(request);
return scoreSubmissionSource.Task;
}
}
}