josh/electric-cherry
1
0
Fork 0
Code Issues 18 Pull Requests Actions Packages Projects Releases Wiki Activity

Fix game timer: cycle-key tracking, wall-clock only, active gate

Browse Source 
games_sp.log is not wiped on restart, so old J; lines from prior
sessions were poisoning the anchor. Now the scanner walks the tail
backward to the LATEST InitGame and only considers lines after it,
returning an opaque cycle key (the first J; line) plus a state. The
worker stamps game_started_at/ended_at with Date.now() at observation
time instead of inferring from the log's own timestamps. Same-players
game restarts produce a new key and cleanly re-anchor. When the server
transitions to 0 players, game state is cleared server-side and the
UI also gates the timer display on activeSince.

Adds servers.game_cycle_key column with additive migration.
This commit is contained in:
josh
2026-09-13 22:47:03 -04:00
parent 8186bb1ccc
commit efd4a4fa66
7 changed files with 87 additions and 97 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/lib/server/db/index.ts
+2 -1
View File
@@ -42,7 +42,8 @@ const SERVERS_COLUMNS: Array<{ name: string; ddl: string }> = [
{ name: 'active_since', ddl: 'ALTER TABLE servers ADD COLUMN active_since TEXT' }, { name: 'active_since', ddl: 'ALTER TABLE servers ADD COLUMN active_since TEXT' },
{ name: 'inactive_since', ddl: 'ALTER TABLE servers ADD COLUMN inactive_since TEXT' }, { name: 'inactive_since', ddl: 'ALTER TABLE servers ADD COLUMN inactive_since TEXT' },
{ name: 'game_started_at', ddl: 'ALTER TABLE servers ADD COLUMN game_started_at TEXT' }, { name: 'game_started_at', ddl: 'ALTER TABLE servers ADD COLUMN game_started_at TEXT' },
{ name: 'game_ended_at', ddl: 'ALTER TABLE servers ADD COLUMN game_ended_at TEXT' } { name: 'game_ended_at', ddl: 'ALTER TABLE servers ADD COLUMN game_ended_at TEXT' },
{ name: 'game_cycle_key', ddl: 'ALTER TABLE servers ADD COLUMN game_cycle_key TEXT' }
]; ];
function migrateServers(handle: Database.Database): void { function migrateServers(handle: Database.Database): void {
src/lib/server/db/schema.sql
+3 -2
View File
@@ -38,8 +38,9 @@ CREATE TABLE IF NOT EXISTS servers (
-- and resume from the same anchor when the server comes back. -- and resume from the same anchor when the server comes back.
active_since TEXT, -- ISO ts of last 0 -> >0 player transition active_since TEXT, -- ISO ts of last 0 -> >0 player transition
inactive_since TEXT, -- ISO ts of last >0 -> 0 player transition inactive_since TEXT, -- ISO ts of last >0 -> 0 player transition
game_started_at TEXT, -- ISO ts we first observed InitGame: for the current match game_started_at TEXT, -- wall-clock ISO when we first saw a J; line for the current match cycle
game_ended_at TEXT, -- ISO ts we observed ExitLevel/ShutdownGame ending it game_ended_at TEXT, -- wall-clock ISO when we first saw ExitLevel/ShutdownGame end it
game_cycle_key TEXT, -- opaque marker for the currently-tracked cycle (the first J; line after the latest InitGame); lets us detect same-players game restarts
created_at TEXT NOT NULL DEFAULT (strftime('%Y-%m-%dT%H:%M:%fZ','now')) created_at TEXT NOT NULL DEFAULT (strftime('%Y-%m-%dT%H:%M:%fZ','now'))
); );
src/lib/server/fleet/match-log.ts
+39 -71
View File
@@ -12,15 +12,10 @@ import { resolveLogPath, tailLog } from './logs.js';
export const MATCH_START = /InitGame:/; export const MATCH_START = /InitGame:/;
export const MATCH_END = /ExitLevel:\s*executed/; export const MATCH_END = /ExitLevel:\s*executed/;
export const MATCH_SHUTDOWN = /ShutdownGame:/; export const MATCH_SHUTDOWN = /ShutdownGame:/;
// Player join line: `MM:SS J;<guid>;<slot>;<name>`. Every joining player emits // Player join line: `MM:SS J;<guid>;<slot>;<name>`. games_sp.log accumulates
// one — the first J; line after an InitGame is when the first player actually // across restarts and contains many old J; lines; only the ones AFTER the
// entered the match, which is what "game time" should anchor to. An empty map // latest InitGame belong to the current match cycle.
// load still emits InitGame but no J; lines follow.
export const MATCH_JOIN = /\sJ;[^;]*;\d+;/; export const MATCH_JOIN = /\sJ;[^;]*;\d+;/;
// Every log line starts with a whitespace-padded MM:SS in-game time. Capture
// it so we can back-compute a wall-clock game_started_at that stays accurate
// across restarts and matches what the game itself reports (e.g. `102:47 J;...`).
const TIME_PREFIX = /^\s*(\d+):(\d{2})\s/;
/** /**
* Poll a server's games_sp.log tail for match markers. Returns whether a * Poll a server's games_sp.log tail for match markers. Returns whether a
@@ -51,25 +46,26 @@ export type MatchScanKind = 'no-signal' | 'idle' | 'in-progress' | 'ended';
export interface MatchScanResult { export interface MatchScanResult {
kind: MatchScanKind; kind: MatchScanKind;
// Populated when kind === 'in-progress': wall-clock ISO of the InitGame moment, // Opaque identifier for the currently-observed match cycle. When kind is
// back-computed from the most recent line's MM:SS prefix so it stays accurate // 'in-progress' or 'ended', this is the first J; line after the latest
// across restarts and matches the log's own timer. // InitGame. Compare against persisted state to detect a fresh cycle
startedAt?: string; // (e.g. game auto-restart with same players — new J; line = new key).
// Populated when kind === 'ended': wall-clock ISO of observation. cycleKey?: string;
endedAt?: string;
} }
/** /**
* Read the games_sp.log tail and classify the current match state: * Read the games_sp.log tail and classify the current match state. We do NOT
* - `in-progress`: the most recent InitGame has at least one J; join line * infer any wall-clock timestamps from log content — the caller stamps
* after it and no ExitLevel/ShutdownGame after that. Emits `startedAt` * game_started_at/game_ended_at with the observation time.
* back-computed from the first join line's in-game MM:SS. *
* - `ended`: the most recent InitGame is followed by ExitLevel/ShutdownGame, * - `in-progress`: latest InitGame has at least one J; join line after it
* and the shutdown wasn't the trivial 0:00 idle cycle. Emits `endedAt` = now. * and no ExitLevel/ShutdownGame between that J; and end-of-tail. `cycleKey`
* - `idle`: no join line has fired inside the current InitGame cycle (empty * is set to the first J; line after the latest InitGame.
* map loaded, or completed idle cycle at 0:00). No timer. * - `ended`: latest InitGame has a J; join line followed by an ExitLevel
* - `no-signal`: log file missing / no InitGame anywhere in the tail — * or ShutdownGame. `cycleKey` identifies which cycle ended.
* caller should leave persisted timer state alone. * - `idle`: no J; line after the latest InitGame — empty map loaded, no
* match happening.
* - `no-signal`: log missing / unreadable / no InitGame in tail.
*/ */
export async function scanMatchState(serverName: string): Promise<MatchScanResult> { export async function scanMatchState(serverName: string): Promise<MatchScanResult> {
const path = resolveLogPath(serverName, 'games_sp'); const path = resolveLogPath(serverName, 'games_sp');
@@ -79,64 +75,36 @@ export async function scanMatchState(serverName: string): Promise<MatchScanResul
if (!tail || tail.lines.length === 0) return { kind: 'no-signal' }; if (!tail || tail.lines.length === 0) return { kind: 'no-signal' };
const lines = tail.lines; const lines = tail.lines;
// Find the LATEST InitGame — everything before it is prior sessions that
// this log accumulated. Only what comes after is the current cycle.
let lastInit = -1; let lastInit = -1;
let lastExit = -1; for (let i = lines.length - 1; i >= 0; i--) {
let lastShut = -1; if (MATCH_START.test(lines[i])) {
for (let i = 0; i < lines.length; i++) { lastInit = i;
if (MATCH_START.test(lines[i])) lastInit = i; break;
if (MATCH_END.test(lines[i])) lastExit = i; }
if (MATCH_SHUTDOWN.test(lines[i])) lastShut = i;
} }
if (lastInit === -1) return { kind: 'no-signal' }; if (lastInit === -1) return { kind: 'no-signal' };
const endAfterInit = Math.max(lastExit, lastShut) > lastInit; // Scan only the current cycle (everything after the latest InitGame).
if (endAfterInit) {
// Was it an idle cycle? Idle = ShutdownGame at 0:00 with no ExitLevel
// between the InitGame and that ShutdownGame.
const exitBetween = lastExit > lastInit && lastExit < lastShut;
const shutIsIdle = !exitBetween && lastShut > lastInit && isZeroTime(lines[lastShut]);
if (shutIsIdle) return { kind: 'idle' };
return { kind: 'ended', endedAt: new Date().toISOString() };
}
// In progress from InitGame's POV — but only anchor the game timer once a
// real player has joined. Find the FIRST J; line after lastInit.
let firstJoinIdx = -1; let firstJoinIdx = -1;
let endIdx = -1;
for (let i = lastInit + 1; i < lines.length; i++) { for (let i = lastInit + 1; i < lines.length; i++) {
if (MATCH_JOIN.test(lines[i])) { if (firstJoinIdx === -1 && MATCH_JOIN.test(lines[i])) {
firstJoinIdx = i; firstJoinIdx = i;
}
if (MATCH_END.test(lines[i]) || MATCH_SHUTDOWN.test(lines[i])) {
endIdx = i;
break; break;
} }
} }
// No join in the current cycle -> nobody entered this match yet.
if (firstJoinIdx === -1) return { kind: 'idle' }; if (firstJoinIdx === -1) return { kind: 'idle' };
// Back-compute the wall-clock start from the delta between the first join const cycleKey = lines[firstJoinIdx];
// line's in-game time and the most recent parseable line's in-game time. if (endIdx !== -1 && endIdx > firstJoinIdx) {
const joinGameTime = parseTimePrefix(lines[firstJoinIdx]) ?? 0; return { kind: 'ended', cycleKey };
let currentGameTime = joinGameTime;
for (let i = lines.length - 1; i > firstJoinIdx; i--) {
const t = parseTimePrefix(lines[i]);
if (t !== null) {
currentGameTime = t;
break;
}
} }
const elapsedSinceJoin = Math.max(0, currentGameTime - joinGameTime); return { kind: 'in-progress', cycleKey };
const startedAt = new Date(Date.now() - elapsedSinceJoin).toISOString();
return { kind: 'in-progress', startedAt };
}
function parseTimePrefix(line: string): number | null {
const m = TIME_PREFIX.exec(line);
if (!m) return null;
const mm = Number(m[1]);
const ss = Number(m[2]);
if (!Number.isFinite(mm) || !Number.isFinite(ss)) return null;
return (mm * 60 + ss) * 1000;
}
function isZeroTime(line: string): boolean {
const t = parseTimePrefix(line);
return t !== null && t < 2000; // <2s — idle cycles are at 0:00
} }
src/lib/server/fleet/servers.ts
+3 -1
View File
@@ -88,6 +88,7 @@ export interface ServerRow {
inactive_since: string | null; inactive_since: string | null;
game_started_at: string | null; game_started_at: string | null;
game_ended_at: string | null; game_ended_at: string | null;
game_cycle_key: string | null;
created_at: string; created_at: string;
} }
@@ -177,7 +178,8 @@ export function setServerField(
'active_since', 'active_since',
'inactive_since', 'inactive_since',
'game_started_at', 'game_started_at',
'game_ended_at' 'game_ended_at',
'game_cycle_key'
]; ];
if (!allowed.includes(field)) throw new Error(`refusing to set ${field}`); if (!allowed.includes(field)) throw new Error(`refusing to set ${field}`);
db().prepare(`UPDATE servers SET ${field} = ? WHERE name = ?`).run(value, name); db().prepare(`UPDATE servers SET ${field} = ? WHERE name = ?`).run(value, name);
src/lib/server/pipeline/worker.ts
+33 -20
View File
@@ -55,29 +55,32 @@ async function scanMatches(): Promise<void> {
return { kind: 'no-signal' as const }; return { kind: 'no-signal' as const };
}); });
const persistedInProgress = !!srv.game_started_at && !srv.game_ended_at; const persistedInProgress = !!srv.game_started_at && !srv.game_ended_at;
const persistedKey = srv.game_cycle_key;
const now = new Date().toISOString();
if (result.kind === 'in-progress' && result.startedAt) { if (result.kind === 'in-progress' && result.cycleKey) {
// Transition to in-progress on fresh state OR when a new match // New cycle when persisted key differs (fresh start, or a game
// has begun after a crash left us with a stale in-progress // restart with the same players — new J; line = new key).
// anchor. The back-computed startedAt for the SAME match stays if (result.cycleKey !== persistedKey) {
// stable across polls (log time and wall time advance in setServerField(srv.name, 'game_started_at', now);
// lockstep), so a new anchor >30s later means a new match. setServerField(srv.name, 'game_ended_at', null);
const newStart = new Date(result.startedAt).getTime(); setServerField(srv.name, 'game_cycle_key', result.cycleKey);
const persistedStart = srv.game_started_at } else if (!persistedInProgress) {
? new Date(srv.game_started_at).getTime() // Same key but previous cycle was ended — treat as new run
: 0; // (shouldn't happen in practice since key would differ,
if (!persistedInProgress || newStart > persistedStart + 30_000) { // but be defensive).
setServerField(srv.name, 'game_started_at', result.startedAt); setServerField(srv.name, 'game_started_at', now);
setServerField(srv.name, 'game_ended_at', null); setServerField(srv.name, 'game_ended_at', null);
} }
} else if (result.kind === 'ended') { } else if (result.kind === 'ended' && result.cycleKey) {
if (persistedInProgress && result.endedAt) { // Only stamp the end if it's the cycle we've been tracking and
setServerField(srv.name, 'game_ended_at', result.endedAt); // we haven't already stamped it.
if (result.cycleKey === persistedKey && persistedInProgress) {
setServerField(srv.name, 'game_ended_at', now);
} }
} }
// 'idle' / 'no-signal': leave state alone. If we were previously // 'idle' / 'no-signal': leave state alone. UI hides the timer when
// in-progress and the log has rolled past the match, we'll only // the server has no players (see ServerCard/detail page).
// learn that later when a new InitGame appears — that's fine.
} }
} }
await Promise.all(Array.from({ length: STATUS_CONCURRENCY }, pump)); await Promise.all(Array.from({ length: STATUS_CONCURRENCY }, pump));
@@ -121,6 +124,8 @@ async function fanoutStatus(): Promise<void> {
const nextPlayers = result.status.players; const nextPlayers = result.status.players;
let activeSince = srv.active_since; let activeSince = srv.active_since;
let inactiveSince = srv.inactive_since; let inactiveSince = srv.inactive_since;
let gameStartedAt = srv.game_started_at;
let gameEndedAt = srv.game_ended_at;
if (nextPlayers > 0 && (activeSince === null || prevPlayers === 0 || prevPlayers === null)) { if (nextPlayers > 0 && (activeSince === null || prevPlayers === 0 || prevPlayers === null)) {
activeSince = now; activeSince = now;
inactiveSince = null; inactiveSince = null;
@@ -131,6 +136,14 @@ async function fanoutStatus(): Promise<void> {
activeSince = null; activeSince = null;
setServerField(srv.name, 'inactive_since', inactiveSince); setServerField(srv.name, 'inactive_since', inactiveSince);
setServerField(srv.name, 'active_since', null); setServerField(srv.name, 'active_since', null);
// Game timer cannot run while inactive. Drop any tracked
// match state so the next active session anchors fresh
// when a new J; line fires.
gameStartedAt = null;
gameEndedAt = null;
setServerField(srv.name, 'game_started_at', null);
setServerField(srv.name, 'game_ended_at', null);
setServerField(srv.name, 'game_cycle_key', null);
} }
// Persist last-observed state. last_seen_at is the health anchor. // Persist last-observed state. last_seen_at is the health anchor.
setServerField(srv.name, 'last_players', nextPlayers); setServerField(srv.name, 'last_players', nextPlayers);
@@ -155,8 +168,8 @@ async function fanoutStatus(): Promise<void> {
replySnippet: result.rawReply, replySnippet: result.rawReply,
activeSince, activeSince,
inactiveSince, inactiveSince,
gameStartedAt: srv.game_started_at, gameStartedAt,
gameEndedAt: srv.game_ended_at gameEndedAt
}; };
} else { } else {
// RCON unreachable — leave last_seen_at, active_since, and // RCON unreachable — leave last_seen_at, active_since, and
src/lib/ui/components/ServerCard.svelte
+3 -1
View File
@@ -67,7 +67,9 @@
// ISO timestamps and re-derived from a shared 1s ticker. // ISO timestamps and re-derived from a shared 1s ticker.
let activeElapsed = $derived(activeSince ? elapsedSince(activeSince, $uiNow) : null); let activeElapsed = $derived(activeSince ? elapsedSince(activeSince, $uiNow) : null);
let inactiveElapsed = $derived(inactiveSince ? elapsedSince(inactiveSince, $uiNow) : null); let inactiveElapsed = $derived(inactiveSince ? elapsedSince(inactiveSince, $uiNow) : null);
let gameInProgress = $derived(!!gameStartedAt && !gameEndedAt); // Game timer only runs while the server is active. Belt-and-suspenders for
// the server-side clear on inactive transition.
let gameInProgress = $derived(!!gameStartedAt && !gameEndedAt && !!activeSince);
let gameElapsed = $derived(gameInProgress ? elapsedSince(gameStartedAt, $uiNow) : null); let gameElapsed = $derived(gameInProgress ? elapsedSince(gameStartedAt, $uiNow) : null);
let showTiming = $derived( let showTiming = $derived(
health !== 'offline' && (activeElapsed !== null || inactiveElapsed !== null || gameElapsed !== null) health !== 'offline' && (activeElapsed !== null || inactiveElapsed !== null || gameElapsed !== null)
src/routes/servers/[name]/+page.svelte
+4 -1
View File
@@ -180,7 +180,10 @@
); );
let activeElapsed = $derived(effectiveActiveSince ? elapsedSince(effectiveActiveSince, $uiNow) : null); let activeElapsed = $derived(effectiveActiveSince ? elapsedSince(effectiveActiveSince, $uiNow) : null);
let inactiveElapsed = $derived(effectiveInactiveSince ? elapsedSince(effectiveInactiveSince, $uiNow) : null); let inactiveElapsed = $derived(effectiveInactiveSince ? elapsedSince(effectiveInactiveSince, $uiNow) : null);
let gameInProgress = $derived(!!effectiveGameStartedAt && !effectiveGameEndedAt); // Game timer only runs while active — see ServerCard.svelte.
let gameInProgress = $derived(
!!effectiveGameStartedAt && !effectiveGameEndedAt && !!effectiveActiveSince
);
let gameElapsed = $derived(gameInProgress ? elapsedSince(effectiveGameStartedAt, $uiNow) : null); let gameElapsed = $derived(gameInProgress ? elapsedSince(effectiveGameStartedAt, $uiNow) : null);
let showTiming = $derived( let showTiming = $derived(
effectiveHealth !== 'offline' && effectiveHealth !== 'offline' &&