로깅 시스템 #6-Spring Boot에서 Zipkin을 이용한 분산 시스템 로깅

Spring Boot + slf4j + MDC + Zipkin

 

조대협 (http://bcho.tistory.com)

 

아래 예제는 MDC를 이용해서 여러 메서드간의 컨텍스트를 연결하는 것을 확장해서, 서로 다른 프로세스와 서버간에 로그를 연결하는 방법이다. 서로 다른 프로세스 또는 서버간에 컨텍스트를 전달하려면 HTTP 헤더등을 통해러 리모트로 컨텍스트를 전달해야 하는데, 이를 가능하게 하는 오픈소스로 Zipkin이 있다. (자세한 설명은 이글을 참고하기 바란다. )

Zipkin은 원래 분산 로그 추적용으로 개발된 오픈소스가 아니라 원래 목적은 분산 시스템에서 각 구간별 레이턴시(지연시간)을 측정해서 구간별 소요 시간을 측정하는 트레이스용도로 개발이 되었지만, 구간별 소요 시간을 측정하기 위해서는 각 개별 서비스를 연결해야 하기 때문에, 트레이스 ID가 필요하게 되었고, 트레이스 ID를 로그에 같이 저장하였기 때문에, 부가적인 효과로 분산 로그 추적에도 사용할 수 있다.

Zipkin을 Spring Boot와 연결하는 방법은 오픈소스인 Spring Sleuth를 이용하면 쉽게 된다.

 

아래 예제는 앞의 글인  Spring Boot에서 MDC를 사용하는 예제에 Zipkin 연동만을 추가한 예제이다.

Spring Boot로 간단한 REST API를 구현한후, 로깅을 하는 예제이다. 로거는 slf4j와 logback을 사용하였고,  MDC를 이용해서 userId와 같은 컨택스트 정보를 넘기도록 하였고, JSON 포맷으로 로그를 출력하였다. 마이크로 서비스와 같은 분산 서비스간에 로그 추적성을 제공하기 위해서 ZipKin 라이브러리를 사용하였다. 스프링에서는 ZipKin 라이브러리 통합을 Spring Sleuth를 통해서 지원하기 때문에, Spring Sleuth와 Zipkin을 연결하여 코드를 작성하였다. 전체 코드는 여기를 참고하면 된다.

 

아래는 Spring Boot에서 Zipkin을 사용하기 위해서 메이븐 pom.xml에 의존성을 추가한 내용이다.

<dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> </dependency> <dependency> <groupId>org.springframework.cloud</groupId> <artifactId>spring-cloud-starter-sleuth</artifactId> <version>2.1.1.RELEASE</version> </dependency> <dependency> <groupId>org.springframework.cloud</groupId> <artifactId>spring-cloud-starter-zipkin</artifactId> <version>2.1.1.RELEASE</version> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-test</artifactId> <scope>test</scope> </dependency> <dependency> <groupId>com.google.cloud</groupId> <artifactId>google-cloud-logging-logback</artifactId> <version>0.84.0-alpha</version> </dependency> <!-- slf4j & logback dependency --> <dependency> <groupId>ch.qos.logback.contrib</groupId> <artifactId>logback-json-classic</artifactId> <version>0.1.5</version> </dependency> <dependency> <groupId>ch.qos.logback.contrib</groupId> <artifactId>logback-jackson</artifactId> <version>0.1.5</version> </dependency> <dependency> <groupId>com.fasterxml.jackson.core</groupId> <artifactId>jackson-databind</artifactId> <version>2.9.3</version> </dependency>

<코드.pom.xml >

 

다음은 logback 로거를 사용하기 위해서 logback에 대한 설정을 한 logback.xml이다. JSON 포맷으로 로깅을 하도록 설정 하였다.

 

<?xml version="1.0" encoding="UTF-8"?> <configuration>    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">            <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">                <timestampFormat>yyyy-MM-dd'T'HH:mm:ss.SSSX</timestampFormat>                <timestampFormatTimezoneId>Etc/UTC</timestampFormatTimezoneId>                <appendLineSeparator>true</appendLineSeparator>                <jsonFormatter class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">                    <!--                    <prettyPrint>true</prettyPrint>                     -->`                </jsonFormatter>            </layout>        </encoder>    </appender>    <root level="info">        <appender-ref ref="stdout"/>    </root> </configuration>

<코드. /resources/logback.xml >

 

Zipkin을 사용할 경우, 트레이스 정보를 zipkin 서버로 전송해야 하는데, 이를 위해서 zipkin 서버에 대한 정보를 설정해야 한다. 보통 zipkin 에이전트가 로컬에서 돌기 때문에, 포트만 지정하면 된다. 아래와 같이 zipkin 서버에 대한 포트를 8081로 지정하였고, 이 애플레케이션의 이름을 zipkin-server1으로 지정하였다. 이 예제에서는 zipkin을 분산로그 추적용으로만 사용하였기 때문에, 실제로 zipkin 서버 에이전트는 실행하지 않았다.

server.port = 8081 spring.application.name = zipkin-server1

<코드. /resources/application.properties >

 

다음은 Spring Boot의 REST API Controller 코드의 일부이다.

@RestController
@RequestMapping("/orders")
public class OrderController {
Logger log = LoggerFactory.getLogger("com.terry.logging.controller.OrderController");
@RequestMapping(value="/{id}",method=RequestMethod.GET)
public Order getOrder(@PathVariable int id,
      @RequestHeader(value="userid") String userid) {
  MDC.put("userId", userid);
  MDC.put("ordierId",Integer.toString(id));
  Order order = queryOrder(id,userid);
  log.info("Get Order");
  MDC.clear();
  return order;
}

Order queryOrder(int id,String userid) {
  String name = "laptop";
  Order order = new Order(id,name);
  order.setUser(userid);
  order.setPricePerItem(100);
  order.setQuantity(1);
  order.setTotalPrice(100);
  log.info("product name:"+name);
  return order;
}

<코드. /resources/application.properties >

 

Spring Sleuth를 사용하게 되면 자동으로 Zipkin 코드를 의존성 주입 (Dependency Injection)을 이용해서 코드에 삽입해주는데, 이때 몇가지 제약사항이 있다. Spring Boot로 들어오는 트래픽은 Servlet Filter를 통해서 의존성 주입을 하는데, Spring Boot에서 다른 서비스로 나가는 트래픽의 경우에는 Rest Template 이나, Feign Client 와 같은 특정한 방법만을 지원한다. 지원되는 라이브러리의 범위에 대해서는 이 링크를 참고하기 바란다.

 

위의 예제는 HTTP Header에서 들어온 userId를 MDC 컨텍스트에 저장하는 예제이다.

위의 REST 서비스를 호출해보면 다음과 같은 결과가 나온다.

<그림. PostMan을 통해서 REST 요청과 응답을 받은 화면 >

 

그리고, 호출후에 나온 로그는 다음과 같다.

 

{     "timestamp":"2019-04-14T05:49:52.573Z",   "level":"INFO",   "thread":"http-nio-8081-exec-1",   "mdc":{        "traceId":"270b7b7b5a8d4b5c",      "spanId":"270b7b7b5a8d4b5c",      "spanExportable":"false",      "X-Span-Export":"false",      "ordierId":"1",      "X-B3-SpanId":"270b7b7b5a8d4b5c",      "X-B3-TraceId":"270b7b7b5a8d4b5c",      "userId":"terry"   },   "logger":"com.terry.logging.controller.OrderController",   "message":"Get Order",   "context":"default" }

<코드. /resources/application.properties >

 

위의 결과와 같이 MDC 부분에, Zipkin이 자동으로 traceId를 선언해서 삽입해 준다. MDC에 저장한 userId도 위처럼 한꺼번에 출력되는 것을 확인할 수 있다.

 

Spring Sleuth는 slf4j를 사용하는 경우에만 MDC 컨텍스트에 트레이스 ID를 넣어주기 때문에, 다른 자바 로깅 프레임웍을 slf4j없이 사용하는 경우 자동으로 트레이스 ID를 넣어주지 않기 때문에 이점을 주의하기 바란다.

(참고 : "Adds trace and span ids to the Slf4J MDC, so you can extract all the logs from a given trace or span in a log aggregator.")