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)
