필사 모드: 구조화 로깅 설계 — 장애가 났을 때 실제로 도움이 되는 로그 만들기

• 들어가며 — 장애 한복판에서 로그를 grep할 수 없다면
• 사람이 읽는 로그와 기계가 읽는 로그는 다른 물건이다
• 모든 로그 라인에 반드시 있어야 하는 필드
• 로그 레벨을 실제로 구분하는 단 하나의 기준
• 상관관계 ID를 서비스 경계 너머로 전파하기
• 카디널리티와 비용 — 무엇을 넣지 말아야 하는가
• 로그와 메트릭과 트레이스, 무엇을 언제 보는가
• 마치며 — 로그는 읽는 것이 아니라 거르는 것이다

들어가며 — 장애 한복판에서 로그를 grep할 수 없다면

새벽에 알림을 받고 로그를 엽니다. 서비스 세 개를 지나는 요청인데, 각 서비스의 로그 포맷이 다릅니다. 한쪽은 로컬 시간, 한쪽은 UTC입니다. 요청을 식별할 공통 키가 없어서 타임스탬프가 비슷한 줄들을 눈으로 짝지어 봅니다. 그러다 "user 8812 checkout failed after 4102ms"라는 줄을 찾지만, 이 사용자가 몇 명이나 되는지 세려면 정규식을 새로 짜야 합니다.

이 상황의 원인은 로그가 부족해서가 아닙니다. 오히려 로그는 하루 수억 줄씩 쌓이고 있습니다. 문제는 그 로그가 사람이 한 줄씩 읽는 것을 전제로 설계되었다는 데 있습니다. 사고 대응에서 필요한 것은 읽기가 아니라 필터링과 집계입니다.

이 글은 그 전제를 바꾸는 설계를 다룹니다.

사람이 읽는 로그와 기계가 읽는 로그는 다른 물건이다

로컬 개발 환경의 로그는 사람이 읽습니다. 색이 있고, 문장이고, 순서대로 스크롤하면 이야기가 됩니다. 프로덕션 로그는 기계가 읽습니다. 필터링되고, 집계되고, 조인됩니다. 두 요구사항을 하나의 포맷으로 만족시키려는 시도가 대부분의 로그를 망칩니다.

정답은 같은 로그를 다르게 출력하는 것입니다. 프로덕션은 JSON 한 줄, 로컬은 pretty 포맷으로 렌더링합니다. 그리고 결정적인 규칙 하나가 있습니다.

// 나쁨: 값이 메시지 문자열 안에 녹아 있다
logger.info(`user ${userId} checkout failed after ${ms}ms: ${err.message}`)
// -> 같은 사건을 세려면 정규식이 필요하고, err.message 가 바뀌면 정규식이 깨진다

// 좋음: 메시지는 상수, 변하는 값은 전부 필드
logger.error(
  {
    event: 'checkout.failed',
    user_id: userId,
    order_id: orderId,
    duration_ms: ms,
    payment_provider: 'tosspay',
    err: { type: err.name, code: err.code, message: err.message },
  },
  'checkout failed'
)

메시지 문자열은 상수로 유지합니다. 그래야 같은 사건을 하나의 키로 셀 수 있습니다. 변하는 값이 메시지 안에 들어가는 순간, 그 로그는 문장이 되고 집계 대상에서 탈락합니다.

이 규칙 하나만 지켜도 다음 질문에 즉시 답할 수 있게 됩니다. 이 실패가 몇 분 전부터 시작됐는가, 특정 결제 프로바이더에 몰려 있는가, 특정 테넌트에만 발생하는가. 문장으로 남긴 로그로는 전부 새로 파싱해야 하는 질문들입니다.

event 필드는 별도로 강조할 가치가 있습니다. 점으로 구분한 도메인 이벤트 이름을 안정적인 식별자로 두면, 로그 백엔드에서 그대로 카운터가 됩니다. 메시지 텍스트는 사람을 위한 것이고 event는 기계를 위한 것입니다.

모든 로그 라인에 반드시 있어야 하는 필드

필드가 많을 필요는 없습니다. 없으면 조사가 막히는 필드가 정해져 있습니다.

타임스탬프는 별도로 짚고 갑니다. 반드시 오프셋을 포함한 RFC 3339 형식으로, 가급적 UTC로 남깁니다. 오프셋 없는 로컬 시간은 다음과 같은 일을 만듭니다.

# payment 서비스는 오프셋 없는 KST, checkout 서비스는 UTC 로 남겼다
grep 'payment accepted' payment.log | tail -1
# 2026-07-26T13:02:11.004 payment accepted order_id=A-99183

grep 'checkout completed' checkout.log | tail -1
# 2026-07-26T04:02:11.118Z checkout completed order_id=A-99183

# 같은 사건인데 9시간 차이로 보인다. 두 로그를 한 화면에서 정렬할 방법이 없다.

pino를 예로 들면 기본 설정에서 이렇게 잡습니다.

import pino from 'pino'

export const logger = pino({
  level: process.env.LOG_LEVEL ?? 'info',
  timestamp: pino.stdTimeFunctions.isoTime, // 오프셋 포함 ISO 8601
  formatters: {
    level: (label) => ({ level: label }), // 30 대신 "info" 로 남긴다
  },
  base: {
    'service.name': process.env.OTEL_SERVICE_NAME,
    'service.version': process.env.SERVICE_VERSION,
    'deployment.environment': process.env.APP_ENV,
  },
})

base에 넣은 값은 모든 라인에 자동으로 붙습니다. 리소스 수준 필드는 개별 호출부에서 반복하지 않습니다. 반복하는 순간 빠뜨리는 곳이 생깁니다.

로그 레벨을 실제로 구분하는 단 하나의 기준

레벨 정의는 어느 문서에나 있지만 팀마다 실제 사용은 제각각입니다. 판단 기준을 하나로 고정하면 논쟁이 끝납니다.

기준은 이것입니다. ERROR는 우리 시스템이 자기 책임을 다하지 못했다는 뜻입니다. 사용자가 잘못했거나, 예상된 실패거나, 재시도로 복구되었다면 ERROR가 아닙니다.

• ERROR: 우리 쪽 결함으로 요청을 처리하지 못했습니다. 누적되면 페이지로 이어져야 합니다. 예: 의존 서비스 타임아웃 후 재시도 소진, 역직렬화 실패, 커넥션 풀 고갈.
• WARN: 처리는 됐지만 열화되었습니다. 지금 조치할 필요는 없지만 추세는 봐야 합니다. 예: 재시도 후 성공, 폴백 응답 사용, 캐시 미스율 급등, 곧 만료되는 인증서.
• INFO: 상태가 변한 사건입니다. 나중에 재현할 때 필요한 사실만 남깁니다. 예: 주문 생성, 배포 완료, 설정 리로드.
• DEBUG: 개발자를 위한 서사입니다. 프로덕션 기본값은 off이고, 특정 요청이나 특정 테넌트에 한해 동적으로 켤 수 있어야 합니다.

여기서 가장 많이 틀리는 지점이 400번대 응답입니다. 잘못된 요청 본문, 만료된 토큰, 권한 없음은 우리 시스템이 정상 동작한 결과입니다. 이것들을 ERROR로 찍는 순간 ERROR 로그의 대부분이 정상 트래픽으로 채워지고, 진짜 결함이 그 안에 묻힙니다. 클라이언트 오류는 INFO나 WARN으로 남기고, 비율이 급등하는 것은 메트릭으로 감시합니다.

// 에러 핸들러: 책임 소재로 레벨을 가른다
app.use((err, req, res, next) => {
  const status = err.status ?? 500
  const fields = {
    event: 'http.request.failed',
    http_status: status,
    route: req.route?.path,
    err: { type: err.name, code: err.code, message: err.message },
  }

  if (status >= 500) {
    req.log.error(fields, 'request failed') // 우리 책임
  } else if (status === 429) {
    req.log.warn(fields, 'request throttled') // 열화
  } else {
    req.log.info(fields, 'request rejected') // 클라이언트 책임
  }

  res.status(status).json({ error: err.publicMessage ?? 'request failed' })
})

레벨 정책이 정착했는지는 한 가지 지표로 확인합니다. ERROR 로그가 나올 때마다 누군가 확인해 볼 만한가. 아니라면 그 로그는 ERROR가 아닙니다.

상관관계 ID를 서비스 경계 너머로 전파하기

한 서비스 안에서만 유효한 요청 ID는 절반짜리입니다. 값이 나오는 지점은 서비스 경계를 넘을 때입니다.

표준은 W3C Trace Context이고, 헤더는 traceparent입니다. 형식은 네 부분으로 고정되어 있습니다.

curl -sD - -o /dev/null https://checkout.internal/v1/orders \
  -H 'traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01' \
  -H 'tracestate: acme=t61rcWkgMzE'

# 00                                 버전
# 4bf92f3577b34da6a3ce929d0e0e4736   트레이스 ID (16바이트, 요청 전체에서 동일)
# 00f067aa0ba902b7                   부모 스팬 ID (8바이트, 호출 단계마다 달라짐)
# 01                                 플래그 (마지막 비트가 1이면 샘플링됨)

마지막 플래그를 눈여겨봐야 합니다. 01이면 이 트레이스는 저장됩니다. 00이면 버려집니다. 로그에 이 값을 함께 남겨두면, 나중에 "트레이스 링크를 눌렀는데 아무것도 없다"는 상황의 원인을 즉시 알 수 있습니다.

애플리케이션에서는 로거가 자동으로 트레이스 컨텍스트를 붙이도록 만드는 것이 핵심입니다. 호출부에서 매번 넘기게 하면 반드시 빠집니다.

import { context, trace } from '@opentelemetry/api'
import { AsyncLocalStorage } from 'node:async_hooks'

const requestStore = new AsyncLocalStorage()

// 요청 진입점에서 한 번만 컨텍스트를 심는다
export function requestContext(req, res, next) {
  const requestId = req.headers['x-request-id'] ?? crypto.randomUUID()
  res.setHeader('x-request-id', requestId)
  requestStore.run({ requestId, tenantId: req.auth?.tenantId }, () => next())
}

// 모든 로그 호출이 통과하는 얇은 래퍼
export function ctx(fields = {}) {
  const store = requestStore.getStore() ?? {}
  const span = trace.getSpan(context.active())
  const sc = span?.spanContext()
  return {
    ...fields,
    request_id: store.requestId,
    tenant_id: store.tenantId,
    trace_id: sc?.traceId,
    span_id: sc?.spanId,
    trace_sampled: sc ? Boolean(sc.traceFlags & 1) : undefined,
  }
}

logger.error(ctx({ event: 'checkout.failed', order_id: orderId }), 'checkout failed')

전파에서 실제로 깨지는 지점은 세 곳입니다. 첫째, 자체 HTTP 클라이언트를 쓰는 코드 경로 — 자동 계측이 감싸지 못하면 헤더가 붙지 않습니다. 둘째, 메시지 큐 — 헤더에 직접 주입하지 않으면 프로듀서와 컨슈머의 트레이스가 끊깁니다. 셋째, 배치 작업과 크론 — 진입점에서 새 트레이스를 시작하지 않으면 로그에 trace_id가 아예 비어 있습니다.

카디널리티와 비용 — 무엇을 넣지 말아야 하는가

로그는 무료가 아닙니다. 계산부터 해 봅니다.

# 한 줄 평균 1.2KB, 초당 4,000줄
python3 -c "print(f'{1.2*1024*4000*86400/1e9:.1f} GB/day')"
# 424.7 GB/day

# 30일 보관, 인덱싱 포함 단가를 GB당 2.5 통화단위로 가정하면
python3 -c "print(f'{424.7*30*2.5:,.0f} per month')"
# 31,853 per month

여기서 줄일 대상은 라인 수가 아니라 라인당 크기와 인덱싱 대상 필드입니다. 다음은 로그에 넣지 않습니다.

• 개인정보: 이메일 전체, 전화번호, 주소, 생년월일, 주민등록번호. 필요한 경우 해시나 내부 ID로 대체합니다.
• 시크릿: Authorization 헤더, 쿠키, API 키, 카드번호, 리프레시 토큰. 이 값들은 한 번 로그에 들어가면 백업과 인덱스와 콜드 스토리지에 동시에 복제됩니다.
• 대용량 페이로드: 요청과 응답 본문 전체, 스택 트레이스의 반복 출력, 직렬화된 객체 덤프. 본문은 크기와 해시만 남기고, 필요하면 별도 저장소에 짧은 TTL로 둡니다.
• 무의미한 고유값: 로그 백엔드가 인덱싱하는 필드에 UUID를 무제한으로 넣으면 인덱스가 데이터보다 커집니다. 인덱싱할 필드와 저장만 할 필드를 구분합니다.

마스킹은 애플리케이션 안에서 처리하는 것이 원칙입니다. 수집 파이프라인에서 지우는 방식은 이미 프로세스 밖으로 나간 뒤라 유출 경로가 늘어납니다.

export const logger = pino({
  redact: {
    paths: [
      'req.headers.authorization',
      'req.headers.cookie',
      'req.headers["x-api-key"]',
      'req.body.password',
      'req.body.card_number',
      '*.email',
      '*.phone',
      'user.ssn',
    ],
    censor: '[REDACTED]',
  },
})

샘플링은 볼륨을 줄이는 마지막 수단이지만 방법이 중요합니다. 흔한 조언인 "INFO 로그의 10%만 남긴다"를 라인 단위 무작위로 구현하면 최악의 결과가 나옵니다. 한 요청의 로그가 조각조각 남아서 어떤 요청도 완전한 이야기를 갖지 못합니다.

샘플링은 라인이 아니라 요청 단위로 결정합니다. trace_id를 해시해서 판단하면 같은 요청의 모든 로그가 함께 남거나 함께 버려집니다.

const KEEP_RATIO = 0.05

// trace_id 로 결정적 판정 — 한 요청의 로그는 전부 남거나 전부 빠진다
function keepLowSeverity(traceId) {
  if (!traceId) return true
  const bucket = parseInt(traceId.slice(-4), 16) / 0xffff
  return bucket < KEEP_RATIO
}

export function emit(level, fields, msg) {
  const enriched = ctx(fields)
  const alwaysKeep = level === 'error' || level === 'warn' || enriched.trace_sampled
  if (!alwaysKeep && !keepLowSeverity(enriched.trace_id)) return
  logger[level](enriched, msg)
}

ERROR와 WARN은 절대 샘플링하지 않습니다. 그리고 트레이스가 샘플링된 요청의 로그는 함께 남깁니다. 그래야 트레이스에서 로그로 넘어갔을 때 빈 화면을 보지 않습니다.

로그와 메트릭과 트레이스, 무엇을 언제 보는가

세 신호는 대체재가 아니라 조사 순서입니다. 셋을 다 켜 놓고도 조사가 느린 팀은 보통 순서가 없습니다.

• 메트릭이 먼저입니다. 언제부터 무엇이 잘못되었는지, 영향 범위가 얼마나 되는지에 답합니다. 값이 싸고 항상 켜져 있고 카디널리티가 낮기 때문에 알림의 근거가 될 수 있는 유일한 신호입니다.
• 트레이스가 다음입니다. 느려진 요청 하나를 열어서 어느 서비스, 어느 구간에서 시간이 갔는지에 답합니다. 메트릭이 알려준 시간대와 라우트로 범위를 좁혀서 진입합니다.
• 로그가 마지막입니다. 그 스팬 안에서 정확히 무슨 일이 있었는지, 어떤 값이 들어와서 어떤 분기를 탔는지에 답합니다. trace_id로 필터링해 들어가면 읽어야 할 줄이 수십 줄로 줄어듭니다.

이 순서가 작동하려면 신호 사이의 연결 고리가 필요합니다. 메트릭에서 트레이스로 가는 다리는 익젬플러입니다. 히스토그램 관측에 trace_id를 붙여 두면, 그래프의 튀는 점을 클릭해서 바로 그 트레이스를 열 수 있습니다.

# 익젬플러가 붙어 있으면 이 그래프의 점에서 바로 트레이스로 이동한다
histogram_quantile(
  0.99,
  sum by (le, route) (rate(http_request_duration_seconds_bucket{job="checkout-api"}[5m]))
)

트레이스에서 로그로 가는 다리는 앞에서 만든 trace_id 필드입니다. 로그에서 메트릭으로 가는 다리는 event 필드입니다. 세 다리가 다 놓여 있으면 조사 시간이 수십 분 단위에서 수 분 단위로 내려갑니다. 하나라도 빠지면 그 지점에서 다시 눈으로 짝짓기가 시작됩니다.

마치며 — 로그는 읽는 것이 아니라 거르는 것이다

기억할 것은 한 문장입니다. 프로덕션 로그의 목적은 읽히는 것이 아니라 걸러지는 것입니다.

그 목적에서 모든 규칙이 따라 나옵니다. 메시지는 상수로 두고 값은 필드로 뺍니다. 모든 라인에 trace_id와 service.name과 오프셋이 포함된 타임스탬프를 넣습니다. ERROR는 우리 책임일 때만 씁니다. 민감한 값은 프로세스를 떠나기 전에 지웁니다. 샘플링은 요청 단위로 합니다.

당장 하나만 고친다면 메시지 문자열에서 변수를 빼내는 것부터 시작하십시오. 이 변경 하나가 정규식으로만 답할 수 있던 질문들을 즉시 집계 가능한 질문으로 바꿉니다.

더 파고들 자료입니다.

• W3C Trace Context 명세
• OpenTelemetry: Logs 데이터 모델
• OpenTelemetry Semantic Conventions
• Google SRE Workbook: Alerting on SLOs