I don't see the first created parent scope being closed. According to the opentracing documentation :
"It is a programming error to neglect to call {@link Scope#close()} on the returned instance "
Probably the scope is closed when the thread ends, but that could lead to strange behaviour when using a threadpool.
Indeed i sometimes see (too long) lived traces, when used with other tracing instrumentated modules like "opentracing-spring-jaeger-web-starter" itself.
Of course this is only an issue if axon is creating the scope, which, mostly, is not the case, as there is almost always a rest endpoind or some other starting point, but i think it should not be a default assumption.

We only support async. send(Command) now, we need to support other methods as well.

So, I have finally finished the MVP of what I was trying to do with tracing and it is available here:
https://github.com/Sam-Kruglov/bike-rental-demo

I ask you to take a look and we can discuss whether the way I changed this extension fits your vision or not. When we agree on something I will create a PR. Sorry for not creating a PR right away, that would probably be easier, but it will take time and I already have this working, so while I do that, you can already check it out.

New features

• At every step, we have our Message payload included in the tags of the span.
• All messages are logged:
  • Command payloads at DEBUG
  • User-friendly events at INFO
  • Event payloads at DEBUG
  • Query payloads at TRACE
  • Query return values at TRACE
• Span names actually contain the Message names, like "Send BikeRentCommand" instead of "sendCommandMessage"
• Event publishing is a separate Span with a user-friendly event name.
• All message handler exceptions are caught
  • Expected exceptions are only logged at DEBUG without a stacktrace and reported to the span as a log with an error.expected key.
  • Unexpected exceptions are logged at ERROR with a stacktrace and reported to the span as a log with an error.unexpected key.
• All application logs mentioned above include tracer id.
• Event handling Spans have names that are dynamically resolved with AOP using package names (questionable, but otherwise you only have application name to know the distinguish the projections)

Instructions to run

1. Checkout the master branch
2. Start Jaeger UI (you can use the included docker-componse.yml for that, localhost:16686)
3. Start the app.
4. Use requests.http to fire some commands
5. Look at Jaeger UI

Would it be nice/usefull to add the aggregateIdentifier als a tracing tag ?
(Only in case of a DomainEventMessage)
That way it is more easy to find a specific trace without having to lookup the traceId first, or by just looking at the start time .

org.axonframework.extensions.tracing.SpanUtils#withMessageTags creates some tags for a message:
message id, message type (query/command name or payload class name), payload class name, command name, aggregate id.
It is added in TracingCommandGateway and in OpenTraceHandlerInterceptor.

I think the only useful are the payload class name and aggregate id, others can be removed. In my project, I just included the whole payload into a tag. These messages are supposed to be small anyway.

P.S. it itches to make this refactoring inside the interceptor:

private Optional<SpanContext> getParentSpan(Message<?> message) {
    MetaData metaData = message.getMetaData();
    MapExtractor extractor = new MapExtractor(metaData);
    try {
        return Optional.ofNullable(tracer.extract(Format.Builtin.TEXT_MAP, extractor));
    } catch (IllegalArgumentException e) {
        log.error("corrupted parent span", e); //this shouldn't happen but if it does, better print the stacktrace
        return Optional.empty();
    }
}

Feature Description

Integrate tracing with apache-skywalking

Current Behaviour

Opentracing is no longer active, and skywalking is only supporting opentracing 0.30;
Extension-tracing is built with opentracing >=0.33?

Wanted Behaviour

Integrate with skywalking directly

Possible Workarounds

No idea

From #15.

I think it could be useful to have a possibility to set a property to start including message payloads as span tags. I agree it should default to not do that.

Basic information

• Axon Framework version: 4.5.9
• JDK version: 11.0.13
• Tracing Extension version: 4.5.2
• Complete executable reproducer if available (e.g. GitHub Repo):

Steps to reproduce

We have Application A that has its tracing context that publish an event using EventBus.
This event is handled by Application B, that does not continue with Application A context but starts a new tracing context.

The problem is that the OpenTraceDispatchInterceptor doesn't intercept the EventBus.publish() call and then does not extract
tracingId from tracing context and does not add metadata to published event.

As workaround, we insert manually the header in the published message.

Our code below:

@AllArgsConstructor
public class SyncEventPublisherAxon implements SyncEventPublisher {

   private final EventBus eventBus;
   private final Tracer tracer;

   @Override
   public void publish( final SyncEvent event ) {
      eventBus.publish( message( event ) );

   }

   protected GenericEventMessage<SyncEvent> message( final SyncEvent syncEvent ) {
      final ScopeManager scopeManager = tracer.scopeManager();
      final Optional<SpanContext> spanContextOptional = Optional.ofNullable( scopeManager )
            .map( ScopeManager::activeSpan )
            .map( Span::context );

      final GenericEventMessage<SyncEvent> message = new GenericEventMessage<>( syncEvent );
      return spanContextOptional.map( ( spanContext ) -> {
         MapInjector injector = new MapInjector();
         this.tracer.inject( spanContext, Format.Builtin.TEXT_MAP, injector );
         return message.andMetaData( injector.getMetaData() );
      } ).orElseGet( () -> message );
   }

}

Expected behaviour

We expect that OpenTracing context 'continues' between applications.

Actual behaviour

Event published in the EventStore by Application A does not contains jaeger uber-trace-id metadata and then Application B starts a new context.

I would like to suggest other operation names for the spans. Now it is
"sendCommand" , "sendAndWaitCommand" and "handleEventMessage" ,"handleCommand" ,
but it also "handle<QueryName>".
This not consistent and not really clear when looking at the traces in Jeager.
I would like to propose :
"send<CommandName>"
"sendAndWait<CommandName>"
"send<QueryName>"
"handle<CommandName>
"handle<QueryName>"
"handle<EventPayloadtype>
Also use simpleNames if the Command and Query classNames are not overruled by commandName and queryName

From the messagenames it mostly is clear that it is an event, command or query.

See #25

So it looks like this :

Make the constructor protected

In send you call GenericCommandMessage#asCommandMessage and use the result to build the span tags, including message id. But you actually send just the payload in super#send, so the command message is created again somewhere up the chain.

I don't know what is the best solution here. I am writing my own gateway, maybe if I get somewhere nice I will submit a PR

This is an issue to track progress, of demo'ing this extension with the giftcard app.

The private sendWithSpan method uses a wrong parameter order for the SpanConsumer functional interface.
Specifically, I am talking about the consumer parameter, where parent and child places are mixed

Also, there is no need for passing Tracer instance there since it's a field.

In #15 @smcvb said the following:

For now we feel that event publication is always paired with another type of message.

But take a look at this picture

Here bike registered event (span operation name is Bike #1234 registered in Vilnius ) has a dedicated span which is a child of handle register bike command span. I think it makes perfect sense. I also create a separate span here for each handling of this event, i.e. for each event listener.

This is the default behavior:

Here is some code to make it work:

interface Describable {
    fun description(): String
}

data class BikeRegisteredEvent(val bikeId: String, val location: String) : Describable {
    override fun description() = "Bike #$bikeId: registered in $location"
}

fun Tracer.extractContextFrom(message: Message<*>): SpanContext? {
    return extract(
            Format.Builtin.TEXT_MAP,
            MapExtractor(message.metaData)
    )
}

/**
 * returns `null` if there is no active span
 */
@Suppress("UNCHECKED_CAST")
fun <T : Message<*>> T.andSpanMetaData(tracer: Tracer): T? {
    val activeSpan = tracer.activeSpan() ?: return null
    val injector = MapInjector()
    tracer.inject(activeSpan.context(), Format.Builtin.TEXT_MAP, injector)
    return andMetaData(injector.metaData) as T
}

@Bean
fun traceDispatchInterceptor(tracer: Tracer): MessageDispatchInterceptor<Message<*>> =
        object : OpenTraceDispatchInterceptor(tracer) {
            override fun handle(messages: MutableList<out Message<*>>?)
                    : BiFunction<Int, Message<*>, Message<*>> {
                return BiFunction { _, message ->
                    val payloadName = message.payloadType.simpleName
                    val span = if (message is EventMessage<*>) {
                        val operationName = try {
                            (message.payload as Describable).description()
                        } catch (e: ClassCastException) {
                            log.error("$payloadName does not implement ${Describable::class.simpleName}")
                            "Publish $payloadName"
                        }
                        tracer.buildSpan(operationName).start()
                    } else {
                        //parent must be present since it triggered the dispatching process
                        tracer.activeSpan()!!.setOperationName("Send $payloadName")
                    }
                    span.setTag(...)
                    if (message is EventMessage<*>) {
                        CurrentUnitOfWork.get().onCleanup { span.finish() }
                        return@BiFunction tracer.activateSpan(span).use { message.andSpanMetaData(tracer)!! }
                    }
                    message.andSpanMetaData(tracer)!!
                }
            }
        }

val EVENT_UOW_SPAN_KEY = "span"

@Bean
fun traceHandlerInterceptor(tracer: Tracer): MessageHandlerInterceptor<Message<*>> =
        object : OpenTraceHandlerInterceptor(tracer) {
            override fun handle(
                    unitOfWork: UnitOfWork<out Message<*>>,
                    interceptorChain: InterceptorChain
            ): Any? {
                val operationName = "Handle ${unitOfWork.message.payloadType.simpleName}"
                //span context must be present in the message metadata for handlers
                val parentSpan = tracer.extractContextFrom(unitOfWork.message)!!
                val span = tracer.buildSpan(operationName)
                        .asChildOf(parentSpan)
                        .withTag(...)
                        .start()
                val scope = tracer.activateSpan(span)
                //for queries this would be printed at the end, not very useful
                if (unitOfWork.message !is QueryMessage<*, *>) {
                    unitOfWork.onPrepareCommit { span.log("finished handling") }
                    if (unitOfWork.message is EventMessage<*>) {
                        /* If we simply embed this Span into this Message
                         * we would only be able to extract it into SpanContext
                         * which doesn't allow to change the Span operation name.
                         * see TracingEventHandlerAspect
                         */
                        unitOfWork.resources()[EVENT_UOW_SPAN_KEY] = span
                    }
                }
                unitOfWork.onCleanup {
                    scope.close()
                    span.finish()
                }
                return interceptorChain.proceed()
            }
        }

//could be as optional maven scope
@Aspect
@Service
class TracingEventHandlerAspect {
    companion object {
        private const val READ_MODEL_PACKAGE = "com.myproject.projections"
    }
    @Around("projectionServiceMethods() && @annotation(org.axonframework.eventhandling.EventHandler)")
    fun logStuff(p: ProceedingJoinPoint): Any? {
        val packageName = p.signature.declaringType.`package`.name
        //capitalized package after "read"
        val projectionName = packageName
                .replace(READ_MODEL_PACKAGE, "")
                .split(".")
                .joinToString(" ") { it.capitalize() }
                .trim()
        CurrentUnitOfWork.get()
                .getResource<Span>(EVENT_UOW_SPAN_KEY)
                .setOperationName("Updating $projectionName Projection")
        return p.proceed()
    }
    @Pointcut("execution(* $READ_MODEL_PACKAGE..*ViewService.*(..))")
    fun projectionServiceMethods() = Unit
}

package com.myproject.projections.main
@Service
class BikeViewService(private val repo: BikeViewRepo) {
    @EventHandler
    fun registered(event: BikeRegisteredEvent) {
        repo.save(BikeView(event.bikeId, event.location))
    }
}

Basic information

• Axon Framework version: 4.4.x
• JDK version: any
• Tracing Extension version: 4.4
• Complete executable reproducer if available (e.g. GitHub Repo): look here

Steps to reproduce

It is similar to the linked issue on extension-kafka and was also noticed by our users on our discuss.

Expected behaviour

TracingCommandGateway and TracingQueryGateway should be used.

Actual behaviour

Default command and query gateway is always used, because AxonAutoConfiguration goes first, and defaultCommandGateway is created there. So tracingCommandGateway in TracingAutoConfiguration is ignored.

• add travis
• add docs.
• do a test build

When throwing a CommandExecutionException the expected behavior is that my method decorated with @ExceptionHandler(CommandExecutionException.class) is called.

But once I've added the tracing extension as a dependency instead the AxonServerRemoteCommandHandlingException is triggered thus not reaching my handler.

Creating another handler to AxonServerRemoteCommandHandlingException is not a possibility as I need the getDetails for my use case.

These guidelines say that it's supposed to be a human-readable string. Why don't we have some spaces? :)

When emitting a query (i.e. From an event handler) , we should propagate trace, so the subscription query is also traced. This should be implemented as part of pulling this repository out of it's milestone-state.

In a production environment, looking at console logs without traceId is nearly impossible because multiple requests from multiple machines write their own things into the same file, and it's very hard to make sense of it.

It is all right if we're looking at the logs via Open Tracing UI that are attached to a span but if we are talking about console logs, it's a different story.

Sensible to include and simple enough to achieve on a users own accord I think. Don't think this requires anything extension specific right now.
(c) @smcvb #15

I think library user is supposed to deal with it themselves in a usual case but this extension is aware of tracing, so, it should use it IMO.

Example:

log.info("[${tracer.activeSpan()?.context()?.toTraceId()}]: ${command.payloadType.simpleName} has been dispatched")

Will print:

[e66dc77b8a1e813b]: RegisterBikeCommand has been dispatched

Currently, Project Reactor is not scoped provided and it should be.

This line assigns message type in place of payload type:

Method below used by command gateway is correct:

Can you consider adding a property that will disable tracing?

It might be more convenient than poking around with dependencies if tracing, for some reason, isn't desired in different environments (dev, qa, prod, etc.).

Tnx.

See picture in #15. I have my own tracing event store that sets up the span.
There is a BikeRegisteredEvent with custom span name "Bike #1234 registered in Vilnius" and it has 2 child spans for each projection that listens to this event. The span is finished as soon as the void publish(..) method returns (not sure if that's good enough though). There are some extra interceptors used to tie projection to that span.

I would like to see something like that out of the box.

Running with Spring Boot v2.3.3.RELEASE, Spring v5.2.8.RELEASE
When combining axon libraries for local development:

        <dependency>
            <groupId>org.axonframework</groupId>
            <artifactId>axon-spring-boot-starter</artifactId>
            <version>${axonframework.version}</version>
        </dependency>

        <dependency>
            <groupId>org.axonframework.extensions.tracing</groupId>
            <artifactId>axon-tracing-spring-boot-starter</artifactId>
            <version>4.3.1</version>
        </dependency>

Local development (mvn spring-boot:run) is unable to proceed due to error mentioned in the title.
This does not happen in any other environment aside from local dev. For the reference, I have the following configuration (and haven't configured any environment variable):

opentracing:
  jaeger:
    enabled: ${JAEGER_ENABLED:false}
    service-name: ${spring.application.name}
    udp-sender:
      host: "${JAEGER_HOST:localhost}"
      port: "${JAEGER_PORT:6831}"

Ideally (and aside from this bug), this extension should be picking a configuration flag instead of looking up for the presence of io.opentracking.Tracer class.

Basic information

• Axon Framework version: 4.6.0-SNAPSHOT
• JDK version: 16
• Tracing Extension version: latest
• Complete executable reproducer if available (e.g. GitHub Repo):

Steps to reproduce

Create an application using streaming queries and add the tracing extension.

Expected behaviour

Streaming query should work.

Actual behaviour

Throws exception on the streaming query:

java.lang.AbstractMethodError: Receiver class org.axonframework.extensions.tracing.TracingQueryGateway does not define or inherit an implementation of the resolved method 'abstract org.reactivestreams.Publisher streamingQuery(java.lang.String, java.lang.Object, java.lang.Class)' of interface org.axonframework.queryhandling.QueryGateway.

Configure Tracing GW's.
Configure Dispatch Interceptor
Configure Handler Interceptor.

Fix warning on build.

Warning: 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.fasterxml.jackson.module:jackson-module-kotlin:jar -> duplicate declaration of version ${jackson.version} @ line 65, column 21

If I declare this:

<dependency>
    <groupId>org.axonframework.extensions.tracing</groupId>
    <artifactId>axon-tracing-spring-boot-starter</artifactId>
    <version>4.2-M1</version>
</dependency>
<dependency>
    <groupId>io.opentracing.contrib</groupId>
    <artifactId>opentracing-spring-jaeger-web-starter</artifactId>
    <version>3.1.1</version>
</dependency>

You are using deprecated methods inside opentracing-api:0.32.0, I bring in 0.33.0 which removed those methods, so, when I browse axon sources, I see "red method calls". For example, see io.opentracing.Tracer.SpanBuilder.

Also, if you visit opentracing.io, you will see they seem to be called OpenTelemetry now.

in TracingCommandGateway#send we do see the span activation and in TracingCommandGateway#sendAndWait we don't. Why is that?

For the moment the library is compatible with opentracing-api 0.31.0. Version 0.33.0 introduces non-backward compatible changes.

The extension must be reworked to use new opentracing API.

The user should be able to simply provide their own beans.

For commands, we can see both payload type and command name, which is exactly the same thing. I think the if statement should be removed

When using the TracingQueryGateway with a null query payload, the gateway throws a NullPointerException as it tries to deduce the message name from the payload of the query payload.

Instead, it should be able to rely entirely on the name of the query, as this already defaults to the payload and will only be different when the query name is explicitly configured.

In order to be aligned with the Axon ecosystem, unit tests need to be migrated to JUnit5.

this method public <R> CompletableFuture<R> send(Object command) is exactly the same as defined in the DefaultCommandGateway. Why not forward it to the delegate?

I didn't test it but your test doesn't look promising as it's using simply new DefaultSubscriptionQueryResult<>(Mono.empty(), Flux.empty(), () -> true) as a stub result.

If we unwrap the code this is essentially what it's doing:

Span childSpan = tracer.buildSpan(operation).start();
try (Scope ignored = tracer.activateSpan(childSpan)) {
    return new TraceableSubscriptionQueryResult<>(
                                   delegate.subscriptionQuery(
                                           queryName,
                                           query,
                                           initialResponseType,
                                           updateResponseType,
                                           backpressure,
                                           updateBufferSize),
                                   childSpan
                           ));
}
...
class TraceableSubscriptionQueryResult{
...
  @Override
  public Mono<I> initialResult() {
      span.log("initialResultReceived");
      return initialResult;
  }
  @Override
  public Flux<U> updates() {
      return updates.doOnEach(ignored -> span.log("updateReceived"));
  }
}

I think that when you call delegate.subscriptionQuery(...) it's going to return an async result and then populate it later. If that's true, the childSpan scope will close as soon as that happens. Later, on initialResult and on update we will call childSpan.log(...) which will fail for sure as it is out of scope.

One can use StepFerifier somehow or the Awaitility library introduced in #39 to test this with a delay.

P.S. Can we replace SpanSupplier<T> with java.util.function.Supplier<Span>?

When using Axon Tracing and Spring Boot Sleuth together,

Message information like:

• Message id
• Message type (Command, Query, Event etc..)
• Payload type.
• Payload size

Could be added as tags to the span or as the operation name of a span.

Now child spans are created with the following names:

Command Gateway -> child span named 'Command'
Query Gateway -> child span named 'Query'
HandlerInterceptor -> child span named 'Extracting'

DispatchInterceptor -> no child span.
CorrelationDataProvider -> no child span.

Propose:

Operation name

• Message payload type

Tags:

• Axon message id.
• Message type.
• Message payload type
• Message payload size

@abuijze @smcvb what do you think?

TracingCommandGateway has a protected constructor but private tracer and delegate fields which are required to do anything meaningful in the child class.

Current Behavior
If I place a command on the TracingCommandGateway with send or sendAndWait and there already is an active span before the TracingCommandGateway is invoked then it will not be deactivated. I close the span after invoking the TracingCommandGateway. If I don't invoke the TracingCommandGateway then the span is closed.

Expected Behavior
I expect the span that was created before invoking the TracingCommandGateway to be deactivated at the end of the try with statement. I have attached a project to demonstrate the behavior. Am I doing something wrong or is this extension exhibiting undesirable behavior? If I don't invoke the CommandGateway within the try with statement then the span is deactivated.

I just want to define @Beans of MessageDispatchInterceptor, MessageHandlerInterceptor, and ListenerInvocationErrorHandler and I don't want to deal with anything else.

Take a look at how I'm defining those beans in TracingAxonConfig and how I'm catching those in AxonConfig.

Note, how I'm using @Bean @Order(0) on the tracing interceptor, @Bean @Onder(1) on exception handling ones, and @Bean (comes last) on others. That controls the ordering in the List that I'm catching later, and, mainly, the invocation order.

This concerns both TracingAutoConfiguration and AxonAutoConfiguration (from core).

1. On any exception caught, there should be a tag error=true set and some log entries like error.*, event, message, stack (see OpenTracing conventions). I also propose to have error.expected=true/false but it's minor.
2. I think point-to-point queries don't have any error handling at all.
3. I think eventHandler.getTargetType().getSimpleName() inside LoggingErrorHandler will include spring proxy like *EnhancerBySpring*.

See my error handlers in TracingAxonConfig. Logging. ErrorLoggingConfig

Enhancement Description

This extension is based on the Open Tracing API. As stated on their website both Open Tracing and Open Census have merged in OpenTelemetry. It would be beneficial if we move over to this newer, merged API, to stay on track with recent developments in the tracing ecosphere.

Current Behaviour

This extension uses the OpenTracing API to support tracing.

Wanted Behaviour

Use the OpenTelemetry API to support tracing.

The current TracingQueryGateway does not support tracing for usages of the QueryGateway#scatterGather. This should be implemented as part of pulling this repository out of it's milestone-state.

In #15, I had to override a DefaultCommandGateway in order to copy-paste the send method to exclude the FailureLoggingCallback so that it doesn't pollute my logs. I have my own very cool logging interceptors that log all messages (see io.axoniq.demo.bikerental.config.tracing.TracingAxonConfig.Logging):

• Command payloads at DEBUG
• User-friendly events at INFO
• Event payloads at DEBUG
• Query payloads at TRACE
• Query return values at TRACE

I suggest that you turn that callback into an interceptor that I can disable/replace or/and you can take my idea for logging.

P.S. whenever we log anything in the tracing context, we must also log trace id or it's going to be a mess.

Currently, we have this:

I feel this would be better:

private static final String TAG_AXON_ID = "axon.message.id";
private static final String TAG_AXON_AGGREGATE_ID = "axon.message.aggregate.id";
private static final String TAG_AXON_MESSAGE_TYPE = "axon.message.type";
private static final String TAG_AXON_PAYLOAD_TYPE = "axon.message.payload.type";
private static final String TAG_AXON_MESSAGE_NAME = "axon.message.name";

My reasons:

• cleaner look
• Jaeger UI displays them in lower case
  

I just configured Jaeger, but then decided to also print traceId in the application logs.
First, Jaeger has an issue with it: opentracing-contrib/java-spring-jaeger#49

Second, when I use the workaround, I find that only the first log entry contains the traceId and others don't.
I suspect this is due to execution being scattered on different threads.

I would suspect that extending an executor mentioned here would help.