test profile 300 NPC unification memory

This commit is contained in:
2026-07-28 05:46:16 +00:00
parent 43966ea1ef
commit 431d3afc42
5 changed files with 443 additions and 7 deletions
+1
View File
@@ -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"
},
@@ -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;
});
@@ -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,
};
}
}
@@ -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<string, unknown>;
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) {
@@ -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는 약
464467 MiB였다. 따라서 이 실행에서 RSS 대부분을 savepoint payload
자체가 설명하지는 않는다.
운영 통일 handler는 `isUnited`와 history를 memory에 반영한 뒤 inheritance,
hall-of-fame, dynasty PostgreSQL 정산 세 개를 await하지 않고 시작한다.
이 프로파일은 통일 판정까지의 engine memory를 측정하지만 그 비동기 정산의
완료, 실패 복구, 메모리 또는 distributed atomicity는 검증하지 않는다.
그 경로를 관찰하려면 격리 PostgreSQL fixture와 정산 완료 barrier 또는
durable outbox가 별도로 필요하다.