개발 일지

Micrometer Log Tracing (feat. Spring Boot 3)

북극곰은콜라 2023. 12. 14. 16:08
반응형


Micrometer란

Vendor-neutral application observability facade

micrometer는 observability의 파사드(고수준 인터페이스)를 제공해주는 프로젝트이다.
observability는 Application의 가시성을 제공해주는 것을 말하며, 이는 Application 내에서 발생하는 process를 외부로 제공해주는 것 이다.
JVM -based Application라면 ventdor에 상관없이 적용할 수 있다.

Project Develop History

2016 [Spring] Create tracing library(Spring Cloud Sleuth) from Spring Cloud team
2017 [Micrometer] Micrometer Project 시작 (only for jvm based application observation)
2018 [Micrometer] 1.0.0 RELEASE
2022.1 [Micrometer-tracing] 1.0.0-M1 RELEASE
2022.11 [Micrometer] 1.10.0 (GA version) RELESE
2022.11 [Micrometer-tracing] 1.0.0 RELEASE → Spring Cloud Sleuth를 흡수

 

Spring 공식 Document에서 Spring Cloud Sleuth는 Micrometer-Tracing Project로 이사 간 사항을 고시하고 있다.
Spring-Cloud 2022 버전부터 Sleuth 적용 시 Initilization Error와 함께 위 공지가 나온다.

Features

1.   Easy to Integration with Spring Project
2.   Easy to pass Metrics to Monitoring tool
3.   Provide Tracing Library
4.   Provide Context Propagation Library

Instrumentation

1.   Provide Spring Metrics
2.   Provide JVM Metrics
3.   Provide Cache Metrics
4.   Provide Instrumentation for Netty
5.   Provide OkHttpClient Metrics
6.   Provide Instrumentation for Jetty, Jersey

Support Monitoring Tools

 

 


// Log Tracing 란

MSA 구조에서 End to End를 사이에 일어난 사항을 확인하기 위한 Tracing 기법
log를 기반으로, traceId, spanId (+parentSpanId)를 활용하여 전체적인 flow를 파악한다.
slow process, error point를 잡아내기에 용이 함

 


Tracing 적용 가이드

Spring boot 3 기반 프로젝트에서 REST, RSocket, Kafka(reactor)에 Tracing 및 Propagation, Zipkin 연동 가이드

Test Version Specification

구분 항목 Version
Java Java 17
Spring org.springframework.boot 3.1.5
Spring io.spring.dependency-management 1.1.2
Spring org.springframework.cloud:spring-cloud-dependencies 2022.0.3
Reactor io.projectreactor.kafka:reactor-kafka 1.3.22
Brave io.zipkin.brave:brave-bom 5.15.1
RSocket io.rsocket:rsocket-micrometer 1.1.4
Docker openzipkin/zipkin 3.0.0-rc0 (latest)

ZipKin Setup

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

REST Tracing

REST Tracing의 경우 Conifg 만으로 적용이 가능하다.
Spring Actuator를 통해서 연동이 가능
WebClient는 반드시 Builder를 인자로 받아 Bean으로 선언해야한다.

Gradle

implementation 'org.springframework.boot:spring-boot-starter-actuator'
implementation 'io.micrometer:micrometer-tracing-bridge-brave'
// for report
implementation 'io.zipkin.reporter2:zipkin-reporter-brave'

application.yml

logging:
  pattern:
    level: "%5p [%X{traceId},%X{spanId}]"
management:
  tracing:
    sampling:
      probability: 1.0
    propagation:
      consume: b3
      produce: b3_multi
    enabled: true
  zipkin:
    tracing:
      endpoint: http://localhost:9411/api/v2/spans

Hooks

private static void hooks() {
  Hooks.enableAutomaticContextPropagation();
}

WebClient

@Bean
public WebClient webClient(WebClient.Builder builder) {
  return builder.build();
}

Test Log

// Application 1
2023-12-07 10:22:36 [reactor-http-nio-6] INFO [65711e5cd3177ba2125ebb529a63dbf4,125ebb529a63dbf4] c.e.tracing4spring3.rest.RestT - get /test start
...
2023-12-07 10:22:36 [reactor-http-nio-6] INFO [65711e5cd3177ba2125ebb529a63dbf4,125ebb529a63dbf4] c.e.tracing4spring3.rest.RestT - res: {result=success}

// Application 2
2023-12-07T10:22:17.100+09:00  INFO [65711e48970b05e498223b2f239e48ca,1c828e842276ba45] 12932 --- [ctor-http-nio-4] : test1 <<<, header: 
  [X-B3-TraceId:"65711e48970b05e498223b2f239e48ca", X-B3-SpanId:"f7fe2062438d0f0e", X-B3-ParentSpanId:"98223b2f239e48ca", X-B3-Sampled:"1", accept-encoding:"gzip", user-agent:"ReactorNetty/1.1.12", host:"127.0.0.1:9083", accept:"*/*"]
...

 

ZipKin


RSocket Tracing

RSocket Tracing의 경우 Integration을 위한 코드 작성이 필요하다.
  1. RSocketResponderTracingObservationHandler, RSocketRequesterTracingObservationHandler 를 Bean으로 생성      2. Micrometer에서 제공하는 RSocketProxy 구현체를 RSocketConnector, RSocketServer의 Interceptor에 등록한다.
      // Inteceptor 등록은 Customizer를 통해 적용
micormeter에서 Sample Code를 제공한다.

 

Gradle

implementation 'io.rsocket:rsocket-micrometer:1.1.4'

application.yml

상동

ObservationHandler Bean등록

@Bean
@Order(Ordered.HIGHEST_PRECEDENCE + 10)
RSocketResponderTracingObservationHandler rSocketResponderTracingObservationHandler(Tracer tracer, Propagator propagator) {
  return new RSocketResponderTracingObservationHandler(tracer, propagator, new ByteBufGetter(), true);
}

@Bean
@Order(Ordered.HIGHEST_PRECEDENCE + 10)
RSocketRequesterTracingObservationHandler rSocketRequesterTracingObservationHandler(Tracer tracer, Propagator propagator) {
  return new RSocketRequesterTracingObservationHandler(tracer, propagator, new ByteBufSetter(), true);
}

RSocketServer 설정

@Bean
ObservationRSocketServerCustomizer observationRSocketServerCustomizer(ObservationRegistry observationRegistry) {
  return new ObservationRSocketServerCustomizer(observationRegistry);
}


class ObservationRSocketServerCustomizer implements RSocketServerCustomizer {

  private final ObservationRegistry observationRegistry;

  ObservationRSocketServerCustomizer(ObservationRegistry observationRegistry) {
    this.observationRegistry = observationRegistry;
  }

  @Override
  public void customize(RSocketServer rSocketServer) {
    rSocketServer.interceptors(ir -> ir.forResponder(
            (RSocketInterceptor) rSocket -> new ObservationResponderRSocketProxy(rSocket, this.observationRegistry))
        .forRequester((RSocketInterceptor) rSocket -> new ObservationRequesterRSocketProxy(rSocket,
            this.observationRegistry)));
  }
}

RSocketReuqester (Connector) 설정

@Bean
ObservationRSocketConnectorConfigurer observationRSocketConnectorConfigurer(
    ObservationRegistry observationRegistry) {
  return new ObservationRSocketConnectorConfigurer(observationRegistry);
}

class ObservationRSocketConnectorConfigurer implements RSocketConnectorConfigurer {

  private final ObservationRegistry observationRegistry;

  ObservationRSocketConnectorConfigurer(ObservationRegistry observationRegistry) {
    this.observationRegistry = observationRegistry;
  }

  @Override
  public void configure(RSocketConnector rSocketConnector) {
    rSocketConnector.interceptors(ir -> ir.forResponder(
            (RSocketInterceptor) rSocket -> new ObservationResponderRSocketProxy(rSocket, this.observationRegistry))
        .forRequester((RSocketInterceptor) rSocket -> new ObservationRequesterRSocketProxy(rSocket,
            this.observationRegistry)));
  }
}

 

Test Log

// Application 1
2023-12-07 11:27:49 [reactor-http-nio-6] INFO [65712da58aa02571bfd0fef42b4056f9,bfd0fef42b4056f9] c.e.t.rsocket.RSocketService - rsocket request start
...
Frame => Stream ID: 1 Type: REQUEST_RESPONSE Flags: 0b100000000 Length: 175
Metadata:
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| fe 00 00 09 08 74 65 73 74 2e 31 2e 31 0b 58 2d |.....test.1.1.X-|
|00000010| 42 33 2d 54 72 61 63 65 49 64 00 00 20 36 35 37 |B3-TraceId.. 657|
|00000020| 31 32 64 61 35 38 61 61 30 32 35 37 31 62 66 64 |12da58aa02571bfd|
|00000030| 30 66 65 66 34 32 62 34 30 35 36 66 39 0a 58 2d |0fef42b4056f9.X-|
|00000040| 42 33 2d 53 70 61 6e 49 64 00 00 10 31 30 37 32 |B3-SpanId...1072|
|00000050| 36 35 37 36 61 34 66 63 65 34 65 39 10 58 2d 42 |6576a4fce4e9.X-B|
|00000060| 33 2d 50 61 72 65 6e 74 53 70 61 6e 49 64 00 00 |3-ParentSpanId..|
|00000070| 10 62 66 64 30 66 65 66 34 32 62 34 30 35 36 66 |.bfd0fef42b4056f|
|00000080| 39 0b 58 2d 42 33 2d 53 61 6d 70 6c 65 64 00 00 |9.X-B3-Sampled..|
|00000090| 01 31                                           |.1              |
+--------+-------------------------------------------------+----------------+
...

// Application 2
2023-12-07T11:27:49.831+09:00  INFO [65712da58aa02571bfd0fef42b4056f9,9618da9fe0e57514] 12932 --- [ctor-http-nio-9] : do handle
...

Zipkin

 


Kafka (Reactor)

Reactor-Kafka에서는 비교적 최근에 Tracing Observation Integration이 추가 되었다.
이슈번호 321에서 다뤄졌으며, 2023.10.27에 머지 되었다. (https://github.com/reactor/reactor-kafka/issues/321)
적용된 버전은 1.3.22 이다.
Reactor-Kafka에서 Tracing을 위한 interface로 SenderOptions, ReceiverOptions에서 withObservation() 메서드를 제공한다.
인자로 ObservationRegistry(Micrometer)를 넣어서 tracing을 propagation 한다.
Receiver의 경우 Propagation된 context를 flow에 할당하는 추가적인 로직이 필요하다.

Gradle, application.yml

상동

KafkaSender (producer)

SenderOptions<String, Object> senderOptions = SenderOptions.create(senderProps);
return KafkaSender.create(senderOptions.withObservation(observationRegistry));
ReceiverOptions<String, String> receiverOptions = ReceiverOptions.create(consumerConfig);
KafkaReceiver<String, String> kafkaReceiver = KafkaReceiver.create(
    receiverOptions
        .withObservation(observationRegistry)
        .atmostOnceCommitAheadSize(20)
        .subscription(Pattern.compile("*")));
        

kafkaReceiver
        .receive()
        .flatMap(record -> {
          Observation receiverObservation =
              KafkaReceiverObservation.RECEIVER_OBSERVATION.start(null,
                  KafkaReceiverObservation.DefaultKafkaReceiverObservationConvention.INSTANCE,
                  () ->
                      new KafkaRecordReceiverContext(
                          record, "user.receiver", receiverOptions.bootstrapServers()),
                  observationRegistry);

          return Mono.just(record)
              .doOnNext(r -> log.info("topic: {}, key: {}, value: {}", r.topic(), r.key(), r.value()))
              .doOnTerminate(receiverObservation::stop)
              .doOnError(receiverObservation::error)
              .contextWrite(context -> context.put(ObservationThreadLocalAccessor.KEY, receiverObservation));})
        .subscribe();

Test Log

2023-12-07 13:28:53 [reactor-http-nio-4] INFO [65714a05e50e542ff15b4dfb2c7c3906,f15b4dfb2c7c3906] c.e.t.kafka.ProducerConfig - produce data >> ProducerRecord(topic=chchoi.test.2, partition=null, headers=RecordHeaders(headers = [], isReadOnly = false), key=1, value={"id":"xxx","message":"test"}, timestamp=null)
2023-12-07 13:28:53 [reactor-http-nio-4] INFO [65714a05e50e542ff15b4dfb2c7c3906,f15b4dfb2c7c3906] c.e.t.kafka.ProducerConfig - produce data >> ProducerRecord(topic=chchoi.test.2, partition=null, headers=RecordHeaders(headers = [], isReadOnly = false), key=2, value={"id":"xxx","message":"test"}, timestamp=null)
2023-12-07 13:28:53 [reactive-kafka-test-1-1] INFO [65714a05e50e542ff15b4dfb2c7c3906,71bd25628c1e61ec] c.e.t.kafka.ConsumerConfig - topic: chchoi.test.2, key: 1, value: "{\"id\":\"xxx\",\"message\":\"test\"}"
2023-12-07 13:28:53 [reactive-kafka-test-1-1] INFO [65714a05e50e542ff15b4dfb2c7c3906,d0527c836ddc587c] c.e.t.kafka.ConsumerConfig - topic: chchoi.test.2, key: 2, value: "{\"id\":\"xxx\",\"message\":\"test\"}"

Kafdrop

Zipkin

 


Conclusion

Spring Cloud Slueth가 Micrometer로 move 됨
Micrometer-tracing에서 Spring Cloud Sleuth로 migration guide를 제공
Micrometer는 Spring이랑 호환성이 매우 뛰어남
Spring Project에서 Log Tracing을 적용하기에 적절
추후 ZipKin 등 log monitoring 도입을 위한 확장성 제공
추후 JVM Metrics등 정보를 받을 수 있도록 확장성을 제공
Spring boot 3에 적용된 reference는 부족함

 

 


REFERENCE

REST

RSocket

Reactor-Kafka

 

 

반응형