Spring Cloud Sleuth [2] - 분산 시스템과 동작 과정

🐻
‘분산 시스템의 리퀘스트 추적을 위한 Spring cloud Sleuth’, 'spring docs'를 공부하면서 정리한 포스팅입니다.

Spring Cloud Sleuth

Microservices에서 Request 추적에서의 문제점

A 서버와 B 서버가 있다고 가정해보자.

1. A 서버에 2개의 요청이 들어와서 B서버에 순서대로 요청을 보낸다고 하더라도 B 서버에서는 순서와 상관없이 처리할 수 있다.
2. A와 B 사이에 식별할 수 있는 값이 없다고 한다면 연관관계도 파악하기 힘들어진다.
   1. 임의 변수를 밀어넣어서 해결할 수는 있다. ⇒ 이것에 대한 문제점은 실습 포스팅에서 다룬다.
3. A에서 호출한 시간과 B에서의 에러 시간이 많은 시간이 차이날 수 있다.
   1. 이렇게 되면 한 눈에 연관관계를 파악하기 힘들어진다.
4. 마이크로서비스의 특징 중 하나인 폴리글랏을 유지하기 위해서 중간에 Redis, Kafka, RabbitMQ와 같은 메시지 큐를 경유가 필요할 수 있다.

🤔
이러한 문제점을 Spring Cloud에서 제공하는 Sleuth로 해결할 수 있다!

분산 시스템에서 요청을 추적하는 방법을 ‘Distributed tracing’ 라고 하는데, 한 번 알아보자.

Distributed tracing(분산 트레이스)

opentracing 홈페이지에 소개되어 있는 Distributed tracing에 대한 글을 번역했다.

What is Distributed Tracing?

Distributed tracing의 정의

Distributed Request Tracing이라고도 하며, 애플리케이션, 특히 마이크로 서비스 아키텍처를 사용하여 구축된 애플리케이션의 프로파일링 및 모니터링에 사용되는 방법이다.

분산 트레이스를 사용하면 장애가 발생하는 장소와 성능 저하를 일으키는 원인을 정확하게 파악할 수 있다.

🤔
Distributed tracing를 누가 사용해야 할까?

IT 팀과 DevOps 팀은 분산 트레이스를 사용하여 애플리케이션을 모니터링할 수 있다.

분산 트레이스는 마이크로 서비스 등의 최신 분산 소프트웨어 아키텍처를 디버깅 및 모니터링하는 데 적합하다.

개발자는 분산 추적을 사용하여 코드를 디버깅하고 최적화할 수 있다.

즉, 효율적인 코드와 유지보수를 위해 전반적인 개발자 모두가 사용해야 한다.

 

다음은 sleuth의 동작 과정을 알아보자.

다음 항에서는 저번 포스팅 때 살펴본 아래의 이미지에 나타난 예에 대해 설명한다.

Distributed Tracing with Zipkin

위 이미지에서는 7개의 span이 존재한다.

Zipkin 내 트레이스에 접근하면 다음 이미지와 같이 두 번째 트레이스에서 7개임을 확인할 수 있다.

단, 특정 트레이스를 선택하면 다음 이미지와 같이 4개의 span이 표시된다.

특정 trace를 선택하면 Marge된 span이 표시된다.

즉, Zipkin에 sr, ss 어노테이션 또는 cr, cs 어노테이션이 있는 2개의 span이 보내는 경우 1개의 스팬으로 표시된다.

🤔
첫 번째 예시에는 span이 7개, 두 번째 예시에는 4개가 나오는 이유가 뭘까?

 

• 위 사진을 보면 Service1에서는 1개의 span을 http://start에서 가져온다.
  • sr과 ss 어노테이션을 가지고 있다.
• Service1에서 Service2를 RPC 호출을 통해 http://foo로 2개의 span이 전송된다.
  • Service1에서 cs와 cr 어노테이션이 발생했다.
  • Service2에서 sr과 ss 어노테이션이 발생했다.
• Service2에서 Service3를 RPC 호출을 통해 http://bar로 2개의 span이 전송된다.
  • Service2에서 cs와 cr 어노테이션이 발생했다.
  • Service3에서 sr과 ss 어노테이션이 발생했다.
• Service2에서 Service4를 RPC 호출을 통해 http://baz로 2개의 span이 전송된다.
  • Service2에서 cs와 cr 어노테이션이 발생했다.
  • Service4에서 sr과 ss 어노테이션이 발생했다.

따라서 물리적(Physical) span를 계산하면

• http:/start에서 1개
• service1에서 호출한 service2에서 2개,
• service2 호출 서비스3에서 2개,
• service2 호출 서비스4에서 2개

총 7개의 span이 있다.

 

논리적(Logical)으로는 4개의 span을 볼 수 있다.

그 이유는 하나의 span과 RPC 호출과 관련된 세 개의 span이 있기 때문이다.

Visualizing errors

Zipkin을 사용하면 추적에서 오류를 시각화할 수 있다.

예외가 던져지고 잡히지 않았을 때, 우리는 적절한 태그를 span에 설정했다면 Zipkin이 적절하게 보정할 수 있다.

Tracing 목록에서 예외가 발생하면 빨간색으로 나타난다.

이 추적을 클릭하면 다음과 같은 유사한 그림이 표시된다.

그런 다음 span 중 하나를 클릭하면 다음이 표시된다.

span에는 error의 이유 및 error와 관련된 전체 스택 trace가 표시된다.

Distributed Tracing with Brave

2.0.0 버전부터 spring cloud sleuth는 brave를 trace 라이브러리로 사용한다.

따라서 sleuth는 더 이상 콘텍스트를 저장하지 않고 brave에게 작업을 위임한다.

slueth가 brave와 다른 명명 및 태그 규칙을 가지고 있기 때문에, 이제부터 브레이브의 규칙을 따른다.

하지만 기존 Sleuth 접근 방식을 사용하고 싶다면 spring.sleuth.http.legacy.enable 프로퍼티를 true로 설정한다.

JSON Logback with Logstash

로그는 텍스트 파일이 아니라 Logstash가 즉시 선택할 수 있는 JSON 파일에 저장하려고 하는 경우가 많다.

이렇게 하려면 다음을 수행해야 한다.

(가독성을 위해 groupId:artifactId:version 표기법에서 종속성을 전달한다).

Dependencies Setup

1. Logback이 classpath에 있는지 확인해야 한다. (ch.qos.logback:logback-core)
2. Logstash Logback 인코딩을 추가한다.
   1. 만약 4.6을 사용하려면 net.logstash.logback:logstash-logback-encoder:4.6 추가한다.

logback-spring.xml은 다음과 같다.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    
    <springProperty scope="context" name="springAppName" source="spring.application.name"/>
    <!-- Example for logging into the build folder of your project -->
    <property name="LOG_FILE" value="${BUILD_FOLDER:-build}/${springAppName}"/>

    <!-- You can override this to have a custom pattern -->
    <property name="CONSOLE_LOG_PATTERN"
              value="%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"/>

    <!-- Appender to log to console -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <!-- Minimum logging level to be presented in the console logs-->
            <level>DEBUG</level>
        </filter>
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>

    <!-- Appender to log to file -->
    <appender name="flatfile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.gz</fileNamePattern>
            <maxHistory>7</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>utf8</charset>
        </encoder>
    </appender>
    
    <!-- Appender to log to file in a JSON format -->
    <appender name="logstash" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_FILE}.json</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_FILE}.json.%d{yyyy-MM-dd}.gz</fileNamePattern>
            <maxHistory>7</maxHistory>
        </rollingPolicy>
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers>
                <timestamp>
                    <timeZone>UTC</timeZone>
                </timestamp>
                <pattern>
                    <pattern>
                        {
                        "severity": "%level",
                        "service": "${springAppName:-}",
                        "trace": "%X{traceId:-}",
                        "span": "%X{spanId:-}",
                        "baggage": "%X{key:-}",
                        "pid": "${PID:-}",
                        "thread": "%thread",
                        "class": "%logger{40}",
                        "rest": "%message"
                        }
                    </pattern>
                </pattern>
            </providers>
        </encoder>
    </appender>
    
    <root level="INFO">
        <appender-ref ref="console"/>
        <!-- uncomment this to have also JSON logs -->
        <!--<appender-ref ref="logstash"/>-->
        <!--<appender-ref ref="flatfile"/>-->
    </root>
</configuration>

애플리케이션의 정보를 JSON 형식으로 build/${spring.application.name}.json 파일에 기록한다.

Propagating(전파) Span Context

span context는 프로세스 경계를 넘어 하위 span으로 전파되어야 하는(Propagated) 상태다.

span context의 일부는 Baggage라고 한다.

trace 및 sapn ID는 span context의 필수 부분이다.

Baggage은 선택 사항이다.

🐻
현재 Baggage 품목의 개수나 크기에는 제한이 없다.
그러나 너무 많으면 시스템 처리량이 감소하거나 RPC 지연 시간이 증가할 수 있다.
극단적인 경우, 너무 많은 Baggage이 전송 수준 메시지 또는 헤더 용량을 초과하여
응용 프로그램을 손상시킬 수 있다.

 

다음 예는 Baggage을 span에 설정하는 방법이다.

Span initialSpan = this.tracer.nextSpan().name("span").start();
ExtraFieldPropagation.set(initialSpan.context(), "foo", "bar");
ExtraFieldPropagation.set(initialSpan.context(), "UPPER_CASE", "someValue");

Baggage vs. Span Tags

Baggage은 trace과 함께 이동한다.

(모든 child span는 parent의 baggage를 포함한다)

Zipkin은 baggage에 대한 지식이 없고 그 정보를 받지 못한다.

 

Tag는 특정 span에 부착된다.

다시 말해서, 그것들은 특정 span에만 표시된다.

그러나 검색된 tag 값을 갖는 span이 존재한다고 가정하면 tag별로 검색하여 trace를 찾을 수 있다.

Baggage를 기준으로 span을 조회하려면 root span에 해당 항목을 tag로 추가해야 한다.