feat: Added more routes to test more behaviors

Author: Sylvain Becuwe

README.md

@@ -9,7 +9,37 @@ This project is an attempt of using [Micrometer Tracing](https://github.com/micr
 - [Zipkin Brave](https://github.com/openzipkin/brave)
 - [Zalando Logbook](https://github.com/zalando/logbook)
 
-This might also be useful for those migrating *Spring Boot 2 & Spring Sleuth* to *Spring Boot 3* which has breaking changes about tracing.
+This might also be useful for those migrating *Spring Boot 2 & Spring Sleuth* to *Spring Boot 3* which has breaking changes about tracing.<br/>
+
+The aim is to manage to have standard baggage (traceId and spanId) and custom baggage (myBaggageFilter and myBaggageController) logged in every single log of the application.
+
+Below are a list of issues related to this mechanism not working properly: 
+- https://github.com/openzipkin/brave/issues/1376
+- https://github.com/zalando/logbook/issues/1513
+- https://github.com/zalando/logbook/issues/1513
+- https://github.com/micrometer-metrics/tracing/issues/174
 
 # How to test the application
-Run `./gradlew bootRun` then call the local server: `curl --location 'http://localhost:8080/test' --header 'Authorization: Basic dXNlcjp1c2Vy'`
+Run `./gradlew bootRun` then call the local server depending on the behavior you want to test:
+## Simple
+This will test the following behavior:
+1) Write a log in the controller
+2) Make a **webClient** call
+
+`curl --location 'http://localhost:8080/simple' --header 'Authorization: Basic dXNlcjp1c2Vy'`
+
+## Suspend
+This will test the following behavior:
+1) Simulate some delay inside the coroutine so that kotlin suspends the function then resume it
+2) Write a log in the controller
+3) Make a **webClient** call
+
+`curl --location 'http://localhost:8080/suspend' --header 'Authorization: Basic dXNlcjp1c2Vy'`
+
+## Coroutine
+This will test the following behavior:
+1) Start a new coroutine
+2) Write a log in the controller
+3) Make a **webClient** call
+
+`curl --location 'http://localhost:8080/coroutine' --header 'Authorization: Basic dXNlcjp1c2Vy'`

app/build.gradle.kts

@@ -2,7 +2,7 @@ import org.jetbrains.kotlin.gradle.tasks.KotlinCompile
 import org.springframework.boot.gradle.plugin.SpringBootPlugin.BOM_COORDINATES
 
 plugins {
-    id("org.springframework.boot") version "3.1.3"
+    id("org.springframework.boot") version "3.1.4"
     kotlin("jvm") version "1.9.10"
     kotlin("plugin.spring") version "1.9.10"
 }
@@ -27,12 +27,14 @@ dependencies {
     runtimeOnly("org.springframework.boot:spring-boot-starter-actuator")
     implementation("org.jetbrains.kotlinx:kotlinx-coroutines-reactor:1.7.3")
     implementation("org.jetbrains.kotlin:kotlin-reflect")
+    implementation("io.micrometer:micrometer-core")
     implementation("io.micrometer:micrometer-tracing-bridge-brave") {
         exclude(group = "io.zipkin.reporter2", module = "zipkin-reporter-brave")
     }
     implementation("io.github.microutils:kotlin-logging:3.0.5")
     implementation("org.zalando:logbook-spring-boot-starter")
     implementation("org.zalando:logbook-spring-boot-webflux-autoconfigure")
+    implementation("org.jetbrains.kotlinx:kotlinx-coroutines-slf4j:1.7.3")
     compileOnly("org.springframework.boot:spring-boot-devtools")
     testImplementation("org.springframework.boot:spring-boot-starter-test")
 }

app/src/main/kotlin/com/grassehh/app/configuration/SecurityConfiguration.kt

@@ -1,6 +1,7 @@
 package com.grassehh.app.configuration
 
 import com.grassehh.app.filter.AppWebFilter
+import io.micrometer.observation.ObservationRegistry
 import io.micrometer.tracing.Tracer
 import org.springframework.context.annotation.Bean
 import org.springframework.context.annotation.Configuration
@@ -28,14 +29,15 @@ class SecurityConfiguration {
     )
 
     @Bean
-    fun springSecurityFilterChain(http: ServerHttpSecurity, tracer: Tracer) =
+    fun springSecurityFilterChain(http: ServerHttpSecurity, tracer: Tracer, observationRegistry: ObservationRegistry) =
         http
             .authorizeExchange { exchanges: AuthorizeExchangeSpec ->
                 exchanges
                     .anyExchange().authenticated()
             }
             .httpBasic(withDefaults())
             .formLogin(withDefaults())
+//            .addFilterBefore(CoroutineWebFilter(observationRegistry), FIRST)
             .addFilterBefore(AppWebFilter(tracer), HTTP_BASIC)
             .build()
 }

app/src/main/kotlin/com/grassehh/app/configuration/TracingConfiguration.kt

@@ -1,9 +1,11 @@
 package com.grassehh.app.configuration
 
+import io.micrometer.context.ContextRegistry
 import io.micrometer.context.ContextSnapshotFactory
 import io.micrometer.observation.ObservationRegistry
 import io.micrometer.observation.contextpropagation.ObservationThreadLocalAccessor
 import io.micrometer.tracing.Tracer
+import io.micrometer.tracing.contextpropagation.ObservationAwareSpanThreadLocalAccessor
 import io.netty.channel.ChannelDuplexHandler
 import io.netty.channel.ChannelHandlerContext
 import io.netty.channel.ChannelPromise
@@ -21,7 +23,7 @@ class TracingConfiguration(private val observationRegistry: ObservationRegistry,
     @PostConstruct
     fun postConstruct() {
         Hooks.enableAutomaticContextPropagation()
-//        ContextRegistry.getInstance().registerThreadLocalAccessor(ObservationAwareSpanThreadLocalAccessor(tracer));
+        ContextRegistry.getInstance().registerThreadLocalAccessor(ObservationAwareSpanThreadLocalAccessor(tracer));
         ObservationThreadLocalAccessor.getInstance().observationRegistry = observationRegistry
         Metrics.observationRegistry(observationRegistry)
     }

app/src/main/kotlin/com/grassehh/app/controller/SampleController.kt

@@ -1,31 +1,65 @@
 package com.grassehh.app.controller
 
+import io.micrometer.core.instrument.kotlin.asContextElement
+import io.micrometer.observation.ObservationRegistry
 import io.micrometer.tracing.Tracer
+import kotlinx.coroutines.*
 import mu.KotlinLogging.logger
 import org.springframework.http.HttpStatus.OK
 import org.springframework.security.access.prepost.PreAuthorize
 import org.springframework.web.bind.annotation.GetMapping
-import org.springframework.web.bind.annotation.RequestMapping
 import org.springframework.web.bind.annotation.ResponseStatus
 import org.springframework.web.bind.annotation.RestController
 import org.springframework.web.reactive.function.client.WebClient
 import org.springframework.web.reactive.function.client.awaitExchange
 import java.util.*
 
 @RestController
-@RequestMapping("/test")
-class SampleController(private val webClient: WebClient, private val tracer: Tracer) {
+class SampleController(
+    private val webClient: WebClient,
+    private val tracer: Tracer,
+    private val observationRegistry: ObservationRegistry
+) {
     companion object {
         private val logger = logger {}
     }
 
-    @GetMapping
+    @GetMapping("simple")
     @ResponseStatus(OK)
     @PreAuthorize("hasRole('USER')")
-    suspend fun test() {
+    suspend fun simple() {
         tracer.createBaggageInScope("myBaggageController", UUID.randomUUID().toString())
-        logger.debug { "Log from inside the controller. This should contain the baggage called myBaggageController" }
-        webClient.get().uri { it.scheme("https").host("google.com").build() }
+        logger.debug { "CONTROLLER LOG" }
+        webClient.get()
+            .uri("https://www.google.fr")
             .awaitExchange { }
     }
-}
+
+    @GetMapping("suspend")
+    @ResponseStatus(OK)
+    @PreAuthorize("hasRole('USER')")
+    suspend fun suspend() {
+        tracer.createBaggageInScope("myBaggageController", UUID.randomUUID().toString())
+        withContext(observationRegistry.asContextElement()) {
+            delay(500)
+            logger.debug { "CONTROLLER LOG INSIDE withContext()" }
+        }
+        logger.debug { "CONTROLLER LOG OUTSIDE withContext()" }
+        webClient.get()
+            .uri("https://www.google.fr")
+            .awaitExchange { }
+    }
+
+    @GetMapping("coroutine")
+    @ResponseStatus(OK)
+    @PreAuthorize("hasRole('USER')")
+    suspend fun coroutine() {
+        CoroutineScope(SupervisorJob()).launch(observationRegistry.asContextElement()) {
+            tracer.createBaggageInScope("myBaggageController", UUID.randomUUID().toString())
+            logger.debug { "CONTROLLER LOG" }
+            webClient.get()
+                .uri("https://www.google.fr")
+                .awaitExchange { }
+        }
+    }
+}

app/src/main/kotlin/com/grassehh/app/filter/CoroutineWebFilter.kt

@@ -0,0 +1,17 @@
+package com.grassehh.app.filter
+
+import io.micrometer.core.instrument.kotlin.asContextElement
+import io.micrometer.observation.ObservationRegistry
+import kotlinx.coroutines.withContext
+import org.springframework.web.server.CoWebFilter
+import org.springframework.web.server.CoWebFilterChain
+import org.springframework.web.server.ServerWebExchange
+
+
+class CoroutineWebFilter(private val observationRegistry: ObservationRegistry) : CoWebFilter() {
+    override suspend fun filter(exchange: ServerWebExchange, chain: CoWebFilterChain) {
+        withContext(observationRegistry.asContextElement()) {
+            chain.filter(exchange)
+        }
+    }
+}

app/src/main/resources/application.yaml

@@ -17,7 +17,7 @@ logging:
     com.grassehh: debug
     org.zalando.logbook: trace
   pattern:
-    console: "MDC Context: [%mdc] - %clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd'T'HH:mm:ss.SSSXXX}}){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}"
+    console: "MDC:[%mdc] %clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd'T'HH:mm:ss.SSSXXX}}){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}"
 
 logbook:
   strategy: status-at-least