Tracing, part 2


#1

Warning: bit long, perhaps cannot be answered here. I’m mostly posting in the hopes someone takes a quick look and tells me if I did something wrong. Link to project below.

A little while, back, I made a thread: Can't get opentracing to work on sample project

Which eventually lead to me find the correct way to initialize a Tracer.

Since then, I’ve been experimenting a bit and have hit a block when it comes to database transactions.

Instead of adding tracing to absolutely all code paths, in order to put logs on queries, their parameters, and their timings, I found this: https://github.com/opentracing-contrib/java-jdbc

OpenTracing instrumentation for JDBC.

While this does indeed log all queries, it doesn’t link them to the parent tracer, since it uses the GlobalTracer. Which can be defined only once for the running code. Once you set the GlobalTracer’s tracer, you can’t do that again. The code prevents it.

I made a demo project here: https://github.com/KoenDG/play-java-ebean-example/tree/tracingAttempt

On a branch called tracingAttempt.

Diff with original can be seen here: https://github.com/KoenDG/play-java-ebean-example/compare/2.6.x...KoenDG:tracingAttempt

PR here, in case someone wants to leave comments: https://github.com/KoenDG/play-java-ebean-example/pull/1

So I run my code, I run the jaeger docker image like this: docker run -p5775:5775/udp -p6831:6831/udp -p6832:6832/udp -p16686:16686 -p14268:14268 jaegertracing/all-in-one:latest

No daemon so I can do a clean launch quick while testing the code.

I got to localhost:9000 and refresh a bunch of times to create traces.

And the result I’m getting is this: https://imgur.com/a/iQ4eA2C

So, each call is getting its own trace, which is what I would expect: a contextually separated, clickable instance in the jaeger overview, per call. Which basically tells me “this call did the following”.

I tried putting everything on globaltracer and then you run into the problem of calls not being separated. Everything just ends up in 1 big trace, which isn’t usable in a multithreaded environment, processing potentially the same call several times, but from different callers providing different details.

While the jdbc traces are there, you can’t tell what they’re a child of. As the various database calls are all on the same indentation/level of the view.

So, if I want to achieve a single trace for each call the HTTP server gets, with the database queries in there, what am I doing wrong?

I also asked this in an existing issue on the project’s issue tracker: https://github.com/opentracing-contrib/java-jdbc/issues/6


Clarification on handling of HTTP calls, multi-threading and dependency injection
#2

After some more testing, I got the tracing to work with GlobalTracer, but the separate execution context for database calls had to be factored out.

Since the scope of the call is ThreadLocal, going to a different thread for the execution of the database query makes it so that it cannot be linked to the thread that started it all(I think).

EDIT: This looks like it handles that scenario: https://github.com/opentracing/opentracing-java#deferring-asynchronous-work

Will look at it later.