Traceparent 헤더로 클라이언트부터 서버까지 추적하기
W3C Trace Context

개요

모니터링 도구를 확인해보니 며칠동안 특정 기능에 에러가 발생하고 있었다. 해당 에러는 알람 임계점(threshold)보다 낮아서 알람이 발생하지 않았고, 이용자는 버그 리포팅을 하지 않았다. 에러 로그를 확인해보니 서버에서는 유효성 검사를 하지 않았고, 클라이언트 앱에서는 유효하지 않은 파라미터를 전달했다. 서버에서 유효성 검사를 추가할 수 있겠지만, 클라이언트 앱에서의 잘못된 요청(bug)은 원인을 알 수 없었다. 클라이언트 이벤트는 연결되어 있지 않기 때문이다.

또 다른 문제가 있었다. 서버에서는 정상적인 상태 코드와 함께 100ms 정도의 속도로 응답했지만 클라이언트에서는 4초 이상의 지연이 발생하거나 아래와 같은 Akamai 에러 페이지가 응답되었다. 그리고 모든 요청이 아닌 전체 요청의 5% 정도에서만 발생하고 있었다. 하지만 국가, Edge IP, User Agent, 요청 URL 등을 확인해봐도 특정 패턴을 보이는 것이 없어서 원인을 알 수 없었다.

Akamai ERR_READ_ERROR

원인을 찾기 위해 클라이언트에서 요청하는 부분부터 추적하고 싶었다. 우리팀에서 사용하는 APM 도구인 데이터독(Datadog)에서는 RUM(Real User Monitoring)을 APM과 연결하면 클라이언트부터 서버 Span까지 한눈에 확인할 수 있다. 하지만 응답 속도가 Akamai에선 4초 이상이라고 측정되고 Datadog RUM에선 수백ms로 측정되었다. 그래서 Datadog에 확인 요청했더니 Akamai Datastream 2에서는 요청하고 응답받을 때까지의 duration을 측정하지만, Datadog RUM에서는 브라우저에서 서버까지의 duration만 측정한다고 한다(2024년 8월 22일 기준). 게다가 일주일 간 RUM 스크립트를 추가해보니 예상 견적이 만만치 않았다. 다른 방법을 찾아야 했다.

Trace Context

W3C 권고안(REC, Recommendation)인 Trace Context1는 분산 추적 통합을 위해 작성되었다. 플랫폼마다 Trace 방법이 달라서 추적 흐름이 끊기는 것을 방지하기 위해 통합이 필요하단 이유2였다. Datadog에서 해당 스펙을 지원하고 있기 때문에 활용해보기로 했다. Log와 Trace를 연결해서 어디서 에러가 발생하는지, 어디서 병목이 발생하는지 확인하기로 했다.

datadog-trace-context.png

Monitor OTel instrumented apps with support for W3C Trace Context | Datadog

Traceparent 헤더 형식

  • 해당 권고안에 명시된 헤더가 2개(traceparent, tracestate3) 있지만 여기서는 추적을 위한 traceparent 헤더만 살펴본다.
  • {version}-{trace-id}-{parent-id}-{trace-flags}
    • version: 8 bits(1 byte). 현재는 00 고정이다. 2글자의 16진수. ff is forbidden.
    • trace-id: 128 bits(16 bytes) trace ID, 32글자의 16진수. All zeroes forbidden.
    • parent-id: 64 bits(8 bytes) span ID, 16글자의 16진수. All zeroes forbidden.
    • trace-flags: 8 bits(1 byte) 비트 필드. 데이터독에서는 2가지를 지정할 수 있음: Sampled (01), not sampled (00).
  • 예시: 00-8adb122e8b139de4a8744a379b4db39a-45897f550adef5c9-01

테스트 환경

전체 네트워크 흐름

Client(Mobile App / Browser) → CDN (Akamai) → [IDC: 방화벽(FortiGate-100E) → L2 Switch → [WAF → L4 Switch → Apache HTTP Server → Application Server]]

trace_id로 Trace와 Log 연결하기

이 방법은 APM Trace와 Log Collection에 로그가 있어야 한다.

1. Browser에서 요청 시 Traceparent 헤더 추가하기

요청 시 아래 스크립트로 생성한 값을 Traceparent 헤더와 함께 보낸다.

/**
 * https://www.w3.org/TR/trace-context-2/#traceparent-header-field-values
 */
class Traceparent {
  constructor(version, traceId, parentId, flags) {
    /**
     * 2HEXDIGLC   ; this document assumes version 00. Version ff is forbidden
     * 
     * @see https://www.w3.org/TR/trace-context-2/#version
     */
    this.version = version;
    /**
     * 32HEXDIGLC  ; 16 bytes array identifier. All zeroes forbidden
     * 
     * @see https://www.w3.org/TR/trace-context-2/#trace-id
     */
    this.traceId = traceId;
    /**
     * 16HEXDIGLC  ; 8 bytes array identifier. All zeroes forbidden
     * 
     * @see https://www.w3.org/TR/trace-context-2/#parent-id
     */
    this.parentId = parentId;
    /**
     * 2HEXDIGLC   ; 8 bit flags.
     * 
     * @see https://www.w3.org/TR/trace-context-2/#trace-flags
     */
    this.flags = flags;
  }
  toString() {
    return `${this.version}-${this.traceId}-${this.parentId}-${this.flags}`;
  }
}

// 랜덤 바이트 생성
// 브라우저에서 사용하기 위해 Node.js의 Buffer 대신 Uint8Array 사용.
function randomBytes(size) {
  const bytes = new Uint8Array(size);
  window.crypto.getRandomValues(bytes);
  return bytes;
}

// 16진수 문자열로 변환
function bufferHex(buffer) {
  return Array.from(buffer)
    .map((b) => b.toString(16).padStart(2, "0"))
    .join("");
}

// 10진수 숫자를 16진수 문자열로 변환
function toHex(number) {
  return number.toString(16).padStart(2, "0");
}

// 버전, traceId, id, flags 생성
function make() {
  const version = toHex(0); // 현재 버전은 항상 `00`이므로 0으로 설정
  const traceId = bufferHex(randomBytes(16));
  const parentId = bufferHex(randomBytes(8));
  const traceFlags = toHex(1); // Datadog: Sampled (01) / not sampled (00)
  return new Traceparent(version, traceId, parentId, traceFlags);
}

export default {
  make,
};

2. Akamai CDN에서 Traceparent의 값을 로그로 추가하기

Akamai Datastream 2에 커스텀 필드를 추가해서 traceparent 헤더의 값을 데이터독에 로그로 전달하도록 한다.

  • Properties (Property Manage) > Property 선택 후 규칙 추가
  • Datadog Log에서 Grok Parser를 활용해 Akamai Datastream - customField로 남겨진 traceparent 헤더에서 trace_id를 추출한다.
# Grok Parser
traceparent_nullif (traceparent:%{traceparent_rule}|traceparent:\^|traceparent:-|traceparent:|-)

traceparent_rule %{_version}-%{_trace_id}-%{_parent_id}-%{_flags}

# Extract from: customField

_version %{regex("[a-zA-Z0-9]*"):traceparent.version}
_trace_id %{regex("[a-zA-Z0-9]*"):traceparent.trace_id}
_parent_id %{regex("[a-zA-Z0-9]*"):traceparent.parent_id}
_flags %{regex("[a-zA-Z0-9]*"):traceparent.flags}

3. Apache HTTP Server(httpd)에서 Traceparent 헤더 로그 남기기

LogFormat에 %{header_name}i 으로 남기면 헤더의 값을 로그로 남길 수 있다. httpd의 로그도 Grok Parser를 활용해 traceparent 헤더에서 trace_id를 추출한다.

<!-- httpd.conf -->
<IfModule log_config_module>
  LogFormat "%h %l %u %t \"%r\" %>s %b %D \"%{Referer}i\" \"%{User-Agent}i\" \"%{traceparent}i\" %{BALANCER_WORKER_ROUTE}e" combined
  CustomLog /var/log/httpd/access.log combined
</IfModule>
# Grok Parser
_traceparent (%{word:traceparent.version})?(-%{word:traceparent.trace_id})?(-%{word:traceparent.parent_id})?(-%{data:traceparent.flags})?

4. Java Application (Spring Boot)

dd.trace.propagation.style 속성의 기본값은 datadog,tracecontext으로 Datadog의 Trace ID가 우선한다. 이를 tracecontext,datadog으로 변경하면 W3C Trace ID를 우선한다. 물론 여기서는 클라이언트에서 전달한 Trace ID를 사용한다.

nohup ~/.jdk/temurin-17.0.6/bin/java \
  -javaagent:/home/encar/tools/datadog/apm-java/dd-java-agent-1.37.0.jar \
  -Ddd.service.name=my-service \
  -Ddd.trace.propagation.style=tracecontext,datadog \
  -jar \
  ${ARTIFACT_PATH}/app.jar \
  --spring.profiles.active=prod \
> /dev/null &
  • dd-java-agent 다운로드
  • W3C의 traceparent는 128비트 Trace ID(32 lowercase hexadecimal characters)인 반면, Datadog은 기본적으로 64비트 Trace ID(decimal numbers)를 지원한다.
  • Datadog도 옵션 dd.trace.128.bit.traceid.generation.enabled을 추가해서 128비트 Trace ID를 출력할 수 있다고 한다.

5. 결과

Trace에 Log를 연결한 모습은 다음과 같다.

Connect Trace and Log

마치며

서버에서 발생한 에러는 Trace에서 먼저 확인 후 클라이언트 > CDN > 웹 서버 로그로 확인할 수 있고, 방화벽 이슈로 발생한 에러는 위와 같이 Log Collection에서 확인할 수 있다.

Browser 스팬을 연결할 다른 방법이 없는지 데이터독 기술 지원을 요청했지만, RUM을 사용해보라는 답변뿐이었다.4 OpenTelemetry(OTel) 도입도 고민했지만, 현재 팀 규모에서 시스템을 더 늘릴 수는 없어서 포기했다.

지연 문제도 찾아서 해결되었다. Akamai Datastream에서 정확한 duration을 확인할 수 있었는데 해당 요청들에 대해 기술 지원을 요청했고, 원인은 CDN이 아니라 IDC에 있던 방화벽에서 특정 Akamai Edge IP를 차단하고 있었다. 아래 이미지는 Akamai Edge IP를 차단 해제했을 때 해소된 모습이다.

Solve Network Delay

이것을 꼼수라고 해야 할지 모르겠지만, 어찌됐건 해당 작업 후 원인을 알 수 없던 문제들을 해결할 수 있었다.

참조

각주


  1. W3C의 권고안에는 레벨이 있는데 Trace Context는 2020년 2월 최고 레벨인 Recommendation(REC)으로 전환된 권고안이다. 올해(2024년)에는 Level 2Level 3까지 나왔다. ↩︎

  2. Problem Statement ↩︎

  3. tracestatekey=value 형태로 메타데이터를 전달하기 위해 사용하라고 되어 있는데 선택 사항이다. ↩︎

  4. Datadog Log Collection에도 Traceparent 헤더를 추가할 수 있지만, beforeSend API를 사용해야 한다고 한다. 2024년 8월 기준 RUM보다 직접 추가하는 것이 나은 듯하다. ↩︎


최종 수정: 2024-09-05