generated from ttipo/project-base
test(backend): CPU 시간 단언을 지금 스레드의 user 시간으로 — CI 흔들림 고침
CI / Backend (lint · type-check · test · e2e · build) (pull_request) Successful in 13m21s
CI / Frontend (lint · type-check · test · build) (pull_request) Successful in 12m37s
CI / Infra (compose · Dockerfile · nginx · 운영 스크립트) (pull_request) Successful in 2m18s
CI / 에러 코드 SSOT 동기화 검사 (pull_request) Successful in 11m10s
CI / Backend (lint · type-check · test · e2e · build) (push) Successful in 14m41s
CI / Frontend (lint · type-check · test · build) (push) Successful in 14m29s
CI / Infra (compose · Dockerfile · nginx · 운영 스크립트) (push) Successful in 2m26s
CI / 에러 코드 SSOT 동기화 검사 (push) Successful in 12m27s
CI / Backend (lint · type-check · test · e2e · build) (pull_request) Successful in 13m21s
CI / Frontend (lint · type-check · test · build) (pull_request) Successful in 12m37s
CI / Infra (compose · Dockerfile · nginx · 운영 스크립트) (pull_request) Successful in 2m18s
CI / 에러 코드 SSOT 동기화 검사 (pull_request) Successful in 11m10s
CI / Backend (lint · type-check · test · e2e · build) (push) Successful in 14m41s
CI / Frontend (lint · type-check · test · build) (push) Successful in 14m29s
CI / Infra (compose · Dockerfile · nginx · 운영 스크립트) (push) Successful in 2m26s
CI / 에러 코드 SSOT 동기화 검사 (push) Successful in 12m27s
문서만 바꾼 PR(#8, run 138)의 CI 에서 할당이 많은 성능 단언 셋이 넘쳤다(받는 사람 맞추기 3.29초 · JSON 모양 1.35초 · DTO 2.94초). 프로세스 user + system 시간에는 V8 의 GC · JIT 도우미 스레드와 페이지 폴트 몫이 들어가 기계 사정을 따라 크게 흔들린다. 같은 Linux 컨테이너에서 전체 테스트 16회: 프로세스 user + system 은 4회 넘침, 스레드 user 는 0회. 막으려는 옛 경로(제곱)는 거의 user 시간이라 그대로 잡힌다(받는 사람 맞추기 옛 방법 51~70초). 받는 사람 맞추기 한도는 CI 쪽 값(0.17~0.25초)의 10배쯤인 2.5초로 올렸다. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit was merged in pull request #12.
This commit is contained in:
+43
-11
@@ -3,14 +3,28 @@
|
||||
*
|
||||
* 왜 벽시계(performance.now)가 아닌가: 다른 프로세스가 CPU 를 나눠 쓰면 벽시계 시간은 그만큼 늘어난다.
|
||||
* 2026-10-27 바쁜 PC(병렬 테스트·개발 서버와 함께)에서 혼자 0.7~0.8초인 정화가 5.9초·9.1초로 재져
|
||||
* 전체 테스트 4번 중 2번이 실패했다. CPU 시간은 이 프로세스가 실제로 계산한 시간만 세므로 다른 작업이 많아도 거의 늘지 않는다 —
|
||||
* 전체 테스트 4번 중 2번이 실패했다. CPU 시간은 실제로 계산한 시간만 세므로 다른 작업이 많아도 덜 는다 —
|
||||
* "계산량이 입력 길이에 비례하는가(예전의 제곱 경로가 돌아오지 않았는가)"를 보는 단언에 쓴다.
|
||||
*
|
||||
* - 프로세스 전체(GC·JIT 스레드 포함)의 user + system 시간이다 — 한도는 지금 값의 10배쯤 넉넉하게, 예전의 제곱 경로는 확실히 넘는 값으로 둔다.
|
||||
* CPU 시간도 늘지 않는 것은 아니다 — 2026-10-28 CI 와 같은 Linux 컨테이너(Docker Desktop)에서 메모리가 모자라고 테스트가 함께 돌 때
|
||||
* 평소의 4~7배로 재져, 여유가 3~6배뿐이던 한도 두 곳이 CI 를 실패시켰다(이미지 많은 정화 1.6초 → 5.75초, DTO 검사 0.08초 → 0.59초).
|
||||
* - **지금 스레드**(테스트 코드가 도는 JS 스레드)의 **user 시간만** 센다 — `process.threadCpuUsage`.
|
||||
* 함수가 없거나 플랫폼이 스레드 시간을 주지 못하면(부르면 던진다) 프로세스 전체(`process.cpuUsage`)의 user 시간으로 물러선다.
|
||||
* 빼는 둘은 잰 코드가 아니라 그때 기계가 얼마나 바쁜지를 따라 흔들린다:
|
||||
* - 다른 스레드 — V8 은 GC(병렬 스캐빈지 · 동시 마킹)와 JIT 컴파일을 도우미 스레드에 나눠 맡긴다.
|
||||
* 할당이 많은 단언에서 프로세스 시간이 이 스레드 시간의 많게는 2~3배였다.
|
||||
* - system 시간 — 새 메모리를 처음 만질 때의 페이지 폴트 등. CI 와 같은 Linux 컨테이너(Docker Desktop VM)에서 JSON.parse 를 포함한 모양 확인이
|
||||
* 혼자는 user 17~45ms · system 16~28ms 인데, 전체 테스트와 함께 돌 때는 같은 폴트 수(4~8천)에 system 이 366ms 까지 갔다.
|
||||
* 2026-10-31 CI(문서만 바꾼 PR)에서 할당이 많은 단언 세 곳이 그때의 프로세스 user + system 시간으로 넘쳤다 — 받는 사람 맞추기 3.29초(한도 1.5초) ·
|
||||
* JSON.parse 를 포함한 모양 확인 1.35초(0.5초) · DTO 검사 2.94초(2초). 같은 컨테이너에서 전체 테스트를 16번 돌리니 한도를 넘은 회가
|
||||
* 프로세스 user + system 으로 4번 · 스레드 user + system 으로 2번 · 스레드 user 로 0번이었다.
|
||||
* 막으려는 옛 경로(제곱 등)는 거의 다 user 시간이라 그대로 넘는다 — 받는 사람 맞추기의 옛 방법은 스레드 51.2초 가운데 user 51.0초.
|
||||
* - user 시간도 부하에서 는다 — 이 스레드가 직접 하는 GC 몫, 코어를 나눠 쓰는 느려짐(하이퍼스레딩 · 효율 코어), VM 이 vCPU 를 쉬게 한 시간
|
||||
* (Docker Desktop VM 은 steal 로 따로 세지 않는다)이 그대로 들어간다 — 위 16번에서 혼자일 때의 3~8배, 많게는 16배까지 재졌다.
|
||||
* 2026-10-28 에도 (그때는 프로세스 user + system 으로) 메모리가 모자라고 테스트가 함께 돌 때 평소의 4~7배로 재져, 여유가 3~6배뿐이던 한도 두 곳이
|
||||
* CI 를 실패시켰다(이미지 많은 정화 1.6초 → 5.75초, DTO 검사 0.08초 → 0.59초). 그래서 한도는 지금 값의 10배쯤 넉넉하게, 예전의 제곱 경로는 확실히 넘는 값으로 둔다.
|
||||
* 지금 값은 CI 와 같은 Linux 컨테이너(Node 24)에서도 잰다 — 호스트(Windows · Node 22)보다 2배쯤 크게 재지는 단언이 있다.
|
||||
* - 기다리는 시간(I/O·타이머)은 CPU 시간에 들어가지 않는다 — 그런 단언(예: 파일이 지워질 때까지 기다리기)에는 쓰지 않는다.
|
||||
* - Windows 에서는 CPU 시간이 스케줄러 틱(약 15.6ms) 단위로 는다 — 수십 ms 아래를 비교하는 데 쓰지 않는다.
|
||||
* system 시간을 세지 않으므로 시스템 호출이 많은 코드의 비용을 재는 데도 쓰지 않는다.
|
||||
* - Windows 에서는 CPU 시간이 스케줄러 틱(약 15.6ms) 단위로 는다(스레드 시간도) — 수십 ms 아래를 비교하는 데 쓰지 않는다.
|
||||
*
|
||||
* 위치: src 밖(test/)이라 빌드(nest build 는 sourceRoot 인 src 만 컴파일한다)와 단위 테스트 커버리지(rootDir 이 src)에 들어가지 않고,
|
||||
* 이름이 `*.spec.ts` 가 아니라 테스트로 돌지도 않는다. 단위 테스트는 `@/../test/cpu-time` 으로 부른다 —
|
||||
@@ -19,17 +33,35 @@
|
||||
|
||||
const MICROSECONDS_PER_MS = 1_000;
|
||||
|
||||
/** CPU 시간 읽기 — 앞서 읽은 값을 주면 그때부터 쓴 만큼 (process.cpuUsage 와 같은 모양) */
|
||||
type CpuUsageReader = (previous?: NodeJS.CpuUsage) => NodeJS.CpuUsage;
|
||||
|
||||
/**
|
||||
* 지금부터 재기 시작한다. 돌려준 함수를 부르면 그때까지 이 프로세스가 쓴 CPU 시간(ms)을 준다.
|
||||
* 지금 스레드의 CPU 시간 읽기를 고른다 — 쓸 수 없으면 프로세스 전체.
|
||||
* 함수가 있어도 플랫폼이 스레드 시간을 주지 못하면(libuv 의 uv_getrusage_thread 가 ENOTSUP) 부르는 순간 던지므로 한 번 불러 본다.
|
||||
*/
|
||||
function pickCpuUsageReader(): CpuUsageReader {
|
||||
if (typeof process.threadCpuUsage === 'function') {
|
||||
try {
|
||||
process.threadCpuUsage();
|
||||
return (previous) => process.threadCpuUsage(previous);
|
||||
} catch {
|
||||
// 스레드 시간을 주지 못하는 플랫폼 — 아래 프로세스 전체로
|
||||
}
|
||||
}
|
||||
return (previous) => process.cpuUsage(previous);
|
||||
}
|
||||
|
||||
const readCpuUsage = pickCpuUsageReader();
|
||||
|
||||
/**
|
||||
* 지금부터 재기 시작한다. 돌려준 함수를 부르면 그때까지 이 스레드가 쓴 user CPU 시간(ms)을 준다.
|
||||
*
|
||||
* const cpuMs = startCpuTimer();
|
||||
* sanitizeMailHtml(html);
|
||||
* expect(cpuMs()).toBeLessThan(5_000);
|
||||
*/
|
||||
export function startCpuTimer(): () => number {
|
||||
const started = process.cpuUsage();
|
||||
return () => {
|
||||
const { user, system } = process.cpuUsage(started);
|
||||
return (user + system) / MICROSECONDS_PER_MS;
|
||||
};
|
||||
const started = readCpuUsage();
|
||||
return () => readCpuUsage(started).user / MICROSECONDS_PER_MS;
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user