import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; import { appendFile, mkdir, rm, utimes, writeFile } from 'node:fs/promises'; import { join } from 'node:path'; import { newFixture, type Fixture } from '../helpers/fixture.js'; import { gameEvent } from '../helpers/telemetry.js'; import type { GameEvent } from '../../src/lib/telemetry.js'; import type { ContextualChatEntry } from '../../src/lib/game-chat.js'; type ChatMessageEntry = Extract; const SERVER = 't5_zombie_theater_1'; const T6_SERVER = 't6_zombie_town_1'; let fixture: Fixture; let baseline: number; const at = (seconds: number) => new Date(baseline + seconds * 1000).toISOString(); beforeEach(async () => { vi.resetModules(); vi.useFakeTimers({ toFake: ['Date'] }); baseline = Math.floor(Date.now() / 1000) * 1000 - 600_000; fixture = await newFixture([SERVER, T6_SERVER]); const { seedServerRegistry } = await import('../../src/lib/server/fleet/servers.js'); const { db } = await import('../../src/lib/server/db/index.js'); await seedServerRegistry(); db().prepare('UPDATE servers SET created_at = ?').run(at(-120)); }); afterEach(async () => { vi.restoreAllMocks(); vi.useRealTimers(); await fixture.cleanup(); }); async function log(lines: string[], lastWrite = 60, server = SERVER, filename?: string) { const folder = join(server.startsWith('t6_') ? fixture.t6 : fixture.t5, server, 'logs'); await mkdir(folder, { recursive: true }); const path = join( folder, filename ?? (server.startsWith('t6_') ? 'games_zm.log' : 'games_sp.log') ); await writeFile(path, lines.join('\n') + '\n'); await utimes(path, new Date(at(lastWrite)), new Date(at(lastWrite))); } async function report( event: GameEvent['event'], seconds: number, round = 1, status = 200, diagnostic = true ) { const value = gameEvent(event, round, 1, SERVER); if (status === 200) { const { saveTelemetry } = await import('../../src/lib/server/fleet/telemetry.js'); saveTelemetry({ ...value, receivedAt: at(seconds) }); } if (diagnostic) { const { recordTelemetryRequest } = await import('../../src/lib/server/fleet/telemetry-requests.js'); recordTelemetryRequest({ value, receivedAt: at(seconds), status, error: status === 200 ? null : 'Rejected request', contentType: 'application/json' }); } } async function get(server = SERVER) { const { GET } = await import('../../src/routes/api/servers/[name]/chat/+server.js'); return GET({ params: { name: server } }); } function advanceTime(milliseconds = 15_000) { vi.setSystemTime(Date.now() + milliseconds); } describe('server chat API', () => { it('buffers partial UTF-8 lines and avoids context queries when the log is unchanged', async () => { await report('game_start', 0); await report('heartbeat', 40, 4); await log(['60:50 say;abc;0;Player;first'], 50); expect((await (await get()).json()).entries).toHaveLength(1); const { db } = await import('../../src/lib/server/db/index.js'); const prepare = vi.spyOn(db(), 'prepare'); advanceTime(); await get(); expect(prepare.mock.calls.some(([sql]) => sql.includes('FROM telemetry_requests'))).toBe( false ); expect( prepare.mock.calls.some(([sql]) => sql.includes('last_received_at AS lastReceivedAt')) ).toBe(false); prepare.mockRestore(); const path = join(fixture.t5, SERVER, 'logs/games_sp.log'); const line = Buffer.from('61:00 say;abc;0;Player;café\n'); await appendFile(path, line.subarray(0, -2)); // Split inside é, before the newline. await utimes(path, new Date(at(60)), new Date(at(60))); advanceTime(); expect((await (await get()).json()).entries).toHaveLength(1); await appendFile(path, line.subarray(-2)); await utimes(path, new Date(at(60)), new Date(at(60))); advanceTime(); const body = await (await get()).json(); expect(body.entries.map((entry: ChatMessageEntry) => entry.message.message)).toEqual([ 'first', 'café' ]); expect(body.entries[1].context.realTime).toBe(at(60)); expect((await (await get()).json()).entries).toEqual(body.entries); }); it('retries appended bytes if archiving fails before publishing the cursor', async () => { await report('game_start', 0); await report('heartbeat', 40, 4); await log(['60:50 say;abc;0;Player;first'], 50); await get(); const path = join(fixture.t5, SERVER, 'logs/games_sp.log'); await appendFile(path, '61:00 say;abc;0;Player;retry me\n'); await utimes(path, new Date(at(60)), new Date(at(60))); advanceTime(); const { db } = await import('../../src/lib/server/db/index.js'); const handle = db(), original = handle.prepare.bind(handle); const prepare = vi.spyOn(handle, 'prepare').mockImplementation((sql: string) => { if (sql.includes('INSERT INTO match_chat')) throw new Error('Temporary database failure'); return original(sql); }); vi.spyOn(console, 'error').mockImplementation(() => {}); expect((await get()).status).toBe(500); prepare.mockRestore(); advanceTime(); expect( (await (await get()).json()).entries.map( (entry: ChatMessageEntry) => entry.message.message ) ).toEqual(['first', 'retry me']); }); it('skips empty, stopped and offline servers and collects one last time after players leave', async () => { const { db } = await import('../../src/lib/server/db/index.js'); const { createHost } = await import('../../src/lib/server/hosts/index.js'); const logs = await import('../../src/lib/server/fleet/logs.js'); const read = vi.spyOn(logs, 'readLogChunk'); const { collectFleetChat } = await import('../../src/lib/server/fleet/chat.js'); db().prepare("UPDATE servers SET last_players=0,container_state='running'").run(); await collectFleetChat(); expect(read).not.toHaveBeenCalled(); db().prepare('UPDATE servers SET last_players=1 WHERE name=?').run(SERVER); await log(['60:50 say;abc;0;Player;playing'], 50); await collectFleetChat(); expect(read).toHaveBeenCalledTimes(1); db().prepare('UPDATE servers SET last_players=0 WHERE name=?').run(SERVER); await log(['60:50 say;abc;0;Player;playing', '61:00 say;abc;0;Player;goodbye']); expect((await (await get()).json()).entries).toHaveLength(1); expect(read).toHaveBeenCalledTimes(1); await collectFleetChat(); await collectFleetChat(); expect(read).toHaveBeenCalledTimes(2); expect((await (await get()).json()).entries).toHaveLength(2); expect(read).toHaveBeenCalledTimes(2); db() .prepare("UPDATE servers SET last_players=1,container_state='stopped' WHERE name=?") .run(SERVER); await collectFleetChat(); expect(read).toHaveBeenCalledTimes(2); const host = createHost({ name: 'Offline' }); db().prepare("UPDATE servers SET container_state='running' WHERE name=?").run(SERVER); db() .prepare( `INSERT INTO native_instances(id,server,host_id,library_id,image,port,created_at) VALUES('offline-instance',?,?,'library','image',28960,?)` ) .run(SERVER, host.id, at(0)); await collectFleetChat(); expect(read).toHaveBeenCalledTimes(2); }); it('keeps real timestamps and historical match context stable across refreshes', async () => { await report('game_start', 0); await report('round_change', 40, 4); await report('round_change', 45, 99, 400); await log(['60:50 say;abc;0;Player;hello', '61:00 J;abc;0;Player']); const response = await get(); const body = await response.json(); expect(response.status).toBe(200); expect(response.headers.get('cache-control')).toBe('no-store'); expect(body).toMatchObject({ ok: true, missing: false, entries: [ { type: 'message', message: { player: 'Player', message: 'hello' }, context: { realTime: at(50), matchElapsedMs: 50_000, round: 4 } } ] }); expect(JSON.stringify(body)).not.toContain('headshots'); vi.spyOn(Date, 'now').mockReturnValue(baseline + 900_000); expect(await (await get()).json()).toEqual(body); }); it('reads the correct game log for each game', async () => { await log(['1:00 say;abc;0;T5 player;t5 message']); await log(['1:00 say;abc;0;Wrong;wrong t5 file'], 60, SERVER, 'games_zm.log'); await log(['1:00 say;abc;0;T6 player;t6 message'], 60, T6_SERVER); await log(['1:00 say;abc;0;Wrong;wrong t6 file'], 60, T6_SERVER, 'games_sp.log'); expect((await (await get()).json()).entries[0].message.message).toBe('t5 message'); expect((await (await get(T6_SERVER)).json()).entries[0].message.message).toBe('t6 message'); }); it('returns an empty successful response until the game log exists', async () => { expect(await (await get()).json()).toEqual({ ok: true, entries: [], missing: true }); }); it('rejects unknown and destroyed servers even when files remain', async () => { expect((await get('t5_zombie_theater_99')).status).toBe(404); await log(['1:00 say;abc;0;Player;hello']); const { db } = await import('../../src/lib/server/db/index.js'); db().prepare('UPDATE servers SET destroyed_at = ? WHERE name = ?').run(at(60), SERVER); expect((await get()).status).toBe(404); }); it('rejects registered names that escape the server directory', async () => { const { db } = await import('../../src/lib/server/db/index.js'); db().prepare('INSERT INTO servers (name) VALUES (?)').run('..'); expect((await get('..')).status).toBe(400); }); it('reports read failures without returning server filesystem paths', async () => { const logs = await import('../../src/lib/server/fleet/logs.js'); vi.spyOn(logs, 'readLogChunk').mockRejectedValue( new Error('read failed at /private/server/log') ); vi.spyOn(console, 'error').mockImplementation(() => {}); const response = await get(); expect(response.status).toBe(500); expect(await response.json()).toEqual({ ok: false, reason: 'Could not read server chat' }); }); it('keeps latest accepted gameplay available when diagnostic logging was unavailable', async () => { await report('game_start', 0, 1, 200, false); await report('heartbeat', 40, 1, 200, false); await log(['60:50 say;abc;0;Player;first round', '61:00 J;abc;0;Player']); const body = await (await get()).json(); expect(body.entries).toHaveLength(1); expect(body.entries[0].context).toEqual({ realTime: at(50), matchElapsedMs: 50_000, round: 1 }); }); it('does not reuse round diagnostics after their retention window', async () => { await report('game_start', 0); await report('heartbeat', 40, 4); await log(['60:50 say;abc;0;Player;older message', '61:00 J;abc;0;Player']); vi.spyOn(Date, 'now').mockReturnValue(baseline + 8 * 86_400_000); const body = await (await get()).json(); expect(body.entries[0].context).toEqual({ realTime: at(50), matchElapsedMs: 50_000, round: null }); }); it('does not associate retained messages with a deleted server incarnation', async () => { await report('game_start', 0); await report('heartbeat', 40, 8); const { db } = await import('../../src/lib/server/db/index.js'); db().prepare('DELETE FROM servers WHERE name = ?').run(SERVER); db() .prepare( `INSERT INTO servers (name, game, map, created_at) VALUES (?, 't5', 'zombie_theater', ?)` ) .run(SERVER, at(70)); await report('game_start', 80); await report('heartbeat', 90, 2); await log( ['60:50 say;abc;0;Player;previous server', '61:40 say;abc;0;Player;current server'], 100 ); const body = await (await get()).json(); const messages = body.entries.filter((entry: { type: string }) => entry.type === 'message'); expect(messages).toHaveLength(1); expect(messages[0].message.message).toBe('current server'); expect(messages[0].context).toEqual({ realTime: at(100), matchElapsedMs: 20_000, round: 2 }); }); it('clears at a new match before it writes to the log and keeps the old chat with its match', async () => { const logs = await import('../../src/lib/server/fleet/logs.js'); const read = vi.spyOn(logs, 'readLogChunk'); await report('game_start', 0); await report('round_change', 20, 4); await log(['60:30 say;abc;0;Player;old match'], 30); expect((await (await get()).json()).entries[0].message.message).toBe('old match'); await report('game_end', 60, 4); await report('game_start', 80); expect((await (await get()).json()).entries).toEqual([]); expect(read).toHaveBeenCalledTimes(1); await report('heartbeat', 90, 2); await log(['60:30 say;abc;0;Player;old match', '61:40 say;abc;0;Player;new match'], 100); advanceTime(); const body = await (await get()).json(); expect(body.entries.map((entry: ChatMessageEntry) => entry.message.message)).toEqual([ 'new match' ]); const { getMatchDetail } = await import('../../src/lib/server/fleet/match-history.js'); expect( getMatchDetail(1)!.chat.map( (entry) => entry.type === 'message' && entry.message.message ) ).toEqual(['old match']); }); it('clears on log boundaries and clock resets before the next telemetry report', async () => { for (const boundary of [ '61:00 InitGame:', '0:00 InitGame:', '0:00 J;abc;0;Player', 'InitGame:' ]) { await report('game_start', 0); await report('heartbeat', 20, 4); await log(['60:30 say;abc;0;Player;old match'], 30); advanceTime(); expect((await (await get()).json()).entries).toHaveLength(1); await log(['60:30 say;abc;0;Player;old match', boundary], 60); advanceTime(); expect((await (await get()).json()).entries, boundary).toEqual([]); } }); it('shows only the latest log session without telemetry', async () => { await log( [ '80:00 say;abc;0;Player;old match', '0:00 InitGame:', '0:30 say;abc;0;Player;new match' ], 60 ); const entries = (await (await get()).json()).entries; expect( entries .filter((entry: ContextualChatEntry) => entry.type === 'message') .map((entry: ChatMessageEntry) => entry.message.message) ).toEqual(['new match']); await log(['80:00 say;abc;0;Player;old match', '0:00 InitGame:'], 60); advanceTime(); expect( (await (await get()).json()).entries.some( (entry: ContextualChatEntry) => entry.type === 'message' ) ).toBe(false); }); it('collects without a viewer and retains repeated messages after log rotation, restart and server deletion', async () => { await report('game_start', 0); await report('heartbeat', 20, 4); const lines = ['60:30 say;abc;0;Player;hello', '60:30 say;abc;0;Player;hello']; await log(lines, 30); const { collectFleetChat } = await import('../../src/lib/server/fleet/chat.js'); await collectFleetChat(); await collectFleetChat(); await report('game_end', 60, 4); await log([...lines, '61:00 ExitLevel:'], 60); await collectFleetChat(); const { closeDb, db } = await import('../../src/lib/server/db/index.js'); const { getMatchDetail } = await import('../../src/lib/server/fleet/match-history.js'); const saved = getMatchDetail(1)!.chat; expect(saved).toHaveLength(2); expect(saved[0]).toMatchObject({ message: { message: 'hello' }, context: { realTime: at(30), round: 4 } }); await rm(join(fixture.t5, SERVER, 'logs'), { recursive: true }); closeDb(); expect((await (await get()).json()).entries).toEqual(saved); db().prepare('DELETE FROM servers WHERE name = ?').run(SERVER); expect(getMatchDetail(1)!.chat).toEqual(saved); // Match retention also removes its chat, with no orphaned history. db().prepare('DELETE FROM leaderboard_matches WHERE id = 1').run(); expect(db().prepare('SELECT * FROM match_chat').all()).toEqual([]); }); });