Fix preference loading bugs (#27742)

First bug: if an error occured during pref loading code, it would fail. If the person then readied up, it would likely cause the round to fail to start.

Why could they ready up? The code only checks that the prefs finished loading, not that they finished loading *successfully*. Whoops.

Anyways, now people get kicked if their prefs fail to load. And I improved the error handling.

Second bug: if a user disconnected while their prefs were loading, it would cause an exception. This exception would go unobserved on lobby servers or raise through gameticker on non-lobby servers.

This happened even on a live server once and then triggered the first bug, but idk how.

Fixed this by properly plumbing through cancellation into the preferences loading code. The stuff is now cancelled properly.

Third bug: if somebody has a loadout item with a playtime requirement active, load-time sanitization of player prefs could run into a race condition because the sanitization can happen *before* play time was loaded.

Fixed by moving pref sanitizations to a later stage in the load process.

Content.Server/Database/ServerDbBase.cs

@@ -33,9 +33,11 @@ namespace Content.Server.Database
         }
 
         #region Preferences
-        public async Task<PlayerPreferences?> GetPlayerPreferencesAsync(NetUserId userId)
+        public async Task<PlayerPreferences?> GetPlayerPreferencesAsync(
+            NetUserId userId,
+            CancellationToken cancel = default)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             var prefs = await db.DbContext
                 .Preference
@@ -47,7 +49,7 @@ namespace Content.Server.Database
                     .ThenInclude(l => l.Groups)
                     .ThenInclude(group => group.Loadouts)
                 .AsSingleQuery()
-                .SingleOrDefaultAsync(p => p.UserId == userId.UserId);
+                .SingleOrDefaultAsync(p => p.UserId == userId.UserId, cancel);
 
             if (prefs is null)
                 return null;
@@ -515,13 +517,13 @@ namespace Content.Server.Database
         #endregion
 
         #region Playtime
-        public async Task<List<PlayTime>> GetPlayTimes(Guid player)
+        public async Task<List<PlayTime>> GetPlayTimes(Guid player, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             return await db.DbContext.PlayTime
                 .Where(p => p.PlayerId == player)
-                .ToListAsync();
+                .ToListAsync(cancel);
         }
 
         public async Task UpdatePlayTimes(IReadOnlyCollection<PlayTimeUpdate> updates)
@@ -673,7 +675,7 @@ namespace Content.Server.Database
          */
         public async Task<Admin?> GetAdminDataForAsync(NetUserId userId, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             return await db.DbContext.Admin
                 .Include(p => p.Flags)
@@ -688,7 +690,7 @@ namespace Content.Server.Database
 
         public async Task<AdminRank?> GetAdminRankDataForAsync(int id, CancellationToken cancel = default)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             return await db.DbContext.AdminRank
                 .Include(r => r.Flags)
@@ -697,7 +699,7 @@ namespace Content.Server.Database
 
         public async Task RemoveAdminAsync(NetUserId userId, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             var admin = await db.DbContext.Admin.SingleAsync(a => a.UserId == userId.UserId, cancel);
             db.DbContext.Admin.Remove(admin);
@@ -707,7 +709,7 @@ namespace Content.Server.Database
 
         public async Task AddAdminAsync(Admin admin, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             db.DbContext.Admin.Add(admin);
 
@@ -716,7 +718,7 @@ namespace Content.Server.Database
 
         public async Task UpdateAdminAsync(Admin admin, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             var existing = await db.DbContext.Admin.Include(a => a.Flags).SingleAsync(a => a.UserId == admin.UserId, cancel);
             existing.Flags = admin.Flags;
@@ -728,7 +730,7 @@ namespace Content.Server.Database
 
         public async Task RemoveAdminRankAsync(int rankId, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             var admin = await db.DbContext.AdminRank.SingleAsync(a => a.Id == rankId, cancel);
             db.DbContext.AdminRank.Remove(admin);
@@ -738,7 +740,7 @@ namespace Content.Server.Database
 
         public async Task AddAdminRankAsync(AdminRank rank, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             db.DbContext.AdminRank.Add(rank);
 
@@ -811,7 +813,7 @@ INSERT INTO player_round (players_id, rounds_id) VALUES ({players[player]}, {id}
 
         public async Task UpdateAdminRankAsync(AdminRank rank, CancellationToken cancel)
         {
-            await using var db = await GetDb();
+            await using var db = await GetDb(cancel);
 
             var existing = await db.DbContext.AdminRank
                 .Include(r => r.Flags)
@@ -1594,7 +1596,9 @@ INSERT INTO player_round (players_id, rounds_id) VALUES ({players[player]}, {id}
             return db.DbContext.Database.HasPendingModelChanges();
         }
 
-        protected abstract Task<DbGuard> GetDb([CallerMemberName] string? name = null);
+        protected abstract Task<DbGuard> GetDb(
+            CancellationToken cancel = default,
+            [CallerMemberName] string? name = null);
 
         protected void LogDbOp(string? name)
         {

Content.Server/Database/ServerDbManager.cs

@@ -29,7 +29,11 @@ namespace Content.Server.Database
         void Shutdown();
 
         #region Preferences
-        Task<PlayerPreferences> InitPrefsAsync(NetUserId userId, ICharacterProfile defaultProfile);
+        Task<PlayerPreferences> InitPrefsAsync(
+            NetUserId userId,
+            ICharacterProfile defaultProfile,
+            CancellationToken cancel);
+
         Task SaveSelectedCharacterIndexAsync(NetUserId userId, int index);
 
         Task SaveCharacterSlotAsync(NetUserId userId, ICharacterProfile? profile, int slot);
@@ -38,7 +42,7 @@ namespace Content.Server.Database
 
         // Single method for two operations for transaction.
         Task DeleteSlotAndSetSelectedIndex(NetUserId userId, int deleteSlot, int newSlot);
-        Task<PlayerPreferences?> GetPlayerPreferencesAsync(NetUserId userId);
+        Task<PlayerPreferences?> GetPlayerPreferencesAsync(NetUserId userId, CancellationToken cancel);
         #endregion
 
         #region User Ids
@@ -157,8 +161,9 @@ namespace Content.Server.Database
         /// Look up a player's role timers.
         /// </summary>
         /// <param name="player">The player to get the role timer information from.</param>
+        /// <param name="cancel"></param>
         /// <returns>All role timers belonging to the player.</returns>
-        Task<List<PlayTime>> GetPlayTimes(Guid player);
+        Task<List<PlayTime>> GetPlayTimes(Guid player, CancellationToken cancel = default);
 
         /// <summary>
         /// Update play time information in bulk.
@@ -346,7 +351,10 @@ namespace Content.Server.Database
             _sqliteInMemoryConnection?.Dispose();
         }
 
-        public Task<PlayerPreferences> InitPrefsAsync(NetUserId userId, ICharacterProfile defaultProfile)
+        public Task<PlayerPreferences> InitPrefsAsync(
+            NetUserId userId,
+            ICharacterProfile defaultProfile,
+            CancellationToken cancel)
         {
             DbWriteOpsMetric.Inc();
             return RunDbCommand(() => _db.InitPrefsAsync(userId, defaultProfile));
@@ -376,10 +384,10 @@ namespace Content.Server.Database
             return RunDbCommand(() => _db.SaveAdminOOCColorAsync(userId, color));
         }
 
-        public Task<PlayerPreferences?> GetPlayerPreferencesAsync(NetUserId userId)
+        public Task<PlayerPreferences?> GetPlayerPreferencesAsync(NetUserId userId, CancellationToken cancel)
         {
             DbReadOpsMetric.Inc();
-            return RunDbCommand(() => _db.GetPlayerPreferencesAsync(userId));
+            return RunDbCommand(() => _db.GetPlayerPreferencesAsync(userId, cancel));
         }
 
         public Task AssignUserIdAsync(string name, NetUserId userId)
@@ -487,10 +495,10 @@ namespace Content.Server.Database
 
         #region Playtime
 
-        public Task<List<PlayTime>> GetPlayTimes(Guid player)
+        public Task<List<PlayTime>> GetPlayTimes(Guid player, CancellationToken cancel)
         {
             DbReadOpsMetric.Inc();
-            return RunDbCommand(() => _db.GetPlayTimes(player));
+            return RunDbCommand(() => _db.GetPlayTimes(player, cancel));
         }
 
         public Task UpdatePlayTimes(IReadOnlyCollection<PlayTimeUpdate> updates)

Content.Server/Database/ServerDbPostgres.cs

@@ -527,22 +527,26 @@ WHERE to_tsvector('english'::regconfig, a.message) @@ websearch_to_tsquery('engl
             return time;
         }
 
-        private async Task<DbGuardImpl> GetDbImpl([CallerMemberName] string? name = null)
+        private async Task<DbGuardImpl> GetDbImpl(
+            CancellationToken cancel = default,
+            [CallerMemberName] string? name = null)
         {
             LogDbOp(name);
 
             await _dbReadyTask;
-            await _prefsSemaphore.WaitAsync();
+            await _prefsSemaphore.WaitAsync(cancel);
 
             if (_msLag > 0)
-                await Task.Delay(_msLag);
+                await Task.Delay(_msLag, cancel);
 
             return new DbGuardImpl(this, new PostgresServerDbContext(_options));
         }
 
-        protected override async Task<DbGuard> GetDb([CallerMemberName] string? name = null)
+        protected override async Task<DbGuard> GetDb(
+            CancellationToken cancel = default,
+            [CallerMemberName] string? name = null)
         {
-            return await GetDbImpl(name);
+            return await GetDbImpl(cancel, name);
         }
 
         private sealed class DbGuardImpl : DbGuard

Content.Server/Database/ServerDbSqlite.cs

@@ -439,7 +439,7 @@ namespace Content.Server.Database
         public override async Task<((Admin, string? lastUserName)[] admins, AdminRank[])> GetAllAdminAndRanksAsync(
             CancellationToken cancel)
         {
-            await using var db = await GetDbImpl();
+            await using var db = await GetDbImpl(cancel);
 
             var admins = await db.SqliteDbContext.Admin
                 .Include(a => a.Flags)
@@ -514,23 +514,27 @@ namespace Content.Server.Database
             return DateTime.SpecifyKind(time, DateTimeKind.Utc);
         }
 
-        private async Task<DbGuardImpl> GetDbImpl([CallerMemberName] string? name = null)
+        private async Task<DbGuardImpl> GetDbImpl(
+            CancellationToken cancel = default,
+            [CallerMemberName] string? name = null)
         {
             LogDbOp(name);
             await _dbReadyTask;
             if (_msDelay > 0)
-                await Task.Delay(_msDelay);
+                await Task.Delay(_msDelay, cancel);
 
-            await _prefsSemaphore.WaitAsync();
+            await _prefsSemaphore.WaitAsync(cancel);
 
             var dbContext = new SqliteServerDbContext(_options());
 
             return new DbGuardImpl(this, dbContext);
         }
 
-        protected override async Task<DbGuard> GetDb([CallerMemberName] string? name = null)
+        protected override async Task<DbGuard> GetDb(
+            CancellationToken cancel = default,
+            [CallerMemberName] string? name = null)
         {
-            return await GetDbImpl(name).ConfigureAwait(false);
+            return await GetDbImpl(cancel, name).ConfigureAwait(false);
         }
 
         private sealed class DbGuardImpl : DbGuard
@@ -569,9 +573,9 @@ namespace Content.Server.Database
                 _semaphore = new SemaphoreSlim(maxCount, maxCount);
             }
 
-            public Task WaitAsync()
+            public Task WaitAsync(CancellationToken cancel = default)
             {
-                var task = _semaphore.WaitAsync();
+                var task = _semaphore.WaitAsync(cancel);
 
                 if (_synchronous)
                 {

Content.Server/Database/UserDbDataManager.cs

@@ -2,6 +2,7 @@
 using System.Threading.Tasks;
 using Content.Server.Players.PlayTimeTracking;
 using Content.Server.Preferences.Managers;
+using Robust.Server.Player;
 using Robust.Shared.Network;
 using Robust.Shared.Player;
 using Robust.Shared.Utility;
@@ -16,17 +17,22 @@ namespace Content.Server.Database;
 /// Actual loading code is handled by separate managers such as <see cref="IServerPreferencesManager"/>.
 /// This manager is simply a centralized "is loading done" controller for other code to rely on.
 /// </remarks>
-public sealed class UserDbDataManager
+public sealed class UserDbDataManager : IPostInjectInit
 {
     [Dependency] private readonly IServerPreferencesManager _prefs = default!;
+    [Dependency] private readonly ILogManager _logManager = default!;
     [Dependency] private readonly PlayTimeTrackingManager _playTimeTracking = default!;
 
     private readonly Dictionary<NetUserId, UserData> _users = new();
 
+    private ISawmill _sawmill = default!;
+
     // TODO: Ideally connected/disconnected would be subscribed to IPlayerManager directly,
     // but this runs into ordering issues with game ticker.
     public void ClientConnected(ICommonSession session)
     {
+        _sawmill.Verbose($"Initiating load for user {session}");
+
         DebugTools.Assert(!_users.ContainsKey(session.UserId), "We should not have any cached data on client connect.");
 
         var cts = new CancellationTokenSource();
@@ -50,12 +56,53 @@ public sealed class UserDbDataManager
     }
 
     private async Task Load(ICommonSession session, CancellationToken cancel)
+    {
+        // The task returned by this function is only ever observed by callers of WaitLoadComplete,
+        // which doesn't even happen currently if the lobby is enabled.
+        // As such, this task must NOT throw a non-cancellation error!
+        try
         {
             await Task.WhenAll(
                 _prefs.LoadData(session, cancel),
                 _playTimeTracking.LoadData(session, cancel));
+
+            cancel.ThrowIfCancellationRequested();
+            _prefs.SanitizeData(session);
+
+            _sawmill.Verbose($"Load complete for user {session}");
+        }
+        catch (OperationCanceledException)
+        {
+            _sawmill.Debug($"Load cancelled for user {session}");
+
+            // We can rethrow the cancellation.
+            // This will make the task returned by WaitLoadComplete() also return a cancellation.
+            throw;
+        }
+        catch (Exception e)
+        {
+            // Must catch all exceptions here, otherwise task may go unobserved.
+            _sawmill.Error($"Load of user data failed: {e}");
+
+            // Kick them from server, since something is hosed. Let them try again I guess.
+            session.Channel.Disconnect("Loading of server user data failed, this is a bug.");
+
+            // We throw a OperationCanceledException so users of WaitLoadComplete() always see cancellation here.
+            throw new OperationCanceledException("Load of user data cancelled due to unknown error");
+        }
     }
 
+    /// <summary>
+    /// Wait for all on-database data for a user to be loaded.
+    /// </summary>
+    /// <remarks>
+    /// The task returned by this function may end up in a cancelled state
+    /// (throwing <see cref="OperationCanceledException"/>) if the user disconnects while loading or an error occurs.
+    /// </remarks>
+    /// <param name="session"></param>
+    /// <returns>
+    /// A task that completes when all on-database data for a user has finished loading.
+    /// </returns>
     public Task WaitLoadComplete(ICommonSession session)
     {
         return _users[session.UserId].Task;
@@ -63,7 +110,7 @@ public sealed class UserDbDataManager
 
     public bool IsLoadComplete(ICommonSession session)
     {
-        return GetLoadTask(session).IsCompleted;
+        return GetLoadTask(session).IsCompletedSuccessfully;
     }
 
     public Task GetLoadTask(ICommonSession session)
@@ -71,5 +118,10 @@ public sealed class UserDbDataManager
         return _users[session.UserId].Task;
     }
 
+    void IPostInjectInit.PostInject()
+    {
+        _sawmill = _logManager.GetSawmill("userdb");
+    }
+
     private sealed record UserData(CancellationTokenSource Cancel, Task Task);
 }

Content.Server/GameTicking/GameTicker.Player.cs

@@ -143,15 +143,34 @@ namespace Content.Server.GameTicking
             UpdateInfoText();
 
             async void SpawnWaitDb()
+            {
+                try
                 {
                     await _userDb.WaitLoadComplete(session);
+                }
+                catch (OperationCanceledException)
+                {
+                    // Bail, user must've disconnected or something.
+                    Log.Debug($"Database load cancelled while waiting to spawn {session}");
+                    return;
+                }
 
                 SpawnPlayer(session, EntityUid.Invalid);
             }
 
             async void SpawnObserverWaitDb()
+            {
+                try
                 {
                     await _userDb.WaitLoadComplete(session);
+                }
+                catch (OperationCanceledException)
+                {
+                    // Bail, user must've disconnected or something.
+                    Log.Debug($"Database load cancelled while waiting to spawn {session}");
+                    return;
+                }
+
                 JoinAsObserver(session);
             }
 

Content.Server/Players/PlayTimeTracking/PlayTimeTrackingManager.cs

@@ -309,7 +309,7 @@ public sealed class PlayTimeTrackingManager : ISharedPlaytimeManager
         var data = new PlayTimeData();
         _playTimeData.Add(session, data);
 
-        var playTimes = await _db.GetPlayTimes(session.UserId);
+        var playTimes = await _db.GetPlayTimes(session.UserId, cancel);
         cancel.ThrowIfCancellationRequested();
 
         foreach (var timer in playTimes)

Content.Server/Preferences/Managers/IServerPreferencesManager.cs

@@ -12,6 +12,7 @@ namespace Content.Server.Preferences.Managers
         void Init();
 
         Task LoadData(ICommonSession session, CancellationToken cancel);
+        void SanitizeData(ICommonSession session);
         void OnClientDisconnected(ICommonSession session);
 
         bool TryGetCachedPreferences(NetUserId userId, [NotNullWhen(true)] out PlayerPreferences? playerPreferences);

Content.Server/Preferences/Managers/ServerPreferencesManager.cs

@@ -13,6 +13,7 @@ using Robust.Shared.Configuration;
 using Robust.Shared.Network;
 using Robust.Shared.Player;
 using Robust.Shared.Prototypes;
+using Robust.Shared.Utility;
 
 
 namespace Content.Server.Preferences.Managers
@@ -27,6 +28,7 @@ namespace Content.Server.Preferences.Managers
         [Dependency] private readonly IConfigurationManager _cfg = default!;
         [Dependency] private readonly IServerDbManager _db = default!;
         [Dependency] private readonly IPlayerManager _playerManager = default!;
+        [Dependency] private readonly IDependencyCollection _dependencies = default!;
         [Dependency] private readonly IPrototypeManager _protos = default!;
 
         // Cache player prefs on the server so we don't need as much async hell related to them.
@@ -101,9 +103,8 @@ namespace Content.Server.Preferences.Managers
 
             var curPrefs = prefsData.Prefs!;
             var session = _playerManager.GetSessionById(userId);
-            var collection = IoCManager.Instance!;
 
-            profile.EnsureValid(session, collection);
+            profile.EnsureValid(session, _dependencies);
 
             var profiles = new Dictionary<int, ICharacterProfile>(curPrefs.Characters)
             {
@@ -196,7 +197,7 @@ namespace Content.Server.Preferences.Managers
 
                 async Task LoadPrefs()
                 {
-                    var prefs = await GetOrCreatePreferencesAsync(session.UserId);
+                    var prefs = await GetOrCreatePreferencesAsync(session.UserId, cancel);
                     prefsData.Prefs = prefs;
                     prefsData.PrefsLoaded = true;
 
@@ -211,6 +212,16 @@ namespace Content.Server.Preferences.Managers
             }
         }
 
+        public void SanitizeData(ICommonSession session)
+        {
+            // This is a separate step from the actual database load.
+            // Sanitizing preferences requires play time info due to loadouts.
+            // And play time info is loaded concurrently from the DB with preferences.
+            var data = _cachedPlayerPrefs[session.UserId];
+            DebugTools.Assert(data.Prefs != null);
+            data.Prefs = SanitizePreferences(session, data.Prefs, _dependencies);
+        }
+
         public void OnClientDisconnected(ICommonSession session)
         {
             _cachedPlayerPrefs.Remove(session.UserId);
@@ -270,18 +281,15 @@ namespace Content.Server.Preferences.Managers
             return null;
         }
 
-        private async Task<PlayerPreferences> GetOrCreatePreferencesAsync(NetUserId userId)
+        private async Task<PlayerPreferences> GetOrCreatePreferencesAsync(NetUserId userId, CancellationToken cancel)
         {
-            var prefs = await _db.GetPlayerPreferencesAsync(userId);
+            var prefs = await _db.GetPlayerPreferencesAsync(userId, cancel);
             if (prefs is null)
             {
-                return await _db.InitPrefsAsync(userId, HumanoidCharacterProfile.Random());
+                return await _db.InitPrefsAsync(userId, HumanoidCharacterProfile.Random(), cancel);
             }
 
-            var session = _playerManager.GetSessionById(userId);
+            return prefs;
-            var collection = IoCManager.Instance!;
-
-            return SanitizePreferences(session, prefs, collection);
         }
 
         private PlayerPreferences SanitizePreferences(ICommonSession session, PlayerPreferences prefs, IDependencyCollection collection)