2021-03-23 14:00:02 +08:00
// 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
2021-03-23 15:41:36 +08:00
using System ;
2021-05-11 10:24:55 +08:00
using System.Linq ;
2021-03-23 14:00:02 +08:00
using System.Threading.Tasks ;
2021-03-24 12:17:13 +08:00
using JetBrains.Annotations ;
2021-03-23 14:00:02 +08:00
using osu.Framework.Allocation ;
2024-01-15 17:17:49 +08:00
using osu.Framework.Graphics ;
2021-03-23 14:00:02 +08:00
using osu.Framework.Logging ;
using osu.Framework.Screens ;
2022-07-13 15:36:55 +08:00
using osu.Game.Beatmaps ;
2023-12-28 01:38:29 +08:00
using osu.Game.Configuration ;
2022-07-13 15:36:55 +08:00
using osu.Game.Database ;
2024-02-29 06:13:31 +08:00
using osu.Game.Online ;
2021-03-23 14:00:02 +08:00
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 ;
2021-03-23 14:00:02 +08:00
using osu.Game.Online.Rooms ;
2022-07-28 19:44:02 +08:00
using osu.Game.Online.Spectator ;
2021-07-04 14:14:25 +08:00
using osu.Game.Rulesets.Scoring ;
2021-03-23 14:00:02 +08:00
using osu.Game.Scoring ;
namespace osu.Game.Screens.Play
{
2021-03-23 14:33:31 +08:00
/// <summary>
/// A player instance which supports submitting scores to an online store.
/// </summary>
2021-03-23 14:00:02 +08:00
public abstract partial class SubmittingPlayer : Player
{
2021-03-24 12:02:17 +08:00
/// <summary>
2021-03-24 12:02:37 +08:00
/// 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 ;
2021-03-23 14:00:02 +08:00
[Resolved]
private IAPIProvider api { get ; set ; }
2022-07-28 19:44:02 +08:00
[Resolved]
private SpectatorClient spectatorClient { get ; set ; }
2023-12-28 01:38:29 +08:00
[Resolved]
private SessionStatics statics { get ; set ; }
2024-02-09 22:19:38 +08:00
[Resolved(canBeNull: true)]
[CanBeNull]
2024-02-23 02:50:46 +08:00
private UserStatisticsWatcher userStatisticsWatcher { get ; set ; }
2024-02-09 17:41:36 +08:00
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 ( ) ;
2021-07-01 16:02:33 +08:00
private TaskCompletionSource < bool > scoreSubmissionSource ;
2021-03-23 14:35:06 +08:00
protected SubmittingPlayer ( PlayerConfiguration configuration = null )
2021-03-23 14:00:02 +08:00
: base ( configuration )
{
}
2023-11-03 05:26:52 +08:00
[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 ;
}
2023-11-06 17:08:19 +08:00
AddInternal ( new PlayerTouchInputDetector ( ) ) ;
2024-01-15 17:17:49 +08:00
// 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 ,
} ) ;
2023-11-03 05:26:52 +08:00
}
2024-01-12 21:59:15 +08:00
protected override GameplayClockContainer CreateGameplayClockContainer ( WorkingBeatmap beatmap , double gameplayStart ) = > new MasterGameplayClockContainer ( beatmap , gameplayStart )
{
ShouldValidatePlaybackRate = true ,
} ;
2021-03-23 15:05:40 +08:00
protected override void LoadAsyncComplete ( )
2021-03-25 12:48:41 +08:00
{
base . LoadAsyncComplete ( ) ;
2021-05-11 10:24:35 +08:00
handleTokenRetrieval ( ) ;
2021-03-25 12:48:41 +08:00
}
private bool handleTokenRetrieval ( )
2021-03-23 14:00:02 +08:00
{
2021-03-23 15:05:40 +08:00
// Token request construction should happen post-load to allow derived classes to potentially prepare DI backings that are used to create the request.
2021-03-23 15:41:36 +08:00
var tcs = new TaskCompletionSource < bool > ( ) ;
2021-03-23 14:00:02 +08:00
2021-06-09 13:32:48 +08:00
if ( Mods . Value . Any ( m = > ! m . UserPlayable ) )
2021-05-11 10:24:55 +08:00
{
2021-06-09 13:32:48 +08:00
handleTokenFailure ( new InvalidOperationException ( "Non-user playable mod selected." ) ) ;
2021-05-11 10:24:55 +08:00
return false ;
}
2021-03-23 15:41:36 +08:00
if ( ! api . IsLoggedIn )
2021-03-23 14:00:02 +08:00
{
2021-03-24 12:20:44 +08:00
handleTokenFailure ( new InvalidOperationException ( "API is not online." ) ) ;
2021-03-25 12:48:41 +08:00
return false ;
2021-03-23 15:41:36 +08:00
}
2021-03-23 14:00:02 +08:00
2021-03-24 12:02:37 +08:00
var req = CreateTokenRequest ( ) ;
2021-03-23 14:00:02 +08:00
2021-03-23 15:41:36 +08:00
if ( req = = null )
{
2021-03-24 12:20:44 +08:00
handleTokenFailure ( new InvalidOperationException ( "Request could not be constructed." ) ) ;
2021-03-25 12:48:41 +08:00
return false ;
2021-03-23 15:41:36 +08:00
}
req . Success + = r = >
{
2022-10-03 16:22:30 +08:00
Logger . Log ( $"Score submission token retrieved ({r.ID})" ) ;
2021-03-24 12:20:44 +08:00
token = r . ID ;
2021-03-23 15:41:36 +08:00
tcs . SetResult ( true ) ;
2021-03-23 14:00:02 +08:00
} ;
2024-02-15 17:40:40 +08:00
req . Failure + = ex = > handleTokenFailure ( ex , displayNotification : true ) ;
2021-03-23 14:00:02 +08:00
api . Queue ( req ) ;
2022-08-20 16:19:17 +08:00
// Generally a timeout would not happen here as APIAccess will timeout first.
2022-11-18 13:07:40 +08:00
if ( ! tcs . Task . Wait ( 30000 ) )
2022-10-17 08:26:28 +08:00
req . TriggerFailure ( new InvalidOperationException ( "Token retrieval timed out (request never run)" ) ) ;
2022-08-20 16:19:17 +08:00
2021-03-25 12:48:41 +08:00
return true ;
2021-03-24 12:20:44 +08:00
2024-02-15 17:40:40 +08:00
void handleTokenFailure ( Exception exception , bool displayNotification = false )
2021-03-23 15:41:36 +08:00
{
2022-10-17 08:26:28 +08:00
tcs . SetResult ( false ) ;
2022-10-03 16:29:46 +08:00
2024-02-15 17:40:40 +08:00
bool shouldExit = ShouldExitOnTokenRetrievalFailure ( exception ) ;
if ( displayNotification | | shouldExit )
2021-03-23 15:41:36 +08:00
{
2024-02-15 17:40:40 +08:00
string whatWillHappen = shouldExit
2024-02-19 20:56:21 +08:00
? "Play in this state is not permitted."
: "Your score will not be submitted." ;
2024-02-15 17:40:40 +08:00
2021-03-23 15:41:36 +08:00
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}" ) ;
2021-03-23 15:41:36 +08:00
else
2024-01-31 15:52:50 +08:00
{
switch ( exception . Message )
{
2024-02-15 17:16:06 +08:00
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 ) ;
2024-02-15 17:16:06 +08:00
break ;
2024-04-03 22:30:14 +08:00
case @"invalid beatmap hash" :
2024-04-04 06:15:22 +08:00
Logger . Log ( $"This beatmap does not match the online version. Please update or redownload it.\n\n{whatWillHappen}" , level : LogLevel . Important ) ;
2024-04-03 22:30:14 +08:00
break ;
2024-02-15 17:16:06 +08:00
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 ) ;
2024-01-31 15:52:50 +08:00
break ;
default :
2024-02-15 17:40:40 +08:00
Logger . Log ( $"{whatWillHappen} {exception.Message}" , level : LogLevel . Important ) ;
2024-01-31 15:52:50 +08:00
break ;
}
}
2024-02-15 17:40:40 +08:00
}
2021-03-23 15:41:36 +08:00
2024-02-15 17:40:40 +08:00
if ( shouldExit )
{
2021-03-23 15:41:36 +08:00
Schedule ( ( ) = >
{
ValidForResume = false ;
this . Exit ( ) ;
} ) ;
}
}
2021-03-23 14:00:02 +08:00
}
2021-03-23 15:41:36 +08:00
/// <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>
2024-02-15 17:40:40 +08:00
protected virtual bool ShouldExitOnTokenRetrievalFailure ( Exception exception ) = > true ;
2021-03-23 15:41:36 +08:00
2021-07-01 16:02:33 +08:00
protected override async Task PrepareScoreForResultsAsync ( Score score )
{
await base . PrepareScoreForResultsAsync ( score ) . ConfigureAwait ( false ) ;
2021-07-19 18:28:35 +08:00
score . ScoreInfo . Date = DateTimeOffset . Now ;
2021-07-01 16:02:33 +08:00
await submitScore ( score ) . ConfigureAwait ( false ) ;
2022-12-18 04:08:11 +08:00
spectatorClient . EndPlaying ( GameplayState ) ;
2024-02-23 02:50:46 +08:00
userStatisticsWatcher ? . RegisterForStatisticsUpdateAfter ( score . ScoreInfo ) ;
2021-07-01 16:02:33 +08:00
}
2022-07-13 15:36:55 +08:00
[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.
2022-07-13 15:36:55 +08:00
realm . WriteAsync ( r = >
{
var realmBeatmap = r . Find < BeatmapInfo > ( Beatmap . Value . BeatmapInfo . ID ) ;
if ( realmBeatmap ! = null )
realmBeatmap . LastPlayed = DateTimeOffset . Now ;
} ) ;
2022-07-28 19:44:02 +08:00
2022-12-12 12:59:27 +08:00
spectatorClient . BeginPlaying ( token , GameplayState , Score ) ;
2022-07-13 15:36:55 +08:00
}
2023-11-23 09:28:15 +08:00
protected override void OnFail ( )
2023-11-22 17:20:22 +08:00
{
2023-11-23 09:28:15 +08:00
base . OnFail ( ) ;
2023-11-22 17:20:22 +08:00
submitFromFailOrQuit ( ) ;
}
2022-04-21 23:52:44 +08:00
public override bool OnExiting ( ScreenExitEvent e )
2021-06-30 19:23:48 +08:00
{
2022-04-21 23:52:44 +08:00
bool exiting = base . OnExiting ( e ) ;
2023-11-22 17:20:22 +08:00
submitFromFailOrQuit ( ) ;
2023-12-28 21:15:15 +08:00
statics . SetValue ( Static . LastLocalUserScore , Score ? . ScoreInfo . DeepClone ( ) ) ;
2023-11-22 17:20:22 +08:00
return exiting ;
}
2021-07-01 16:38:28 +08:00
2023-11-22 17:20:22 +08:00
private void submitFromFailOrQuit ( )
{
2022-03-09 16:50:05 +08:00
if ( LoadedBeatmapSuccessfully )
2022-07-28 19:44:02 +08:00
{
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 ( ) ;
2022-07-28 19:44:02 +08:00
}
2021-06-30 19:23:48 +08:00
}
2021-07-01 16:02:33 +08:00
/// <summary>
/// Construct a request to be used for retrieval of the score token.
2024-02-15 17:40:40 +08:00
/// Can return null, at which point <see cref="ShouldExitOnTokenRetrievalFailure"/> will be fired.
2021-07-01 16:02:33 +08:00
/// </summary>
[CanBeNull]
protected abstract APIRequest < APIScoreToken > CreateTokenRequest ( ) ;
2021-03-23 14:00:02 +08:00
2021-07-01 16:02:33 +08:00
/// <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 )
{
2023-12-26 18:20:41 +08:00
var masterClock = GameplayClockContainer as MasterGameplayClockContainer ;
if ( masterClock ? . PlaybackRateValid . Value ! = true )
{
Logger . Log ( "Score submission cancelled due to audio playback rate discrepancy." ) ;
return Task . CompletedTask ;
}
2021-03-23 15:41:36 +08:00
// 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 )
2023-10-30 14:07:26 +08:00
{
Logger . Log ( "No token, skipping score submission" ) ;
2021-07-01 16:02:33 +08:00
return Task . CompletedTask ;
2023-10-30 14:07:26 +08:00
}
2021-03-23 14:00:02 +08:00
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 > ( ) ;
}
2021-07-01 16:02:33 +08:00
2021-07-04 14:14:25 +08:00
// if the user never hit anything, this score should not be counted in any way.
2021-07-04 15:41:09 +08:00
if ( ! score . ScoreInfo . Statistics . Any ( s = > s . Key . IsHit ( ) & & s . Value > 0 ) )
2021-07-04 14:14:25 +08:00
return Task . CompletedTask ;
2023-10-30 14:07:26 +08:00
Logger . Log ( $"Beginning score submission (token:{token.Value})..." ) ;
2021-03-24 12:20:44 +08:00
var request = CreateSubmissionRequest ( score , token . Value ) ;
2021-03-23 14:00:02 +08:00
request . Success + = s = >
{
2021-12-10 14:37:12 +08:00
score . ScoreInfo . OnlineID = s . ID ;
2021-12-08 14:22:02 +08:00
score . ScoreInfo . Position = s . Position ;
2021-07-01 16:02:33 +08:00
scoreSubmissionSource . SetResult ( true ) ;
2023-10-30 14:07:26 +08:00
Logger . Log ( $"Score submission completed! (token:{token.Value} id:{s.ID})" ) ;
2021-03-23 14:00:02 +08:00
} ;
request . Failure + = e = >
{
2023-10-30 14:07:26 +08:00
Logger . Error ( e , $"Failed to submit score (token:{token.Value}): {e.Message}" ) ;
2021-07-01 16:02:33 +08:00
scoreSubmissionSource . SetResult ( false ) ;
2021-03-23 14:00:02 +08:00
} ;
api . Queue ( request ) ;
2021-07-01 16:02:33 +08:00
return scoreSubmissionSource . Task ;
2021-03-23 14:00:02 +08:00
}
}
}