ISSUE-041: make a ghost session say which mechanism produced it

docs/backlog/issues.md

@@ -61,9 +61,11 @@ So one exception thrown anywhere inside `SignOut()` leaves the server in exactly
 A second variant needs no rollback at all: `Disconnected` is a plain multicast invoke with no
 per-subscriber guard, so if `OnSessionDisconnected` throws, `Remove` — subscribed after it — never runs.
 
-This also fits the report saying *sometimes* rather than *always*: `SignIn` runs
-`update characters set inuse=0 where accountid=@id` (`Session.cs:209`), so a ghost clears itself the
-next time that player signs in.
+This also fits the report saying *sometimes* rather than *always*: `SignIn` clears the flags for the
+account on the way in, so a ghost heals itself the next time that player signs in. That statement now
+lives in `StaleOnlineFlags.ClearForAccount` and carries `and inuse=1`, which leaves the data identical
+and makes the rows affected mean something: without the predicate the update matches every character
+on the account and reports that count on every sign in, stale or not.
 
 **What is not established is what throws.** The remaining candidates are the three `Character` database
 writes in `DeselectCharacter` and the `ThrowIfNull(AccountNotFound)` against the account repository.
@@ -84,9 +86,17 @@ runs from the transaction's commit callback.
 - Anything gated on online state acts on stale information for the lifetime of the ghost.
 
 ### Proposed Fix
-1. **Ask for a live server log before changing anything.** In a window where a ghost was reported, look
-   for a logged exception with no matching `[Relay] client disconnected.` line. That confirms or kills
-   the mechanism above at zero cost, and it decides what the fix has to be.
+1. **Instrumented 2026-08-19 instead of asked.** The question was whether a ghost came from a sign out
+   that rolled back or from a peer that vanished without closing, and the log could not tell them
+   apart: the sign in handler wrote `a logged in account was found` for both. It now writes which one
+   it is — `[Ghost] stale login: live session still held` with the connection's silence when the
+   server is still holding the session, and `[Ghost] stale login: no live session, the account flag was
+   left set` when the flag outlived it. The first is the missing idle timeout, the second is the
+   rolled-back sign out. Also shipped: `[Session] closing.` carrying session, account, character,
+   endpoint and silence, written before sign out clears the identity; a count of the stale flags each
+   sign in clears (`StaleOnlineFlags`); and `StaleOnlineFlagCensus`, which reports every five minutes
+   and at startup how many characters are flagged online with no session behind them. Nothing here
+   changes behaviour. **Read the live log after the next patch deploy and the mechanism is named.**
 2. **DONE 2026-08-17.** The teardown no longer depends on `SignOut()` succeeding.
    `Session.OnDisconnected` raises `Disconnected` from a `finally`, so the session leaves `_sessions`
    either way, and `SessionManager.OnSessionDisconnected` contains its own failure so it cannot cancel
@@ -109,6 +119,19 @@ runs from the transaction's commit callback.
    inspection only. `ConnectionActivity` was built as a separate unit precisely so the part that could
    be tested, was — eleven tests, written first and observed failing.
 
+### A live report, 2026-08-19
+
+The operator lost their connection to the live server when their internet dropped, and on signing in
+again was told the character was already logged in and that continuing would disconnect the old
+session. That is the `account.IsLoggedIn` branch of `SignInRequestHandler`, and it is the **keepalive**
+half of this issue rather than the rollback half: a dropped link sends no close, so the server went on
+holding a session whose peer was gone. It is also the case the shipped measurement was built for — the
+silence on that session is exactly what `ConnectionActivity` records.
+
+It cannot be attributed with certainty, because the log of the day could not distinguish the two
+mechanisms. That is what the step 1 instrumentation fixes, and the next occurrence will say which it
+was.
+
 ### The half still open
 
 Step 2 stops the session leaking and stops the `Player` being ticked forever, but it does **not** put

docs/codebase/TESTING.md

@@ -10,7 +10,7 @@ coverage map below states what is covered and what is not.
 | Tier | Project | Count | Needs |
 |------|---------|-------|-------|
 | 1 — smoke | `tools/smoke-test.ps1` | 1 end-to-end run | A configured `GameRoot` and a live database |
-| 2 — unit | `src/Perpetuum.Tests` | 58 tests | Nothing. Runs anywhere the solution builds |
+| 2 — unit | `src/Perpetuum.Tests` | 99 tests | Nothing. Runs anywhere the solution builds |
 | 3 — integration | `src/Perpetuum.Tests.Integration` | 10 tests | A configured `GameRoot` and a live database |
 
 Tier 2 is the tier that runs in CI. Tiers 1 and 3 run on a developer machine that already has the
@@ -75,6 +75,12 @@ production change.
 against a command pattern, then asserts on the SQL and parameters the code under test actually
 produced. `Fakes/RecordingLogger.cs` does the same for log output.
 
+`Fakes/Sessions/` holds hand-written doubles for `ISession`, `ISessionManager`, `IAccountRepository`,
+`IRelayStateService`, `ILoginQueueService` and `IRequest`, which is what makes request handlers
+reachable at this tier. Every member no test uses throws rather than returning a default, so a path
+that starts being exercised cannot pass unnoticed. The project references `Perpetuum.RequestHandlers`
+for the same reason.
+
 Because these seams are process-wide static state, the fixtures live in xUnit collections
 (`PerpetuumStaticsCollection`) so classes touching them do not run in parallel with each other.
 

src/Perpetuum.Bootstrapper/PerpetuumBootstrapper.cs

@@ -415,6 +415,14 @@ private void InitContainer(string gameRoot)
 
             _ = _builder.RegisterType<SessionManager>().As<ISessionManager>().SingleInstance();
 
+            // Reports how many characters are flagged online with nobody connected behind them.
+            // Five minutes because it is a trend, not an alarm: the number is read off a log after
+            // the fact, and a shorter period would only add lines.
+            _ = _builder.RegisterType<StaleOnlineFlagCensus>().AutoActivate().OnActivated(e =>
+            {
+                e.Context.Resolve<IProcessManager>().AddProcess(e.Instance.ToAsync().AsTimed(TimeSpan.FromMinutes(5)));
+            }).SingleInstance();
+
             InitRelayManager();
 
             _ = _builder.RegisterType<AdminCommandRouter>().SingleInstance();

src/Perpetuum.RequestHandlers/SignInRequestHandler.cs

@@ -42,9 +42,23 @@ public void HandleRequest(IRequest request)
             var isLoggedIn = account.IsLoggedIn;
             if (isLoggedIn)
             {
-                Logger.Info("a logged in account was found, starting disconnect. accountID:" + account.Id);
-
                 var session = _sessionManager.GetByAccount(account);
+
+                // This is the only place a ghost announces itself, and the two shapes of it need
+                // different fixes. A session still held means the peer vanished without closing and
+                // nothing noticed, which is the missing idle timeout. No session behind the flag
+                // means the sign out ran and rolled back, leaving the row saying logged in. The one
+                // line this replaced said "a logged in account was found" for both, so a live log
+                // could not tell them apart.
+                Logger.Info(session == null
+                    ? SessionDiagnostics.DescribeStaleLogin(account.Id)
+                    : SessionDiagnostics.DescribeStaleLogin(
+                        account.Id,
+                        session.Id,
+                        session.RemoteEndPoint,
+                        session.Activity.SilentFor(DateTime.Now),
+                        session.Activity.LongestGap));
+
                 session?.ForceQuit(ErrorCodes.NoSimultaneousLoginsAllowed);
 
                 account.IsLoggedIn = false;

src/Perpetuum.Tests/Fakes/Sessions/FakeAccountRepository.cs

@@ -0,0 +1,31 @@
+using Perpetuum.Accounting;
+
+namespace Perpetuum.Tests.Fakes.Sessions
+{
+    /// <summary>
+    /// Holds one account in memory and records the updates written to it.
+    /// </summary>
+    public sealed class FakeAccountRepository : IAccountRepository
+    {
+        private readonly Account _account;
+
+        public FakeAccountRepository(Account account)
+        {
+            _account = account;
+        }
+
+        public int Updates { get; private set; }
+
+        public Account Get(int id) => _account;
+
+        public void Update(Account item) => Updates++;
+
+        public AccessLevel GetAccessLevel(int accountId) => _account.AccessLevel;
+        public Account Get(int accountId, string steamId) => _account;
+        public Account Get(string email, string password) => _account;
+        public IEnumerable<Account> GetBySteamId(string steamId) => [_account];
+        public IEnumerable<Account> GetAll() => [_account];
+        public void Insert(Account item) => throw new NotSupportedException();
+        public void Delete(Account item) => throw new NotSupportedException();
+    }
+}

src/Perpetuum.Tests/Fakes/Sessions/FakeRelayServices.cs

@@ -0,0 +1,41 @@
+using Perpetuum.Host.Requests;
+using Perpetuum.Services.Relay;
+using Perpetuum.Services.Sessions;
+
+namespace Perpetuum.Tests.Fakes.Sessions
+{
+    public sealed class FakeRelayStateService : IRelayStateService
+    {
+        public RelayState State { get; set; } = RelayState.OpenForPublic;
+
+        public event Action<RelayState> StateChanged { add { } remove { } }
+
+        public void SendStateToClient(ISession session) => throw new NotSupportedException();
+        public void ConfigOnlyAllowAdmins(bool enabled) => throw new NotSupportedException();
+    }
+
+    public sealed class FakeLoginQueueService : ILoginQueueService
+    {
+        public int Enqueued { get; private set; }
+
+        public void EnqueueAccount(ISession session, int accountID, string hwHash, int language) => Enqueued++;
+
+        public void Start() { }
+        public void Stop() { }
+        public void Update(TimeSpan time) { }
+    }
+
+    public sealed class FakeRequest : IRequest
+    {
+        public FakeRequest(ISession session, Dictionary<string, object>? data = null)
+        {
+            Session = session;
+            Data = data ?? [];
+        }
+
+        public ISession Session { get; }
+        public Dictionary<string, object> Data { get; }
+        public Command Command => throw new NotSupportedException();
+        public string Target => throw new NotSupportedException();
+    }
+}

src/Perpetuum.Tests/Fakes/Sessions/FakeSession.cs

@@ -0,0 +1,59 @@
+using System.Net;
+using Perpetuum.Accounting.Characters;
+using Perpetuum.Host.Requests;
+using Perpetuum.Network;
+using Perpetuum.Services.Sessions;
+using Perpetuum.Zones;
+
+namespace Perpetuum.Tests.Fakes.Sessions
+{
+    /// <summary>
+    /// A session that carries an identity and records whether it was forced to quit. Everything a
+    /// test does not use throws, so a member that starts being used cannot pass silently.
+    /// </summary>
+    public sealed class FakeSession : ISession
+    {
+        public FakeSession(int accountId, ConnectionActivity? activity = null, IPEndPoint? remoteEndPoint = null)
+        {
+            AccountId = accountId;
+            Activity = activity ?? new ConnectionActivity(DateTime.Now);
+            RemoteEndPoint = remoteEndPoint ?? new IPEndPoint(IPAddress.Loopback, 1024 + accountId);
+        }
+
+        public SessionID Id { get; } = SessionID.New();
+        public int AccountId { get; }
+        public IPEndPoint RemoteEndPoint { get; }
+        public ConnectionActivity Activity { get; }
+        public bool IsAuthenticated => AccountId > 0;
+        // Deliberately not initialised to Character.None: that property reaches into the entity
+        // services locator, which a test using this fake has no reason to have installed.
+        public Character Character { get; set; }
+        public AccessLevel AccessLevel => AccessLevel.normal;
+        public bool AccountCreatedInSession { get; set; }
+        public string ClientVersion { get; set; } = string.Empty;
+        public int SteamBuild { get; set; }
+
+        public ErrorCodes? ForcedQuitWith { get; private set; }
+
+        public void ForceQuit(ErrorCodes error = ErrorCodes.NoError, string comment = null)
+        {
+            ForcedQuitWith = error;
+        }
+
+        public IZoneManager ZoneMgr => throw new NotSupportedException();
+        public void SendMessage(MessageBuilder builder) => throw new NotSupportedException();
+        public void SendMessage(IMessage message) => throw new NotSupportedException();
+        public IRequest CreateLocalRequest(string data) => throw new NotSupportedException();
+        public void HandleLocalRequest(IRequest request) => throw new NotSupportedException();
+        public void Start() => throw new NotSupportedException();
+        public void SignIn(int accountID, string hwHash, int language) => throw new NotSupportedException();
+        public void SignOut() => throw new NotSupportedException();
+        public void SelectCharacter(Character character) => throw new NotSupportedException();
+        public void DeselectCharacter() => throw new NotSupportedException();
+
+        public event SessionEventHandler Disconnected { add { } remove { } }
+        public event SessionEventHandler RsaKeyReceived { add { } remove { } }
+        public event SessionEventHandler<Character> CharacterSelected { add { } remove { } }
+        public event SessionEventHandler<Character> CharacterDeselected { add { } remove { } }
+    }
+}

src/Perpetuum.Tests/Fakes/Sessions/FakeSessionManager.cs

@@ -0,0 +1,35 @@
+using Perpetuum.Accounting;
+using Perpetuum.Accounting.Characters;
+using Perpetuum.Services.Sessions;
+
+namespace Perpetuum.Tests.Fakes.Sessions
+{
+    /// <summary>
+    /// Holds whatever sessions a test put in it. Lookups that no test needs throw rather than
+    /// returning null, so an unimplemented path cannot be mistaken for an empty one.
+    /// </summary>
+    public sealed class FakeSessionManager : ISessionManager
+    {
+        private readonly List<ISession> _sessions = [];
+
+        public void Add(ISession session) => _sessions.Add(session);
+
+        public IEnumerable<ISession> Sessions => _sessions;
+
+        public ISession GetByAccount(Account account) => GetByAccount(account.Id);
+
+        public ISession GetByAccount(int accountId) => _sessions.FirstOrDefault(s => s.AccountId == accountId);
+
+        public int MaxSessions { get; set; }
+
+        public ISession Get(SessionID sessionId) => throw new NotSupportedException();
+        public ISession GetByCharacter(Character character) => throw new NotSupportedException();
+        public ISession GetByCharacter(int characterid) => throw new NotSupportedException();
+        public IEnumerable<Character> SelectedCharacters => throw new NotSupportedException();
+        public bool Contains(SessionID sessionId) => throw new NotSupportedException();
+        public bool IsOnline(Character character) => throw new NotSupportedException();
+
+        public event SessionEventHandler SessionAdded { add { } remove { } }
+        public event SessionEventHandler<Character> CharacterDeselected { add { } remove { } }
+    }
+}

src/Perpetuum.Tests/Perpetuum.Tests.csproj

@@ -17,6 +17,7 @@
 
   <ItemGroup>
     <ProjectReference Include="..\Perpetuum\Perpetuum.csproj" />
+    <ProjectReference Include="..\Perpetuum.RequestHandlers\Perpetuum.RequestHandlers.csproj" />
   </ItemGroup>
 
 </Project>

src/Perpetuum.Tests/Unit/SessionDiagnosticsTests.cs

@@ -0,0 +1,80 @@
+using System.Net;
+using Perpetuum.Services.Sessions;
+using Xunit;
+
+namespace Perpetuum.Tests.Unit
+{
+    public class SessionDiagnosticsTests
+    {
+        private static readonly IPEndPoint Remote = new(IPAddress.Loopback, 4321);
+
+        [Fact]
+        public void A_stale_login_that_still_holds_a_session_reports_how_long_it_has_been_silent()
+        {
+            SessionID sessionId = SessionID.New();
+
+            string line = SessionDiagnostics.DescribeStaleLogin(
+                accountId: 7,
+                sessionId: sessionId,
+                remoteEndPoint: Remote,
+                silentFor: TimeSpan.FromSeconds(93),
+                longestGap: TimeSpan.FromSeconds(12));
+
+            // The silence is the discriminator. A session still held by the server means the peer
+            // vanished without closing and nothing here noticed, which is the missing idle timeout
+            // rather than a rolled back sign out.
+            Assert.Contains("live session", line);
+            Assert.Contains("accountId:7", line);
+            Assert.Contains($"sessionId:{sessionId}", line);
+            Assert.Contains("silentFor:93.0s", line);
+            Assert.Contains("longestGap:12.0s", line);
+            Assert.Contains(Remote.ToString(), line);
+        }
+
+        [Fact]
+        public void A_stale_login_with_no_session_left_is_reported_as_a_flag_nobody_cleared()
+        {
+            string line = SessionDiagnostics.DescribeStaleLogin(accountId: 7);
+
+            // The other half of the discriminator: the session is gone but the account row still
+            // says logged in, which is what a sign out that rolled back leaves behind.
+            Assert.Contains("no live session", line);
+            Assert.Contains("accountId:7", line);
+            Assert.DoesNotContain("silentFor", line);
+        }
+
+        [Fact]
+        public void A_closing_session_is_reported_with_everything_needed_to_stitch_the_other_lines()
+        {
+            SessionID sessionId = SessionID.New();
+
+            string line = SessionDiagnostics.DescribeClosing(
+                sessionId: sessionId,
+                accountId: 7,
+                characterId: 55,
+                remoteEndPoint: Remote,
+                silentFor: TimeSpan.FromSeconds(4),
+                longestGap: TimeSpan.FromSeconds(2.5));
+
+            // TcpConnection and SessionManager both log the same disconnect with only the endpoint
+            // to identify it. This line is the one that carries the identity, so it has to be
+            // written before sign out clears AccountId and Character.
+            Assert.Contains($"sessionId:{sessionId}", line);
+            Assert.Contains("accountId:7", line);
+            Assert.Contains("characterId:55", line);
+            Assert.Contains(Remote.ToString(), line);
+            Assert.Contains("silentFor:4.0s", line);
+            Assert.Contains("longestGap:2.5s", line);
+        }
+
+        [Fact]
+        public void A_census_reports_the_flags_that_have_nobody_connected_behind_them()
+        {
+            string line = SessionDiagnostics.DescribeCensus(orphaned: 3, flagged: 40, liveSessions: 37);
+
+            Assert.Contains("3", line);
+            Assert.Contains("40", line);
+            Assert.Contains("37", line);
+        }
+    }
+}