java - Programmatic tracing with opentelemetry and virtual threads - Stack Overflow

admin管理员组

文章数量:1313788

It's normal, for example, that my request first arrives at a OncePerRequestFilter, then goes to a RequestMDCInterceptor that captures the traceId and spanId. After that, it passes through several calls in the filter, such as saving the idempotency key in memory. In all logs, the traceId remains the same, but the spanId changes. Is this the correct behavior?

File RequestMdcInterceptor.java

@Component
public class RequestMdcInterceptor implements HandlerInterceptor {

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

    private final BuildProperties buildProperties;

    public RequestMdcInterceptor(final BuildProperties buildProperties) {
        this.buildProperties = Objects.requireNonNull(buildProperties);
    }

    @Override
    public boolean preHandle(
            final HttpServletRequest request,
            @NonNull final HttpServletResponse response,
            @NonNull final Object handler
    ) {
        final var aCurrentSpan = Span.fromContext(Context.current());

        MDC.put("appName", buildProperties.getName());
        MDC.put("appVersion", buildProperties.getVersion());
        MDC.put("appBuildDate", buildProperties.getTime().toString());
        MDC.put("traceId", aCurrentSpan.getSpanContext().isValid() ? aCurrentSpan.getSpanContext().getTraceId() : " ");
        MDC.put("spanId", aCurrentSpan.getSpanContext().isValid() ? aCurrentSpan.getSpanContext().getSpanId() : " ");
        MDC.put("host", request.getHeader("Host"));
        MDC.put("requestMethod", request.getMethod());
        MDC.put("userAgent", request.getHeader("User-Agent"));
        MDC.put("requestUri", request.getRequestURI());
        MDC.put("clientIp", request.getRemoteAddr());
        if (request.getHeader("b3") != null) {
            MDC.put("b3", request.getHeader("b3"));
        } else {
            MDC.put("b3", " ");
        }

        log.debug("Request: {}", MDC.getCopyOfContextMap());

        return true;
    }
}

File ObservationHelper.java

public class ObservationHelper {
    private static final Logger log = LoggerFactory.getLogger(ObservationHelper.class);

    private final OpenTelemetry openTelemetry;

    public ObservationHelper(OpenTelemetry openTelemetry) {
        this.openTelemetry = openTelemetry;
    }

    public <T> void withObservation(String tracerName, String spanName, Function<Span, T> block) {
        Tracer tracer = openTelemetry.getTracer(tracerName);
        Span span = tracer.spanBuilder(spanName)
                .setParent(Context.current()).startSpan();

        try (Scope scope = span.makeCurrent()) {
            log.debug("Starting span: {} {}", spanName, span.getSpanContext());
            block.apply(span);
        } catch (Exception e) {
            span.recordException(e);
            throw e;
        } finally {
            span.end();
        }
    }
 }

File InMemoryIdempotencyKeyGateway.java

@Override
    public void save(final String idempotencyKey, final long ttl, final TimeUnit timeUnit) {
        this.observationHelper.withObservation(
                "in_memory_idempotency_key_save",
                "idempotency_key_initial_save",
                (span) -> {
                    span.setAttribute("idempotency", idempotencyKey);
                    span.setAttribute("ttl", String.valueOf(ttl));
                    span.setAttribute("time_unit", timeUnit.name());

                    log.debug("Saving idempotency key: {}", idempotencyKey);
                    this.idempotencyKeyMap.put(idempotencyKey, Json.writeValueAsString(
                            new IdempotencyKeyDTO(0, "", Map.of())
                    ));
                    log.info("Idempotency key saved: {}", idempotencyKey);
                    return idempotencyKey;
                }
        );
    }

    @Override
    public void save(final String idempotencyKey, final IdempotencyKeyInput body, final long ttl, final TimeUnit timeUnit) {
        this.observationHelper.withObservation(
                "in_memory_idempotency_key_save",
                "idempotency_key_save",
                (span) -> {
                    span.setAttribute("idempotency", idempotencyKey);
                    span.setAttribute("ttl", String.valueOf(ttl));
                    span.setAttribute("time_unit", timeUnit.name());

                    log.debug("Saving idempotency key with body: {}", idempotencyKey);
                    this.idempotencyKeyMap.put(idempotencyKey, Json.writeValueAsString(body));
                    log.info("Idempotency key saved with body: {}", idempotencyKey);
                    return idempotencyKey;
                }
        );
    }

Example for logs

17:30:55.843-0300 [XNIO-1 task-2] [d3ce3145df80dc59fe55baa48042e995] [094c62c947f7e5c7] DEBUG c.k.t.i.i.IdempotencyKeyFilter - Processing the idempotency key filter
17:30:55.845-0300 [XNIO-1 task-2] [d3ce3145df80dc59fe55baa48042e995] [6d98d056f883688b] INFO  c.k.t.i.utils.ObservationHelper - Starting span: process_idempotency_key_filter ImmutableSpanContext{traceId=d3ce3145df80dc59fe55baa48042e995, spanId=6d98d056f883688b, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}
17:30:55.849-0300 [XNIO-1 task-2] [d3ce3145df80dc59fe55baa48042e995] [6d98d056f883688b] DEBUG c.k.t.i.i.IdempotencyKeyFilter - Idempotency key not found, saving before processing the request [key:123e4567-e89b-12d3-a456-426614174000] [ttl:1] [timeUnit:HOURS]
17:30:55.851-0300 [XNIO-1 task-2] [d3ce3145df80dc59fe55baa48042e995] [4bd2a564148311c4] INFO  c.k.t.i.utils.ObservationHelper - Starting span: idempotency_key_initial_save ImmutableSpanContext{traceId=d3ce3145df80dc59fe55baa48042e995, spanId=4bd2a564148311c4, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}
17:30:55.851-0300 [XNIO-1 task-2] [d3ce3145df80dc59fe55baa48042e995] [4bd2a564148311c4] DEBUG c.k.t.i.i.g.InMemoryIdempotencyKeyGateway - Saving idempotency key: 123e4567-e89b-12d3-a456-426614174000
17:30:55.890-0300 [XNIO-1 task-2] [d3ce3145df80dc59fe55baa48042e995] [4bd2a564148311c4] INFO  c.k.t.i.i.g.InMemoryIdempotencyKeyGateway - Idempotency key saved: 123e4567-e89b-12d3-a456-426614174000
17:30:55.898-0300 [XNIO-1 task-2] [d3ce3145df80dc59fe55baa48042e995] [6d98d056f883688b] DEBUG c.k.t.i.c.i.RequestMdcInterceptor - Request: {traceId=d3ce3145df80dc59fe55baa48042e995, spanId=6d98d056f883688b, b3= , appVersion=0.1.0, appBuildDate=2025-01-30T20:30:51.830Z, appName=java-template, requestMethod=POST, clientIp=127.0.0.1, host=localhost:8081, userAgent=curl/7.81.0, requestUri=/api/hello/rest}

本文标签： javaProgrammatic tracing with opentelemetry and virtual threadsStack Overflow