Using tracing in a multithreaded Java server

Question

I am having trouble with using tracing in my multithreaded application.

background:

In my SpringBoot application I have a function "service" which calls another function "innerService", and I want to trace each function with its own span. I am implementing OpenTracing with Jaeger in the following way:

AppConfig.java:

@Bean
public static JaegerTracer getTracer() {
    io.jaegertracing.Configuration.SamplerConfiguration samplerConfig = io.jaegertracing.Configuration.SamplerConfiguration.fromEnv().withType("const").withParam(1);
    io.jaegertracing.Configuration.ReporterConfiguration reporterConfig = io.jaegertracing.Configuration.ReporterConfiguration.fromEnv().withLogSpans(true);
    io.jaegertracing.Configuration config = new io.jaegertracing.Configuration("myService").withSampler(samplerConfig).withReporter(reporterConfig);
    return config.getTracer();
}

I then use it in one of my apps' services:

@GrpcService
public class ServiceA extends ServiceAGrpc.ServiceAImplBase {
     private final Tracer tracer;

     @Autowired
     public ServiceA(Tracer tracer) {
         this.tracer = tracer;
}

@Override
public void service(Request request, StreamObserver<ResultGrpc> responseObserver) {
    Span span = startSpanInScope(this.tracer, "service");
    ...
    innerService();
    ...
    span.finish();
}

the function that returns a span:

public static Span startSpanInScope(Tracer tracer, String spanName) {
    if (tracer == null) {
        return null;
    }
    Span span = tracer.buildSpan(spanName).start();
    Scope scope = tracer.scopeManager().activate(span);
    return span;
}

When sending a single request to the service, everything seems fine and the spans appear one inside the other:

However, when I send multiple requests at once, using multiple threads, the spans interfere one another:

I guess it happens because whenever a span starts it becomes the child of the currently active span, even if this span is from another thread. I don't understand why, since I read that the ScopeManager is by default a ThreadLocal object.

Can anyone suggest a solution to this? I want a separate trace for each thread, which will show the spans for "service" and "innerService" as its child.

You should use `try { ... } finally { }` to ensure that the scope that started are then closed. — Gray, Aug 24 '21 at 18:59

score 0 · Answer 1 · answered Aug 23 '21 at 12:00

You have to close your scope too (scope.close()) and not only the span which might be the reason why your trace continuous. Closing the scope automatically finishes the span. Furthermore, you can directly create a span as an active one in a single command: Scope scope = tracer.buildSpan(spanName).startActive(true). This way, you don't have to manually call the scopeManager.

Due to the fact that the Scope class implements the AutoClosableinterface, you can use try-resource blocks in order to prevent missing a scope from closing:

try (Scope scope = this.tracer.buildSpan("service").startActive(true)) {
    innerService();
}

Thank you. I see that the startActive method is deprecated in the latest JaegerTracer. Is the another way to achieve this behavior? — peleg, Aug 23 '21 at 14:32

Using tracing in a multithreaded Java server

1 Answers1