You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Valeriy Ak (Jira)" <ji...@apache.org> on 2022/12/01 14:17:00 UTC

[jira] [Created] (ARTEMIS-4102) Pass OpenTelemetry data to artemis logs

Valeriy Ak created ARTEMIS-4102:
-----------------------------------

             Summary: Pass OpenTelemetry data to artemis logs
                 Key: ARTEMIS-4102
                 URL: https://issues.apache.org/jira/browse/ARTEMIS-4102
             Project: ActiveMQ Artemis
          Issue Type: New Feature
            Reporter: Valeriy Ak


Hi,

We add OpenTelemetry to our artemis broker and we use for it your solution from 2.21.0 release  [ARTEMIS-3686] - Add example integrating OpenTelemetry ([OpenTelemetryPlugin.java|https://github.com/apache/activemq-artemis/blob/main/examples/features/standard/opentelemetry/src/main/java/org/apache/activemq/artemis/jms/example/OpenTelemetryPlugin.java] from [examle for Open Tracing Plugin ). |https://github.com/apache/activemq-artemis/tree/main/examples/features/standard/opentelemetry] Its works fine!

But trace_id and span_id that generated by OpenTelemetry does not shows in broker logs like it works in spring boot application with injected opentelemetry javaagent. 

We can show trace_id and span_id in logs only putting they into MDC manually, but that's not pass across threads. 

Could you tell us any way for fix it or provide some example for get trace_id and span_id in logs for all threads? 

Simple implementation ActiveMQServerPlugin:
{code:java}
 public class OpenTracingActiveMQServerPlugin implements ActiveMQServerPlugin {

    private static final Logger logger = Logger.getLogger(OpenTracingActiveMQServerPlugin.class);
    private static final String OPERATION_NAME = "ArtemisMessageDelivery";
    private static OpenTelemetry sdk = initOpenTracing();
    private static Tracer tracer = sdk.getTracer(OpenTracingActiveMQServerPlugin.class.getName());

    public static OpenTelemetry initOpenTracing() {
        OpenTelemetry openTelemetry = OpenTelemetrySdk.builder()
                .setPropagators(ContextPropagators.create(W3CTraceContextPropagator.getInstance()))
                .buildAndRegisterGlobal();
        return openTelemetry;

    }
    @Override
    public void beforeSend(ServerSession session,
                           Transaction tx,
                           Message message,
                           boolean direct,
                           boolean noAutoCreateQueue) throws ActiveMQException {
        SpanBuilder spanBuilder = getTracer().spanBuilder(OPERATION_NAME).setAttribute("message", message.toString()).setSpanKind(SpanKind.SERVER);
        spanBuilder.setParent(sdk.getPropagators().getTextMapPropagator().extract(Context.current(), message, new ArtemisMessageTextMapGetter().getGetter()));
        Span span = spanBuilder.startSpan();
        SpanContext spanContext = span.getSpanContext();
        message.putObjectProperty(Span.class.getSimpleName(), span);
        MDC.put("trace_id", spanContext.getTraceId());
        MDC.put("span_id", spanContext.getSpanId());

        logger.debug("beforeSend trace_id: "+spanContext.getTraceId());
        logger.debug("beforeSend span_id: "+spanContext.getSpanId());
        logger.debug("\nbeforeSend message: \n"+message);
        logger.debug("\nbeforeSend span: \n"+span);
    }

    @Override
    public void afterSend(ServerSession session, Transaction tx, Message message, boolean direct, boolean noAutoCreateQueue, RoutingStatus result) {
        Span span = getSpan(message);
        span.addEvent("send " + result.name());
        logger.debug("afterSend trace_id: "+span.getSpanContext().getTraceId());
        logger.debug("afterSend span_id: "+span.getSpanContext().getSpanId());
        logger.debug("\nafterSend message: \n"+message);
        logger.debug("\nafterSend span: \n"+span);
    }

    @Override
    public void afterDeliver(ServerConsumer consumer, MessageReference reference) throws ActiveMQException {
        Span span = (Span) reference.getMessage().getObjectProperty(Span.class.getSimpleName());
        span.addEvent("deliver " + consumer.getSessionName());
        logger.debug("afterDeliver trace_id: "+span.getSpanContext().getTraceId());
        logger.debug("afterDeliver span_id: "+span.getSpanContext().getSpanId());
        logger.debug("\nafterDeliver message: \n"+reference.getMessage());
        logger.debug("\nafterDeliver span: \n"+span);
        span.end();
    }

    @Override
    public void onSendException(ServerSession session,
                                Transaction tx,
                                Message message,
                                boolean direct,
                                boolean noAutoCreateQueue,
                                Exception e) throws ActiveMQException {
        getSpan(message).setStatus(StatusCode.ERROR).recordException(e);
    }

    public Tracer getTracer() {
        return tracer;
    }

    public void setTracer(Tracer myTracer) {
        tracer = myTracer;
    }

    private Span getSpan(Message message) {
        Span span = (Span) message.getObjectProperty(Span.class.getSimpleName());
        return span;
    }

}{code}
 

And logs, as you can see some threads without trace and span IDs:
{code:java}
 [Thread-13 ] [4b7f23e9d0f57655425ad037f4cc2a60,9911b1d422dc15c3] 2022-12-01 17:35:51,289 DEBUG [org.example.OpenTracingActiveMQServerPlugin] afterSend span: ...
[Thread-0 (] [384fdbc7530ed125b0d6fc132242cd32,a88106807271bebe] 2022-12-01 17:35:51,292 DEBUG [org.apache.activemq.artemis.core.server.impl.QueueImpl] Queue test doing deliver. messageReferences=49 with consumers=0
[Thread-0 (] [384fdbc7530ed125b0d6fc132242cd32,a88106807271bebe] 2022-12-01 17:35:51,292 DEBUG [org.apache.activemq.artemis.core.server.impl.QueueMessageMetrics] QueuePendingMessageMetrics[queue=test, name=pending] increment messageCount to 50: ....
[Thread-10 ] [,] 2022-12-01 17:35:51,293 FINE  [proton.trace] IN: CH[1] : Detach{handle=0, closed=true, error=null}
[Thread-10 ] [,] 2022-12-01 17:35:51,295 FINE  [proton.trace] IN: CH[1] : End{error=null}
[Thread-7 (] [b6c061af1de9468c4d936f25adf98af6,5de50f4328167ede] 2022-12-01 17:35:51,295 DEBUG [org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] Couldn't find any bindings for address=CoreMessage[...
[Thread-7 (] [b6c061af1de9468c4d936f25adf98af6,5de50f4328167ede] 2022-12-01 17:35:51,295 DEBUG [org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] Message CoreMessage[...
[Thread-10 ] [,] 2022-12-01 17:35:51,296 FINE  [proton.trace] IN: CH[0] : Close{error=null}
[Thread-10 ] [,] 2022-12-01 17:35:51,296 DEBUG [org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl] RemotingServiceImpl::removing connection ID f5a80709{code}



--
This message was sent by Atlassian Jira
(v8.20.10#820010)