diff --git a/app/game-engine/package.json b/app/game-engine/package.json index 0531cd16..e6bb87d8 100644 --- a/app/game-engine/package.json +++ b/app/game-engine/package.json @@ -98,6 +98,7 @@ "lint": "eslint .", "lint:fix": "eslint . --fix", "profile:npc-unification-memory": "node scripts/profile-npc-unification-memory.mjs", + "profile:npc-unification-timing": "node scripts/profile-npc-unification-timing.mjs", "test": "vitest run --config vitest.config.ts", "typecheck": "pnpm -w tsc7 -b app/game-engine/tsconfig.json" }, diff --git a/app/game-engine/scripts/profile-npc-unification-timing.mjs b/app/game-engine/scripts/profile-npc-unification-timing.mjs new file mode 100644 index 00000000..a12aa753 --- /dev/null +++ b/app/game-engine/scripts/profile-npc-unification-timing.mjs @@ -0,0 +1,42 @@ +import { spawn } from 'node:child_process'; +import path from 'node:path'; +import { fileURLToPath } from 'node:url'; + +const packageRoot = path.resolve(path.dirname(fileURLToPath(import.meta.url)), '..'); +const vitestPath = path.join(packageRoot, 'node_modules', 'vitest', 'vitest.mjs'); + +const child = spawn( + process.execPath, + [ + '--expose-gc', + vitestPath, + 'run', + '--config', + 'vitest.config.ts', + '--pool=threads', + '--maxWorkers=1', + 'test/npcScenarioUnificationBenchmark.test.ts', + ], + { + cwd: packageRoot, + env: { + ...process.env, + NPC_UNIFICATION_BENCHMARK: '1', + }, + stdio: 'inherit', + } +); + +child.once('error', (error) => { + console.error('[npc-unification-timing] failed to start benchmark', error); + process.exitCode = 1; +}); + +child.once('exit', (code, signal) => { + if (signal) { + console.error(`[npc-unification-timing] benchmark terminated by ${signal}`); + process.exitCode = 1; + return; + } + process.exitCode = code ?? 1; +}); diff --git a/app/game-engine/src/turn/reservedTurnHandler.ts b/app/game-engine/src/turn/reservedTurnHandler.ts index d7d23a0b..c9d4cf1a 100644 --- a/app/game-engine/src/turn/reservedTurnHandler.ts +++ b/app/game-engine/src/turn/reservedTurnHandler.ts @@ -753,6 +753,21 @@ export const createReservedTurnHandler = async (options: { blockedReason?: string; aiState?: ReturnType; }) => void; + onActionProfiled?: (payload: { + kind: 'nation' | 'general'; + generalId: number; + nationId: number | null; + officerLevel: number; + npcState: number; + year: number; + month: number; + requestedAction: string; + actionKey: string; + usedFallback: boolean; + usedAi: boolean; + aiDecisionDurationNs: bigint; + actionDurationNs: bigint; + }) => void; }): Promise => { const env = options.commandEnv ?? buildCommandEnv(options.scenarioConfig, options.unitSet); const itemRegistry = createItemModuleRegistry(await loadItemModules([...ITEM_KEYS])); @@ -1627,7 +1642,11 @@ export const createReservedTurnHandler = async (options: { hasReservedTurn = true; } let nationAiState: ReturnType | undefined; + let nationAiDecisionDurationNs = 0n; + let nationUsedAi = false; if (worldView && shouldUseAi(currentGeneral, context.world)) { + nationUsedAi = true; + const aiStartedAt = options.onActionProfiled ? process.hrtime.bigint() : 0n; sharedAi = new GeneralAI({ general: currentGeneral, city: currentCity, @@ -1647,6 +1666,9 @@ export const createReservedTurnHandler = async (options: { }); const ai = sharedAi; const candidate = ai.chooseNationTurn(nationCommand); + if (options.onActionProfiled) { + nationAiDecisionDurationNs = process.hrtime.bigint() - aiStartedAt; + } if (candidate) { if ( (process.env.CORE_AI_TRACE_GENERAL_IDS?.split(',') ?? []).includes( @@ -1690,7 +1712,11 @@ export const createReservedTurnHandler = async (options: { } nationAiState = ai.getDebugState(); } + const nationActionStartedAt = options.onActionProfiled ? process.hrtime.bigint() : 0n; const nationResult = runAction('nation', nationDefinitions, nationFallback, nationCommand, false); + const nationActionDurationNs = options.onActionProfiled + ? process.hrtime.bigint() - nationActionStartedAt + : 0n; // Ref persists the nation command here, but LazyVarUpdater only // clears its dirty flags: it does not replace the same PHP // General object's fractional values with the MariaDB INT row. @@ -1722,6 +1748,21 @@ export const createReservedTurnHandler = async (options: { ...(nationResult.blockedReason ? { blockedReason: nationResult.blockedReason } : {}), ...(nationAiState ? { aiState: nationAiState } : {}), }); + options.onActionProfiled?.({ + kind: 'nation', + generalId: currentGeneral.id, + nationId: currentNation?.id ?? null, + officerLevel: currentGeneral.officerLevel, + npcState: currentGeneral.npcState, + year: context.world.currentYear, + month: context.world.currentMonth, + requestedAction: nationCommand.action, + actionKey: nationResult.actionKey, + usedFallback: nationResult.usedFallback, + usedAi: nationUsedAi, + aiDecisionDurationNs: nationAiDecisionDurationNs, + actionDurationNs: nationActionDurationNs, + }); options.reservedTurns.shiftNationTurns(currentNation.id, currentGeneral.officerLevel, -1); } if (isBlocked && currentNation && currentGeneral.officerLevel >= 5) { @@ -1745,7 +1786,11 @@ export const createReservedTurnHandler = async (options: { } let generalAiState: ReturnType | undefined; let generalAutorunMode = false; + let generalAiDecisionDurationNs = 0n; + let generalUsedAi = false; if (!isBlocked && worldView && shouldUseAi(currentGeneral, context.world)) { + generalUsedAi = true; + const aiStartedAt = options.onActionProfiled ? process.hrtime.bigint() : 0n; const ai = sharedAi ?? new GeneralAI({ @@ -1766,6 +1811,9 @@ export const createReservedTurnHandler = async (options: { nationFallback, }); const candidate = ai.chooseGeneralTurn(generalCommand); + if (options.onActionProfiled) { + generalAiDecisionDurationNs = process.hrtime.bigint() - aiStartedAt; + } // Ref GeneralAI::calcDiplomacyState writes // nation_env.last_attackable for ordinary generals too. The // nation-turn path consumes this patch above, but most NPCs @@ -1818,6 +1866,7 @@ export const createReservedTurnHandler = async (options: { } generalAiState = ai.getDebugState(); } + const generalActionStartedAt = options.onActionProfiled ? process.hrtime.bigint() : 0n; const generalResult = isBlocked ? { actionKey: DEFAULT_ACTION, @@ -1826,6 +1875,9 @@ export const createReservedTurnHandler = async (options: { blockedReason: '블럭 대상자입니다.', } : runAction('general', generalDefinitions, generalFallback, generalCommand, true); + const generalActionDurationNs = options.onActionProfiled + ? process.hrtime.bigint() - generalActionStartedAt + : 0n; options.onActionResolved?.({ kind: 'general', generalId: currentGeneral.id, @@ -1837,6 +1889,21 @@ export const createReservedTurnHandler = async (options: { ...(generalResult.blockedReason ? { blockedReason: generalResult.blockedReason } : {}), ...(generalAiState ? { aiState: generalAiState } : {}), }); + options.onActionProfiled?.({ + kind: 'general', + generalId: currentGeneral.id, + nationId: currentNation?.id ?? null, + officerLevel: currentGeneral.officerLevel, + npcState: currentGeneral.npcState, + year: context.world.currentYear, + month: context.world.currentMonth, + requestedAction: generalCommand.action, + actionKey: generalResult.actionKey, + usedFallback: generalResult.usedFallback, + usedAi: generalUsedAi, + aiDecisionDurationNs: generalAiDecisionDurationNs, + actionDurationNs: generalActionDurationNs, + }); let nextTurnAt = 'nextTurnAt' in generalResult ? generalResult.nextTurnAt : undefined; options.reservedTurns.shiftGeneralTurns(currentGeneral.id, -1); diff --git a/app/game-engine/test/helpers/npcUnificationTimingProfiler.ts b/app/game-engine/test/helpers/npcUnificationTimingProfiler.ts new file mode 100644 index 00000000..5e9f01fc --- /dev/null +++ b/app/game-engine/test/helpers/npcUnificationTimingProfiler.ts @@ -0,0 +1,250 @@ +import os from 'node:os'; + +import type { createReservedTurnHandler } from '../../src/turn/reservedTurnHandler.js'; + +export type ProfiledAction = Parameters< + NonNullable[0]['onActionProfiled']> +>[0]; + +type DurationSeries = { + durationsNs: number[]; + totalNs: number; +}; + +type MonthBucket = { + year: number; + month: number; + generalTurns: number; + chiefGeneralTurns: number; + ordinaryGeneralTurns: number; + totalGeneralTurnNs: number; + aiDecisionCount: number; + aiDecisionNs: number; + commandCount: number; + commandExecutionNs: number; + activeNationCount: number; + generalCount: number; +}; + +const createSeries = (): DurationSeries => ({ durationsNs: [], totalNs: 0 }); + +const percentile = (values: readonly number[], ratio: number): number => { + if (values.length === 0) return 0; + const sorted = [...values].sort((left, right) => left - right); + const index = Math.min(sorted.length - 1, Math.max(0, Math.ceil(sorted.length * ratio) - 1)); + return sorted[index] ?? 0; +}; + +const maximum = (values: readonly number[]): number => { + let result = 0; + for (const value of values) result = Math.max(result, value); + return result; +}; + +const summarizeSeries = (series: DurationSeries) => ({ + count: series.durationsNs.length, + totalMs: series.totalNs / 1_000_000, + averageMs: series.durationsNs.length > 0 ? series.totalNs / series.durationsNs.length / 1_000_000 : 0, + p50Ms: percentile(series.durationsNs, 0.5) / 1_000_000, + p95Ms: percentile(series.durationsNs, 0.95) / 1_000_000, + p99Ms: percentile(series.durationsNs, 0.99) / 1_000_000, + maxMs: maximum(series.durationsNs) / 1_000_000, +}); + +const monthKey = (year: number, month: number): string => `${year}-${String(month).padStart(2, '0')}`; + +export class NpcUnificationTimingProfiler { + private readonly commandSeries = new Map(); + private readonly commandAiSeries = new Map(); + private readonly decisionSeries = new Map<'chief' | 'ordinary', DurationSeries>([ + ['chief', createSeries()], + ['ordinary', createSeries()], + ]); + private readonly turnSeries = new Map<'chief' | 'ordinary', DurationSeries>([ + ['chief', createSeries()], + ['ordinary', createSeries()], + ]); + private readonly months = new Map(); + private readonly monthWallMs = new Map(); + private maxHeapUsedBytes = 0; + private maxRssBytes = 0; + + private getMonth(year: number, month: number): MonthBucket { + const key = monthKey(year, month); + const existing = this.months.get(key); + if (existing) return existing; + const created: MonthBucket = { + year, + month, + generalTurns: 0, + chiefGeneralTurns: 0, + ordinaryGeneralTurns: 0, + totalGeneralTurnNs: 0, + aiDecisionCount: 0, + aiDecisionNs: 0, + commandCount: 0, + commandExecutionNs: 0, + activeNationCount: 0, + generalCount: 0, + }; + this.months.set(key, created); + return created; + } + + observeAction(payload: ProfiledAction): void { + const commandKey = `${payload.kind}:${payload.actionKey}`; + const actionDurationNs = Number(payload.actionDurationNs); + const command = this.commandSeries.get(commandKey) ?? createSeries(); + command.durationsNs.push(actionDurationNs); + command.totalNs += actionDurationNs; + this.commandSeries.set(commandKey, command); + + const month = this.getMonth(payload.year, payload.month); + month.commandCount += 1; + month.commandExecutionNs += actionDurationNs; + + if (!payload.usedAi) return; + const decisionDurationNs = Number(payload.aiDecisionDurationNs); + const commandAi = this.commandAiSeries.get(commandKey) ?? createSeries(); + commandAi.durationsNs.push(decisionDurationNs); + commandAi.totalNs += decisionDurationNs; + this.commandAiSeries.set(commandKey, commandAi); + + const officerGroup = payload.officerLevel >= 5 ? 'chief' : 'ordinary'; + const decision = this.decisionSeries.get(officerGroup)!; + decision.durationsNs.push(decisionDurationNs); + decision.totalNs += decisionDurationNs; + month.aiDecisionCount += 1; + month.aiDecisionNs += decisionDurationNs; + } + + observeGeneralTurn(input: { year: number; month: number; officerLevel: number; durationNs: bigint }): void { + const durationNs = Number(input.durationNs); + const officerGroup = input.officerLevel >= 5 ? 'chief' : 'ordinary'; + const series = this.turnSeries.get(officerGroup)!; + series.durationsNs.push(durationNs); + series.totalNs += durationNs; + + const month = this.getMonth(input.year, input.month); + month.generalTurns += 1; + month.totalGeneralTurnNs += durationNs; + if (officerGroup === 'chief') month.chiefGeneralTurns += 1; + else month.ordinaryGeneralTurns += 1; + } + + observeMonth(input: { + year: number; + month: number; + wallDurationMs: number; + activeNationCount: number; + generalCount: number; + }): void { + this.monthWallMs.set(monthKey(input.year, input.month), input.wallDurationMs); + const month = this.getMonth(input.year, input.month); + month.activeNationCount = input.activeNationCount; + month.generalCount = input.generalCount; + const usage = process.memoryUsage(); + this.maxHeapUsedBytes = Math.max(this.maxHeapUsedBytes, usage.heapUsed); + this.maxRssBytes = Math.max(this.maxRssBytes, usage.rss); + } + + buildReport(input: { + startedAtNs: bigint; + scenarioId: number; + scenarioTitle: string; + hiddenSeed: string; + initialGeneralCount: number; + initialCityCount: number; + startYear: number; + startMonth: number; + finalYear: number; + finalMonth: number; + finalGeneralCount: number; + foundedNationCount: number; + finalNationCount: number; + unificationReached: boolean; + convergenceAssist: string; + discardedDrafts: { logs: number; messages: number; neutralAuctions: number }; + }) { + const commandKeys = Array.from(this.commandSeries.keys()).sort(); + const commands = commandKeys.map((key) => ({ + key, + execution: summarizeSeries(this.commandSeries.get(key)!), + aiDecision: summarizeSeries(this.commandAiSeries.get(key) ?? createSeries()), + })); + const months = Array.from(this.months.entries()) + .sort(([left], [right]) => left.localeCompare(right)) + .map(([key, bucket]) => ({ + key, + year: bucket.year, + month: bucket.month, + generalTurns: bucket.generalTurns, + chiefGeneralTurns: bucket.chiefGeneralTurns, + ordinaryGeneralTurns: bucket.ordinaryGeneralTurns, + activeNationCount: bucket.activeNationCount, + generalCount: bucket.generalCount, + wallDurationMs: this.monthWallMs.get(key) ?? 0, + totalGeneralTurnMs: bucket.totalGeneralTurnNs / 1_000_000, + averageGeneralTurnMs: + bucket.generalTurns > 0 ? bucket.totalGeneralTurnNs / bucket.generalTurns / 1_000_000 : 0, + aiDecisionCount: bucket.aiDecisionCount, + totalAiDecisionMs: bucket.aiDecisionNs / 1_000_000, + averageAiDecisionMs: + bucket.aiDecisionCount > 0 ? bucket.aiDecisionNs / bucket.aiDecisionCount / 1_000_000 : 0, + commandCount: bucket.commandCount, + totalCommandExecutionMs: bucket.commandExecutionNs / 1_000_000, + averageCommandExecutionMs: + bucket.commandCount > 0 ? bucket.commandExecutionNs / bucket.commandCount / 1_000_000 : 0, + })); + const startIndex = input.startYear * 12 + input.startMonth - 1; + const finalIndex = input.finalYear * 12 + input.finalMonth - 1; + + return { + schemaVersion: 1, + runtime: { + node: process.version, + platform: process.platform, + arch: process.arch, + cpuModel: os.cpus()[0]?.model ?? 'unknown', + logicalCpuCount: os.cpus().length, + totalMemoryBytes: os.totalmem(), + }, + scenario: { + id: input.scenarioId, + title: input.scenarioTitle, + hiddenSeed: input.hiddenSeed, + initialGeneralCount: input.initialGeneralCount, + initialCityCount: input.initialCityCount, + startYear: input.startYear, + startMonth: input.startMonth, + convergenceAssist: input.convergenceAssist, + }, + result: { + unificationReached: input.unificationReached, + finalYear: input.finalYear, + finalMonth: input.finalMonth, + simulatedMonths: finalIndex - startIndex, + finalGeneralCount: input.finalGeneralCount, + foundedNationCount: input.foundedNationCount, + finalNationCount: input.finalNationCount, + wallDurationMs: Number(process.hrtime.bigint() - input.startedAtNs) / 1_000_000, + discardedDrafts: input.discardedDrafts, + }, + npcDecisionByOfficerGroup: { + chief: summarizeSeries(this.decisionSeries.get('chief')!), + ordinary: summarizeSeries(this.decisionSeries.get('ordinary')!), + }, + generalTurnByOfficerGroup: { + chief: summarizeSeries(this.turnSeries.get('chief')!), + ordinary: summarizeSeries(this.turnSeries.get('ordinary')!), + }, + memory: { + maxObservedHeapUsedBytes: this.maxHeapUsedBytes, + maxObservedRssBytes: this.maxRssBytes, + processResourceMaxRssBytes: process.resourceUsage().maxRSS * 1024, + }, + commands, + months, + }; + } +} diff --git a/app/game-engine/test/helpers/turnTestHarness.ts b/app/game-engine/test/helpers/turnTestHarness.ts index d8f8b612..64e0a7dc 100644 --- a/app/game-engine/test/helpers/turnTestHarness.ts +++ b/app/game-engine/test/helpers/turnTestHarness.ts @@ -67,10 +67,12 @@ export type TurnTestHarnessOptions = { }; turnProcessorOptions?: { tickMinutes: number; + beforeExecuteGeneral?: InMemoryTurnProcessorOptions['beforeExecuteGeneral']; afterExecuteGeneral?: InMemoryTurnProcessorOptions['afterExecuteGeneral']; }; worldRef?: { current: InMemoryTurnWorld | null }; onActionResolved?: Parameters[0]['onActionResolved']; + onActionProfiled?: Parameters[0]['onActionProfiled']; commandRngFactory?: Parameters[0]['commandRngFactory']; wrapGeneralTurnHandler?: (handler: GeneralTurnHandler) => GeneralTurnHandler; extraCalendarHandlers?: TurnCalendarHandler[]; @@ -110,6 +112,7 @@ export const createTurnTestHarness = async (options: TurnTestHarnessOptions) => unitSet: options.snapshot.unitSet, getWorld: () => worldRef.current, onActionResolved: options.onActionResolved, + onActionProfiled: options.onActionProfiled, commandRngFactory: options.commandRngFactory, }); @@ -150,6 +153,7 @@ export const createTurnTestHarness = async (options: TurnTestHarnessOptions) => const processor = new InMemoryTurnProcessor(world, { tickMinutes: options.turnProcessorOptions?.tickMinutes ?? 10, + beforeExecuteGeneral: options.turnProcessorOptions?.beforeExecuteGeneral, afterExecuteGeneral: options.turnProcessorOptions?.afterExecuteGeneral, }); diff --git a/app/game-engine/test/npcScenarioUnificationBenchmark.test.ts b/app/game-engine/test/npcScenarioUnificationBenchmark.test.ts new file mode 100644 index 00000000..b0bcb7ba --- /dev/null +++ b/app/game-engine/test/npcScenarioUnificationBenchmark.test.ts @@ -0,0 +1,313 @@ +import { mkdirSync, writeFileSync } from 'node:fs'; +import { dirname, resolve } from 'node:path'; + +import { buildScenarioBootstrap, type City, type TurnSchedule } from '@sammo-ts/logic'; +import { describe, expect, it } from 'vitest'; + +import { loadMapDefinitionByName } from '../src/scenario/mapLoader.js'; +import { loadScenarioDefinitionById } from '../src/scenario/scenarioLoader.js'; +import { loadUnitSetDefinitionByName } from '../src/scenario/unitSetLoader.js'; +import { applyInitialChangeCityEvents } from '../src/turn/monthlyChangeCityAction.js'; +import { createUnificationHandler } from '../src/turn/unificationHandler.js'; +import type { InMemoryTurnWorld } from '../src/turn/inMemoryWorld.js'; +import type { TurnGeneral, TurnWorldSnapshot, TurnWorldState } from '../src/turn/types.js'; +import { createTurnTestHarness } from './helpers/turnTestHarness.js'; +import { NpcUnificationTimingProfiler } from './helpers/npcUnificationTimingProfiler.js'; + +const benchmarkEnabled = process.env.NPC_UNIFICATION_BENCHMARK === '1'; +const benchmarkDescribe = describe.runIf(benchmarkEnabled); +const SCENARIO_ID = 2601; +const HIDDEN_SEED = 'scenario-2601-npc-unification-benchmark-v1'; +const TURN_MINUTES = 10; + +const createGameDate = (year: number, month: number): Date => { + const date = new Date(0); + date.setUTCFullYear(year, month - 1, 1); + date.setUTCHours(0, 0, 0, 0); + return date; +}; + +const buildTurnGeneral = ( + domainGeneral: ReturnType['snapshot']['generals'][number], + seedGeneral: ReturnType['seed']['generals'][number], + startTime: Date, + startYear: number, + startMonth: number +): TurnGeneral => { + const deathMonthRaw = seedGeneral.meta.deathMonth; + const deathMonth = + typeof deathMonthRaw === 'number' && Number.isInteger(deathMonthRaw) ? deathMonthRaw : startMonth; + const killturn = Math.max(0, (seedGeneral.deathYear - startYear) * 12 + (deathMonth - 1) + startMonth - 1); + const initialTurnOffsetMicros = + typeof seedGeneral.meta.initialTurnOffsetMicros === 'number' ? seedGeneral.meta.initialTurnOffsetMicros : 0; + return { + ...domainGeneral, + userId: null, + bornYear: seedGeneral.birthYear, + deadYear: seedGeneral.deathYear, + affinity: seedGeneral.affinity, + picture: seedGeneral.picture === null ? null : String(seedGeneral.picture), + startAge: 20, + turnTime: new Date(startTime.getTime() + Math.floor(initialTurnOffsetMicros / 1_000)), + recentWarTime: null, + lastTurn: { command: '휴식' }, + penalty: {}, + inheritancePoints: {}, + meta: { + ...domainGeneral.meta, + ...seedGeneral.meta, + killturn, + npcType: seedGeneral.npcType, + crewTypeId: seedGeneral.crewTypeId, + }, + }; +}; + +const buildTurnCity = (seed: ReturnType['seed']['cities'][number]): City => ({ + id: seed.id, + name: seed.name, + nationId: seed.nationId, + level: seed.level, + state: seed.state, + population: seed.population, + populationMax: seed.populationMax, + agriculture: seed.agriculture, + agricultureMax: seed.agricultureMax, + commerce: seed.commerce, + commerceMax: seed.commerceMax, + security: seed.security, + securityMax: seed.securityMax, + supplyState: seed.supplyState, + frontState: seed.frontState, + defence: seed.defence, + defenceMax: seed.defenceMax, + wall: seed.wall, + wallMax: seed.wallMax, + meta: { + ...seed.meta, + region: seed.region, + trust: seed.trust, + trade: seed.trade, + positionX: seed.position.x, + positionY: seed.position.y, + }, +}); + +const applyConvergenceAssist = (world: InMemoryTurnWorld, mode: string): void => { + if (mode !== 'nation-1-max-city') return; + for (const city of world.listCities()) { + if (city.nationId !== 1) continue; + world.updateCity(city.id, { + population: city.populationMax, + agriculture: city.agricultureMax, + commerce: city.commerceMax, + security: city.securityMax, + defence: city.defenceMax, + wall: city.wallMax, + meta: { ...city.meta, trust: 100 }, + }); + } +}; + +benchmarkDescribe('scenario 2601 NPC 완전 인메모리 천통 벤치마크', () => { + it('DB와 Redis 없이 시작 상태부터 통일까지 자동 실행하고 상세 시간을 기록한다', async () => { + const startedAtNs = process.hrtime.bigint(); + const scenario = await loadScenarioDefinitionById(SCENARIO_ID); + const map = await loadMapDefinitionByName(scenario.config.environment.mapName); + const unitSet = await loadUnitSetDefinitionByName(scenario.config.environment.unitSet); + const startYear = scenario.startYear ?? 180; + const startMonth = 1; + const startTime = createGameDate(startYear, startMonth); + const bootstrap = buildScenarioBootstrap({ + scenario, + map, + unitSet, + options: { + hiddenSeed: HIDDEN_SEED, + initialYear: startYear, + initialMonth: startMonth, + turnTermMinutes: TURN_MINUTES, + includeNeutralNationInSeed: true, + }, + }); + expect(bootstrap.warnings).toEqual([]); + + const cities = applyInitialChangeCityEvents(bootstrap.seed.cities, bootstrap.seed.initialEvents).map( + buildTurnCity + ); + const domainGeneralById = new Map(bootstrap.snapshot.generals.map((general) => [general.id, general])); + const generals = bootstrap.seed.generals.map((seedGeneral) => { + const domainGeneral = domainGeneralById.get(seedGeneral.id); + if (!domainGeneral) throw new Error(`missing domain general ${seedGeneral.id}`); + return buildTurnGeneral(domainGeneral, seedGeneral, startTime, startYear, startMonth); + }); + + const snapshot: TurnWorldSnapshot = { + scenarioConfig: bootstrap.snapshot.scenarioConfig, + scenarioMeta: bootstrap.snapshot.scenarioMeta, + worldConfig: { + fiction: scenario.fiction, + npcMode: 2, + turnTermMinutes: TURN_MINUTES, + tournamentTrig: false, + }, + map, + unitSet, + generals, + cities, + nations: bootstrap.snapshot.nations, + troops: bootstrap.snapshot.troops, + diplomacy: bootstrap.snapshot.diplomacy.map((entry) => ({ + fromNationId: entry.fromNationId, + toNationId: entry.toNationId, + state: entry.state, + term: entry.durationMonths, + dead: 0, + meta: {}, + })), + // This benchmark isolates general/nation commands and core monthly + // handlers. Scenario event actions are excluded explicitly below. + events: [], + initialEvents: [], + }; + const state: TurnWorldState = { + id: 1, + currentYear: startYear, + currentMonth: startMonth, + tickSeconds: TURN_MINUTES * 60, + lastTurnTime: startTime, + clockBaseTime: startTime, + clockTick: 0, + clockMode: 'manual', + clockWallAnchor: startTime, + lastTurnTick: 0, + meta: { + scenarioId: SCENARIO_ID, + scenarioMeta: bootstrap.seed.scenarioMeta, + hiddenSeed: HIDDEN_SEED, + seed: HIDDEN_SEED, + initYear: startYear, + initMonth: startMonth, + fiction: scenario.fiction, + killturn: 4800 / TURN_MINUTES, + develcost: 20, + isUnited: 0, + isunited: 0, + lastGeneralId: Math.max(0, ...generals.map((general) => general.id)), + lastNationId: 0, + serverId: 'benchmark-scenario-2601', + }, + }; + const schedule: TurnSchedule = { entries: [{ startMinute: 0, tickMinutes: TURN_MINUTES }] }; + const worldRef = { current: null as InMemoryTurnWorld | null }; + const profiler = new NpcUnificationTimingProfiler(); + const turnStartedAt = new Map(); + const convergenceAssist = process.env.NPC_UNIFICATION_BENCHMARK_CONVERGENCE_ASSIST ?? 'none'; + let foundedNationCount = 0; + const discardedDrafts = { logs: 0, messages: 0, neutralAuctions: 0 }; + + const unification = createUnificationHandler({ + profileName: 'benchmark-scenario-2601', + getWorld: () => worldRef.current, + dispatchUnitedEvents: async () => {}, + }); + const harness = await createTurnTestHarness({ + snapshot, + state, + schedule, + map, + worldRef, + extraCalendarHandlers: [unification.handler], + onActionProfiled: (payload) => profiler.observeAction(payload), + turnProcessorOptions: { + tickMinutes: TURN_MINUTES, + beforeExecuteGeneral: async (general) => { + turnStartedAt.set(general.id, process.hrtime.bigint()); + }, + afterExecuteGeneral: async (general) => { + const generalStartedAt = turnStartedAt.get(general.id); + if (generalStartedAt === undefined) throw new Error(`missing turn timer ${general.id}`); + const current = worldRef.current?.getState(); + if (!current) throw new Error('world not initialized'); + profiler.observeGeneralTurn({ + year: current.currentYear, + month: current.currentMonth, + officerLevel: general.officerLevel, + durationNs: process.hrtime.bigint() - generalStartedAt, + }); + turnStartedAt.delete(general.id); + }, + }, + }); + + const maximumYear = Number(process.env.NPC_UNIFICATION_BENCHMARK_MAX_YEAR ?? 300); + while (true) { + const before = harness.world.getState(); + const monthStartedAtNs = process.hrtime.bigint(); + await harness.runOneTick({ budgetMs: 600_000, maxGenerals: 100_000, catchUpCap: 1 }); + profiler.observeMonth({ + year: before.currentYear, + month: before.currentMonth, + wallDurationMs: Number(process.hrtime.bigint() - monthStartedAtNs) / 1_000_000, + activeNationCount: harness.world.listNations().filter((nation) => nation.level > 0).length, + generalCount: harness.world.listGenerals().length, + }); + applyConvergenceAssist(harness.world, convergenceAssist); + const activeNationCount = harness.world.listNations().filter((nation) => nation.level > 0).length; + foundedNationCount = Math.max(foundedNationCount, activeNationCount); + const changes = harness.world.consumeDirtyState(); + discardedDrafts.logs += changes.logs.length; + discardedDrafts.messages += changes.messages.length; + discardedDrafts.neutralAuctions += changes.pendingNeutralAuctions.length; + const reservedChanges = harness.reservedTurnStore.peekDirtyState(); + harness.reservedTurnStore.acknowledgeDirtyState(reservedChanges); + + const current = harness.world.getState(); + const meta = current.meta as Record; + if ((meta.isUnited ?? meta.isunited ?? 0) !== 0) break; + if (current.currentYear >= maximumYear) break; + } + + const finalState = harness.world.getState(); + const finalMeta = finalState.meta as Record; + const unificationReached = (finalMeta.isUnited ?? finalMeta.isunited ?? 0) !== 0; + const finalNationCount = harness.world.listNations().filter((nation) => nation.level > 0).length; + const report = profiler.buildReport({ + startedAtNs, + scenarioId: SCENARIO_ID, + scenarioTitle: scenario.title, + hiddenSeed: HIDDEN_SEED, + initialGeneralCount: generals.length, + initialCityCount: cities.length, + startYear, + startMonth, + finalYear: finalState.currentYear, + finalMonth: finalState.currentMonth, + finalGeneralCount: harness.world.listGenerals().length, + foundedNationCount, + finalNationCount, + unificationReached, + convergenceAssist, + discardedDrafts, + }); + const reportPath = resolve( + process.env.NPC_UNIFICATION_BENCHMARK_REPORT_PATH ?? 'test-results/npc-scenario-unification-benchmark.json' + ); + mkdirSync(dirname(reportPath), { recursive: true }); + writeFileSync(reportPath, `${JSON.stringify(report, null, 2)}\n`, 'utf8'); + console.log( + `[NPC_UNIFICATION_BENCHMARK_REPORT]${JSON.stringify({ + reportPath, + scenario: report.scenario, + result: report.result, + npcDecisionByOfficerGroup: report.npcDecisionByOfficerGroup, + generalTurnByOfficerGroup: report.generalTurnByOfficerGroup, + memory: report.memory, + })}` + ); + + expect(generals.length).toBeGreaterThanOrEqual(600); + expect(cities.length).toBeGreaterThanOrEqual(90); + expect(unificationReached).toBe(true); + }, 1_800_000); +}); diff --git a/docs/architecture/npc-unification-timing-benchmark.md b/docs/architecture/npc-unification-timing-benchmark.md new file mode 100644 index 00000000..94bed514 --- /dev/null +++ b/docs/architecture/npc-unification-timing-benchmark.md @@ -0,0 +1,90 @@ +# NPC 대규모 인메모리 천통 시간 벤치마크 + +## 목적 + +`scenario_2601`의 장수 roster와 `che` 지도를 사용해 PostgreSQL·Redis를 +연결하지 않은 계산 전용 월드에서 NPC가 건국부터 통일까지 자동 진행하는 시간을 +측정한다. 전체 wall time과 함께 다음 구간을 분리한다. + +- 일반/국가 커맨드 실행 시간 +- NPC AI 판단 시간 +- 수뇌(`officerLevel >= 5`)와 일반 NPC 장수 턴 시간 +- 게임 연월별 월 처리 시간과 국가·장수 수 + +이 벤치마크는 DB throughput이나 production daemon capacity를 측정하지 않는다. +서버 계산량의 상한/회귀를 재현하는 프로파일이며 실제 운영 wall time에는 +PostgreSQL transaction, flush, lease, Redis, API와 다른 프로세스 경합을 별도로 +더해야 한다. + +## 실행 + +기본 실행은 고정 seed, 시나리오 2601, 880명, 94도시, 10분 턴과 300년 안전 +상한을 사용한다. + +```sh +NPC_UNIFICATION_BENCHMARK_CONVERGENCE_ASSIST=none \ +NPC_UNIFICATION_BENCHMARK_MAX_YEAR=300 \ +NPC_UNIFICATION_BENCHMARK_REPORT_PATH=/dev/shm/npc-unification.json \ +pnpm --filter @sammo-ts/game-engine profile:npc-unification-timing +``` + +`NPC_UNIFICATION_BENCHMARK_CONVERGENCE_ASSIST=none`이 무보정 자연 진행이다. +비교용 `nation-1-max-city`는 매월 1번 국가가 이미 소유한 도시의 인구·내정·방어·성벽과 +민심을 최대값으로 복원한다. 국가 선택, 외교, 출병, 전투, 점령, 멸망과 통일 +판정을 직접 만들지는 않는다. 대형 fixture가 유한 시간에 통일하도록 한 기존 +`npcNationUprisingUnification.test.ts`의 수렴 보조를 94도시로 확장한 것이다. + +## 실행 경계 + +포함하는 경로는 다음과 같다. + +- `scenario_2601.json` 합성 loader, `map_che.json`, `unitset_che.json` +- `buildScenarioBootstrap()`의 deterministic 초기 배치 +- `InMemoryTurnWorld`, `InMemoryReservedTurnStore`, `InMemoryTurnProcessor` +- `GeneralAI.chooseNationTurn()`과 `chooseGeneralTurn()` +- 실제 일반/국가 action definition, 전투, 점령과 국가 멸망 +- test harness의 국가 예약턴 월 갱신, 수입, NPC 세금, 전선 갱신 +- 실제 `unificationHandler.ts`의 단일 국가·전 도시 소유 판정과 in-memory draft + +제외하는 경로는 다음과 같다. + +- PostgreSQL loader, transaction, lease, flush와 통일 최종 archive +- Redis tournament/realtime +- scenario event action과 yearbook persistence +- API, scheduler sleep, worker IPC와 browser + +월마다 `world.consumeDirtyState()`와 예약 큐 acknowledgement를 호출해 log, +message와 persistence draft를 메모리 sink로 비운다. DB write는 수행하지 않지만 +운영 flush 뒤 메모리 draft가 정리되는 경계는 재현한다. + +## 계측 정의 + +`createReservedTurnHandler()`의 선택적 `onActionProfiled` hook은 hook을 넘긴 +경우에만 `process.hrtime.bigint()`로 다음 시간을 잰다. + +- `aiDecisionDurationNs`: `GeneralAI` 생성/재사용과 해당 + `chooseNationTurn()` 또는 `chooseGeneralTurn()` 호출 +- `actionDurationNs`: 선택된 action의 parse, constraint, execute와 결과 patch + 생성 + +`InMemoryTurnProcessor`의 before/after hook은 한 장수 턴 전체를 잰다. 수뇌는 +한 턴에 국가 AI와 일반 AI를 모두 실행할 수 있으므로 수뇌의 “판단/턴”은 두 +decision 합계를 수뇌 턴 수로 나누어 해석한다. JSON은 커맨드별 count/total/ +average/p50/p95/p99/max, 수뇌 여부, 연월별 합계와 process memory high-water를 +포함한다. + +계측 clock 호출과 배열 수집 자체의 overhead가 wall time에 포함된다. 같은 +고정 seed의 독립 실행을 반복하여 결과 state가 같고 wall time만 변하는지 함께 +확인해야 한다. + +## 2026-08-15 기준 결과 + +AMD Ryzen 7 9800X3D, 16 logical CPU, Node v24.18.0, Linux x64의 shared 개발 +호스트에서 무보정 자연 실행 두 번 모두 242년 4월, 747개월, 46개국 건국, +총 699,892 장수 턴과 최종 장수 970명으로 동일하게 통일했다. wall time은 +483.68초와 466.91초(평균 475.29초)였다. 상세 수치와 커맨드 33종 표는 상위 작업공간의 +`report/2026-08-15-NPC-대규모-인메모리-천통-벤치마크.md`에 기록한다. + +수렴 보조 실행 두 번은 225년 11월에 375.24/422.68초로 끝났다. +도시 자원 복원이 전쟁과 통일 연월에 영향을 줬으므로 이 수치는 자연 실행과 분리한 +비교 근거로만 사용한다.