diff --git a/app/game-engine/package.json b/app/game-engine/package.json index 935f222..4bfe7ba 100644 --- a/app/game-engine/package.json +++ b/app/game-engine/package.json @@ -11,6 +11,7 @@ "start": "pnpm run build && node dist/index.js", "lint": "eslint .", "lint:fix": "eslint . --fix", + "profile:npc-unification-memory": "node scripts/profile-npc-unification-memory.mjs", "test": "vitest run --config vitest.config.ts", "typecheck": "tsc -b" }, diff --git a/app/game-engine/scripts/profile-npc-unification-memory.mjs b/app/game-engine/scripts/profile-npc-unification-memory.mjs new file mode 100644 index 0000000..c959043 --- /dev/null +++ b/app/game-engine/scripts/profile-npc-unification-memory.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/npcNationUprisingUnification.test.ts', + ], + { + cwd: packageRoot, + env: { + ...process.env, + NPC_UNIFICATION_MEMORY_PROFILE: '1', + }, + stdio: 'inherit', + } +); + +child.once('error', (error) => { + console.error('[npc-unification-memory] failed to start profiler', error); + process.exitCode = 1; +}); + +child.once('exit', (code, signal) => { + if (signal) { + console.error(`[npc-unification-memory] profiler terminated by ${signal}`); + process.exitCode = 1; + return; + } + process.exitCode = code ?? 1; +}); diff --git a/app/game-engine/test/helpers/npcUnificationMemoryProfiler.ts b/app/game-engine/test/helpers/npcUnificationMemoryProfiler.ts new file mode 100644 index 0000000..f834387 --- /dev/null +++ b/app/game-engine/test/helpers/npcUnificationMemoryProfiler.ts @@ -0,0 +1,206 @@ +import { performance } from 'node:perf_hooks'; +import { serialize } from 'node:v8'; + +import type { InMemoryReservedTurnStore } from '../../src/turn/reservedTurnStore.js'; +import type { InMemoryTurnWorld } from '../../src/turn/inMemoryWorld.js'; + +type MemoryUsageSnapshot = { + rssBytes: number; + heapTotalBytes: number; + heapUsedBytes: number; + externalBytes: number; + arrayBuffersBytes: number; +}; + +export type NpcUnificationMemorySample = { + label: string; + year: number; + month: number; + activeNationCount: number; + generalCount: number; + cityCount: number; + troopCount: number; + processBeforeSnapshot: MemoryUsageSnapshot; + processWithSnapshot: MemoryUsageSnapshot; + processAfterRelease: MemoryUsageSnapshot; + worldSnapshotBytes: number; + reservedTurnSnapshotBytes: number; + totalParticipantSnapshotBytes: number; + participantSnapshotCloneMs: number; +}; + +type TickObservation = { + heapUsedBytes: number; + rssBytes: number; +}; + +const readMemoryUsage = (): MemoryUsageSnapshot => { + const usage = process.memoryUsage(); + return { + rssBytes: usage.rss, + heapTotalBytes: usage.heapTotal, + heapUsedBytes: usage.heapUsed, + externalBytes: usage.external, + arrayBuffersBytes: usage.arrayBuffers, + }; +}; + +const percentile = (values: 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 average = (values: number[]): number => + values.length === 0 ? 0 : values.reduce((sum, value) => sum + value, 0) / values.length; + +export class NpcUnificationMemoryProfiler { + private readonly samples: NpcUnificationMemorySample[] = []; + private readonly tickObservations: TickObservation[] = []; + + constructor( + private readonly world: InMemoryTurnWorld, + private readonly reservedTurns: InMemoryReservedTurnStore + ) {} + + observeTick(): void { + const usage = readMemoryUsage(); + this.tickObservations.push({ + heapUsedBytes: usage.heapUsedBytes, + rssBytes: usage.rssBytes, + }); + } + + sample(label: string): NpcUnificationMemorySample { + globalThis.gc?.(); + const processBeforeSnapshot = readMemoryUsage(); + const snapshotMetrics = (() => { + const startedAt = performance.now(); + const worldSnapshot = this.world.captureState(); + const reservedTurnSnapshot = this.reservedTurns.captureState(); + return { + participantSnapshotCloneMs: performance.now() - startedAt, + processWithSnapshot: readMemoryUsage(), + worldSnapshotBytes: serialize(worldSnapshot).byteLength, + reservedTurnSnapshotBytes: serialize(reservedTurnSnapshot).byteLength, + }; + })(); + globalThis.gc?.(); + const processAfterRelease = readMemoryUsage(); + + const state = this.world.getState(); + const cities = this.world.listCities(); + const nations = this.world.listNations(); + const sample: NpcUnificationMemorySample = { + label, + year: state.currentYear, + month: state.currentMonth, + activeNationCount: nations.filter( + (nation) => nation.level > 0 && cities.some((city) => city.nationId === nation.id) + ).length, + generalCount: this.world.listGenerals().length, + cityCount: cities.length, + troopCount: this.world.listTroops().length, + processBeforeSnapshot, + processWithSnapshot: snapshotMetrics.processWithSnapshot, + processAfterRelease, + worldSnapshotBytes: snapshotMetrics.worldSnapshotBytes, + reservedTurnSnapshotBytes: snapshotMetrics.reservedTurnSnapshotBytes, + totalParticipantSnapshotBytes: + snapshotMetrics.worldSnapshotBytes + snapshotMetrics.reservedTurnSnapshotBytes, + participantSnapshotCloneMs: snapshotMetrics.participantSnapshotCloneMs, + }; + this.samples.push(sample); + return sample; + } + + buildReport(input: { + startedAtMs: number; + initialGeneralCount: number; + foundedNationCount: number; + declarationCount: number; + sortieCount: number; + unifiedAt: { year: number; month: number }; + startYear: number; + startMonth: number; + }) { + const cloneTimes = this.samples.map((sample) => sample.participantSnapshotCloneMs); + const snapshotSizes = this.samples.map((sample) => sample.totalParticipantSnapshotBytes); + const retainedSnapshotHeapDeltas = this.samples.map( + (sample) => + sample.processWithSnapshot.heapUsedBytes - sample.processBeforeSnapshot.heapUsedBytes + ); + const releasedSnapshotHeapDeltas = this.samples.map( + (sample) => + sample.processAfterRelease.heapUsedBytes - sample.processBeforeSnapshot.heapUsedBytes + ); + const observedHeap = [ + ...this.tickObservations.map((entry) => entry.heapUsedBytes), + ...this.samples.flatMap((sample) => [ + sample.processBeforeSnapshot.heapUsedBytes, + sample.processWithSnapshot.heapUsedBytes, + sample.processAfterRelease.heapUsedBytes, + ]), + ]; + const observedRss = [ + ...this.tickObservations.map((entry) => entry.rssBytes), + ...this.samples.flatMap((sample) => [ + sample.processBeforeSnapshot.rssBytes, + sample.processWithSnapshot.rssBytes, + sample.processAfterRelease.rssBytes, + ]), + ]; + const startIndex = input.startYear * 12 + input.startMonth - 1; + const unifiedIndex = input.unifiedAt.year * 12 + input.unifiedAt.month - 1; + + return { + schemaVersion: 1, + runtime: { + node: process.version, + platform: process.platform, + arch: process.arch, + explicitGc: typeof globalThis.gc === 'function', + }, + scenario: { + name: 'npcNationUprisingUnification-large-test-map', + initialGeneralCount: input.initialGeneralCount, + cityCount: this.samples[0]?.cityCount ?? 0, + startYear: input.startYear, + startMonth: input.startMonth, + }, + result: { + unifiedAt: input.unifiedAt, + simulatedMonths: unifiedIndex - startIndex, + foundedNationCount: input.foundedNationCount, + declarationCount: input.declarationCount, + sortieCount: input.sortieCount, + wallDurationMs: performance.now() - input.startedAtMs, + }, + memory: { + processIncludes: ['node', 'vitest-worker', 'scenario-harness', 'engine-state'], + maxObservedHeapUsedBytes: Math.max(0, ...observedHeap), + maxObservedRssBytes: Math.max(0, ...observedRss), + processResourceMaxRssBytes: process.resourceUsage().maxRSS * 1024, + participantSnapshotBytes: { + initial: snapshotSizes[0] ?? 0, + final: snapshotSizes.at(-1) ?? 0, + peak: Math.max(0, ...snapshotSizes), + }, + participantSnapshotHeapDeltaBytes: { + peakWhileRetained: Math.max(0, ...retainedSnapshotHeapDeltas), + peakAfterRelease: Math.max(0, ...releasedSnapshotHeapDeltas), + }, + participantSnapshotCloneMs: { + count: cloneTimes.length, + average: average(cloneTimes), + p95: percentile(cloneTimes, 0.95), + max: Math.max(0, ...cloneTimes), + }, + }, + samples: this.samples, + }; + } +} diff --git a/app/game-engine/test/npcNationUprisingUnification.test.ts b/app/game-engine/test/npcNationUprisingUnification.test.ts index 214f681..a074456 100644 --- a/app/game-engine/test/npcNationUprisingUnification.test.ts +++ b/app/game-engine/test/npcNationUprisingUnification.test.ts @@ -1,10 +1,14 @@ import { describe, expect, it } from 'vitest'; +import { mkdirSync, writeFileSync } from 'node:fs'; +import { dirname, resolve } from 'node:path'; +import { performance } from 'node:perf_hooks'; import type { LogEntryDraft, TurnSchedule, UnitSetDefinition } from '@sammo-ts/logic'; import { DIPLOMACY_STATE, LogCategory, LogFormat, LogScope } from '@sammo-ts/logic'; import type { InMemoryTurnWorld, TurnCalendarHandler } from '../src/turn/inMemoryWorld.js'; import type { TurnGeneral, TurnWorldSnapshot, TurnWorldState } from '../src/turn/types.js'; import { LARGE_TEST_MAP, buildLargeTestCities } from './fixtures/largeTestMap.js'; import { createTurnTestHarness } from './helpers/turnTestHarness.js'; +import { NpcUnificationMemoryProfiler } from './helpers/npcUnificationMemoryProfiler.js'; const mockDate = new Date('0181-08-01T00:00:00Z'); @@ -148,6 +152,8 @@ const dumpWorldStatus = (world: InMemoryTurnWorld, label: string) => { describe('NPC 건국/통일 장기 시뮬레이션', () => { it('건국, 선포, 출병, 점령과 장기 국가 감소가 안정적으로 진행되어야 한다', async () => { + const memoryProfileEnabled = process.env.NPC_UNIFICATION_MEMORY_PROFILE === '1'; + const profileStartedAtMs = performance.now(); const cities = buildLargeTestCities().map(maxCityStats); for (const city of cities) { city.nationId = 0; @@ -253,6 +259,7 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { const worldRef = { current: null as InMemoryTurnWorld | null }; + let unificationLogObserved = false; const unificationHandler: TurnCalendarHandler = { onMonthChanged: () => { const world = worldRef.current; @@ -279,6 +286,7 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { } world.updateWorldMeta({ isUnited: 2 }); world.pushLog(buildUnificationLog(winner.name)); + unificationLogObserved = true; }, }; @@ -287,7 +295,14 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { let sortieCount = 0; let lastResolvedAction = 'none'; - const { runUntil, getCollectedLogs, getCollectedLogsCount, getCollectedLogsRange } = + const { + runUntil, + reservedTurnStore, + getCollectedLogs, + getCollectedLogsCount, + getCollectedLogsRange, + getAndClearCollectedLogs, + } = await createTurnTestHarness({ snapshot, state, @@ -326,6 +341,30 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { } }, }); + const memoryProfiler = + memoryProfileEnabled && worldRef.current + ? new NpcUnificationMemoryProfiler(worldRef.current, reservedTurnStore) + : null; + memoryProfiler?.sample('initialized'); + let lastProfileYearMonth = -1; + const observeProfileMonth = (current: TurnWorldState) => { + if (!memoryProfiler) { + return; + } + const yearMonth = current.currentYear * 100 + current.currentMonth; + if (yearMonth === lastProfileYearMonth) { + return; + } + lastProfileYearMonth = yearMonth; + memoryProfiler.observeTick(); + const logs = getAndClearCollectedLogs(); + if (logs.some((log) => log.text.includes('전토를 통일하였습니다.'))) { + unificationLogObserved = true; + } + if (current.currentMonth === 1) { + memoryProfiler.sample(`year-${current.currentYear}`); + } + }; let monthlyLogCursor = 0; const maxMonthlyLogEntries = 20; @@ -355,7 +394,9 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { try { await runUntil( - (current) => current.currentYear > 182 || (current.currentYear === 182 && current.currentMonth >= 1) + (current) => current.currentYear > 182 || (current.currentYear === 182 && current.currentMonth >= 1), + undefined, + observeProfileMonth ); const world = worldRef.current; @@ -366,10 +407,14 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { const foundedNations = world.listNations().filter((nation) => nation.level > 0); expect(foundedNations.length).toBeGreaterThanOrEqual(2); const foundedNationCount = foundedNations.length; + memoryProfiler?.sample('nations-founded'); await runUntil( - (current) => current.currentYear > 183 || (current.currentYear === 183 && current.currentMonth >= 6) + (current) => current.currentYear > 183 || (current.currentYear === 183 && current.currentMonth >= 6), + undefined, + observeProfileMonth ); + memoryProfiler?.sample('all-cities-occupied'); const neutralCities = world.listCities().filter((city) => city.nationId <= 0); expect(neutralCities.length).toBe(0); @@ -381,7 +426,9 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { if (declarationCount === 0) { await runUntil( - (current) => current.currentYear > 190 || (current.currentYear === 190 && current.currentMonth >= 1) + (current) => current.currentYear > 190 || (current.currentYear === 190 && current.currentMonth >= 1), + undefined, + observeProfileMonth ); if (declarationCount === 0) { const generals = world.listGenerals().filter((general) => general.nationId > 0); @@ -488,7 +535,9 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { await runUntil( (current) => current.currentYear > target.year || - (current.currentYear === target.year && current.currentMonth >= target.month) + (current.currentYear === target.year && current.currentMonth >= target.month), + undefined, + observeProfileMonth ); //_dumpMonthlyLogs(`${target.year}-${String(target.month).padStart(2, '0')}`); @@ -521,9 +570,12 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { await runUntil( (current) => current.currentYear > nextMonth.year || - (current.currentYear === nextMonth.year && current.currentMonth >= nextMonth.month) + (current.currentYear === nextMonth.year && current.currentMonth >= nextMonth.month), + undefined, + observeProfileMonth ); unifiedAt = nextMonth; + memoryProfiler?.sample('unified'); break; } @@ -537,7 +589,8 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { const meta = world.getState().meta as Record; const logs = getCollectedLogs(); - const hasUnificationLog = logs.some((log) => log.text.includes('전토를 통일하였습니다.')); + const hasUnificationLog = + unificationLogObserved || logs.some((log) => log.text.includes('전토를 통일하였습니다.')); if (unifiedAt) { expect(meta.isUnited).toBe(2); expect(hasUnificationLog).toBe(true); @@ -546,6 +599,39 @@ describe('NPC 건국/통일 장기 시뮬레이션', () => { expect(meta.isUnited ?? 0).toBe(0); } expect(sortieCount).toBeGreaterThan(0); + + if (memoryProfiler) { + expect(typeof globalThis.gc).toBe('function'); + expect(unifiedAt).not.toBeNull(); + if (!unifiedAt) { + throw new Error('memory profile requires actual unification'); + } + const report = memoryProfiler.buildReport({ + startedAtMs: profileStartedAtMs, + initialGeneralCount: generals.length, + foundedNationCount, + declarationCount, + sortieCount, + unifiedAt, + startYear: state.currentYear, + startMonth: state.currentMonth, + }); + const reportPath = resolve( + process.env.NPC_UNIFICATION_MEMORY_REPORT_PATH ?? + 'test-results/npc-unification-memory.json' + ); + mkdirSync(dirname(reportPath), { recursive: true }); + writeFileSync(reportPath, `${JSON.stringify(report, null, 2)}\n`, 'utf8'); + console.log( + `[NPC_UNIFICATION_MEMORY_REPORT]${JSON.stringify({ + reportPath, + runtime: report.runtime, + scenario: report.scenario, + result: report.result, + memory: report.memory, + })}` + ); + } } catch (error) { const world = worldRef.current; if (world) { diff --git a/docs/architecture/npc-unification-memory-profile.md b/docs/architecture/npc-unification-memory-profile.md new file mode 100644 index 0000000..2fd6d8c --- /dev/null +++ b/docs/architecture/npc-unification-memory-profile.md @@ -0,0 +1,101 @@ +# NPC 통일 장기 실행 메모리 프로파일 + +## 목적 + +`npcNationUprisingUnification.test.ts`의 고정 시나리오를 실제 턴 처리기로 +통일까지 실행하고, 장수 수백 명 규모에서 Node 프로세스와 계산 savepoint가 +차지하는 메모리를 분리해 관찰한다. 이 프로파일은 성능 회귀 관찰용이며 +운영 capacity 산정이나 레거시 결과 동등성의 단독 근거가 아니다. + +## 시나리오 계약 + +- 시작: 181년 8월, NPC 300명, 도시 9개, 국가 없음 +- 고정 입력: world id/seed `1`, 고정 장수 능력치와 배치, 고정 map/unit set +- 실제 경로: NPC 건국, 국가 AI 선전포고, 장수 AI 출병, 전투, 점령, 멸망, + 월 경계와 통일 판정 +- 수렴 보조: 매 월 국가 ID 1 소유 도시의 인구·방어·성벽·민심을 최대값으로 + 복원한다. 따라서 이것은 자연 분포 예측이 아니라 통일 도달을 보장하기 위한 + synthetic stress fixture다. +- 통일 handler는 실제 조건인 “활성 국가 1개이며 모든 도시를 소유”와 + `isUnited=2`/통일 history만 재현한다. 운영 handler의 PostgreSQL + inheritance/hall-of-fame/dynasty 정산은 실행하지 않는다. +- yearbook PostgreSQL upsert와 tournament Redis lifecycle도 실행하지 않는다. + 이 외부 저장소들의 메모리는 아래 프로세스 수치에 포함되지 않는다. + +연감 map/nation payload는 같은 월 경계 world 상태라면 결정적이고 hash가 +같다. 토너먼트 월 판정도 `hiddenSeed + previous year/month`와 선행 국가 +power RNG 소비 횟수가 같으면 결정적이다. 이 profile 조사 중 발견한 빈 +`tournamentPattern`의 `Math.random()` fallback은 +`hiddenSeed, "monthly", previousYear, previousMonth, "tournamentPattern"` +전용 `LiteHashDRBG` shuffle로 교체했다. 이 독립 substream은 pattern을 +결정적으로 만들면서 뒤따르는 중립 경매의 기존 monthly RNG 위치를 바꾸지 +않는다. + +## 실행 + +```bash +pnpm --filter @sammo-ts/game-engine profile:npc-unification-memory +``` + +runner는 `node --expose-gc`, Vitest thread worker 1개로 이 파일만 실행한다. +전체 JSON은 기본적으로 +`app/game-engine/test-results/npc-unification-memory.json`에 기록되며 +`test-results/`는 Git에서 제외된다. 경로는 +`NPC_UNIFICATION_MEMORY_REPORT_PATH`로 바꿀 수 있다. + +## 측정 정의 + +- `maxObservedHeapUsedBytes`: 월별 관찰과 명시적 GC 전후 savepoint sample에서 + 본 Node heap 최고치 +- `maxObservedRssBytes`: 같은 관찰점의 프로세스 RSS 최고치 +- `processResourceMaxRssBytes`: OS가 보고한 실행 전체 high-water RSS +- `participantSnapshotBytes`: world와 reserved-turn snapshot을 V8 serialize한 + 크기. 실제 live heap 크기가 아니라 비교 가능한 payload 크기다. +- `participantSnapshotHeapDeltaBytes.peakWhileRetained`: 명시적 GC 직후 + snapshot을 잡아 둔 동안의 heap 증가 최고치 +- `participantSnapshotHeapDeltaBytes.peakAfterRelease`: snapshot 참조를 + 해제하고 다시 GC한 뒤 baseline 대비 heap 차이 최고치 +- `participantSnapshotCloneMs`: `captureState()` 두 개의 복제 시간 + +프로세스 수치는 Node, Vitest worker, 테스트 harness, engine state를 모두 +포함한다. 반대로 PostgreSQL, Redis와 production daemon 주변 프로세스는 +포함하지 않는다. + +## 2026-07-28 관찰 결과 + +Node `v24.14.1`, Linux x64에서 독립 실행 두 번 모두 다음 게임 결과가 +동일했다. + +- 193년 1월 통일, 137개월 진행 +- 5개국 건국, 선전포고 6회, 출병 2,136회 +- 종료 시 장수 356명 +- participant snapshot: 초기 139,363 bytes, 종료 449,359 bytes, + 최고 452,686 bytes +- snapshot 유지 중 heap 증가 최고 2,399,640 bytes, 해제·GC 후 최고 + 1,132,104 bytes + +프로세스 관찰값은 실행별로 다음과 같았다. + +| 실행 | wall time | max heap used | max observed RSS | OS max RSS | clone 평균 / 최고 | +| --- | ---: | ---: | ---: | ---: | ---: | +| 1 | 19.87 s | 145,309,008 B | 481,943,552 B | 486,830,080 B | 3.18 / 4.33 ms | +| 2 | 19.86 s | 145,253,136 B | 488,198,144 B | 489,697,280 B | 3.24 / 3.91 ms | + +게임 결과와 serialized snapshot 크기는 두 번 모두 정확히 같았다. RSS는 +allocator/JIT/Vitest 영향으로 약 6.3 MB 차이가 났으므로 단일 숫자를 엔진 +상태 크기로 해석하지 않는다. + +## 해석과 남은 범위 + +이 fixture에서 계산 rollback용 participant snapshot payload의 최고치는 +약 0.43 MiB이고, snapshot이 살아 있는 순간의 관찰 heap 증가는 약 +2.29 MiB였다. 반면 전체 테스트 프로세스 high-water RSS는 약 +464–467 MiB였다. 따라서 이 실행에서 RSS 대부분을 savepoint payload +자체가 설명하지는 않는다. + +운영 통일 handler는 `isUnited`와 history를 memory에 반영한 뒤 inheritance, +hall-of-fame, dynasty PostgreSQL 정산 세 개를 await하지 않고 시작한다. +이 프로파일은 통일 판정까지의 engine memory를 측정하지만 그 비동기 정산의 +완료, 실패 복구, 메모리 또는 distributed atomicity는 검증하지 않는다. +그 경로를 관찰하려면 격리 PostgreSQL fixture와 정산 완료 barrier 또는 +durable outbox가 별도로 필요하다.