Details
-
New Feature
-
Status: Closed
-
Major
-
Resolution: Won't Do
-
None
-
None
-
None
Description
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 from examle for Open Tracing Plugin ). 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:
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; } }
And logs, as you can see some threads without trace and span IDs:
[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
