Too many OpenTelemetry spans: One for each and every SubscribingEventProcessor

Hi there! I’m integrating OpenTelemetry in an application using Axon 4.9.3. Traces properly propagate throughout this application, including the Axon part. But in such a trace, I see too many spans.

  • Our Spring Boot 3.3.5 application is decomposed into multiple modules (i.e. jar files build using maven)
  • 13 of those modules declare Axon @EventHandler methods.
  • But only 1 module declares an @EventHandler method for event ChargingStationUpdateLastSeenEvent.
  • I would therefore expect to see only 1 #bc815789df655335 EventProcessor.process(ChargingStationUpdateLastSeenEvent) span.
  • Instead I’m seeing 13:
    • 1 for my declared event handler implementation.
    • And 12 for… I don’t know.

How can I suppress span creation for those 12 other cases. These spans result in lot’s of noise…

Debugging showed the Axon internals resulting in > 1 span.

And this is my one-and-only event handler:

PS: Sorry for the multiple posts but I was not allowed to add more than one image in my initial post…

First and foremost, @Niels_de_Feijter, welcome to the forum!
Secondly:

No worries, perfectly fine to do multiple posts. All that’s needed to get the point across if you ask me :slight_smile:


Now, on to the question.
What you’re seeing, is that Axon Framework’s StreamingEventProcessor will read all events that it reads from the event store. Regardless of whether there’s an event handler for the given event.

The EventProcessor will process a batch of events, and it’s there where the SpanFactory is invoked to set a span. The EventProcessor will provide events to the so-called EventHandlerInvoker; this is the wrapper class around your class containing the event handling methods. It’s the EventHandlerInvoker that will check if there’s an event handler for the given event, as you can see here.

Thus, sadly, the span creation occurs before the actual handling of the event. Hence, this noise is…well, just there.

There is a way to filter some of these, though, which would be done by filtering the events from the event store. This is something the TrackingEventProcessor implementation can do whenever there are no event handlers for a given event type present within that event processor.
However, for this to work, the “Event Stream” implementation should support that feature. Right now, only an event stream coming from Axon Server does so.

Note that even when using Axon Server and Event Processors telling the stream to not give certain events, it will still give them from time to time. By default after every 1000 events. This is done to ensure that, if event handlers are added to the processor at a later stage, the known set of filtered events can be updated.


Long story short, the added spans with name EventProcessor.process will thus exist always, with one caveat: If you are using a TrackingEventProcessor! The PooledStreamingEventProcessor (PSEP, for short) does an earlier validation if there are event handlers for a given event. Hence, if you switch your processors to the PSEP, you should eliminate a lot of your logging.

Let us know whether that solves your issue, @Niels_de_Feijter!

Hi Steven, thanks for your extensive response!

If I understand you correctly, the Axon Server is a requirement for your solution to work. Unfortunately the software I’m currently working on does not use the Axon Server (it uses the AsynchronousCommandBus instead).

For now we’ll live with the noise… Unless you know of an alternative solution :slight_smile: .

For the longer term we are considering the Axon Server to make our software more scalable, but that’s still to be determined.

Sorry, Niels, I think I made my reply a little too long-winded :sweat_smile:
What should already help is changing the default StreamingEventProcessor to a PooledStreamingEventProcessor.

You could switch that default by adding the following ConfigurerModule to your application context:

@Bean
public ConfigurerModule psepMode() {
    return configurer -> configurer.eventProcessing().usingPooledStreamingEventProcessors();
}

Please give that a try an let me know whether it solves your predicament.

That’s nice to hear; thanks for sharing! Pretty sure you know where to find us if you need any help or guidance with that :slight_smile:

Hi Steven,

Thank you for the additional details! I’ll give it a try and keep you updated!

Hi Steven,

I’ve added the bean you suggested but it is not compatible with the SimpleEventBus we are using. This is our Axon/Spring config:

@AutoConfiguration
@EnableCaching
@EnableTransactionManagement
public class AxonAutoConfiguration {
    @Bean
    public CorrelationDataProvider correlationDataProvider() {
        return new DomainCorrelationDataProvider();
    }

    @Bean
    public CommandBus commandBus(TransactionManager txManager, SpringAxonConfiguration axonConfiguration,
            DuplicateCommandHandlerResolver duplicateCommandHandlerResolver, SpanFactory spanFactory) {
        AsynchronousCommandBus commandBus =
                AsynchronousCommandBus.builder()
                        .spanFactory(spanFactory)
                        .transactionManager(txManager)
                        .duplicateCommandHandlerResolver(duplicateCommandHandlerResolver)
                        .messageMonitor(axonConfiguration.getObject().messageMonitor(CommandBus.class, "commandBus"))
                        .build();

        commandBus.registerHandlerInterceptor(
                new CorrelationDataInterceptor<>(axonConfiguration.getObject().correlationDataProviders())
        );

        return commandBus;
    }

    @Primary
    @Bean
    public EventBus eventBus() {
        return SimpleEventBus.builder().build();
    }

    @Bean
    public ConfigurerModule psepMode() {
        return configurer -> configurer.eventProcessing().usingPooledStreamingEventProcessors();
    }

    @Bean
    public SpanFactory axonSpanFactory(@NonNull final OpenTelemetry openTelemetry) {
        return OpenTelemetrySpanFactory
                .builder()
                .contextPropagators(openTelemetry.getPropagators().getTextMapPropagator())
                .tracer(openTelemetry.getTracer("AxonFramework"))
                .addSpanAttributeProviders(List.of(
                        new AggregateIdentifierSpanAttributesProvider(),
                        new MessageIdSpanAttributesProvider(),
                        new MessageNameSpanAttributesProvider(),
                        new MessageTypeSpanAttributesProvider(),
                        new MetadataSpanAttributesProvider(),
                        new PayloadTypeSpanAttributesProvider()
                ))
                .textMapGetter(MetadataContextGetter.INSTANCE)
                .textMapSetter(MetadataContextSetter.INSTANCE)
                .build();
    }
}

But the SimpleEventBus does not seem to be compatible with the PooledStreamingEventProcessor you suggested, see this stack trace:

java.util.concurrent.ExecutionException: java.lang.ClassCastException: class org.axonframework.eventhandling.SimpleEventBus cannot be cast to class org.axonframework.messaging.StreamableMessageSource (org.axonframework.eventhandling.SimpleEventBus and org.axonframework.messaging.StreamableMessageSource are in unnamed module of loader 'app')
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2096) ~[na:na]
	at org.axonframework.config.DefaultConfigurer.invokeLifecycleHandlers(DefaultConfigurer.java:1060) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.DefaultConfigurer.invokeStartHandlers(DefaultConfigurer.java:1004) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.DefaultConfigurer$ConfigurationImpl.start(DefaultConfigurer.java:1156) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.spring.config.SpringAxonConfiguration.start(SpringAxonConfiguration.java:76) ~[axon-spring-4.9.3.jar:4.9.3]
	at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:285) ~[spring-context-6.1.14.jar:6.1.14]
	at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:472) ~[spring-context-6.1.14.jar:6.1.14]
	at java.base/java.lang.Iterable.forEach(Iterable.java:75) ~[na:na]
	at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:257) ~[spring-context-6.1.14.jar:6.1.14]
	at org.springframework.context.support.DefaultLifecycleProcessor.onRefresh(DefaultLifecycleProcessor.java:202) ~[spring-context-6.1.14.jar:6.1.14]
	at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:990) ~[spring-context-6.1.14.jar:6.1.14]
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:628) ~[spring-context-6.1.14.jar:6.1.14]
	at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146) ~[spring-boot-3.3.5.jar:3.3.5]
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754) ~[spring-boot-3.3.5.jar:3.3.5]
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:456) ~[spring-boot-3.3.5.jar:3.3.5]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:335) ~[spring-boot-3.3.5.jar:3.3.5]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1363) ~[spring-boot-3.3.5.jar:3.3.5]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1352) ~[spring-boot-3.3.5.jar:3.3.5]
	at io.motown.sample.simple.Application.main(Application.java:23) ~[classes/:na]
Caused by: java.lang.ClassCastException: class org.axonframework.eventhandling.SimpleEventBus cannot be cast to class org.axonframework.messaging.StreamableMessageSource (org.axonframework.eventhandling.SimpleEventBus and org.axonframework.messaging.StreamableMessageSource are in unnamed module of loader 'app')
	at org.axonframework.config.EventProcessingModule.lambda$new$24(EventProcessingModule.java:189) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.Component.get(Component.java:85) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.EventProcessingModule.lambda$usingPooledStreamingEventProcessors$59(EventProcessingModule.java:691) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.EventProcessingModule.buildEventProcessor(EventProcessingModule.java:401) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.EventProcessingModule.lambda$null$28(EventProcessingModule.java:238) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.Component.get(Component.java:85) ~[axon-configuration-4.9.3.jar:4.9.3]
	at java.base/java.util.HashMap$Values.forEach(HashMap.java:1065) ~[na:na]
	at org.axonframework.config.EventProcessingModule.initializeProcessors(EventProcessingModule.java:243) ~[axon-configuration-4.9.3.jar:4.9.3]
	at org.axonframework.config.LifecycleOperations.lambda$onStart$0(LifecycleOperations.java:62) ~[axon-configuration-4.9.3.jar:4.9.3]
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[na:na]
	at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:992) ~[na:na]
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[na:na]
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[na:na]
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921) ~[na:na]
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[na:na]
	at java.base/java.util.stream.ReferencePipeline.reduce(ReferencePipeline.java:662) ~[na:na]
	at org.axonframework.config.DefaultConfigurer.invokeLifecycleHandlers(DefaultConfigurer.java:1058) ~[axon-configuration-4.9.3.jar:4.9.3]
	... 17 common frames omitted

Am I still missing something to get it going without the Axon Server?