Axon Server failed starting up after upgrade to 2025.1.1

matdue-fletec · July 3, 2025, 3:33pm

Hi,

I’m running a standalone Axon Server using Docker compose. After upgrading from 2024.2.4 to 2025.1.1, Axon Server does not start up completely:

     _                     ____
    / \   __  _____  _ __ / ___|  ___ _ ____   _____ _ __
   / _ \  \ \/ / _ \| '_ \\___ \ / _ \ '__\ \ / / _ \ '__|
  / ___ \  >  < (_) | | | |___) |  __/ |   \ V /  __/ |
 /_/   \_\/_/\_\___/|_| |_|____/ \___|_|    \_/ \___|_|
 2025.1.1                      Powered by AxonIQ

2025-07-03T13:13:03.677Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.AxonServer          : Starting AxonServer using Java 17.0.15 with PID 1 (/axonserver/axonserver.jar started by root in /axonserver)
2025-07-03T13:13:03.679Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.AxonServer          : No active profile set, falling back to 1 default profile: "default"
2025-07-03T13:13:05.507Z  INFO 1 --- [Axon Server] [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port 8024 (http)
2025-07-03T13:13:05.566Z  INFO 1 --- [Axon Server] [           main] A.i.a.a.c.MessagingPlatformConfiguration : Configuration initialized with SSL DISABLED and access control DISABLED.
2025-07-03T13:13:07.958Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.AxonServer          : Axon Server version 2025.1.1
2025-07-03T13:13:10.849Z  WARN 1 --- [Axon Server] [           main] i.m.core.instrument.MeterRegistry        : This Gauge has been already registered (MeterId{name='disk.free', tags=[tag(axonserver=axonserver),tag(path=/)]}), the registration will be ignored. Note that subsequent logs will be logged at debug level.
2025-07-03T13:13:11.138Z  INFO 1 --- [Axon Server] [           main] i.a.a.e.c.i.MessagingClusterServer       : Axon Server Cluster Server started on port: 8224 - no SSL
2025-07-03T13:13:11.164Z  INFO 1 --- [Axon Server] [           main] i.a.a.c.r.file.PrimaryLogEntryStore      : _admin: Initializing log
2025-07-03T13:13:11.165Z  INFO 1 --- [Axon Server] [           main] i.a.a.c.r.file.PrimaryLogEntryStore      : _admin: File for segment 1 does not exist. Creating new file with size of 16777216.
2025-07-03T13:13:11.189Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.cluster.RaftNode    : _admin in term 242: Updating state from null to IdleState (Node initialized.)
2025-07-03T13:13:11.192Z  INFO 1 --- [Axon Server] [           main] i.a.a.c.r.file.PrimaryLogEntryStore      : default: Initializing log
2025-07-03T13:13:11.193Z  INFO 1 --- [Axon Server] [           main] i.a.a.c.r.file.PrimaryLogEntryStore      : default: File for segment 1 does not exist. Creating new file with size of 16777216.
2025-07-03T13:13:11.194Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.cluster.RaftNode    : default in term 242: Updating state from null to IdleState (Node initialized.)
2025-07-03T13:13:11.195Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.cluster.RaftNode    : _admin in term 242: Starting the node...
2025-07-03T13:13:11.195Z ERROR 1 --- [Axon Server] [           main] io.axoniq.axonserver.cluster.RaftNode    : _admin in term 242: Last applied index 1 is higher than last log index 0
2025-07-03T13:13:11.195Z  WARN 1 --- [Axon Server] [           main] i.a.a.e.replication.GrpcRaftController   : _admin: Failed to initialize replicationGroup

java.lang.NullPointerException: Cannot invoke "java.util.function.LongFunction.apply(long)" because "<local1>.D" is null
	at io.axoniq.axonserver.cluster.LogEntryProcessor.m(ogb:19) ~[!/:na]
	at io.axoniq.axonserver.cluster.LogEntryProcessor.H(ogb:48) ~[!/:na]
	at io.axoniq.axonserver.cluster.RaftNode.f(zab:271) ~[!/:na]
	at io.axoniq.axonserver.cluster.RaftGroup.start(bd:219) ~[!/:na]
	at io.axoniq.axonserver.enterprise.replication.GrpcRaftGroup.start(eva:237) ~[!/:na]
	at io.axoniq.axonserver.enterprise.replication.GrpcRaftController.f(vsa:96) ~[!/:na]
	at java.base/java.lang.Iterable.forEach(Iterable.java:75) ~[na:na]
	at io.axoniq.axonserver.enterprise.replication.GrpcRaftController.start(vsa:219) ~[!/:na]
	at org.springframework.context.support.DefaultLifecycleProcessor.doStart(DefaultLifecycleProcessor.java:286) ~[spring-context-6.1.21.jar!/:6.1.21]
	at org.springframework.context.support.DefaultLifecycleProcessor$LifecycleGroup.start(DefaultLifecycleProcessor.java:473) ~[spring-context-6.1.21.jar!/:6.1.21]
	at java.base/java.lang.Iterable.forEach(Iterable.java:75) ~[na:na]
	at org.springframework.context.support.DefaultLifecycleProcessor.startBeans(DefaultLifecycleProcessor.java:258) ~[spring-context-6.1.21.jar!/:6.1.21]
	at org.springframework.context.support.DefaultLifecycleProcessor.onRefresh(DefaultLifecycleProcessor.java:203) ~[spring-context-6.1.21.jar!/:6.1.21]
	at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:990) ~[spring-context-6.1.21.jar!/:6.1.21]
	at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:628) ~[spring-context-6.1.21.jar!/:6.1.21]
	at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:146) ~[spring-boot-3.3.13.jar!/:3.3.13]
	at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754) ~[spring-boot-3.3.13.jar!/:3.3.13]
	at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:456) ~[spring-boot-3.3.13.jar!/:3.3.13]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:335) ~[spring-boot-3.3.13.jar!/:3.3.13]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1363) ~[spring-boot-3.3.13.jar!/:3.3.13]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1352) ~[spring-boot-3.3.13.jar!/:3.3.13]
	at io.axoniq.axonserver.AxonServer.main(a:225) ~[!/:na]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
	at java.base/java.lang.reflect.Method.invoke(Method.java:569) ~[na:na]
	at org.springframework.boot.loader.launch.Launcher.launch(Launcher.java:102) ~[axonserver.jar:na]
	at org.springframework.boot.loader.launch.Launcher.launch(Launcher.java:64) ~[axonserver.jar:na]
	at org.springframework.boot.loader.launch.PropertiesLauncher.main(PropertiesLauncher.java:580) ~[axonserver.jar:na]

2025-07-03T13:13:11.260Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.grpc.Gateway        : Axon Server Gateway started on port: 8124 - no SSL
2025-07-03T13:13:11.280Z  INFO 1 --- [Axon Server] [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 8024 (http) with context path '/'
2025-07-03T13:13:11.303Z  INFO 1 --- [Axon Server] [           main] io.axoniq.axonserver.AxonServer          : Started AxonServer in 7.92 seconds (process running for 8.213)
2025-07-03T13:13:11.489Z  INFO 1 --- [Axon Server] [task-scheduler2] i.a.a.l.file.WritableFileStorageTier     : default-EVENT: Index on disk is up to date
2025-07-03T13:13:11.491Z  INFO 1 --- [Axon Server] [task-scheduler2] i.a.a.l.file.WritableFileStorageTier     : default-EVENT: Opening file ./events/default/00000000000004572864.events
2025-07-03T13:13:11.567Z  INFO 1 --- [Axon Server] [task-scheduler2] i.a.a.l.file.WritableFileStorageTier     : default-EVENT: Segments initialized
2025-07-03T13:13:12.359Z  INFO 1 --- [Axon Server] [task-scheduler2] i.a.a.l.file.WritableFileStorageTier     : default-SNAPSHOT: Index on disk is up to date
2025-07-03T13:13:12.360Z  INFO 1 --- [Axon Server] [task-scheduler2] i.a.a.l.file.WritableFileStorageTier     : default-SNAPSHOT: Opening file ./events/default/00000000000000000000.snapshots
2025-07-03T13:13:12.360Z  INFO 1 --- [Axon Server] [task-scheduler2] i.a.a.l.file.WritableFileStorageTier     : default-SNAPSHOT: Segments initialized
2025-07-03T13:13:12.361Z  INFO 1 --- [Axon Server] [task-scheduler2] io.axoniq.axonserver.cluster.RaftNode    : default in term 242: Starting the node...
2025-07-03T13:13:12.362Z ERROR 1 --- [Axon Server] [task-scheduler2] io.axoniq.axonserver.cluster.RaftNode    : default in term 242: Last applied index 1 is higher than last log index 0
2025-07-03T13:13:12.362Z  INFO 1 --- [Axon Server] [task-scheduler2] io.axoniq.axonserver.cluster.RaftNode    : default in term 242: Updating state from IdleState to FatalState (Force to fatal state)

There are no further log entries. Axon Server’s web interface works, but querying events, for example, is not possible (didn’t take a note of the error message, something about leader node).

Any subsequent start is successful.

Upgrading from 2024.2.4 to 2025.0.2 works fine, while upgrading afterwards to 2025.1.1 fails as described above. Again, any subsequent start is successful.

Is this something to worry about? Is it just an upgrade hiccup?

Best regards,
Matthias

Marc_Gathier · July 4, 2025, 6:41am

Hi Matthias,
In the logging it shows the following error:

2025-07-03T13:13:12.362Z ERROR 1 — [Axon Server] [task-scheduler2] io.axoniq.axonserver.cluster.RaftNode : default in term 242: Last applied index 1 is higher than last log index 0

This indicates that the replication logs were lost during the upgrade, which causes the issue when restarting with the latest version. The replication logs are stored in the volume mounted at “/axonserver/log”, and should be retained.
The latest version is more sensitive to missing log files than the previous one; this is why the error shows up after this upgrade and not after the previous upgrade.

Marc

Marc_Gathier · July 4, 2025, 6:53am

One addition, after a restart Axon Server continues to work normally.

matdue-fletec · July 4, 2025, 12:13pm

That’s it, thanks! After fixing Docker compose file by adding the missing volume for “/axonserver/log”, upgrading works like a charm.