서비스와 작업 전반에 걸쳐 확장 가능한 구조화된 로깅
자유 형식 로그는 요청이 서비스를 넘나드는 순간 단절됩니다. JSON 로그, 상관관계 ID, 그리고 하나의 공유 스키마가 분산 요청을 추적 가능하게 만드는 방법은 다음과 같습니다.
단일 서비스와 단일 로그 파일은 디버깅하기 쉽습니다. 오류 문자열을 grep으로 찾고, 그 주변의 라인들을 읽으면 전체 상황을 파악할 수 있습니다. 요청이 두 번째 서비스에 닿거나, 비동기 워커(async worker)에 작업을 넘겨주거나, 백그라운드 작업을 생성하는 순간 그 모델은 깨집니다. 이제 하나의 요청에 대한 이야기는 그것들을 하나로 묶어주는 연결고리 없이, 수천 개의 관련 없는 라인들과 뒤섞인 채 세 개의 로그 스트림에 흩어지게 됩니다. 해결책은 더 많은 로깅이 아닙니다. 해결책은 요청이 가는 모든 곳을 따라다니는 공유 식별자를 사용하여 구조화된 데이터로 로깅하는 것입니다. 이 게시물은 그 방법에 대해 보여줍니다. 즉, 문장 대신 JSON 로그를 사용하고, 진입점(entry point)에서 생성되어 모든 홉(hop)을 통해 전파되는 상관관계 ID(correlation ID)를 사용하며, 모든 서비스가 동의하는 하나의 스키마를 사용하는 것입니다.
자유 형식 텍스트 로그가 더 이상 확장되지 않는 이유
user 4021 failed to charge card, retrying과 같은 라인은 사람이 읽기에는 괜찮습니다. 로그 시스템에게는 이것이 불투명한 문자열입니다. "지난 한 시간 동안 연간 플랜 사용자의 결제 실패가 몇 번이나 발생했는가"와 같은 질문에 답하고 싶어도 할 수 없습니다. "연간 플랜"과 "결제 실패"라는 정보가 로그 호출마다 달라지는 문장 속에 묻혀 있기 때문입니다. 어떤 엔지니어는 charge failed라고 쓰고, 다른 엔지니어는 payment declined라고 쓰며, 또 다른 엔지니어는 could not bill이라고 씁니다. 이들은 모두 같은 이벤트를 의미하지만, 어떤 쿼리로도 이들을 그룹화할 수 없습니다.
더 깊은 문제는 요청이 여러 서비스에 걸쳐 있을 때 나타납니다. API 서버가 요청을 받아 결제 서비스를 호출하고, 결제 서비스는 워커를 위한 작업을 큐에 넣습니다. 워커에서 무언가 실패합니다. 워커의 오류는 있지만, 이를 최초의 요청, 사용자 또는 그 요청을 시작한 API 호출과 다시 연결해주는 것이 아무것도 없습니다. 결국 타임스탬프와 추측에 의존해 서로 연관시키게 되고, 시간이 맞기를 바라며 세 개의 터미널을 스크롤하게 됩니다. 처리량이 적을 때는 이것이 성가신 일입니다. 실제 처리량에서는 불가능합니다. 같은 초 내에 각 스트림에 수십 개의 관련 없는 요청이 뒤섞여 있기 때문입니다.
자유 형식 로그는 사람이 순서대로 읽는다고 가정합니다. 분산 시스템은 이 두 가지 가정을 모두 위반합니다. 아무것도 순서대로 되어 있지 않으며, 그 많은 양을 사람이 읽을 수도 없습니다. 로그는 쿼리 가능한 데이터가 되어야 합니다.
로그는 문장이 아니라 데이터입니다
사고방식의 전환은 다음과 같습니다. 로그 한 줄은 사람이 읽는 메시지가 아니라, 기계가 쿼리하는 레코드입니다. 값을 문장으로 형식화하는 대신, 필드를 내보냅니다. 이벤트 이름은 필드입니다. 사용자 ID는 필드입니다. 결과는 필드입니다. 메시지가 있다면, 그것은 또 하나의 필드일 뿐이며, 중요한 필드는 아닙니다.
동일한 결제 실패를 자유 형식 텍스트와 구조화된 데이터로 나타내면 다음과 같습니다.
| 측면 | 자유 형식 텍스트 | 구조화 (JSON) |
|---|---|---|
| 형태 | user 4021 failed to charge, retrying |
{"event":"charge_failed","user_id":4021,"retry":true} |
| 이벤트로 필터링 | 부분 문자열 일치, 깨지기 쉬움 | event = "charge_failed" |
| 집계 | 불가능 | count() group by user_plan |
| 서비스 간 조인 | 타임스탬프 추측 | trace_id로 조인 |
| 스키마 | 작성자마다 다름 | 합의된 하나의 필드 집합 |
| 읽는 주체 | 사람, 순서대로 | 쿼리 엔진, 순서 무관 |
로그가 필드가 되면, 로그 수집기가 예전에 눈으로 하던 작업을 수행합니다. 하나의 이벤트 유형으로 필터링하고, 임의의 필드로 그룹화하고, 시간 창에 걸쳐 개수를 세고, 결과를 차트로 만듭니다. "지난 한 시간 동안 연간 요금제 사용자의 결제 실패는 몇 건인가"라는 질문은 불가능한 grep 대신 필터와 그룹화(group-by)로 해결됩니다.
Go에서는 표준 라이브러리가 바로 이 목적을 위해 log/slog를 제공합니다. 핵심적인 통찰은 값을 보간된 문자열(interpolated string)이 아니라, 타입이 지정된 키-값 쌍으로 첨부한다는 것입니다.
import "log/slog"
logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
Level: slog.LevelInfo,
}))
// Not this. The values are trapped inside a sentence.
// logger.Info(fmt.Sprintf("user %d failed to charge, retry=%v", userID, true))
// This. Every value is a field the collector can query.
logger.Info("charge failed",
slog.String("event", "charge_failed"),
slog.Int("user_id", userID),
slog.String("plan", "annual"),
slog.Bool("retry", true),
)
출력은 한 줄에 하나의 JSON 객체이며, 모든 로그 수집기가 이를 기본적으로 파싱합니다.
{"time":"2026-07-17T09:14:22+09:00","level":"INFO","msg":"charge failed","event":"charge_failed","user_id":4021,"plan":"annual","retry":true}
event 필드가 msg와 별개라는 점에 유의하세요. 메시지는 자유롭게 변경할 수 있는 사용자 친화적인 텍스트입니다. event는 쿼리할 때 사용하는 안정적인 머신 키이며, 절대 변경되어서는 안 됩니다. 이벤트 이름을 한 번 정한 후에는 API처럼 다루세요.
요청을 하나로 묶는 상관관계 ID
구조화된 필드는 하나의 서비스를 쿼리할 수 있게 만듭니다. 상관관계 ID는 전체 시스템을 추적할 수 있게 만듭니다. 아이디어는 간단합니다. 요청이 시스템에 처음 들어올 때, 해당 요청에 대한 고유한 ID를 생성합니다. 그런 다음 그 ID를 모든 로그 라인, 모든 다운스트림 서비스 호출, 그리고 요청이 생성하는 모든 작업에 첨부합니다. 모든 서비스를 거치는 한 요청의 전체 여정을 재구성하려면, 하나의 값으로 필터링하면 됩니다.
이 ID는 trace_id, request_id, correlation_id 등 여러 이름으로 불립니다. 중요한 것은 에지(edge)에서 한 번 생성되고 절대 다시 생성되지 않는다는 점입니다. 보통 HTTP 미들웨어인 진입점에서 이 ID가 생성됩니다.
// Middleware: reuse an inbound trace ID if a trusted upstream sent one,
// otherwise mint a fresh one. Store it on the context so every log call
// downstream can read it.
type ctxKey string
const traceIDKey ctxKey = "trace_id"
func TraceMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
traceID := r.Header.Get("X-Trace-Id")
if traceID == "" {
traceID = newTraceID() // e.g. a random 16-byte hex string
}
ctx := context.WithValue(r.Context(), traceIDKey, traceID)
// Bind the trace ID into a logger stored on the context, so no
// call site has to remember to pass it.
reqLogger := slog.With(slog.String("trace_id", traceID))
ctx = context.WithValue(ctx, loggerKey, reqLogger)
w.Header().Set("X-Trace-Id", traceID)
next.ServeHTTP(w, r.WithContext(ctx))
})
}
// Every handler pulls the request-scoped logger back off the context.
func loggerFrom(ctx context.Context) *slog.Logger {
if l, ok := ctx.Value(loggerKey).(*slog.Logger); ok {
return l
}
return slog.Default()
}
이제 요청 내의 모든 로그 호출은 로거가 에지에서 한 번 그것과 바인딩되었기 때문에 추적 ID를 자동으로 전달합니다.
func chargeHandler(w http.ResponseWriter, r *http.Request) {
log := loggerFrom(r.Context())
log.Info("charge started", slog.String("event", "charge_started"))
// ... every line from here carries the same trace_id
}
서비스 및 워커 경계를 넘어 ID 전파하기
하나의 서비스 내부에만 존재하는 ID는 경계에서 아무런 이득을 주지 않습니다. 핵심은 그 ID가 홉(hop)을 거쳐도 살아남는다는 것입니다. 처리해야 할 홉에는 두 가지가 있습니다. 다른 서비스로의 동기적 호출과 워커 또는 잡(job)으로의 비동기적 핸드오프입니다.
동기적 HTTP 호출의 경우, 호출자는 컨텍스트에서 추적 ID를 읽어 아웃바운드 헤더에 씁니다. 피호출자의 미들웨어는 바로 그 헤더를 읽으며, 이것이 바로 위 미들웨어가 새 ID를 만들기 전에 X-Trace-Id를 확인하는 이유입니다.
// Outbound call: carry the trace ID forward as a header.
func callBilling(ctx context.Context, body io.Reader) (*http.Response, error) {
req, _ := http.NewRequestWithContext(ctx, http.MethodPost, billingURL, body)
if id, ok := ctx.Value(traceIDKey).(string); ok {
req.Header.Set("X-Trace-Id", id)
}
return http.DefaultClient.Do(req)
}
비동기 핸드오프의 경우 헤더 트릭은 적용되지 않습니다. 워커는 나중에 호출자와의 실시간 연결 없이 실행되기 때문입니다. 그래서 ID는 메시지 내부에서 이동합니다. 작업 페이로드에 ID를 넣으면, 워커가 그것을 꺼내서 미들웨어가 했던 것과 동일한 방식으로 로거를 다시 바인딩합니다.
// Enqueue: the trace ID rides along inside the job payload.
type ChargeJob struct {
TraceID string `json:"trace_id"`
UserID int `json:"user_id"`
}
func enqueueCharge(ctx context.Context, q Queue, userID int) error {
id, _ := ctx.Value(traceIDKey).(string)
return q.Push(ChargeJob{TraceID: id, UserID: userID})
}
// Worker: rebuild the request-scoped logger from the payload, so the
// worker's logs share the trace_id of the request that queued the job.
func (w *Worker) handle(job ChargeJob) {
log := slog.With(slog.String("trace_id", job.TraceID))
log.Info("charge job picked up", slog.String("event", "charge_job_started"))
// ... the worker's failure now joins to the original API request
}
이 설정이 적용되면, 하나의 trace_id가 API 로그, 결제 서비스 로그, 워커 로그를 연결합니다. 워커가 실패하면, 해당 ID로 모든 스트림을 필터링하고 마치 단일 로그 파일에서 실행된 것처럼 프로세스 경계를 넘어 요청의 전체 경로를 순서대로 읽습니다.
어디서든 하나의 스키마, 하나의 시간 기준
전파는 모든 서비스가 필드에 동의해야만 의미가 있습니다. API 서버는 trace_id를, 워커는 traceId를, 빌링 서비스는 request_id를 쓴다면, 이들을 조인할 수 없으며 다시 추측에 의존해야 합니다. 공유 스키마는 서비스 간 쿼리가 실제로 작동하게 만드는 것입니다. 모든 서비스가 모든 라인에 내보내는 소수의 기본 필드 집합에 동의하십시오:
timestamp, 전체 플릿에 대한 하나의 시간 기준. UTC나 단일 고정 시간대를 선호하여 다른 호스트의 라인이 올바르게 정렬되도록 하십시오. 혼합된 로컬 시간대는 순서를 거짓으로 만듭니다.level, 심각도.service, 내보내는 서비스의 이름. 병합된 스트림에서 하나의 서비스를 필터링할 수 있도록 합니다.event, 발생한 일에 대한 안정적인 머신 키.trace_id, 위에서 언급한 상관관계 ID.
이 외에도 각 이벤트는 자체 필드를 추가합니다. 기본 집합은 계약이고, 추가적인 것들은 자유입니다. 기본 집합을 강제하는 가장 저렴한 방법은 각 팀이 기억할 것이라고 믿는 대신, 모든 서비스가 임포트하는 공유 로거 생성자에 내장하는 것입니다. 필드 이름이 하나의 라이브러리에 있으면, 서로 달라질 수 없습니다.
시간 기준은 가장 흔하게 드러나지 않는 오류의 원인이므로 별도로 강조할 가치가 있습니다. 한 호스트는 현지 시간으로, 다른 호스트는 UTC로 로그를 남기면, 병합된 뷰는 이벤트를 잘못 정렬하고, 실제로 200밀리초가 걸린 요청이 시간을 거슬러 올라간 것처럼 보일 수 있습니다. 머신 타임스탬프에 대해 하나의 시간대를 선택하고 절대 벗어나지 마십시오. 사용자 친화적인 현지 시간은 로그에 쓸 때가 아니라, 대시보드에서 읽을 때 렌더링하십시오.
레벨 규율과 비밀 정보 제외하기
일단 시스템이 갖춰지면 두 가지 규칙이 전체 시스템을 사용 가능하게 유지합니다.
첫째, 로그 레벨을 신중하게 사용해야 합니다. error는 사람이 조치를 취해야 함을 의미해야 합니다. 만약 일상적이고 복구 가능한 조건이 error로 기록되면, 해당 레벨은 아무 의미도 없게 되고, 이를 기반으로 한 경고는 양치기 소년이 되며, 사람들은 결코 무시해서는 안 되는 단 하나의 신호를 무시하는 법을 배우게 됩니다. 복구 가능하지만 주목할 만한 경우에는 warn을 사용하고, 요청의 일반적인 흐름에는 info를, 특정 문제를 추적할 때만 원하는 세부 정보에는 debug를 사용하세요. 성공한 재시도는 error가 아닌 info 또는 warn입니다. 실제로 실패했고 실패한 상태로 남아있는 결과에 대해서만 error를 사용하세요.
둘째, 비밀 정보나 개인 데이터를 절대 로그에 기록하지 마세요. 구조화된 로깅은 전체 구조체를 필드로 덤프하기가 매우 쉽기 때문에 이 함정을 더 좋게 만드는 것이 아니라 더 악화시킵니다. 그 구조체에는 비밀번호 해시, 액세스 토큰, 전체 카드 번호, 이메일 주소 등이 포함될 수 있습니다. 로그는 타사 수집기로 전송되어 몇 달 동안 보관되며, 원시 개인 데이터를 절대 봐서는 안 되는 사람들이 읽게 됩니다. 따라서 로그 라인에 있는 비밀 정보는 발견되기를 기다리는 침해 사고와 같습니다. 로깅 경계에서 민감한 필드를 마스킹하거나 삭제하세요. 사용자 ID는 로그에 기록하되, 이메일은 절대 기록하지 마세요. 토큰이 있었다는 사실은 로그에 기록하되, 토큰 자체는 절대 기록하지 마세요. 오류 객체를 로그에 기록할 때, 이를 유발한 요청 본문이 포함되지 않도록 하세요.
구조화된 로깅의 비용
이 중 어느 것도 공짜는 아니며, 절충안을 신중하게 결정할 수 있도록 그 대가를 명시하는 것은 가치가 있습니다. 구조화된 로깅은 값을 문장에 그냥 넣는 대신 각 필드의 이름을 지정하기 때문에 printf보다 작성하기 더 장황합니다. 모든 서비스 호출과 작업 페이로드에 추적 ID를 연결하는 것은 구축하고 유지해야 하는 연결 작업이며, ID 전파를 잊어버린 단일 서비스는 가장 원치 않는 바로 그곳에 사각지대를 만듭니다. JSON 로그는 또한 일반 텍스트보다 크며, 더 큰 로그는 전송, 저장, 보관하는 데 더 많은 비용이 듭니다. 특히 info 및 debug 볼륨에서는 더욱 그렇습니다.
완화 방법은 평범합니다. 샘플링은 대용량의 낮은 가치를 지닌 라인 중 일부를 제외하므로, 실패는 여전히 전체를 로깅하면서도 성공한 요청은 각각 전체 비용을 지불하지 않습니다. 레벨 원칙은 기본적으로 프로덕션 스토리지에서 debug를 제외합니다. 공유 로깅 라이브러리는 전파 연결 작업을 흡수하여 개별 호출 사이트를 단순하게 유지합니다. 시간이 흐르는 장애 상황에서 세 개의 터미널과 타임스탬프 추측 작업이라는 대안과 비교해 보면 그 비용은 작습니다. 서비스 체인의 어딘가에서 요청이 실패하는 순간, 하나의 상관관계 ID와 하나의 쿼리 가능한 스키마는 오후 내내 해야 할 추측 작업을 단일 필터로 바꿔주며, 그것이 바로 얼마나 빨리 복구할지를 결정합니다.
관련 글
Redis 키스페이스 알림 및 임대를 사용한 GPU 워커 풀의 로드 밸런싱
GPU는 비싸고 한 번에 하나의 무거운 작업만 실행하므로, 라운드 로빈 라우팅은 바쁜 워커 뒤에서 지연됩니다. 여기에 Redis 리스(lease)와 키스페이스 알림(keyspace notification)으로 구축된 바쁨을 인지하는 스케줄러가 있습니다.
CAS와 하트비트를 사용한 단일 실행기 작업을 위한 리스 잠금
일반적인 락은 홀더가 죽었을 때 영원히 교착 상태에 빠집니다. 리스는 만료됩니다. 여기서는 `compare-and-swap` 획득과 하트비트를 사용하여 리스를 구축하는 방법과, 설계를 결정하는 실패 모드를 다룹니다.
멱등성 업서트를 위한 결정적 ULID
데이터베이스가 자동 쓰기 재시도를 금지하는 경우, 모든 쓰기는 그 자체로 멱등적이어야 합니다. 콘텐츠 기반 ID는 이를 추가 비용 없이 가능하게 합니다. 여기에 그 유도 과정과 안전성을 유지하는 한 가지 불변식이 있습니다.
환불 후 복구 재시도를 위한 멱등성 신용 원장
실패한 작업은 크레딧을 환불받습니다. 그 후 재시도가 성공합니다. 이중으로 청구하지 않고 크레딧을 회수하려면 멱등성 원장과 원자적 가드가 필요합니다.
MongoDB 변경 스트림을 이용한 Cron 스케줄 핫스왑
cron을 하드코딩하면 스케줄이 변경될 때마다 재배포해야 합니다. 스케줄을 데이터베이스에 저장하고 데몬이 변경 스트림으로 수정 사항에 반응하도록 하십시오. 여기에 그 설계와 장애 처리 방법이 있습니다.
처리 속도보다 빠르게 채워지는 워커 큐를 위한 백프레셔
생산자가 작업자보다 더 빨라지면, 무한 큐는 부하를 흡수하는 것이 아니라 충돌을 지연시킬 뿐입니다. 역압력이 시스템을 계속 유지하는 방법은 다음과 같습니다.