Integrating manual instrumentation with Vert.x SQL Client auto-instrumentation

[dozsa]

Hi,

I need to do manual instrumentation for messages received over NATS, which is not supported by the agent. Also we use Vert.x in our application. The agent provides Vert.x SQL Client auto-instrumentation. But we cannot seem to correlate our spans with the sql spans. They do not inherit. The main problem is Vert.x's threading model is not thread per request, so thread-local context storing does not work (the same context will bleed to other requests). So, we are not sure how to make a span current in a Vert.x application. Using span.makeCurrent() will cause the same span to be set for all requests processed on that verticle thread. Reading through the agent code for Vert.x SQL Client, I noticed it stores the OTEL context it in the Vert.x context under the "otel.context" key. I tried to do that in our manual instrumentation too, but still the sql trace does not use our span as parent. Any guidance on how to integrate Integrating manual instrumentation with Vert.x SQL Client auto-instrumentation?

Thanks,
Adrian

[laurit]

Provide a minimal application that shows what you are attempting to do.

[dozsa]

It's just an app that receives a message from NATS and uses Vert.x for it's processing, including Vert.x Postgres Client. The agent intrumentation takes care of the Vert.x Postgres Client. But because NATS is not on the supported list, we need to do manual instrumentation for incoming messages (as described in https://opentelemetry.io/docs/instrumentation/java/manual/). But we cannot used the usual static calls in the OpenTelemetry SDK, like span makeCurrent or get current, because all those use ThreadLocal internally, which won't work for Vert.x that processes multiple requests in the same context. I guess we need to store the OTEL context in the Vert.x request context, and I saw such logic in the agent Vert.x Postgres Client. But did not manage to get that logic to find our OTEL context to use it as parent.

[laurit]

Without a sample app to try things out on it is hard to tell what exactly goes wrong and how it could be fixed. It could be something as simple as forgetting to close the Scope returned from makeCurrent or something completely different. General strategy for complex threading is to activate the scope (call makeCurrent) around the calls where you need access to the current trace (e.g. where you make the sql call) and otherwise pass otel context along in some framework specific context like vetrt.x context that the framework propagates itself.

[dozsa]

The code is just the sample code from https://opentelemetry.io/docs/instrumentation/java/manual/. But span.makeCurrent() is not safe with Vert.x as it will activate that span for ALL requests being processed by that verticle.

As for "pass otel context along in some framework specific context like vetrt.x context", exactly what I am trying to ask here. What are those assumptions built into the otel java agent that handles the Vert.x SQL Client instrumentation? An user needs to know that in order to align any manual intrumentation with that. But I do not see that documented anywhere here.

[trask]

The code is just the sample code from https://opentelemetry.io/docs/instrumentation/java/manual/. But span.makeCurrent() is not safe with Vert.x as it will activate that span for ALL requests being processed by that verticle.

.makeCurrent() should only be used inside try/finally to ensure it's closed and doesn't leak to all requests (this is a problem across all frameworks not just Vert.x)

[dozsa]

Understood. But how do I pass the current OTEL context/span to the agent instrumented code for Vert.x SQL Client? That is my question. As I cannot use the standard OTEL advice on how to do manual instrumentation.

[laurit]

Please provide a minimal sample application that illustrates what you are attempting to do. We need to have a better understanding of the challenges you are facing to give you advice.

[dozsa]

Ok, I think I found my problem. Seems Vert.x SQL Client instrumentation does not work well with transactions. If I only do a query then the query span is tied to my manual instrumentation span. If I run a query in a transaction the query span does not use my parent span anymore. Simplified example below.

public class NatsVertxOtelTestVerticle extends AbstractVerticle {

  private Connection natsCon;
  private Pool sqlPool;
  private Tracer tracer;

  public NatsVertxOtelTestVerticle(Pool sqlPool) {
    this.sqlPool = sqlPool;
    tracer = GlobalOpenTelemetry.get().getTracer("test-tracer", "1.0.0");
  }

  public void start() throws Exception {
    natsCon = Nats.connect("nats://localhost:4222");

    Dispatcher d = natsCon.createDispatcher((msg) -> {
      context.runOnContext(Void -> handleMessage(msg));
    });
    d.subscribe("test");
  }

  private void handleMessage(Message message) {
    System.out.println("Received " + new String(message.getData()));
    Span span = tracer.spanBuilder("test-span").startSpan();
    try (Scope ss = span.makeCurrent()) {
      sqlPool
          .withTransaction(conn -> conn.preparedQuery("SELECT 1").execute().compose(rows -> {
            natsCon.publish(message.getReplyTo(), message.getData());
            span.end();
            return Future.succeededFuture();
          }));
//      sqlPool.preparedQuery("SELECT 1").execute().compose(rows -> {
//        natsCon.publish(message.getReplyTo(), message.getData());
//        span.end();
//        return Future.succeededFuture();
//      });
    }
  }

  private static Pool createSqlPool(Vertx vertx) {
    PgConnectOptions connectOptions = new PgConnectOptions().setPort(5432).setHost("localhost")
        .setDatabase("db").setUser("user").setPassword("password");
    PoolOptions poolOptions = new PoolOptions().setMaxSize(1).setShared(true);
    Pool sqlPool = PgPool.pool(vertx, connectOptions, poolOptions);
    sqlPool.preparedQuery("SELECT 1").execute();
    return sqlPool;

  }

  public static void main(String[] args) {
    Vertx vertx = Vertx.vertx();
    NatsVertxOtelTestVerticle verticle = new NatsVertxOtelTestVerticle(createSqlPool(vertx));

    vertx.deployVerticle(verticle);
    System.out.println("Started.");
  }
}

[laurit]

Hopefully fixed with #9462

[dozsa]

Thank you for the quick fix. Unfortunately I see it did not make it into the just released 1.30 version.

[laurit]

You are correct, it is available in the snapshot build https://oss.sonatype.org/content/repositories/snapshots/io/opentelemetry/javaagent/opentelemetry-javaagent/1.31.0-SNAPSHOT/

[dozsa]

Tested the snapshot and works as expected. Thank you again.

[dozsa]

I did the same test with a Vert.x HttpServer and without any manual instrumentation. Meaning all features supported by the OTEL agent. And same behavior. When I only use a query the query span ties to the http span. When I add a transaction the two spans are not tied anymore, and presented as independent spans. Seems SQL transactions break the instrumentation logic.