メトリクスでは答えられない問い

한 줄 요약

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

왜 이게 필요했나

결제 화면이 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 를 만들고, 모든 로그에 그 필드를 넣고, 모든 하위 호출 헤더에 실어 보내는 것. 이것만으로 장애 조사 시간이 극적으로 줄어듭니다.

샘플링을 어떻게 정하나

모든 요청의 트레이스를 다 저장하면 비용이 감당되지 않는다. 그래서 일부만 남기는데, 어떻게 고르느냐가 트레이싱의 값어치를 거의 결정한다.

가장 단순한 방법은 요청이 들어올 때 정해진 비율로 주사위를 굴리는 것이다. 구현이 쉽고 비용을 예측할 수 있지만 결정적인 약점이 있다. 느렸던 요청과 실패한 요청도 같은 확률로 버려진다. 조사하고 싶은 것이 바로 그 요청들인데 말이다. 1% 로 샘플링하면 문제가 되는 요청 100건 중 1건만 남는다.

그래서 나온 것이 요청이 끝난 뒤에 남길지 정하는 방식이다. 트레이스가 완성될 때까지 잠시 모아 두었다가, 느렸거나 오류가 있었으면 남기고 아니면 버린다. 원하는 것만 정확히 남길 수 있지만 대가가 있다. 트레이스 전체를 기억하고 있어야 하므로 수집기 쪽에 메모리와 상태가 필요하고, 그 수집기가 규모에 따라 여러 대가 되면 같은 트레이스의 스팬이 같은 수집기로 가도록 경로를 맞춰야 한다.

실무에서는 대개 둘을 섞는다. 기본은 낮은 비율로 두어 평상시의 그림을 얻고, 오류나 느린 요청은 무조건 남긴다. 그리고 결정은 요청의 맨 앞에서 한 번만 내리고 그 결과를 헤더로 전파한다. 서비스마다 따로 주사위를 굴리면 트레이스가 중간부터 끊겨 아무 데도 쓸 수 없는 조각이 남는다. traceparent 의 마지막 플래그가 하는 일이 정확히 이것이다.

한 가지 더 정해 두어야 할 것이 보존 기간이다. 트레이스는 로그보다도 양이 많아서 길게 두기 어렵다. 대신 트레이스에서 뽑은 지표는 오래 남길 수 있으므로, 원본은 며칠만 두고 서비스별·경로별 지연 분포는 지표로 뽑아 장기 보관하는 조합이 무난하다. 몇 달 전과 비교하는 질문에는 지표가 답하고, 지금 이 요청이 왜 느렸는지에는 트레이스가 답한다.

다음 실습에서 할 것

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