Skip to content

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

Merged
Sellafield merged 4 commits into
OpenPerpetuum:developfrom
meketreve:issue-041-session-diagnostics
Aug 20, 2026
Merged

ISSUE-041: make a ghost session say which mechanism produced it#57
Sellafield merged 4 commits into
OpenPerpetuum:developfrom
meketreve:issue-041-session-diagnostics

Conversation

@meketreve

Copy link
Copy Markdown
Contributor

What this does. Nothing changes behaviour. A ghost session currently produces the same log line whichever mechanism made it, and this makes the log say which.

SignInRequestHandler wrote a logged in account was found, starting disconnect for both shapes of the same symptom:

What is true What it means What the log said
The server still holds the session The peer vanished without closing and nothing noticed — the missing idle timeout the same line
No session behind the flag The sign out ran and rolled back, leaving accounts.isloggedin set the same line

It now writes which one it is, and the held case carries the connection's silence from the ConnectionActivity added in #56, so the gap that produced it sits next to it.

Three more pieces:

  • [Session] closing. carrying session, account, character, endpoint and both silence numbers. Written before sign out rather than after, because sign out clears AccountId and Character on commit and every later line has only the endpoint left to identify the connection by. Unauthenticated connections are skipped.
  • A count of the stale online flags each sign in clears, in StaleOnlineFlags. Sign in has always run that update defensively; nothing recorded that it ever found anything.
  • StaleOnlineFlagCensus, reporting every five minutes and at startup how many characters are flagged online with no session behind them. It reports and does not repair: a census that cleared what it counted would erase the evidence it exists to gather, and doing that on a timer would race the sessions legitimately holding those flags.

One statement changed shape. The defensive update at sign in gained and inuse=1. The data it leaves behind is identical — setting a column to the value it already holds changes nothing — but without the predicate the rows affected are the account's character count on every sign in rather than the stale flags, and the count is the whole point of touching it.

What this does not do. No compensating write, no idle timeout, no threshold. All three need numbers that only a live server produces, which is what this is for.

Verification. Build 0 errors, no new warnings in the touched files. Tier 2 99/99, up from 84. Tier 3 10/10 with 0 skipped. Smoke green, exit 0 — and the census line appears in its log:

[16:05:09] INF [Ghost] census: 0 of 0 online flag(s) have no live session. liveSessions:0

That line is the point of running it: it proves the process is registered and running rather than merely compiled.

Coverage, stated plainly. The two new types and the sign-in handler are unit tested, fifteen tests, each written first and observed failing. Perpetuum.Tests now references Perpetuum.RequestHandlers and carries hand-written session fakes, which is what makes a request handler reachable at that tier; every member no test uses throws rather than returning a default. The Session closing line is covered by inspection only — Session builds its connection from a raw Socket in its constructor and cannot be constructed at the unit tier — which is exactly why the wording it logs lives in SessionDiagnostics, where it is tested.

Two tags, so a live log can be grepped. [Session] for the ordinary lifecycle, [Ghost] for a character left flagged online with nobody behind it.

Open question, and it stays open on purpose. A ghost session was reported on the live server on 2026-08-19 after a dropped internet connection: signing in again reported the character was already logged in. That looks like the keepalive path rather than the rollback path, but it cannot be attributed with certainty, because distinguishing them is precisely what the log could not do. The next occurrence after this is deployed will say which it was.

Measured against 1c21cdc.

meketreve and others added 4 commits August 19, 2026 16:01
…n in clears

Two small types, both unit tested, neither wired in yet.

SessionDiagnostics composes the lines in one place so the words and the units
stay the same wherever they are written from. Two tags: [Session] for the
ordinary lifecycle, [Ghost] for a character left flagged online with nobody
behind it. It also exists so the wording can be tested at all -- Session builds
its connection from a raw socket and cannot be reached at the unit tier.

StaleOnlineFlags takes over the update sign in has always run defensively
against characters.inuse, and reports how many rows it cleared. Those rows are
exactly the online flags a previous sign out failed to clear, and nothing has
ever recorded how often that happens.

The statement gains "and inuse=1". The data it leaves behind is identical --
setting a column to the value it already holds changes nothing -- but without
the predicate the update matches every character on the account and would report
that count on every single sign in, stale or not.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…ing session

A ghost announces itself at sign in: the account row says logged in when nobody
asked it to be. Until now the handler wrote "a logged in account was found" for
both shapes of that, and they need different fixes.

If the server is still holding the session, the peer vanished without closing
and nothing here noticed -- the missing idle timeout. If there is no session
behind the flag, the sign out ran and rolled back, leaving the row set. The
handler now writes which one it is, and the held case carries the connection's
silence, so the gap that produced it is on the record next to it.

Session gains a line of its own when it closes, carrying session, account,
character, endpoint and both silence numbers. It is written before sign out
rather than after, because sign out clears AccountId and Character on commit and
every later line has only the endpoint left to identify the connection by.
Unauthenticated connections are skipped: no identity to correlate, and
TcpConnection already logs their close.

ISession and ITcpConnection expose the ConnectionActivity that OpenPerpetuum#56 added, which
is what lets the handler report a held session's silence.

Perpetuum.Tests now references Perpetuum.RequestHandlers, and Fakes/Sessions
holds the doubles that make a request handler reachable at the unit tier. Every
member no test uses throws rather than returning a default.

Sign in no longer runs the flag update inline; it calls StaleOnlineFlags.

Three tests, written first and observed failing against the single old line.
The Session change itself is covered by inspection only -- Session takes a raw
Socket in its constructor and cannot be constructed at this tier -- which is why
the wording it logs lives in SessionDiagnostics, where it is tested.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The per-event lines say when a ghost was made or found. This says how many are
standing right now, which is the number that tells a bad evening apart from a
steady leak -- and the only one of the two that keeps being true while nobody is
signing in.

StaleOnlineFlagCensus counts the characters flagged online whose account holds
no live session, and logs the count every five minutes. Five minutes because it
is a trend rather than an alarm: the number is read off a log afterwards, and a
shorter period would only add lines.

It also reports as soon as it starts. The timer fires a full interval after
that, so the first number would otherwise arrive five minutes into the run, and
the reading at start is the sharpest one available: no session is connected yet,
so every flag still set was left behind by the run before.

Counted per row rather than per account, because one account can hold several
characters and the flag is left on whichever one was selected.

It reports and does not repair. A census that cleared what it counted would
erase the evidence it was added to gather, and doing that on a timer would race
the sessions legitimately holding those flags.

Five tests, written first and observed failing.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The backlog entry asked for a live server log before anything else, on the
grounds that only a log could say whether a ghost came from a sign out that
rolled back or from a peer that vanished without closing. The log of the day
could not say: the sign in handler wrote the same line for both. Step 1 now
describes what was shipped to make it answerable instead of who to ask.

Also recorded: a ghost session reported from the live server on 2026-08-19,
after a dropped internet connection. That is the keepalive half of this issue
rather than the rollback half, and it is the case the measurement in OpenPerpetuum#56 was
built for -- but it cannot be attributed with certainty, because that is exactly
the distinction the log could not draw.

TESTING.md picks up the unit count, which was stale, and the session fakes that
make request handlers reachable at that tier.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@Sellafield
Sellafield merged commit d17f3cb into OpenPerpetuum:develop Aug 20, 2026
4 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants