메트릭으로는 답할 수 없는 질문

한 줄 요약

각 서비스가 개별적으로 빠르다는 사실과, 그것들을 순서대로 통과한 하나의 요청이 느렸다는 사실은 서로 모순이 아니다.

왜 이게 필요했나

결제 화면이 2초 걸린다는 신고가 들어옵니다. 게이트웨이 p99 는 1.8초로 올라가 있습니다. 뒤에 있는 열 개 서비스의 p99 를 하나씩 열어 보면 전부 정상입니다.

이 상황에서 메트릭은 원리적으로 답을 줄 수 없습니다. 메트릭은 집계값이라 개별 요청의 경로를 복원하지 못하기 때문입니다. 서비스 A 의 p99 와 서비스 B 의 p99 가 같은 요청의 것이라는 보장이 없습니다. 필요한 것은 서비스별 통계가 아니라 요청 하나의 전체 경로입니다.

어떻게 동작하나

트레이스는 하나의 트레이스 ID 를 공유하는 스팬들의 트리입니다. 각 스팬은 이름, 시작·종료 시각, 부모 스팬 ID, 속성, 그리고 종류(kind)를 가집니다. 종류가 실무에서 중요합니다 — SERVER 는 받는 쪽, CLIENT 는 부르는 쪽입니다. CLIENT 스팬과 SERVER 스팬의 시간 차가 네트워크와 큐잉에서 소비된 시간이고, 둘 다 있어야 그 값을 알 수 있습니다.

이 트리를 만드는 유일한 메커니즘이 컨텍스트 전파입니다. 표준 헤더는 W3C traceparent 이고 형식은 이렇습니다.

traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01             ^버전 ^트레이스 ID(32hex)            ^부모 스팬 ID(16hex) ^샘플 플래그

트레이스 ID 는 요청 전체에서 같고, 스팬 ID 는 홉마다 바뀝니다. 이 두 규칙만 지켜도 로그를 트레이스 ID 로 조인할 수 있고, 그것만으로도 절반은 해결됩니다.

트레이싱이 답하는 질문은 셋입니다. 첫째, 하나의 요청이 어디서 시간을 썼는가. 하루 수백만 건 중 1% 만 쿠폰 조회에서 1,612ms 를 쓴다면 평균 대시보드는 꿈쩍도 하지 않습니다. 둘째, 반복 호출 문제. 개별 쿼리가 4ms 로 빨라도 한 요청에서 340번 실행되면 1.4초입니다. 이것은 스팬을 세어야만 보입니다. 셋째, 조건부 경로 — 특정 테넌트, 특정 플래그, 특정 캐시 미스 조합에서만 느려지는 경우입니다.

현장에서 만나는 모습

전파가 끊기는 지점은 거의 정해져 있습니다. 자동 계측이 감싸지 못한 자체 HTTP 클라이언트, 작업을 스레드 풀이나 워커로 넘기는 코드, 메시지 큐, 그리고 헤더를 지우는 서드파티 프록시입니다. 트레이스가 이상하게 짧다면 이 네 곳부터 봅니다.

자체 소요 시간(self time)이라는 개념도 알아 둘 만합니다. 한 스팬의 전체 지속 시간에서 자식 스팬들의 시간을 뺀 값입니다. 여기가 크면 자동 계측이 보지 못하는 인프로세스 작업 — 직렬화, 정렬, 압축 — 이 숨어 있다는 뜻입니다.

트레이싱을 다 붙이기 전이라도 최소한 상관관계 ID 는 넣으세요. 요청 진입점에서 ID 를 만들고, 모든 로그에 그 필드를 넣고, 모든 하위 호출 헤더에 실어 보내는 것. 이것만으로 장애 조사 시간이 극적으로 줄어듭니다.

다음 실습에서 할 것

3단 체인 서비스를 띄우고 traceparent 를 직접 만들어 전파합니다. 형식을 검증하고, 홉마다 스팬 ID 가 바뀌는지 확인하고, 세 서비스의 로그를 트레이스 ID 로 조인하고, 전파가 끊긴 지점을 찾아내고, 마지막에 가장 느린 구간과 자체 소요 시간을 계산합니다.