애플리케이션·접근 로그를 JSON과 추적 필드로 연결하기

여러 서비스의 로그를 함께 보려면 형식과 필드 이름부터 맞춰야 했습니다. 어느 서비스는 사용자 식별자를 남기고 다른 서비스는 요청 경로만 남기면, 같은 작업의 기록을 모으는 데도 서비스별 지식이 필요했습니다.

애플리케이션 로그와 접근 로그를 JSON으로 출력하고, 공통 필드와 추적 정보를 함께 남기도록 정리했습니다. 로그를 모으는 인프라 설정과 각 서비스의 출력 설정을 함께 바꾼 작업이었습니다.

공통 필드와 로그 종류

서비스 이름, 로그 레벨, 요청 경로, 사용자·요청 식별 정보처럼 검색에 사용할 필드를 맞췄습니다. log_type으로는 application과 access를 구분했습니다.

애플리케이션 로그에서는 코드가 어떤 작업을 처리했는지 보고, 접근 로그에서는 HTTP 메서드·상태 코드·처리 시간 등을 확인할 수 있습니다. 두 로그의 필드를 전부 같게 만들 필요는 없지만, 같은 요청에 해당하는 기록을 모을 공통 키는 필요했습니다.

다음은 내부 사용자나 경로를 그대로 옮기지 않고 필드 관계만 줄인 예입니다.

{
  "log_type": "application",
  "level": "INFO",
  "message": "Account activation completed",
  "actor_id": "operator-123",
  "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736",
  "span_id": "b7ad6b7169203331"
}

{
  "log_type": "access",
  "method": "POST",
  "path": "/api/accounts/activate",
  "status_code": 200,
  "elapsed_ms": 245,
  "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736",
  "span_id": "b7ad6b7169203331"
}

이 예시는 같은 서버 span 안의 로그를 보여 줍니다. 실제로는 요청 처리 중 하위 span이 만들어질 수 있으므로 모든 로그의 span_id가 같아야 하는 것은 아닙니다. 요청 전체를 모을 때는 trace_id를 사용하고, 세부 작업을 구분할 때 span을 봅니다.

Trace Context와 MDC

서비스 간 요청은 W3C Trace Context의 traceparent 헤더로 연결했습니다. 버전 00 형식은 다음과 같습니다.

00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

순서대로 버전, trace ID, 호출자가 보낸 parent ID, 플래그입니다. 여기서 parent ID는 이 헤더를 보낸 쪽의 span ID입니다. 서버가 요청을 이어받아 새 span을 만들면 서버 로그의 span_id는 들어온 parent ID와 달라집니다. 위 로그 예시에서 trace ID는 같고 span ID가 다른 이유입니다.

Splunk OTel Java Agent의 로깅 계측을 사용하면 현재 trace의 trace_id·span_id 등을 MDC와 연결할 수 있습니다. 다만 MDC에 값이 있는 것과 JSON 로그에 출력되는 것은 별도이므로, 인코더에서도 해당 필드를 포함하도록 설정해야 합니다.

접근 로그에는 별도 provider를 연결했습니다. 접근 로그가 출력될 때는 요청 처리 중의 MDC가 이미 정리됐을 수 있어, 값을 확보하는 시점도 중요합니다. 요청 처리 중의 trace 정보를 접근 로그까지 전달할 수 있어야 같은 요청으로 검색할 수 있습니다.

LogstashEncoder를 사용한 출력

처음에는 애플리케이션 로그에 LogstashEncoder, 접근 로그에 LogstashAccessEncoder를 사용했습니다. 두 종류의 로그 설정을 따로 관리하면서 log_type 같은 필드도 추가했습니다.

아래는 애플리케이션 로그의 기본 구성을 보여 주는 예입니다. logstash-logback-encoder 의존성이 준비된 Logback 환경을 전제로 합니다.

<configuration>
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
      <customFields>{"log_type":"application"}</customFields>
    </encoder>
  </appender>
  <root level="INFO">
    <appender-ref ref="CONSOLE"/>
  </root>
</configuration>

접근 로그는 인코더만 추가해서 생기는 로그가 아닙니다. 서버의 접근 로그 연동과 별도 설정이 필요하고, 여기에 trace 정보를 출력하는 provider도 연결해야 했습니다.

Spring Boot 구조화 로깅으로 변경

이후 애플리케이션 로그는 Spring Boot의 구조화 로깅으로 옮겼습니다. Spring Boot 3.4부터 제공되는 기능으로, 기본 로깅 구성을 사용할 때 다음 설정으로 Logstash 형식의 JSON을 출력할 수 있습니다.

logging.structured.format.console=logstash

이 형식은 MDC의 키·값을 JSON에 포함하며, SLF4J fluent API의 addKeyValue()로도 필드를 추가할 수 있습니다. 직접 작성한 Logback 설정을 계속 사용한다면 해당 appender·encoder 구성이 새 설정과 연결되는지도 확인해야 합니다.

바뀐 것은 애플리케이션 로그의 출력 방식입니다. 별도로 연동한 접근 로그까지 이 속성 하나로 전환되는 것은 아니어서, 접근 로그 설정은 따로 유지했습니다.

stdout에서 Splunk까지

ECS 환경에서는 컨테이너의 stdout 로그를 Splunk 로깅 드라이버와 HEC로 보내도록 구성했습니다. 이 수집 경로는 인프라 설정에서 관리하고, 애플리케이션의 출력 필드는 각 서비스 저장소에 반영했습니다.

JSON으로 보냈다고 모든 필드가 항상 같은 방식으로 인덱싱되는 것은 아닙니다. Splunk의 sourcetype과 필드 추출 설정에 따라 검색 시점에 필드를 추출할 수도 있습니다. 로그가 들어오는지와 원하는 필드로 검색되는지를 모두 확인해야 합니다.

필드 추출이 맞춰진 환경에서는 다음과 같이 같은 trace의 로그를 모을 수 있습니다. 인덱스 이름은 예시입니다.

index=application_logs trace_id="4bf92f3577b34da6a3ce929d0e0e4736"

index=application_logs trace_id="4bf92f3577b34da6a3ce929d0e0e4736"
| search log_type="access"

필드를 맞춘 뒤에는 서비스마다 다른 문장을 찾는 대신 같은 키로 요청을 찾아볼 수 있었습니다. 인프라의 수집 설정만 공통화해도 끝나는 작업은 아니었습니다. 각 서비스의 출력 설정과 비동기 실행에서도 해당 필드가 이어져야 했습니다.

비동기 작업의 문맥 전달

동기 요청에서는 보이던 사용자·요청 정보가 비동기 작업에서 빠지는 문제도 있었습니다. MDC는 실행 스레드와 관련되므로 작업을 다른 스레드로 넘길 때 별도 처리가 필요했습니다.

이 부분은 ThreadPoolTaskExecutor에 MDC를 전달하는 TaskDecorator를 등록하는 방식으로 보완했습니다. MDC를 복사하는 처리와 분산 추적 context를 전파하는 처리는 구분해서 봐야 합니다. 다음 글인 비동기 작업에서 사라진 MDC 전달하기에서 이어서 설명합니다.

참고 자료

• W3C Trace Context 
• Spring Boot 3.4 로깅 문서 
• Splunk Java 추적 정보와 로그 연결 
• Docker Splunk 로깅 드라이버 
• Splunk JSON 필드 추출 설정