MSA 환경에서 분산 추적시스템 적용하기

서론

마이크로 서비스 환경에서는 사용자가 보낸 하나의 HTTP 요청이 내부적으로 여러 서비스를 거쳐서 응답을 제공하는 경우가 많다.

이런 이유에서 마이크로 서비스 환경에서는 요청을 추적하거나, 병목 구간을 파악하기가 힘들다.

 

 

마이크로 서비스에서 요청을 추적하는 건 매우 중요하고 필수적입니다.

이번 글에서는 zipkin & spring cloud sleuth를 활용해서 이를 관리하는 방법을 소개하겠습니다.

 

Zipkin

zipkin은 대표적은 분산 추적 시스템 오픈소스다. 흐름 구성도는 다음과 같이 구성되어있다.

Reference: https://zipkin.io/pages/architecture.html

리포터는 추적 데이터를 전송하고 데이터베이스에 저장하게된다.

이 데이터는 나중에 API를 통해서 스토리지에 쿼리하여 UI로 제공하게된다.

 

트레이서 라이브러리는 홈페이지에서 확인 가능하다. 다양한 언어를 지원하고있다. (자바 진영에서는 brave)

스토리지 같은 경우는 엘라스틱서치, MySql, 인 메모리 등을 지원하고있다.

 

zipkin은 B3 형식으로 헤더로 제공하는데, B3-propagation은 다음과 같이 HTTP 헤더에 X-B3-{name} 형식으로 전파된다.

Reference: https://github.com/openzipkin/b3-propagation

 

Spring Cloud Sleuth

Spring Cloud Sleuth (이하 Slueth)는 Spring Boot에서 손쉬운 분산 추적을 구성해준다. (zipkin과 손쉽게 연동된다고 생각하면 된다)

아까 위 사진에서 보았듯이 X-B3 값들은 TraceContext에서 관리되는데, Slf4j MDC를 이용해서 손 쉽게 추출할 수 있다.

 

그럼 어떤식으로 Trace Id와 Span Id를 관리하고 있을까? 

Reference: https://docs.spring.io/spring-cloud-sleuth/docs/current/reference/html/getting-started.html#getting-started

Trace Id는 최초 클라이언트가 보낸 HTTP 요청의 흐름이고, Span Id는 서비스, 트랜잭션 별로 다른 값이 부여된다.

즉 Trace Id로 사용자의 요청을 추적할 수 있는 것이다. 최초로 들어온 요청에는 Trace Id와 Span Id가 없으므로, 필터에서 이를 검사해서 없을 경우 새롭게 생성해준다.

 

예제

실험을 위해서는 두 개 이상의 서비스가 띄워져있어야합니다.

 

build.gradle

plugins {
    id 'org.springframework.boot' version '2.6.4'
    id 'io.spring.dependency-management' version '1.0.11.RELEASE'
    id 'java'
}

group 'org.example'
version '1.0-SNAPSHOT'

ext {
    set('springCloudVersion', "2021.0.1")
}

repositories {
    mavenCentral()
}

dependencies {
    implementation 'org.springframework.boot:spring-boot-starter-web'
    implementation 'org.springframework.cloud:spring-cloud-starter-sleuth'
    
    testImplementation 'org.springframework.boot:spring-boot-starter-test'
}

dependencyManagement {
    imports {
        mavenBom "org.springframework.cloud:spring-cloud-dependencies:${springCloudVersion}"
    }
}

test {
    useJUnitPlatform()
}

 

application.yml

logging:
  level:
    org.apache.coyote.http11: debug

 

OrderService(A) -> ItemService(B) 서비스로 Http 요청을 보내고 로그를 확인해보자.

 

 

A서비스 로그

User-Agent: PostmanRuntime/7.28.4
Accept: */*
Postman-Token: 656dc426-593e-46be-a1b7-b388b0726ee4
Host: localhost:8080
Accept-Encoding: gzip, deflate, br
Connection: keep-alive

INFO [order,d6dd953b3ffab3d9,d6dd953b3ffab3d9] 78346 --- [nio-8080-exec-1] com.example.OrderController: >>> OrderController
// 왼쪽부터 애플리케이션 이름, trace id, spand id가 로그에 출력된다

 

 

B서비스의 로그.

X-B3-TraceId: d6dd953b3ffab3d9
X-B3-SpanId: ac6b4f2e1fa55046
X-B3-ParentSpanId: d6dd953b3ffab3d9
X-B3-Sampled: 0
Accept: */*
User-Agent: Java/17.0.2
Host: localhost:8081
Connection: keep-alive

INFO [item,d6dd953b3ffab3d9,ac6b4f2e1fa55046] 78345 --- [nio-8081-exec-3] com.example.ItemController : >>> ItemController

// trace id는 동일하지만, span id는 다르게 출력되었다.

trace 정보들이 헤더에 전달된 것을 확인할 수 있다.

로그를 확인해보면 trace id는 동일하지만, span id는 다르게 출력되었다.

 

그렇다면 header에 값을 넣어준적이 없는데, 어떻게 값이 들어간걸까?

우선 Http client마다 다르다. Feign Client로 요청을 보내면, TracingFeignClient에서 헤더에 값을 넣어준다.

 

application.yml에 다음 옵션을 추가하면 로그를 보다 정확하게 확인할 수 있다.

logging:
  level:
    org.springframework.cloud.sleuth: trace

TRACE [order,4889c56adaaf5009,4889c56adaaf5009] 84484 --- [nio-8080-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Added key [X-B3-TraceId] and header value [4889c56adaaf5009]
TRACE [order,4889c56adaaf5009,4889c56adaaf5009] 84484 --- [nio-8080-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Added key [X-B3-SpanId] and header value [66c3e8bbebecd4be]
TRACE [order,4889c56adaaf5009,4889c56adaaf5009] 84484 --- [nio-8080-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Added key [X-B3-ParentSpanId] and header value [4889c56adaaf5009]
TRACE [order,4889c56adaaf5009,4889c56adaaf5009] 84484 --- [nio-8080-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Added key [X-B3-Sampled] and header value [1]
DEBUG [order,4889c56adaaf5009,4889c56adaaf5009] 84484 --- [nio-8080-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Handled send of RealSpan(4889c56adaaf5009/66c3e8bbebecd4be)
DEBUG [order,4889c56adaaf5009,4889c56adaaf5009] 84484 --- [nio-8080-exec-3] o.s.c.s.i.w.c.feign.TracingFeignClient   : Handled receive of RealSpan(4889c56adaaf5009/66c3e8bbebecd4be)

 

 

그럼 이번엔 MDC에서 trace 정보를 가져와보자.

여기서 주의할 점이 있다. Spring Cloud Sleuth 3.0부터는 MDC에서 값을 가져올때는 traceId, spanId로 값을 가져와야한다.
(공식 문서)

MDC에서 값을 가져올때 저장된 key 값을 확인할 수 있다.

 

 

Zipkin 실행 및 연동

 

이번엔 zipkin을 실행한 뒤 연동해보자. 간단하게 실행하기 위해서 도커로 실행하였다.

docker run -d -p 9411:9411 openzipkin/zipkin

 

실행하고 난 뒤 http://localhost:9411로 접속해서 다음과 같은 화면이 뜨면 정상적으로 실행된 것이다.

 

 

이제 스프링부트에 의존성을 추가해보자.

implementation "org.springframework.cloud:spring-cloud-sleuth-zipkin"

 

spring-cloud-sleuth-zipkin은 HTTP를 통해 zipkin에 추적 정보를 보고한다. 기본적으로 localhost:9411에 요청을 보내지만 application.yml에서 설정을 변경할 수 있다.

spring.zipkin.base-url:

 

설정이 끝났으면 요청을 보낸 뒤 RUN QUERY를 눌러보자.

요청을 잘 기록하고 있는 걸 확인할 수 있다.

 

원래 얼마전 로그 관련해서 트러블 슛팅을 하게 되었는데, 그 과정에서 얻은 지식들을 공유드렸습니다.

다음번에는 로그 관련 트러블 슛팅 경험에 대해서 설명하는 글을 작성하겠습니다.

 

 

Reference

- https://docs.spring.io/spring-cloud-sleuth/docs/current/reference/html/getting-started.html#getting-started

- https://engineering.linecorp.com/ko/blog/line-ads-msa-opentracing-zipkin/