420 lines
19 KiB
TypeScript
420 lines
19 KiB
TypeScript
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<ContextualChatEntry, { type: 'message' }>;
|
|
|
|
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('checks idle servers once, skips stopped and offline servers and collects 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).toHaveBeenCalledTimes(2);
|
|
await collectFleetChat();
|
|
expect(read).toHaveBeenCalledTimes(2);
|
|
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(3);
|
|
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(3);
|
|
await collectFleetChat();
|
|
await collectFleetChat();
|
|
expect(read).toHaveBeenCalledTimes(4);
|
|
expect((await (await get()).json()).entries).toHaveLength(2);
|
|
expect(read).toHaveBeenCalledTimes(4);
|
|
db()
|
|
.prepare("UPDATE servers SET last_players=1,container_state='stopped' WHERE name=?")
|
|
.run(SERVER);
|
|
await collectFleetChat();
|
|
expect(read).toHaveBeenCalledTimes(4);
|
|
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(4);
|
|
});
|
|
|
|
it('archives surviving idle match logs with distinct stable public and team message identities', async () => {
|
|
await report('game_start', 0);
|
|
await report('heartbeat', 20, 4);
|
|
await report('game_end', 60, 4);
|
|
await log(['60:30 say;abc;0;Player;hello', '60:30 sayteam;abc;0;Player;hello'], 30);
|
|
const { db } = await import('../../src/lib/server/db/index.js');
|
|
db().prepare('UPDATE servers SET last_players=0').run();
|
|
const { collectFleetChat, matchChatTimeline } =
|
|
await import('../../src/lib/server/fleet/chat.js');
|
|
await collectFleetChat();
|
|
const saved = matchChatTimeline(1);
|
|
expect(saved).toHaveLength(2);
|
|
expect(saved[0]).toMatchObject({ message: { message: 'hello' } });
|
|
expect(saved[0].type === 'message' && saved[0].message.channel).toBeUndefined();
|
|
expect(saved[1]).toMatchObject({ message: { message: 'hello', channel: 'team' } });
|
|
expect(new Set(saved.map((entry) => entry.messageId)).size).toBe(2);
|
|
expect(saved.every((entry) => typeof entry.messageId === 'string')).toBe(true);
|
|
advanceTime();
|
|
await get();
|
|
await collectFleetChat();
|
|
expect(matchChatTimeline(1)).toEqual(saved);
|
|
});
|
|
|
|
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([]);
|
|
});
|
|
});
|