/* * 부하 계기판 — **어떤 작업이 루프를 얼마나 쓰는지.** * * 지키는 것: ① 작업별로 따로 쌓인다 ② 무거운 것부터 나온다 ③ 몫이 합계와 맞는다 ④ 잰 적이 없으면 * `null`(0 이 아니다) ⑤ 예산 초과를 세되 경고는 쿨다운을 둔다 ⑥ 경고 문구가 **무엇이 느린지** 말한다. * * ④가 특히 중요하다. 재지 않은 것을 0 으로 채우면 "0ms 다"(= 아주 빠르다)로 읽혀 **재지 않았다는 사실과 * 정반대의 뜻**이 된다. 이 세션에서 같은 종류의 착각을 여러 번 겪었다 — 포트가 열렸다고 서버가 응답하는 * 줄 알았던 것도 그것이다. */ import { test } from 'node:test' import assert from 'node:assert/strict' import { LOAD_PHASES, fleetLoad, newCpuSampler, sampleCpu, judgeCycle, loadSummary, newLoadMeter, recordFork, recordPhase, rollWindow, slowTickMessage, TICK_BUDGET_RATIO, WARN_COOLDOWN_MS, WINDOW_MS } from '../server/engine/load-meter.ts' const TICK = 1000 test('작업별로 따로 쌓이고, 무거운 것부터 나온다', () => { const m = newLoadMeter() recordPhase(m, 'tick', 300) recordPhase(m, 'tick', 500) recordPhase(m, 'snapshot', 100) recordPhase(m, 'publish', 20) const s = loadSummary(m, TICK)!.total! assert.deepEqual(s.phases.map(p => p.phase), ['tick', 'snapshot', 'publish'], '총 시간 순') const tick = s.phases[0] assert.equal(tick.count, 2) assert.equal(tick.lastMs, 500) assert.equal(tick.maxMs, 500) assert.equal(tick.avgMs, 400) assert.equal(tick.totalMs, 800) }) test('몫이 잰 작업들의 합과 맞는다 — 어디를 고칠지 이 값이 정한다', () => { const m = newLoadMeter() recordPhase(m, 'tick', 750) recordPhase(m, 'snapshot', 250) const s = loadSummary(m, TICK)!.total! assert.equal(s.measuredTotalMs, 1000) assert.equal(s.phases.find(p => p.phase === 'tick')!.share, 0.75) assert.equal(s.phases.find(p => p.phase === 'snapshot')!.share, 0.25) assert.equal( +s.phases.reduce((a, p) => a + p.share, 0).toFixed(2), 1, '몫의 합은 1 — 다만 재지 않은 작업은 분모에 없다' ) }) test('잰 적이 없으면 null 이다 — 0 으로 채우면 "빠르다" 로 읽힌다', () => { assert.equal(loadSummary(undefined, TICK), null, '계기판 자체가 없을 때') assert.equal(loadSummary(newLoadMeter(), TICK), null, '있지만 한 번도 안 쟀을 때') const m = newLoadMeter() recordPhase(m, 'publish', 5) assert.equal(loadSummary(m, TICK)!.loadRatio, null, '틱을 안 쟀으면 루프 점유율도 없다 — 0 이 아니다') }) test('음수·NaN 은 기록하지 않는다 — 시계가 뒤로 가도 평균이 거짓이 되지 않게', () => { const m = newLoadMeter() recordPhase(m, 'tick', -5) recordPhase(m, 'tick', NaN) recordPhase(m, 'tick', Infinity) assert.equal(loadSummary(m, TICK), null, '아무것도 안 쌓였다') }) test('예산은 간격의 절반 — 넘으면 센다', () => { const m = newLoadMeter() const under = judgeCycle(m, TICK * TICK_BUDGET_RATIO - 1, TICK, 0) assert.equal(under.over, false) assert.equal(m.overBudget, 0) const over = judgeCycle(m, TICK * TICK_BUDGET_RATIO + 1, TICK, 0) assert.equal(over.over, true) assert.equal(over.budgetMs, 500) assert.equal(m.overBudget, 1) }) test('경고는 쿨다운을 둔다 — 느린 트윈이 매 틱 경고하면 로그가 원인을 덮는다', () => { const m = newLoadMeter() const slow = 900 assert.equal(judgeCycle(m, slow, TICK, 1000).warn, true, '처음엔 말한다') assert.equal(judgeCycle(m, slow, TICK, 2000).warn, false, '쿨다운 안에는 알리지 않고') assert.equal(judgeCycle(m, slow, TICK, 1000 + WARN_COOLDOWN_MS).warn, true, '쿨다운이 지나면 다시') assert.equal(m.overBudget, 3, '말하지 않아도 세기는 한다') }) test('경고 문구가 무엇이 느린지 알린다 — "틱 800ms" 만으로는 볼 곳을 모른다', () => { const m = newLoadMeter() recordPhase(m, 'tick', 800) recordPhase(m, 'snapshot', 600) recordPhase(m, 'publish', 100) const msg = slowTickMessage('wms-1', 800, 500, m) assert.match(msg, /wms-1/) assert.match(msg, /800ms/) assert.match(msg, /예산 500ms/) assert.match(msg, /tick .*%/, '가장 무거운 작업과 몫') assert.match(msg, /snapshot/, '두 번째로 무거운 것까지') assert.match(msg, /메인 이벤트 루프/, '왜 문제인지도 말한다') }) test('실시간(최근 창)과 누적을 따로 낸다 — 지금 아픈 것과 오래 쌓인 것은 다르다', () => { const m = newLoadMeter() recordPhase(m, 'tick', 100, 0) // 첫 창 시작 recordPhase(m, 'tick', 100, 1000) recordPhase(m, 'tick', 700, WINDOW_MS + 1) // 창이 닫히고 새 창에 쌓인다 const s = loadSummary(m, TICK)! assert.equal(s.total!.phases[0].totalMs, 900, '누적은 전부') assert.equal(s.recent!.measuredTotalMs, 200, '최근은 닫힌 창만 — 채우는 중인 창은 과소 집계라 안 쓴다') assert.equal(s.recent!.spanMs, WINDOW_MS + 1) assert.equal(s.recent!.busyRatio, 0.02, '창의 2%를 썼다') }) test('창이 하나도 안 닫혔으면 최근은 null — 채우는 중인 값을 실시간이라 하지 않는다', () => { const m = newLoadMeter() recordPhase(m, 'tick', 300, 0) recordPhase(m, 'tick', 300, 500) const s = loadSummary(m, TICK)! assert.equal(s.recent, null) assert.equal(s.total!.measuredTotalMs, 600) assert.equal(s.total!.spanMs, null, '누적은 구간을 모른다') assert.equal(s.total!.busyRatio, null, '구간을 모르면 비율도 없다 — 0 이 아니다') }) test('fork 수를 센다 — 예측 한 번이 수십 개를 만든다', () => { const m = newLoadMeter() recordFork(m, 30) recordFork(m) assert.equal(loadSummary(m, TICK)!.forksCreated, 31, '아무 작업도 안 쟀어도 fork 수는 보인다') }) test('전체 한눈에 — 최근 부하가 큰 순서로, 대수와 fork 총수까지', () => { const mk = (busy: number, forks = 0) => { const m = newLoadMeter() recordPhase(m, 'tick', busy, 0) recordFork(m, forks) rollWindow(m, WINDOW_MS) // 창을 닫아 '최근' 으로 만든다 return m } const f = fleetLoad( [ { instanceId: 'idle-1', mode: 'sim', meter: mk(10) }, { instanceId: 'hot-1', mode: 'sim', meter: mk(4000, 30) }, { instanceId: 'live-1', mode: 'live', meter: mk(50) }, { instanceId: 'fresh-1', mode: 'sim' } // 아직 아무것도 안 쟀다 ], TICK ) assert.equal(f.instances, 4) assert.deepEqual(f.byMode, { sim: 3, live: 1 }) assert.equal(f.forksCreated, 30) assert.equal(f.slowest[0].instanceId, 'hot-1', '지금 아픈 것이 맨 위') assert.equal(f.slowest[0].topPhase, 'tick') assert.equal(f.slowest.at(-1)!.instanceId, 'fresh-1', '안 잰 것은 0 으로 맨 아래') assert.equal(f.recentBusyMs, 4060) assert.equal(f.recentSpanMs, WINDOW_MS) assert.equal(f.fleetBusyRatio, 0.406, '창의 40.6% — 1 을 넘으면 한 틱 안에 다 못 끝낸다') }) test('전체 뷰: 닫힌 창이 하나도 없으면 비율을 지어내지 않는다', () => { const f = fleetLoad([{ instanceId: 'a', mode: 'sim', meter: newLoadMeter() }], TICK) assert.equal(f.recentSpanMs, null) assert.equal(f.fleetBusyRatio, null) assert.equal(f.recentBusyMs, 0) }) test('아주 작은 비율이 0 으로 사라지지 않는다 — 재서 나온 값과 없는 값은 다르다', () => { const m = newLoadMeter() recordPhase(m, 'tick', 24, 0) rollWindow(m, 11_000) const r = loadSummary(m, TICK)!.recent! assert.ok(r.busyRatio! > 0, `0 이 되면 "안 쓴다" 로 읽힌다 — 실제 ${r.busyRatio}`) assert.equal(r.busyRatio, 0.0022) }) test('도메인별 점유 — 어느 테넌트가 루프를 먹나', () => { const mk = (busy: number) => { const m = newLoadMeter() recordPhase(m, 'tick', busy, 0) rollWindow(m, WINDOW_MS) return m } const f = fleetLoad( [ { instanceId: 'a1', mode: 'sim', domainId: 'D1', domainLabel: 'acme', meter: mk(300) }, { instanceId: 'a2', mode: 'sim', domainId: 'D1', domainLabel: 'acme', meter: mk(500) }, { instanceId: 'b1', mode: 'live', domainId: 'D2', meter: mk(200) }, { instanceId: 'c1', mode: 'sim' } // 도메인도 계측도 없다 ], TICK ) assert.deepEqual( f.byDomain.map(d => `${d.label} ${d.instances} ${d.recentBusyMs}ms ${Math.round(d.share * 100)}%`), ['acme 2 800ms 80%', 'D2 1 200ms 20%', '(unknown) 1 0ms 0%'], '무거운 순 · 이름을 모르면 id 를 그대로 쓴다(지어내지 않는다)' ) assert.equal( +f.byDomain.reduce((a, d) => a + d.share, 0).toFixed(2), 1, '몫의 합은 1 — 잰 트윈들 사이의 비율이다' ) }) test('도메인별 점유: 아무도 안 쟀으면 몫이 0 이고 비율을 지어내지 않는다', () => { const f = fleetLoad([{ instanceId: 'a', mode: 'sim', domainId: 'D1' }], TICK) assert.equal(f.byDomain.length, 1) assert.equal(f.byDomain[0].share, 0) assert.equal(f.fleetBusyRatio, null) }) test('보이는 부분의 합이 보이는 합계와 맞는다 — 도메인 = 그 도메인 트윈들의 합', () => { /* 실제로 어긋났던 값: 잎마다 따로 반올림해서 도메인 0.08ms 인데 트윈 둘은 0.08+0.01=0.09ms 였다. */ const mk = (busy: number) => { const m = newLoadMeter() recordPhase(m, 'tick', busy, 0) rollWindow(m, WINDOW_MS) return m } const f = fleetLoad( [ { instanceId: 'big', mode: 'sim', domainId: 'D1', domainLabel: 'hatiolab', meter: mk(39.114) }, { instanceId: 's1', mode: 'sim', domainId: 'D2', domainLabel: 'system', meter: mk(0.084) }, { instanceId: 's2', mode: 'sim', domainId: 'D2', domainLabel: 'system', meter: mk(0.014) } ], TICK ) for (const d of f.byDomain) { const mine = f.slowest.filter(s => s.domainId === d.domainId) assert.equal( d.recentBusyMs, +mine.reduce((a, s) => a + s.recentBusyMs, 0).toFixed(2), `${d.label} 의 합계가 그 트윈들의 합과 다르다` ) } assert.equal( f.recentBusyMs, +f.byDomain.reduce((a, d) => a + d.recentBusyMs, 0).toFixed(2), '전체 합계가 도메인들의 합과 다르다' ) }) test('도메인 몫의 합은 1 이다 — 백분율로 읽어 100% 가 된다', () => { const mk = (busy: number) => { const m = newLoadMeter() recordPhase(m, 'tick', busy, 0) rollWindow(m, WINDOW_MS) return m } const f = fleetLoad( [ { instanceId: 'a', mode: 'sim', domainId: 'D1', meter: mk(39.11) }, { instanceId: 'b', mode: 'sim', domainId: 'D2', meter: mk(0.08) }, { instanceId: 'c', mode: 'sim', domainId: 'D3', meter: mk(0.01) } ], TICK ) assert.equal(+f.byDomain.reduce((a, d) => a + d.share, 0).toFixed(3), 1) }) test('프로세스 CPU 는 첫 표본에서 null 이다 — 잰 구간이 없으면 0 이 아니다', () => { const s = newCpuSampler() assert.equal(sampleCpu(s, 1_000_000, 1000), null, '비교할 앞 표본이 없다') }) test('프로세스 CPU 는 두 표본 사이의 점유율이다 — 코어를 여럿 쓰면 1 을 넘는다', () => { const s = newCpuSampler() sampleCpu(s, 1_000_000, 0) assert.deepEqual(sampleCpu(s, 1_500_000, 1000), { ratio: 0.5, spanMs: 1000 }, '1초에 0.5초 = 50%') assert.deepEqual(sampleCpu(s, 2_600_000, 2000), { ratio: 1.1, spanMs: 1000 }, '1초에 1.1초 = 110%, 코어 여러 개') }) test('시계가 뒤로 가거나 구간이 0 이면 비율을 지어내지 않는다', () => { const s = newCpuSampler() sampleCpu(s, 1_000_000, 1000) assert.equal(sampleCpu(s, 1_200_000, 1000), null, '구간 0') assert.equal(sampleCpu(newCpuSampler(), 5, 5), null) }) /* * ── 부팅 구간도 재는 이름을 갖는다 (2026-08-22) ───────────────────────────── * 실측으로 부팅이 620~717초였고 트윈 하나를 세우는 데 15~93초였는데, **어느 작업이 그 시간을 쓰는지 * 답할 이름이 없었다** — 재는 이름이 도는 중의 작업뿐이었다. 그래서 짐작으로 원인을 적을 수밖에 * 없었고, 그것은 이 프로젝트가 금하는 일이다. */ test('부팅 구간을 재는 이름이 있다 — 웜스타트와 자극 시작', () => { assert.ok(LOAD_PHASES.includes('warmStart' as any), '상태 심기를 재는 이름이 있어야 한다') assert.ok(LOAD_PHASES.includes('stimulus' as any), '자극 시작을 재는 이름이 있어야 한다') /* 계기가 그 값을 실제로 들고 답한다 — 이름만 있고 담기지 않으면 화면이 빈칸을 보인다. */ const m = newLoadMeter() recordPhase(m, 'warmStart', 93_000, 1_000) recordPhase(m, 'stimulus', 72_000, 1_000) assert.equal(m.phases.warmStart?.maxMs, 93_000) assert.equal(m.phases.stimulus?.maxMs, 72_000) }) test('부팅 구간은 틱 예산으로 판정하지 않는다 — 한 번뿐인 일이다', () => { /* * 웜스타트는 트윈을 세울 때 한 번이고 몇십 초가 정상일 수 있다. 그것을 틱 예산(간격의 절반)으로 * 재면 부팅마다 「느린 주기」가 쏟아진다 — 거짓 경보는 참 경보를 죽인다. 판정은 틱만 받는다. */ const m = newLoadMeter() recordPhase(m, 'warmStart', 93_000, 1_000) assert.equal(m.overBudget, 0, '기록만으로는 판정하지 않는다') })