leo.dev
backend

로거 64곳을 고치지 않고 묶은 Correlation ID

— SERIES 관측가능성 Part 01 / 02
  1. Part 01 로거 64곳을 고치지 않고 묶은 Correlation ID
  2. Part 02 무음 실패와 opt-in 관측가능성 3단계

운영 중인 백엔드에서 “이 사용자가 결제하다 에러 났다는데 로그가 어디 있냐”를 찾는 건 생각보다 어렵다. 요청 하나가 컨트롤러 → 여러 서비스 → 외부 API를 거치며 수십 줄을 남기는데, 그 줄들이 같은 요청이라는 표시가 없으면 시간대로 grep해 눈으로 잇는 수밖에 없다. 요청이 동시에 여러 개 흐르면 로그가 뒤섞여 사실상 추적 불가다.

이건 관측가능성 3단계의 맨 아래 1층 이야기다. 분산추적도 에러 트래킹도 그 위에 얹는 거고, 토대는 요청마다 고유 ID를 붙여 로그를 묶는 것이다. 외부 라이브러리도 인프라도 없이, Node 내장 AsyncLocalStorage만으로 깔았다.

ID를 만드는 건 쉽다, 전파가 어렵다

Correlation ID 자체는 쉽다. 요청 진입점에서 UUID 하나 만들면 된다. 어려운 건 그 ID를 요청 흐름 어디서나 꺼내 쓰게 하는 것이다.

순진한 방법은 모든 서비스 메서드에 requestId 인자를 추가하는 것이다. 수백 개 시그니처를 오염시키니 비현실적이다. 로그 한 줄에 ID 붙이자고 코드 전체에 인자를 흘려보낼 순 없다.

해법은 AsyncLocalStorage(ALS). Node가 비동기 호출 체인을 따라 유지해주는 “요청 전용 보관함”이다. 요청 시작 시 store를 한 번 심으면, 그 요청에서 파생된 모든 await·콜백에서 별도 인자 없이 같은 store를 읽는다.

request-context.ts
import { AsyncLocalStorage } from 'node:async_hooks';
const storage = new AsyncLocalStorage<{ requestId: string }>();
export const RequestContext = {
run<T>(store: { requestId: string }, cb: () => T): T {
return storage.run(store, cb);
},
getRequestId(): string | undefined {
return storage.getStore()?.requestId;
},
};

진입점에서 컨텍스트를 연다

요청 가장 바깥에서 requestId를 만들고 RequestContext.run으로 나머지 전부를 감싼다. 외부(게이트웨이·프론트)가 보낸 X-Request-Id가 있으면 재사용해 엔드투엔드로 잇고, 없으면 새로 만든다. 응답 헤더로 echo해 클라이언트도 자기 요청 ID를 안다.

export function requestContextMiddleware(req, res, next): void {
const incoming = req.headers['x-request-id'];
const requestId =
typeof incoming === 'string' && incoming.trim() ? incoming.trim() : randomUUID();
res.setHeader('X-Request-Id', requestId);
RequestContext.run({ requestId }, () => next()); // 이후 모든 처리가 이 컨텍스트 안
}

여기서 프레임워크 함정을 하나 밟았다. 처음엔 @Injectable() NestMiddleware + forRoutes('*')를 쓰려 했는데, NestJS 11은 Express 5(path-to-regexp v8)를 쓰고 와일드카드 라우트 문법이 바뀌어 '*'가 그대로 안 통한다. 함수형 Express 미들웨어 + app.use()로 전환했다. 라우트 매칭을 거치지 않고 가장 바깥 Express 레이어에서 모든 요청에 최우선 적용되니, NestJS 파이프라인 전체(가드·인터셉터·컨트롤러·서비스·예외필터)가 ALS 컨텍스트 안에서 돈다.

백미 — 로거 64곳을 무수정으로 묶기

requestId를 로그에 붙이겠다고 new Logger() 호출처 64곳을 일일이 고치는 건 유지보수 부채다. 대신 로거 한 곳에서 주입한다.

NestJS의 new Logger(context) 인스턴스는 NestFactory.create({ logger })로 등록한 앱 로거에 내부적으로 위임(delegate) 한다. 그러니 ConsoleLogger를 확장해 “메시지 앞에 현재 requestId를 붙이는” 로거를 만들어 등록하면, 전역의 모든 new Logger()가 자동으로 그 동작을 갖는다.

app-logger.ts
export class AppLogger extends ConsoleLogger {
private withRequestId(message: unknown): unknown {
const id = RequestContext.getRequestId();
return id && typeof message === 'string' ? `[req:${id}] ${message}` : message;
}
log(message: unknown, ...rest: unknown[]): void {
super.log(this.withRequestId(message), ...rest);
}
// error/warn/debug/verbose/fatal 동일 패턴
}
main.ts
const app = await NestFactory.create(AppModule, { logger: new AppLogger() });

코드 64곳 중 0곳을 고치고도 모든 로그가 [req:abc-123] ... 형태가 됐다. 횡단 관심사(cross-cutting concern)를 다루는 정석이다. 호출처를 고치지 말고, 모두가 거치는 한 지점에서 주입한다.

의도적으로 남긴 v1 한계 둘은 받아들였다. 비문자열 메시지(logger.error(errObj))는 객체에 문자열을 붙일 수 없어 prefix를 생략하고, 응답이 detach된 뒤 던져진 예외의 필터 로그는 ALS 프레임 밖일 수 있다. 둘 다 “대부분의 로그는 묶인다”를 해치지 않는 드문 경계라 v1으로 뒀다.

그래서

라이브러리부터 깔지 않고 표준 기능을 먼저 봤다. ALS·인터셉터·ConsoleLogger 위임은 전부 Node·NestJS 내장이라, 의존성 0으로 관측가능성 1층을 세웠다. 두 가지가 남는다. 요청 컨텍스트는 인자가 아니라 AsyncLocalStorage로 전파하고, 횡단 관심사는 호출처가 아니라 단일 주입점에서 푼다. 이 1층 위에 요청 로깅 게이팅·분산추적·에러 트래킹을 얹으면, requestId가 trace ID와 이어지고 예외가 그 ID와 함께 수집된다.

↑↓ 이동 열기esc 닫기