test: 부하에 흔들리던 시간 검사를 계산량·조건 대기로 고정

다른 작업과 함께 돌면 혼자 0.8초인 정화가 9초로 재지는 등, 벽시계 한도와 고정 대기를 쓰던 테스트가 가끔 실패했다.

- 백엔드 성능 단언은 벽시계 대신 이 프로세스의 CPU 시간으로 잰다 (backend/test/cpu-time.ts 의 startCpuTimer).
  부하 중에도 1.4배쯤만 늘고, 예전 제곱 시간 경로(15~172초)는 그대로 한도를 넘는다
- 임시 업로드 삭제 테스트는 고정 20ms 대신 파일이 지워질 때까지 기다린다 (최대 2초, 지워지지 않으면 실패)
- 프론트 테스트 시간 한도를 20초로 (jsdom·편집기 테스트가 부하에서 5~13초), 긴 초안을 맞추는 테스트는 30초
  (src/test-utils/timeouts.ts)

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
2026-10-27 13:00:08 +09:00
parent 13888af2c2
commit 2701d04fc2
7 changed files with 112 additions and 31 deletions
@@ -13,8 +13,25 @@ function contextWith(file?: { path: string }): ExecutionContext {
} as unknown as ExecutionContext;
}
/** finalize 의 비동기 삭제가 끝날 때까지 잠깐 기다린다 */
const settle = () => new Promise((resolve) => setTimeout(resolve, 20));
/** 임시 파일이 지워지기를 기다리는 최대 시간 — 바쁜 CI 에서도 넉넉하게 */
const REMOVAL_DEADLINE_MS = 2_000;
/** 지워졌는지 다시 보는 간격 */
const REMOVAL_POLL_MS = 10;
/**
* 파일이 지워질 때까지 기다린다 — 기한 안에 지워졌으면 true, 기한이 지나도 남아 있으면 false.
* 인터셉터는 finalize 안에서 삭제를 시작만 하고 기다리지 않는다(`void this.remove(...)`) — 응답이 끝난 뒤에도 rm 이 진행 중일 수 있다.
* 예전에는 고정으로 20ms 만 기다렸는데, 부하가 큰 CI 에서 rm 이 그보다 늦어 가끔 실패했다 (2026-10-27).
* 그래서 지워질 때까지 자주 확인하고, 기한 안에 지워졌는지를 검사한다 — 삭제가 빠지면 기한 뒤에 그대로 실패한다.
*/
async function waitUntilRemoved(path: string): Promise<boolean> {
const deadline = Date.now() + REMOVAL_DEADLINE_MS;
while (existsSync(path)) {
if (Date.now() >= deadline) return false;
await new Promise((resolve) => setTimeout(resolve, REMOVAL_POLL_MS));
}
return true;
}
describe('DeleteUploadedFileInterceptor', () => {
let dir: string;
@@ -35,9 +52,8 @@ describe('DeleteUploadedFileInterceptor', () => {
await expect(
lastValueFrom(interceptor.intercept(contextWith({ path: file }), next)),
).resolves.toEqual({ id: 'blob' });
await settle();
expect(existsSync(file)).toBe(false);
await expect(waitUntilRemoved(file)).resolves.toBe(true);
});
it('핸들러가 실패해도 임시 파일을 지운다', async () => {
@@ -48,9 +64,8 @@ describe('DeleteUploadedFileInterceptor', () => {
await expect(
lastValueFrom(interceptor.intercept(contextWith({ path: file }), next)),
).rejects.toThrow('engine down');
await settle();
expect(existsSync(file)).toBe(false);
await expect(waitUntilRemoved(file)).resolves.toBe(true);
});
it('파일이 없는 요청은 그냥 통과한다', async () => {
@@ -1,5 +1,6 @@
import { Parser } from 'htmlparser2';
import { startCpuTimer } from '@/../test/cpu-time';
import {
MAX_HTML_PARSE_COST,
MAX_HTML_PARSE_LENGTH,
@@ -9,8 +10,11 @@ import {
import { sanitizeMailHtml } from './sanitize-mail-html';
import { sanitizeOutgoingHtml } from './sanitize-outgoing-html';
/** 시간 단언은 넉넉하게 — 이 PC 에서 검사는 2MB 에 0.1초 안쪽이다 (느린 CI 도 견디게) */
const GENEROUS_MS = 2_000;
/**
* CPU 시간 한도 (벽시계가 아니다 — test/cpu-time.ts). 지금 검사는 2MB 를 끝까지 읽어도 CPU 0.3초 안쪽이고 공격 모양은 0.15초 안쪽에 멈춘다.
* 막으려는 제곱 경로는 같은 공격 입력을 정화하는 것 — '<b>' 2MB 에 172초다.
*/
const GENEROUS_CPU_MS = 2_000;
/** 보내는 서식 본문 한도 (계약 2절 — DTO 가 막는다) */
const OUTGOING_MAX_CHARS = 500_000;
@@ -19,10 +23,11 @@ const OUTGOING_MAX_CHARS = 500_000;
const fillTo = (unit: string, chars = MAX_HTML_PARSE_LENGTH) =>
unit.repeat(Math.floor(chars / unit.length));
function elapsedMs<T>(run: () => T): [number, T] {
const started = performance.now();
/** run 이 쓴 CPU 시간(ms)과 그 결과 */
function cpuTimed<T>(run: () => T): [number, T] {
const cpuMs = startCpuTimer();
const result = run();
return [performance.now() - started, result];
return [cpuMs(), result];
}
/** htmlparser2 Parser 의 빈 요소 (12.0.0 src/Parser.ts) — 스택에 올라가지 않으므로 비교에서 뺀다 */
@@ -227,10 +232,11 @@ describe('checkHtmlParseBudget (정화 전 사전 검사)', () => {
const html = make(MAX_HTML_PARSE_LENGTH);
expect(html.length).toBeLessThanOrEqual(MAX_HTML_PARSE_LENGTH);
const [ms, result] = elapsedMs(() => checkHtmlParseBudget(html));
const [cpuMs, result] = cpuTimed(() => checkHtmlParseBudget(html));
expect(result).toEqual({ ok: false, reason: 'too-complex' });
expect(ms).toBeLessThan(GENEROUS_MS);
// 지금 CPU 0.15초 안쪽에 멈춘다 — 정화까지 갔다면 '<b>' 2MB 에 172초
expect(cpuMs).toBeLessThan(GENEROUS_CPU_MS);
});
it.each(ATTACKS)('보내는 서식 본문 500,000자 — %s', (_name, make) => {
@@ -265,10 +271,11 @@ describe('checkHtmlParseBudget (정화 전 사전 검사)', () => {
const html = make();
expect(html.length).toBeLessThanOrEqual(MAX_HTML_PARSE_LENGTH);
const [ms, result] = elapsedMs(() => checkHtmlParseBudget(html));
const [cpuMs, result] = cpuTimed(() => checkHtmlParseBudget(html));
expect(result).toEqual({ ok: true });
expect(ms).toBeLessThan(GENEROUS_MS);
// 끝까지 읽어도 지금 CPU 0.3초 안쪽 (검사는 사건마다 O(1) — 스택을 훑지 않는다)
expect(cpuMs).toBeLessThan(GENEROUS_CPU_MS);
});
it('300단 인용 스레드도 상한에 3배 넘게 여유가 있다', () => {
@@ -294,12 +301,12 @@ describe('checkHtmlParseBudget (정화 전 사전 검사)', () => {
const html = '<b>'.repeat(1_000) + '</i>'.repeat(closes);
expect(checkHtmlParseBudget(html)).toEqual({ ok: true });
const [receivedMs] = elapsedMs(() => sanitizeMailHtml(html));
const [outgoingMs] = elapsedMs(() => sanitizeOutgoingHtml(html));
const [receivedCpuMs] = cpuTimed(() => sanitizeMailHtml(html));
const [outgoingCpuMs] = cpuTimed(() => sanitizeOutgoingHtml(html));
// 이 PC 에서 0.1~0.2초 — 상한이 없으면 같은 모양 2MB 가 0.6초, 깊이 3000 이면 1.7초다
expect(receivedMs).toBeLessThan(GENEROUS_MS);
expect(outgoingMs).toBeLessThan(GENEROUS_MS);
// 지금 CPU 0.2~0.4초 — 상한이 없으면 같은 모양 2MB 가 0.6초, 깊이 3000 이면 1.7초다 (벽시계로 잰 값)
expect(receivedCpuMs).toBeLessThan(GENEROUS_CPU_MS);
expect(outgoingCpuMs).toBeLessThan(GENEROUS_CPU_MS);
});
});
@@ -325,12 +332,12 @@ describe('measureHtmlParseCost', () => {
const html = '<b>'.repeat(600_000);
const limit = 1_000_000;
const [ms, cost] = elapsedMs(() => measureHtmlParseCost(html, { limit }));
const [cpuMs, cost] = cpuTimed(() => measureHtmlParseCost(html, { limit }));
// 깊이 1414 쯤에서 넘는다 (끝까지 세면 1.8×10¹¹)
// 깊이 1414 쯤에서 넘는다 (끝까지 세면 1.8×10¹¹) — 멈췄는지는 비용 단언이 본다. 지금 CPU 수 ms
expect(cost).toBeGreaterThan(limit);
expect(cost).toBeLessThan(limit + 2_000);
expect(ms).toBeLessThan(GENEROUS_MS);
expect(cpuMs).toBeLessThan(GENEROUS_CPU_MS);
});
describe('htmlparser2 Parser 와 같은 순서로 열고 닫는다 — 판을 올려 규칙이 바뀌면 여기서 걸린다', () => {
@@ -1,3 +1,4 @@
import { startCpuTimer } from '@/../test/cpu-time';
import { sanitizeMailHtml } from './sanitize-mail-html';
const clean = (html: string, inline?: ReadonlyMap<string, string>) =>
@@ -99,14 +100,15 @@ describe('sanitizeMailHtml', () => {
});
it('url( 뒤 공백이 아주 길어도 한 번만 훑는다 (예전: 공백 4만 개에 0.6초 — 공백 수의 제곱)', () => {
const started = performance.now();
const cpuMs = startCpuTimer();
const result = sanitizeMailHtml(
`<b style="background:url(${' '.repeat(1_900_000)}x)">y</b>`,
);
expect(result).toEqual({ html: '<b>y</b>', hasBlockedImages: false });
expect(performance.now() - started).toBeLessThan(2_000);
// CPU 시간 (test/cpu-time.ts) — 지금 190만 개에 0.2초 안쪽. 예전 제곱 경로면 같은 길이에 20분 넘게 걸린다 (0.6초 × 47.5²)
expect(cpuMs()).toBeLessThan(2_000);
// 따옴표 앞뒤의 공백도 그대로 외부 주소로 알아본다
expect(
sanitizeMailHtml(
@@ -224,13 +226,14 @@ describe('sanitizeMailHtml', () => {
it('주소가 남지 않은 이미지가 아주 많아도 입력 길이에 비례해 끝난다 (예전: 27만 개에 15초)', () => {
const count = 333_333; // 2MB
const started = performance.now();
const cpuMs = startCpuTimer();
const result = sanitizeMailHtml('x<img>'.repeat(count));
expect(result.html).toBe('x'.repeat(count));
// 이 PC 에서 0.5초 안쪽 — 넉넉하게
expect(performance.now() - started).toBeLessThan(5_000);
// CPU 시간 (test/cpu-time.ts) — 지금 1.1~1.6초(부하 중에도). 예전 경로(결과를 이미지마다 다시 자름)는 27만 개(1.6MB)에 15초, 이 크기면 20초가 넘는다.
// 벽시계로 재던 때는 바쁜 PC 에서 5.9초·9.1초로 재져 실패했다 (2026-10-27)
expect(cpuMs()).toBeLessThan(5_000);
});
});
+33
View File
@@ -0,0 +1,33 @@
/**
* CPU 시간 스톱워치 — 단위 테스트 전용 도우미 (앱 코드에서 import 하지 않는다).
*
* 왜 벽시계(performance.now)가 아닌가: 다른 프로세스가 CPU 를 나눠 쓰면 벽시계 시간은 그만큼 늘어난다.
* 2026-10-27 바쁜 PC(병렬 테스트·개발 서버와 함께)에서 혼자 0.7~0.8초인 정화가 5.9초·9.1초로 재져
* 전체 테스트 4번 중 2번이 실패했다. CPU 시간은 이 프로세스가 실제로 계산한 시간만 세므로 다른 작업이 많아도 거의 늘지 않는다 —
* "계산량이 입력 길이에 비례하는가(예전의 제곱 경로가 돌아오지 않았는가)"를 보는 단언에 쓴다.
*
* - 프로세스 전체(GC·JIT 스레드 포함)의 user + system 시간이다 — 한도는 지금 값보다 넉넉하게, 예전의 제곱 경로는 확실히 넘는 값으로 둔다.
* - 기다리는 시간(I/O·타이머)은 CPU 시간에 들어가지 않는다 — 그런 단언(예: 파일이 지워질 때까지 기다리기)에는 쓰지 않는다.
* - Windows 에서는 CPU 시간이 스케줄러 틱(약 15.6ms) 단위로 는다 — 수십 ms 아래를 비교하는 데 쓰지 않는다.
*
* 위치: src 밖(test/)이라 빌드(nest build 는 sourceRoot 인 src 만 컴파일한다)와 단위 테스트 커버리지(rootDir 이 src)에 들어가지 않고,
* 이름이 `*.spec.ts` 가 아니라 테스트로 돌지도 않는다. 단위 테스트는 `@/../test/cpu-time` 으로 부른다 —
* `@/` 기준이라 부르는 파일의 깊이와 상관없다 (tsconfig paths 와 jest moduleNameMapper 가 그대로 푼다).
*/
const MICROSECONDS_PER_MS = 1_000;
/**
* 지금부터 재기 시작한다. 돌려준 함수를 부르면 그때까지 이 프로세스가 쓴 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;
};
}
@@ -8,6 +8,7 @@ import { docToText } from '@/components/mail/editor/mail-serialize'
import { MAIL_BODY_MAX_LENGTH, MAIL_QUOTE_OMITTED_MARK } from '@/shared/constants/mail'
import { MAIL_BODY_HTML_MAX_LENGTH } from '@/shared/constants/mail-editor'
import { editorOf, fileDragEvent, installProseMirrorDom, pasteEvent } from '@/test-utils/prosemirror-dom'
import { LONG_DRAFT_TIMEOUT_MS } from '@/test-utils/timeouts'
import { buildQuoteHtml, textToParagraphHtml } from '@/shared/utils/mail-quote'
type EditorWrapper = VueWrapper<InstanceType<typeof MailEditor>>
@@ -112,7 +113,7 @@ describe('MailEditor (서식 편집기)', () => {
expect(html?.length ?? 0).toBeLessThanOrEqual(INITIAL_DRAFT_LIMITS.html)
expect(text.endsWith(`> ${MAIL_QUOTE_OMITTED_MARK}`)).toBe(true)
expect(text).toContain('> 제목: 긴 메일')
})
}, LONG_DRAFT_TIMEOUT_MS)
describe('보내기 직전의 길이 (텍스트 100,000 · 서식 500,000 — 최종 직렬화 결과로 잰다)', () => {
it('맞춘 초안에 몇 글자 쓰면 그대로 보낸다 — 남겨 둔 자리 안이다', () => {
@@ -127,7 +128,7 @@ describe('MailEditor (서식 편집기)', () => {
expect(content?.text.length).toBeLessThanOrEqual(MAIL_BODY_MAX_LENGTH)
// 인용은 그대로 — 처음 맞춘 모양
expect(mailQuoteOf(editor.state.doc)).toBe(quoteBefore)
})
}, LONG_DRAFT_TIMEOUT_MS)
it('남겨 둔 자리보다 길게 쓰면 인용을 더 줄여 맞추고 편집기에도 그 모양을 보인다 — 내 글은 그대로', () => {
const view = mountEditor({ initialHtml: longQuoteDraft(), fitToLimits: true })
@@ -148,7 +149,7 @@ describe('MailEditor (서식 편집기)', () => {
// 실행 취소로 되돌릴 수 있다
editor.commands.undo()
expect(docToText(editor.state.doc).length).toBeGreaterThan(MAIL_BODY_MAX_LENGTH)
})
}, LONG_DRAFT_TIMEOUT_MS)
it('인용이 없는데(또는 인용을 다 줄여도) 내 글만으로 넘으면 null — 편집기는 그대로 둔다', () => {
const view = mountEditor()
+11
View File
@@ -0,0 +1,11 @@
// 단위 테스트 전용 — 여러 테스트 파일이 함께 쓰는 시간 한도. 전체 한도는 vitest.config.ts 의 TEST_TIMEOUT_MS(20초)다.
// 앱 코드에서 import 하지 않는다 (번들에 들어가지 않는다).
/**
* 긴 초안 — 텍스트 한도(100,000자)를 넘는 11만 자 남짓의 원문 인용 — 을 만들어 한도에 맞추는 테스트의 시간 한도.
* 초안을 편집기로 옮기고 한도에 맞추느라 오래 걸린다 (MailEditor.spec 의 긴 초안 테스트 · ComposePage.spec 의 긴 답장 보내기).
* 따로 돌리면 0.7~3.6초지만, 전체 테스트를 한꺼번에 돌리던 중 5.76초, 이 파일과 전체 실행을 함께 돌린 부하에서 11.7초,
* 전체 실행 두 개를 함께 돌린 부하에서 13.2초까지 걸렸다 — 쓰기 화면의 긴 답장 보내기는 부하에서 7.6초 (2026-10-27).
* 전체 한도에 가까워 이 테스트들에만 30초를 준다.
*/
export const LONG_DRAFT_TIMEOUT_MS = 30_000
+11
View File
@@ -2,6 +2,15 @@ import { fileURLToPath } from 'node:url'
import { mergeConfig, defineConfig, configDefaults } from 'vitest/config'
import viteConfig from './vite.config'
/**
* 테스트 하나 · 훅 하나의 시간 한도 (기본은 테스트 5초 · 훅 10초).
* jsdom 에 서식 편집기(TipTap/ProseMirror)를 띄우는 테스트는 CPU 를 많이 쓴다 — 부하가 걸리면 테스트 하나가 5~13초 걸려
* 기본 5초에서 전체 실행이 들쭉날쭉 실패했다. 이 호스트는 다른 프로젝트의 CI 도 함께 돌려 두 겹 부하가 흔하다 —
* 전체 실행 두 개를 함께 돌리자 15초 한도 아래의 가장 느린 테스트가 12.8초까지 걸려 20초로 둔다 (2026-10-27).
* 정말 멈춘 테스트는 이 한도(20초) 안에 여전히 실패한다.
*/
const TEST_TIMEOUT_MS = 20_000
// vite.config 는 mode 별 설정(포트·프록시)을 계산하는 함수다.
// mergeConfig 는 함수를 병합하지 못하므로 테스트용 ConfigEnv 로 먼저 평가한다.
// (테스트는 dev 서버를 띄우지 않아 포트·프록시 값에 영향받지 않는다)
@@ -12,6 +21,8 @@ export default mergeConfig(
environment: 'jsdom',
exclude: [...configDefaults.exclude, 'e2e/**'],
root: fileURLToPath(new URL('./', import.meta.url)),
testTimeout: TEST_TIMEOUT_MS,
hookTimeout: TEST_TIMEOUT_MS,
},
}),
)