LabHub
배우기 러닝패스 코스

ログから原因を見つける

注文がひとつ消えたが、サービスは五つあった

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)에서 꺼내 쓰세요. 마지막 절은 다음 배포에서 무엇을 바꾸면 이 조사가 필요 없어지는지 적습니다.