LabHub
배우기 러닝패스 코스

Finding the Cause in Logs

One Order Vanished, and There Were Five Services

LabHub 에서 이어서 보기

한국어 원문으로 표시합니다.

목표

서비스 다섯 개의 로그에서 주문 하나의 경로를 처음부터 끝까지 잇습니다. W3C traceparent 를 네 칸으로 갈라 무효한 값을 격리하고, 한 trace-id 의 줄을 시간순으로 세우고, parent-id 로 구간 나무를 만들고, 구간별 소요 시간을 구하고, 헤더가 끊긴 자리를 업무 키로 이은 뒤, sampled 플래그를 마스크로 읽습니다.

왜 중요한가

고객은 "주문 하나가 사라졌다" 고 말하는데 서비스는 다섯 개입니다. 시각으로 짐작하면 초당 수십 건의 요청 가운데 어느 것이 그 주문인지 고를 근거가 없습니다. 상관 id 는 그 자리를 메우지만, 현장에서 실제로 부딪히는 문제는 id 가 없는 것이 아니라 중간 한 곳에서 끊기는 것입니다. 끊긴 자리를 찾아내고, 그 앞뒤를 업무 키로 다시 이어 증명하는 일까지가 조사입니다. 그 증명이 다음 배포에서 헤더를 전달하게 만드는 근거가 됩니다.

단계

  1. /root/trace/gen_trace.py 를 만들어 실행해 /root/trace/raw/ 아래 다섯 서비스의 로그를 만드세요.
  2. /root/trace/parsed.ndjson/root/trace/badtp.ndjson — 모든 traceparent 를 네 칸으로 가르고, 규격에 맞지 않는 값은 이유와 함께 격리하세요.
  3. /root/trace/one_trace.ndjson — 주문 ORD-2026-4117 의 trace-id 를 찾아 그 추적의 모든 줄을 시간순으로 세우세요.
  4. /root/trace/tree.ndjson — parent-id 로 부모-자식 관계를 세워 구간 나무를 만드세요.
  5. /root/trace/elapsed.json — 구간별 소요 시간과 자기 시간을 구하세요.
  6. /root/trace/bridge.ndjson/root/trace/gap.json — 헤더가 끊긴 서비스를 찾아 그 앞뒤를 주문번호로 이으세요.
  7. /root/trace/sampled.json — sampled 플래그를 마스크로 읽어 기록된 추적과 안 된 추적을 가르세요.
  8. /root/trace/trace_report.md — 조사 결과를 보고서로 남기세요.

참고

다섯 서비스의 로그를 손에 쥐기

/root/trace/gen_trace.py 를 만들어 실행해 /root/trace/raw/ 아래 edge.jsonl(58줄) · orders.jsonl(72줄) · payments.jsonl(48줄) · stock.jsonl(48줄) · ledger.jsonl(48줄)을 만드세요.

다섯 파일 모두 한 줄에 JSON 객체 하나(JSON Lines)입니다. 대부분의 줄에는 traceparent_in 과 traceparent_out 이 붙지만, 한 서비스의 줄에는 하나도 붙지 않습니다 — 그 서비스가 이 실습의 주인공입니다. edge 에는 헬스체크 줄과 옛 모바일 게이트웨이가 찍은 잘못된 헤더도 섞여 있습니다.

traceparent 를 네 칸으로 가르기

/root/trace/parsed.ndjson 에 규격에 맞는 traceparent 마다 svc · line_no(1부터) · field(traceparent_in|traceparent_out) · version · trace_id · parent_id · trace_flags 를 한 줄에 하나씩 쓰세요. 규격에 맞지 않는 값은 /root/trace/badtp.ndjson 에 svc · line_no · field · raw(원문 그대로) · reason 으로 남기세요.

재료는 1단계에서 만든 /root/trace/raw/ 아래 다섯 파일 전부입니다. traceparent 는 고정 길이입니다 — 하이픈으로 나뉜 네 칸의 길이가 차례대로 2 · 32 · 16 · 2 이고 문자는 소문자 16진만 허용됩니다. reason 은 지시문이 정한 검사 순서대로 붙이세요. 파일을 읽을 때 줄 번호는 원본 파일에서 1부터 세고, traceparent 가 아예 없는 줄은 어느 쪽에도 넣지 않습니다.

그 주문의 추적을 시간순으로 세우기

고객이 말한 주문은 ORD-2026-4117 입니다. edge 로그에서 그 주문의 traceparent 를 찾아 trace-id 를 얻고, /root/trace/one_trace.ndjson 에 그 trace-id 를 가진 모든 줄을 ts · svc · trace_id · span_id · parent_span_id · msg 로 ts 오름차순으로 쓰세요. span_id 는 그 줄의 traceparent_out 의 parent-id 이고, parent_span_id 는 traceparent_in 의 parent-id 입니다(없으면 빈 문자열).

재료는 /root/trace/raw/ 아래 다섯 파일입니다. trace-id 는 추적 전체를 가리키고 parent-id 는 요청 하나를 가리킵니다. 그래서 모으는 기준은 trace-id 입니다. 다섯 서비스가 관여한 주문인데 여기에 몇 개의 서비스가 나오는지 세어 보세요 — 그 숫자가 이 실습의 문제입니다.

parent-id 로 구간 나무 세우기

/root/trace/tree.ndjson 에 3단계의 추적에 나온 구간마다 span_id · parent_span_id · svc · depth(뿌리가 0) · child_count 를 한 줄에 하나씩 쓰세요. depth 오름차순, 같으면 span_id 오름차순입니다. 뿌리는 하나여야 합니다.

재료는 3단계에서 만든 /root/trace/one_trace.ndjson 입니다. 한 구간이 여러 줄을 남기므로 먼저 span_id 로 접어야 합니다. depth 는 parent_span_id 를 따라 위로 올라가며 세면 됩니다. child_count 는 나를 부모로 가리키는 구간의 수입니다 — 이 숫자가 0인데 그 서비스가 다른 서비스를 부른다는 걸 안다면, 그 자리가 끊긴 자리입니다.

시간이 어디서 갔는지 구간별로 재기

/root/trace/elapsed.json 에 spans(구간마다 span_id · svc · ms · self_ms, span_id 오름차순) · slowest_self_svc · slowest_self_ms 를 적으세요. ms 는 그 구간의 첫 줄과 마지막 줄의 시각 차이(밀리초 정수)이고, self_ms 는 거기서 자식 구간들의 ms 합을 뺀 값입니다.

재료는 3단계에서 만든 /root/trace/one_trace.ndjson 입니다. 소요 시간만 보면 맨 위 구간이 늘 가장 큽니다 — 자식을 품고 있으니 당연합니다. 알고 싶은 것은 각 서비스가 스스로 쓴 시간이라 자식의 시간을 빼야 합니다. 시각은 이미 같은 표기로 굳어 있으니 밀리초로 바꿔 빼면 됩니다. 자기 시간이 유난히 큰 구간이 나오면, 그것이 범인이라고 단정하기 전에 6단계를 보세요.

끊긴 자리를 찾아 주문번호로 잇기

/root/trace/bridge.ndjson 에 주문 ORD-2026-4117 이 적힌 모든 서비스의 모든 줄을 ts · svc · trace_id(없으면 빈 문자열) · order_id · linked_by(traceparent|order_id)로 ts 오름차순으로 쓰세요. 또 /root/trace/gap.json 에 dropped_at(traceparent 를 한 줄도 남기지 않은 서비스) · restarted_at(그 뒤에서 새 trace-id 의 뿌리 구간을 만든 서비스) · trace_ids(이 주문에 걸린 trace-id 를 처음 나온 순서대로)를 적으세요.

재료는 다시 /root/trace/raw/ 아래 다섯 파일입니다. 3단계의 추적에는 세 서비스만 나왔지만 이 주문은 다섯 서비스를 지났습니다. 나머지 둘을 찾는 열쇠는 추적 문맥이 아니라 업무 키입니다. dropped_at 은 그 서비스의 로그 어느 줄에도 traceparent 가 없는 서비스이고, restarted_at 은 받은 헤더가 없어 스스로 새 trace-id 를 만든 서비스입니다.

sampled 플래그를 마스크로 읽기

/root/trace/sampled.json 에 total_traces · sampled_traces · unsampled_traces · flag_values(trace-flags 값마다 추적 수) · naive_equal_01(trace-flags 가 문자열 01 인 추적 수)을 적으세요. 세는 대상은 2단계에서 만든 /root/trace/parsed.ndjson 에 나온 서로 다른 trace-id 전부이고, 한 추적 안의 trace-flags 는 모두 같습니다.

trace-flags 는 8비트 필드입니다. 규격은 16진수를 숫자로 해석해 그 값과 비교하지 말고 마스크하라고 못박아 둡니다. 파이썬에서는 int(flags, 16) & 1 입니다. naive_equal_01 은 일부러 틀린 방법으로 센 숫자라, 두 값을 나란히 놓는 것이 이 단계의 목적입니다.

조사 결과를 보고서로 남기기

/root/trace/trace_report.md## 고객은 무엇을 물었나 ## 추적이 어디서 끊겼나 ## 시간은 어디서 갔나 ## 다음 배포에서 고칠 것 네 절로 적으세요. 주문번호 · 헤더가 끊긴 서비스 이름 · 가장 큰 self_ms · 무효한 traceparent 수 · sampled 추적 수를 그대로 포함해야 합니다.

고객에게 돌려줄 문장은 '주문이 사라지지 않았고 어디까지 갔다' 와 '왜 도구에서 안 보였다' 두 가지입니다. 숫자는 지어내지 말고 앞 단계의 산출물(/root/trace/gap.json · /root/trace/elapsed.json · /root/trace/sampled.json · /root/trace/badtp.ndjson · /root/trace/bridge.ndjson)에서 꺼내 쓰세요. 마지막 절은 다음 배포에서 무엇을 바꾸면 이 조사가 필요 없어지는지 적습니다.