diff --git a/README.md b/README.md index 5b46edc..e285b7e 100644 --- a/README.md +++ b/README.md @@ -23,6 +23,14 @@ Historical scoreboards remain visible and are labeled separately from live count RCON diagnostics retain their own results. Telemetry does not report ping or player capacity, so those fields remain unknown in telemetry-only observations. +**Active** measures time since the lobby was first observed with players; +**Match** measures time since the script's `game_start` was received. Telemetry +records occupancy changes immediately, so a later heartbeat or status poll does +not move the active timer forward. A new match keeps the active timer if the +lobby stays occupied. An empty report clears the match timer and begins the +inactive period; a later join begins a new active period. These are observed +times, not exact player connection timestamps. + ## Fleet overview Fleet searches server names, map names, and the full player roster. Filter occupied, diff --git a/src/lib/server-observation.ts b/src/lib/server-observation.ts index 9782097..fe67756 100644 --- a/src/lib/server-observation.ts +++ b/src/lib/server-observation.ts @@ -50,14 +50,22 @@ export function selectServerObservation(server: T, const containerFresh = server.container_state === 'running' && freshStatusTimestamp(checked ?? null, now); if (containerFresh && report?.server === server.name && freshTelemetry(report, now, server.telemetry_after)) { const players = report.players.length; + // New reports carry persisted anchors through both SSE and HTTP. Keep + // the fallback for telemetry saved before server timing was included. + const timing = report.timing?.server ?? { + activeSince: server.active_since ?? report.receivedAt, + inactiveSince: server.inactive_since ?? report.receivedAt, + gameStartedAt: report.event === 'game_start' ? report.receivedAt : server.game_started_at, + gameEndedAt: report.event === 'game_start' ? null : report.event === 'game_end' ? report.receivedAt : server.game_ended_at + }; return { ...result, health: 'online', status_source: 'telemetry', last_players: players, last_map: report.map, last_seen_at: report.receivedAt, last_error: null, roster: report.players.map(player => ({ num: null, score: 'score' in player ? player.score : null, ping: null, guid: player.guid, name: player.name })), - active_since: players > 0 ? server.active_since ?? report.receivedAt : null, - inactive_since: players === 0 ? server.inactive_since ?? report.receivedAt : null, - game_started_at: players === 0 ? null : report.event === 'game_start' ? report.receivedAt : server.game_started_at, - game_ended_at: players === 0 || report.event === 'game_start' ? null : report.event === 'game_end' ? report.receivedAt : server.game_ended_at }; + active_since: players > 0 ? timing.activeSince : null, + inactive_since: players === 0 ? timing.inactiveSince : null, + game_started_at: players === 0 ? null : timing.gameStartedAt, + game_ended_at: players === 0 ? null : timing.gameEndedAt }; } const after = !server.telemetry_after || Date.parse(raw.last_seen_at ?? '') > Date.parse(server.telemetry_after); const fresh = after && freshStatusTimestamp(raw.last_seen_at, now) && !raw.last_error; diff --git a/src/lib/server/db/schema.sql b/src/lib/server/db/schema.sql index fa76753..9c1828e 100644 --- a/src/lib/server/db/schema.sql +++ b/src/lib/server/db/schema.sql @@ -89,9 +89,9 @@ CREATE TABLE IF NOT EXISTS servers ( created_by TEXT, -- 'ui' | operator identifier destroyed_at TEXT, -- ISO ts when tombstoned (row usually deleted; kept as safety net) -- Occupancy + match timers. active_since / inactive_since are mutually - -- exclusive: exactly one is non-null while a server is reachable. RCON - -- outages do NOT clear either — timers survive transient unreachability - -- and resume from the same anchor when the server comes back. + -- exclusive. Accepted telemetry records transitions immediately; status + -- polls provide the RCON fallback. Outages do NOT clear either — timers + -- survive transient unreachability and resume from the same anchor. active_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, -- receipt time of the script's game_start diff --git a/src/lib/server/fleet/telemetry.ts b/src/lib/server/fleet/telemetry.ts index 63dac5a..a295233 100644 --- a/src/lib/server/fleet/telemetry.ts +++ b/src/lib/server/fleet/telemetry.ts @@ -1,7 +1,8 @@ import { db } from '../db/index.js'; -import type { GameTelemetry } from '../../telemetry.js'; +import type { GameTelemetry, ServerTiming } from '../../telemetry.js'; import { MIN_RECORDED_ROUND } from '../../match-history.js'; import { recordLeaderboardTelemetry } from './leaderboard-ingest.js'; +import { latestGameSubmission } from './status-evidence.js'; export function listTelemetry(): GameTelemetry[] { const rows = db().prepare(`SELECT t.payload FROM server_telemetry t JOIN servers s ON s.name = t.server @@ -16,11 +17,30 @@ export function saveTelemetry(report: GameTelemetry): GameTelemetry { const row = handle.prepare('SELECT payload FROM server_telemetry WHERE server = ?').get(report.server) as { payload: string | null } | undefined; const previous: GameTelemetry | undefined = row?.payload ? JSON.parse(row.payload) : undefined; recordLeaderboardTelemetry(handle, report); + // Record each occupancy transition at receipt, before a heartbeat can + // replace game_start or an empty report between status polls. + const after = latestGameSubmission(report.server); + if (!after || Date.parse(report.receivedAt) > Date.parse(after)) { + if (report.players.length > 0) { + handle.prepare('UPDATE servers SET active_since = COALESCE(active_since, ?), inactive_since = NULL WHERE name = ?') + .run(report.receivedAt, report.server); + if (report.event === 'game_start') { + handle.prepare('UPDATE servers SET game_started_at = ?, game_ended_at = NULL WHERE name = ?').run(report.receivedAt, report.server); + } else if (report.event === 'game_end') { + handle.prepare('UPDATE servers SET game_ended_at = ? WHERE name = ?').run(report.receivedAt, report.server); + } + } else { + handle.prepare(`UPDATE servers SET active_since = NULL, inactive_since = COALESCE(inactive_since, ?), + game_started_at = NULL, game_ended_at = NULL WHERE name = ?`).run(report.receivedAt, report.server); + } + } + const serverTiming = handle.prepare(`SELECT active_since AS activeSince, inactive_since AS inactiveSince, + game_started_at AS gameStartedAt, game_ended_at AS gameEndedAt FROM servers WHERE name = ?`).get(report.server) as ServerTiming; const match = handle.prepare('SELECT id FROM leaderboard_matches WHERE server = ? ORDER BY id DESC LIMIT 1').get(report.server) as { id: number }; const sameMatch = previous?.timing?.matchId === match.id; // A gap beyond the normal heartbeat window cannot establish continuity. const continuous = previous && Date.parse(report.receivedAt) - Date.parse(previous.receivedAt) <= 120_000; - report = { ...report, timing: { matchId: match.id, players: Object.fromEntries(report.players.map(player => { + report = { ...report, timing: { matchId: match.id, server: serverTiming, players: Object.fromEntries(report.players.map(player => { const prior = continuous ? previous?.timing?.players[player.guid] : undefined; return [player.guid, { serverJoinedAt: prior?.serverJoinedAt ?? report.receivedAt, @@ -32,10 +52,7 @@ export function saveTelemetry(report: GameTelemetry): GameTelemetry { VALUES (?, ?, ?, ?, ?) ON CONFLICT(server) DO UPDATE SET round = excluded.round, players = excluded.players, received_at = excluded.received_at, payload = excluded.payload`) .run(report.server, report.event === 'game_start' ? 0 : report.round, report.players.length, report.receivedAt, JSON.stringify(report)); - if (report.event === 'game_start') { - handle.prepare('UPDATE servers SET game_started_at = ?, game_ended_at = NULL WHERE name = ?').run(report.receivedAt, report.server); - } else if (report.event === 'game_end') { - handle.prepare('UPDATE servers SET game_ended_at = ? WHERE name = ?').run(report.receivedAt, report.server); + if (report.event === 'game_end') { // Legacy betas also take match completion directly from the script. if (report.round >= MIN_RECORDED_ROUND) handle.prepare(`UPDATE beta_servers SET match_seen_at = ? WHERE server = ? AND server_deleted_at IS NULL AND stage = 'awaiting-match' AND healthy_at <= ? AND beta_id IN (SELECT id FROM betas WHERE state = 'running')`) diff --git a/src/lib/telemetry.ts b/src/lib/telemetry.ts index b6e1108..6b2edeb 100644 --- a/src/lib/telemetry.ts +++ b/src/lib/telemetry.ts @@ -22,9 +22,17 @@ export interface PlayerTiming { roundStarted: number | null; } +/** Server-owned anchors, included so successive live reports keep the same timers. */ +export interface ServerTiming { + activeSince: string | null; + inactiveSince: string | null; + gameStartedAt: string | null; + gameEndedAt: string | null; +} + export type GameTelemetry = GameEvent & { receivedAt: string; - timing?: { matchId: number; players: Record }; + timing?: { matchId: number; players: Record; server?: ServerTiming }; }; /** Validate the four script payloads; beta state is never part of the protocol. */ diff --git a/tests/unit/server-status.test.ts b/tests/unit/server-status.test.ts index 0847c17..37208d1 100644 --- a/tests/unit/server-status.test.ts +++ b/tests/unit/server-status.test.ts @@ -17,7 +17,7 @@ beforeEach(async () => { vi.clearAllMocks(); fixture = await newFixture(['unregistered-folder']); }); -afterEach(async () => { await fixture.cleanup(); }); +afterEach(async () => { vi.useRealTimers(); await fixture.cleanup(); }); async function setup() { const { db } = await import('../../src/lib/server/db/index.js'); @@ -85,6 +85,95 @@ describe('database fleet and container readiness', () => { expect(getServer('managed')?.game_ended_at).toBeNull(); }); + it('keeps the first occupied report as the active timer when more telemetry arrives before polling', async () => { + const { inspect, rcon, fanoutStatus, getServer } = await setup(); + const { GET } = await import('../../src/routes/api/servers/+server.js'); + const { subscribe } = await import('../../src/lib/server/pipeline/bus.js'); + const startedAt = Date.parse('2026-09-27T12:00:00Z'); + const at = (seconds: number) => new Date(startedAt + seconds * 1000).toISOString(); + vi.useFakeTimers({ toFake: ['Date'] }); + vi.setSystemTime(startedAt); + inspect.mockResolvedValue({ ok: true, state: 'running' }); + expect((await postTelemetry(gameEvent('game_start', 0, 1, 'managed'))).status).toBe(200); + expect(getServer('managed')).toMatchObject({ active_since: at(0), inactive_since: null, game_started_at: at(0) }); + + vi.setSystemTime(startedAt + 19_000); + const heartbeat = await (await postTelemetry(gameEvent('heartbeat', 2, 1, 'managed'))).json(); + expect(heartbeat.telemetry.timing.server).toEqual({ + activeSince: at(0), inactiveSince: null, gameStartedAt: at(0), gameEndedAt: null + }); + vi.setSystemTime(startedAt + 30_000); + const events: unknown[] = []; + const unsubscribe = subscribe(event => events.push(event)); + try { await fanoutStatus(); } finally { unsubscribe(); } + expect(rcon).not.toHaveBeenCalled(); + expect((await (await GET()).json()).servers[0]).toMatchObject({ + active_since: at(0), game_started_at: at(0), last_seen_at: at(19) + }); + expect(events).toContainEqual(expect.objectContaining({ type: 'server-status', entries: [expect.objectContaining({ + activeSince: at(0), gameStartedAt: at(0), lastSeenAt: at(19) + })] })); + + const { closeDb } = await import('../../src/lib/server/db/index.js'); + closeDb(); + expect((await (await GET()).json()).servers[0]).toMatchObject({ active_since: at(0), game_started_at: at(0) }); + }); + + it('preserves occupancy observed by RCON before game-start telemetry', async () => { + const { inspect, rcon, fanoutStatus, getServer } = await setup(); + const startedAt = Date.parse('2026-09-27T12:00:00Z'); + const at = (seconds: number) => new Date(startedAt + seconds * 1000).toISOString(); + vi.useFakeTimers({ toFake: ['Date'] }); + vi.setSystemTime(startedAt - 20_000); + inspect.mockResolvedValue({ ok: true, state: 'running' }); + rcon.mockResolvedValue({ ok: true, endpoint: { host: 'localhost', port: 28960 }, rawReply: 'status', + status: { players: 1, map: 'zombie_theater', gametype: 'zom', roster: [] } }); + await fanoutStatus(); + expect(getServer('managed')).toMatchObject({ active_since: at(-20), game_started_at: null }); + + vi.setSystemTime(startedAt); + const start = await (await postTelemetry(gameEvent('game_start', 0, 1, 'managed'))).json(); + expect(start.telemetry.timing.server).toEqual({ + activeSince: at(-20), inactiveSince: null, gameStartedAt: at(0), gameEndedAt: null + }); + expect(getServer('managed')).toMatchObject({ active_since: at(-20), inactive_since: null, game_started_at: at(0) }); + }); + + it('records an empty lobby and rejoin between status polls without restoring the old match', async () => { + const { inspect, fanoutStatus, getServer } = await setup(); + const { GET } = await import('../../src/routes/api/servers/+server.js'); + const startedAt = Date.parse('2026-09-27T12:00:00Z'); + const at = (seconds: number) => new Date(startedAt + seconds * 1000).toISOString(); + vi.useFakeTimers({ toFake: ['Date'] }); + vi.setSystemTime(startedAt); + inspect.mockResolvedValue({ ok: true, state: 'running' }); + await postTelemetry(gameEvent('game_start', 0, 1, 'managed')); + vi.setSystemTime(startedAt + 10_000); + await postTelemetry(gameEvent('game_end', 2, 1, 'managed')); + vi.setSystemTime(startedAt + 11_000); + const empty = await (await postTelemetry(gameEvent('heartbeat', 0, 0, 'managed'))).json(); + expect(empty.telemetry.timing.server).toEqual({ + activeSince: null, inactiveSince: at(11), gameStartedAt: null, gameEndedAt: null + }); + expect(getServer('managed')).toMatchObject({ + active_since: null, inactive_since: at(11), game_started_at: null, game_ended_at: null + }); + + vi.setSystemTime(startedAt + 15_000); + const rejoin = await (await postTelemetry(gameEvent('heartbeat', 1, 1, 'managed'))).json(); + expect(rejoin.telemetry.timing.server).toEqual({ + activeSince: at(15), inactiveSince: null, gameStartedAt: null, gameEndedAt: null + }); + expect(getServer('managed')).toMatchObject({ + active_since: at(15), inactive_since: null, game_started_at: null, game_ended_at: null + }); + vi.setSystemTime(startedAt + 30_000); + await fanoutStatus(); + expect((await (await GET()).json()).servers[0]).toMatchObject({ + active_since: at(15), inactive_since: null, game_started_at: null, game_ended_at: null + }); + }); + it('waits for game_start telemetry after log initialization and player joins', async () => { const { inspect, rcon, fanoutStatus, getServer } = await setup(); const { GET } = await import('../../src/routes/api/servers/+server.js'); diff --git a/tests/unit/telemetry.test.ts b/tests/unit/telemetry.test.ts index 806b28a..3123c75 100644 --- a/tests/unit/telemetry.test.ts +++ b/tests/unit/telemetry.test.ts @@ -13,6 +13,30 @@ afterEach(async () => fixture.cleanup()); const payload = gameEvent('round_change', 17); +it('does not let a request received before a lifecycle submission restore cleared timers', async () => { + const { db } = await import('../../src/lib/server/db/index.js'); + const { saveTelemetry } = await import('../../src/lib/server/fleet/telemetry.js'); + const { getServer } = await import('../../src/lib/server/fleet/servers.js'); + const at = (seconds: number) => new Date(Date.parse('2026-09-20T12:00:00Z') + seconds * 1000).toISOString(); + db().prepare('INSERT INTO restart_rollout (server, requested_at) VALUES (?, ?)').run(payload.server, at(10)); + for (const seconds of [9, 10]) { + saveTelemetry({ ...gameEvent('game_start'), receivedAt: at(seconds) }); + expect(getServer(payload.server)).toMatchObject({ active_since: null, game_started_at: null }); + } + const current = saveTelemetry({ ...gameEvent('heartbeat', 2), receivedAt: at(11) }); + expect(current.timing?.server).toEqual({ activeSince: at(11), inactiveSince: null, gameStartedAt: null, gameEndedAt: null }); +}); + +it('generates timer anchors on the server instead of accepting client-supplied timing', async () => { + const response = await post({ ...gameEvent('game_start'), receivedAt: '2000-01-01T00:00:00Z', + timing: { server: { activeSince: '2000-01-01T00:00:00Z' } } }); + const { telemetry } = await response.json(); + expect(response.status).toBe(200); + expect(telemetry.receivedAt).not.toBe('2000-01-01T00:00:00Z'); + expect(telemetry.timing.server).toEqual({ activeSince: telemetry.receivedAt, inactiveSince: null, + gameStartedAt: telemetry.receivedAt, gameEndedAt: null }); +}); + it('persists player timing across matches and resets after absence or a telemetry gap', async () => { const { saveTelemetry, listTelemetry } = await import('../../src/lib/server/fleet/telemetry.js'); const { closeDb } = await import('../../src/lib/server/db/index.js'); diff --git a/tests/unit/ui-server-clock.test.ts b/tests/unit/ui-server-clock.test.ts index 16c3b3f..48c5e70 100644 --- a/tests/unit/ui-server-clock.test.ts +++ b/tests/unit/ui-server-clock.test.ts @@ -2,6 +2,7 @@ import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; import { get } from 'svelte/store'; import { freshServer, matchesFleet, type FleetServer } from '../../src/lib/fleet-overview.js'; import type { ServerStatus } from '../../src/lib/ui/stores/servers.js'; +import type { GameEvent, ServerTiming } from '../../src/lib/telemetry.js'; import { gameEvent } from '../helpers/telemetry.js'; vi.mock('$app/environment', () => ({ browser: true })); @@ -66,6 +67,46 @@ async function setup() { } describe('Fleet report clock', () => { + it('keeps persisted occupancy and match anchors through live reports before the next status poll', async () => { + const at = (seconds: number) => new Date(epoch + seconds * 1000).toISOString(); + snapshot.servers = [server(epoch, { container_state: 'running', container_checked_at: at(0) })]; + const { fleetServers } = await setup(); + const report = (event: GameEvent['event'], seconds: number, players: number, timing: ServerTiming) => { + source.dispatchEvent(new MessageEvent('server-telemetry', { data: JSON.stringify({ serverNow: epoch + seconds * 1000, + entries: [{ ...gameEvent(event, 2, players), receivedAt: at(seconds), + timing: { matchId: 1, players: {}, server: timing } }] }) })); + return get(fleetServers)[0]; + }; + const active = { activeSince: at(1), inactiveSince: null, gameStartedAt: at(1), gameEndedAt: null }; + report('game_start', 1, 1, active); + expect(report('heartbeat', 20, 1, active)).toMatchObject({ + active_since: at(1), inactive_since: null, game_started_at: at(1), game_ended_at: null + }); + const ended = { ...active, gameEndedAt: at(30) }; + report('game_end', 30, 1, ended); + expect(report('heartbeat', 31, 1, ended).game_ended_at).toBe(at(30)); + const nextMatch = { ...active, gameStartedAt: at(32) }; + report('game_start', 32, 1, nextMatch); + expect(report('heartbeat', 33, 1, nextMatch)).toMatchObject({ + active_since: at(1), game_started_at: at(32), game_ended_at: null + }); + expect(report('heartbeat', 34, 0, { activeSince: null, inactiveSince: at(34), gameStartedAt: null, gameEndedAt: null })) + .toMatchObject({ active_since: null, inactive_since: at(34), game_started_at: null, game_ended_at: null }); + expect(report('heartbeat', 35, 1, { activeSince: at(35), inactiveSince: null, gameStartedAt: null, gameEndedAt: null })) + .toMatchObject({ active_since: at(35), inactive_since: null, game_started_at: null, game_ended_at: null }); + }); + + it('restores timers from a telemetry snapshot even when the browser missed game_start', async () => { + const startedAt = new Date(epoch - 19_000).toISOString(); + snapshot.servers = [server(epoch, { container_state: 'running', container_checked_at: new Date(epoch).toISOString() })]; + const { fleetServers } = await setup(); + source.dispatchEvent(new MessageEvent('server-telemetry', { data: JSON.stringify({ serverNow: epoch, snapshot: true, + entries: [{ ...gameEvent('heartbeat', 2, 1), receivedAt: new Date(epoch).toISOString(), + timing: { matchId: 1, players: {}, server: { activeSince: startedAt, inactiveSince: null, + gameStartedAt: startedAt, gameEndedAt: null } } }] }) })); + expect(get(fleetServers)[0]).toMatchObject({ active_since: startedAt, game_started_at: startedAt }); + }); + it('updates count and roster immediately from telemetry and expires them together', async () => { snapshot.servers = [server(epoch, { container_state: 'running', container_checked_at: new Date(epoch).toISOString(), last_players: 4 })]; const { fleetServers, uiNow } = await setup();