무음 실패와 opt-in 관측가능성 3단계

운영에서 정말 무서운 건 빨간 스택트레이스가 아니다. 그건 적어도 보인다. 무서운 건 아무 데도 안 남는 실패다. 배치 잡이 try/catch로 에러를 삼키고 조용히 끝나거나, 로그아웃한 사용자의 /auth/refresh 401이 터미널을 도배해 진짜 에러를 묻어버리는 것. 둘 다 “에러 없음”처럼 보이지만 시스템은 일하지 않고 있다.

관측가능성을 붙이기로 했는데 조건을 달았다. 벤더에 묶이지 않고, 환경변수 하나로 켜고 끌 수 있고, 안 켜면 완전 no-op일 것. 로컬·CI에서 오버헤드 0, 수집기 없으면 그냥 안 돈다. 그 제약 위에 로그·추적·에러 세 단계를 쌓았다.

① 로그를 줄여야 로그가 보인다

첫 단계는 늘리는 게 아니라 줄이는 거였다. 모든 HTTP 요청을 한 줄씩 찍으면 터미널은 firehose가 되고, 그중 최악은 401이었다. 토큰 만료된 클라이언트가 /auth/refresh를 계속 때리면 401 로그가 무한히 쌓여 정작 봐야 할 5xx를 덮는다.

LOG_HTTP 환경변수로 상세도를 게이팅했다. all(전부)·summary(기본)·off(5xx만).

// summary : 느린(>1s) 요청과 5xx·주요 4xx만. 401(미인증)은 라우틴 노이즈라 침묵
export type HttpLogMode = 'all' | 'summary' | 'off';

기본값 summary는 느린 요청(>1s)과 에러만 남긴다. 성공 요청 한 줄짜리 firehose를 끄고, 401은 침묵시킨다. 대신 응답 시간을 항상 같이 찍는다. latency 한 줄이 N+1이나 느린 쿼리 병목을 사후 분석 없이 즉시 드러내기 때문이다.

GET /companies/:id/documents 200 1340ms   ← summary에서도 남는다(느림)
POST /auth/refresh 401 3ms                 ← summary에서 침묵(노이즈)

한 가지 함정은 이중 로그였다. 인터셉터가 에러를 찍고 예외 필터도 또 찍으면 같은 에러가 두 번 뜬다. 그래서 summary에선 인터셉터가 에러 로깅을 예외 필터에 위임하고 자기는 성공·느린 요청만 본다. 로그를 줄이는 일의 절반은 “한 번만 찍기”였다.

② 분산추적은 가장 먼저 import돼야 한다

둘째는 OpenTelemetry 분산추적이다. 여기서 비자명했던 건 코드가 아니라 import 순서였다.

자동 계측(auto-instrumentation)은 http·express·mysql2가 require되기 전에 패치를 걸어야 동작한다. 모듈이 이미 메모리에 올라온 뒤엔 늦다. 그래서 추적 초기화 파일을 main.ts의 맨 첫 줄에서 import한다. NestJS·TypeORM보다 앞서야 한다.

const endpoint = process.env.OTEL_EXPORTER_OTLP_ENDPOINT;
if (endpoint) {                       // opt-in: 수집기 엔드포인트 없으면 통째로 no-op
  const sdk = new NodeSDK({
    traceExporter: new OTLPTraceExporter(),
    instrumentations: [getNodeAutoInstrumentations()],
  });
  try {
    sdk.start();                      // 계측 설정 오류가 부팅 자체를 막지 않게 격리
  } catch (err) {
    console.error('[otel] SDK 시작 실패 — 트레이싱 없이 부팅 계속', err);
  }
}

설계의 두 축은 격리와 연결이다. 격리: 트레이싱은 부가기능이라, SDK 시작이 실패해도 try/catch로 삼켜 앱은 정상 부팅한다. 관측 도구가 서비스를 죽이면 본말전도다. 연결: 로그의 requestId와 트레이스의 traceId를 양방향으로 묶었다(이 requestId를 인자 없이 전역에 까는 AsyncLocalStorage 1층이 토대다). 로그엔 활성 span의 traceId를 [trace:<id>]로 붙이고, span엔 app.request_id 속성을 단다. 한 요청을 로그에서 추적으로, 추적에서 로그로 오갈 수 있다.

종료 시 버퍼의 span을 flush하는 SIGTERM 핸들러는 main HTTP 앱에만 달았다. 배치 프로세스는 NestJS의 enableShutdownHooks로 DB 연결을 정리하는데, 여기에 process.exit를 부르는 flush 핸들러를 얹으면 Nest의 종료 라이프사이클을 선점해 끊어버린다. 같은 파일을 배치에 import하지 않는 게 규칙이 됐다.

③ 두 OpenTelemetry를 한 프로세스에 욱여넣기

셋째 Sentry 에러 트래킹에서 진짜 함정이 나왔다. Sentry는 v8부터 OTel 네이티브라, init하면 자체 NodeSDK(컨텍스트 매니저·instrumentation)를 띄운다. 그런데 우리는 이미 tracing.ts에서 NodeSDK를 돌리고 있다. 둘을 그대로 켜면 OTel 컨텍스트가 이중 등록돼 충돌한다.

해법은 Sentry의 OTel을 끄고 순수 에러 캡처만 맡기는 것이다. 분산추적은 기존 OTLP가 계속 담당한다.

if (dsn) {                            // opt-in: SENTRY_DSN 없으면 no-op
  Sentry.init({
    dsn,
    environment: process.env.SENTRY_ENVIRONMENT ?? 'unknown',
    skipOpenTelemetrySetup: true,     // Sentry의 OTel 비활성 → tracing.ts와 충돌 회피
    tracesSampleRate: 0,              // 트레이싱은 OTLP가, Sentry는 에러만
  });
}

보고 대상은 5xx만이다. 4xx와 routine 401은 사용자 입력 문제지 서버 결함이 아니라 제외한다. 핵심은 처음의 그 무음 실패. 삼켜진 배치 에러를 잡는 거였다. 두 경로로 나뉜다. 에러를 catch해서 re-throw하지 않는(삼키는) 잡은 reportError를 직접 호출하고, 그대로 전파되는 잡은 unhandledRejection 통합이 자동 캡처한다. 전파되는 예외에까지 수동 호출을 넣으면 이중 보고가 되니, “삼키는 곳에서만 직접 부른다”로 갈랐다.

마지막 디테일은 flush다. 배치는 일이 끝나면 process.exit하는데, Sentry 전송은 비동기라 그냥 나가면 보고 이벤트가 버퍼째 유실된다. 그래서 부팅 실패 같은 종료 경로에서 flushErrors()로 전송 완료를 기다린 뒤 exit한다. 에러를 잡아놓고 보내기 전에 죽으면 안 잡은 것과 같다.

그래서

세 단계를 관통하는 건 두 가지다. 하나는 opt-in no-op. 켜는 비용이 0이면(미설정 시 완전 무영향) 어디에 켤지 끌지를 부담 없이 정한다. 다른 하나는, 관측가능성이 데이터를 늘리는 일이 아니라는 것. 401 스팸을 줄이고, 삼켜진 배치 에러를 들리게 하고, 한 요청을 로그와 추적으로 꿰는 일이다. 더 많이 찍는 게 아니라, 안 보이던 실패가 보이게 하는 것. 운영의 사각지대는 에러가 많은 곳이 아니라 에러가 안 남는 곳이다.