Spring Boot 개발 시 sleuth, zipkin을 활용한 분산추적환경 구축

Spring Boot 개발 시 sleuth, zipkin을 활용한 분산 추적 환경 구축

MSA형태로 개발 환경을 구축하다보니 단순히 아래와 같은 여러 가지 생길 것인데,

• 게이트웨이 -> A서비스
• 게이트웨이 -> A 서비스 -> B 서비스
• 게이트웨이 -> A 서비스 -> B 서비스 -> D 서비스
                                 -> C서비스 
• .....

복잡한 서비스 간의 호출 시 장애나 지연 상황이 발생했을 시 파악하기가 어렵다. 특히 다른 팀에서 개발 중인 서비스일 경우 추적하기가 더욱 어려울 수 있고, 로그를 남길 때에도 단순히 서비스에서 로그를 남기게 되면 그 로그가 단일로 실행된 로그인지 어떠한 비즈니스 로직 중 하나인지 알기 어렵다. 그래서 하나의 요청에 어떤 서비스들이 호출되었고, 어떤 순서로 수행되었으며, 각 서비스의 수행 시간에 대해서 파악하기 위해서 seleuth, zipkin을 활용해보기로 하자.

 

1. Sleuth, Zipkin 설치, 세팅

지금 개발하고 있는 환경이 메이븐 환경이라 메이븐을 기준으로 아래와 같이 의존성을 설정한다. (gradle도 검색하면 금방 나온다)

<dependency>
    <groupId>org.springframework.cloud</groupId>
    <artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>
<dependency>
    <groupId>org.springframework.cloud</groupId>
    <artifactId>spring-cloud-starter-zipkin</artifactId>
</dependency>

- Sleuth

Sleuth는 위에서 설명한 내용 중에 Slf4j를 이용해 로그를 출력할 시 TraceId와 SpanId 등을 자동으로 출력되도록 할 수 있다.. 여기서 TraceId란 어떠한 하나의 요청에 대해 아이디를 부여한다. 그리고 그러한 하나의 요청(TraceId) 내에서 서비스 간의 로그는 SpanId로 구분 및 순서를 파악할 수 있다. Sleuth에 대한 설명만 보면 단순히 의존성만 설정한 상태로도 로그 출력 시 TraceId와 SpanId가 출력된다고 되어있지만, 나는 진행 중인 프로젝트 환경에 무언가 방해 요소가 있는지 나오지 않았고, 그래서 Logback.xml파일을 생성해서 출력을 해 보았

다. 

 

Logback.xml (resources 폴더에 작성)

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern> %d{yyyy-MM-dd HH:mm:ss.SSS} %highlight(%-5level) %magenta(%-4relative) --- [ %thread{10}, %X{X-B3-TraceId:-}, %X{X-B3-SpanId:-}, %X{X-Span-Export:-} ] %cyan(%logger{20}) : %msg%n </pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>labatory.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>labatory.%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>

        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %-4relative --- [ %thread{10} ] %logger{35} - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="org.springframework" level="info"/>
    <logger name="org.hibernate" level="info"/>

    <root level="info">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="FILE"/>
    </root>
</configuration>

 

appender -> encoder -> pattern 부분을 살펴보면 % X {X-B3-TraceId:-}, % X {X-B3-SpanId:-} 부분이 해당 내용을 출력하도록 설정된 부분이다. 위의 파일을 작성 및 적용하기 전에 그냥 먼저 실행을 해보고 안되면 작성하는 것이 좋을 것 같다. (기본적인 세팅으로 대부분 잘 되어 있다.)

 

설정이 된 상태에서의 로그 출력을 살펴보면 아래와 같이 aa6075453 ac7 e2 af(TraceId), aa6075453 ac7 e2 af(SpanId)가 출력되는 것을 확인할 수 있다.

2021-07-08 08:07:24.553 INFO  25012 --- [ https-jsse-nio-9000-exec-3, aa6075453ac7e2af, aa6075453ac7e2af, true ] log4jdbc.log4j2 : 1. PreparedStatement.executeUpdate() returned 1
2021-07-08 08:07:24.553 INFO  25012 --- [ https-jsse-nio-9000-exec-3, aa6075453ac7e2af, aa6075453ac7e2af, true ] log4jdbc.log4j2 : 1. PreparedStatement.close() returned
2021-07-08 08:07:24.553 INFO  25012 --- [ https-jsse-nio-9000-exec-3, aa6075453ac7e2af, aa6075453ac7e2af, true ] log4jdbc.log4j2 : 1. Connection.clearWarnings() returned

 

- Zipkin

zipkin의 경우에는 이렇게 traceId와 SpanId로 묶인 로그들을 저장하고 검색하고, 분석할 수 있도록 도와준다. 상세한 설명은 zipkin에 대해 검색해보면 확인해볼 수 있다. 바쁜 관계로 실제 적용, 구축에 대한 내용들만 먼저 간략히 작성해두고 있는 터라 개념적이거나, 이론적인 부분은 이후에 시간이 날 때 보충해야 될 것 같다.

 

maven에 zipkin대한 의존성을 설정하면 기본적으로 인메모리 데이터에 로그에 대한 내용을 넣는다. 인메모리 외에도 MySQL, Cassandra, ElasticSearch를 저장소로 지원하고 있다. 각 저장소에 대한 구성은 zipkin github를 참고하기 바란다.

 

이렇게 저장된 내용으로 무엇을 하느냐가 중요한데 zipkin server를 설치 및 연결하여 살펴볼 수 있다. 

먼저, zuul이나 각 서비스의 설정 파일에 아래 내용을 입력한다. (9411이 기본 포트이다)

spring:
  zipkin:
    base-url: http://localhost:9411   # Zipkin URL

 

그리고 zipkin을 설치해보자 뭔가 검색을 해서 다운로드를 하여서 해보았는데 잘 되지 않아(난 windows환경이라) github에서 소스를 받아서 빌드 후. jar파일을 이용해 zipkin서버를 구동하였다. 그 과정에서 java(openjdk)의 버전이 16.0.1이 지원이 되지 않아 11 버전을 받아서 적용하여 빌드를 하였으며, 11버전을 이용해 서버를 띄웠다. zipkin을 받아서 시작하는 부분은 공식 홈페이지를 참조해도 된다. 파일을 올리고 싶지만 용량이 초과되어서 올리지 못했다. 

 

아무튼.. jar파일을 확보했다면 간단히 아래의 명령으로 구동할 수 있다. 정상적으로 구동되면 http://localhost:9411로 접속해보면 

java -jar zipkin-server-2.23.3-SNAPSHOT-exec.jar

아래와 같은 사이트가 나타난다.

zipkin구동 완료

여러 검색 조건을 제공한다. 서비스별, 최대 지연시간, 최소 지연시간 태그 쿼리 등, [RUN QUERY] 버튼을 눌리면 조회된다.

검색조건

살펴보면 하나의 행은 수집된 트랜잭션이라고 보면 되고 zuul이라고 표시된 부분과 test로 표기된 부분이 span이라고 볼 수 있다.

zipkin결과

보면 zuul게이트웨이에서 서비스 3건, test서비스에서 1건의 스팬이 하나의 트랜잭션으로 묶여있는 걸 확인할 수 있다.  zuul의 경우 게이트웨이로 호출받은 건에 대해 새로운 호출을 만들어서 서비스에 호출하기 때문에 생각보다 span이 더 많이 나올 수 있다.  총 345.880ms의 시간이 걸렸고, 좌측의 SHOW버튼을 눌러서 상세 내용을 확인해보면 

상세1

위와 같이 트랜잭션 내 각 스팬에 소요된 시간과 순서를 확인할 수 있다. 혹시나 하나의 트랜잭션이 시간이 너무 오래 걸려 문제점을 파악할 경우 이렇게 상세 화면에서 어떤 서비스에서 시간이 많이 지연됐는지 확인하기 쉽다, 우측의 [SHOW ALL ANNOTATIONS] 버튼을 눌러서 좀 더 상세하고 중요한 정보를 살펴보자

상세2

위의 상세 내용에는 호출을 받은 시점과, 응답한 시점의 정보가 기록되어있으며, 이런 정보들의 네트워크 지연 문제를 파악하는데 매우 중요하다고 볼 수 있다. 

 

2. 마치며

지금까지 트랜잭션에 대한 시각화를 제공해주는 zipkin에 대해서 살펴보았다. 아직 로그를 남기는 부분은 좀 더 살펴봐야겠지만, 로그를 남기기 이전에 마이크로 서비스 사이의 트랜잭션에 대해 확인하고 추적할 수 있는 기능이 우선이라 많이 활용할 수 있을 것 같다. 다음은 통합된 로깅 환경을 구축해보도록 하자