id 하나로 다섯 서비스를 꿰기

한 줄 요약

서비스가 다섯 개인 시스템에서 "주문 하나가 사라졌다" 에 답하는 방법은 시각으로 짐작하는 것이 아니라 요청마다 붙어 다니는 id 로 줄을 잇는 것이고, 현장에서 실제로 부딪히는 문제는 id 가 없는 것이 아니라 중간 한 곳에서 끊기는 것이다.

왜 이게 필요했나

시각으로 묶는 방법은 요청이 드문드문 올 때만 통한다. 초당 수십 건이 들어오면 02:01:08 언저리의 줄이 서비스마다 수십 개씩 나오고, 그중 어느 것이 이 주문의 것인지 고를 근거가 없다. 게다가 서비스마다 시계가 조금씩 다르면 순서마저 뒤집혀 보인다.

그래서 요청이 시작될 때 id 를 하나 만들어 모든 하위 호출에 함께 넘긴다. 문제는 그 id 를 저마다 다른 이름으로 불렀다는 것이다 — X-Request-Id, X-B3-TraceId, X-Correlation-Id. 벤더가 다르면 사슬이 끊겼다. [W3C Trace Context](https://www.w3.org/TR/trace-context/)는 그 이름과 형식을 하나로 정한 표준이고, 지금 나오는 거의 모든 추적 라이브러리가 이 헤더를 쓴다.

어떻게 동작하나

traceparent 는 고정 길이의 값 하나다.

00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01

하이픈으로 나뉜 네 칸은 각각 version · trace-id · parent-id · trace-flags 다. 현재 버전은 00 이다. trace-id 는 16바이트(소문자 16진 32자)로 추적 전체를 가리키고, parent-id 는 8바이트(16자)로 이 요청 하나를 가리킨다. 다른 추적 시스템에서는 parent-id 를 span-id 라고 부른다. 규격은 두 값 모두 전부 0 이면 무효이고, 무효한 traceparent 는 벤더가 무시해야 한다(MUST)고 적는다. parent-id 에 대문자 16진이 섞인 경우도 같다.

여기서 이름이 헷갈린다. 내가 받은 헤더의 parent-id 는 나를 부른 쪽의 구간 id 이고, 내가 보내는 헤더의 parent-id 는 내 구간 id 다. 그래서 로그에 들어온 헤더와 나가는 헤더를 둘 다 남겨 두면, 그 두 값으로 부모-자식 관계가 그대로 복원된다. 그것이 구간 나무다.

trace-flags 는 8비트 필드다. 지금은 sampled 플래그 하나만 쓰지만, 규격은 16진수를 숫자로 해석해 그 값과 비교하지 말고 마스크하라고 못박아 둔다 — 01 만 sampled 가 아니라 09 도 sampled 다(00000001 과 00001000 이 함께 켜진 값). [Trace Context Level 2](https://www.w3.org/TR/trace-context-2/)는 두 번째 비트에 random-trace-id 플래그를 추가했으므로, 실제로 03 과 02 가 돌아다니기 시작했다. flags == "01" 로 센 숫자는 이미 틀려 있다.

tracestate 는 벤더별 값의 이름=값 목록이고, 추적에 참여한 시스템이 왼쪽에 새 항목을 추가한다. 왼쪽 끝이 지금 traceparent 를 쓴 시스템이다.

로그 쪽 규약도 맞물려 있다. [OpenTelemetry 로그 데이터 모델](https://opentelemetry.io/docs/specs/otel/logs/data-model/)은 로그 레코드에 TraceId · SpanId · TraceFlags 필드를 두고, SpanId 가 있으면 TraceId 도 있어야 한다(SHOULD)고 적는다. 로그와 추적이 같은 id 로 만나는 자리가 여기다.

현장에서 만나는 모습

끊긴다. 규격은 중간 구성 요소가 최소한 traceparent 와 tracestate 를 그대로 전달해 추적이 끊기지 않게 해야 한다(MUST)고 적지만, 계측되지 않은 옛 서비스·프록시·메시지 큐는 헤더를 그냥 떨어뜨린다. 그 뒤의 서비스는 받은 헤더가 없으니 추적을 새로 시작한다. 화면에는 짧은 추적 두 개가 뜨고, 둘 사이의 관계는 어디에도 없다.

이때 쓰는 것이 업무 키다. 주문번호·결제번호처럼 시스템이 원래 들고 다니는 값으로 앞뒤를 이어 붙이면, 추적이 끊긴 구간도 한 줄로 세울 수 있다. 완전한 해법은 아니다 — 업무 키는 재시도까지 같은 값이라 요청 하나를 가리키지 못한다. 그래도 "어디서 끊겼는가" 를 증명하는 데는 충분하고, 그 증명이 다음 배포에서 헤더를 전달하게 만드는 근거가 된다.

자기 시간이 거짓말처럼 보인다. 구간의 소요 시간에서 자식 구간들의 시간을 빼면 그 서비스가 스스로 쓴 시간이 나온다. 그런데 자식 하나가 계측되지 않아 보이지 않으면, 그 시간이 부모의 자기 시간에 그대로 얹힌다. "주문 서비스가 800ms 를 썼다" 는 결론은 사실 "주문 서비스가 부르는 보이지 않는 무언가가 800ms 를 썼다" 이다. 자기 시간이 유난히 큰 구간은 범인이 아니라 다음에 계측할 자리다.

표본만 남는다. 대량 트래픽에서는 모든 추적을 저장하지 않는다. sampled 가 꺼진 추적은 화면에 아예 없거나 일부만 있다. 고객이 말한 그 주문이 표본에서 빠졌다면 추적 도구에 아무것도 없는 것이 정상이고, 그때는 로그로 내려가야 한다.

다음 실습에서 할 것

다섯 서비스의 로그를 만들고, 모든 traceparent 를 네 칸으로 갈라 무효한 값을 이유와 함께 격리한다. 고객이 말한 주문의 trace-id 를 찾아 그 추적의 줄을 시간순으로 세우고, parent-id 로 구간 나무를 만들고, 구간별 소요 시간과 자기 시간을 구한다. 그다음 헤더가 끊긴 서비스를 찾아 그 앞뒤를 주문번호로 잇고, sampled 플래그를 마스크로 읽어 기록된 추적과 안 된 추적을 가른 뒤, 조사 결과를 보고서로 남긴다. 채점기는 원본을 스스로 다시 파싱해 여러분의 결과와 대조한다.