Spring-cloud-sleuth: Regression in 3.0.2: tracer context lost when used with spring-data-mongodb

[beltram]

Describe the bug

Hi, I think there's a regression introduced in 3.0.2. Given an endpoint like:

import org.springframework.cloud.sleuth.Tracer

@GetMapping("chain-with-mongo")
fun chainMongo(): Mono<SpanWrapper> {
    val result = SpanWrapper()
    return tracer.spanId()
           .map { result.add(it) }
           .flatMap { repo.insert(Person(it)) }
           .flatMap { tracer.spanId() } // <-- spanId is empty here
           .map { result.add(it) }
           .map { result }
}

fun Tracer.spanId() = currentSpan()?.context()?.spanId().orEmpty().toMono()

After the reactive repository, traceId or spanId are empty.
This happens from 3.0.2. Previous versions (3.0.1 & 3.0.0) are fine.
Other versions:

• Spring Cloud 2020.0.2
• Spring Boot 2.4.4

If I were to guess where this might come from I would point at the recent optimizations in Reactor operator decoration.

Sample

You can find a reproducer here. You can sample the issue by executing ./gradlew test

[marcingrzejszczak]

I'm looking at this one now. I wonder if it's not related to mongo really cause in the controller before the mongo call flatMap does work fine. I'll need to investigate this

[marcingrzejszczak]

I'm sorry to ask this but can you please rewrite this to maven and java? I've spent 2 hours today on making gradle work with my local snapshots, then I rewrote it to Maven like below and I can't run kotlin stuff from Intellij (I have some class missing exceptions).

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns="http://maven.apache.org/POM/4.0.0"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.example</groupId>
    <artifactId>sleuth-data-reproducer</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <packaging>jar</packaging>

    <name>sleuth-data-reproducer</name>
    <description>sleuth-data-reproducer</description>

    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.4.4</version>
        <relativePath/> <!-- lookup parent from repository -->
    </parent>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-webflux</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-data-mongodb-reactive</artifactId>
        </dependency>
        <dependency>
            <groupId>io.opentracing.brave</groupId>
            <artifactId>brave-opentracing</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>*</groupId>
                    <artifactId>brave-tests</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <dependency>
            <groupId>com.fasterxml.jackson.module</groupId>
            <artifactId>jackson-module-kotlin</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-starter-sleuth</artifactId>
        </dependency>
        <dependency>
            <groupId>org.jetbrains.kotlin</groupId>
            <artifactId>kotlin-stdlib-jdk8</artifactId>
        </dependency>
        <dependency>
            <groupId>org.jetbrains.kotlin</groupId>
            <artifactId>kotlin-reflect</artifactId>
        </dependency>
        <dependency>
            <groupId>io.projectreactor.kotlin</groupId>
            <artifactId>reactor-kotlin-extensions</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.projectreactor</groupId>
            <artifactId>reactor-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>io.rest-assured</groupId>
            <artifactId>spring-web-test-client</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>de.flapdoodle.embed</groupId>
            <artifactId>de.flapdoodle.embed.mongo</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.junit.jupiter</groupId>
            <artifactId>junit-jupiter-api</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.junit.jupiter</groupId>
            <artifactId>junit-jupiter-engine</artifactId>
            <scope>test</scope>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
            <exclusions>
                <exclusion>
                    <groupId>org.junit.vintage</groupId>
                    <artifactId>junit-vintage-engine</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

        <!-- For JDK 14 -->
        <dependency>
            <groupId>javax.inject</groupId>
            <artifactId>javax.inject</artifactId>
            <version>1</version>
            <scope>test</scope>
        </dependency>
    </dependencies>

    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <java.version>11</java.version>
        <kotlin.version>1.4.32</kotlin.version>
        <spring-cloud.version>2020.0.3-SNAPSHOT</spring-cloud.version>
    </properties>

    <build>
        <sourceDirectory>${project.basedir}/src/main/kotlin</sourceDirectory>
        <testSourceDirectory>${project.basedir}/src/test/kotlin</testSourceDirectory>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
            <plugin>
                <groupId>org.jetbrains.kotlin</groupId>
                <artifactId>kotlin-maven-plugin</artifactId>
                <configuration>
                    <args>
                        <arg>-Xjsr305=strict</arg>
                    </args>
                    <compilerPlugins>
                        <plugin>spring</plugin>
                    </compilerPlugins>
                </configuration>
                <dependencies>
                    <dependency>
                        <groupId>org.jetbrains.kotlin</groupId>
                        <artifactId>kotlin-maven-allopen</artifactId>
                        <version>${kotlin.version}</version>
                    </dependency>
                </dependencies>
            </plugin>
        </plugins>
    </build>

    <dependencyManagement>
        <dependencies>
            <dependency>
                <groupId>org.springframework.cloud</groupId>
                <artifactId>spring-cloud-dependencies</artifactId>
                <version>${spring-cloud.version}</version>
                <type>pom</type>
                <scope>import</scope>
            </dependency>
        </dependencies>
    </dependencyManagement>


    <repositories>
        <repository>
            <id>spring-snapshots</id>
            <name>Spring Snapshots</name>
            <url>https://repo.spring.io/snapshot</url>
            <snapshots>
                <enabled>true</enabled>
            </snapshots>
        </repository>
        <repository>
            <id>spring-milestones</id>
            <name>Spring Milestones</name>
            <url>https://repo.spring.io/milestone</url>
            <snapshots>
                <enabled>false</enabled>
            </snapshots>
        </repository>
        <repository>
            <id>spring-releases</id>
            <name>Spring Releases</name>
            <url>https://repo.spring.io/release</url>
            <snapshots>
                <enabled>false</enabled>
            </snapshots>
        </repository>
    </repositories>
    <pluginRepositories>
        <pluginRepository>
            <id>spring-snapshots</id>
            <name>Spring Snapshots</name>
            <url>https://repo.spring.io/snapshot</url>
            <snapshots>
                <enabled>true</enabled>
            </snapshots>
        </pluginRepository>
        <pluginRepository>
            <id>spring-milestones</id>
            <name>Spring Milestones</name>
            <url>https://repo.spring.io/milestone</url>
            <snapshots>
                <enabled>false</enabled>
            </snapshots>
        </pluginRepository>
        <pluginRepository>
            <id>spring-plugin-snapshots</id>
            <name>Spring Snapshots</name>
            <url>https://repo.spring.io/snapshot</url>
            <snapshots>
                <enabled>true</enabled>
            </snapshots>
        </pluginRepository>
        <pluginRepository>
            <id>spring-plugin-milestones</id>
            <name>Spring Milestones</name>
            <url>https://repo.spring.io/release</url>
            <snapshots>
                <enabled>false</enabled>
            </snapshots>
        </pluginRepository>
    </pluginRepositories>

</project>

[beltram]

Sure I'll try to do it

[beltram]

I have migrated the reproducer to java + maven. You can find it on the java-maven branch.
Hope this'll help

[marcingrzejszczak]

Hi! The fact that it used to work had to be accidental. We have done a big analysis with @mp911de and we need to talk to Mongo folks about providing hook points to allow the reactive context propagation. Until now as a workaround you have to IMO use the WebFluxSleuthOperators and the like:

@RestController
@RequestMapping("/spans")
public class TestController {

    private static final Logger log = LoggerFactory.getLogger(TestController.class);

    private final Tracer tracer;
    private final CurrentTraceContext currentTraceContext;
    private final PersonRepository repo;

    public TestController(Tracer tracer, CurrentTraceContext currentTraceContext, PersonRepository repo) {
        this.tracer = tracer;
        this.currentTraceContext = currentTraceContext;
        this.repo = repo;
    }

    @GetMapping("chain-with-mongo")
    Mono<SpanWrapper> chainMongo(ServerWebExchange serverWebExchange) {
        SpanWrapper result = new SpanWrapper().setSpans(new ArrayList<>());
        return spanId(tracer)
                .map(result::add)
                .doOnNext(s -> log.info("ASD1: [{}]", s))
                .flatMap(s -> repo.insert(new Person(s)))
// log stuff with tracing context
                .doOnNext(person -> WebFluxSleuthOperators.withSpanInScope(tracer, currentTraceContext, serverWebExchange, () -> log.info("ASD 2")))
// retrieve the root span and put it in thread local (the scope should be cleared by the TraceFilter later on)
                .doOnNext(person -> tracer.withSpan(serverWebExchange.getAttribute(Span.class.getName())))
                .flatMap(p -> spanId(tracer)) // <-- spanId is empty here
                .map(result::add)
                .map(it -> result);
    }
}

I'll mark this as in progress cause we can't do much about it ATM.

[marcingrzejszczak]

BTW - if you bump mongodb to version <mongodb.version>4.2.3</mongodb.version> then things work out of the box without any changes! That's beacuse Mongo started using project reactor under the hood. I can close this issue then since the recommended approach is to use version 4.2 of the mongodb driver