spring-cloud / spring-cloud-sleuth

Distributed tracing for spring cloud
https://spring.io/projects/spring-cloud-sleuth
Apache License 2.0
1.76k stars 782 forks source link

Sleuth and OpenTelemetry exporter doesn't work #2151

Closed hugree closed 2 years ago

hugree commented 2 years ago

Describe the bug I have two microservices in Spring Boot with nearly identical configuration as far as tracing goes but only one of them actually works (sends traces)

Here's a part of the dependence tree for spring

[INFO] |  +- org.springframework:spring-web:jar:5.3.18:compile
[INFO] |  |  \- org.springframework:spring-beans:jar:5.3.18:compile
[INFO] |  \- org.springframework.boot:spring-boot-starter-validation:jar:2.6.6:compile
[INFO] +- io.melements.integrator:spring-cache:jar:1.0.0-SNAPSHOT:compile
[INFO] |  \- org.springframework.boot:spring-boot-starter:jar:2.6.6:compile
[INFO] |     +- org.springframework.boot:spring-boot-starter-logging:jar:2.6.6:compile
[INFO] |  +- org.springframework.boot:spring-boot:jar:2.6.6:compile
[INFO] |  |  \- org.springframework:spring-context:jar:5.3.18:compile
[INFO] |  +- org.springframework.boot:spring-boot-autoconfigure:jar:2.6.6:compile
[INFO] +- org.springframework.boot:spring-boot-starter-web:jar:2.6.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-json:jar:2.6.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-tomcat:jar:2.6.6:compile
[INFO] |  \- org.springframework:spring-webmvc:jar:5.3.18:compile
[INFO] |     +- org.springframework:spring-aop:jar:5.3.18:compile
[INFO] |     \- org.springframework:spring-expression:jar:5.3.18:compile
[INFO] +- org.springframework.boot:spring-boot-starter-data-jpa:jar:2.6.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-aop:jar:2.6.6:compile
[INFO] |  +- org.springframework.boot:spring-boot-starter-jdbc:jar:2.6.6:compile
[INFO] |  |  \- org.springframework:spring-jdbc:jar:5.3.18:compile
[INFO] |  +- org.springframework.data:spring-data-jpa:jar:2.6.3:compile
[INFO] |  |  +- org.springframework.data:spring-data-commons:jar:2.6.3:compile
[INFO] |  |  +- org.springframework:spring-orm:jar:5.3.18:compile
[INFO] |  |  \- org.springframework:spring-tx:jar:5.3.18:compile
[INFO] |  \- org.springframework:spring-aspects:jar:5.3.18:compile
[INFO] +- org.springframework.boot:spring-boot-starter-cache:jar:2.6.6:compile
[INFO] |  \- org.springframework:spring-context-support:jar:5.3.18:compile
[INFO] +- org.springframework.cloud:spring-cloud-kubernetes-fabric8-config:jar:2.1.1:compile
[INFO] |  +- org.springframework.cloud:spring-cloud-kubernetes-fabric8-autoconfig:jar:2.1.1:compile
[INFO] |  |  +- org.springframework.cloud:spring-cloud-kubernetes-commons:jar:2.1.1:compile
[INFO] |  |  \- org.springframework.cloud:spring-cloud-context:jar:3.1.1:compile
[INFO] |  +- org.springframework.cloud:spring-cloud-starter:jar:3.1.1:compile
[INFO] |  \- org.springframework.security:spring-security-rsa:jar:1.0.10.RELEASE:compile
[INFO] +- org.springframework.cloud:spring-cloud-starter-sleuth:jar:3.1.1:compile
[INFO] |  \- org.springframework.cloud:spring-cloud-sleuth-autoconfigure:jar:3.1.1:compile
[INFO] +- org.springframework.cloud:spring-cloud-sleuth-otel-autoconfigure:jar:1.1.0-M5:compile
[INFO] |  +- org.springframework.cloud:spring-cloud-sleuth-instrumentation:jar:3.1.1:compile
[INFO] |  |  \- org.springframework.cloud:spring-cloud-sleuth-api:jar:3.1.1:compile
[INFO] |  +- org.springframework.cloud:spring-cloud-sleuth-otel:jar:1.1.0-M5:compile
[INFO] |  |  +- org.springframework:spring-jcl:jar:5.3.18:compile
[INFO] +- com.github.gavlyukovskiy:p6spy-spring-boot-starter:jar:1.8.0:compile
[INFO] |  +- com.github.gavlyukovskiy:datasource-decorator-spring-boot-autoconfigure:jar:1.8.0:compile
[INFO] +- org.springframework.cloud:spring-cloud-starter-bootstrap:jar:3.1.1:compile
[INFO] +- org.springframework.cloud:spring-cloud-commons:jar:3.1.1:compile
[INFO] |  \- org.springframework.security:spring-security-crypto:jar:5.6.2:compile
[INFO] +- com.hazelcast:hazelcast-spring:jar:5.0.2:compile
[INFO] |  +- org.springframework:spring-jms:jar:5.3.18:compile
[INFO] |  |  \- org.springframework:spring-messaging:jar:5.3.18:compile
[INFO] +- org.springframework.boot:spring-boot-starter-actuator:jar:2.6.6:compile
[INFO] |  \- org.springframework.boot:spring-boot-actuator-autoconfigure:jar:2.6.6:compile
[INFO] |     \- org.springframework.boot:spring-boot-actuator:jar:2.6.6:compile
[INFO] +- org.springframework.boot:spring-boot-devtools:jar:2.6.6:runtime
[INFO] +- org.springframework.retry:spring-retry:jar:1.3.2:compile
[INFO] +- org.springframework.boot:spring-boot-starter-test:jar:2.6.6:test
[INFO] |  +- org.springframework.boot:spring-boot-test:jar:2.6.6:test
[INFO] |  +- org.springframework.boot:spring-boot-test-autoconfigure:jar:2.6.6:test
[INFO] |  +- org.springframework:spring-core:jar:5.3.18:compile
[INFO] |  +- org.springframework:spring-test:jar:5.3.18:test
[INFO] +- org.spockframework:spock-spring:jar:2.1-groovy-3.0:test

here's the same for opentrelemetry

[INFO] |  |  \- io.opentelemetry:opentelemetry-extension-aws:jar:1.12.0:compile
[INFO] |  +- io.opentelemetry:opentelemetry-api:jar:1.12.0:compile
[INFO] |  |  \- io.opentelemetry:opentelemetry-context:jar:1.12.0:compile
[INFO] |  +- io.opentelemetry:opentelemetry-sdk-metrics:jar:1.12.0-alpha:compile
[INFO] |  +- io.opentelemetry:opentelemetry-sdk-logs:jar:1.12.0-alpha:compile
[INFO] |  +- io.opentelemetry:opentelemetry-semconv:jar:1.12.0-alpha:compile
[INFO] |  +- io.opentelemetry:opentelemetry-sdk-common:jar:1.12.0:compile
[INFO] |  +- io.opentelemetry:opentelemetry-sdk-trace:jar:1.12.0:compile
[INFO] |  +- io.opentelemetry:opentelemetry-sdk:jar:1.12.0:compile
[INFO] |  +- io.opentelemetry:opentelemetry-sdk-extension-autoconfigure-spi:jar:1.12.0:compile
[INFO] |  +- io.opentelemetry.instrumentation:opentelemetry-instrumentation-api:jar:1.11.1-alpha:compile
[INFO] |  \- io.opentelemetry:opentelemetry-extension-trace-propagators:jar:1.12.0:compile
[INFO] +- io.opentelemetry:opentelemetry-exporter-otlp-trace:jar:1.12.0:compile
[INFO] |  \- io.opentelemetry:opentelemetry-exporter-otlp-common:jar:1.12.0:runtime

here's the corresponding pom section

        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-starter-sleuth</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.cloud</groupId>
                    <artifactId>spring-cloud-sleuth-brave</artifactId>
                </exclusion>
            </exclusions>
        </dependency>
        <dependency>
            <groupId>org.springframework.cloud</groupId>
            <artifactId>spring-cloud-sleuth-otel</artifactId>
        </dependency>
        <dependency>
            <groupId>io.grpc</groupId>
            <artifactId>grpc-okhttp</artifactId>
        </dependency>
        <dependency>
            <groupId>io.opentelemetry</groupId>
            <artifactId>opentelemetry-exporter-otlp-trace</artifactId>
        </dependency>
        <dependency>
            <groupId>com.github.gavlyukovskiy</groupId>
            <artifactId>p6spy-spring-boot-starter</artifactId>
            <version>1.8.0</version>
        </dependency>
<spring-cloud.version>2021.0.1</spring-cloud.version>
 <spring-cloud-sleuth-otel.version>1.1.0-M5</spring-cloud-sleuth-otel.version>

here's the bootstrap.yml the slueth section

  sleuth:
    jdbc:
      p6spy:
        tracing:
          include-parameter-values: true
    otel:
      exporter:
        otlp:
          endpoint: http://otel-opentelemetry-collector.monitoring.svc.cluster.local:4317
      config:
        trace-id-ratio-based: 1.0
      traces:
        exporter: otlp

Here's the working service (actually two of them: merchant-service and payment-method-service) image

The other one (payment-service) just doesn't send spans.

I see my Istio proxy spans for both but only one of them is working with Spring.

In general I did the same configuration for 4 services ... 2 of them work ok ... 2 of them don't.

How to debug this situation?

I tried setting

    logging.level.org.springframework.cloud: DEBUG
    logging.level.org.springframework.cloud.sleuth: ALL
    logging.level.io.opentelemetry: ALL

but most of the beans within sleuth don't log anything when exporting spans or I can't find that.

BTW... when I use the agent approach like here https://signoz.io/opentelemetry/java-agent/ it's working ok... I see the spans from HTTP calls and Repository operations but TIDs between Istio and Spring get mixed up so it's not ideal either. I would prefer to do this 100% in Spring anyway.

Please advise how to successfully debug this situation. thanks!

marcingrzejszczak commented 2 years ago

Hi! This dependency is no longer needed com.github.gavlyukovskiy:p6spy-spring-boot-starter. Here you have an example of a mix of brave & otel apps https://github.com/spring-cloud-samples/sleuth-documentation-apps/ . Also here you have samples with brave & otel https://github.com/spring-cloud-samples/spring-cloud-sleuth-samples/ . Also please ensure that either of these exporters is actually registered https://github.com/spring-projects-experimental/spring-cloud-sleuth-otel/blob/main/spring-cloud-sleuth-otel-autoconfigure/src/main/java/org/springframework/cloud/sleuth/autoconfig/otel/OtelExporterConfiguration.java#L53

hugree commented 2 years ago

Without com.github.gavlyukovskiy:p6spy-spring-boot-starter I don't see the JDBC tracing. Why do you say it's not needed?

As for my problem I've found the weirdest thing. I'm using regular Spring Boot's regular JDBC capabilities but for services that send JMS messages ... I did have to create a custom configuration, which seems to be the problem btw, in order to handle multiple queues. It looks like this:

@Slf4j
@Configuration
@EnableJms
public class JmsConfiguration {

    private static final String QUEUE_CONFIGURATIONS_PREFIX = "queue.configurations";

    private static final Integer MAX_CLIENT_SIDE_REDELIVERY_COUNT = 20; // bigger than any azure service bus redelivery count

    @Bean
    public ListenerManager listenerManager() {
        return new ListenerManager();
    }

    @Bean
    public JavaTimeModule javaTimeModule() {
        return new JavaTimeModule();
    }

    @Bean
    public ObjectMapper objectMapper() {
        ObjectMapper objectMapper = new ObjectMapper();
        objectMapper.registerModule(javaTimeModule());
        objectMapper.disable(SerializationFeature.WRITE_DATES_AS_TIMESTAMPS);
        objectMapper.setSerializationInclusion(JsonInclude.Include.NON_NULL);
        return objectMapper;
    }

    @Bean
    public MappingJackson2MessageConverter messageConverter(ObjectMapper objectMapper) {
        MappingJackson2MessageConverter converter = new MappingJackson2MessageConverter();
        converter.setTargetType(MessageType.TEXT);
        converter.setTypeIdPropertyName("_type");
        converter.setObjectMapper(objectMapper);
        return converter;
    }

    @Bean
    public JmsDefaultPrefetchPolicy prefetchPolicy() {
        JmsDefaultPrefetchPolicy policy = new JmsDefaultPrefetchPolicy();
        policy.setAll(1);
        return policy;
    }

    @Bean
    public BeanFactoryPostProcessor beanDefinitionRegistryPostProcessor(
            Optional<ErrorHandler> errorHandler, Environment environment,
            MessageConverter messageConverter) {
        Bindable<Map<String, QueueConfiguration>> mapBindable = Bindable.mapOf(String.class, QueueConfiguration.class);
        Map<String, QueueConfiguration> queueConfigurationMap = Binder.get(environment).bind(QUEUE_CONFIGURATIONS_PREFIX, mapBindable).get();
        int outcome = environment.getProperty("queue.max-redelivery-outcome", Integer.class, REJECTED);
        return beanFactory -> queueConfigurationMap.forEach((queue, config) -> {
            ConnectionFactory connectionFactory = jmsConnectionFactory(prefetchPolicy(), config, outcome, null, null);
            JmsTemplate jmsTemplate = jmsTemplate(connectionFactory, messageConverter);
            beanFactory.registerSingleton(config.getName() + "ConnectionFactory", connectionFactory);
            beanFactory.registerSingleton(config.getContainerFactoryName(), queueContainerFactory(connectionFactory, errorHandler, config, messageConverter));
            beanFactory.registerSingleton(config.getJmsTemplateName(), jmsTemplate);
            if (config.getMessageHandlerName() != null) {
                registerMessageHandler(outcome, beanFactory, config, jmsTemplate);
            }
        });
    }

    private void registerMessageHandler(int outcome, ConfigurableListableBeanFactory beanFactory, QueueConfiguration config, JmsTemplate jmsTemplate) {
        RedeliverySender redeliverySender = config.getRedeliveryDelays() != null ? redeliverySender(jmsTemplate, config) : null;
        beanFactory.registerSingleton(config.getMessageHandlerName(), messageHandler(outcome, redeliverySender));
    }

    private JmsTemplate jmsTemplate(ConnectionFactory connectionFactory, MessageConverter messageConverter) {
        JmsTemplate jmsTemplate = new JmsTemplate(connectionFactory);
        jmsTemplate.setMessageConverter(messageConverter);
        return jmsTemplate;
    }

    private ConnectionFactory jmsConnectionFactory(
            JmsPrefetchPolicy prefetchPolicy,
            QueueConfiguration properties,
            int maxRedeliveriesOutcome,
            Tracer tracer,
            OpenTelemetry openTelemetry) {
        JmsConnectionFactory connectionFactory = new JmsConnectionFactory(properties.getUrl());
        connectionFactory.setClientID(properties.getClientId());
        connectionFactory.setUsername(properties.getUsername());
        connectionFactory.setPassword(properties.getPassword());
        connectionFactory.setReceiveLocalOnly(true);
        JmsDefaultRedeliveryPolicy jmsRedeliveryPolicy = new JmsDefaultRedeliveryPolicy();
        jmsRedeliveryPolicy.setMaxRedeliveries(properties.getRedeliveryDelays() != null ? 0 : MAX_CLIENT_SIDE_REDELIVERY_COUNT);
        jmsRedeliveryPolicy.setOutcome(maxRedeliveriesOutcome);
        connectionFactory.setRedeliveryPolicy(jmsRedeliveryPolicy);
        connectionFactory.setPrefetchPolicy(prefetchPolicy);
        SingleConnectionFactory singleConnectionFactory = new SingleConnectionFactory(connectionFactory);
        singleConnectionFactory.setReconnectOnException(true);
        //        JmsTracer jmsTracer = new OpenTelemetryTracer(tracer, openTelemetry);
        //        connectionFactory.setTracer(jmsTracer);
        return singleConnectionFactory;
    }

    private JmsListenerContainerFactory<DefaultMessageListenerContainer> queueContainerFactory(
            ConnectionFactory connectionFactory,
            Optional<ErrorHandler> errorHandler,
            QueueConfiguration queueConfiguration,
            MessageConverter messageConverter) {
        DefaultJmsListenerContainerFactory factory = new DefaultJmsListenerContainerFactory();
        factory.setConnectionFactory(connectionFactory);
        factory.setSubscriptionDurable(false); // won't work with concurrent listeners
        factory.setPubSubDomain(false); // false for queue
        factory.setMessageConverter(messageConverter);
        factory.setDestinationResolver(new DynamicDestinationResolver());
        factory.setConcurrency(queueConfiguration.getConcurrency());
        factory.setSessionAcknowledgeMode(Session.CLIENT_ACKNOWLEDGE);
        factory.setSessionTransacted(false);
        errorHandler.ifPresent(factory::setErrorHandler);
        return factory;
    }

    private RedeliverySender redeliverySender(JmsTemplate jmsTemplate, QueueConfiguration config) {
        return RedeliverySender.builder()
                .jmsTemplate(jmsTemplate)
                .queueName(config.getName())
                .redeliveryDelays(config.getRedeliveryDelays())
                .build();
    }

    private MessageHandler messageHandler(int maxRedeliveryOutcome, MessageHandler.RetryConsumer retryConsumer) {
        return new MessageHandler(maxRedeliveryOutcome, objectMapper(), retryConsumer);
    }
}

I'm also trying to create my own OpenTelemetry JmsTracer for Apache Qpid and it actually works (the spans are being propagated). Qpid only support OpenTracing, but I would like to have only one standard since Spring is ready for OpenTelemetry now. It's still a work in progress but it looks like this:

@Slf4j
public class OpenTelemetryTracer implements JmsTracer {

    static final String REDELIVERIES_EXCEEDED = "redeliveries-exceeded";

    static final String MESSAGE_EXPIRED = "message-expired";

    static final String SEND_SPAN_NAME = "amqp-delivery-send";

    static final String RECEIVE_SPAN_NAME = "receive";

    static final String ONMESSAGE_SPAN_NAME = "onMessage";

    static final String DELIVERY_SETTLED = "delivery settled";

    static final String STATE = "state";

    static final String EVENT = "event";

    static final String COMPONENT = "qpid-jms";

    static final Object ERROR_EVENT = "error";

    static final String SEND_SPAN_CONTEXT_KEY = "sendSpan";

    static final String ARRIVING_SPAN_CTX_CONTEXT_KEY = "arrivingContext";

    static final String DELIVERY_SPAN_CONTEXT_KEY = "deliverySpan";

    static final String ONMESSAGE_SCOPE_CONTEXT_KEY = "onMessageScope";

    static final String ANNOTATION_KEY = "x-opt-qpid-tracestate";

    private Tracer tracer;

    private OpenTelemetry openTelemetry;

    OpenTelemetryTracer(Tracer tracer, OpenTelemetry openTelemetry) {
        this.tracer = tracer;
        this.openTelemetry = openTelemetry;
    }

    @Override
    public void initSend(TraceableMessage message, String address) {
        Span span = tracer.spanBuilder(SEND_SPAN_NAME).setSpanKind(SpanKind.CLIENT)
                .setAttribute(Tags.SPAN_KIND, Tags.SPAN_KIND_PRODUCER)
                .setAttribute(Tags.MESSAGE_BUS_DESTINATION, address)
                .setAttribute(Tags.COMPONENT, COMPONENT)
                .startSpan();

        String tidFromMdc = MDC.get("traceId");
        String spanFromMdc = MDC.get("spanId");
        log.info("initSend START span.isRecording()={} tidFromMdc={} spanFromMdc={}", span.isRecording(), tidFromMdc, spanFromMdc);

        TextMapSetter<TraceableMessage> setter =
                new TextMapSetter<>() {

                    @Override
                    public void set(TraceableMessage carrier, String key, String value) {
                        // Insert the context as Header
                        log.info("initSend SET carrier={} key={} value={}", carrier, key, value);
                        carrier.setTracingContext(key, value);
                        carrier.setTracingAnnotation(key, value);
                    }
                };

        try (Scope scope = span.makeCurrent()) {
            //            log.info("initSend makeCurrent");
            openTelemetry.getPropagators().getTextMapPropagator().inject(Context.current(), message, setter);
        } finally {
            log.info("initSend END");
            span.end();
        }
    }

    @Override
    public void completeSend(TraceableMessage message, String outcome) {
        //        log.info("completeSend");
        Object cachedSpan = message.getTracingContext(SEND_SPAN_CONTEXT_KEY);
        //        log.info("completeSend {}", SEND_SPAN_CONTEXT_KEY);
        if (cachedSpan != null) {
            log.info("completeSend cachedSpan={}", cachedSpan);
            Span span = (Span) cachedSpan;

            span.addEvent(EVENT, Attributes.of(AttributeKey.stringKey(EVENT), DELIVERY_SETTLED));
            span.addEvent(STATE, Attributes.of(AttributeKey.stringKey(STATE), outcome == null ? "null" : outcome));

            span.end();
        }
    }

    @Override
    public void syncReceive(TraceableMessage message, String address, DeliveryOutcome outcome) {
        //        log.info("syncReceive");
        TextMapGetter<TraceableMessage> getter =
                new TextMapGetter<>() {

                    @Override
                    public String get(TraceableMessage carrier, String key) {
                        log.info("syncReceive key={} carrier={}", key, carrier.toString());
                        Object stringProperty = carrier.getTracingAnnotation(key);
                        log.info("syncReceive stringProperty value={} class={}", stringProperty, stringProperty.getClass());
                        return isEmpty(stringProperty) ? "stringProperty" : stringProperty.toString();
                    }

                    @Override
                    public Iterable<String> keys(TraceableMessage carrier) {
                        log.info("syncReceive carrier {}", carrier.toString());
                        log.info("syncReceive stringProperty lista");
                        return List.of();
                    }
                };

        Context extractedContext = openTelemetry.getPropagators().getTextMapPropagator().extract(Context.current(), message, getter);
        //        try (Scope scope = extractedContext.makeCurrent()) { // Automatically use the extracted SpanContext as parent.
        Scope scope = extractedContext.makeCurrent(); // Automatically use the extracted SpanContext as parent.
        Span serverSpan = tracer.spanBuilder(RECEIVE_SPAN_NAME)
                .setParent(extractedContext)
                .setSpanKind(SpanKind.SERVER)
                .startSpan();
        //            try {
        serverSpan.setAttribute(SemanticAttributes.HTTP_USER_AGENT, "valid! user agent");
        //            } finally {
        serverSpan.end();

        String tidFromMdc = MDC.get("traceId");
        String spanFromMdc = MDC.get("spanId");

        String tidFromMdcB3 = MDC.get("X-B3-TraceId");
        String spanFromMdcB3 = MDC.get("X-B3-SpanId");

        log.info("syncReceive END tidFromMdc={} spanFromMdc={} tidFromMdcB3={} spanFromMdcB3={}", tidFromMdc, spanFromMdc, tidFromMdcB3, spanFromMdcB3);
        //            }
        //        }
    }

    private void addDeliveryLogIfNeeded(DeliveryOutcome outcome, Span span) {
        log.info("addDeliveryLogIfNeeded");
        if (outcome == DeliveryOutcome.EXPIRED) {
            span.addEvent(EVENT, Attributes.of(AttributeKey.stringKey(EVENT), MESSAGE_EXPIRED));
            log.info("addDeliveryLogIfNeeded: {}", DeliveryOutcome.EXPIRED);
        } else if (outcome == DeliveryOutcome.REDELIVERIES_EXCEEDED) {
            span.addEvent(EVENT, Attributes.of(AttributeKey.stringKey(EVENT), REDELIVERIES_EXCEEDED));
            log.info("addDeliveryLogIfNeeded: {}", DeliveryOutcome.REDELIVERIES_EXCEEDED);
        }
    }

    @Override
    public void asyncDeliveryInit(TraceableMessage message, String address) {
        log.info("asyncDeliveryInit");
        Span span = tracer.spanBuilder(SEND_SPAN_NAME).setSpanKind(SpanKind.CLIENT)
                .setAttribute(Tags.SPAN_KIND, Tags.SPAN_KIND_PRODUCER)
                .setAttribute(Tags.MESSAGE_BUS_DESTINATION, address)
                .setAttribute(Tags.COMPONENT, COMPONENT)
                .startSpan();
        log.info("asyncDeliveryInit {}", span.isRecording());

        TextMapSetter<TraceableMessage> setter =
                new TextMapSetter<>() {

                    @Override
                    public void set(TraceableMessage carrier, String key, String value) {
                        // Insert the context as Header
                        log.info("asyncDeliveryInit carrier {}", carrier);
                        log.info("asyncDeliveryInit key {}", key);
                        log.info("asyncDeliveryInit value {}", value);
                        carrier.setTracingContext(key, value);
                        carrier.setTracingAnnotation(key, value);
                    }
                };

        try (Scope scope = span.makeCurrent()) {
            log.info("asyncDeliveryInit makeCurrent");
            openTelemetry.getPropagators().getTextMapPropagator().inject(Context.current(), message, setter);
        } finally {
            log.info("asyncDeliveryInit end");
            span.end();
        }
    }

    @Override
    public void asyncDeliveryComplete(TraceableMessage message, DeliveryOutcome outcome, Throwable throwable) {
        Scope scope = (Scope) message.removeTracingContext(ONMESSAGE_SCOPE_CONTEXT_KEY);
        log.info("asyncDeliveryComplete scope {}", scope);
        try {
            if (scope != null) {
                log.info("asyncDeliveryComplete scope!=null");
                scope.close();
            }
        } finally {
            Span span = (Span) message.getTracingContext(DELIVERY_SPAN_CONTEXT_KEY);
            log.info("asyncDeliveryComplete span != null {}", span != null);
            if (span != null) {
                try {
                    if (throwable != null) {
                        span.setStatus(StatusCode.ERROR, "Application error, exception thrown from onMessage.");
                        span.recordException(throwable);
                        log.info("asyncDeliveryComplete throwable != null");
                    } else {
                        addDeliveryLogIfNeeded(outcome, span);
                    }
                } finally {
                    span.end();
                }
            }
        }
    }

    @Override
    public void close() {
        log.info("opentelemtry close()");
        // NOOP
    }

}

The super WEIRD thing is when I try to autowire the Tracer object in the beanDefinitionRegistryPostProcessor method the whole Spring Boot tracing goes dead :/. I don't need to use the object even... just Autowire it and boom. No REST tracing. No JDBC tracing. and no JMSTracing... obviously. Still I get zero errors so I don't know what I'm doing wrong.

hugree commented 2 years ago

Also I don't see any JMS examples in the samples https://github.com/spring-cloud-samples/spring-cloud-sleuth-samples/

marcingrzejszczak commented 2 years ago

Without com.github.gavlyukovskiy:p6spy-spring-boot-starter I don't see the JDBC tracing. Why do you say it's not needed?

You can check this section of the docs https://docs.spring.io/spring-cloud-sleuth/docs/current/reference/html/integrations.html#sleuth-jdbc-integration

The super WEIRD thing is when I try to autowire the Tracer object in the beanDefinitionRegistryPostProcessor method the whole Spring Boot tracing goes dead :/. I don't need to use the object even... just Autowire it and boom. No REST tracing. No JDBC tracing. and no JMSTracing... obviously. Still I get zero errors so I don't know what I'm doing wrong.

That's because you're trying to inject it too early and there's a deadlock. You should not be injecting such a bean there. You should try to resolve it at runtime.

hugree commented 2 years ago

We’re decorating DataSources in a trace representation. We delegate actual proxying to either p6spy or datasource-proxy. In order to use this feature you need to have them on the classpath.

it says you need one of those on the classpath. You mean it's a different artifact right?

That's because you're trying to inject it too early and there's a deadlock. You should not be injecting such a bean there. You should try to resolve it at runtime.

That's what we did yesterday and it works now. Thanks. I will look for more explanation later on ;)

@marcingrzejszczak what about JMS tracing in general? What is supported by Spring right now with JMS? Brave? OpenTracing? OpenTelemetry? where can I see the codes for that instrumentation?

marcingrzejszczak commented 2 years ago

it says you need one of those on the classpath. You mean it's a different artifact right?

You don't need com.github.gavlyukovskiy:p6spy-spring-boot-starter, you need either p6spy or datasource-proxy

That's what we did yesterday and it works now. Thanks. I will look for more explanation later on ;)

Great to hear that!

@marcingrzejszczak what about JMS tracing in general? What is supported by Spring right now with JMS? Brave? OpenTracing? OpenTelemetry? where can I see the codes for that instrumentation?

With Sleuth we support spring-jms over Brave or via Spring Integration.

hugree commented 2 years ago

Is there a plan to adopt spring-jms to OpenTelemetry?

marcingrzejszczak commented 2 years ago

Not for spring-cloud-sleuth-otel. We will consider adding it natively with Spring Framework 6.0