diff --git a/.github/workflows/node.js.yml b/.github/workflows/node.js.yml index 044de22..30e5aaa 100644 --- a/.github/workflows/node.js.yml +++ b/.github/workflows/node.js.yml @@ -117,3 +117,11 @@ jobs: - name: MCP end-to-end test timeout-minutes: 5 run: npm run test:mcp-e2e + + - name: Upload MCP end-to-end screenshots + if: failure() + uses: actions/upload-artifact@v4 + with: + name: mcp-e2e-screenshots-${{ matrix.os }} + path: e2e/mcp/screenshots + if-no-files-found: ignore diff --git a/e2e/mcp/run.mjs b/e2e/mcp/run.mjs index d305ea6..a76a040 100644 --- a/e2e/mcp/run.mjs +++ b/e2e/mcp/run.mjs @@ -5,8 +5,9 @@ * 2. a player joins in Chrome * 3. an MCP client starts `mavonengine mcp` over stdio, like an AI assistant would, and reads the server * and the player's tab: scene on both sides, renderer stats, the client's world, network, console - * output, a screenshot, and the player compared on server and client - * 4. a second tab opens the editor: both tabs are listed, and `auto` still picks the player's tab + * output, a screenshot, the player compared on server and client, and the packets and state sync of both sides + * 4. a second tab opens the editor: both tabs are listed, and `auto` still picks the player's tab. + * Its Network panel lists the server's packets, and the overlay draws the player's ghost and sync ring * * Needs Chrome, core and the CLI built and the template's dependencies installed. The docs tools are left out * (--no-docs): they read mavonengine.com, which CI shouldn't depend on. @@ -31,6 +32,76 @@ async function waitFor(page, fn, arg, timeout = 30000) { await page.waitForFunction(fn, arg, { timeout, polling: 200 }) } +/** + * What went wrong on a page besides thrown errors: console errors, requests that failed or were refused. + * A module of the editor that doesn't load shows up here and nowhere else + */ +function watchPage(page, name, problems) { + page.on('console', (message) => { + if (message.type() === 'error') + problems.push(`${name} console: ${message.text()}`) + }) + page.on('requestfailed', request => problems.push(`${name} request failed: ${request.url()} (${request.failure()?.errorText})`)) + page.on('response', (response) => { + if (response.status() >= 400) + problems.push(`${name} ${response.status()}: ${response.url()}`) + }) +} + +/** How long the editor's UI may take to load: it is built from source by the dev server, next to a game that renders in software */ +const EDITOR_UI_TIMEOUT = 120000 + +/** + * The editor exists as soon as `.` is pressed, its UI only once the dev server has built it and React has drawn it. + * Fails with what the page reported when that doesn't happen, instead of a bare timeout + */ +async function waitForEditorUi(page, errors, problems) { + const started = Date.now() + const tab = page.getByRole('tab', { name: 'Network' }) + + while (true) { + if (await tab.count() > 0) + break + if (errors.length) + throw new Error(`the editor's UI did not load:\n ${errors.join('\n ')}`) + if (Date.now() - started > EDITOR_UI_TIMEOUT) + throw new Error(`the editor's UI was not there after ${EDITOR_UI_TIMEOUT / 1000}s${problems.length ? `:\n ${problems.slice(-20).join('\n ')}` : ', and the page reported nothing'}`) + await delay(500) + } + + log(` the editor's UI took ${((Date.now() - started) / 1000).toFixed(1)}s to load`) + return tab +} + +/** Everything that helps to tell why a run failed, since CI can't be looked at afterwards */ +async function reportFailure(context, server, errors, problems) { + log('\n== failure details') + if (errors.length) + log(`page errors:\n ${errors.join('\n ')}`) + if (problems.length) + log(`page problems (last 30):\n ${problems.slice(-30).join('\n ')}`) + + for (const [index, page] of (context?.pages() ?? []).entries()) { + try { + const state = await page.evaluate(() => ({ + title: document.title, + editor: !!window.Game?.editor, + uiChildren: window.Game?.uiRoot?.childElementCount ?? null, + tabs: Array.from(document.querySelectorAll('[role=tab]'), tab => tab.textContent), + text: document.body.textContent.replace(/\s+/g, ' ').slice(0, 300), + })) + log(`page ${index}: ${JSON.stringify(state)}`) + await page.screenshot({ path: join(screenshots, `failure-page-${index}.png`), timeout: 15000 }) + } + catch (err) { + log(`page ${index}: could not be looked at: ${err.message.split('\n')[0]}`) + } + } + + if (server) + log(`server output (last 40 lines):\n${server.output().split('\n').slice(-40).join('\n')}`) +} + async function joinGame(page, name) { await page.goto(base) await page.locator('.name-input').fill(name) @@ -42,7 +113,9 @@ async function main() { let server let browser let mcp + let context const errors = [] + const problems = [] rmSync(screenshots, { recursive: true, force: true }) mkdirSync(screenshots, { recursive: true }) @@ -54,9 +127,10 @@ async function main() { log('\n== player') browser = await chromium.launch({ channel: 'chrome', headless: true, args: ['--use-gl=angle', '--use-angle=swiftshader', '--enable-unsafe-swiftshader'] }) - const context = await browser.newContext({ viewport: { width: 1200, height: 800 } }) + context = await browser.newContext({ viewport: { width: 1200, height: 800 } }) const player = await context.newPage() player.on('pageerror', error => errors.push(`player: ${error.message}`)) + watchPage(player, 'player', problems) await joinGame(player, 'Alice') log('\n== mcp') @@ -72,7 +146,7 @@ async function main() { const data = async (name, args) => JSON.parse((await call(name, args)).content[0].text) const { tools } = await mcp.listTools() - check(tools.length === 18 && tools.every(tool => tool.annotations?.readOnlyHint), 'it lists 18 read-only tools') + check(tools.length === 24 && tools.every(tool => tool.annotations?.readOnlyHint), 'it lists 24 read-only tools') const serverPlayers = await data('list_players') check(serverPlayers.length === 1 && serverPlayers[0].displayName === 'Alice', 'list_players shows Alice on the server') @@ -109,6 +183,44 @@ async function main() { check(compared.positionDelta.length < 1, `the client's player is where the server has it (${compared.positionDelta.length.toFixed(3)} apart)`) check(Math.abs(compared.server.position.z) + Math.abs(compared.server.position.x) > 0.1, 'after it moved') + log('\n== network') + const sent = await data('network_packets', { peer: playerId, type: 'sv_state', direction: 'out', limit: 5 }) + const ticks = sent.records.map(record => record.tick) + check(sent.records.length === 5 && ticks.every((tick, i) => i === 0 || tick === ticks[i - 1] + 1), `network_packets lists the states sent to the player, one per tick (${ticks.join(', ')})`) + check(sent.records.every(record => record.bytes > 0 && record.info.entities >= 1), 'with their size and entity count') + + const packet = await data('network_packet', { id: sent.records.at(-1).id }) + check(packet.payload.tick === ticks.at(-1) && packet.payload.entities.some(e => e.id === playerId) && typeof packet.payload.ack === 'number', 'network_packet shows the payload: tick, ack and the player') + + const moves = await data('network_packets', { peer: playerId, type: 'command', direction: 'in' }) + check(moves.records.length > 0 && moves.records.every(record => typeof record.sequenceId === 'number'), `and the server recorded the player's inputs (${moves.records.length})`) + check(packet.payload.ack === moves.records.at(-1).sequenceId, `the last state acknowledges the last input (${packet.payload.ack})`) + + const received = await data('client_packets', { type: 'sv_state', limit: 5 }) + check(received.records.length === 5 && received.records.every(record => record.direction === 'in' && record.tick > 0), 'client_packets lists the states the tab received') + const joined = await data('client_packets', { type: 'cl_init' }) + check(joined.records.length === 1 && joined.records[0].reliable === true, 'and the game\'s own reliable message, once') + const lastState = (await data('client_network')).network.lastState + check(lastState.tick > 0 && lastState.ack === packet.payload.ack && lastState.ageMs < 1000, `client_network tells the last state: tick ${lastState.tick}, ack ${lastState.ack}, ${lastState.ageMs}ms ago`) + + const sync = await data('network_sync') + check(sync.syncDistance === 200 && sync.players.length === 1 && sync.players[0].tracked.includes(playerId), 'network_sync shows what the player is sent') + check(sync.players[0].lastState.tick <= sync.tick && sync.entities.find(e => e.id === playerId).trackedBy === 1, 'and by how many players each entity is tracked') + + // The newest arrival and the newest handled input: their other halves are older, so well inside the window + const timeline = await data('network_timeline', { sinceMs: 10000, limit: 2000 }) + const arrived = timeline.entries.findLast(e => e.side === 'client' && e.type === 'sv_state') + const left = timeline.entries.find(e => e.side === 'server' && e.type === 'sv_state' && e.tick === arrived?.tick) + // Two clocks a millisecond apart can swap the two on localhost, so the order is not checked + const travelMs = arrived && left ? new Date(arrived.time) - new Date(left.time) : Number.NaN + check(Math.abs(travelMs) < 1000, `network_timeline shows a state on both sides (tick ${arrived?.tick}, ${travelMs}ms apart)`) + const handled = timeline.entries.findLast(e => e.side === 'server' && e.type === 'command') + const input = timeline.entries.find(e => e.side === 'client' && e.type === 'command' && e.sequenceId === handled?.sequenceId) + check(input && handled, `and an input on both sides (seq ${handled?.sequenceId}, ${handled && input && new Date(handled.time) - new Date(input.time)}ms apart)`) + const events = await data('network_timeline', { sinceMs: 60000, eventsOnly: true }) + check(events.entries.some(e => e.side === 'server' && e.type === 'sync_enter' && e.info.entities.includes(playerId)), 'and, events only, the player coming into its own sync range') + check(events.entries.some(e => e.side === 'client' && e.type === 'connect'), 'next to the tab\'s own connect') + await player.evaluate(() => console.error('e2e marker', { id: 1 })) const errorLogs = await data('client_logs', { level: 'error', contains: 'e2e marker' }) check(errorLogs.entries.length === 1 && errorLogs.entries[0].message === 'e2e marker {"id":1}', 'client_logs has the console error') @@ -129,6 +241,7 @@ async function main() { log('\n== editor') const editor = await context.newPage() editor.on('pageerror', error => errors.push(`editor: ${error.message}`)) + watchPage(editor, 'editor', problems) await editor.goto(base) await waitFor(editor, () => window.Game?.activeScene?.name === 'main') await editor.locator('canvas').click({ position: { x: 600, y: 400 }, force: true }) @@ -148,19 +261,42 @@ async function main() { const editorId = both.clients.find(c => c.editor).id check((await data('client_network', { clientId: editorId })).network.editorMode === true, 'and the editor tab by its id') + log('\n== editor network panel') + await (await waitForEditorUi(editor, errors, problems)).click() + await editor.getByText('sv_state').first().waitFor({ timeout: 10000 }) + check(await editor.getByText('Alice').count() === 1, 'the Network panel lists the server\'s packets and the players it syncs') + + await editor.getByLabel('Server ghosts').check() + await editor.getByLabel('Sync radius').check() + await waitFor(editor, () => window.Game.editor.networkOverlay.counts.ghosts > 0 && window.Game.editor.networkOverlay.counts.rings === 1, undefined, 10000) + const overlay = await editor.evaluate((id) => { + const { group, counts } = window.Game.editor.networkOverlay + const ghost = group.getObjectByName(`ServerGhost:${id}`) + const ring = group.getObjectByName(`SyncRing:${id}`) + return { counts, ghost: ghost && { x: ghost.position.x, z: ghost.position.z }, ringScale: ring?.scale.x } + }, playerId) + const onServer = (await data('get_entity', { id: playerId })).position + check(overlay.ghost && Math.hypot(overlay.ghost.x - onServer.x, overlay.ghost.z - onServer.z) < 0.5, 'the overlay draws the player\'s ghost where the server has it') + check(overlay.ringScale === 200, 'and a ring of the sync distance around it') + await editor.screenshot({ path: join(screenshots, 'editor-network.png') }) + await editor.close() - let left + let remaining for (let tries = 0; tries < 20; tries++) { - left = (await data('list_clients')).clients - if (left.length === 1) + remaining = (await data('list_clients')).clients + if (remaining.length === 1) break await delay(250) } - check(left.length === 1 && left[0].playerId === playerId, 'a closed tab leaves the list') + check(remaining.length === 1 && remaining[0].playerId === playerId, 'a closed tab leaves the list') check(errors.length === 0, `no page errors${errors.length ? `:\n ${errors.join('\n ')}` : ''}`) log('\nmcp end-to-end test passed') } + catch (err) { + await reportFailure(context, server, errors, problems).catch(() => {}) + throw err + } finally { await mcp?.close().catch(() => {}) await browser?.close() diff --git a/packages/cli/README.md b/packages/cli/README.md index 01bc736..1fae936 100644 --- a/packages/cli/README.md +++ b/packages/cli/README.md @@ -127,10 +127,12 @@ npx @mavonengine/cli dashboard --sim | `--transparent` | | Let a transparent terminal background show through. Text can be hard to read over a light wallpaper | | `--sim` | | Simulated data instead of a server | -Keys: `q` quits, `r` refreshes now, `o` opens the game the server serves in the browser, `1`–`4` switch between the Overview, Players, Logs and HTTP tabs. The mouse wheel scrolls the players table, the logs and the requests; scroll the logs back to the bottom, or the requests back to the top, to follow new ones again. +Keys: `q` quits, `r` refreshes now, `o` opens the game the server serves in the browser, `1`–`5` switch between the Overview, Players, Logs, HTTP and Network tabs. The mouse wheel scrolls the players table, the logs, the requests and the packets; scroll the logs back to the bottom, or the requests and packets back to the top, to follow new ones again. The HTTP tab lists every request the game server's HTTP server received, newest first: the client (static files or Vite in dev), your own `onHttp` routes, the geckos.io signaling requests and WebSocket upgrades such as Vite's HMR socket, each with status, duration, size and client address. Query strings are left out since they can hold tokens, and the dashboard's own polling is not recorded. The game traffic itself is WebRTC, not HTTP, so it shows on the Players tab instead; with a separate `socketPort` the signaling requests go to that port and don't show up either. +The Network tab shows the game socket while developing. State sync lists each player with the entities in its last state update, its last acknowledged input and the size and tick of that update (red when it fell behind the others), and counts the synced entities no player is in range of. By message breaks the traffic of the last 5 seconds down by message name and direction: packets per second, average size and bytes per second, the largest share first. Below, every packet and network event, newest first, with its client, size, tick, input sequence id and a few facts about its payload; `p` shows the pings, `e` only the events (`connect`, `disconnect`, `dropped`, `sync_enter`, `sync_leave`). Click a packet, or move through the list with the arrow keys (or `j` / `k`), to see its content next to the list: the payload as it went over the wire, scrolled with the mouse wheel. `esc`, or a second click on it, closes it. The server drops the payloads of old packets to bound its memory, so only recent ones can be opened. The packets are only fetched while the tab shows, and only a server that is not running in production records them, see the [network tools](#mavonengine-mcp). + ### Server access The metrics endpoint is configured on the game server: @@ -179,6 +181,8 @@ Game server tools: | `get_entity` | One entity with the state it sends to clients (dev only) | | `recent_logs` | Server log lines, filtered by level and text | | `recent_requests` | HTTP requests the server answered, filtered by path and status | +| `network_packets` / `network_packet` | Packets the server sent and received and its network events, per client: size, tick, input sequence id; and one packet with its payload (dev only) | +| `network_sync` | Who is sent what: each player's tracked entities and last state update, and by how many players each entity is tracked (dev only) | Client tools, for the game tabs open while Vite serves the client in dev: @@ -188,7 +192,9 @@ Client tools, for the game tabs open while Vite serves the client in dev: | `client_status` | Draw calls and triangles of one frame, GPU geometries / textures / programs, JS heap, canvas, camera | | `client_entities` / `client_entity` | The tab's world, in the same shape as the server's, with its local player marked | | `client_scene` | The scene loaded in the tab, and which objects the client built | -| `client_network` | Connection, ping, and inputs sent but not yet acknowledged by the server | +| `client_network` | Connection, ping, inputs sent but not yet acknowledged by the server, and the last state update: its server tick, ack and age | +| `client_packets` / `client_packet` | Packets the tab sent and received and its network events, and one packet with its payload | +| `network_timeline` | The server's records for one tab and the tab's own, merged by time | | `client_logs` | Console output, uncaught errors and unhandled rejections, filtered by level and text | | `client_screenshot` | What the tab renders, as an image (the WebGL canvas, without HTML UI) | | `client_trace` | Records a few seconds of the tab and analyses it: frame times, render CPU vs GPU, composer passes, ticks, WebGL work per frame, the bottleneck, and the worst hitches with their causes. Saves a flame chart trace file | @@ -213,6 +219,8 @@ The client tools go through the dev bridge of the Vite plugin in `@mavonengine/c `client_trace` patches the tab only while it records and puts everything back afterwards. It times every frame and composer pass, counts the WebGL calls on the context, keeps slow single calls (shader compiles, texture uploads, `readPixels` / `getError` stalls), long animation frames with the scripts that ran, and your own `performance.measure()` spans. GPU time per frame needs `EXT_disjoint_timer_query_webgl2` (Chrome and Edge on most GPUs; the three-perf panel pauses while tracing since it uses the same queries). JS call stacks come from the [JS Self-Profiling API](https://wicg.github.io/js-self-profiling/) in Chromium browsers: the Vite plugin serves dev pages with `Document-Policy: js-profiling` for it, so reload tabs opened before you updated. The trace file is [Chrome Trace Event](https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU) JSON with tracks for frames, passes, GPU time, ticks, JS samples and slow WebGL calls: open it in [Perfetto](https://ui.perfetto.dev), `chrome://tracing` or [speedscope](https://www.speedscope.app). Keep the tab in the foreground while it records, browsers throttle hidden tabs. +The network tools read what both sides record while developing: every message through the game socket, the engine's and your own, with its size, and events such as `connect`, `disconnect`, `dropped` (the transport dropped a message), `sync_enter` / `sync_leave` (entities coming into or leaving a player's sync distance) and, on a client, `state_gap` (state updates that never arrived) and `state_out_of_order`. Each side keeps its last 2000 records, and 8 MB of their payloads. The server records when `NODE_ENV` is not `production` and serves them on `GET /api/game/dev/net/packets`, `/packets/:id` and `/sync`; a tab records while the dev bridge or the editor runs. Nothing is recorded, and the socket is left untouched, in a production build. `network_timeline` orders the two sides by their own clocks, which line up on one machine. + To let `compare_entity` match your own player with the server's, set `game.localPlayer` to the entity the tab controls, or give it `isLocalPlayer = true`: the server keys players by socket id, which the client often doesn't. ## Writing a plugin diff --git a/packages/cli/src/commands/dashboard.ts b/packages/cli/src/commands/dashboard.ts index 2439db5..d803407 100644 --- a/packages/cli/src/commands/dashboard.ts +++ b/packages/cli/src/commands/dashboard.ts @@ -6,7 +6,7 @@ import { openBrowser, servesPage } from '../browser' import MetricsClient, { httpSource } from '../dashboard/MetricsClient' import { simulatedSource } from '../dashboard/simulator' import { readableTheme } from '../dashboard/theme' -import { handlePlayersKey, renderDashboard, tabForKey } from '../dashboard/view' +import { handleNetworkKey, handlePlayersKey, initialViewState, renderDashboard, showsNetwork, tabForKey } from '../dashboard/view' export const DASHBOARD_HELP = `Usage: mavonengine dashboard [options] @@ -107,15 +107,29 @@ export async function runDashboard(options: DashboardOptions, signal?: AbortSign intervalMs: options.intervalMs, startupIntervalMs: options.startup ? STARTUP_POLL_MS : undefined, }) - const view: ViewState = { tab: 0, playerOffset: 0, logFromEnd: 0, requestTopId: null, selectedPlayerId: null, followSelectedPlayer: true } + const view: ViewState = initialViewState() const app = await createApp({ fps: 15, theme: readableTheme(options.theme), paintBackground: !options.transparent }) - app.render(({ ui, theme }) => renderDashboard(ui, theme, client.state, view, { - transparent: options.transparent, - startup: options.startup?.(), - openKey: !!options.clientUrl, - })) + app.render(({ ui, theme }) => { + renderDashboard(ui, theme, client.state, view, { + transparent: options.transparent, + startup: options.startup?.(), + openKey: !!options.clientUrl, + }) + + // The tab changes by key or by mouse, so what was drawn decides. Packets are only fetched for the Network tab + const watch = showsNetwork(view) + if (watch && !client.watchNetwork) { + client.watchNetwork = true + void client.refresh() + } + client.watchNetwork = watch + + // A click or a key picked another packet: load its content + if ((client.state.packetDetail?.id ?? null) !== view.selectedPacketId) + void client.inspectPacket(view.selectedPacketId) + }) client.onChange(() => app.invalidate()) @@ -144,7 +158,7 @@ export async function runDashboard(options: DashboardOptions, signal?: AbortSign app.invalidate() } - if (handlePlayersKey(view, client.state.snapshot, event.key)) + if (handlePlayersKey(view, client.state.snapshot, event.key) || handleNetworkKey(view, event.key, client.state.packets)) app.invalidate() }) diff --git a/packages/cli/src/dashboard/MetricsClient.ts b/packages/cli/src/dashboard/MetricsClient.ts index 6762e39..2d76385 100644 --- a/packages/cli/src/dashboard/MetricsClient.ts +++ b/packages/cli/src/dashboard/MetricsClient.ts @@ -1,5 +1,5 @@ -import type { LogLine, RequestLine, ServerMetricsSnapshot } from './snapshot' -import { normalizeLogs, normalizeRequests, normalizeSnapshot } from './snapshot' +import type { LogLine, PacketDetail, PacketLine, RequestLine, ServerMetricsSnapshot, SyncInfo } from './snapshot' +import { normalizeLogs, normalizePacketDetail, normalizePackets, normalizeRequests, normalizeSnapshot, normalizeSync } from './snapshot' export type ConnectionStatus = 'connecting' | 'live' | 'unreachable' | 'unauthorized' | 'forbidden' | 'disabled' @@ -21,6 +21,14 @@ export interface DashboardState { requests: RequestLine[] /** false once the server turned out not to record requests, null until known */ requestsAvailable: boolean | null + /** Recent packets and network events of the game socket, oldest first. Only followed while `watchNetwork` is on */ + packets: PacketLine[] + /** false once the server turned out not to serve them (production, or an older server), null until known */ + packetsAvailable: boolean | null + /** Who is sent what, null until known or when the server doesn't tell */ + sync: SyncInfo | null + /** The packet opened with `inspectPacket()`, null when none is */ + packetDetail: PacketDetail | null } /** Log lines kept in memory by the dashboard */ @@ -29,6 +37,9 @@ export const MAX_LOG_LINES = 1000 /** HTTP requests kept in memory by the dashboard */ export const MAX_REQUEST_LINES = 1000 +/** Packets kept in memory by the dashboard: as many as the server keeps, a few seconds of a busy server */ +export const MAX_PACKET_LINES = 2000 + export class MetricsSourceError extends Error { constructor(message: string, readonly status: ConnectionStatus) { super(message) @@ -44,6 +55,12 @@ export interface MetricsSource { fetch(): Promise fetchLogs?(afterId: number): Promise fetchRequests?(afterId: number): Promise + /** Packets and network events of the game socket newer than `afterId` */ + fetchPackets?(afterId: number): Promise + /** The server's state sync */ + fetchSync?(): Promise + /** One packet with its payload */ + fetchPacket?(id: number): Promise } export interface HttpSourceOptions { @@ -57,6 +74,10 @@ export function httpSource({ url, token, timeoutMs = 3000, fetch = globalThis.fe // Logs live next to metrics: .../api/game/metrics -> .../api/game/logs const logsUrl = new URL('logs', url) const requestsUrl = new URL('requests', url) + // Dev only: .../api/game/dev/net/* + const packetsUrl = new URL('dev/net/packets', url) + packetsUrl.searchParams.set('limit', String(MAX_PACKET_LINES)) + const syncUrl = new URL('dev/net/sync', url) async function request(target: string) { let res: Response @@ -94,6 +115,12 @@ export function httpSource({ url, token, timeoutMs = 3000, fetch = globalThis.fe requestsUrl.searchParams.set('after', String(afterId)) return request(requestsUrl.toString()) }, + fetchPackets: (afterId) => { + packetsUrl.searchParams.set('after', String(afterId)) + return request(packetsUrl.toString()) + }, + fetchSync: () => request(syncUrl.toString()), + fetchPacket: id => request(new URL(`dev/net/packets/${id}`, url).toString()), } } @@ -167,6 +194,14 @@ export default class MetricsClient { private listeners = new Set<(state: DashboardState) => void>() private logs: Feed private requests: Feed + private packets: Feed + private syncAvailable: boolean + + /** + * Follow the packets and the state sync too. Off by default: it is a lot of data on a busy server, + * so the dashboard only turns it on while its Network tab is shown. + */ + watchNetwork = false constructor(private source: MetricsSource, { intervalMs = 1000, maxBackoffMs = 10000, startupIntervalMs }: MetricsClientOptions = {}) { this.intervalMs = intervalMs @@ -174,6 +209,8 @@ export default class MetricsClient { this.startupIntervalMs = startupIntervalMs this.logs = new Feed(source.fetchLogs?.bind(source), normalizeLogs, MAX_LOG_LINES) this.requests = new Feed(source.fetchRequests?.bind(source), normalizeRequests, MAX_REQUEST_LINES) + this.packets = new Feed(source.fetchPackets?.bind(source), normalizePackets, MAX_PACKET_LINES) + this.syncAvailable = !!source.fetchSync this.state = { status: 'connecting', source: source.label, @@ -185,7 +222,50 @@ export default class MetricsClient { logsAvailable: this.logs.available, requests: [], requestsAvailable: this.requests.available, + packets: [], + packetsAvailable: this.packets.available, + sync: null, + packetDetail: null, + } + } + + /** + * Load the content of one packet into `state.packetDetail`, or close it with null. + */ + async inspectPacket(id: number | null) { + if (id === null) { + this.state.packetDetail = null + this.notify() + return + } + + if (!this.source.fetchPacket) { + this.state.packetDetail = { id, status: 'error', lines: [], error: 'This source does not serve packet contents' } + this.notify() + return + } + + this.state.packetDetail = { id, status: 'loading', lines: [] } + this.notify() + + let detail: PacketDetail + try { + detail = normalizePacketDetail(id, await this.source.fetchPacket(id)) + } + catch (err) { + detail = { id, status: 'error', lines: [], error: (err as Error).message } } + + // Another packet was opened, or this one closed, while it loaded + if (this.state.packetDetail?.id !== id) + return + + this.state.packetDetail = detail + this.notify() + } + + private notify() { + this.listeners.forEach(listener => listener(this.state)) } onChange(listener: (state: DashboardState) => void) { @@ -238,6 +318,12 @@ export default class MetricsClient { this.state.logsAvailable = this.logs.available this.state.requests = this.requests.entries this.state.requestsAvailable = this.requests.available + + if (this.watchNetwork) { + await Promise.all([this.packets.poll(), this.pollSync()]) + this.state.packets = this.packets.entries + this.state.packetsAvailable = this.packets.available + } } catch (err) { this.state.status = err instanceof MetricsSourceError ? err.status : 'unreachable' @@ -245,7 +331,23 @@ export default class MetricsClient { this.state.failures++ } - this.listeners.forEach(listener => listener(this.state)) + this.notify() + } + + private async pollSync() { + if (!this.syncAvailable) + return + + try { + this.state.sync = normalizeSync(await this.source.fetchSync!()) + } + catch (err) { + // Not served (production, or an older server): stop asking. Anything else is transient + if (err instanceof MetricsSourceError && err.status === 'disabled') { + this.syncAvailable = false + this.state.sync = null + } + } } /** diff --git a/packages/cli/src/dashboard/simulator.ts b/packages/cli/src/dashboard/simulator.ts index 6245896..5ea3666 100644 --- a/packages/cli/src/dashboard/simulator.ts +++ b/packages/cli/src/dashboard/simulator.ts @@ -2,6 +2,10 @@ import type { MetricsSource } from './MetricsClient' import type { LogLine, RequestLine, ServerMetricsSnapshot } from './snapshot' const HISTORY_LENGTH = 60 +/** As many as a real server keeps */ +const PACKET_LIMIT = 2000 +/** State updates per player and second in the simulation: fewer than the tick rate, so the list stays readable */ +const STATES_PER_SECOND = 5 /** * Small deterministic PRNG so --sim output is the same every run. @@ -50,6 +54,17 @@ export function simulatedSource(seed = 1, sampleIntervalMs = 1000): MetricsSourc requests.push({ id: requests.length + 1, timestamp: now, method, path, status, durationMs: Math.round((1 + random() * 20) * 100) / 100, bytes, address }) } + // The game socket's traffic, in the shape of GET /api/game/dev/net/packets + const packets: Record[] = [] + let packetId = 0 + let tick = 0 + let syncPlayers: Record[] = [] + const record = (entry: Record, offsetMs = 0) => { + packets.push({ id: ++packetId, timestamp: now + offsetMs, hasPayload: entry.kind === 'packet', ...entry }) + if (packets.length > PACKET_LIMIT) + packets.shift() + } + log('info', 'Starting @mavon/engine - Socket Server') log('info', 'Starting @mavon/engine - HTTP Server') @@ -93,15 +108,52 @@ export function simulatedSource(seed = 1, sampleIntervalMs = 1000): MetricsSourc request('GET', '/favicon.ico', 404, 160, address) request('POST', '/.wrtc/v2/connections', 200, 2900, address) request('POST', `/.wrtc/v2/connections/${players[i].id}/additional-candidates`, 200, 600, address) + record({ kind: 'event', type: 'connect', peer: players[i].id }) + record({ kind: 'packet', direction: 'in', type: 'cl_init', peer: players[i].id, bytes: 24, reliable: true }) + record({ kind: 'event', type: 'sync_enter', peer: players[i].id, tick, info: { count: players[i].trackedEntities } }) log('info', `Connected: ${players[i].id}`) log('info', `${i + 1} total players connected`) } for (let i = previousPlayers - 1; i >= playerCount; i--) { + record({ kind: 'event', type: 'disconnect', peer: `sim-${(i + 1).toString().padStart(2, '0')}` }) log('info', `Disconnected sim-${(i + 1).toString().padStart(2, '0')}`) log('info', `${i} total players connected`) } previousPlayers = playerCount + // One second of traffic, spread over the sample + const lastStates = new Map() + for (let state = 0; state < STATES_PER_SECOND; state++) { + const offset = Math.round(state * sampleIntervalMs / STATES_PER_SECOND) - sampleIntervalMs + tick += tickRate / STATES_PER_SECOND + for (const player of players) { + const bytes = 180 + player.trackedEntities * 96 + Math.floor(random() * 40) + if (state % 2 === 0) + record({ kind: 'packet', direction: 'in', type: 'command', peer: player.id, bytes: 58, sequenceId: player.lastProcessedSequenceId, info: { command: 'cl_move' } }, offset) + record({ kind: 'packet', direction: 'out', type: 'sv_state', peer: player.id, bytes, tick, info: { entities: player.trackedEntities, ack: player.lastProcessedSequenceId } }, offset + 2) + lastStates.set(player.id, { tick, bytes, entities: player.trackedEntities }) + } + } + for (const player of players) { + record({ kind: 'packet', direction: 'in', type: 'ping', peer: player.id, bytes: 0 }) + record({ kind: 'packet', direction: 'out', type: 'pong', peer: player.id, bytes: 0 }) + } + if (step % 9 === 0) + record({ kind: 'event', type: 'sync_leave', peer: players[0].id, tick, info: { count: 2, entities: ['rock-12', 'rock-40'] } }) + if (step % 13 === 0) + record({ kind: 'event', type: 'dropped', peer: players.at(-1)!.id, info: { reason: 'DROPPED_FROM_BUFFERING', message: 'sv_state' } }) + if (step % 4 === 0) + record({ kind: 'packet', direction: 'out', type: 'sv_chat', peer: players[0].id, bytes: 74, reliable: true }) + + syncPlayers = players.map(player => ({ + id: player.id, + displayName: player.displayName, + position: player.position, + ack: player.lastProcessedSequenceId, + tracked: Array.from({ length: player.trackedEntities }, (_, i) => `entity-${i}`), + lastState: lastStates.get(player.id) ?? null, + })) + if (step % 10 === 0) request('GET', '/api/game/health', 200, 180, '198.51.100.7') if (step % 23 === 0) @@ -184,5 +236,48 @@ export function simulatedSource(seed = 1, sampleIntervalMs = 1000): MetricsSourc async fetchRequests(afterId) { return { entries: requests.filter(entry => entry.id > afterId), latestId: requests.length } }, + async fetchPackets(afterId) { + const records = packets.filter(entry => (entry.id as number) > afterId) + return { enabled: true, latestId: packetId, matched: records.length, records } + }, + async fetchPacket(id) { + const found = packets.find(entry => entry.id === id) + if (!found) + return { record: null } + if (found.kind === 'event' || !found.bytes) + return { record: found } + + const info = (found.info ?? {}) as { entities?: number, ack?: number } + const payload = found.type === 'sv_state' + ? { + type: 'sv_state', + sequenceId: 0, + tick: found.tick, + serverTime: found.timestamp, + ack: info.ack, + entities: Array.from({ length: info.entities ?? 0 }, (_, i) => ({ + id: i === 0 ? found.peer : `entity-${i}`, + $typeName: i === 0 ? 'player' : 'rock', + position: { x: i * 3, y: 0, z: -i * 2 }, + rotation: { x: 0, y: (i % 6) / 2, z: 0 }, + scale: { x: 1, y: 1, z: 1 }, + })), + } + : found.type === 'command' + ? { type: 'cl_move', sequenceId: found.sequenceId, keys: ['KeyW'], yaw: 1.57 } + : found.type === 'cl_init' + ? { name: `Player ${String(found.peer).slice(-2)}` } + : { playerId: found.peer, playerName: 'Player 1', message: 'hello' } + + return { record: { ...found, payload } } + }, + async fetchSync() { + const entities = [ + ...syncPlayers.map(player => ({ id: player.id, type: 'player', player: true, trackedBy: syncPlayers.length })), + // The last few are out of every player's range + ...Array.from({ length: 140 }, (_, i) => ({ id: `entity-${i}`, type: 'rock', player: false, trackedBy: i < 134 ? 1 + (i % syncPlayers.length) : 0 })), + ] + return { tick, serverTime: now, tickRate, syncDistance: 200, players: syncPlayers, editors: [], entities } + }, } } diff --git a/packages/cli/src/dashboard/snapshot.ts b/packages/cli/src/dashboard/snapshot.ts index 0bbfc57..881e8e5 100644 --- a/packages/cli/src/dashboard/snapshot.ts +++ b/packages/cli/src/dashboard/snapshot.ts @@ -6,6 +6,58 @@ export type { ServerMetricsSnapshot } export type LogLine = LogEntry export type RequestLine = RequestLogEntry +/** One packet or network event the server recorded (GET /api/game/dev/net/packets) */ +export interface PacketLine { + id: number + timestamp: number + kind: 'packet' | 'event' + /** Seen from the server: `out` was sent to the client, `in` came from it. Null for events */ + direction: 'in' | 'out' | null + /** Message name on the wire, or the event's name */ + type: string + /** Channel id of the client, which is its player id */ + peer: string | null + bytes: number + tick: number | null + sequenceId: number | null + reliable: boolean + /** Short facts about the payload, e.g. `{ entities: 12, ack: 40 }` */ + info: Record +} + +/** The content of one packet or event, for the details panel of the Network tab */ +export interface PacketDetail { + id: number + /** `gone`: the server no longer keeps the record or its payload. `empty`: it never had one, like a ping */ + status: 'loading' | 'loaded' | 'gone' | 'empty' | 'error' + /** The payload as indented JSON, one line each. For an event, its details */ + lines: string[] + error?: string +} + +/** The server's state sync (GET /api/game/dev/net/sync), without the per-entity list */ +export interface SyncInfo { + tick: number + tickRate: number + syncDistance: number | null + /** Entities the server syncs */ + entities: number + /** Synced entities no player is in range of, players themselves not counted */ + untracked: number + editors: number + players: SyncPlayerLine[] +} + +export interface SyncPlayerLine { + id: string + displayName: string + /** Entities in its last state update */ + tracked: number + /** Sequence id of its last input the server processed */ + ack: number + lastState: { tick: number, bytes: number, entities: number } | null +} + /** * The newest metrics schema this CLI understands. */ @@ -173,3 +225,79 @@ export function normalizeRequests(raw: unknown): { entries: RequestLine[], lates latestId: num(r.latestId, entries.at(-1)?.id ?? 0), } } + +/** + * Same as normalizeSnapshot, for a GET /api/game/dev/net/packets response. + */ +export function normalizePackets(raw: unknown): { entries: PacketLine[], latestId: number } { + const r = section(raw) + const entries = arr(r.records, (e): PacketLine => ({ + id: num(e.id), + timestamp: num(e.timestamp), + kind: e.kind === 'event' ? 'event' : 'packet', + direction: e.direction === 'in' || e.direction === 'out' ? e.direction : null, + type: str(e.type, '?'), + peer: strOrNull(e.peer), + bytes: num(e.bytes), + tick: numOrNull(e.tick), + sequenceId: numOrNull(e.sequenceId), + reliable: e.reliable === true, + info: section(e.info), + })) + + return { + entries, + latestId: num(r.latestId, entries.at(-1)?.id ?? 0), + } +} + +/** + * Same as normalizeSnapshot, for a GET /api/game/dev/net/sync response. + */ +export function normalizeSync(raw: unknown): SyncInfo { + const r = section(raw) + const players = arr(r.players, (p): SyncPlayerLine => { + const lastState = isRecord(p.lastState) ? p.lastState : null + return { + id: str(p.id), + displayName: str(p.displayName, str(p.id)), + tracked: Array.isArray(p.tracked) ? p.tracked.length : 0, + ack: num(p.ack), + lastState: lastState && { tick: num(lastState.tick), bytes: num(lastState.bytes), entities: num(lastState.entities) }, + } + }) + const entities = arr(r.entities, e => ({ player: e.player === true, trackedBy: num(e.trackedBy) })) + + return { + tick: num(r.tick), + tickRate: num(r.tickRate), + syncDistance: numOrNull(r.syncDistance), + entities: entities.length, + // Without players nothing is tracked, which says nothing about the entities + untracked: players.length ? entities.filter(e => !e.player && e.trackedBy === 0).length : 0, + editors: Array.isArray(r.editors) ? r.editors.length : 0, + players, + } +} + +/** + * A GET /api/game/dev/net/packets/:id response as the lines the details panel shows. + */ +export function normalizePacketDetail(id: number, raw: unknown): PacketDetail { + const record = section(raw).record + if (!isRecord(record)) + return { id, status: 'gone', lines: [] } + + const lines = (value: unknown) => JSON.stringify(value, null, 2).split('\n') + + if (record.payload !== undefined && record.payload !== null) + return { id, status: 'loaded', lines: lines(record.payload) } + // An event has no payload: what it says is in its info + if (record.kind === 'event' && isRecord(record.info)) + return { id, status: 'loaded', lines: lines(record.info) } + // It had a payload once, dropped since to bound the server's memory + if (record.kind !== 'event' && num(record.bytes) > 0) + return { id, status: 'gone', lines: [] } + + return { id, status: 'empty', lines: [] } +} diff --git a/packages/cli/src/dashboard/view.ts b/packages/cli/src/dashboard/view.ts index ed41439..bbf0a0f 100644 --- a/packages/cli/src/dashboard/view.ts +++ b/packages/cli/src/dashboard/view.ts @@ -1,6 +1,6 @@ import type { Color, Container, Span, Theme } from '@profullstack/hqtui' import type { ConnectionStatus, DashboardState } from './MetricsClient' -import type { LogLine, RequestLine, ServerMetricsSnapshot } from './snapshot' +import type { LogLine, PacketDetail, PacketLine, RequestLine, ServerMetricsSnapshot, SyncPlayerLine } from './snapshot' import { stripVTControlCharacters } from 'node:util' import { bootBanner } from '@mavonengine/core/Utils/BootBanner' import { DEFAULT_COLOR, hex } from '@profullstack/hqtui' @@ -23,6 +23,22 @@ export interface ViewState { logFromEnd: number /** Request at the top of the HTTP table while scrolled, null follows the newest */ requestTopId: number | null + /** Packet at the top of the Network table while scrolled, null follows the newest */ + packetTopId: number | null + /** Show ping / pong on the Network tab: one pair a second per client */ + showPings: boolean + /** Only show network events on the Network tab, not the packets */ + eventsOnly: boolean + /** Packet whose content shows in the details panel on the Network tab */ + selectedPacketId: number | null + /** Keep the selected packet on screen; off while the mouse wheel scrolls the table */ + followSelectedPacket: boolean + /** First line of the payload shown in the details panel */ + payloadOffset: number +} + +export function initialViewState(): ViewState { + return { tab: 0, playerOffset: 0, logFromEnd: 0, requestTopId: null, selectedPlayerId: null, followSelectedPlayer: true, packetTopId: null, showPings: false, eventsOnly: false, selectedPacketId: null, followSelectedPacket: true, payloadOffset: 0 } } export interface RenderOptions { @@ -50,7 +66,15 @@ export interface StartupInfo { type PlayerRow = ServerMetricsSnapshot['players'][number] -export const DASHBOARD_TABS = ['Overview', 'Players', 'Logs', 'HTTP'] as const +export const DASHBOARD_TABS = ['Overview', 'Players', 'Logs', 'HTTP', 'Network'] as const + +/** Whether the tab showing needs the packets and the state sync, which are only fetched for it */ +export function showsNetwork(view: ViewState): boolean { + return DASHBOARD_TABS[view.tab] === 'Network' +} + +/** How far back the "By message" table of the Network tab looks, in ms */ +export const MESSAGE_STATS_WINDOW_MS = 5000 const WIDE_LAYOUT = 100 const NEWLINE_RE = /\r?\n/ @@ -105,6 +129,109 @@ export function handlePlayersKey(view: ViewState, snapshot: ServerMetricsSnapsho return true } +/** Open a packet in the details panel of the Network tab, or close the panel with null */ +function selectPacket(view: ViewState, id: number | null) { + view.selectedPacketId = id + view.payloadOffset = 0 + view.followSelectedPacket = true +} + +/** + * Keys of the Network tab: `p` shows or hides pings, `e` switches to events only, arrow keys / j k open + * the next packet in the list (down is older, as listed) and escape closes it. + * Returns whether the key was used. + */ +export function handleNetworkKey(view: ViewState, key: string, packets: PacketLine[] = []): boolean { + if (!showsNetwork(view)) + return false + + if (key === 'escape') { + const had = view.selectedPacketId !== null + selectPacket(view, null) + return had + } + + const delta = key === 'down' || key === 'j' ? 1 : key === 'up' || key === 'k' ? -1 : 0 + if (delta !== 0) { + // Newest first, as the table lists them + const rows = visiblePackets(packets, view).reverse() + if (rows.length === 0) + return false + + const current = rows.findIndex(p => p.id === view.selectedPacketId) + const next = current === -1 + ? (delta > 0 ? 0 : rows.length - 1) + : Math.max(0, Math.min(rows.length - 1, current + delta)) + selectPacket(view, rows[next].id) + return true + } + + if (key === 'p') + view.showPings = !view.showPings + else if (key === 'e') + view.eventsOnly = !view.eventsOnly + else + return false + + // The rows changed, so the scroll anchor may no longer be among them + view.packetTopId = null + return true +} + +export interface MessageStat { + direction: 'in' | 'out' + type: string + /** Packets per second */ + rate: number + bytesPerSecond: number + avgBytes: number +} + +/** + * What the traffic is made of: packets per message name and direction over the last `windowMs` + * before the newest record, largest share of the bandwidth first. + */ +export function messageStats(packets: PacketLine[], windowMs = MESSAGE_STATS_WINDOW_MS): MessageStat[] { + const newest = packets.at(-1)?.timestamp + if (newest === undefined) + return [] + + const recent = packets.filter(p => p.kind === 'packet' && p.direction && p.timestamp > newest - windowMs) + // A server that just started has less than the window to show + const seconds = Math.max(1000, Math.min(windowMs, newest - (packets[0]?.timestamp ?? newest))) / 1000 + + const groups = new Map() + for (const packet of recent) { + const key = `${packet.direction} ${packet.type}` + const group = groups.get(key) ?? { direction: packet.direction!, type: packet.type, count: 0, bytes: 0 } + group.count++ + group.bytes += packet.bytes + groups.set(key, group) + } + + return Array.from(groups.values(), ({ direction, type, count, bytes }) => ({ direction, type, rate: count / seconds, bytesPerSecond: bytes / seconds, avgBytes: bytes / count })) + .sort((a, b) => b.bytesPerSecond - a.bytesPerSecond || b.rate - a.rate || a.type.localeCompare(b.type)) +} + +/** The facts of a packet or event in one line: tick, sequence id and what its `info` holds */ +export function describePacket(packet: PacketLine): string { + const parts: string[] = [] + if (packet.tick !== null) + parts.push(`tick ${packet.tick}`) + if (packet.sequenceId !== null) + parts.push(`seq ${packet.sequenceId}`) + if (packet.reliable) + parts.push('reliable') + + for (const [key, value] of Object.entries(packet.info)) { + if (value === undefined || value === null) + continue + parts.push(`${key} ${Array.isArray(value) ? value.join(', ') : typeof value === 'object' ? JSON.stringify(value) : String(value)}`) + } + + return parts.join(' · ') +} + function statusColor(status: ConnectionStatus, theme: Theme): Color { if (status === 'live') return theme.success @@ -156,6 +283,9 @@ export function renderDashboard(ui: Container, theme: Theme, state: DashboardSta else if (tab === 'HTTP') { requestsPanel(root, theme, state, view, transparent) } + else if (tab === 'Network') { + networkTab(root, theme, state, view, transparent) + } else { root.responsive({ [WIDE_LAYOUT]: c => wideLayout(c, theme, state, snapshot, view, transparent), @@ -175,6 +305,14 @@ export function renderDashboard(ui: Container, theme: Theme, state: DashboardSta ...(snapshot && DASHBOARD_TABS[view.tab] === 'Players' ? [{ key: '↑↓', label: 'Select player' }, ...(view.selectedPlayerId ? [{ key: 'esc', label: 'Close' }] : [])] : []), + ...(snapshot && showsNetwork(view) + ? [ + { key: 'p', label: view.showPings ? 'Hide pings' : 'Show pings' }, + { key: 'e', label: view.eventsOnly ? 'All records' : 'Events only' }, + { key: '↑↓', label: 'Open packet' }, + ...(view.selectedPacketId !== null ? [{ key: 'esc', label: 'Close' }] : []), + ] + : []), ], right: [starting ? { label: 'STARTING', color: statusColor('connecting', theme) } @@ -630,3 +768,250 @@ function requestsPanel(ui: Container, theme: Theme, state: DashboardState, view: }) }) } + +const NETWORK_UNAVAILABLE = 'Not available: the game server runs with NODE_ENV=production, where nothing is recorded, ' + + 'or it runs a @mavonengine/core release without GET /api/game/dev/net' + +/** Height of the packet details under the list on a narrow terminal, which leaves the list a few rows */ +const NARROW_PACKET_DETAILS_SIZE = 12 + +/** Height of the State sync and By message panels of the Network tab */ +const NETWORK_SUMMARY_SIZE = 10 + +/** + * The game socket: who is sent what, what the traffic is made of, and every packet and event, newest first + */ +function networkTab(ui: Container, theme: Theme, state: DashboardState, view: ViewState, transparent: boolean) { + if (state.packetsAvailable === false) { + ui.panel({ title: 'Network', size: '1fr' }, panel => panel.text(NETWORK_UNAVAILABLE, { wrap: true })) + return + } + + ui.responsive({ + [WIDE_LAYOUT]: c => c.row({ size: NETWORK_SUMMARY_SIZE }, (row) => { + syncPanel(row, theme, state, transparent) + messagesPanel(row, theme, state, transparent) + }), + 0: (c) => { + syncPanel(c, theme, state, transparent, NETWORK_SUMMARY_SIZE) + messagesPanel(c, theme, state, transparent, NETWORK_SUMMARY_SIZE) + }, + }) + + if (view.selectedPacketId === null) { + packetsPanel(ui, theme, state, view, transparent) + return + } + + ui.responsive({ + [WIDE_LAYOUT]: c => c.row({ size: '1fr' }, (row) => { + packetsPanel(row, theme, state, view, transparent) + packetDetails(row, theme, state, view, '40%') + }), + 0: (c) => { + packetsPanel(c, theme, state, view, transparent) + packetDetails(c, theme, state, view, NARROW_PACKET_DETAILS_SIZE) + }, + }) +} + +/** + * The content of the selected packet: its payload as it went over the wire, scrolled with the mouse wheel + */ +function packetDetails(ui: Container, theme: Theme, state: DashboardState, view: ViewState, size: number | string) { + const id = view.selectedPacketId! + const packet = state.packets.find(p => p.id === id) + // The details are loaded after the selection changed, so they can still be the previous packet's + const detail: PacketDetail | null = state.packetDetail?.id === id ? state.packetDetail : null + + const name = packet ? `${packet.type}${packet.direction ? ` ${packet.direction}` : ''}` : `#${id}` + const title = packet?.kind === 'packet' ? `${name} · ${formatBytes(packet.bytes)}` : name + + ui.panel({ title, size }, (panel) => { + if (packet) { + const facts = describePacket({ ...packet, info: {} }) + panel.text([ + { text: formatTimeMs(packet.timestamp), fg: theme.muted }, + ...(packet.peer ? [{ text: ` ${packet.peer}` }] : []), + ...(facts ? [{ text: ` ${facts}`, fg: theme.muted }] : []), + ], { size: 1 }) + } + + if (!detail || detail.status === 'loading') { + panel.label('Loading…') + return + } + if (detail.status === 'error') { + panel.text([{ text: detail.error ?? 'Could not load it', fg: theme.danger }], { wrap: true }) + return + } + if (detail.status === 'gone') { + panel.text('The server no longer keeps this payload: it keeps the last 2000 records and 8 MB of payloads.', { wrap: true }) + return + } + if (detail.status === 'empty') { + panel.label('No payload') + return + } + + const maxOffset = Math.max(0, detail.lines.length - 1) + view.payloadOffset = Math.min(view.payloadOffset, maxOffset) + + panel.list({ + items: detail.lines, + offset: view.payloadOffset, + bullet: '', + scrollbar: true, + size: '1fr', + onScroll: (delta) => { + view.payloadOffset = Math.max(0, Math.min(maxOffset, view.payloadOffset + delta * 3)) + ui.ctx.invalidate() + }, + }) + }) +} + +function syncPanel(ui: Container, theme: Theme, { sync }: DashboardState, transparent: boolean, size: number | string = '1fr') { + ui.panel({ title: sync ? `State sync (tick ${sync.tick})` : 'State sync', size }, (panel) => { + if (!sync) { + panel.label('Waiting for the server…') + return + } + + panel.text([ + { text: `${sync.entities}`, bold: true }, + { text: sync.entities === 1 ? ' synced entity' : ' synced entities', fg: theme.muted }, + ...(sync.untracked > 0 ? [{ text: `, ${sync.untracked} out of every player's range`, fg: theme.warning }] : []), + { text: ' distance ', fg: theme.muted }, + { text: sync.syncDistance === null ? 'unknown' : String(sync.syncDistance) }, + ...(sync.editors > 0 ? [{ text: ` ${sync.editors} editor${sync.editors === 1 ? '' : 's'}`, fg: theme.info }] : []), + ], { size: 1 }) + + if (sync.players.length === 0) { + panel.label('No players connected') + return + } + + // Behind the others means its state updates are not going out + const newest = Math.max(...sync.players.map(p => p.lastState?.tick ?? 0)) + + panel.table({ + rows: [...sync.players].sort((a, b) => a.id.localeCompare(b.id)), + scrollbar: true, + zebra: !transparent, + size: '1fr', + columns: [ + { key: 'displayName', title: 'Player' }, + { key: 'tracked', title: 'Tracked', width: 8, align: 'right' }, + { key: 'ack', title: 'Ack', width: 9, align: 'right' }, + { key: 'bytes', title: 'State', width: 10, align: 'right', render: p => p.lastState ? formatBytes(p.lastState.bytes) : '—' }, + { + key: 'tick', + title: 'Tick', + width: 9, + align: 'right', + color: p => !p.lastState || newest - p.lastState.tick > sync.tickRate ? theme.danger : undefined, + render: p => p.lastState ? String(p.lastState.tick) : 'none', + }, + ], + }) + }) +} + +function messagesPanel(ui: Container, theme: Theme, state: DashboardState, transparent: boolean, size: number | string = '1fr') { + const stats = messageStats(state.packets) + + ui.panel({ title: `By message (last ${MESSAGE_STATS_WINDOW_MS / 1000} s)`, size }, (panel) => { + if (stats.length === 0) { + panel.label(state.packetsAvailable === null ? 'Waiting for the server…' : 'No packets yet') + return + } + + panel.table({ + rows: stats, + scrollbar: true, + zebra: !transparent, + size: '1fr', + columns: [ + { key: 'direction', title: '', width: 3, color: s => s.direction === 'out' ? theme.graph[0] : theme.graph[1], render: s => s.direction === 'out' ? 'out' : 'in' }, + { key: 'type', title: 'Message' }, + { key: 'rate', title: 'Per s', width: 8, align: 'right', render: s => s.rate.toFixed(1) }, + { key: 'avgBytes', title: 'Avg size', width: 10, align: 'right', render: s => formatBytes(Math.round(s.avgBytes)) }, + { key: 'bytesPerSecond', title: 'Rate', width: 12, align: 'right', render: s => formatRate(Math.round(s.bytesPerSecond)) }, + ], + }) + }) +} + +function formatTimeMs(timestamp: number) { + return `${formatTime(timestamp)}.${(timestamp % 1000).toString().padStart(3, '0')}` +} + +/** The packets and events the Network table shows, oldest first */ +export function visiblePackets(packets: PacketLine[], view: Pick): PacketLine[] { + return packets.filter(p => + (!view.eventsOnly || p.kind === 'event') + && (view.showPings || (p.type !== 'ping' && p.type !== 'pong'))) +} + +function packetsPanel(ui: Container, theme: Theme, state: DashboardState, view: ViewState, transparent: boolean) { + // Newest first, like the HTTP requests + const rows = visiblePackets(state.packets, view).reverse() + const anchor = view.packetTopId === null ? 0 : rows.findIndex(r => r.id <= view.packetTopId!) + const offset = Math.max(0, anchor) + + const what = view.eventsOnly ? 'Events' : 'Packets and events' + const title = `${what} (${rows.length}${view.showPings || view.eventsOnly ? '' : ', pings hidden'})${offset > 0 ? ', scroll up to follow' : ''}` + + ui.panel({ title, size: '1fr' }, (panel) => { + if (rows.length === 0) { + panel.label(state.packetsAvailable === null ? 'Waiting for the server…' : view.eventsOnly ? 'No events yet' : 'No packets yet') + return + } + + // Index of the row drawn first, which the handlers of this frame count from + let top = offset + // A narrow terminal, or the details panel next to the table, keeps the details and cuts the client id short + const narrow = panel.width < WIDE_LAYOUT + const directionColor = (p: PacketLine) => p.kind === 'event' ? theme.warning : p.direction === 'out' ? theme.graph[0] : theme.graph[1] + + panel.table({ + rows, + offset, + scrollbar: true, + zebra: !transparent, + size: '1fr', + selected: rows.findIndex(p => p.id === view.selectedPacketId), + followSelection: view.selectedPacketId !== null && view.followSelectedPacket, + // Following the selection can move the window, so the anchor goes by the row that was really drawn first + onRow: (_row, index, y) => { + if (y === 1) { + top = index + view.packetTopId = index === 0 ? null : rows[index].id + } + }, + // A click opens the packet, a second one on it closes it again + onSelectRow: (visibleRow) => { + const row = rows[top + visibleRow] + if (!row) + return + selectPacket(view, row.id === view.selectedPacketId ? null : row.id) + ui.ctx.invalidate() + }, + onScroll: (delta) => { + const next = Math.max(0, Math.min(rows.length - 1, top + delta)) + view.packetTopId = next === 0 ? null : rows[next].id + view.followSelectedPacket = false + ui.ctx.invalidate() + }, + columns: [ + { key: 'time', title: 'Time', width: 12, color: theme.muted, render: p => formatTimeMs(p.timestamp) }, + { key: 'direction', title: '', width: 3, color: directionColor, render: p => p.kind === 'event' ? '•' : p.direction === 'out' ? 'out' : 'in' }, + { key: 'type', title: 'Message', width: narrow ? 12 : 18, color: p => p.kind === 'event' ? theme.warning : undefined }, + { key: 'peer', title: 'Client', width: narrow ? 8 : 26, color: theme.muted, render: p => p.peer ?? '—' }, + { key: 'bytes', title: 'Size', width: narrow ? 9 : 10, align: 'right', render: p => p.kind === 'packet' ? formatBytes(p.bytes) : '' }, + { key: 'info', title: 'Details', render: describePacket }, + ], + }) + }) +} diff --git a/packages/cli/src/mcp/GameServerClient.ts b/packages/cli/src/mcp/GameServerClient.ts index ddcdadb..7f5d2e7 100644 --- a/packages/cli/src/mcp/GameServerClient.ts +++ b/packages/cli/src/mcp/GameServerClient.ts @@ -21,7 +21,26 @@ export interface EntityQuery { export class GameServerError extends Error { } -export type ClientQuery = 'status' | 'entities' | 'entity' | 'scene' | 'network' | 'logs' | 'screenshot' | 'trace' +export type ClientQuery = 'status' | 'entities' | 'entity' | 'scene' | 'network' | 'packets' | 'packet' | 'logs' | 'screenshot' | 'trace' + +export interface PacketQuery { + after?: number + kind?: 'packet' | 'event' + direction?: 'in' | 'out' + /** Message or event name, several separated by commas */ + type?: string + /** Channel id of a client, which is its player id */ + peer?: string + limit?: number +} + +const NET_UNAVAILABLE = 'The network debug endpoints are not available: the game server runs with NODE_ENV=production ' + + '(they are never served there), or it uses a @mavonengine/core release without them' + +/** A packet query as query string params, without the unset fields */ +export function packetParams(query: PacketQuery): Record { + return Object.fromEntries(Object.entries(query).filter(([, value]) => value !== undefined && value !== '').map(([key, value]) => [key, String(value)])) +} const DEV_UNAVAILABLE = 'The dev endpoints are not available: the game server runs with NODE_ENV=production ' + '(they are never served there), or it uses a @mavonengine/core release without them' @@ -87,6 +106,21 @@ export default class GameServerClient { return this.get(`api/game/dev/entities/${encodeURIComponent(id)}`, {}, DEV_UNAVAILABLE) } + /** Packets and network events the server recorded, oldest first */ + packets(query: PacketQuery = {}) { + return this.get('api/game/dev/net/packets', packetParams(query), NET_UNAVAILABLE) + } + + /** One recorded packet with its payload */ + packet(id: number) { + return this.get(`api/game/dev/net/packets/${id}`, {}, NET_UNAVAILABLE) + } + + /** Who is sent which entities */ + sync() { + return this.get('api/game/dev/net/sync', {}, NET_UNAVAILABLE) + } + /** The game tabs open in a browser, through the dev bridge */ clients() { return this.bridge('__mavonengine/clients', {}) diff --git a/packages/cli/src/mcp/networkTools.ts b/packages/cli/src/mcp/networkTools.ts new file mode 100644 index 0000000..59ba30e --- /dev/null +++ b/packages/cli/src/mcp/networkTools.ts @@ -0,0 +1,155 @@ +import type { McpServer } from '@modelcontextprotocol/sdk/server/mcp.js' +import type GameServerClient from './GameServerClient' +import { z } from 'zod' +import { READ_ONLY, run } from './result' + +const clientId = z.string().optional().describe('Tab id from list_clients. Default: the only open tab, or the only one not running the editor') + +const packetFilters = { + kind: z.enum(['packet', 'event']).optional().describe('packet: messages on the wire. event: connect, disconnect, sync_enter, sync_leave, dropped, state_gap…'), + direction: z.enum(['in', 'out']).optional().describe('Seen from the side that recorded it: out was sent, in was received'), + type: z.string().optional().describe('Message or event name, e.g. sv_state or command. Several separated by commas'), + afterId: z.number().int().min(0).default(0), + limit: z.number().int().min(1).max(2000).default(50).describe('Newest records kept when more match'), +} + +interface NetRecord { id: number, timestamp: number, kind: string, type: string, direction?: string, peer?: string, [key: string]: unknown } + +function withTime({ timestamp, ...record }: T) { + return { ...record, time: new Date(timestamp).toISOString() } +} + +function listing(list: { enabled?: boolean, latestId: number, matched: number, records: NetRecord[] }) { + return { + latestId: list.latestId, + matched: list.matched, + records: list.records.map(withTime), + ...(list.enabled === false ? { note: 'Nothing is being recorded on this side' } : {}), + } +} + +/** + * Server and client records in one list by time. Both clocks are epoch ms, so in dev on one machine they line up; + * across machines the two sides are off by their clock difference. + */ +export function mergeTimeline(server: NetRecord[], client: NetRecord[]) { + return [ + ...server.map(record => ({ side: 'server' as const, ...record })), + ...client.map(record => ({ side: 'client' as const, ...record })), + ].sort((a, b) => a.timestamp - b.timestamp || (a.side === b.side ? a.id - b.id : a.side === 'server' ? -1 : 1)) +} + +export function registerNetworkTools(server: McpServer, client: GameServerClient) { + server.registerTool('network_packets', { + title: 'Packets on the server', + description: 'Packets the game server sent and received and its network events, oldest first: time, direction, message name, ' + + 'client (peer), size in bytes, server tick, input sequence id and a few facts about the payload (entity count, ack, command). ' + + 'The server keeps the last 2000. Pass the returned latestId as afterId to get only newer ones; network_packet shows a payload. ' + + 'Development only.', + inputSchema: { ...packetFilters, peer: z.string().optional().describe('Only one client: its player id (list_players, or playerId from list_clients)') }, + annotations: READ_ONLY, + }, ({ afterId, ...query }) => run(async () => listing(await client.packets({ ...query, after: afterId })))) + + server.registerTool('network_packet', { + title: 'One packet on the server', + description: 'One record from network_packets with its payload, as it was serialized for the wire. Payloads of old records are ' + + 'dropped to bound memory (hasPayload false). Development only.', + inputSchema: { id: z.number().int().min(1) }, + annotations: READ_ONLY, + }, ({ id }) => run(async () => { + const { record } = await client.packet(id) + if (!record) + throw new Error(`No record ${id}: it is older than the 2000 the server keeps, or was never recorded`) + return withTime(record) + })) + + server.registerTool('network_sync', { + title: 'State sync', + description: 'Who is sent what: the current server tick, the sync distance, each player with the entities in its last state update ' + + '(tracked), its last acknowledged input and the size of that update; and each synced entity with how many players track it ' + + '(trackedBy, 0 means no player is in range), whether it changed since it was last synced and the tick it was last sent in. ' + + 'For entities that do not show up or stop updating on a client. Development only.', + inputSchema: { + player: z.string().optional().describe('Only this player, and the entities with `tracked` telling whether it is sent them'), + includeEntities: z.boolean().default(true), + }, + annotations: READ_ONLY, + }, ({ player, includeEntities }) => run(async () => { + const sync = await client.sync() + const { entities = [], players = [], ...rest } = sync + + if (!player) + return includeEntities ? sync : { ...rest, players, entityCount: entities.length } + + const one = players.find((p: { id: string }) => p.id === player) + if (!one) + throw new Error(`No player "${player}". Players: ${players.map((p: { id: string }) => p.id).join(', ') || 'none'}`) + + const tracked = new Set(one.tracked) + return { + ...rest, + player: one, + ...(includeEntities + ? { entities: entities.map((entity: { id: string }) => ({ ...entity, tracked: tracked.has(entity.id) })) } + : { entityCount: entities.length }), + } + })) + + server.registerTool('client_packets', { + title: 'Packets on a client', + description: 'Packets a tab sent and received and its network events (connect, disconnect, state_gap for lost state updates, ' + + 'state_out_of_order), in the same shape as network_packets. Recorded since the tab loaded, the last 2000.', + inputSchema: { clientId, ...packetFilters }, + annotations: READ_ONLY, + }, ({ clientId, afterId, ...query }) => run(async () => listing(await client.client('packets', { ...query, after: afterId }, clientId)))) + + server.registerTool('client_packet', { + title: 'One packet on a client', + description: 'One record from client_packets with its payload.', + inputSchema: { id: z.number().int().min(1), clientId }, + annotations: READ_ONLY, + }, ({ id, clientId }) => run(async () => { + const { record } = await client.client('packet', { id }, clientId) + if (!record) + throw new Error(`No record ${id}: it is older than the 2000 the tab keeps, or was never recorded`) + return withTime(record) + })) + + server.registerTool('network_timeline', { + title: 'Network timeline of one client', + description: 'What happened between the server and one tab, in order of time: the server\'s records for that client and the ' + + 'tab\'s own, merged, each marked with its side. Shows a packet leaving one side and arriving on the other (or not), inputs ' + + 'against the state updates that acknowledge them, and events like sync_enter / sync_leave, dropped and state_gap. ' + + 'Needs the server in development too.', + inputSchema: { + clientId, + sinceMs: z.number().int().min(100).max(600000).default(5000).describe('How far back to look'), + includePings: z.boolean().default(false).describe('Keep ping / pong, one pair per second'), + eventsOnly: z.boolean().default(false).describe('Leave the packets out'), + limit: z.number().int().min(1).max(2000).default(200).describe('Newest entries kept when more match'), + }, + annotations: READ_ONLY, + }, ({ clientId, sinceMs, includePings, eventsOnly, limit }) => run(async () => { + const { network } = await client.client('network', {}, clientId) + if (!network?.playerId) + throw new Error('This tab is not connected to the game server, so the server has no records for it') + + const kind = eventsOnly ? 'event' as const : undefined + const [onServer, onClient] = await Promise.all([ + client.packets({ peer: network.playerId, kind, limit: 2000 }), + client.client('packets', { kind, limit: 2000 }, clientId), + ]) + + const from = Date.now() - sinceMs + const entries = mergeTimeline(onServer.records, onClient.records) + .filter(record => record.timestamp >= from && (includePings || (record.type !== 'ping' && record.type !== 'pong'))) + + return { + playerId: network.playerId, + pingMs: network.pingMs, + matched: entries.length, + entries: entries.slice(-limit).map(withTime), + note: 'Times are each side\'s own clock. On one machine they line up; otherwise shift one side by the clock difference', + } + })) +} diff --git a/packages/cli/src/mcp/server.ts b/packages/cli/src/mcp/server.ts index f6cf085..3d49a11 100644 --- a/packages/cli/src/mcp/server.ts +++ b/packages/cli/src/mcp/server.ts @@ -5,6 +5,7 @@ import { z } from 'zod' import { version } from '../../package.json' import { registerClientTools } from './clientTools' import { registerDocsTools } from './docs' +import { registerNetworkTools } from './networkTools' import { LOG_LEVELS, READ_ONLY, run, vec3 } from './result' const INSTRUCTIONS = `Reads the live state of a running MavonEngine game: the game server (health, performance, players, scene, @@ -13,6 +14,8 @@ network state, console logs, screenshots). Every tool is read-only. Server scene / entity tools need the server in development (NODE_ENV is not "production"); client tools need the client served by Vite in dev. Start with server_status and list_clients. Use type / near filters rather than paging through a world. compare_entity shows one entity on both sides, for prediction, interpolation and sync bugs. +network_packets / client_packets list the packets each side sent and received, network_timeline merges both sides for one +client, and network_sync tells which entities each player is sent: use them when something does not arrive or arrives late. client_trace records a few seconds of a tab for frame drops, stutter and slow rendering: the bottleneck, hitches with their causes, hot JS functions, WebGL load, and a trace file for flame charts. docs_list_pages / docs_get_page read the MavonEngine documentation: check it before guessing how an engine API works.` @@ -163,6 +166,7 @@ export function createMcpServer(client: GameServerClient, docs?: DocsClient): Mc })) registerClientTools(server, client) + registerNetworkTools(server, client) if (docs) registerDocsTools(server, docs) diff --git a/packages/cli/tests/MetricsClient.test.ts b/packages/cli/tests/MetricsClient.test.ts index d88c1b2..baeeb37 100644 --- a/packages/cli/tests/MetricsClient.test.ts +++ b/packages/cli/tests/MetricsClient.test.ts @@ -284,6 +284,136 @@ describe('metricsClient', () => { expect(client.state.status).toBe('live') }) + it('follows packets and the state sync only while the network is watched', async () => { + const packetCalls: number[] = [] + let syncCalls = 0 + const client = new MetricsClient({ + label: 'test', + fetch: async () => ({}), + fetchPackets: async (afterId: number) => { + packetCalls.push(afterId) + return { latestId: afterId + 1, records: [{ id: afterId + 1, timestamp: 1, kind: 'packet', direction: 'out', type: 'sv_state', peer: 'p1', bytes: 120, tick: 4, info: { entities: 2 } }] } + }, + fetchSync: async () => { + syncCalls++ + return { tick: 4, tickRate: 30, syncDistance: 100, editors: ['e1'], players: [{ id: 'p1', displayName: 'Ada', ack: 3, tracked: ['p1', 'rock'], lastState: { tick: 4, bytes: 120, entities: 2 } }], entities: [{ id: 'p1', player: true, trackedBy: 1 }, { id: 'rock', trackedBy: 1 }, { id: 'tree', trackedBy: 0 }] } + }, + }) + + await client.poll() + expect(packetCalls).toEqual([]) + expect(client.state).toMatchObject({ packets: [], packetsAvailable: null, sync: null }) + + client.watchNetwork = true + await client.poll() + await client.poll() + + expect(packetCalls).toEqual([0, 1]) + expect(syncCalls).toBe(2) + expect(client.state.packetsAvailable).toBe(true) + expect(client.state.packets).toEqual([ + { id: 1, timestamp: 1, kind: 'packet', direction: 'out', type: 'sv_state', peer: 'p1', bytes: 120, tick: 4, sequenceId: null, reliable: false, info: { entities: 2 } }, + expect.objectContaining({ id: 2 }), + ]) + expect(client.state.sync).toEqual({ + tick: 4, + tickRate: 30, + syncDistance: 100, + entities: 3, + untracked: 1, + editors: 1, + players: [{ id: 'p1', displayName: 'Ada', tracked: 2, ack: 3, lastState: { tick: 4, bytes: 120, entities: 2 } }], + }) + }) + + it('marks the network unavailable on a production or older server without failing the poll', async () => { + let syncCalls = 0 + const disabled = async () => { + syncCalls++ + throw new MetricsSourceError('not found', 'disabled') + } + const client = new MetricsClient({ label: 'test', fetch: async () => ({}), fetchPackets: disabled, fetchSync: disabled }) + client.watchNetwork = true + + await client.poll() + await client.poll() + + expect(client.state).toMatchObject({ status: 'live', packetsAvailable: false, sync: null }) + expect(syncCalls).toBe(2) + }) + + it('loads the content of a packet, and closes it again', async () => { + const records: Record = { + 1: { id: 1, kind: 'packet', bytes: 30, payload: { tick: 4, entities: [] } }, + 2: { id: 2, kind: 'event', info: { count: 1, entities: ['rock'] } }, + 3: { id: 3, kind: 'packet', bytes: 30 }, + 4: { id: 4, kind: 'packet', bytes: 0 }, + } + const client = new MetricsClient({ label: 'test', fetch: async () => ({}), fetchPacket: async id => ({ record: records[id] ?? null }) }) + const seen: (string | undefined)[] = [] + client.onChange(state => seen.push(state.packetDetail?.status)) + + await client.inspectPacket(1) + expect(seen).toEqual(['loading', 'loaded']) + expect(client.state.packetDetail).toEqual({ id: 1, status: 'loaded', lines: ['{', ' "tick": 4,', ' "entities": []', '}'] }) + + await client.inspectPacket(2) + expect(client.state.packetDetail!.lines.join('')).toContain('"rock"') + await client.inspectPacket(3) + expect(client.state.packetDetail).toMatchObject({ status: 'gone' }) + await client.inspectPacket(4) + expect(client.state.packetDetail).toMatchObject({ status: 'empty' }) + await client.inspectPacket(99) + expect(client.state.packetDetail).toMatchObject({ id: 99, status: 'gone' }) + + await client.inspectPacket(null) + expect(client.state.packetDetail).toBeNull() + }) + + it('keeps the packet that was opened last when an earlier one answers late', async () => { + const pending = new Map void>() + const client = new MetricsClient({ label: 'test', fetch: async () => ({}), fetchPacket: id => new Promise(resolve => pending.set(id, resolve)) }) + + const first = client.inspectPacket(1) + const second = client.inspectPacket(2) + pending.get(2)!({ record: { id: 2, payload: 'second' } }) + pending.get(1)!({ record: { id: 1, payload: 'first' } }) + await Promise.all([first, second]) + + expect(client.state.packetDetail).toEqual({ id: 2, status: 'loaded', lines: ['"second"'] }) + }) + + it('reports a packet that could not be loaded', async () => { + const failing = new MetricsClient({ label: 'test', fetch: async () => ({}), fetchPacket: async () => { + throw new MetricsSourceError('Can\'t reach the server', 'unreachable') + } }) + await failing.inspectPacket(1) + expect(failing.state.packetDetail).toEqual({ id: 1, status: 'error', lines: [], error: 'Can\'t reach the server' }) + + const without = new MetricsClient({ label: 'test', fetch: async () => ({}) }) + await without.inspectPacket(1) + expect(without.state.packetDetail).toMatchObject({ id: 1, status: 'error' }) + }) + + it('derives the network urls from the metrics url', async () => { + const urls: string[] = [] + const fetch = (async (url: string) => { + urls.push(url) + return Response.json({}) + }) as unknown as typeof globalThis.fetch + const source = httpSource({ url: 'http://localhost:8050/api/game/metrics', fetch }) + + await source.fetchPackets!(7) + await source.fetchSync!() + await source.fetchPacket!(12) + + expect(urls).toEqual([ + 'http://localhost:8050/api/game/dev/net/packets?limit=2000&after=7', + 'http://localhost:8050/api/game/dev/net/sync', + 'http://localhost:8050/api/game/dev/net/packets/12', + ]) + }) + it('derives the requests url from the metrics url', async () => { const fetch = vi.fn(async () => response(200, { entries: [], latestId: 0 })) const source = httpSource({ url: 'http://localhost:8050/api/game/metrics', fetch }) diff --git a/packages/cli/tests/mcp.test.ts b/packages/cli/tests/mcp.test.ts index 753f514..33504a5 100644 --- a/packages/cli/tests/mcp.test.ts +++ b/packages/cli/tests/mcp.test.ts @@ -8,6 +8,7 @@ import { parseMcpArgs } from '../src/commands/mcp' import { compareEntities } from '../src/mcp/clientTools' import { writeMcpConfig } from '../src/mcp/config' import GameServerClient from '../src/mcp/GameServerClient' +import { mergeTimeline } from '../src/mcp/networkTools' import { createMcpServer } from '../src/mcp/server' const metrics = { @@ -62,6 +63,8 @@ describe('mcp server', () => { 'client_entity', 'client_logs', 'client_network', + 'client_packet', + 'client_packets', 'client_scene', 'client_screenshot', 'client_status', @@ -72,6 +75,10 @@ describe('mcp server', () => { 'list_clients', 'list_entities', 'list_players', + 'network_packet', + 'network_packets', + 'network_sync', + 'network_timeline', 'recent_logs', 'recent_requests', 'server_metrics', @@ -300,6 +307,134 @@ describe('client tools', () => { }) }) +describe('network tools', () => { + const bridge = '/__mavonengine/clients' + const record = (id: number, timestamp: number, extra: Record = {}) => ({ id, timestamp, kind: 'packet', type: 'sv_state', hasPayload: true, ...extra }) + + it('lists the server\'s packets, passing the filters on', async () => { + const { call, calls } = await connect({ + '/api/game/dev/net/packets': { enabled: true, latestId: 9, matched: 1, records: [record(9, 0, { direction: 'out', peer: 'p1', bytes: 120, tick: 4 })] }, + }) + + const { data } = await call('network_packets', { peer: 'p1', direction: 'out', type: 'sv_state', afterId: 3, limit: 10 }) + + expect(Object.fromEntries(calls.at(-1)!.searchParams)).toEqual({ peer: 'p1', direction: 'out', type: 'sv_state', after: '3', limit: '10' }) + expect(data).toEqual({ + latestId: 9, + matched: 1, + records: [{ id: 9, kind: 'packet', type: 'sv_state', hasPayload: true, direction: 'out', peer: 'p1', bytes: 120, tick: 4, time: '1970-01-01T00:00:00.000Z' }], + }) + }) + + it('says when a side records nothing', async () => { + const { call } = await connect({ '/api/game/dev/net/packets': { enabled: false, latestId: 0, matched: 0, records: [] } }) + expect((await call('network_packets')).data.note).toContain('Nothing is being recorded') + }) + + it('shows one packet with its payload and explains a missing one', async () => { + const { call } = await connect({ + '/api/game/dev/net/packets/9': { record: { ...record(9, 0), payload: { tick: 4, entities: [] } } }, + '/api/game/dev/net/packets/1': { record: null }, + }) + + expect((await call('network_packet', { id: 9 })).data.payload).toEqual({ tick: 4, entities: [] }) + const missing = await call('network_packet', { id: 1 }) + expect(missing.isError).toBe(true) + expect(missing.text).toContain('No record 1') + }) + + it('explains that the network tools need a development server', async () => { + const { call } = await connect({}) + const result = await call('network_sync') + expect(result.isError).toBe(true) + expect(result.text).toContain('NODE_ENV=production') + }) + + it('reads the state sync, for everyone or as one player', async () => { + const sync = { + tick: 40, + syncDistance: 100, + players: [{ id: 'p1', tracked: ['p1', 'rock'] }, { id: 'p2', tracked: ['p2'] }], + editors: [], + entities: [{ id: 'p1' }, { id: 'p2' }, { id: 'rock' }], + } + const { call } = await connect({ '/api/game/dev/net/sync': sync }) + + expect((await call('network_sync')).data).toEqual(sync) + expect((await call('network_sync', { includeEntities: false })).data).toMatchObject({ tick: 40, entityCount: 3, players: sync.players }) + + const asPlayer = (await call('network_sync', { player: 'p2' })).data + expect(asPlayer.player).toEqual({ id: 'p2', tracked: ['p2'] }) + expect(asPlayer.entities).toEqual([{ id: 'p1', tracked: false }, { id: 'p2', tracked: true }, { id: 'rock', tracked: false }]) + + const unknown = await call('network_sync', { player: 'nope' }) + expect(unknown.isError).toBe(true) + expect(unknown.text).toContain('Players: p1, p2') + }) + + it('lists and shows a tab\'s packets', async () => { + const { call, calls } = await connect({ + [`${bridge}/auto/packets`]: { enabled: true, latestId: 2, matched: 1, records: [record(2, 0, { direction: 'in' })] }, + [`${bridge}/tab1/packet`]: { record: { ...record(2, 0), payload: { tick: 1 } } }, + }) + + expect((await call('client_packets', { kind: 'packet' })).data.records).toMatchObject([{ id: 2, direction: 'in' }]) + expect(Object.fromEntries(calls.at(-1)!.searchParams)).toEqual({ kind: 'packet', after: '0', limit: '50' }) + + expect((await call('client_packet', { id: 2, clientId: 'tab1' })).data.payload).toEqual({ tick: 1 }) + expect(calls.at(-1)!.searchParams.get('id')).toBe('2') + }) + + it('merges both sides of one client into a timeline', async () => { + const now = Date.now() + const { call, calls } = await connect({ + [`${bridge}/auto/network`]: { network: { playerId: 'p1', pingMs: 20 } }, + '/api/game/dev/net/packets': { + latestId: 4, + matched: 4, + records: [ + record(1, now - 60000, { direction: 'out' }), + record(2, now - 300, { direction: 'out', tick: 7 }), + record(3, now - 200, { type: 'pong', direction: 'out' }), + record(4, now - 100, { kind: 'event', type: 'sync_leave' }), + ], + }, + [`${bridge}/auto/packets`]: { + latestId: 2, + matched: 2, + records: [record(1, now - 280, { direction: 'in', tick: 7 }), record(2, now - 250, { type: 'command', direction: 'out', sequenceId: 3 })], + }, + }) + + const { data } = await call('network_timeline') + + expect(calls.find(url => url.pathname === '/api/game/dev/net/packets')!.searchParams.get('peer')).toBe('p1') + expect(data).toMatchObject({ playerId: 'p1', pingMs: 20, matched: 4 }) + expect(data.entries.map((e: any) => [e.side, e.type, e.direction])).toEqual([ + ['server', 'sv_state', 'out'], + ['client', 'sv_state', 'in'], + ['client', 'command', 'out'], + ['server', 'sync_leave', undefined], + ]) + + expect((await call('network_timeline', { includePings: true })).data.matched).toBe(5) + await call('network_timeline', { eventsOnly: true }) + expect(calls.at(-1)!.searchParams.get('kind')).toBe('event') + }) + + it('explains a tab that is not connected', async () => { + const { call } = await connect({ [`${bridge}/auto/network`]: { network: null } }) + const result = await call('network_timeline') + expect(result.isError).toBe(true) + expect(result.text).toContain('not connected') + }) + + it('orders records with the same time server first', () => { + const merged = mergeTimeline([record(5, 100), record(6, 100)], [record(1, 100), record(2, 50)]) + expect(merged.map(r => [r.side, r.id])).toEqual([['client', 2], ['server', 5], ['server', 6], ['client', 1]]) + }) +}) + describe('parseMcpArgs', () => { it('builds the server URL from host and port, or takes --url', () => { const fromPort = parseMcpArgs(['--port', '9000'], {}) diff --git a/packages/cli/tests/view.test.ts b/packages/cli/tests/view.test.ts index d477ec2..6242fa7 100644 --- a/packages/cli/tests/view.test.ts +++ b/packages/cli/tests/view.test.ts @@ -1,10 +1,11 @@ import type { DashboardState } from '../src/dashboard/MetricsClient' +import type { PacketDetail, PacketLine } from '../src/dashboard/snapshot' import type { StartupInfo, ViewState } from '../src/dashboard/view' import { DEFAULT_COLOR, renderToScreen } from '@profullstack/hqtui' import { describe, expect, it } from 'vitest' import { simulatedSource } from '../src/dashboard/simulator' -import { normalizeSnapshot } from '../src/dashboard/snapshot' -import { handlePlayersKey, renderDashboard, tabForKey, toLogRows } from '../src/dashboard/view' +import { normalizePackets, normalizeSnapshot, normalizeSync } from '../src/dashboard/snapshot' +import { describePacket, handleNetworkKey, handlePlayersKey, initialViewState, messageStats, renderDashboard, showsNetwork, tabForKey, toLogRows, visiblePackets } from '../src/dashboard/view' async function liveState(samples = 30): Promise { const source = simulatedSource() @@ -30,11 +31,15 @@ async function liveState(samples = 30): Promise { { id: 3, timestamp: 0, method: 'WS', path: '/hmr', status: 101, durationMs: 1.1, bytes: 129, address: '127.0.0.1' }, ], requestsAvailable: true, + packets: normalizePackets(await source.fetchPackets!(0)).entries, + packetsAvailable: true, + sync: normalizeSync(await source.fetchSync!()), + packetDetail: null, } } function viewState(overrides: Partial = {}): ViewState { - return { tab: 0, playerOffset: 0, logFromEnd: 0, requestTopId: null, selectedPlayerId: null, followSelectedPlayer: true, ...overrides } + return { ...initialViewState(), ...overrides } } function render(state: DashboardState, width = 130, height = 40, transparent = false, tab = 0, view = viewState({ tab }), startup?: StartupInfo) { @@ -42,7 +47,7 @@ function render(state: DashboardState, width = 130, height = 40, transparent = f } function startingState(status: DashboardState['status']): DashboardState { - return { status, source: 'http://localhost:8050/api/game/metrics', snapshot: null, lastUpdate: null, error: 'Can\'t reach', failures: 3, logs: [], logsAvailable: null, requests: [], requestsAvailable: null } + return { status, source: 'http://localhost:8050/api/game/metrics', snapshot: null, lastUpdate: null, error: 'Can\'t reach', failures: 3, logs: [], logsAvailable: null, requests: [], requestsAvailable: null, packets: [], packetsAvailable: null, sync: null, packetDetail: null } } describe('dashboard view', () => { @@ -177,7 +182,8 @@ describe('dashboard view', () => { it('maps number keys to tabs', () => { expect(tabForKey('1')).toBe(0) expect(tabForKey('4')).toBe(3) - expect(tabForKey('5')).toBeNull() + expect(tabForKey('5')).toBe(4) + expect(tabForKey('6')).toBeNull() expect(tabForKey('0')).toBeNull() expect(tabForKey('q')).toBeNull() }) @@ -201,6 +207,10 @@ describe('dashboard view', () => { logsAvailable: null, requests: [], requestsAvailable: null, + packets: [], + packetsAvailable: null, + sync: null, + packetDetail: null, }) expect(screen.contains('UNAUTHORIZED')).toBe(true) @@ -337,6 +347,213 @@ describe('dashboard view', () => { }) }) +describe('network tab', () => { + const packet = (id: number, overrides: Partial = {}): PacketLine => ({ + id, + timestamp: id * 100, + kind: 'packet', + direction: 'out', + type: 'sv_state', + peer: 'p1', + bytes: 1000, + tick: id, + sequenceId: null, + reliable: false, + info: {}, + ...overrides, + }) + + it('shows the state sync, what the traffic is made of and the packets, newest first', async () => { + const screen = render(await liveState(), 150, 40, false, 4) + + for (const text of ['5 Network', 'State sync (tick 900)', '151 synced entities', 'out of every player\'s range', 'distance 200', 'By message (last 5 s)', 'sv_state', 'cl_move', 'pings hidden', 'p Show pings', 'e Events only']) + expect(screen.contains(text), text).toBe(true) + // Pings count in the summary but are left out of the list + expect(screen.find('pong')!.y).toBeLessThan(screen.find('Details')!.y) + expect(screen.contains('CPU')).toBe(false) + expect(screen.find('tick 900 ·')!.y).toBeLessThan(screen.find('tick 894 ·')!.y) + }) + + it('keeps the details on a narrow terminal', async () => { + const screen = render(await liveState(), 80, 44, false, 4) + expect(screen.contains('State sync')).toBe(true) + expect(screen.contains('By message')).toBe(true) + expect(screen.contains('tick 900 · entities')).toBe(true) + }) + + it('shows pings and only events on request', async () => { + const state = await liveState() + const view = viewState({ tab: 4, packetTopId: 40 }) + + expect(handleNetworkKey(view, 'p')).toBe(true) + expect(view).toMatchObject({ showPings: true, packetTopId: null }) + expect(render(state, 150, 40, false, 4, view).contains('p Hide pings')).toBe(true) + + expect(handleNetworkKey(view, 'e')).toBe(true) + const screen = render(state, 150, 40, false, 4, view) + expect(screen.contains('Events (')).toBe(true) + expect(screen.contains('sync_enter')).toBe(true) + expect(screen.contains('cl_move')).toBe(false) + expect(screen.contains('e All records')).toBe(true) + + expect(handleNetworkKey(view, 'x')).toBe(false) + expect(handleNetworkKey(viewState({ tab: 0 }), 'p')).toBe(false) + }) + + it('keeps a scrolled table on the same packet as new ones arrive', async () => { + const state = await liveState() + state.packets = Array.from({ length: 80 }, (_, i) => packet(i + 1)) + const view = viewState({ tab: 4, packetTopId: 60 }) + + state.packets.push(packet(81)) + const screen = render(state, 150, 40, false, 4, view) + + expect(screen.find('tick 60 ')!.y).toBe(screen.find('Details')!.y + 1) + expect(screen.contains('tick 81')).toBe(false) + expect(screen.contains('scroll up to follow')).toBe(true) + expect(view.packetTopId).toBe(60) + }) + + it('marks a player whose state updates fell behind', async () => { + const state = await liveState() + state.sync!.players[0].lastState = null + expect(render(state, 150, 40, false, 4).contains('none')).toBe(true) + }) + + it('waits for the first answer, and explains a server that records nothing', async () => { + const state = await liveState() + state.packets = [] + state.sync = null + state.packetsAvailable = null + expect(render(state, 150, 40, false, 4).contains('Waiting for the server')).toBe(true) + + state.packetsAvailable = false + const screen = render(state, 150, 40, false, 4) + expect(screen.contains('NODE_ENV=production')).toBe(true) + expect(screen.contains('State sync')).toBe(false) + }) + + it('opens a packet with the arrow keys and shows its content', async () => { + const state = await liveState() + const view = viewState({ tab: 4 }) + const newestFirst = visiblePackets(state.packets, view).reverse() + + expect(handleNetworkKey(view, 'down', state.packets)).toBe(true) + expect(view.selectedPacketId).toBe(newestFirst[0].id) + expect(handleNetworkKey(view, 'j', state.packets)).toBe(true) + expect(handleNetworkKey(view, 'k', state.packets)).toBe(true) + expect(handleNetworkKey(view, 'up', state.packets)).toBe(true) + expect(view.selectedPacketId).toBe(newestFirst[0].id) + + // Its content is loaded after the selection changed + expect(render(state, 150, 40, false, 4, view).contains('Loading…')).toBe(true) + + state.packetDetail = { id: view.selectedPacketId!, status: 'loaded', lines: ['{', ' "tick": 900,', ' "entities": []', '}'] } + const screen = render(state, 150, 40, false, 4, view) + for (const text of [`${newestFirst[0].type} out ·`, '"tick": 900,', 'esc Close', '↑↓ Open packet', 'By message']) + expect(screen.contains(text), text).toBe(true) + // The list stays next to it + expect(screen.find('"tick": 900,')!.x).toBeGreaterThan(screen.find('Details')!.x) + + // The details of another packet are not shown for this one + state.packetDetail = { id: -1, status: 'loaded', lines: ['"other"'] } + expect(render(state, 150, 40, false, 4, view).contains('"other"')).toBe(false) + + expect(handleNetworkKey(view, 'escape', state.packets)).toBe(true) + expect(view.selectedPacketId).toBeNull() + expect(handleNetworkKey(view, 'escape', state.packets)).toBe(false) + expect(render(state, 150, 40, false, 4, view).contains('esc Close')).toBe(false) + }) + + it('opens the first or last packet when none is selected, and stops at the ends', () => { + const packets = [packet(1), packet(2), packet(3)] + const view = viewState({ tab: 4, payloadOffset: 9 }) + + handleNetworkKey(view, 'up', packets) + expect(view).toMatchObject({ selectedPacketId: 1, payloadOffset: 0 }) + handleNetworkKey(view, 'down', packets) + expect(view.selectedPacketId).toBe(1) + + expect(handleNetworkKey(viewState({ tab: 4 }), 'down', [])).toBe(false) + expect(handleNetworkKey(viewState({ tab: 3 }), 'down', packets)).toBe(false) + }) + + it('puts the content under the list on a narrow terminal and scrolls long payloads', async () => { + const state = await liveState() + const id = state.packets.at(-1)!.id + state.packetDetail = { id, status: 'loaded', lines: Array.from({ length: 200 }, (_, i) => `line ${i}`) } + const view = viewState({ tab: 4, selectedPacketId: id, payloadOffset: 150 }) + + const screen = render(state, 80, 44, false, 4, view) + + expect(screen.contains('Packets and events')).toBe(true) + expect(screen.contains('line 150')).toBe(true) + expect(screen.contains('line 149')).toBe(false) + expect(screen.find('line 150')!.y).toBeGreaterThan(screen.find('Details')!.y) + + // A shorter payload than where the last one was scrolled to + state.packetDetail = { id, status: 'loaded', lines: ['only line'] } + expect(render(state, 80, 44, false, 4, view).contains('only line')).toBe(true) + expect(view.payloadOffset).toBe(0) + }) + + it('explains a packet without content', async () => { + const state = await liveState() + const id = state.packets.at(-1)!.id + const view = viewState({ tab: 4, selectedPacketId: id }) + const shows = (detail: Partial, text: string) => { + state.packetDetail = { id, status: 'loaded', lines: [], ...detail } + return render(state, 150, 40, false, 4, view).contains(text) + } + + expect(shows({ status: 'gone' }, 'no longer keeps this payload')).toBe(true) + expect(shows({ status: 'empty' }, 'No payload')).toBe(true) + expect(shows({ status: 'error', error: 'Can\'t reach the server' }, 'Can\'t reach the server')).toBe(true) + + // A packet the dashboard no longer lists keeps its panel + view.selectedPacketId = 999999 + state.packetDetail = { id: 999999, status: 'loaded', lines: ['"kept"'] } + const screen = render(state, 150, 40, false, 4, view) + expect(screen.contains('#999999')).toBe(true) + expect(screen.contains('"kept"')).toBe(true) + }) + + it('only needs the packets while its tab shows', () => { + expect(showsNetwork(viewState({ tab: 4 }))).toBe(true) + expect(showsNetwork(viewState({ tab: 3 }))).toBe(false) + }) + + it('sums the traffic per message over the window, largest first', () => { + const packets = [ + packet(1, { timestamp: 0, bytes: 9999 }), // Before the window + packet(2, { timestamp: 6000, bytes: 1000 }), + packet(3, { timestamp: 8000, bytes: 3000 }), + packet(4, { timestamp: 9000, direction: 'in', type: 'command', bytes: 50 }), + packet(5, { timestamp: 9500, kind: 'event', direction: null, type: 'sync_leave', bytes: 0 }), + packet(6, { timestamp: 10000, direction: 'in', type: 'command', bytes: 50 }), + ] + + expect(messageStats(packets, 5000)).toEqual([ + { direction: 'out', type: 'sv_state', rate: 0.4, bytesPerSecond: 800, avgBytes: 2000 }, + { direction: 'in', type: 'command', rate: 0.4, bytesPerSecond: 20, avgBytes: 50 }, + ]) + expect(messageStats([])).toEqual([]) + // Half a second of data is not stretched to less than a second + expect(messageStats([packet(1, { timestamp: 0 }), packet(2, { timestamp: 500 })])[0]).toMatchObject({ rate: 2, bytesPerSecond: 2000 }) + }) + + it('filters and describes packets', () => { + const packets = [packet(1), packet(2, { type: 'ping' }), packet(3, { kind: 'event', type: 'connect' })] + + expect(visiblePackets(packets, { showPings: false, eventsOnly: false }).map(p => p.id)).toEqual([1, 3]) + expect(visiblePackets(packets, { showPings: true, eventsOnly: false }).map(p => p.id)).toEqual([1, 2, 3]) + expect(visiblePackets(packets, { showPings: true, eventsOnly: true }).map(p => p.id)).toEqual([3]) + + expect(describePacket(packet(1, { tick: 7, info: { entities: 3, ack: null } }))).toBe('tick 7 · entities 3') + expect(describePacket(packet(1, { tick: null, sequenceId: 4, reliable: true, info: { entities: ['a', 'b'], drop: { reason: 'x' } } }))).toBe('seq 4 · reliable · entities a, b · drop {"reason":"x"}') + }) +}) + describe('toLogRows', () => { it('splits multi-line messages and trims blank edges', () => { const rows = toLogRows([{ id: 1, timestamp: 0, level: 'info', message: '\n\n┌──┐\n│ME│\n└──┘\n' }]) diff --git a/packages/core/src/Dev/DevBridge.ts b/packages/core/src/Dev/DevBridge.ts index de33b0f..83d6f26 100644 --- a/packages/core/src/Dev/DevBridge.ts +++ b/packages/core/src/Dev/DevBridge.ts @@ -2,6 +2,7 @@ import type Game from '../Game' import type GameObject from '../World/GameObject' import type { BridgeClientInfo, BridgeQuery, BridgeRequest, BridgeResponse } from './bridgeProtocol' import type { EntitySummary } from './inspect' +import { parseNetRecordQuery, setNetDebugDefault } from '../Networking/Debug/NetRecorder' import { BRIDGE_ANNOUNCE, BRIDGE_HELLO, BRIDGE_QUERIES, BRIDGE_REQUEST, BRIDGE_RESPONSE, traceDuration } from './bridgeProtocol' import { describeScene, detailEntity, parseEntityQuery, queryEntities, summarizeEntity, vec } from './inspect' import { recordTrace } from './trace' @@ -47,6 +48,11 @@ export function startDevBridge(hot: HotChannel) { captureConsole() + // Record the traffic of the game connection, whether it exists yet or not + setNetDebugDefault(true) + if (window.Game?.network?.net) + window.Game.network.net.enabled = true + const hello = () => hot.send(BRIDGE_HELLO, info()) hot.on(BRIDGE_ANNOUNCE, hello) hot.on('vite:ws:connect', hello) @@ -232,10 +238,36 @@ const QUERIES: Record) => unknown> /** Inputs sent but not yet acknowledged by the server, replayed for prediction */ pendingCommands: internals.localCommandQueue?.length ?? null, nextSequenceId: internals.currentSequenceId ?? null, + /** The last state update: its server tick, the last input it acknowledges, how long ago it arrived */ + lastState: network.serverView && { + tick: network.serverView.tick, + serverTime: network.serverView.serverTime, + ack: network.serverView.ack, + ageMs: network.serverView.receivedAt === null ? null : Math.round(performance.now() - network.serverView.receivedAt), + missedStates: network.serverView.missedStates, + }, + recording: network.net?.enabled ?? false, }, } }, + packets(params) { + const query = parseNetRecordQuery(params) + if (typeof query === 'string') + throw new Error(query) + const net = game().network?.net + if (!net) + throw new Error('This tab has no NetworkManager: it is not connected to a game server') + return net.list(query) + }, + + packet({ id }) { + const net = game().network?.net + if (!net) + throw new Error('This tab has no NetworkManager: it is not connected to a game server') + return { record: net.get(Number(id)) ?? null } + }, + logs({ after }) { const afterId = Number(after ?? 0) || 0 return { entries: logs.filter(entry => entry.id > afterId), latestId: nextLogId - 1 } diff --git a/packages/core/src/Dev/bridgeProtocol.ts b/packages/core/src/Dev/bridgeProtocol.ts index 51d8c53..6e91c5f 100644 --- a/packages/core/src/Dev/bridgeProtocol.ts +++ b/packages/core/src/Dev/bridgeProtocol.ts @@ -19,7 +19,7 @@ export const BRIDGE_CLIENTS_PATH = '/__mavonengine/clients' /** Client id that picks the only open game tab (the only one not running the editor, if there are several) */ export const AUTO_CLIENT_ID = 'auto' -export const BRIDGE_QUERIES = ['info', 'status', 'entities', 'entity', 'scene', 'network', 'logs', 'screenshot', 'trace'] as const +export const BRIDGE_QUERIES = ['info', 'status', 'entities', 'entity', 'scene', 'network', 'packets', 'packet', 'logs', 'screenshot', 'trace'] as const export type BridgeQuery = typeof BRIDGE_QUERIES[number] /** Trace length limits, in ms. The dev server waits this long plus TRACE_GRACE_MS for the tab to answer */ diff --git a/packages/core/src/Networking/Client/NetworkManager.ts b/packages/core/src/Networking/Client/NetworkManager.ts index 9f41fe8..add46a3 100644 --- a/packages/core/src/Networking/Client/NetworkManager.ts +++ b/packages/core/src/Networking/Client/NetworkManager.ts @@ -1,11 +1,48 @@ import type { ClientChannel } from '@geckos.io/client' import type { ClientOptions } from '@geckos.io/common/lib/types' -import type { CommandPacket } from '../Server/Commands' +import type { Vec3 } from '../../Dev/inspect' +import type { CommandPacket, StatePacket } from '../Server/Commands' import { geckos } from '@geckos.io/client' import Game from '../../BaseGame' import EventEmitter from '../../Utils/EventEmitter' -import { ClientCommand } from '../Server/Commands' +import NetRecorder, { netDebugDefault } from '../Debug/NetRecorder' +import { tapMessages } from '../Debug/tap' +import { ClientCommand, ServerCommand } from '../Server/Commands' + +/** An entity as the server last sent it, before the client smoothed or predicted anything */ +export interface ServerEntityView { + id: string + type: string | null + position: Vec3 + rotation: Vec3 + scale: Vec3 + /** Server tick of the state it was last in */ + tick: number + /** `performance.now()` when that state arrived */ + receivedAt: number +} + +/** The last sv_state this client received */ +export interface ServerView { + /** Null until the first state arrived */ + tick: number | null + /** Epoch ms on the server when the state was taken */ + serverTime: number | null + /** Last input of this client the server had processed, null for the editor */ + ack: number | null + /** `performance.now()` when it arrived */ + receivedAt: number | null + /** States that never arrived, counted from gaps in the tick numbers */ + missedStates: number + /** Raw server state per entity id. Only filled while `net` records, for the dev tools */ + entities: Map +} + +function vec(value: unknown): Vec3 { + const { x = 0, y = 0, z = 0 } = (value ?? {}) as Partial + return { x, y, z } +} let instance: NetworkManager | undefined @@ -18,6 +55,15 @@ export default class NetworkManager extends EventEmitter { private currentSequenceId = 0 + /** + * The last packets and network events of this client, for the dev tools. Off unless the dev bridge + * or the editor runs; turn it on with `net.enabled = true`. + */ + readonly net = new NetRecorder({ enabled: netDebugDefault() }) + + /** What the server last sent, untouched by interpolation or prediction */ + readonly serverView: ServerView = { tick: null, serverTime: null, ack: null, receivedAt: null, missedStates: 0, entities: new Map() } + /** * This command queue is used for replaying packets locally. * When ServerCommand.SV_STATE comes in we drop anything thats below @@ -34,6 +80,16 @@ export default class NetworkManager extends EventEmitter { this._socket = geckos(options) + // Only hooked into the socket once something records + this.net.onEnabled(() => { + const internals = this._socket as unknown as { connectionsManager?: unknown, bridge?: unknown } + tapMessages(internals.connectionsManager, 'emit', 'out', this.net) + tapMessages(internals.bridge, 'emit', 'in', this.net) + }) + + this._socket.on(ServerCommand.SV_STATE, data => this.trackServerState(data as unknown as StatePacket)) + this._socket.on(ServerCommand.SV_REMOVE_ENTITY, data => this.serverView.entities.delete((data as unknown as { id: string }).id)) + this._socket.onConnect((error) => { if (error) { Game.instance().logger?.error(`Socket error: ${error.message}`) @@ -42,6 +98,7 @@ export default class NetworkManager extends EventEmitter { Game.instance().logger?.info(`Socket connection established: ${this._socket.id}`) this._connected = true + this.net.event('connect', { info: { id: this._socket.id } }) if (this._editorMode) this.announceEditor() this.onConnect() @@ -51,6 +108,7 @@ export default class NetworkManager extends EventEmitter { Game.instance().logger?.info('Socket disconnected') this._connected = false + this.net.event('disconnect') this.onDisconnect() }) @@ -61,13 +119,60 @@ export default class NetworkManager extends EventEmitter { // Created after the editor booted, e.g. the editor connects to watch the game without having joined this._editorMode = !!(Game.instance() as { editor?: unknown }).editor + if (this._editorMode) + this.net.enabled = true + Game.instance().on('editorBoot', () => { this._editorMode = true + this.net.enabled = true if (this._connected) this.announceEditor() }) } + /** + * Keep what the server said about its tick and, for the dev tools, about each entity + */ + private trackServerState(state: StatePacket) { + const view = this.serverView + const now = performance.now() + + if (typeof state?.tick === 'number') { + if (view.tick !== null && state.tick > view.tick + 1) { + const missed = state.tick - view.tick - 1 + view.missedStates += missed + this.net.event('state_gap', { tick: state.tick, info: { missed, after: view.tick } }) + } + else if (view.tick !== null && state.tick <= view.tick) { + // Arrived after a newer one: the data channel is unordered + this.net.event('state_out_of_order', { tick: state.tick, info: { newest: view.tick } }) + return + } + + view.tick = state.tick + view.serverTime = state.serverTime ?? null + view.ack = state.ack ?? null + } + view.receivedAt = now + + if (!this.net.enabled || !Array.isArray(state?.entities)) + return + + for (const entity of state.entities as { id?: string, $typeName?: string, position?: unknown, rotation?: unknown, scale?: unknown }[]) { + if (typeof entity?.id !== 'string') + continue + view.entities.set(entity.id, { + id: entity.id, + type: entity.$typeName ?? null, + position: vec(entity.position), + rotation: vec(entity.rotation), + scale: entity.scale ? vec(entity.scale) : { x: 1, y: 1, z: 1 }, + tick: view.tick ?? 0, + receivedAt: now, + }) + } + } + private announceEditor() { this._socket.emit(ClientCommand.CL_EDITOR, { type: ClientCommand.CL_EDITOR }, { reliable: true }) } diff --git a/packages/core/src/Networking/Debug/NetRecorder.ts b/packages/core/src/Networking/Debug/NetRecorder.ts new file mode 100644 index 0000000..579e5b8 --- /dev/null +++ b/packages/core/src/Networking/Debug/NetRecorder.ts @@ -0,0 +1,328 @@ +/** + * Keeps the last packets and network events of one side (the server, or one client) for the dev tools: + * the packet inspector, the network timeline, `mavonengine mcp` and the editor's Network panel. + * Shared by the server and the browser, so it uses nothing from Node or the DOM. + */ + +export type NetDirection = 'in' | 'out' + +export interface NetRecord { + id: number + /** Epoch ms */ + timestamp: number + /** A message on the wire, or something that happened to the connection or the sync (connect, sync_enter, dropped…) */ + kind: 'packet' | 'event' + /** `out` was sent by this side, `in` received. Events have none */ + direction?: NetDirection + /** Message name on the wire (sv_state, command, ping…) or the event's name */ + type: string + /** On the server: channel id of the client it was sent to or came from. Unset on a client */ + peer?: string + /** Size of the JSON payload in bytes, without the transport's framing */ + bytes?: number + reliable?: boolean + /** Server tick the packet belongs to (sv_state) */ + tick?: number + /** Input sequence id of a command */ + sequenceId?: number + /** Short facts about the payload, e.g. `{ entities: 12, ack: 40 }` or `{ command: 'cl_move' }` */ + info?: Record + /** Whether `get(id)` still has the payload: it is dropped from old records to bound memory */ + hasPayload: boolean +} + +export interface NetRecordDetail extends NetRecord { + payload?: unknown +} + +export interface NetRecordInput { + kind: NetRecord['kind'] + type: string + direction?: NetDirection + peer?: string + bytes?: number + reliable?: boolean + tick?: number + sequenceId?: number + info?: Record + /** The payload as JSON, kept for `get()` */ + json?: string + timestamp?: number +} + +export interface NetRecordQuery { + /** Only records newer than this id */ + after?: number + kind?: NetRecord['kind'] + direction?: NetDirection + /** Exact message / event name, or several separated by commas */ + type?: string + peer?: string + /** Newest records kept when more match. Default 200 */ + limit?: number +} + +export interface NetRecordList { + enabled: boolean + /** Id of the newest record, pass it as `after` to get only newer ones */ + latestId: number + /** Records matching the query before `limit` cut them */ + matched: number + records: NetRecord[] +} + +export interface NetRecorderOptions { + enabled?: boolean + /** How many records are kept. Default 2000 */ + size?: number + /** Bytes of payload JSON kept over all records, the oldest payloads go first. Default 8 MB */ + payloadBudget?: number +} + +export const DEFAULT_NET_RECORD_LIMIT = 200 +export const MAX_NET_RECORD_LIMIT = 2000 + +interface Stored extends NetRecord { + json?: string +} + +let debugByDefault = false + +/** + * Whether a client's NetworkManager records its traffic from the start. Turned on by the dev bridge and the editor, + * so a production build records nothing. + */ +export function setNetDebugDefault(enabled: boolean) { + debugByDefault = enabled +} + +export function netDebugDefault() { + return debugByDefault +} + +const encoder = typeof TextEncoder === 'undefined' ? undefined : new TextEncoder() + +/** UTF-8 size of a string */ +export function byteLength(text: string): number { + if (encoder) + return encoder.encode(text).length + + // No TextEncoder: count the bytes of each code point + let bytes = 0 + for (const char of text) { + const code = char.codePointAt(0)! + bytes += code < 0x80 ? 1 : code < 0x800 ? 2 : code < 0x10000 ? 3 : 4 + } + return bytes +} + +/** + * The fields the dev tools show without opening the payload, read from the engine's own packet shapes. + * Game packets get their `type` and `sequenceId` picked up when they follow `CommandPacket`. + */ +export function describePayload(type: string, data: unknown): Pick { + if (!data || typeof data !== 'object') + return {} + + const packet = data as { type?: unknown, tick?: unknown, ack?: unknown, sequenceId?: unknown, entities?: unknown, id?: unknown } + const info: Record = {} + + if (Array.isArray(packet.entities)) + info.entities = packet.entities.length + if (typeof packet.ack === 'number') + info.ack = packet.ack + if (typeof packet.type === 'string' && packet.type !== type) + info.command = packet.type + if (typeof packet.id === 'string') + info.id = packet.id + + return { + tick: typeof packet.tick === 'number' ? packet.tick : undefined, + // sv_state carries the ack instead: its sequenceId is unused + sequenceId: typeof packet.sequenceId === 'number' && typeof packet.tick !== 'number' ? packet.sequenceId : undefined, + info: Object.keys(info).length ? info : undefined, + } +} + +export default class NetRecorder { + private _enabled = false + private enableCallbacks: (() => void)[] = [] + + private records: Stored[] = [] + private nextId = 1 + private size: number + private payloadBudget: number + private payloadBytes = 0 + /** Records before this index have no payload left */ + private payloadFloor = 0 + + constructor(options: NetRecorderOptions = {}) { + this.size = options.size ?? 2000 + this.payloadBudget = options.payloadBudget ?? 8 * 1024 * 1024 + this.enabled = options.enabled ?? false + } + + get enabled() { + return this._enabled + } + + set enabled(enabled: boolean) { + this._enabled = enabled + if (enabled) { + for (const callback of this.enableCallbacks.splice(0)) + callback() + } + } + + /** + * Run `callback` once, when recording is first turned on (now, when it is on already). + * For hooks that should not exist while nothing is recorded. + */ + onEnabled(callback: () => void) { + if (this._enabled) + callback() + else + this.enableCallbacks.push(callback) + } + + get latestId() { + return this.nextId - 1 + } + + record(input: NetRecordInput): NetRecord | undefined { + if (!this.enabled) + return undefined + + const { json, timestamp, ...rest } = input + const record: Stored = { id: this.nextId++, timestamp: timestamp ?? Date.now(), ...rest, hasPayload: json !== undefined } + if (json !== undefined) { + record.json = json + this.payloadBytes += json.length + } + + this.records.push(record) + this.trim() + return record + } + + /** + * Record a message. Serializes `data` unless its JSON is passed, so only call it when `enabled`. + */ + packet(direction: NetDirection, type: string, data: unknown, extra: Partial = {}) { + if (!this.enabled) + return undefined + + let json = extra.json + if (json === undefined && data !== undefined && data !== null) { + try { + json = JSON.stringify(data) + } + catch { + json = undefined + } + } + + return this.record({ + kind: 'packet', + direction, + type, + bytes: json === undefined ? 0 : byteLength(json), + ...describePayload(type, data), + ...extra, + json, + }) + } + + event(type: string, extra: Partial = {}) { + return this.record({ kind: 'event', type, ...extra }) + } + + list(query: NetRecordQuery = {}): NetRecordList { + const after = query.after ?? 0 + const types = query.type ? new Set(query.type.split(',').map(type => type.trim()).filter(Boolean)) : undefined + const limit = Math.max(1, Math.min(query.limit ?? DEFAULT_NET_RECORD_LIMIT, MAX_NET_RECORD_LIMIT)) + + const matches = this.records.filter(record => + record.id > after + && (!query.kind || record.kind === query.kind) + && (!query.direction || record.direction === query.direction) + && (!types || types.has(record.type)) + && (!query.peer || record.peer === query.peer)) + + return { + enabled: this.enabled, + latestId: this.latestId, + matched: matches.length, + records: matches.slice(-limit).map(({ json: _json, ...record }) => record), + } + } + + get(id: number): NetRecordDetail | undefined { + // Ids are consecutive, so the record sits at a fixed distance from the first one + const first = this.records[0] + const stored = first ? this.records[id - first.id] : undefined + if (!stored) + return undefined + + const { json, ...record } = stored + return json === undefined ? record : { ...record, payload: JSON.parse(json) } + } + + clear() { + this.records = [] + this.payloadBytes = 0 + this.payloadFloor = 0 + } + + private trim() { + const overflow = this.records.length - this.size + if (overflow > 0) { + for (const dropped of this.records.splice(0, overflow)) + this.payloadBytes -= dropped.json?.length ?? 0 + this.payloadFloor = Math.max(0, this.payloadFloor - overflow) + } + + // Always keep the newest payload, however large + while (this.payloadBytes > this.payloadBudget && this.payloadFloor < this.records.length - 1) { + const record = this.records[this.payloadFloor++] + if (record.json !== undefined) { + this.payloadBytes -= record.json.length + record.json = undefined + record.hasPayload = false + } + } + } +} + +/** Query string params of GET …/net/packets as a query, or the reason they are invalid */ +export function parseNetRecordQuery(params: Record): NetRecordQuery | string { + const query: NetRecordQuery = {} + + for (const key of ['after', 'limit'] as const) { + if (params[key] === undefined || params[key] === '') + continue + const value = Number(params[key]) + if (!Number.isInteger(value) || value < 0) + return `${key} must be a non-negative integer` + query[key] = value + } + + if (params.kind !== undefined && params.kind !== '') { + if (params.kind !== 'packet' && params.kind !== 'event') + return 'kind must be packet or event' + query.kind = params.kind + } + + if (params.direction !== undefined && params.direction !== '') { + if (params.direction !== 'in' && params.direction !== 'out') + return 'direction must be in or out' + query.direction = params.direction + } + + if (typeof params.type === 'string' && params.type) + query.type = params.type + if (typeof params.peer === 'string' && params.peer) + query.peer = params.peer + + return query +} diff --git a/packages/core/src/Networking/Debug/sync.ts b/packages/core/src/Networking/Debug/sync.ts new file mode 100644 index 0000000..8cc6f4a --- /dev/null +++ b/packages/core/src/Networking/Debug/sync.ts @@ -0,0 +1,59 @@ +import type { Vec3 } from '../../Dev/inspect' +import type NetRecorder from './NetRecorder' + +/** + * Who is sent what: the server's view of its state sync, for the editor's sync overlay and the MCP tools. + */ +export interface SyncSnapshot { + /** Number of the last server tick, the one stamped on the newest sv_state packets */ + tick: number + /** Epoch ms */ + serverTime: number + tickRate: number + /** Entities closer than this to a player are sent to it. Null when the game's server doesn't tell */ + syncDistance: number | null + players: SyncPlayer[] + /** Channels of clients running the editor: they are sent every synced entity */ + editors: string[] + /** Every entity the server syncs */ + entities: SyncEntity[] +} + +export interface SyncStateSummary { + tick: number + bytes: number + entities: number +} + +export interface SyncPlayer { + id: string + displayName: string + position: Vec3 + /** Sequence id of the last input of this player the server processed */ + ack: number + /** Ids of the entities in its last state update */ + tracked: string[] + /** The last sv_state sent to it, null when none was yet */ + lastState: SyncStateSummary | null +} + +export interface SyncEntity { + id: string + type: string + position: Vec3 + rotation: Vec3 + scale: Vec3 + player: boolean + /** Changed since it was last marked synced */ + needsSync: boolean + /** How many players had it in their last state update. 0: no player is in range of it */ + trackedBy: number + /** Tick it was last sent to a player or an editor in, null when it never was */ + lastSentTick: number | null +} + +/** What the HTTP server needs to serve the network debug endpoints under GET /api/game/dev/net */ +export interface NetDebugSource { + readonly net: NetRecorder + syncSnapshot(): SyncSnapshot +} diff --git a/packages/core/src/Networking/Debug/tap.ts b/packages/core/src/Networking/Debug/tap.ts new file mode 100644 index 0000000..046340f --- /dev/null +++ b/packages/core/src/Networking/Debug/tap.ts @@ -0,0 +1,70 @@ +import type NetRecorder from './NetRecorder' +import type { NetDirection } from './NetRecorder' + +/** Events geckos.io raises on the same emitters as the messages: they never were on the wire */ +const TRANSPORT_EVENTS = new Set([ + 'connect', + 'connection', + 'dataChannelIsOpen', + 'disconnect', + 'disconnected', + 'dropped', + 'error', + 'receiveFromDataChannel', + 'sendOverDataChannel', +]) + +const MAX_SEEN_RELIABLE_IDS = 500 + +const serialized = new WeakMap() + +/** + * Tell the tap the JSON of a payload that was serialized already, so it isn't serialized a second time + */ +export function rememberJson(data: object, json: string) { + serialized.set(data, json) +} + +/** + * Record every message that passes through `target[method]`, called as `(eventName, data)`. + * + * The hooks sit inside geckos.io rather than on the public `emit()` / `on()`, so they see the game's own messages + * however it sends or listens, and leave the channel's public methods as they are: + * - sent by the server: `channel._emit` + * - received by the server: `channel.eventEmitter.emit` + * - sent by a client: `socket.connectionsManager.emit` + * - received by a client: `socket.bridge.emit` + * + * Does nothing when `target` has no such method, e.g. another transport or a mock. + */ +export function tapMessages(target: unknown, method: string, direction: NetDirection, recorder: NetRecorder, peer?: string) { + const holder = target as Record | null | undefined + const original = holder?.[method] + if (!holder || typeof original !== 'function') + return + + const seenReliable = new Set() + + holder[method] = function (this: unknown, ...args: unknown[]) { + const [eventName, data] = args as [string, unknown] + if (recorder.enabled && typeof eventName === 'string' && !TRANSPORT_EVENTS.has(eventName)) { + const wrapped = data as { RELIABLE?: number, ID?: string, MESSAGE?: unknown } | null + const reliable = !!wrapped && typeof wrapped === 'object' && wrapped.RELIABLE === 1 + + if (!reliable) { + recorder.packet(direction, eventName, data, { + peer, + json: data && typeof data === 'object' ? serialized.get(data) : undefined, + }) + } + else if (!seenReliable.has(wrapped.ID!)) { + // A reliable message is sent several times, only the first copy is recorded + seenReliable.add(wrapped.ID!) + if (seenReliable.size > MAX_SEEN_RELIABLE_IDS) + seenReliable.delete(seenReliable.values().next().value!) + recorder.packet(direction, eventName, wrapped.MESSAGE, { peer, reliable: true }) + } + } + return original.apply(this, args) + } +} diff --git a/packages/core/src/Networking/NetworkedLivingActor.ts b/packages/core/src/Networking/NetworkedLivingActor.ts index 4e52c16..ac13787 100644 --- a/packages/core/src/Networking/NetworkedLivingActor.ts +++ b/packages/core/src/Networking/NetworkedLivingActor.ts @@ -22,8 +22,9 @@ export default abstract class NetworkedLivingActor extends NetworkedGameObjectMi /** * Update the state hash if it is changed */ - if (this.stateHash !== this.previousStateHash) { - this.previousStateHash = this.stateHash + const stateHash = this.stateHash + if (stateHash !== this.previousStateHash) { + this.previousStateHash = stateHash this.needsSync = true } } diff --git a/packages/core/src/Networking/Server/Commands.ts b/packages/core/src/Networking/Server/Commands.ts index 49704ca..3fa943e 100644 --- a/packages/core/src/Networking/Server/Commands.ts +++ b/packages/core/src/Networking/Server/Commands.ts @@ -21,6 +21,22 @@ export interface CommandPacket { sequenceId?: number } +/** + * The world as one client should see it, sent every server tick + */ +export interface StatePacket extends CommandPacket { + entities: TEntity[] + /** Number of the server tick this state was taken in. Goes up by one per tick, so a gap means a lost packet */ + tick: number + /** Epoch ms on the server when the state was taken */ + serverTime: number + /** + * Sequence id of the last input of the receiving client that the server processed before this state. + * Inputs after it are not in this state yet. Null for a client without a player, like the editor. + */ + ack: number | null +} + export interface IncomingClientCommandPacket extends CommandPacket { playerId: ChannelId } diff --git a/packages/core/src/Networking/Server/Http/HttpServer.ts b/packages/core/src/Networking/Server/Http/HttpServer.ts index 2620b27..a2b1e26 100644 --- a/packages/core/src/Networking/Server/Http/HttpServer.ts +++ b/packages/core/src/Networking/Server/Http/HttpServer.ts @@ -1,6 +1,7 @@ import type { Express, NextFunction, Request, Response } from 'express' import type { Server as NodeServer } from 'node:http' import type winston from 'winston' +import type { NetDebugSource } from '../../Debug/sync' import type LogBuffer from '../Stats/LogBuffer' import type RequestLog from '../Stats/RequestLog' import type ServerMetrics from '../Stats/ServerMetrics' @@ -12,6 +13,7 @@ import { join } from 'node:path' import process from 'node:process' import express from 'express' import { parseEntityQuery } from '../../../Dev/inspect' +import { parseNetRecordQuery } from '../../Debug/NetRecorder' import { devEndpointsEnabled } from '../Stats/WorldInspector' import { devClientMiddleware, staticClientMiddleware } from './ClientMiddleware' @@ -46,6 +48,11 @@ export interface HttpServerOptions { * and are protected like the metrics endpoint. */ inspector?: WorldInspector + /** + * Serves the recorded packets, network events and the state sync on GET /api/game/dev/net/* when given. + * Same rules as `inspector`: never in production. + */ + net?: NetDebugSource } const LOOPBACK_ADDRESSES = new Set(['127.0.0.1', '::1', '::ffff:127.0.0.1']) @@ -65,6 +72,7 @@ export default class HttpServer { private requests?: RequestLog private clientOptions?: ClientOptions private inspector?: WorldInspector + private net?: NetDebugSource private lastMetricsRequestAt?: number private listener?: NodeServer @@ -81,6 +89,7 @@ export default class HttpServer { this.requests = options.requests this.clientOptions = options.client this.inspector = options.inspector + this.net = options.net this.registerHealthEndpoint() this.registerMetricsEndpoint() @@ -89,6 +98,8 @@ export default class HttpServer { if (this.devEndpointsEnabled) this.registerDevEndpoints() + if (this.net && devEndpointsEnabled()) + this.registerNetEndpoints(this.net) } /** @@ -229,6 +240,35 @@ export default class HttpServer { }) } + /** + * GET /api/game/dev/net/packets?after=&kind=&direction=&type=&peer=&limit= recorded packets and events, oldest first + * GET /api/game/dev/net/packets/:id one record with its payload + * GET /api/game/dev/net/sync who is sent which entities + * + * Never registered in production. + */ + private registerNetEndpoints(source: NetDebugSource) { + const authorize = (req: Request, res: Response, next: NextFunction) => this.authorizeMetrics(req, res, next) + + this.app.get('/api/game/dev/net/packets', authorize, (req, res) => { + const query = parseNetRecordQuery(req.query as Record) + if (typeof query === 'string') { + res.status(400).json({ error: query }) + return + } + + res.json(source.net.list(query)) + }) + + this.app.get('/api/game/dev/net/packets/:id', authorize, (req, res) => { + res.json({ record: source.net.get(Number(req.params.id)) ?? null }) + }) + + this.app.get('/api/game/dev/net/sync', authorize, (_req, res) => { + res.json(source.syncSnapshot()) + }) + } + private authorizeMetrics(req: Request, res: Response, next: NextFunction) { if (!this.metricsEnabled) { res.status(404).end() diff --git a/packages/core/src/Networking/Server/Server.ts b/packages/core/src/Networking/Server/Server.ts index 0690ceb..a017ff6 100644 --- a/packages/core/src/Networking/Server/Server.ts +++ b/packages/core/src/Networking/Server/Server.ts @@ -6,8 +6,9 @@ import type winston from 'winston' import type { LoadedPlugin, ServerPlugin, ServerPluginContext } from '../../Plugins/types' import type GameScene from '../../Scene/GameScene' import type GameObject from '../../World/GameObject' +import type { NetDebugSource, SyncSnapshot, SyncStateSummary } from '../Debug/sync' import type NetworkedActor from '../NetworkedActor' -import type { CommandPacket, IncomingClientCommandPacket } from './Commands' +import type { CommandPacket, IncomingClientCommandPacket, StatePacket } from './Commands' import type { ClientOptions } from './Http/ClientMiddleware' import type { MetricsEndpointOptions } from './Http/HttpServer' import type { LatencySimulatorOptions } from './LatencySimulator' @@ -22,6 +23,8 @@ import { loadServerPlugins } from '../../Plugins/loadServerPlugins' import PluginHost from '../../Plugins/PluginHost' import { readSceneFile, sceneFilePath, sceneNameOf } from '../../Scene/loadSceneFile' import { registerSceneObject, sceneObjectKey } from '../../Scene/SceneObjectRegistry' +import NetRecorder from '../Debug/NetRecorder' +import { rememberJson, tapMessages } from '../Debug/tap' import Player from '../Entities/Player' import NetworkedGameObject from '../NetworkedGameObject' import { ClientCommand, ServerCommand } from './Commands' @@ -30,7 +33,7 @@ import LatencySimulator from './LatencySimulator' import LogBuffer from './Stats/LogBuffer' import RequestLog from './Stats/RequestLog' import ServerMetrics, { SERVER_BANDWIDTH_ID } from './Stats/ServerMetrics' -import WorldInspector from './Stats/WorldInspector' +import WorldInspector, { devEndpointsEnabled } from './Stats/WorldInspector' import ServerWorld from './World' let instance: Server @@ -93,7 +96,12 @@ function toLoadedPlugin(plugin: ServerPlugin | LoadedPlugin, index return { package: bare.name ?? `plugin-${index}`, options: {}, plugin: bare } } -export default abstract class Server implements ServerMetricsSource, WorldInspectorSource { +/** How many entity ids a sync_enter / sync_leave event lists before it only counts them */ +const MAX_SYNC_EVENT_IDS = 20 + +const vec = ({ x, y, z }: { x: number, y: number, z: number }) => ({ x, y, z }) + +export default abstract class Server implements ServerMetricsSource, WorldInspectorSource, NetDebugSource { game: BaseGame private commandBuffer: IncomingClientCommandPacket[] = [] @@ -106,6 +114,22 @@ export default abstract class Server implements Serv readonly logs?: LogBuffer readonly requests?: RequestLog + /** + * The last packets and network events, for the dev tools (GET /api/game/dev/net/*). + * Records outside production only; set `net.enabled` to change that. + */ + readonly net = new NetRecorder({ enabled: devEndpointsEnabled() }) + + /** Number of the tick being simulated. Stamped on every sv_state, so clients and tools can tell them apart */ + tickCount = 0 + + /** Tick each entity was last sent in, kept while `net` records */ + private lastSentTick = new Map() + /** The last sv_state sent to each channel, kept while `net` records */ + private lastStates = new Map() + /** The transport's byte counters per channel, as they were when bandwidth was last recorded */ + private transportBytes = new Map() + private onHttpCallback?: (httpServer: Express) => void private options: ServerOptions @@ -165,11 +189,15 @@ export default abstract class Server implements Serv requests: this.requests, client: this.options.client, inspector: new WorldInspector(this), + net: this, }) this.gameSocket.onConnection((channel) => { this.logger.info(`Connected: ${channel.id}`) + // Before anything is sent or listened to, so the game's own messages are recorded too + this.tapChannel(channel) + const client = this.onConnection(channel) if (client instanceof Player) client.channel = channel @@ -195,6 +223,12 @@ export default abstract class Server implements Serv channel.onDisconnect(() => { const playerId = channel.id! + this.net.event('disconnect', { peer: playerId }) + this.lastStates.delete(playerId) + // Count what it sent and received since the last sample before its counters are gone + this.recordTransportBytes(channel) + this.transportBytes.delete(playerId) + if (this.editorChannels.delete(playerId)) { this.logger.info(`Editor disconnected: ${playerId}`) return @@ -236,12 +270,7 @@ export default abstract class Server implements Serv this.logger.info(`${(this.game.world as ServerWorld).players.length - 1} total players connected`) }) - channel.on('command', (data) => { - const bytes = Buffer.byteLength(JSON.stringify(data)) - this.bandwidthTracker.recordReceived(SERVER_BANDWIDTH_ID, bytes) - - this.bufferIncomingCommand(channel, data) - }) + channel.on('command', data => this.bufferIncomingCommand(channel, data)) }) this.game.onUpdate(delta => this.tick(delta)) @@ -259,6 +288,40 @@ export default abstract class Server implements Serv return this.metrics.bandwidth } + /** + * Add the bytes a channel sent and received since it was last looked at to the bandwidth tracker. + * Read from the WebRTC connection's own counters, so every message counts and none is serialized just to be measured. + */ + private recordTransportBytes(channel: ServerChannel) { + const peer = channel.webrtcConnection?.peerConnection + if (!peer) + return + + let sent: number + let received: number + // node-datachannel throws once the peer connection is closed + try { + sent = peer.bytesSent() + received = peer.bytesReceived() + } + catch { + return + } + + const before = this.transportBytes.get(channel.id!) ?? { sent: 0, received: 0 } + this.transportBytes.set(channel.id!, { sent, received }) + this.bandwidthTracker.recordSent(SERVER_BANDWIDTH_ID, Math.max(0, sent - before.sent)) + this.bandwidthTracker.recordReceived(SERVER_BANDWIDTH_ID, Math.max(0, received - before.received)) + } + + /** + * Close the current sampling window of the metrics, with the bytes every connection moved in it + */ + private sampleMetrics() { + this.gameSocket.connectionsManager.connections.forEach(con => this.recordTransportBytes(con.channel)) + this.metrics.sample() + } + get latencySimulation() { return this.latencySimulator?.config } @@ -270,7 +333,29 @@ export default abstract class Server implements Serv }) } + /** + * Record what this channel sends and receives, and what the transport drops. + * Channels that connected while `net` was off stay unrecorded. + */ + private tapChannel(channel: ServerChannel) { + if (!this.net.enabled) + return + + const peer = channel.id! + tapMessages(channel, '_emit', 'out', this.net, peer) + tapMessages((channel as unknown as { eventEmitter?: unknown }).eventEmitter, 'emit', 'in', this.net, peer) + + if (typeof channel.onDrop === 'function') { + channel.onDrop((drop) => { + this.net.event('dropped', { peer, info: { reason: (drop as { reason?: string }).reason, message: drop.event } }) + }) + } + + this.net.event('connect', { peer }) + } + private tick(delta: number) { + this.tickCount++ this.commandsProcessedThisTick += this.runThroughBuffer() this.onTick(delta) @@ -290,7 +375,7 @@ export default abstract class Server implements Serv this.gameSocket.connectionsManager.connections.forEach((con, id) => { if (this.editorChannels.has(id!)) { - this.sendState(con.channel, [...this.game.world.entities.items.values()].filter(entity => this.isSynced(entity))) + this.sendState(con.channel, [...this.game.world.entities.items.values()].filter(entity => this.isSynced(entity)), null) return } @@ -302,6 +387,8 @@ export default abstract class Server implements Serv // Create a temporary set of entities that should be tracked for this player in this tick const currentTickTrackedEntities = new Set() + // Copied, because entities out of range are deleted from the player's set below + const previouslyTracked = this.net.enabled ? new Set(player.trackedEntities) : undefined this.game.world.entities.items.forEach((entity) => { if (!this.isSynced(entity)) @@ -329,11 +416,14 @@ export default abstract class Server implements Serv } }) + if (previouslyTracked) + this.recordSyncChanges(id!, previouslyTracked, currentTickTrackedEntities) + // Update the player's trackedEntities to reflect the current tick's within-distance entities // This is crucial for correctly handling re-entry. player.trackedEntities = currentTickTrackedEntities - this.sendState(con.channel, entitiesToSend) + this.sendState(con.channel, entitiesToSend, player.lastProcessedSequenceId) }) // Mark entities as synced ONLY if they were actually sent to at least one client @@ -348,14 +438,42 @@ export default abstract class Server implements Serv return !this.game.activeScene?.entryOf(entity) || entity instanceof NetworkedGameObject } - private sendState(channel: ServerChannel, entities: GameObject[]) { - const state = { + /** + * Which entities came into a player's sync distance this tick and which left it, as timeline events + */ + private recordSyncChanges(peer: string, before: Set, now: Set) { + const entered = [...now].filter(id => !before.has(id)) + const left = [...before].filter(id => !now.has(id)) + + if (entered.length) + this.net.event('sync_enter', { peer, tick: this.tickCount, info: { count: entered.length, entities: entered.slice(0, MAX_SYNC_EVENT_IDS) } }) + if (left.length) + this.net.event('sync_leave', { peer, tick: this.tickCount, info: { count: left.length, entities: left.slice(0, MAX_SYNC_EVENT_IDS) } }) + } + + /** + * Send `entities` to one client. `ack` is the sequence id of the last input of this client that was processed, + * null for a client without a player (the editor). + */ + private sendState(channel: ServerChannel, entities: GameObject[], ack: number | null) { + const state: StatePacket = { entities, sequenceId: 0, type: ServerCommand.SV_STATE, + tick: this.tickCount, + serverTime: Date.now(), + ack, } - this.bandwidthTracker.recordSent(SERVER_BANDWIDTH_ID, Buffer.byteLength(JSON.stringify(state))) + // Serialized here for the dev tools only: geckos.io serializes the state itself when it sends it + if (this.net.enabled) { + const json = JSON.stringify(state) + // The tap on the channel records the packet when it is really sent, after any simulated latency + rememberJson(state, json) + this.lastStates.set(channel.id!, { tick: state.tick, bytes: Buffer.byteLength(json), entities: entities.length }) + for (const entity of entities) + this.lastSentTick.set(entity.id, state.tick) + } const SendState = () => channel.emit(ServerCommand.SV_STATE, state) @@ -367,6 +485,63 @@ export default abstract class Server implements Serv } } + /** + * Who is sent what right now: every synced entity with how many players track it, and each player's last state update + */ + syncSnapshot(): SyncSnapshot { + const world = this.game.world as ServerWorld + const players = world.players + const trackedBy = new Map() + for (const player of players) { + for (const id of player.trackedEntities) + trackedBy.set(id, (trackedBy.get(id) ?? 0) + 1) + } + + let syncDistance: number | null = null + try { + syncDistance = this.getStateSyncDistance() + } + catch { + // The game's server doesn't implement it + } + + const entities = [...world.entities.items.values()].filter(entity => this.isSynced(entity)) + + // Forget entities that left the world + const ids = new Set(entities.map(entity => entity.id)) + for (const id of this.lastSentTick.keys()) { + if (!ids.has(id)) + this.lastSentTick.delete(id) + } + + return { + tick: this.tickCount, + serverTime: Date.now(), + tickRate: this.game.tickRate, + syncDistance, + players: players.map(player => ({ + id: player.id, + displayName: player.displayName, + position: vec(player.position), + ack: player.lastProcessedSequenceId, + tracked: [...player.trackedEntities], + lastState: this.lastStates.get(player.id) ?? null, + })), + editors: [...this.editorChannels], + entities: entities.map(entity => ({ + id: entity.id, + type: (entity as { $typeName?: string }).$typeName ?? entity.constructor.name, + position: vec(entity.position), + rotation: vec(entity.rotation), + scale: vec(entity.scale), + player: entity instanceof Player, + needsSync: (entity as Partial).needsSync === true, + trackedBy: trackedBy.get(entity.id) ?? 0, + lastSentTick: this.lastSentTick.get(entity.id) ?? null, + })), + } + } + /** * A client booted the editor: take its player out of the world, tell the other players it is gone, * and from now on send it the whole world state. @@ -376,6 +551,7 @@ export default abstract class Server implements Serv if (this.editorChannels.has(id)) return this.editorChannels.add(id) + this.net.event('editor_attached', { peer: id }) const player = this.game.world.entities.items.get(id) if (player) { @@ -603,7 +779,7 @@ export default abstract class Server implements Serv private startMetrics() { const logIntervalMs = this.options.metrics?.logIntervalMs ?? 5000 - this.timers.push(setInterval(() => this.metrics.sample(), this.metrics.sampleIntervalMs)) + this.timers.push(setInterval(() => this.sampleMetrics(), this.metrics.sampleIntervalMs)) this.timers.push(setInterval(() => this.logStats(logIntervalMs), logIntervalMs)) } diff --git a/packages/core/src/Networking/Server/Stats/RequestLog.ts b/packages/core/src/Networking/Server/Stats/RequestLog.ts index 73266f3..14bb7c4 100644 --- a/packages/core/src/Networking/Server/Stats/RequestLog.ts +++ b/packages/core/src/Networking/Server/Stats/RequestLog.ts @@ -30,6 +30,9 @@ export interface RequestLogResponse { /** Requests the dashboard makes every poll, which would bury everything else */ export const UNLOGGED_PATHS = new Set(['/api/game/metrics', '/api/game/logs', '/api/game/requests']) +/** The network debug endpoints, polled by the dashboard's Network tab and the editor's Network panel */ +export const UNLOGGED_PREFIX = '/api/game/dev/net/' + const STATUS_LINE_RE = /^HTTP\/\d(?:\.\d)? (\d{3})/ /** @@ -86,7 +89,7 @@ export default class RequestLog { private onRequest(req: IncomingMessage, res: ServerResponse) { const path = pathOf(req) - if (UNLOGGED_PATHS.has(path) || this.ignoredPrefixes.some(prefix => path.startsWith(prefix))) + if (UNLOGGED_PATHS.has(path) || path.startsWith(UNLOGGED_PREFIX) || this.ignoredPrefixes.some(prefix => path.startsWith(prefix))) return const timestamp = Date.now() diff --git a/packages/core/src/World/Actor.ts b/packages/core/src/World/Actor.ts index 4be1ce6..33e33c3 100644 --- a/packages/core/src/World/Actor.ts +++ b/packages/core/src/World/Actor.ts @@ -20,7 +20,10 @@ export default abstract class Actor extends GameObject { } } + /** + * Everything `serialize()` returns as one string, to tell whether the actor changed since it was last looked at + */ get stateHash() { - return btoa(JSON.stringify(this.serialize())) + return JSON.stringify(this.serialize()) } } diff --git a/packages/core/tests/Dev/DevBridge.test.ts b/packages/core/tests/Dev/DevBridge.test.ts index 010ae0b..516ed5c 100644 --- a/packages/core/tests/Dev/DevBridge.test.ts +++ b/packages/core/tests/Dev/DevBridge.test.ts @@ -4,6 +4,7 @@ import { Vector3 } from 'three' import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' import { BRIDGE_HELLO, BRIDGE_REQUEST, BRIDGE_RESPONSE } from '../../src/Dev/bridgeProtocol' import { answer, formatArgs, pushLog, resetDevBridgeLogs, startDevBridge } from '../../src/Dev/DevBridge' +import NetRecorder from '../../src/Networking/Debug/NetRecorder' import BaseWorld from '../../src/World/BaseWorld' import GameObject from '../../src/World/GameObject' @@ -27,6 +28,10 @@ function fakeGame() { other: new Character('other', false, new Vector3(2, 0, 0)), }) + const net = new NetRecorder({ enabled: true }) + net.packet('out', 'command', { type: 'cl_move', sequenceId: 16 }) + net.packet('in', 'sv_state', { tick: 12, ack: 16, entities: [] }) + const info = { autoReset: true, reset: vi.fn(), render: { calls: 12, triangles: 3400, points: 0, lines: 2 }, memory: { geometries: 5, textures: 3 }, programs: [{}, {}] } return { world, @@ -44,6 +49,8 @@ function fakeGame() { editorMode: false, localCommandQueue: [{}, {}, {}], currentSequenceId: 17, + net, + serverView: { tick: 12, serverTime: 5000, ack: 16, receivedAt: performance.now(), missedStates: 1, entities: new Map() }, }, } } @@ -100,9 +107,30 @@ describe('answer', () => { expect(await ask('entity')).toMatchObject({ ok: false, error: 'id is required' }) }) + it('lists the recorded packets and shows one with its payload', async () => { + const res = await ask('packets', { direction: 'in', limit: '5' }) as any + expect(res.data).toMatchObject({ enabled: true, latestId: 2, matched: 1, records: [{ id: 2, type: 'sv_state', tick: 12 }] }) + + expect(((await ask('packet', { id: '1' })) as any).data.record).toMatchObject({ type: 'command', payload: { type: 'cl_move', sequenceId: 16 } }) + expect(((await ask('packet', { id: '9' })) as any).data).toEqual({ record: null }) + expect(await ask('packets', { kind: 'frame' })).toMatchObject({ ok: false, error: 'kind must be packet or event' }) + + delete (window as any).Game.network + expect(await ask('packets')).toMatchObject({ ok: false, error: expect.stringContaining('no NetworkManager') }) + }) + it('reports the network state', async () => { const res = await ask('network') as any - expect(res.data.network).toEqual({ connected: true, playerId: 'socket-1', pingMs: 42, editorMode: false, pendingCommands: 3, nextSequenceId: 17 }) + expect(res.data.network).toEqual({ + connected: true, + playerId: 'socket-1', + pingMs: 42, + editorMode: false, + pendingCommands: 3, + nextSequenceId: 17, + lastState: { tick: 12, serverTime: 5000, ack: 16, ageMs: expect.any(Number), missedStates: 1 }, + recording: true, + }) delete (window as any).Game.network expect(((await ask('network')) as any).data.network).toBeNull() diff --git a/packages/core/tests/Networking/Client/NetworkManager.test.ts b/packages/core/tests/Networking/Client/NetworkManager.test.ts index 560fb97..8772e50 100644 --- a/packages/core/tests/Networking/Client/NetworkManager.test.ts +++ b/packages/core/tests/Networking/Client/NetworkManager.test.ts @@ -132,6 +132,89 @@ describe('networkManager', () => { vi.useRealTimers() }) + describe('server view', () => { + const stateHandler = () => mockSocket.on.mock.calls.find(([event]) => event === 'sv_state')![1] + const entity = (id: string, x: number) => ({ id, $typeName: 'rock', position: { x, y: 0, z: 0 }, rotation: { x: 0, y: 1, z: 0 }, scale: { x: 1, y: 1, z: 1 } }) + + it('keeps the tick, server time and ack of the last state', () => { + const nm = new NetworkManager({}) + expect(nm.serverView).toMatchObject({ tick: null, ack: null, receivedAt: null, missedStates: 0 }) + + stateHandler()({ tick: 5, serverTime: 1234, ack: 9, entities: [entity('rock', 1)] }) + + expect(nm.serverView).toMatchObject({ tick: 5, serverTime: 1234, ack: 9, missedStates: 0 }) + expect(nm.serverView.receivedAt).toBeGreaterThan(0) + // Entities are only kept for the dev tools + expect(nm.serverView.entities.size).toBe(0) + }) + + it('keeps the raw state of each entity while recording, until the server removes it', () => { + const nm = new NetworkManager({}) + nm.net.enabled = true + + stateHandler()({ tick: 5, serverTime: 1, ack: 0, entities: [entity('rock', 1), entity('tree', 2)] }) + stateHandler()({ tick: 6, serverTime: 2, ack: 0, entities: [entity('rock', 3)] }) + + expect(nm.serverView.entities.get('rock')).toMatchObject({ id: 'rock', type: 'rock', position: { x: 3, y: 0, z: 0 }, rotation: { x: 0, y: 1, z: 0 }, tick: 6 }) + // Not in the newest state: still where the server last said, with the tick it said so in + expect(nm.serverView.entities.get('tree')).toMatchObject({ position: { x: 2, y: 0, z: 0 }, tick: 5 }) + + mockSocket.on.mock.calls.find(([event]) => event === 'sv_remove_entity')![1]({ id: 'tree' }) + expect(nm.serverView.entities.has('tree')).toBe(false) + }) + + it('counts states that never arrived and ignores ones that arrive late', () => { + const nm = new NetworkManager({}) + nm.net.enabled = true + + stateHandler()({ tick: 5, serverTime: 1, ack: 0, entities: [entity('rock', 5)] }) + stateHandler()({ tick: 8, serverTime: 2, ack: 0, entities: [entity('rock', 8)] }) + stateHandler()({ tick: 7, serverTime: 2, ack: 0, entities: [entity('rock', 7)] }) + + expect(nm.serverView).toMatchObject({ tick: 8, missedStates: 2 }) + expect(nm.serverView.entities.get('rock')!.position.x).toBe(8) + expect(nm.net.list({ kind: 'event' }).records).toMatchObject([ + { type: 'state_gap', tick: 8, info: { missed: 2, after: 5 } }, + { type: 'state_out_of_order', tick: 7, info: { newest: 8 } }, + ]) + }) + + it('records what the socket sends and receives once recording is on', () => { + const sent = vi.fn() + const received = vi.fn() + const socket = mockSocket as typeof mockSocket & { connectionsManager?: unknown, bridge?: unknown } + socket.connectionsManager = { emit: sent } + socket.bridge = { emit: received } + + const nm = new NetworkManager({}) + const { connectionsManager, bridge } = socket as unknown as { connectionsManager: { emit(...args: unknown[]): void }, bridge: { emit(...args: unknown[]): void } } + + // Nothing is hooked into the socket before + expect(connectionsManager.emit).toBe(sent) + nm.net.enabled = true + + connectionsManager.emit('command', { type: 'cl_move', sequenceId: 0 }) + bridge.emit('sv_state', { tick: 1, ack: 0, entities: [] }) + + expect(sent).toHaveBeenCalledWith('command', { type: 'cl_move', sequenceId: 0 }) + expect(received).toHaveBeenCalledWith('sv_state', { tick: 1, ack: 0, entities: [] }) + expect(nm.net.list().records).toMatchObject([ + { direction: 'out', type: 'command', sequenceId: 0, info: { command: 'cl_move' } }, + { direction: 'in', type: 'sv_state', tick: 1, info: { entities: 0, ack: 0 } }, + ]) + + delete socket.connectionsManager + delete socket.bridge + }) + + it('records from the start when the editor runs', () => { + const nm = new NetworkManager({}) + expect(nm.net.enabled).toBe(false) + mockGame.on.mock.calls[0][1]() + expect(nm.net.enabled).toBe(true) + }) + }) + describe('command queue', () => { it('sendCommand assigns sequential sequenceIds starting at 0', () => { const nm = new NetworkManager({}) diff --git a/packages/core/tests/Networking/Debug/NetRecorder.test.ts b/packages/core/tests/Networking/Debug/NetRecorder.test.ts new file mode 100644 index 0000000..6241614 --- /dev/null +++ b/packages/core/tests/Networking/Debug/NetRecorder.test.ts @@ -0,0 +1,141 @@ +import { describe, expect, it } from 'vitest' +import NetRecorder, { byteLength, describePayload, parseNetRecordQuery } from '../../../src/Networking/Debug/NetRecorder' + +describe('netRecorder', () => { + it('records nothing while it is off', () => { + const recorder = new NetRecorder() + + expect(recorder.packet('out', 'sv_state', { tick: 1 })).toBeUndefined() + expect(recorder.event('connect')).toBeUndefined() + expect(recorder.list()).toEqual({ enabled: false, latestId: 0, matched: 0, records: [] }) + }) + + it('records packets with their size and the facts of the payload', () => { + const recorder = new NetRecorder({ enabled: true }) + + const state = { type: 'sv_state', tick: 7, ack: 3, sequenceId: 0, entities: [{}, {}] } + const command = { type: 'cl_move', sequenceId: 4 } + recorder.packet('out', 'sv_state', state, { peer: 'p1', timestamp: 1000 }) + recorder.packet('in', 'command', command, { peer: 'p1', timestamp: 1001 }) + recorder.packet('in', 'ping', null, { peer: 'p1', timestamp: 1002 }) + + const { records } = recorder.list() + expect(records).toEqual([ + { id: 1, timestamp: 1000, kind: 'packet', direction: 'out', type: 'sv_state', peer: 'p1', bytes: JSON.stringify(state).length, tick: 7, sequenceId: undefined, info: { entities: 2, ack: 3 }, hasPayload: true }, + { id: 2, timestamp: 1001, kind: 'packet', direction: 'in', type: 'command', peer: 'p1', bytes: JSON.stringify(command).length, tick: undefined, sequenceId: 4, info: { command: 'cl_move' }, hasPayload: true }, + { id: 3, timestamp: 1002, kind: 'packet', direction: 'in', type: 'ping', peer: 'p1', bytes: 0, hasPayload: false }, + ]) + }) + + it('uses the JSON it is given instead of serializing again', () => { + const recorder = new NetRecorder({ enabled: true }) + const data = { + toJSON: () => { + throw new Error('serialized twice') + }, + } + + recorder.packet('out', 'sv_state', data, { json: '{"tick":1}' }) + + expect(recorder.get(1)).toMatchObject({ bytes: 10, payload: { tick: 1 } }) + }) + + it('filters by id, kind, direction, type and peer, keeping the newest', () => { + const recorder = new NetRecorder({ enabled: true }) + recorder.event('connect', { peer: 'a' }) + recorder.packet('out', 'sv_state', {}, { peer: 'a' }) + recorder.packet('out', 'sv_state', {}, { peer: 'b' }) + recorder.packet('in', 'command', {}, { peer: 'a' }) + recorder.packet('in', 'ping', null, { peer: 'a' }) + + const ids = (query: Parameters[0]) => recorder.list(query).records.map(record => record.id) + + expect(ids({ after: 3 })).toEqual([4, 5]) + expect(ids({ kind: 'event' })).toEqual([1]) + expect(ids({ direction: 'out' })).toEqual([2, 3]) + expect(ids({ type: 'command, ping' })).toEqual([4, 5]) + expect(ids({ peer: 'b' })).toEqual([3]) + expect(recorder.list({ limit: 2 })).toMatchObject({ latestId: 5, matched: 5, records: [{ id: 4 }, { id: 5 }] }) + }) + + it('keeps only the newest records', () => { + const recorder = new NetRecorder({ enabled: true, size: 3 }) + for (let i = 0; i < 5; i++) + recorder.packet('out', 'sv_state', { tick: i }) + + expect(recorder.list().records.map(record => record.id)).toEqual([3, 4, 5]) + expect(recorder.get(2)).toBeUndefined() + expect(recorder.get(4)).toMatchObject({ id: 4, payload: { tick: 3 } }) + expect(recorder.get(6)).toBeUndefined() + }) + + it('drops the oldest payloads over the budget but keeps their records', () => { + const recorder = new NetRecorder({ enabled: true, payloadBudget: 25 }) + recorder.packet('out', 'a', { value: 'aaaaa' }) // 17 chars + recorder.packet('out', 'b', { value: 'bbbbb' }) + recorder.packet('out', 'c', { value: 'ccccc' }) + + expect(recorder.list().records.map(record => record.hasPayload)).toEqual([false, false, true]) + expect(recorder.get(1)).toMatchObject({ type: 'a', bytes: 17, hasPayload: false }) + expect(recorder.get(1)).not.toHaveProperty('payload') + expect(recorder.get(3)).toMatchObject({ payload: { value: 'ccccc' } }) + }) + + it('runs onEnabled hooks once recording starts', () => { + const recorder = new NetRecorder() + let hooked = 0 + recorder.onEnabled(() => hooked++) + expect(hooked).toBe(0) + + recorder.enabled = true + recorder.enabled = false + recorder.enabled = true + expect(hooked).toBe(1) + + recorder.onEnabled(() => hooked++) + expect(hooked).toBe(2) + }) + + it('clears', () => { + const recorder = new NetRecorder({ enabled: true }) + recorder.packet('out', 'a', { a: 1 }) + recorder.clear() + + expect(recorder.list()).toMatchObject({ latestId: 1, records: [] }) + recorder.packet('out', 'b', { b: 1 }) + expect(recorder.get(2)).toMatchObject({ type: 'b' }) + }) +}) + +describe('describePayload', () => { + it('ignores payloads that are not objects', () => { + expect(describePayload('ping', null)).toEqual({}) + expect(describePayload('raw', 'text')).toEqual({}) + }) + + it('reads the id of a removed entity', () => { + expect(describePayload('sv_remove_entity', { id: 'rock' })).toEqual({ tick: undefined, sequenceId: undefined, info: { id: 'rock' } }) + }) +}) + +describe('byteLength', () => { + it('counts UTF-8 bytes', () => { + expect(byteLength('abc')).toBe(3) + expect(byteLength('ä€')).toBe(5) + }) +}) + +describe('parseNetRecordQuery', () => { + it('parses query string params', () => { + expect(parseNetRecordQuery({ after: '12', limit: '5', kind: 'packet', direction: 'in', type: 'sv_state', peer: 'p1' })) + .toEqual({ after: 12, limit: 5, kind: 'packet', direction: 'in', type: 'sv_state', peer: 'p1' }) + expect(parseNetRecordQuery({ after: '', kind: '' })).toEqual({}) + }) + + it('rejects bad values', () => { + expect(parseNetRecordQuery({ after: 'x' })).toBe('after must be a non-negative integer') + expect(parseNetRecordQuery({ limit: '-1' })).toBe('limit must be a non-negative integer') + expect(parseNetRecordQuery({ kind: 'frame' })).toBe('kind must be packet or event') + expect(parseNetRecordQuery({ direction: 'up' })).toBe('direction must be in or out') + }) +}) diff --git a/packages/core/tests/Networking/Debug/tap.test.ts b/packages/core/tests/Networking/Debug/tap.test.ts new file mode 100644 index 0000000..090c3fd --- /dev/null +++ b/packages/core/tests/Networking/Debug/tap.test.ts @@ -0,0 +1,88 @@ +import { describe, expect, it, vi } from 'vitest' +import NetRecorder from '../../../src/Networking/Debug/NetRecorder' +import { rememberJson, tapMessages } from '../../../src/Networking/Debug/tap' + +describe('tapMessages', () => { + it('records what passes through and still calls the original with the same arguments', () => { + const recorder = new NetRecorder({ enabled: true }) + const original = vi.fn(() => 'sent') + const channel = { _emit: original } + + tapMessages(channel, '_emit', 'out', recorder, 'p1') + expect(channel._emit('sv_chat', { message: 'hi' })).toBe('sent') + channel._emit('pong') + + expect(original.mock.calls).toEqual([['sv_chat', { message: 'hi' }], ['pong']]) + expect(original.mock.contexts[0]).toBe(channel) + expect(recorder.list().records).toMatchObject([ + { direction: 'out', type: 'sv_chat', peer: 'p1', bytes: 16 }, + { direction: 'out', type: 'pong', peer: 'p1', bytes: 0 }, + ]) + }) + + it('records a reliable message once, unwrapped', () => { + const recorder = new NetRecorder({ enabled: true }) + const original = vi.fn() + const emitter = { emit: original } + tapMessages(emitter, 'emit', 'in', recorder) + + const wrapped = { MESSAGE: { name: 'Ada' }, RELIABLE: 1, ID: 'abc' } + emitter.emit('cl_init', wrapped) + emitter.emit('cl_init', wrapped) + emitter.emit('cl_init', { MESSAGE: { name: 'Ada' }, RELIABLE: 1, ID: 'def' }) + + expect(original).toHaveBeenCalledTimes(3) + expect(recorder.list().records).toMatchObject([ + { type: 'cl_init', reliable: true, bytes: 14 }, + { type: 'cl_init', reliable: true }, + ]) + expect(recorder.get(1)).toMatchObject({ payload: { name: 'Ada' } }) + }) + + it('leaves the transport\'s own events out', () => { + const recorder = new NetRecorder({ enabled: true }) + const original = vi.fn() + const emitter = { emit: original } + tapMessages(emitter, 'emit', 'in', recorder) + + emitter.emit('disconnect', 'closed') + emitter.emit('dropped', { reason: 'x' }) + + expect(original).toHaveBeenCalledTimes(2) + expect(recorder.list().records).toEqual([]) + }) + + it('passes messages through unrecorded while the recorder is off', () => { + const recorder = new NetRecorder() + const original = vi.fn() + const emitter = { emit: original } + tapMessages(emitter, 'emit', 'in', recorder) + + emitter.emit('command', { type: 'cl_move' }) + + expect(original).toHaveBeenCalledWith('command', { type: 'cl_move' }) + expect(recorder.latestId).toBe(0) + }) + + it('uses remembered JSON', () => { + const recorder = new NetRecorder({ enabled: true }) + const channel = { _emit: vi.fn() } + tapMessages(channel, '_emit', 'out', recorder) + + const state = { tick: 2 } + rememberJson(state, '{"tick":1}') + channel._emit('sv_state', state) + + expect(recorder.get(1)).toMatchObject({ payload: { tick: 1 } }) + }) + + it('does nothing to a target without the method', () => { + const recorder = new NetRecorder({ enabled: true }) + const mock = { emit: vi.fn() } + + tapMessages(mock, '_emit', 'out', recorder) + tapMessages(undefined, 'emit', 'in', recorder) + + expect(Object.keys(mock)).toEqual(['emit']) + }) +}) diff --git a/packages/core/tests/Networking/NetworkedLivingActor.test.ts b/packages/core/tests/Networking/NetworkedLivingActor.test.ts new file mode 100644 index 0000000..b5912ec --- /dev/null +++ b/packages/core/tests/Networking/NetworkedLivingActor.test.ts @@ -0,0 +1,54 @@ +import { describe, expect, it, vi } from 'vitest' +import NetworkedLivingActor from '../../src/Networking/NetworkedLivingActor' + +class TestLivingActor extends NetworkedLivingActor { + $typeName = 'testLivingActor' + health = 100 + maxHealth = 100 + name = 'Player' + + takeDamage(_amount: number): void {} + heal(_amount: number): void {} + + serialize() { + return { ...super.serialize(), name: this.name } + } +} + +describe('networkedLivingActor', () => { + it('needs a sync after something it serializes changed', () => { + const actor = new TestLivingActor() + actor.update(0) + actor.markSyncd() + + actor.update(0) + expect(actor.needsSync).toBe(false) + + actor.position.set(1, 0, 0) + actor.update(0) + expect(actor.needsSync).toBe(true) + + actor.markSyncd() + actor.name = 'Renamed' + actor.update(0) + expect(actor.needsSync).toBe(true) + }) + + it('serializes itself once per update to tell whether it changed', () => { + const actor = new TestLivingActor() + const serialize = vi.spyOn(actor, 'serialize') + + actor.position.set(1, 0, 0) + actor.update(0) + + expect(serialize).toHaveBeenCalledTimes(1) + }) + + it('takes fields with characters outside Latin-1', () => { + const actor = new TestLivingActor() + actor.name = '日本語 🎮' + + expect(() => actor.update(0)).not.toThrow() + expect(actor.needsSync).toBe(true) + }) +}) diff --git a/packages/core/tests/Networking/Server.test.ts b/packages/core/tests/Networking/Server.test.ts index b303015..7bb4842 100644 --- a/packages/core/tests/Networking/Server.test.ts +++ b/packages/core/tests/Networking/Server.test.ts @@ -484,6 +484,105 @@ describe('server', () => { }) }) + describe('bandwidth', () => { + function connect(id: string, counters: { sent: number, received: number }) { + const handlers: Record void> = {} + let disconnect = () => {} + const peerConnection = { bytesSent: () => counters.sent, bytesReceived: () => counters.received } + const channel = { id, emit: vi.fn(), on: (event: string, cb: () => void) => (handlers[event] = cb), onDisconnect: (cb: () => void) => (disconnect = cb), webrtcConnection: { peerConnection } } + mockGeckosOnConnection.mock.calls[0][0](channel) + mockGeckosServer.connectionsManager.connections.set(id, { channel }) + return { channel, handlers, disconnect: () => disconnect() } + } + + function startServer() { + const server = new TestServer(logger, undefined, { metrics: { sampleIntervalMs: 1000 } }) + ;(server.gameSocket as any).listen = vi.fn() + vi.spyOn(server.http, 'start').mockImplementation(() => {}) + vi.spyOn(server.metrics.cpu, 'sample').mockImplementation(() => undefined as any) + vi.spyOn(server, 'getStateSyncDistance').mockReturnValue(100) + server.start() + return server + } + + afterEach(() => { + vi.useRealTimers() + mockGeckosServer.connectionsManager.connections = new Map() + }) + + it('samples what the connections sent and received from the transport\'s counters', () => { + vi.useFakeTimers() + const server = startServer() + const one = { sent: 1000, received: 200 } + const two = { sent: 50, received: 5 } + connect('p1', one) + connect('p2', two) + + vi.advanceTimersByTime(1000) + expect(server.bandwidthTracker.history.at(-1)).toMatchObject({ sent: 1050, received: 205 }) + + // Only what was added since the last sample counts + one.sent += 300 + two.received += 20 + vi.advanceTimersByTime(1000) + server.stop() + + expect(server.bandwidthTracker.history.at(-1)).toMatchObject({ sent: 300, received: 20 }) + }) + + it('counts the last bytes of a connection that closed between two samples', () => { + vi.useFakeTimers() + const server = startServer() + const counters = { sent: 100, received: 10 } + const { disconnect } = connect('p1', counters) + + vi.advanceTimersByTime(1000) + counters.sent += 40 + counters.received += 4 + disconnect() + mockGeckosServer.connectionsManager.connections.delete('p1') + vi.advanceTimersByTime(1000) + server.stop() + + expect(server.bandwidthTracker.history.at(-1)).toMatchObject({ sent: 40, received: 4 }) + }) + + it('skips a connection whose counters cannot be read', () => { + vi.useFakeTimers() + const server = startServer() + const { channel } = connect('p1', { sent: 100, received: 10 }) + channel.webrtcConnection.peerConnection.bytesSent = () => { + throw new Error('closed') + } + // Without a WebRTC connection, like a mocked channel + mockGeckosServer.connectionsManager.connections.set('p2', { channel: { id: 'p2', emit: vi.fn() } }) + + vi.advanceTimersByTime(1000) + server.stop() + + expect(server.bandwidthTracker.history.at(-1)).toMatchObject({ sent: 0, received: 0 }) + }) + + it('does not serialize a state just to measure it', () => { + const server = new TestServer(logger) + vi.spyOn(server, 'getStateSyncDistance').mockReturnValue(100) + const player = new TestClient('p1') + const toJSON = vi.fn(() => player.serialize()) + ;(player as any).toJSON = toJSON + server.game.world.entities.items.set('p1', player) + mockGeckosServer.connectionsManager.connections = new Map([['p1', { channel: { id: 'p1', emit: vi.fn() } }]]) + + server.net.enabled = false + ;(server as any).stateSync() + expect(toJSON).not.toHaveBeenCalled() + + // The dev tools show the packet, so they need it serialized + server.net.enabled = true + ;(server as any).stateSync() + expect(toJSON).toHaveBeenCalled() + }) + }) + describe('editor clients', () => { function connect(id: string) { const handlers: Record void> = {} @@ -548,6 +647,159 @@ describe('server', () => { }) }) + describe('network debugging', () => { + /** A channel with the parts of a geckos channel the recorder hooks into */ + function connect(id: string) { + const handlers: Record void> = {} + let drop = (_drop: { reason: string, event: string }) => {} + const sent = vi.fn() + const channel = { + id, + _emit: sent, + emit(event: string, data?: unknown) { + this._emit(event, data) + }, + eventEmitter: { + emit: (event: string, data?: unknown) => handlers[event]?.(data), + }, + on: (event: string, cb: () => void) => (handlers[event] = cb), + onDisconnect: (cb: () => void) => (handlers.disconnect = cb), + onDrop: (cb: typeof drop) => (drop = cb), + } + mockGeckosOnConnection.mock.calls[0][0](channel) + mockGeckosServer.connectionsManager.connections.set(id, { channel }) + return { channel, sent, handlers, drop: (reason: string, event: string) => drop({ reason, event }) } + } + + afterEach(() => { + mockGeckosServer.connectionsManager.connections = new Map() + vi.unstubAllEnvs() + }) + + function syncedServer() { + const server = new TestServer(logger) + server.getStateSyncDistance = () => 10 + return server + } + + it('stamps every state with the tick, the server time and the player\'s last processed input', () => { + const server = syncedServer() + const { sent } = connect('p1') + ;(server.game.world.entities.items.get('p1') as TestClient).updateLastProcessedSequenceId(41) + + server.game.update(0.1) + server.game.update(0.1) + + const states = sent.mock.calls.filter(([event]) => event === ServerCommand.SV_STATE).map(([, state]) => state) + expect(states.map(state => state.tick)).toEqual([1, 2]) + expect(states[1]).toMatchObject({ type: ServerCommand.SV_STATE, ack: 41, sequenceId: 0 }) + expect(Math.abs(states[1].serverTime - Date.now())).toBeLessThan(1000) + expect(server.tickCount).toBe(2) + }) + + it('sends an editor a null ack', () => { + const server = syncedServer() + const editor = connect('editor') + editor.handlers[ClientCommand.CL_EDITOR]() + + server.game.update(0.1) + + const [, state] = editor.sent.mock.calls.find(([event]) => event === ServerCommand.SV_STATE)! + expect(state).toMatchObject({ tick: 1, ack: null }) + }) + + it('records what each client is sent and sends, and the events of its connection', () => { + const server = syncedServer() + const { channel, handlers, drop } = connect('p1') + + channel.eventEmitter.emit('command', { type: 'cl_move', sequenceId: 3 }) + channel.eventEmitter.emit('ping') + server.game.update(0.1) + drop('DROPPED_FROM_BUFFERING', 'sv_state') + handlers.disconnect() + + const records = server.net.list().records.map(({ kind, direction, type, peer, tick, sequenceId, info }) => ({ kind, direction, type, peer, tick, sequenceId, info })) + expect(records).toEqual([ + { kind: 'event', direction: undefined, type: 'connect', peer: 'p1', tick: undefined, sequenceId: undefined, info: undefined }, + { kind: 'packet', direction: 'in', type: 'command', peer: 'p1', tick: undefined, sequenceId: 3, info: { command: 'cl_move' } }, + { kind: 'packet', direction: 'in', type: 'ping', peer: 'p1', tick: undefined, sequenceId: undefined, info: undefined }, + { kind: 'packet', direction: 'out', type: 'pong', peer: 'p1', tick: undefined, sequenceId: undefined, info: undefined }, + { kind: 'event', direction: undefined, type: 'sync_enter', peer: 'p1', tick: 1, sequenceId: undefined, info: { count: 1, entities: ['p1'] } }, + { kind: 'packet', direction: 'out', type: 'sv_state', peer: 'p1', tick: 1, sequenceId: undefined, info: { entities: 1, ack: 3 } }, + { kind: 'event', direction: undefined, type: 'dropped', peer: 'p1', tick: undefined, sequenceId: undefined, info: { reason: 'DROPPED_FROM_BUFFERING', message: 'sv_state' } }, + { kind: 'event', direction: undefined, type: 'disconnect', peer: 'p1', tick: undefined, sequenceId: undefined, info: undefined }, + ]) + + const state = server.net.list({ type: 'sv_state' }).records[0] + expect(server.net.get(state.id)).toMatchObject({ payload: { tick: 1, ack: 3, entities: [{ id: 'p1' }] } }) + expect(state.bytes).toBe(JSON.stringify(server.net.get(state.id)!.payload).length) + }) + + it('records entities entering and leaving a player\'s sync distance', () => { + const server = syncedServer() + connect('p1') + const rock = new TestClient('rock') + rock.position.set(5, 0, 0) + server.game.world.entities.items.set('rock', rock) + + server.game.update(0.1) + rock.position.set(50, 0, 0) + server.game.update(0.1) + + expect(server.net.list({ kind: 'event', type: 'sync_enter,sync_leave' }).records).toMatchObject([ + { type: 'sync_enter', peer: 'p1', tick: 1, info: { count: 2, entities: ['p1', 'rock'] } }, + { type: 'sync_leave', peer: 'p1', tick: 2, info: { count: 1, entities: ['rock'] } }, + ]) + }) + + it('describes the state sync', () => { + const server = syncedServer() + connect('p1') + const near = new TestClient('near') + near.position.set(5, 0, 0) + const far = new TestClient('far') + far.position.set(500, 0, 0) + server.game.world.entities.items.set('near', near) + server.game.world.entities.items.set('far', far) + + server.game.update(0.1) + const sync = server.syncSnapshot() + + expect(sync).toMatchObject({ tick: 1, tickRate: server.game.tickRate, syncDistance: 10, editors: [] }) + expect(sync.players).toHaveLength(3) + expect(sync.players[0]).toMatchObject({ id: 'p1', ack: 0, tracked: ['p1', 'near'], lastState: { tick: 1, entities: 2 } }) + expect(sync.players[0].lastState!.bytes).toBeGreaterThan(0) + // near and far are players without a connection here, so they track what is around them but are sent nothing + expect(sync.players[2]).toMatchObject({ id: 'far', lastState: null }) + + expect(sync.entities.map(({ id, trackedBy, lastSentTick, position }) => ({ id, trackedBy, lastSentTick, x: position.x }))).toEqual([ + { id: 'p1', trackedBy: 1, lastSentTick: 1, x: 0 }, + { id: 'near', trackedBy: 1, lastSentTick: 1, x: 5 }, + { id: 'far', trackedBy: 0, lastSentTick: null, x: 500 }, + ]) + }) + + it('tells when the game\'s server has no sync distance', () => { + const server = new TestServer(logger) + expect(server.syncSnapshot()).toMatchObject({ tick: 0, syncDistance: null, players: [], entities: [] }) + }) + + it('records nothing in production', () => { + vi.stubEnv('NODE_ENV', 'production') + const server = syncedServer() + const { channel, sent } = connect('p1') + + channel.eventEmitter.emit('ping') + server.game.update(0.1) + + expect(server.net.enabled).toBe(false) + expect(server.net.latestId).toBe(0) + // The channel is left as it was + expect(channel._emit).toBe(sent) + expect(sent).toHaveBeenCalledWith(ServerCommand.SV_STATE, expect.objectContaining({ tick: 1 })) + }) + }) + describe('scenes', () => { class Crate extends GameObject { update(): void {} diff --git a/packages/core/tests/Networking/Server/Http/HttpServer.test.ts b/packages/core/tests/Networking/Server/Http/HttpServer.test.ts index 5fda732..a513072 100644 --- a/packages/core/tests/Networking/Server/Http/HttpServer.test.ts +++ b/packages/core/tests/Networking/Server/Http/HttpServer.test.ts @@ -2,6 +2,7 @@ import type { Server as NodeServer } from 'node:http' import type { AddressInfo } from 'node:net' import type { HttpServerOptions } from '../../../../src/Networking/Server/Http/HttpServer' import { afterEach, describe, expect, it, vi } from 'vitest' +import NetRecorder from '../../../../src/Networking/Debug/NetRecorder' import HttpServer, { METRICS_CLIENT_TIMEOUT_MS, parseEntityQuery } from '../../../../src/Networking/Server/Http/HttpServer' import LogBuffer from '../../../../src/Networking/Server/Stats/LogBuffer' import RequestLog from '../../../../src/Networking/Server/Stats/RequestLog' @@ -178,6 +179,37 @@ describe('httpServer', () => { expect(await bad.json()).toEqual({ error: 'near must be x,y,z' }) }) + it('serves the recorded packets and the state sync', async () => { + const net = new NetRecorder({ enabled: true }) + net.packet('out', 'sv_state', { tick: 1, entities: [] }, { peer: 'p1' }) + net.packet('in', 'command', { type: 'cl_move', sequenceId: 2 }, { peer: 'p1' }) + const request = await serve({ net: { net, syncSnapshot: () => ({ tick: 9 }) as any } }) + + const all = await (await request('/api/game/dev/net/packets')).json() + expect(all).toMatchObject({ enabled: true, latestId: 2, matched: 2, records: [{ type: 'sv_state' }, { type: 'command' }] }) + + const filtered = await (await request('/api/game/dev/net/packets?after=1&direction=in&peer=p1&limit=5')).json() + expect(filtered.records).toMatchObject([{ id: 2, type: 'command', sequenceId: 2 }]) + + expect(await (await request('/api/game/dev/net/packets/1')).json()).toMatchObject({ record: { id: 1, payload: { tick: 1, entities: [] } } }) + expect(await (await request('/api/game/dev/net/packets/99')).json()).toEqual({ record: null }) + expect(await (await request('/api/game/dev/net/sync')).json()).toEqual({ tick: 9 }) + + const bad = await request('/api/game/dev/net/packets?kind=frame') + expect(bad.status).toBe(400) + expect(await bad.json()).toEqual({ error: 'kind must be packet or event' }) + }) + + it('does not serve the network debug endpoints in production or without a source', async () => { + expect((await (await serve({ inspector: fakeInspector() }))('/api/game/dev/net/sync')).status).toBe(404) + listener?.close() + + vi.stubEnv('NODE_ENV', 'production') + const request = await serve({ net: { net: new NetRecorder({ enabled: true }), syncSnapshot: () => ({}) as any }, metrics: { token: 'secret' } }) + expect((await request('/api/game/dev/net/sync?token=secret')).status).toBe(404) + expect((await request('/api/game/dev/net/packets?token=secret')).status).toBe(404) + }) + it('are not registered without an inspector', async () => { const request = await serve() diff --git a/packages/core/tests/Networking/Server/Stats/RequestLog.test.ts b/packages/core/tests/Networking/Server/Stats/RequestLog.test.ts index 71e7396..6a86469 100644 --- a/packages/core/tests/Networking/Server/Stats/RequestLog.test.ts +++ b/packages/core/tests/Networking/Server/Stats/RequestLog.test.ts @@ -67,10 +67,14 @@ describe('requestLog', () => { await fetch(`http://127.0.0.1:${port}/api/game/metrics`) await fetch(`http://127.0.0.1:${port}/api/game/logs?after=3`) await fetch(`http://127.0.0.1:${port}/api/game/requests`) + // Polled by the dashboard's Network tab and the editor's Network panel + await fetch(`http://127.0.0.1:${port}/api/game/dev/net/packets?after=3`) + await fetch(`http://127.0.0.1:${port}/api/game/dev/net/sync`) await fetch(`http://127.0.0.1:${port}/api/game/health`) + await fetch(`http://127.0.0.1:${port}/api/game/dev/scene`) await settle() - expect(log.since().entries.map(e => e.path)).toEqual(['/api/game/health']) + expect(log.since().entries.map(e => e.path)).toEqual(['/api/game/health', '/api/game/dev/scene']) }) it('skips paths under an ignored prefix', async () => { diff --git a/packages/editor/src/Editor.ts b/packages/editor/src/Editor.ts index 096c6bb..e56d4c0 100644 --- a/packages/editor/src/Editor.ts +++ b/packages/editor/src/Editor.ts @@ -17,6 +17,7 @@ import { TransformControls } from 'three/examples/jsm/controls/TransformControls import { OutlinePass } from 'three/examples/jsm/postprocessing/OutlinePass.js' import { applyShadeMode } from './Editor/applyShadeMode' import { DEFAULT_SCENE_NAME, demoScene } from './Editor/demoScene' +import NetworkOverlay from './Editor/Network/NetworkOverlay' import { registerEditorPanel, unregisterEditorPanel } from './Editor/panels' export type { EditorPanelDefinition, EditorPanelLocation } from './Editor/panels' @@ -41,6 +42,9 @@ export default class Editor extends EventEmitter implements IEditor, GameObjectI private abort = new AbortController() private saving?: Promise + /** Server ghosts and sync rings in the viewport, switched on from the Network panel */ + networkOverlay!: NetworkOverlay + availableAssetCategories!: string[] activeAssetCategory: 'Object' | '_texture' | 'CubeTexture' | 'AudioBuffer' | 'Font' = 'Object' @@ -98,6 +102,9 @@ export default class Editor extends EventEmitter implements IEditor, GameObjectI import('./Editor/UI/global.css'), ]).then(([{ mountEditorUI }]) => { this.reactRoot = mountEditorUI(Game.instance().uiRoot) + }).catch((err: Error) => { + // Without its UI the editor is a blank page: say why rather than leave it at that + Game.instance().logger?.error(`The editor's UI could not be loaded: ${err?.stack ?? err}`) }) } @@ -116,6 +123,7 @@ export default class Editor extends EventEmitter implements IEditor, GameObjectI Game.instance().renderer.composer.addPass(this.outlinePass) this.initFlyControls() + this.networkOverlay = new NetworkOverlay() this.watchScene(Game.instance().activeScene) Game.instance().on('sceneLoaded', (scene: GameScene) => { @@ -412,6 +420,7 @@ export default class Editor extends EventEmitter implements IEditor, GameObjectI update(delta: number): void { this.updateCamera(delta) this.helpers.forEach(h => h.update(delta)) + this.networkOverlay.update() } updateCamera(delta: number) { @@ -432,6 +441,7 @@ export default class Editor extends EventEmitter implements IEditor, GameObjectI this.abort.abort() this.reactRoot.unmount() this.outlinePass.dispose() + this.networkOverlay.dispose() this.shadeOverrideMaterials.forEach(m => m.dispose()) this.shadeOverrideMaterials.clear() this.originalMaterials.clear() diff --git a/packages/editor/src/Editor/Network/NetworkOverlay.ts b/packages/editor/src/Editor/Network/NetworkOverlay.ts new file mode 100644 index 0000000..66d2eb6 --- /dev/null +++ b/packages/editor/src/Editor/Network/NetworkOverlay.ts @@ -0,0 +1,297 @@ +import type { ServerEntityView } from '@mavonengine/core/Networking/Client/NetworkManager' +import type { SyncSnapshot } from '@mavonengine/core/Networking/Debug/sync' +import Game from '@mavonengine/core/Game' +import EventEmitter from '@mavonengine/core/Utils/EventEmitter' +import { + BoxGeometry, + BufferGeometry, + EdgesGeometry, + Float32BufferAttribute, + Group, + Line, + LineBasicMaterial, + LineLoop, + LineSegments, +} from 'three' +import SyncStore from './SyncStore' + +export interface NetworkOverlayOptions { + /** A wireframe box per networked entity, where the server last said it is */ + ghosts: boolean + /** A ring around each player at the server's sync distance */ + rings: boolean + /** Colour the ghosts by what this player is sent, instead of by what any player is */ + viewAs: string | null +} + +export type GhostState = 'synced' | 'stale' | 'untracked' + +export const GHOST_COLORS: Record = { + /** In the newest state update */ + synced: 0x4EC9B0, + /** Known to this client, but not in the newest state update */ + stale: 0xCE9178, + /** No player (or not the viewed one) is sent it */ + untracked: 0x888888, +} + +const RING_COLOR = 0x007ACC +const RING_SELECTED_COLOR = 0xFFFFFF +const ERROR_COLOR = 0xF44747 +const RING_SEGMENTS = 96 +/** A ghost whose entity left the client's world is hidden once its state is this old, in ms */ +const ORPHAN_GHOST_MS = 2000 +/** Distance between the server's position and the rendered one from which the error line is drawn */ +const ERROR_EPSILON = 0.01 +const STORAGE_KEY = 'editor-network-overlay' + +interface Ghost { + box: LineSegments + /** From the server's position to where the client renders the entity */ + error: Line +} + +/** + * How a ghost is coloured: by the server's sync when it is known, otherwise by what this client last received. + */ +export function ghostState(view: ServerEntityView, newestTick: number | null, sync?: SyncSnapshot, viewAs?: string | null): GhostState { + if (sync) { + const player = viewAs ? sync.players.find(p => p.id === viewAs) : undefined + if (player) + return player.id === view.id || player.tracked.includes(view.id) ? 'synced' : 'untracked' + + const entity = sync.entities.find(e => e.id === view.id) + if (entity && !entity.player && entity.trackedBy === 0 && sync.players.length > 0) + return 'untracked' + } + + return newestTick !== null && newestTick - view.tick > 1 ? 'stale' : 'synced' +} + +function loadOptions(): NetworkOverlayOptions { + const defaults: NetworkOverlayOptions = { ghosts: false, rings: false, viewAs: null } + try { + return { ...defaults, ...JSON.parse(localStorage.getItem(STORAGE_KEY) ?? '{}'), viewAs: null } + } + catch { + return defaults + } +} + +/** + * Draws the network state into the editor's viewport: where the server says each entity is (ghosts) + * and how far each player's state sync reaches (rings). + * + * Triggers `changed` when its options change. + */ +export default class NetworkOverlay extends EventEmitter { + readonly sync: SyncStore + readonly group = new Group() + + private _options: NetworkOverlayOptions + private ghosts = new Map() + private rings = new Map() + private unsubscribe?: () => void + + private boxGeometry: BufferGeometry + private ringGeometry: BufferGeometry + private materials: Record + private errorMaterial = overlayMaterial(ERROR_COLOR) + private ringMaterial = overlayMaterial(RING_COLOR) + private ringSelectedMaterial = overlayMaterial(RING_SELECTED_COLOR) + + constructor(sync = new SyncStore(), options: NetworkOverlayOptions = loadOptions()) { + super() + this.sync = sync + this._options = options + + this.group.name = 'NetworkOverlay' + this.group.userData.isEditorInternal = true + + // A unit box standing on its origin, like most entities do + const box = new BoxGeometry(1, 1, 1) + box.translate(0, 0.5, 0) + this.boxGeometry = new EdgesGeometry(box) + box.dispose() + + const circle: number[] = [] + for (let i = 0; i < RING_SEGMENTS; i++) { + const angle = (i / RING_SEGMENTS) * Math.PI * 2 + circle.push(Math.cos(angle), 0, Math.sin(angle)) + } + this.ringGeometry = new BufferGeometry().setAttribute('position', new Float32BufferAttribute(circle, 3)) + + this.materials = { + synced: overlayMaterial(GHOST_COLORS.synced), + stale: overlayMaterial(GHOST_COLORS.stale), + untracked: overlayMaterial(GHOST_COLORS.untracked), + } + + this.applyOptions() + } + + get options(): Readonly { + return this._options + } + + setOptions(options: Partial) { + this._options = { ...this._options, ...options } + try { + localStorage.setItem(STORAGE_KEY, JSON.stringify({ ghosts: this._options.ghosts, rings: this._options.rings })) + } + catch { + // Not remembered, e.g. storage is blocked + } + + this.applyOptions() + this.trigger('changed', this._options) + } + + private get active() { + return this._options.ghosts || this._options.rings + } + + private applyOptions() { + const scene = Game.instance().scene + + if (this.active && !this.group.parent) { + scene.add(this.group) + // The overlay only asks the server while something is drawn + this.unsubscribe = this.sync.subscribe(() => { }) + } + else if (!this.active && this.group.parent) { + scene.remove(this.group) + this.unsubscribe?.() + this.unsubscribe = undefined + } + } + + update() { + if (!this.active) + return + + // A scene reload clears the scene, put the overlay back + if (!this.group.parent) + Game.instance().scene.add(this.group) + + this.updateGhosts() + this.updateRings() + } + + private updateGhosts() { + const network = Game.instance().network + const view = this._options.ghosts ? network?.serverView : undefined + const { sync } = this.sync.get() + const entities = Game.instance().world.entities.items + const now = performance.now() + const seen = new Set() + + for (const entity of view?.entities.values() ?? []) { + const rendered = entities.get(entity.id) + if (!rendered && now - entity.receivedAt > ORPHAN_GHOST_MS) + continue + + seen.add(entity.id) + const ghost = this.ghosts.get(entity.id) ?? this.createGhost(entity.id) + + ghost.box.position.set(entity.position.x, entity.position.y, entity.position.z) + ghost.box.rotation.set(entity.rotation.x, entity.rotation.y, entity.rotation.z) + // 1 x 2 x 1 at scale 1, about a character: the ghost marks a transform, not the model's bounds + ghost.box.scale.set(entity.scale.x, entity.scale.y * 2, entity.scale.z) + ghost.box.material = this.materials[ghostState(entity, view!.tick, sync, this._options.viewAs)] + + const off = rendered ? rendered.position.distanceTo(ghost.box.position) : 0 + ghost.error.visible = off > ERROR_EPSILON + if (ghost.error.visible) { + const positions = ghost.error.geometry.getAttribute('position') + positions.setXYZ(0, entity.position.x, entity.position.y, entity.position.z) + positions.setXYZ(1, rendered!.position.x, rendered!.position.y, rendered!.position.z) + positions.needsUpdate = true + } + } + + for (const [id, ghost] of this.ghosts) { + if (seen.has(id)) + continue + this.group.remove(ghost.box, ghost.error) + ghost.error.geometry.dispose() + this.ghosts.delete(id) + } + } + + private createGhost(id: string): Ghost { + const box = unpickable(new LineSegments(this.boxGeometry, this.materials.synced)) + box.name = `ServerGhost:${id}` + + const geometry = new BufferGeometry().setAttribute('position', new Float32BufferAttribute([0, 0, 0, 0, 0, 0], 3)) + const error = unpickable(new Line(geometry, this.errorMaterial)) + error.frustumCulled = false + error.visible = false + + const ghost = { box, error } + this.group.add(box, error) + this.ghosts.set(id, ghost) + return ghost + } + + private updateRings() { + const { sync } = this.sync.get() + const players = this._options.rings && sync?.syncDistance ? sync.players : [] + const seen = new Set() + + for (const player of players) { + seen.add(player.id) + let ring = this.rings.get(player.id) + if (!ring) { + ring = unpickable(new LineLoop(this.ringGeometry, this.ringMaterial)) + ring.name = `SyncRing:${player.id}` + this.rings.set(player.id, ring) + this.group.add(ring) + } + + ring.position.set(player.position.x, player.position.y + 0.05, player.position.z) + ring.scale.setScalar(sync!.syncDistance!) + ring.material = player.id === this._options.viewAs ? this.ringSelectedMaterial : this.ringMaterial + } + + for (const [id, ring] of this.rings) { + if (seen.has(id)) + continue + this.group.remove(ring) + this.rings.delete(id) + } + } + + /** How many ghosts and rings are drawn */ + get counts() { + return { ghosts: this.ghosts.size, rings: this.rings.size } + } + + dispose() { + this.unsubscribe?.() + this.unsubscribe = undefined + this.group.removeFromParent() + this.ghosts.forEach(ghost => ghost.error.geometry.dispose()) + this.ghosts.clear() + this.rings.clear() + this.boxGeometry.dispose() + this.ringGeometry.dispose() + Object.values(this.materials).forEach(material => material.dispose()) + this.errorMaterial.dispose() + this.ringMaterial.dispose() + this.ringSelectedMaterial.dispose() + } +} + +/** Drawn over the scene, so a ghost inside a mesh or behind a wall still shows */ +function overlayMaterial(color: number) { + return new LineBasicMaterial({ color, depthTest: false, depthWrite: false, transparent: true, toneMapped: false }) +} + +/** The overlay is never selected by a click in the viewport */ +function unpickable(object: T): T { + object.raycast = () => { } + object.renderOrder = 999 + object.userData.isEditorInternal = true + return object +} diff --git a/packages/editor/src/Editor/Network/SyncStore.ts b/packages/editor/src/Editor/Network/SyncStore.ts new file mode 100644 index 0000000..120b5fe --- /dev/null +++ b/packages/editor/src/Editor/Network/SyncStore.ts @@ -0,0 +1,61 @@ +import type { SyncSnapshot } from '@mavonengine/core/Networking/Debug/sync' +import { fetchSync } from './serverApi' + +export interface SyncState { + /** The server's state sync, undefined until the first answer or after a failed one */ + sync?: SyncSnapshot + error?: string +} + +/** + * The server's state sync, asked for a few times a second while something listens: the sync overlay or the Network panel. + */ +export default class SyncStore { + private state: SyncState = {} + private listeners = new Set<() => void>() + private timer?: ReturnType + private loading = false + + constructor(private intervalMs = 250, private load: () => Promise = fetchSync) { } + + /** Stable until the next answer, for `useSyncExternalStore` */ + get = (): SyncState => this.state + + subscribe = (listener: () => void): (() => void) => { + this.listeners.add(listener) + if (!this.timer) { + this.timer = setInterval(() => void this.refresh(), this.intervalMs) + void this.refresh() + } + + return () => { + this.listeners.delete(listener) + if (!this.listeners.size && this.timer) { + clearInterval(this.timer) + this.timer = undefined + } + } + } + + async refresh() { + if (this.loading) + return + this.loading = true + + try { + this.state = { sync: await this.load() } + } + catch (err) { + // Keep answering with the same error object, so listeners don't re-render on every failed poll + const error = (err as Error).message + if (this.state.error === error && !this.state.sync) + return + this.state = { error } + } + finally { + this.loading = false + } + + this.listeners.forEach(listener => listener()) + } +} diff --git a/packages/editor/src/Editor/Network/serverApi.ts b/packages/editor/src/Editor/Network/serverApi.ts new file mode 100644 index 0000000..ec84eef --- /dev/null +++ b/packages/editor/src/Editor/Network/serverApi.ts @@ -0,0 +1,58 @@ +import type { NetRecordDetail, NetRecordList, NetRecordQuery } from '@mavonengine/core/Networking/Debug/NetRecorder' +import type { SyncSnapshot } from '@mavonengine/core/Networking/Debug/sync' + +/** + * The game server's network debug endpoints (GET /api/game/dev/net/*), read by the editor. + * + * They are asked on the page's own origin, which is where the game server serves the client in dev. + * For a client served elsewhere, put the server's URL in `localStorage['mavonengine:server-url']`; + * the server then has to allow that origin (CORS). + */ +export const SERVER_URL_KEY = 'mavonengine:server-url' + +const TRAILING_SLASH_RE = /\/$/ + +export function serverUrl(): string { + try { + return (localStorage.getItem(SERVER_URL_KEY) ?? '').replace(TRAILING_SLASH_RE, '') + } + catch { + return '' + } +} + +async function get(path: string, params: Record = {}, fetchFn: typeof fetch = fetch): Promise { + const search = new URLSearchParams() + for (const [key, value] of Object.entries(params)) { + if (value !== undefined && value !== '') + search.set(key, String(value)) + } + const query = search.toString() + + let res: Response + try { + res = await fetchFn(`${serverUrl()}/api/game/dev/net/${path}${query ? `?${query}` : ''}`) + } + catch { + throw new Error('The game server is not reachable') + } + + if (res.status === 404 || !res.headers.get('content-type')?.includes('application/json')) + throw new Error('The game server has no network debug endpoints here. They are served in development, on the origin of this page') + if (!res.ok) + throw new Error(`The game server answered ${res.status} ${res.statusText}`) + + return res.json() as Promise +} + +export function fetchSync(fetchFn?: typeof fetch) { + return get('sync', {}, fetchFn) +} + +export function fetchPackets(query: NetRecordQuery, fetchFn?: typeof fetch) { + return get('packets', { ...query }, fetchFn) +} + +export async function fetchPacket(id: number, fetchFn?: typeof fetch) { + return (await get<{ record: NetRecordDetail | null }>(`packets/${id}`, {}, fetchFn)).record +} diff --git a/packages/editor/src/Editor/UI/Network/NetworkPanel.module.css b/packages/editor/src/Editor/UI/Network/NetworkPanel.module.css new file mode 100644 index 0000000..f0ed6fc --- /dev/null +++ b/packages/editor/src/Editor/UI/Network/NetworkPanel.module.css @@ -0,0 +1,205 @@ +.root { + display: flex; + flex-direction: column; + gap: var(--spacing-md); + height: 100%; + min-height: 0; + font-size: var(--font-size-sm); + color: var(--text-primary); +} + +.toolbar { + display: flex; + flex-wrap: wrap; + align-items: center; + gap: var(--spacing-md); +} + +.toolbar select, +.toolbar input[type='search'], +.toolbar button { + background-color: var(--bg-input); + border: 1px solid var(--border-primary); + border-radius: var(--radius-sm); + color: var(--text-primary); + font-family: var(--font-ui); + font-size: var(--font-size-sm); + padding: 2px var(--spacing-md); +} + +.toolbar button { + background-color: var(--bg-active); + border-color: var(--border-active); + cursor: pointer; +} + +.toolbar button:hover { + background-color: var(--bg-hover); +} + +.toolbar label { + display: flex; + align-items: center; + gap: var(--spacing-sm); + color: var(--text-label); + white-space: nowrap; + cursor: pointer; +} + +.spacer { + flex: 1; +} + +.status { + display: flex; + align-items: center; + gap: var(--spacing-sm); + color: var(--text-secondary); + font-family: var(--font-mono); + white-space: nowrap; +} + +.dotOn, +.dotOff { + width: 6px; + height: 6px; + border-radius: 50%; + background-color: var(--accent-green); +} + +.dotOff { + background-color: var(--accent-red); +} + +.timeline { + width: 100%; + flex-shrink: 0; + background-color: var(--bg-input); + border-radius: var(--radius-sm); +} + +.body { + display: flex; + gap: var(--spacing-lg); + flex: 1; + min-height: 0; +} + +.records { + flex: 2; + min-width: 0; + overflow: auto; +} + +.side { + flex: 1; + min-width: 200px; + overflow: auto; + border-left: 1px solid var(--border-primary); + padding-left: var(--spacing-lg); +} + +.table { + width: 100%; + border-collapse: collapse; + font-family: var(--font-mono); + font-variant-numeric: tabular-nums; +} + +.table th { + text-align: left; + font-weight: normal; + color: var(--text-muted); + padding: 1px var(--spacing-md) 1px 0; +} + +.table td { + padding: 1px var(--spacing-md) 1px 0; + white-space: nowrap; +} + +.table tbody tr { + cursor: pointer; +} + +.table tbody tr:hover { + background-color: var(--bg-hover); +} + +.table tbody tr.selected { + background-color: var(--bg-selected); +} + +.time { + color: var(--text-muted); +} + +.out .arrow { + color: var(--accent-blue); +} + +.in .arrow { + color: var(--accent-green); +} + +.event .arrow, +.event .type { + color: var(--accent-yellow); +} + +.peer { + max-width: 90px; + overflow: hidden; + text-overflow: ellipsis; + color: var(--text-secondary); +} + +.bytes { + text-align: right; + color: var(--text-label); +} + +.info { + width: 100%; + color: var(--text-secondary); +} + +.sectionTitle { + font-size: var(--font-size-xs); + color: var(--text-muted); + text-transform: uppercase; + letter-spacing: 0.04em; + margin-bottom: var(--spacing-md); +} + +.payload { + margin: 0; + font-family: var(--font-mono); + font-size: var(--font-size-sm); + color: var(--text-label); + white-space: pre-wrap; + word-break: break-word; + user-select: text; +} + +.sync { + display: flex; + flex-direction: column; + gap: var(--spacing-md); +} + +.syncSummary { + color: var(--text-label); + line-height: 1.5; +} + +.note { + color: var(--text-secondary); + line-height: 1.5; +} + +.error { + color: var(--accent-yellow); + line-height: 1.5; + margin-bottom: var(--spacing-md); +} diff --git a/packages/editor/src/Editor/UI/Network/NetworkPanel.tsx b/packages/editor/src/Editor/UI/Network/NetworkPanel.tsx new file mode 100644 index 0000000..d9ae23a --- /dev/null +++ b/packages/editor/src/Editor/UI/Network/NetworkPanel.tsx @@ -0,0 +1,238 @@ +import type { NetRecord } from '@mavonengine/core/Networking/Debug/NetRecorder' +import type NetworkOverlay from '../../Network/NetworkOverlay' +import type { NetworkOverlayOptions } from '../../Network/NetworkOverlay' +import type { RecordFilter } from './format' +import type { RecordSource } from './useRecords' +import { useEffect, useMemo, useState, useSyncExternalStore } from 'react' +import { describeRecord, filterRecords, formatBytes, formatTime } from './format' +import styles from './NetworkPanel.module.css' +import Timeline, { laneOf } from './Timeline' +import { useRecordDetail, useRecords } from './useRecords' + +const ARROWS = { out: '↑', in: '↓', event: '•' } + +function overlay(): NetworkOverlay | undefined { + return (window.Game.editor as { networkOverlay?: NetworkOverlay } | undefined)?.networkOverlay +} + +function useOverlayOptions(): [NetworkOverlayOptions | undefined, (options: Partial) => void] { + const target = overlay() + const [options, setOptions] = useState(target?.options) + + useEffect(() => { + if (!target) + return + target.on('changed', setOptions) + return () => target.off('changed', setOptions) + }, [target]) + + return [options, changes => target?.setOptions(changes)] +} + +/** Connection of this tab, read a few times a second */ +function useConnection() { + const read = () => { + const network = window.Game.network + if (!network) + return undefined + const { tick, receivedAt, missedStates } = network.serverView + return { + connected: network.connected, + ping: network.ping, + tick, + stateAge: receivedAt === null ? null : Math.round(performance.now() - receivedAt), + missedStates, + } + } + + const [connection, setConnection] = useState(read) + useEffect(() => { + const timer = setInterval(() => setConnection(read()), 500) + return () => clearInterval(timer) + }, []) + + return connection +} + +function Status() { + const connection = useConnection() + if (!connection) + return This tab has no game connection + + return ( + + + {connection.connected ? `${connection.ping} ms` : 'disconnected'} + {connection.tick !== null && ` · tick ${connection.tick}`} + {connection.stateAge !== null && ` · state ${connection.stateAge} ms ago`} + {connection.missedStates > 0 && ` · ${connection.missedStates} missed`} + + ) +} + +function SyncTable({ viewAs, onViewAs }: { viewAs: string | null, onViewAs(id: string | null): void }) { + const store = overlay()?.sync + const { sync, error } = useSyncExternalStore(store?.subscribe ?? (() => () => { }), store?.get ?? (() => ({} as { sync?: undefined, error?: string }))) + + if (!sync) + return
{error ?? 'Asking the server…'}
+ + const untracked = sync.entities.filter(entity => !entity.player && entity.trackedBy === 0).length + + return ( +
+
+ {`Tick ${sync.tick} · ${sync.tickRate} Hz · sync distance ${sync.syncDistance ?? 'unknown'} · ${sync.entities.length} synced entities`} + {untracked > 0 && sync.players.length > 0 && `, ${untracked} out of every player's range`} + {sync.editors.length > 0 && ` · ${sync.editors.length} editor${sync.editors.length > 1 ? 's' : ''}`} +
+ + {sync.players.length === 0 + ?
No players connected
+ : ( + + + + + + + + + + + {sync.players.map(player => ( + onViewAs(player.id === viewAs ? null : player.id)} + > + + + + + + ))} + +
PlayerTrackedAckLast state
{player.displayName}{player.tracked.length}{player.ack}{player.lastState ? `${formatBytes(player.lastState.bytes)} · tick ${player.lastState.tick}` : 'none'}
+ )} +
+ ) +} + +function RecordRow({ record, selected, onSelect }: { record: NetRecord, selected: boolean, onSelect(): void }) { + const lane = laneOf(record) + return ( + + {formatTime(record.timestamp)} + {ARROWS[lane]} + {record.type} + {record.peer} + {record.kind === 'packet' ? formatBytes(record.bytes) : ''} + {describeRecord(record)} + + ) +} + +/** + * The editor's Network panel: packets and network events of the server or of this tab, a timeline of them, + * the server's state sync, and the switches of the viewport overlay. + */ +export default function NetworkPanel() { + const [source, setSource] = useState('server') + const [paused, setPaused] = useState(false) + const [filter, setFilter] = useState({ kind: 'all', pings: false, text: '' }) + const [selectedId, setSelectedId] = useState() + const [options, setOptions] = useOverlayOptions() + + const { records, error, clear } = useRecords(source, paused) + const visible = useMemo(() => filterRecords(records, filter), [records, filter]) + const detail = useRecordDetail(source, selectedId) + + const changeSource = (next: RecordSource) => { + setSource(next) + setSelectedId(undefined) + } + + return ( +
+
+ + + setFilter({ ...filter, text: event.target.value })} + /> + + + + + {options && ( + <> + + + + )} + +
+ + + +
+
+ {error &&
{error}
} + {!error && visible.length === 0 &&
No packets yet
} + + + {visible.slice(-300).reverse().map(record => ( + setSelectedId(record.id === selectedId ? undefined : record.id)} + /> + ))} + +
+
+ +
+ {selectedId !== undefined + ? ( + <> +
{`Record ${selectedId}`}
+ {detail === undefined &&
Loading…
} + {detail === null &&
This record is no longer kept
} + {detail && !detail.hasPayload &&
{detail.kind === 'event' ? describeRecord(detail) || 'No details' : 'The payload is no longer kept'}
} + {detail?.hasPayload &&
{JSON.stringify(detail.payload, null, 2)}
} + + ) + : ( + <> +
State sync
+ setOptions({ viewAs: id })} /> + + )} +
+
+
+ ) +} diff --git a/packages/editor/src/Editor/UI/Network/Timeline.tsx b/packages/editor/src/Editor/UI/Network/Timeline.tsx new file mode 100644 index 0000000..245cece --- /dev/null +++ b/packages/editor/src/Editor/UI/Network/Timeline.tsx @@ -0,0 +1,76 @@ +import type { NetRecord } from '@mavonengine/core/Networking/Debug/NetRecorder' +import { useEffect, useRef } from 'react' +import styles from './NetworkPanel.module.css' + +const LANES = ['out', 'in', 'event'] as const +const COLORS = { out: '#007ACC', in: '#4EC9B0', event: '#DCDCAA', selected: '#FFFFFF', grid: '#333333', label: '#666666' } +const LANE_HEIGHT = 16 +const LABEL_WIDTH = 40 +const HEIGHT = LANES.length * LANE_HEIGHT + +export function laneOf(record: NetRecord): typeof LANES[number] { + return record.kind === 'event' ? 'event' : record.direction ?? 'out' +} + +/** + * The last `windowMs` of traffic as marks on three lanes: sent, received and events. Taller marks are larger packets. + * While `live` the newest moment sits at the right edge and the marks scroll; paused it ends at the last record. + */ +export default function Timeline({ records, selectedId, live, windowMs = 10000 }: { records: NetRecord[], selectedId?: number, live: boolean, windowMs?: number }) { + const canvas = useRef(null) + + useEffect(() => { + const draw = () => { + const element = canvas.current + const context = element?.getContext?.('2d') + if (!element || !context) + return + + const ratio = window.devicePixelRatio || 1 + const width = element.clientWidth + if (element.width !== width * ratio || element.height !== HEIGHT * ratio) { + element.width = width * ratio + element.height = HEIGHT * ratio + } + context.setTransform(ratio, 0, 0, ratio, 0, 0) + context.clearRect(0, 0, width, HEIGHT) + + const end = live ? Date.now() : records.at(-1)?.timestamp ?? Date.now() + const start = end - windowMs + const span = width - LABEL_WIDTH + + context.font = '10px sans-serif' + context.textBaseline = 'middle' + LANES.forEach((lane, index) => { + context.fillStyle = COLORS.label + context.fillText(lane, 2, index * LANE_HEIGHT + LANE_HEIGHT / 2) + context.fillStyle = COLORS.grid + context.fillRect(LABEL_WIDTH, (index + 1) * LANE_HEIGHT - 1, span, 1) + }) + + // One line per second + for (let time = Math.ceil(start / 1000) * 1000; time <= end; time += 1000) + context.fillRect(LABEL_WIDTH + ((time - start) / windowMs) * span, 0, 1, HEIGHT) + + for (const record of records) { + if (record.timestamp < start || record.timestamp > end) + continue + const lane = laneOf(record) + const x = LABEL_WIDTH + ((record.timestamp - start) / windowMs) * span + // 4px for an empty packet up to the full lane from 2 kB on + const height = lane === 'event' ? LANE_HEIGHT - 4 : 4 + Math.min(1, (record.bytes ?? 0) / 2048) * (LANE_HEIGHT - 8) + const selected = record.id === selectedId + context.fillStyle = selected ? COLORS.selected : COLORS[lane] + context.fillRect(x - (selected ? 1 : 0), (LANES.indexOf(lane) + 1) * LANE_HEIGHT - 2 - height, selected ? 3 : lane === 'event' ? 2 : 1, height) + } + } + + draw() + if (!live) + return + const timer = setInterval(draw, 100) + return () => clearInterval(timer) + }, [records, selectedId, live, windowMs]) + + return +} diff --git a/packages/editor/src/Editor/UI/Network/format.ts b/packages/editor/src/Editor/UI/Network/format.ts new file mode 100644 index 0000000..acfc499 --- /dev/null +++ b/packages/editor/src/Editor/UI/Network/format.ts @@ -0,0 +1,51 @@ +import type { NetRecord } from '@mavonengine/core/Networking/Debug/NetRecorder' + +export function formatBytes(bytes: number | undefined): string { + if (bytes === undefined) + return '' + if (bytes < 1024) + return `${bytes} B` + return `${(bytes / 1024).toFixed(bytes < 10240 ? 2 : 1)} kB` +} + +/** Local time with milliseconds, e.g. 14:02:11.123 */ +export function formatTime(timestamp: number): string { + const date = new Date(timestamp) + const pad = (value: number, length = 2) => String(value).padStart(length, '0') + return `${pad(date.getHours())}:${pad(date.getMinutes())}:${pad(date.getSeconds())}.${pad(date.getMilliseconds(), 3)}` +} + +/** The facts of a record in one line: tick, sequence id and what `info` holds */ +export function describeRecord(record: NetRecord): string { + const parts: string[] = [] + if (record.tick !== undefined) + parts.push(`tick ${record.tick}`) + if (record.sequenceId !== undefined) + parts.push(`seq ${record.sequenceId}`) + if (record.reliable) + parts.push('reliable') + + for (const [key, value] of Object.entries(record.info ?? {})) { + if (value === undefined || value === null) + continue + parts.push(`${key} ${Array.isArray(value) ? value.join(', ') : String(value)}`) + } + + return parts.join(' · ') +} + +export interface RecordFilter { + kind: 'all' | 'packet' | 'event' + /** ping / pong: one pair a second per client */ + pings: boolean + /** Part of the message name or the peer, case-insensitive */ + text: string +} + +export function filterRecords(records: NetRecord[], { kind, pings, text }: RecordFilter): NetRecord[] { + const needle = text.trim().toLowerCase() + return records.filter(record => + (kind === 'all' || record.kind === kind) + && (pings || (record.type !== 'ping' && record.type !== 'pong')) + && (!needle || record.type.toLowerCase().includes(needle) || !!record.peer?.toLowerCase().includes(needle))) +} diff --git a/packages/editor/src/Editor/UI/Network/useRecords.ts b/packages/editor/src/Editor/UI/Network/useRecords.ts new file mode 100644 index 0000000..3fd7b94 --- /dev/null +++ b/packages/editor/src/Editor/UI/Network/useRecords.ts @@ -0,0 +1,89 @@ +import type { NetRecord, NetRecordDetail, NetRecordList } from '@mavonengine/core/Networking/Debug/NetRecorder' +import { useEffect, useRef, useState } from 'react' +import { fetchPacket, fetchPackets } from '../../Network/serverApi' + +/** Whose records are shown: everything the server sent and received, or only this tab's own traffic */ +export type RecordSource = 'server' | 'client' + +const MAX_ROWS = 1000 +const POLL_MS = 500 +const NOT_CONNECTED = 'This tab is not connected to a game server' + +async function list(source: RecordSource, after: number): Promise { + if (source === 'server') + return fetchPackets({ after, limit: MAX_ROWS }) + + const net = window.Game.network?.net + if (!net) + throw new Error(NOT_CONNECTED) + return net.list({ after, limit: MAX_ROWS }) +} + +/** + * The newest records of one side, oldest first, kept up to date while not paused + */ +export function useRecords(source: RecordSource, paused: boolean) { + const [records, setRecords] = useState([]) + const [error, setError] = useState() + const after = useRef(0) + + useEffect(() => { + after.current = 0 + setRecords([]) + setError(undefined) + }, [source]) + + useEffect(() => { + if (paused) + return + + let cancelled = false + const poll = async () => { + try { + const result = await list(source, after.current) + if (cancelled) + return + after.current = result.latestId + if (result.records.length) + setRecords(previous => [...previous, ...result.records].slice(-MAX_ROWS)) + setError(result.enabled ? undefined : 'Nothing is being recorded on this side') + } + catch (err) { + if (!cancelled) + setError((err as Error).message) + } + } + + void poll() + const timer = setInterval(() => void poll(), POLL_MS) + return () => { + cancelled = true + clearInterval(timer) + } + }, [source, paused]) + + return { records, error, clear: () => setRecords([]) } +} + +/** One record with its payload, undefined while it loads or when nothing is selected */ +export function useRecordDetail(source: RecordSource, id: number | undefined) { + const [detail, setDetail] = useState() + + useEffect(() => { + setDetail(undefined) + if (id === undefined) + return + + let cancelled = false + const load = source === 'server' + ? fetchPacket(id) + : Promise.resolve(window.Game.network?.net.get(id) ?? null) + load.then(record => !cancelled && setDetail(record), () => !cancelled && setDetail(null)) + + return () => { + cancelled = true + } + }, [source, id]) + + return detail +} diff --git a/packages/editor/src/Editor/mount.ts b/packages/editor/src/Editor/mount.ts index b6183e0..220bd14 100644 --- a/packages/editor/src/Editor/mount.ts +++ b/packages/editor/src/Editor/mount.ts @@ -1,9 +1,14 @@ import type { Root } from 'react-dom/client' import { createElement } from 'react' import { createRoot } from 'react-dom/client' +import { registerEditorPanel } from './panels' import EditorUI from './UI/Editor' +import NetworkPanel from './UI/Network/NetworkPanel' export function mountEditorUI(container: HTMLElement): Root { + // Docked like a custom panel, so it only asks the server while its tab is shown. Before the game's own panels + registerEditorPanel({ id: 'network', title: 'Network', location: 'bottom', order: -1, component: NetworkPanel }) + const root = createRoot(container) root.render(createElement(EditorUI)) return root diff --git a/packages/editor/tests/Editor/Network/NetworkOverlay.test.ts b/packages/editor/tests/Editor/Network/NetworkOverlay.test.ts new file mode 100644 index 0000000..5052bf7 --- /dev/null +++ b/packages/editor/tests/Editor/Network/NetworkOverlay.test.ts @@ -0,0 +1,217 @@ +// @vitest-environment jsdom + +import type { ServerEntityView } from '@mavonengine/core/Networking/Client/NetworkManager' +import type { SyncSnapshot } from '@mavonengine/core/Networking/Debug/sync' +import Game from '@mavonengine/core/Game' +import { Scene, Vector3 } from 'three' +import { beforeEach, describe, expect, it, vi } from 'vitest' +import NetworkOverlay, { ghostState } from '../../../src/Editor/Network/NetworkOverlay' +import SyncStore from '../../../src/Editor/Network/SyncStore' + +// The real Game pulls in the renderer, which needs a canvas +vi.mock('@mavonengine/core/Game', () => ({ default: { instance: vi.fn() } })) + +const at = (x: number) => ({ x, y: 0, z: 0 }) + +function view(id: string, x: number, tick: number, receivedAt = performance.now()): ServerEntityView { + return { id, type: 'rock', position: at(x), rotation: at(0), scale: { x: 1, y: 1, z: 1 }, tick, receivedAt } +} + +function snapshot(overrides: Partial = {}): SyncSnapshot { + return { + tick: 10, + serverTime: 0, + tickRate: 30, + syncDistance: 50, + players: [ + { id: 'p1', displayName: 'Ada', position: at(0), ack: 0, tracked: ['p1', 'rock'], lastState: null }, + { id: 'p2', displayName: 'Bob', position: at(200), ack: 0, tracked: ['p2'], lastState: null }, + ], + editors: [], + entities: [ + { id: 'rock', type: 'rock', position: at(1), rotation: at(0), scale: at(1), player: false, needsSync: false, trackedBy: 1, lastSentTick: 10 }, + { id: 'tree', type: 'tree', position: at(900), rotation: at(0), scale: at(1), player: false, needsSync: false, trackedBy: 0, lastSentTick: null }, + ], + ...overrides, + } +} + +describe('ghostState', () => { + it('goes by what this client received when the server\'s sync is unknown', () => { + expect(ghostState(view('rock', 0, 10), 10)).toBe('synced') + expect(ghostState(view('rock', 0, 9), 10)).toBe('synced') + expect(ghostState(view('rock', 0, 5), 10)).toBe('stale') + expect(ghostState(view('rock', 0, 5), null)).toBe('synced') + }) + + it('marks entities no player is sent', () => { + expect(ghostState(view('tree', 0, 10), 10, snapshot())).toBe('untracked') + expect(ghostState(view('rock', 0, 10), 10, snapshot())).toBe('synced') + // Without players nothing is tracked, which says nothing about the entity + expect(ghostState(view('tree', 0, 10), 10, snapshot({ players: [] }))).toBe('synced') + }) + + it('goes by one player when viewing as it', () => { + expect(ghostState(view('rock', 0, 10), 10, snapshot(), 'p1')).toBe('synced') + expect(ghostState(view('rock', 0, 10), 10, snapshot(), 'p2')).toBe('untracked') + expect(ghostState(view('p2', 0, 10), 10, snapshot(), 'p2')).toBe('synced') + // A player that left: back to everyone's view + expect(ghostState(view('rock', 0, 10), 10, snapshot(), 'gone')).toBe('synced') + }) +}) + +describe('networkOverlay', () => { + let scene: Scene + let serverView: { tick: number | null, entities: Map } + let entities: Map + let sync: SyncStore + + beforeEach(() => { + localStorage.clear() + scene = new Scene() + serverView = { tick: 10, entities: new Map() } + entities = new Map() + vi.mocked(Game.instance).mockReturnValue({ scene, network: { serverView }, world: { entities: { items: entities } } } as any) + sync = new SyncStore(1000, async () => snapshot()) + }) + + it('stays out of the scene and asks nothing until something is switched on', () => { + const load = vi.fn(async () => snapshot()) + const overlay = new NetworkOverlay(new SyncStore(1000, load)) + overlay.update() + + expect(scene.children).toHaveLength(0) + expect(load).not.toHaveBeenCalled() + + overlay.setOptions({ ghosts: true }) + expect(scene.children).toEqual([overlay.group]) + expect(overlay.group.userData.isEditorInternal).toBe(true) + expect(load).toHaveBeenCalledTimes(1) + + overlay.setOptions({ ghosts: false }) + expect(scene.children).toHaveLength(0) + overlay.dispose() + }) + + it('draws a ghost where the server said the entity is, with a line to where it is rendered', () => { + const overlay = new NetworkOverlay(sync, { ghosts: true, rings: false, viewAs: null }) + serverView.entities.set('rock', view('rock', 4, 10)) + entities.set('rock', { position: new Vector3(4, 0, 0) }) + + overlay.update() + + const ghost = overlay.group.getObjectByName('ServerGhost:rock')! + expect(ghost.position.x).toBe(4) + const line = overlay.group.children.find(child => child !== ghost)! + expect(line.visible).toBe(false) + + // The client renders it somewhere else than the server has it + entities.get('rock')!.position.set(6, 0, 0) + overlay.update() + expect(line.visible).toBe(true) + expect(Array.from((line as any).geometry.getAttribute('position').array)).toEqual([4, 0, 0, 6, 0, 0]) + + // Nothing in the overlay can be picked in the viewport + const hits: unknown[] = [] + ;(ghost as any).raycast({}, hits) + expect(hits).toEqual([]) + overlay.dispose() + }) + + it('colours ghosts by their sync state and removes ghosts of entities that are gone', async () => { + const overlay = new NetworkOverlay(sync, { ghosts: true, rings: false, viewAs: null }) + await sync.refresh() + serverView.entities.set('rock', view('rock', 1, 10)) + serverView.entities.set('tree', view('tree', 900, 10)) + entities.set('rock', { position: new Vector3(1, 0, 0) }) + entities.set('tree', { position: new Vector3(900, 0, 0) }) + + overlay.update() + const color = (id: string) => (overlay.group.getObjectByName(`ServerGhost:${id}`) as any).material.color.getHex() + expect(color('rock')).toBe(0x4EC9B0) + expect(color('tree')).toBe(0x888888) + + overlay.setOptions({ viewAs: 'p2' }) + overlay.update() + expect(color('rock')).toBe(0x888888) + + // Removed on the client and not heard of for a while + entities.delete('tree') + serverView.entities.set('tree', view('tree', 900, 3, performance.now() - 5000)) + overlay.update() + expect(overlay.counts.ghosts).toBe(1) + expect(overlay.group.getObjectByName('ServerGhost:tree')).toBeUndefined() + overlay.dispose() + }) + + it('draws a ring of the sync distance around each player', async () => { + const overlay = new NetworkOverlay(sync, { ghosts: false, rings: true, viewAs: 'p2' }) + await sync.refresh() + + overlay.update() + + expect(overlay.counts).toEqual({ ghosts: 0, rings: 2 }) + const ring = overlay.group.getObjectByName('SyncRing:p2')! + expect(ring.position.x).toBe(200) + expect(ring.scale.x).toBe(50) + expect((ring as any).material.color.getHex()).toBe(0xFFFFFF) + expect((overlay.group.getObjectByName('SyncRing:p1') as any).material.color.getHex()).toBe(0x007ACC) + + overlay.setOptions({ rings: false, ghosts: true }) + overlay.update() + expect(overlay.counts.rings).toBe(0) + overlay.dispose() + }) + + it('remembers what was switched on, and tells listeners', () => { + const overlay = new NetworkOverlay(sync) + const changed = vi.fn() + overlay.on('changed', changed) + + overlay.setOptions({ rings: true, viewAs: 'p1' }) + + expect(changed).toHaveBeenCalledWith({ ghosts: false, rings: true, viewAs: 'p1' }) + overlay.dispose() + + // The viewed player is not remembered: it may be gone next time + const next = new NetworkOverlay(sync) + expect(next.options).toEqual({ ghosts: false, rings: true, viewAs: null }) + next.dispose() + }) +}) + +describe('syncStore', () => { + it('asks while something listens and keeps the last answer', async () => { + vi.useFakeTimers() + const load = vi.fn(async () => snapshot()) + const store = new SyncStore(250, load) + const listener = vi.fn() + + const unsubscribe = store.subscribe(listener) + await vi.advanceTimersByTimeAsync(0) + expect(store.get().sync?.tick).toBe(10) + expect(listener).toHaveBeenCalledTimes(1) + + await vi.advanceTimersByTimeAsync(500) + expect(load).toHaveBeenCalledTimes(3) + + unsubscribe() + await vi.advanceTimersByTimeAsync(1000) + expect(load).toHaveBeenCalledTimes(3) + vi.useRealTimers() + }) + + it('reports why the server could not be asked, once', async () => { + const store = new SyncStore(250, async () => { + throw new Error('The game server is not reachable') + }) + const listener = vi.fn() + store.subscribe(listener)() + + await store.refresh() + await store.refresh() + + expect(store.get()).toEqual({ error: 'The game server is not reachable' }) + expect(listener).not.toHaveBeenCalled() + }) +}) diff --git a/packages/editor/tests/Editor/UI/NetworkPanel.test.tsx b/packages/editor/tests/Editor/UI/NetworkPanel.test.tsx new file mode 100644 index 0000000..723e4ed --- /dev/null +++ b/packages/editor/tests/Editor/UI/NetworkPanel.test.tsx @@ -0,0 +1,192 @@ +// @vitest-environment jsdom + +import NetRecorder from '@mavonengine/core/Networking/Debug/NetRecorder' +import { act, cleanup, fireEvent, render, screen } from '@testing-library/react' +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest' +import SyncStore from '../../../src/Editor/Network/SyncStore' +import { describeRecord, filterRecords, formatBytes, formatTime } from '../../../src/Editor/UI/Network/format' +import NetworkPanel from '../../../src/Editor/UI/Network/NetworkPanel' + +vi.mock('../../../src/Editor/UI/Network/NetworkPanel.module.css', () => ({ + default: new Proxy({}, { get: (_, key) => String(key) }), +})) + +const sync = { + tick: 40, + serverTime: 0, + tickRate: 30, + syncDistance: 100, + players: [{ id: 'p1', displayName: 'Ada', position: { x: 0, y: 0, z: 0 }, ack: 7, tracked: ['p1', 'rock'], lastState: { tick: 40, bytes: 2048, entities: 2 } }], + editors: ['e1'], + entities: [ + { id: 'rock', type: 'rock', player: false, trackedBy: 1 }, + { id: 'tree', type: 'tree', player: false, trackedBy: 0 }, + ], +} + +let net: NetRecorder +let overlay: { options: { ghosts: boolean, rings: boolean, viewAs: string | null }, setOptions: ReturnType, on: ReturnType, off: ReturnType, sync: SyncStore } +let fetchMock: ReturnType + +/** Let the polls that are under way finish and render */ +function settle() { + return act(async () => { + await vi.advanceTimersByTimeAsync(600) + }) +} + +beforeEach(() => { + vi.useFakeTimers() + net = new NetRecorder({ enabled: true }) + net.packet('out', 'command', { type: 'cl_move', sequenceId: 3 }) + net.packet('in', 'sv_state', { tick: 40, ack: 3, entities: [{ id: 'rock' }] }) + net.packet('out', 'ping', null) + net.event('state_gap', { tick: 42, info: { missed: 1 } }) + + overlay = { + options: { ghosts: false, rings: false, viewAs: null }, + setOptions: vi.fn(), + on: vi.fn(), + off: vi.fn(), + sync: new SyncStore(250, async () => sync as any), + } + + fetchMock = vi.fn(async () => new Response('', { status: 404 })) + vi.stubGlobal('fetch', fetchMock) + ;(window as any).Game = { + editor: { networkOverlay: overlay }, + network: { connected: true, ping: 23, net, serverView: { tick: 40, receivedAt: performance.now(), missedStates: 1 } }, + } +}) + +afterEach(() => { + cleanup() + vi.useRealTimers() + vi.unstubAllGlobals() +}) + +describe('networkPanel', () => { + it('explains when the server\'s records cannot be read', async () => { + render() + await settle() + + screen.getByText(/has no network debug endpoints here/) + expect(String(fetchMock.mock.calls[0][0])).toBe('/api/game/dev/net/packets?after=0&limit=1000') + }) + + it('lists the server\'s records, newest first', async () => { + fetchMock.mockImplementation(async () => Response.json({ + enabled: true, + latestId: 2, + matched: 2, + records: [ + { id: 1, timestamp: 0, kind: 'packet', direction: 'out', type: 'sv_state', peer: 'p1', bytes: 2048, tick: 40, info: { entities: 2, ack: 7 }, hasPayload: true }, + { id: 2, timestamp: 1, kind: 'event', type: 'sync_leave', peer: 'p1', info: { count: 1, entities: ['rock'] }, hasPayload: false }, + ], + })) + render() + await settle() + + const rows = screen.getAllByRole('row').map(row => row.textContent) + expect(rows[0]).toContain('sync_leave') + expect(rows[0]).toContain('count 1 · entities rock') + expect(rows[1]).toContain('sv_state') + expect(rows[1]).toContain('2.00 kB') + expect(rows[1]).toContain('tick 40 · entities 2 · ack 7') + }) + + it('shows this tab\'s own records, without pings unless asked, and a payload on click', async () => { + render() + fireEvent.change(screen.getByLabelText('Source'), { target: { value: 'client' } }) + await settle() + + expect(screen.queryByText('ping')).toBeNull() + screen.getByText('state_gap') + screen.getByText('seq 3 · command cl_move') + + fireEvent.click(screen.getByLabelText('Pings')) + screen.getByText('ping') + + fireEvent.change(screen.getByPlaceholderText('Filter by message or client'), { target: { value: 'sv_' } }) + expect(screen.queryByText('state_gap')).toBeNull() + expect(screen.queryByText('ping')).toBeNull() + + fireEvent.click(screen.getByText('sv_state')) + await settle() + expect(screen.getByText(/"ack": 3/).textContent).toContain('"id": "rock"') + }) + + it('stops reading while paused', async () => { + render() + fireEvent.change(screen.getByLabelText('Source'), { target: { value: 'client' } }) + await settle() + + fireEvent.click(screen.getByText('Pause')) + net.packet('in', 'sv_chat', { message: 'hi' }) + await settle() + expect(screen.queryByText('sv_chat')).toBeNull() + + fireEvent.click(screen.getByText('Resume')) + await settle() + screen.getByText('sv_chat') + + fireEvent.click(screen.getByText('Clear')) + expect(screen.queryByText('sv_chat')).toBeNull() + }) + + it('shows the connection and the state sync, and switches the overlay', async () => { + render() + await settle() + + screen.getByText(/23 ms · tick 40 · state \d+ ms ago · 1 missed/) + screen.getByText(/Tick 40 · 30 Hz · sync distance 100 · 2 synced entities, 1 out of every player's range · 1 editor/) + const player = screen.getByText('Ada').closest('tr')! + expect(player.textContent).toBe('Ada272.00 kB · tick 40') + + fireEvent.click(player) + expect(overlay.setOptions).toHaveBeenCalledWith({ viewAs: 'p1' }) + fireEvent.click(screen.getByLabelText('Server ghosts')) + expect(overlay.setOptions).toHaveBeenCalledWith({ ghosts: true }) + fireEvent.click(screen.getByLabelText('Sync radius')) + expect(overlay.setOptions).toHaveBeenCalledWith({ rings: true }) + }) + + it('says when the tab has no game connection', async () => { + delete (window as any).Game.network + render() + fireEvent.change(screen.getByLabelText('Source'), { target: { value: 'client' } }) + await settle() + + screen.getByText('This tab has no game connection') + screen.getByText('This tab is not connected to a game server') + }) +}) + +describe('format', () => { + it('formats sizes and times', () => { + expect(formatBytes(undefined)).toBe('') + expect(formatBytes(512)).toBe('512 B') + expect(formatBytes(1536)).toBe('1.50 kB') + expect(formatBytes(20480)).toBe('20.0 kB') + expect(formatTime(new Date(2026, 0, 1, 9, 5, 7, 42).getTime())).toBe('09:05:07.042') + }) + + it('describes a record in one line', () => { + expect(describeRecord({ id: 1, timestamp: 0, kind: 'packet', type: 'cl_init', reliable: true, hasPayload: true })).toBe('reliable') + expect(describeRecord({ id: 1, timestamp: 0, kind: 'event', type: 'connect', hasPayload: false })).toBe('') + }) + + it('filters records', () => { + const records = [ + { id: 1, timestamp: 0, kind: 'packet' as const, type: 'ping', peer: 'abc', hasPayload: false }, + { id: 2, timestamp: 0, kind: 'packet' as const, type: 'sv_state', peer: 'abc', hasPayload: true }, + { id: 3, timestamp: 0, kind: 'event' as const, type: 'connect', peer: 'xyz', hasPayload: false }, + ] + const ids = (filter: Parameters[1]) => filterRecords(records, filter).map(record => record.id) + + expect(ids({ kind: 'all', pings: false, text: '' })).toEqual([2, 3]) + expect(ids({ kind: 'all', pings: true, text: '' })).toEqual([1, 2, 3]) + expect(ids({ kind: 'event', pings: true, text: '' })).toEqual([3]) + expect(ids({ kind: 'all', pings: true, text: 'ABC' })).toEqual([1, 2]) + }) +}) diff --git a/packages/multiplayer-template/README.md b/packages/multiplayer-template/README.md index 161938b..5aadc08 100644 --- a/packages/multiplayer-template/README.md +++ b/packages/multiplayer-template/README.md @@ -122,7 +122,7 @@ Press `.` in the game to open the editor on the running game: the connection to | Command | Payload | |---|---| -| `SV_STATE` | `{ entities: [{ id, position, rotation, state, health, name }] }` | +| `SV_STATE` | `{ tick, serverTime, ack, entities: [{ id, position, rotation, state, health, name }] }`: `tick` counts server ticks, `ack` is the sequence id of the receiver's last processed input | | `SV_REMOVE_ENTITY` | `{ id: string }` | | `SV_CHAT` | `{ playerId, playerName, message }` | | `SV_TREES` | `{ positions, rotations, scales }` (flat typed arrays) |