Tracing not working with Spring cloud Gateway - springCloudVersion 2023.0.0

[5aab]

Description I generated sample project from spring initializer (SB 3.2.0 and springCloudVersion 2023.0.0) with io.micrometer:micrometer-tracing-bridge-brave

I created one test route as following:

spring:
  cloud:
    gateway:
      routes:
        - id: service_route
          uri: http://localhost:8081
          predicates:
            - Path=/service/**
          filters:
            - RewritePath=/service(?<segment>/?.*), $\{segment}

I wrote one interceptor as following:

@Configuration
@Slf4j
public class CustomGatewayInterceptor {

    @Bean
    public GlobalFilter customFilter() {
        return new CustomGlobalFilter();
    }

    public class CustomGlobalFilter implements GlobalFilter, Ordered {

        @Override
        public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
            log.info("custom global filter");
            return chain.filter(exchange);
        }

        @Override
        public int getOrder() {
            return 1;
        }
    }
}

invoked the random endpoint with service in the URL context path

curl http://localhost:8080/service/hello

Problem log is getting printed on console. but it doesn't have any trace or span Id

2023-12-13T17:40:42.586+05:30  INFO 25644 --- [ctor-http-nio-2] [        ] c.e.demo.rest.CustomGatewayInterceptor   : custom global filter

[bal-asha]

facing same issue after upgrading Spring boot version from 2.7.4 to 3.2.0. any suggestions?

[5aab]

+1 the same issue exists for Spring Webflux as well.

[code-uri]

could you try this?

 public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) {
        long startMillis = System.currentTimeMillis();
        return chain.filter(exchange)
                .tap(() -> new DefaultSignalListener<>() {
                    @Override
                    public void doOnSubscription() throws Throwable {
                        log.info("[{}] start.", exchange.getRequest().getPath());
                    }

                    @Override
                    public void doOnComplete() throws Throwable {
                        log.info("[{}] executed in  {} ms with status {}", exchange.getRequest().getPath(), System.currentTimeMillis() - startMillis, exchange.getResponse().getStatusCode());
                    }

                    @Override
                    public void doOnError(Throwable error) throws Throwable {
                        log.warn("[{}] errored in {} ms with status {}", exchange.getRequest().getPath(), System.currentTimeMillis() - startMillis, exchange.getResponse().getStatusCode());
                    }
                });
    }

[code-uri]

doOnComplete() can also include this.

                   @Override
                    public void doOnComplete() throws Throwable {
                        //log.info("[{}] executed in  {} ms with status {}", exchange.getRequest().getPath(), System.currentTimeMillis() - startMillis, exchange.getResponse().getStatusCode());

                        exchange.getResponse().beforeCommit(() -> {
                            log.info("[{}] committed in {} ms with status {}", exchange.getRequest().getPath(), System.currentTimeMillis() - startMillis, exchange.getResponse().getStatusCode());
                            return Mono.empty();
                        });
                    }

[libkad]

You need to call Hooks.enableAutomaticContextPropagation() from anywhere in your app e.g. main()

[verbitan]

I'm having a similar problem but with OpenTelemetry.

I have the following in my pom.xml:

...
  <parent>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-parent</artifactId>
    <version>3.2.4</version>
    <relativePath />
  </parent>
...
  <dependencyManagement>
    <dependencies>
      <dependency>
        <groupId>org.springframework.cloud</groupId>
        <artifactId>spring-cloud-dependencies</artifactId>
        <version>2023.0.1</version>
        <type>pom</type>
        <scope>import</scope>
      </dependency>
  </dependencyManagement>
...
  <dependencies>
    <dependency>
      <groupId>org.springframework.boot</groupId>
      <artifactId>spring-boot-starter-actuator</artifactId>
    </dependency>
    <dependency>
      <groupId>org.springframework.cloud</groupId>
      <artifactId>spring-cloud-starter-gateway</artifactId>
    </dependency>
    <dependency>
      <groupId>io.micrometer</groupId>
      <artifactId>micrometer-tracing-bridge-otel</artifactId>
    </dependency>
  </dependencies>
...

And the following in my application.yml:

management:
  tracing:
    enabled: true
    sampling:
      probability: 1
  otlp:
    tracing:
      endpoint: http://172.17.0.1:4318/v1/traces

logging:
  level:
    io.micrometer: TRACE

If I use curl to call an endpoint on my application I can see that being traced in the logs (both inbound and outbound connections), but nothing is output to my OTEL collector.

2024-04-05T15:32:21.650Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.o.b.Slf4JBaggageEventListener      : Got scope attached event [ScopeAttached{context: [span: SdkSpan{traceId=66101985dbf79320a3811cfabb2631cc, spanId=f77de774ffd54c38, parentSpanContext=ImmutableSpanContext{traceId=66101985dbf79320a3811cfabb2631cc, spanId=62c23879a9a69ba4, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, name=<unspecified span name>, kind=CLIENT, attributes=null, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1712331141007399429, endEpochNanos=0}] [baggage: {}]}]
2024-04-05T15:32:21.652Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.otel.bridge.Slf4JEventListener     : Got scope changed event [ScopeAttached{context: [span: SdkSpan{traceId=66101985dbf79320a3811cfabb2631cc, spanId=f77de774ffd54c38, parentSpanContext=ImmutableSpanContext{traceId=66101985dbf79320a3811cfabb2631cc, spanId=62c23879a9a69ba4, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, name=<unspecified span name>, kind=CLIENT, attributes=null, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1712331141007399429, endEpochNanos=0}] [baggage: ScopeAttached{context: [span: SdkSpan{traceId=66101985dbf79320a3811cfabb2631cc, spanId=f77de774ffd54c38, parentSpanContext=ImmutableSpanContext{traceId=66101985dbf79320a3811cfabb2631cc, spanId=62c23879a9a69ba4, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, name=<unspecified span name>, kind=CLIENT, attributes=null, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1712331141007399429, endEpochNanos=0}] [baggage: {}]}]}]
2024-04-05T15:32:21.654Z TRACE 1 --- [or-http-epoll-4] [66101985dbf79320a3811cfabb2631cc-f77de774ffd54c38] i.m.t.o.b.Slf4JBaggageEventListener      : Got scope closed event [io.micrometer.tracing.otel.bridge.EventPublishingContextWrapper$ScopeClosedEvent@6b0490d5]
2024-04-05T15:32:21.655Z TRACE 1 --- [or-http-epoll-4] [66101985dbf79320a3811cfabb2631cc-f77de774ffd54c38] i.m.t.otel.bridge.Slf4JEventListener     : Got scope closed event [io.micrometer.tracing.otel.bridge.EventPublishingContextWrapper$ScopeClosedEvent@6b0490d5]
2024-04-05T15:32:21.656Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.o.b.Slf4JBaggageEventListener      : Got scope restored event [ScopeRestored{context: [span: null] [baggage: null]}]
2024-04-05T15:32:21.657Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.otel.bridge.Slf4JEventListener     : Got scope restored event [ScopeRestored{context: [span: null] [baggage: null]}]
2024-04-05T15:32:21.672Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.o.b.Slf4JBaggageEventListener      : Got scope attached event [ScopeAttached{context: [span: SdkSpan{traceId=66101985dbf79320a3811cfabb2631cc, spanId=62c23879a9a69ba4, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, name=<unspecified span name>, kind=SERVER, attributes=null, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1712331141000186758, endEpochNanos=0}] [baggage: {}]}]
2024-04-05T15:32:21.673Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.otel.bridge.Slf4JEventListener     : Got scope changed event [ScopeAttached{context: [span: SdkSpan{traceId=66101985dbf79320a3811cfabb2631cc, spanId=62c23879a9a69ba4, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, name=<unspecified span name>, kind=SERVER, attributes=null, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1712331141000186758, endEpochNanos=0}] [baggage: ScopeAttached{context: [span: SdkSpan{traceId=66101985dbf79320a3811cfabb2631cc, spanId=62c23879a9a69ba4, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, name=<unspecified span name>, kind=SERVER, attributes=null, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1712331141000186758, endEpochNanos=0}] [baggage: {}]}]}]
2024-04-05T15:32:21.675Z TRACE 1 --- [or-http-epoll-4] [66101985dbf79320a3811cfabb2631cc-62c23879a9a69ba4] i.m.t.o.b.Slf4JBaggageEventListener      : Got scope closed event [io.micrometer.tracing.otel.bridge.EventPublishingContextWrapper$ScopeClosedEvent@2afb9d59]
2024-04-05T15:32:21.675Z TRACE 1 --- [or-http-epoll-4] [66101985dbf79320a3811cfabb2631cc-62c23879a9a69ba4] i.m.t.otel.bridge.Slf4JEventListener     : Got scope closed event [io.micrometer.tracing.otel.bridge.EventPublishingContextWrapper$ScopeClosedEvent@2afb9d59]
2024-04-05T15:32:21.676Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.o.b.Slf4JBaggageEventListener      : Got scope restored event [ScopeRestored{context: [span: null] [baggage: null]}]
2024-04-05T15:32:21.677Z TRACE 1 --- [or-http-epoll-4] [                                                 ] i.m.t.otel.bridge.Slf4JEventListener     : Got scope restored event [ScopeRestored{context: [span: null] [baggage: null]}]