필사 모드: 로그와 스택트레이스를 탐정처럼 읽기

• 들어가며 — 로그는 사건 현장이다
• 스택트레이스 읽기 — 위는 현장, 아래는 발단
• "Caused by" 사슬 — 진짜 근본 원인
• 구조화 로깅 — 문장이 아니라 데이터로
• 상관관계 ID와 trace_id — 요청 하나를 꿰다
• grep, jq, ripgrep — 로그를 파헤치는 도구
• 로그 레벨 — 소음을 통제하는 다이얼
• 샘플링 — 다 남길 수 없을 때
• 종합 — 새벽 3시의 장애를 추적하다
• 마치며
• 참고 자료

들어가며 — 로그는 사건 현장이다

새벽 3시, 알림이 울립니다. 프로덕션이 죽었습니다. 당신 손에 있는 건 재현 안 되는 장애와, 수십만 줄의 로그, 그리고 빨간 스택트레이스 하나뿐입니다. 좋은 소식은, 이것들이 사실 증거라는 겁니다. 스택트레이스는 사건 현장의 사진이고, 로그는 목격자들의 진술서입니다. 탐정이 할 일은 이 증거를 읽어 범인을 지목하는 것입니다.

문제는 많은 개발자가 이 증거를 제대로 읽지 못한다는 겁니다. 스택트레이스를 보면 눈이 뒤집혀 위쪽 몇 줄만 보고 추측으로 넘어가고, 로그는 너무 많아서 포기하고 아무거나 grep합니다. 하지만 증거를 읽는 데에는 방법이 있습니다. 이 글은 스택트레이스와 로그를 탐정처럼—체계적으로, 증거에 기반해—읽는 기술을 정리합니다.

스택트레이스 읽기 — 위는 현장, 아래는 발단

스택트레이스를 처음 만나면 압도됩니다. 하지만 구조를 알면 정보의 보고입니다. 핵심 규칙 하나만 기억하세요. 맨 위는 사건이 터진 곳, 맨 아래는 그 사건이 시작된 곳입니다.

파이썬 스택트레이스를 예로 봅시다.

Traceback (most recent call last):
  File "app.py", line 42, in <module>
    result = process_order(order_id)
  File "services/order.py", line 18, in process_order
    total = calculate_total(items)
  File "services/pricing.py", line 7, in calculate_total
    return sum(item.price for item in items)
  File "services/pricing.py", line 7, in <genexpr>
    return sum(item.price for item in items)
AttributeError: 'NoneType' object has no attribute 'price'

읽는 순서와 뽑아낼 정보:

1. 맨 아래 예외 줄부터 읽는다. AttributeError: 'NoneType' object has no attribute 'price'. 무슨 일이 일어났는지의 요약입니다. None인 무언가에서 .price를 꺼내려 했다는 것.
2. 바로 위 프레임이 터진 지점. pricing.py의 7번 줄, item.price. 여기서 item이 None이었습니다. 이게 사건 현장입니다.
3. 아래로 훑으며(=위로 거슬러) 호출 사슬을 본다. app.py(42) → process_order(18) → calculate_total(7). 요청이 어떤 경로로 여기까지 왔는지, 즉 발단을 보여 줍니다.

여기서 중요한 판단이 하나 있습니다. 어느 프레임이 "내 코드"인가. 스택트레이스에는 프레임워크·라이브러리 내부 프레임이 잔뜩 섞여 있곤 합니다. 예외는 라이브러리 깊은 곳에서 터졌지만, 진짜 원인은 라이브러리에 이상한 값을 넘긴 내 코드에 있는 경우가 대부분입니다. 그러니 스택을 훑으며 "내 프로젝트 경로가 마지막으로 등장하는 프레임"을 찾으세요. 십중팔구 거기가 조사를 시작할 지점입니다.

언어마다 방향이 헷갈릴 수 있습니다. 파이썬은 "most recent call last"라 맨 아래가 터진 곳이지만, 자바스크립트나 자바는 보통 맨 위가 터진 곳이고 아래로 갈수록 발단입니다. 규칙 자체("한쪽 끝이 현장, 반대쪽 끝이 발단")는 같으니, 그 언어가 어느 방향인지만 확인하면 됩니다.

"Caused by" 사슬 — 진짜 근본 원인

자바 계열에서 특히 자주 만나는, 그리고 반드시 알아야 하는 패턴이 "Caused by" 사슬입니다. 하나의 에러가 다른 에러를 감싸며 층층이 쌓인 형태입니다.

Exception in thread "main" com.example.OrderProcessingException: Failed to process order 4821
    at com.example.OrderService.process(OrderService.java:52)
    at com.example.Main.main(Main.java:14)
Caused by: java.sql.SQLException: Connection timed out
    at com.example.db.Pool.getConnection(Pool.java:88)
    at com.example.OrderService.process(OrderService.java:48)
    ... 1 more
Caused by: java.net.SocketTimeoutException: connect timed out
    at java.base/java.net.Socket.connect(Socket.java:507)
    at com.example.db.Pool.getConnection(Pool.java:85)
    ... 2 more

여기서 초보가 흔히 저지르는 실수는 맨 위 예외만 보고 판단하는 것입니다. OrderProcessingException: Failed to process order 4821은 사실 가장 바깥의 포장지일 뿐입니다. "주문 처리에 실패했다"는 건 증상이지 원인이 아닙니다.

진짜 원인은 **사슬을 끝까지 따라 내려간 맨 마지막 "Caused by"**에 있습니다. 위 예에서:

• 최상위: 주문 처리 실패 (증상)
• Caused by: SQL 예외, 커넥션 타임아웃 (중간 원인)
• Caused by: 소켓 연결 타임아웃 (근본 원인 — DB에 네트워크로 못 붙었다)

그러니 "Caused by"가 보이면 끝까지 스크롤하세요. 가장 아래의 근본 예외가 실제로 고쳐야 할 대상입니다. 위쪽 예외들은 그것이 각 계층을 거치며 다시 포장된 것뿐입니다. 이 사슬을 "이래서 → 이래서 → 결국 이것 때문에"로 읽는 것이 탐정의 인과 추적입니다.

구조화 로깅 — 문장이 아니라 데이터로

스택트레이스가 "터진 순간"의 스냅샷이라면, 로그는 "시간에 걸친 사건들"의 기록입니다. 그런데 로그를 어떻게 남기느냐가 나중에 조사 가능성을 완전히 갈라놓습니다. 핵심은 로그를 사람이 읽는 문장이 아니라 기계가 파싱할 구조화된 데이터로 남기는 것입니다.

전통적인 로그는 이렇게 생겼습니다.

2026-06-28 03:14:22 ERROR Failed to process order 4821 for user 91 after 3 retries

사람 눈엔 읽히지만, 이걸 프로그램으로 다루려면 정규식으로 파싱해야 하고, 필드 하나 추가되면 파서가 깨집니다. 반면 **구조화 로깅(JSON)**은 이렇습니다.

{
  "timestamp": "2026-06-28T03:14:22.481Z",
  "level": "ERROR",
  "service": "order-service",
  "message": "failed to process order",
  "order_id": 4821,
  "user_id": 91,
  "retries": 3,
  "duration_ms": 2140,
  "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736"
}

구조화 로그의 이점은 압도적입니다.

• 검색·필터: "order_id가 4821인 로그"나 "duration_ms가 2000 넘는 로그"를 정확히 질의할 수 있다. 문자열 매칭이 아니라 필드 질의다.
• 집계: "서비스별 에러 수", "retries 평균" 같은 통계를 로그에서 바로 뽑는다.
• 파싱 안정성: 필드가 추가돼도 기존 파이프라인이 안 깨진다.
• 상관관계: trace_id 같은 필드를 심어 두면, 뒤에 볼 것처럼 여러 서비스의 로그를 하나의 요청으로 엮을 수 있다.

원칙: 로그에 넣고 싶은 값은 문자열에 우겨넣지 말고 별도 필드로 남기세요. "order 4821 failed"가 아니라 message는 "order failed"로 두고 order_id: 4821을 필드로 붙이는 겁니다. 나중에 조사할 때 이 차이가 생사를 가릅니다.

상관관계 ID와 trace_id — 요청 하나를 꿰다

마이크로서비스 환경에서 하나의 사용자 요청은 여러 서비스를 거칩니다. API 게이트웨이 → 주문 서비스 → 결제 서비스 → 알림 서비스... 각 서비스가 자기 로그를 따로 남기면, 문제가 생겼을 때 "이 요청이 남긴 로그"를 어떻게 다 모을까요? 답이 상관관계 ID(correlation ID), 그중 표준화된 형태가 trace_id입니다.

원리는 단순합니다. 요청이 시스템에 처음 들어올 때 고유 ID를 하나 발급하고, 그 요청이 거치는 모든 서비스가 자기 로그에 그 ID를 함께 남깁니다. 서비스 간 호출 시에는 HTTP 헤더 등에 실어 ID를 전파합니다. 그러면 나중에 그 ID 하나로 필터링하는 것만으로, 여러 서비스에 흩어진 로그가 한 요청의 타임라인으로 재구성됩니다.

{ "service": "gateway", "trace_id": "abc123", "message": "request received", "path": "/checkout" }
{ "service": "order-service", "trace_id": "abc123", "message": "order created", "order_id": 4821 }
{ "service": "payment-service", "trace_id": "abc123", "message": "charge failed", "reason": "card_declined" }
{ "service": "gateway", "trace_id": "abc123", "message": "responded 402", "duration_ms": 890 }

trace_id가 abc123인 것만 필터링하면, 게이트웨이에서 들어와 주문이 생성되고 결제가 거절돼 402로 응답한 전 과정이 한눈에 보입니다. 상관관계 ID 없이는, 이 네 줄이 수십만 줄 속에 흩어져 서로 연결되지 않은 채 파묻힙니다.

실무 팁: 상관관계 ID는 요청의 최전선(게이트웨이나 미들웨어)에서 한 번 발급하고, 이후 모든 로그에 자동으로 주입되게 하세요. 로그마다 손으로 넣는 게 아니라, 로거의 컨텍스트에 한 번 심어 두면 그 요청 처리 동안의 모든 로그에 자동으로 붙습니다. 그리고 이 ID를 사용자에게 보여 주는 에러 화면에도 노출하면("문의 시 이 코드를 알려 주세요: abc123"), 사용자 문의를 로그와 즉시 연결할 수 있습니다.

grep, jq, ripgrep — 로그를 파헤치는 도구

로그를 다 모아 놨어도, 그 안에서 원하는 걸 뽑아내지 못하면 소용없습니다. 명령줄에는 이 일을 위한 강력한 도구들이 있습니다.

grep / ripgrep(rg): 텍스트 로그에서 패턴을 찾는 기본기입니다. ripgrep은 grep보다 빠르고 기본값이 편리합니다.

# 특정 trace_id의 모든 로그
rg "abc123" app.log

# ERROR 레벨만
rg '"level":"ERROR"' app.log

# 매칭된 줄의 앞뒤 3줄까지 함께 보기 (맥락 확보)
rg -C 3 "card_declined" app.log

# 여러 조건: 결제 서비스의 에러
rg '"service":"payment-service"' app.log | rg '"level":"ERROR"'

여기서 -C(context) 옵션이 탐정에게 특히 중요합니다. 에러 한 줄만 보는 것과, 그 직전에 무슨 일이 있었는지 앞뒤 몇 줄을 함께 보는 것은 하늘과 땅 차이입니다. 사건은 대개 그 직전의 사건이 원인이니까요.

jq: JSON 로그를 다루는 전용 칼입니다. 구조화 로깅을 쓴다면 jq가 grep보다 훨씬 정밀합니다.

# ERROR 레벨 로그의 order_id만 뽑기
jq 'select(.level == "ERROR") | .order_id' app.log

# duration_ms가 2000 넘는 느린 요청
jq 'select(.duration_ms > 2000)' app.log

# 특정 trace_id의 로그를 시간순으로, 서비스와 메시지만
jq 'select(.trace_id == "abc123") | {service, message}' app.log

# 에러를 이유별로 세기
jq -r 'select(.level=="ERROR") | .reason' app.log | sort | uniq -c | sort -rn

이게 구조화 로깅의 보상입니다. duration_ms > 2000 같은 숫자 비교나 필드 단위 집계는 문자열 grep으론 사실상 불가능하지만, JSON이면 jq 한 줄입니다.

HTTP를 다루는 서비스라면 로그에 상태 코드가 자주 등장합니다. 402가 뭐였는지, 499와 500이 어떻게 다른지 헷갈릴 때는 HTTP 상태 코드 레퍼런스에서 각 코드의 의미를 빠르게 확인해, 로그 속 상태 코드가 "클라이언트 잘못인지 서버 잘못인지"부터 정확히 가르세요.

로그 레벨 — 소음을 통제하는 다이얼

로그를 무작정 다 남기면 정작 필요할 때 신호가 소음에 묻힙니다. 그래서 로그 레벨이 있습니다. 각 로그에 심각도를 매겨, 상황에 따라 어느 수준 이상만 볼지 조절하는 겁니다. 표준적인 위계는 이렇습니다.

• DEBUG: 개발·디버깅용 상세 정보. "이 변수 값이 이거다" 수준. 프로덕션에선 보통 끈다.
• INFO: 정상적인 주요 사건. "주문 4821 생성됨", "서버 시작됨". 시스템이 뭘 하고 있는지의 기록.
• WARN: 지금 당장 문제는 아니지만 수상한 것. "재시도 3회 후 성공", "설정값이 없어 기본값 사용". 잠재적 문제의 조기 경보.
• ERROR: 무언가 실패했고 조치가 필요한 것. "결제 처리 실패", "DB 연결 끊김".

레벨을 잘 쓰는 것은 예의이자 실력입니다. 흔한 안티패턴 둘:

• 모든 걸 ERROR로 찍기: 사소한 것까지 ERROR면, 진짜 ERROR가 묻힙니다. "늑대다"를 남발하면 정작 늑대가 왔을 때 아무도 안 봅니다.
• 아무것도 안 찍기: 정상 경로에 INFO 하나 없으면, 문제가 터졌을 때 "여기까진 왔나?"를 알 방법이 없습니다.

조사할 때는 레벨을 필터로 씁니다. 먼저 ERROR만 봐서 큰 사건들을 잡고, 특정 시점이 수상하면 그 근처의 INFO·DEBUG로 내려가 맥락을 채웁니다. 넓게(ERROR) → 좁게(그 시점의 전체 레벨)로 좁혀 가는 것이 요령입니다.

샘플링 — 다 남길 수 없을 때

트래픽이 큰 서비스에서는 모든 로그를 100% 남기는 것이 불가능하거나 비경제적입니다. 초당 수만 요청이 각각 여러 줄의 로그를 남기면, 저장 비용과 처리 부하가 감당이 안 됩니다. 그래서 샘플링을 합니다. 일부만 대표로 남기는 것입니다.

핵심 원칙은 정상은 샘플링하되, 문제는 전량 남기는 것입니다.

• 성공한 정상 요청: 전부 남길 필요가 없습니다. 예를 들어 1%만 샘플링해도 전체 경향을 파악하는 데 충분합니다.
• 에러·느린 요청: 100% 남깁니다. 정작 조사가 필요한 건 이것들이고, 이건 상대적으로 드물어 전량 남겨도 양이 감당됩니다.

이렇게 하면 저장량은 극적으로 줄면서도, 실제로 파헤칠 사건(에러·이상)은 하나도 놓치지 않습니다. 앞 글(관측 가능성)에서 다룬 트레이스의 테일 샘플링이 정확히 이 철학의 트레이스판입니다. "끝나고 보니 에러이거나 느렸으면 무조건 저장"하는 규칙이죠.

주의할 함정: 샘플링을 걸 때는 같은 요청의 로그가 함께 남거나 함께 버려지도록 trace_id 단위로 결정해야 합니다. 요청 하나에서 어떤 로그는 남고 어떤 로그는 버려지면, 나중에 그 trace_id로 조사할 때 타임라인에 구멍이 뚫립니다. "이 trace는 샘플링 대상"이면 그 trace의 모든 로그를 남기는 식으로, 요청 전체를 원자적으로 다루세요.

종합 — 새벽 3시의 장애를 추적하다

지금까지의 도구를 하나의 수사로 엮어 봅시다. 알림이 왔습니다. "결제 성공률 급락."

1. 스택트레이스 확보: 에러 리포팅 도구에서 대표 스택트레이스를 연다. 맨 아래 "Caused by"를 끝까지 따라가니 SocketTimeoutException. DB나 외부 API에 네트워크로 못 붙고 있다.
2. 어느 쪽?: 스택의 "내 코드" 프레임을 보니 결제 게이트웨이 클라이언트. 우리 DB가 아니라 외부 카드사 API에 못 붙는 것으로 좁혀진다.
3. 로그로 교차 검증: 실패한 요청 하나의 trace_id를 잡아 jq로 그 요청의 전체 타임라인을 뽑는다. payment-service에서 카드사 호출이 딱 타임아웃 값에서 죽었다.
4. 범위 파악: 에러를 이유별로 집계(jq ... | sort | uniq -c). 전부 같은 카드사 엔드포인트의 타임아웃. 우리 버그가 아니라 카드사 장애일 가능성이 크다.
5. 맥락 확보: rg -C 5로 첫 타임아웃 직전 로그를 본다. 특정 시각부터 지연이 급증했다. 카드사 상태 페이지를 확인하니 마침 그 시각에 장애 공지.

스택트레이스가 "무엇이(네트워크 타임아웃)"를, trace_id 기반 로그가 "어디서(카드사 API)"를, 집계가 "얼마나(전량)"를, 맥락이 "언제부터(그 시각)"를 답했습니다. 추측 없이, 증거만으로 범인이 우리 밖에 있음을 밝혔습니다.

마치며

로그와 스택트레이스는 귀찮은 빨간 텍스트가 아니라, 사건이 남긴 증거입니다. 탐정의 기술을 다시 모으면 이렇습니다.

• 스택트레이스는 한쪽 끝이 현장, 반대쪽 끝이 발단. "내 코드" 프레임을 찾아라.
• "Caused by"는 끝까지 따라가라. 근본 원인은 맨 아래에 있다.
• 로그는 문장이 아니라 **구조화된 데이터(JSON)**로 남겨라.
• trace_id로 흩어진 로그를 한 요청으로 꿰라.
• grep/rg/jq로 파헤치되, 맥락(-C)을 함께 봐라.
• 로그 레벨로 소음을 통제하고, 샘플링으로 정상은 줄이되 문제는 전량 남겨라.

다음에 스택트레이스를 만나면 눈을 감고 추측하지 마세요. 그건 자백서입니다. 끝까지 읽으세요. 다음에 로그의 바다를 만나면 절망하지 마세요. 그건 목격자 진술입니다. trace_id로 소환하세요. 증거는 이미 다 있습니다. 읽기만 하면 됩니다.

참고 자료

• "Structured Logging" (honeycomb.io 블로그): https://www.honeycomb.io/blog/structured-logging-and-your-team
• jq 매뉴얼: https://jqlang.github.io/jq/manual/
• ripgrep 사용자 가이드: https://github.com/BurntSushi/ripgrep/blob/master/GUIDE.md
• W3C Trace Context (trace_id 전파 표준): https://www.w3.org/TR/trace-context/
• Python 공식 문서 — 트레이스백 읽기: https://docs.python.org/3/tutorial/errors.html