Unexpected event handling logic by Aggregate in Axon QuickStart

I was playing with Axon and noticed this behaviour which I cannot explain…

It is likely intentional (and then it means I have insufficient understanding of the CQRS/ES) or something unintentional - misconfiguration done by me or even an unlikely bug in Axon.

To simplify the case, I was able to reproduce the behaviour in example based on Axon QuickStart - see these sources:

https://github.com/uvsmtid/incubator/tree/5a2f3a239da62f380493ea6dd03a67d63ba63eaa/code_samples/axon-examples/axon-quickstart-spring

Build and run the example:

mvn clean install

mvn exec:java -Dexec.mainClass=“com.spectlog.axon.quickstart.ToDoItemRunner”

When the program is executed the output is the following (#comments by me):

1. Create

As expected: Creation command, Creation event for aggregate, Creation event for other handlers.

ctor: 187550194: ToDoItem: CreateToDoItemCommand: 08c7869d-9afb-4ac4-ae93-88a34e2cbc5d

fnct: 187550194: ToDoItem: ToDoItemCreatedEvent: 08c7869d-9afb-4ac4-ae93-88a34e2cbc5d

hndl: 1956060028: ToDoEventHandler: ToDoItemCreatedEvent: 08c7869d-9afb-4ac4-ae93-88a34e2cbc5d

2. Mark

# Why the ToDoItemCreatedEvent is processed by aggregate again?

fnct: 187550194: ToDoItem: ToDoItemCreatedEvent: 08c7869d-9afb-4ac4-ae93-88a34e2cbc5d

The rest is as expected: Completion command, Completion event handlers (aggregate does not have handler for ToDoItemCompletedEvent).

fnct: 187550194: ToDoItem: MarkCompletedCommand: 08c7869d-9afb-4ac4-ae93-88a34e2cbc5d

hndl: 1956060028: ToDoEventHandler: ToDoItemCompletedEvent: 08c7869d-9afb-4ac4-ae93-88a34e2cbc5d

What puzzles me is the second invocation of event handler for ToDoItemCreatedEvent by aggregate in response to MarkCompletedCommand.

Isn’t aggregate supposed to be already constructed in response to CreateToDoItemCommand?

I’ve compared stack traces (below) - based on the starting line numbers:

  • left = 1st case = in response to CreateToDoItemCommand

  • right = 2nd case = in response to MarkCompletedCommand

Both stacks end at handling of ToDoItemCreatedEvent by ToDoItem aggregate but have different middle part:

Why is there the 2nd case?

I can see that the second stack tries to loadAggregate.

Do I understand it correctly that Axon tries to reconstruct aggregate from event source?

It seems unnecessary if the aggregate has just been created (and, therefore, should be considered as loaded).

More info to the first post…

If I slightly extend the example and add additional MarkCompletedCommand for the same aggregate id (and add corresponding handler for aggregate + logging), then it becomes clearly visible that every newly command results full reload of aggregate from event store - all events are re-applied on every new command.

OUTPUT (blank lines added by me for readability and unexpected re-played events are highlighted):

ctor: 1600742994: ToDoItem: CreateToDoItemCommand: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCreatedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
hndl: 1193075494: ToDoEventHandler: ToDoItemCreatedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc

fnct: 1600742994: ToDoItem: ToDoItemCreatedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: MarkCompletedCommand: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
hndl: 1193075494: ToDoEventHandler: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc

fnct: 1600742994: ToDoItem: ToDoItemCreatedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: MarkCompletedCommand: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
hndl: 1193075494: ToDoEventHandler: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc

fnct: 1600742994: ToDoItem: ToDoItemCreatedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: MarkCompletedCommand: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
hndl: 1193075494: ToDoEventHandler: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc

fnct: 1600742994: ToDoItem: ToDoItemCreatedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: MarkCompletedCommand: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
hndl: 1193075494: ToDoEventHandler: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc

fnct: 1600742994: ToDoItem: ToDoItemCreatedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: MarkCompletedCommand: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
fnct: 1600742994: ToDoItem: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc
hndl: 1193075494: ToDoEventHandler: ToDoItemCompletedEvent: 99e0b61c-2699-4ae4-8d25-fc6839cc5fcc

PATCH:

diff --git a/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/ToDoItemRunner.java b/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/ToDoItemRunner.java

index b74b045…c1e25ab 100644

— a/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/ToDoItemRunner.java

+++ b/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/ToDoItemRunner.java

@@ -27,5 +27,9 @@ public class ToDoItemRunner {

final String itemId = UUID.randomUUID().toString();

commandGateway.send(new CreateToDoItemCommand(itemId, “Need to do this”));

commandGateway.send(new MarkCompletedCommand(itemId));

  • commandGateway.send(new MarkCompletedCommand(itemId));

  • commandGateway.send(new MarkCompletedCommand(itemId));

  • commandGateway.send(new MarkCompletedCommand(itemId));

  • commandGateway.send(new MarkCompletedCommand(itemId));

}

}

diff --git a/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/aggregates/ToDoItem.java b/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/aggregates/ToDoItem.java

index 72919e7…6445d38 100644

— a/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/aggregates/ToDoItem.java

+++ b/code_samples/axon-examples/axon-quickstart-spring/src/main/java/com/spectlog/axon/quickstart/aggregates/ToDoItem.java

@@ -41,4 +41,10 @@ public class ToDoItem extends AbstractAnnotatedAggregateRoot {

this.id = event.getTodoId();

}

  • @EventHandler

  • public void onToDoItemCompleted(final ToDoItemCompletedEvent event) {

  • System.out.println("fnct: " + this.getClass().hashCode() + ": " + this.getClass().getSimpleName() + ": " + event.getClass().getSimpleName() + ": " + event.getTodoId());

  • this.id = event.getTodoId();

  • }

}

Obviously, Axon tries to replay all events and reconstruct aggregate.
But it does it on every new command handled by aggregate.
I understand that it should not happen when framework is setup properly.
Am I missing something trivial?

Hi Alexey,

That behavior is intentional. The aggregate in your example is event sourced which means its state is rebuild from events each time it is loaded to handle a command.

This is indeed configurable. Aggregates can be also be stored as JPA entities for example.

The main advantage of using event sourcing is that it gives you an audit trail of state changes of your application. To prevent reloading of all events published by an aggregate each time it is loaded Axon provides 2 mechanisms. First of all, it is possible to let Axon create snapshots of your aggregate after every X events. In that case when an aggregate is loaded only the snapshot + events since the snapshot need to be loaded. 2) It is also possible to cache the aggregate state preventing any reloading of aggregates. This is particularly useful if your aggregate is handling many commands in quick succession.

Best,
Rene

Rene, thank you! It’s very informative.

Now, when I know, I don’t understand why I rejected idea that aggregate could always be reloaded from event store.
There is at least mathematical beauty in it. And assuming that writes (commands) are not often per aggregate, this indeed sounds like reasonable default.

JPA, caches, snapshots… I haven’t broken them in my hands yet. Thanks for directions. If anything, I’ll post on a different topic.