NPE during Karaf shutdown

Description

Observed here: https://s3-logs.opendaylight.org/logs/releng/vex-yul-odl-jenkins-1/aaa-maven-merge-0.18.x/196/features/odl-aaa-encryption-service/target/SFT/karaf.log.gz

2024-07-30T19:38:05,458 | INFO | Framework stop - Equinox Container: e097eb7e-494b-4124-9b1b-f0fdad783d0d | OSGiActorSystemProvider | 137 - org.opendaylight.controller.sal-distributed-datastore - 8.0.6 | Actor System provider stopping 2024-07-30T19:38:05,458 | INFO | Framework stop - Equinox Container: e097eb7e-494b-4124-9b1b-f0fdad783d0d | ActorSystemProviderImpl | 137 - org.opendaylight.controller.sal-distributed-datastore - 8.0.6 | Shutting down ActorSystem 2024-07-30T19:38:05,454 | ERROR | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | OneForOneStrategy | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Cannot invoke "org.opendaylight.controller.cluster.access.client.AbstractClientActorBehavior.persistenceId()" because "this.currentBehavior" is null java.lang.NullPointerException: Cannot invoke "org.opendaylight.controller.cluster.access.client.AbstractClientActorBehavior.persistenceId()" because "this.currentBehavior" is null at org.opendaylight.controller.cluster.access.client.AbstractClientActor.persistenceId(AbstractClientActor.java:31) ~[bundleFile:?] at org.opendaylight.controller.cluster.access.client.AbstractClientActor.onReceiveCommand(AbstractClientActor.java:76) ~[bundleFile:?] at akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:24) ~[bundleFile:?] at akka.japi.pf.UnitCaseStatement.apply(CaseStatements.scala:20) ~[bundleFile:?] at scala.PartialFunction.applyOrElse(PartialFunction.scala:214) ~[bundleFile:?] at scala.PartialFunction.applyOrElse$(PartialFunction.scala:213) ~[bundleFile:?] at akka.japi.pf.UnitCaseStatement.applyOrElse(CaseStatements.scala:20) ~[bundleFile:?] at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:269) ~[bundleFile:?] at akka.actor.Actor.aroundReceive(Actor.scala:537) ~[bundleFile:?] at akka.actor.Actor.aroundReceive$(Actor.scala:535) ~[bundleFile:?] at akka.persistence.AbstractPersistentActor.akka$persistence$Eventsourced$$super$aroundReceive(PersistentActor.scala:295) ~[bundleFile:?] at akka.persistence.Eventsourced$$anon$4.stateReceive(Eventsourced.scala:917) ~[bundleFile:?] at akka.persistence.Eventsourced.aroundReceive(Eventsourced.scala:245) ~[bundleFile:?] at akka.persistence.Eventsourced.aroundReceive$(Eventsourced.scala:244) ~[bundleFile:?] at akka.persistence.AbstractPersistentActor.aroundReceive(PersistentActor.scala:295) ~[bundleFile:?] at akka.actor.ActorCell.receiveMessage(ActorCell.scala:579) [bundleFile:?] at akka.actor.ActorCell.invoke(ActorCell.scala:547) [bundleFile:?] at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:270) [bundleFile:?] at akka.dispatch.Mailbox.run(Mailbox.scala:231) [bundleFile:?] at akka.dispatch.Mailbox.exec(Mailbox.scala:243) [bundleFile:?] at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) [?:?] at java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) [?:?] at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) [?:?] at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) [?:?] at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) [?:?] 2024-07-30T19:38:05,468 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | RepointableActorRef | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Message [org.opendaylight.controller.cluster.common.actor.ExecuteInSelfMessage] to Actor[akka://opendaylight-cluster-data/user/shardmanager-config#-1942338142] was not delivered. [7] dead letters encountered. If this is not an expected behavior then Actor[akka://opendaylight-cluster-data/user/shardmanager-config#-1942338142] may have terminated unexpectedly. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. 2024-07-30T19:38:05,468 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | RepointableActorRef | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Message [org.opendaylight.controller.cluster.databroker.actors.dds.AbstractDataStoreClientBehavior$$Lambda$1902/0x0000000100de21b0] to Actor[akka://opendaylight-cluster-data/user/$a#-715719560] was not delivered. [8] dead letters encountered. If this is not an expected behavior then Actor[akka://opendaylight-cluster-data/user/$a#-715719560] may have terminated unexpectedly. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. 2024-07-30T19:38:05,468 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | RepointableActorRef | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Message [akka.persistence.RecoveryPermitter$RecoveryPermitGranted$] from Actor[akka://opendaylight-cluster-data/system/recoveryPermitter#-1217163464] to Actor[akka://opendaylight-cluster-data/user/$a#-715719560] was not delivered. [9] dead letters encountered. If this is not an expected behavior then Actor[akka://opendaylight-cluster-data/user/$a#-715719560] may have terminated unexpectedly. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. 2024-07-30T19:38:05,468 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | CoordinatedShutdown | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Running CoordinatedShutdown with reason [ActorSystemTerminateReason] 2024-07-30T19:38:05,469 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | Cluster | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Cluster Node [akka://opendaylight-cluster-data@127.0.0.1:2550] - Marked address [akka://opendaylight-cluster-data@127.0.0.1:2550] as [Leaving] 2024-07-30T19:38:05,472 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-30 | ClusterSingletonManager | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Exited [akka://opendaylight-cluster-data@127.0.0.1:2550]. 2024-07-30T19:38:05,472 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-30 | ClusterSingletonManager | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Oldest observed OldestChanged: [akka://opendaylight-cluster-data@127.0.0.1:2550 -> None] 2024-07-30T19:38:05,473 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-30 | ClusterSingletonManager | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | ClusterSingletonManager state change [Oldest -> WasOldest] 2024-07-30T19:38:06,106 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | ClusterSingletonProxy | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Singleton identified at [akka://opendaylight-cluster-data/system/singletonManagerOwnerSupervisor/OwnerSupervisor] 2024-07-30T19:38:06,113 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-30 | LocalActorRef | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Message [org.opendaylight.controller.eos.akka.owner.supervisor.command.ClearCandidatesResponse] wrapped in [akka.actor.typed.internal.AdaptMessage] to Actor[akka://opendaylight-cluster-data/user/EOSBootstrap/CandidateRegistry#-1063390059] was not delivered. [10] dead letters encountered, no more dead letters will be logged in next [5.000 min]. If this is not an expected behavior then Actor[akka://opendaylight-cluster-data/user/EOSBootstrap/CandidateRegistry#-1063390059] may have terminated unexpectedly. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. 2024-07-30T19:38:06,307 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-30 | Cluster | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Cluster Node [akka://opendaylight-cluster-data@127.0.0.1:2550] - Leader is moving node [akka://opendaylight-cluster-data@127.0.0.1:2550] to [Exiting] 2024-07-30T19:38:06,485 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | ClusterSingletonManager | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Singleton manager stopping singleton actor [akka://opendaylight-cluster-data/system/singletonManagerOwnerSupervisor/OwnerSupervisor] 2024-07-30T19:38:06,486 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | ClusterSingletonManager | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | ClusterSingletonManager state change [WasOldest -> Stopping] 2024-07-30T19:38:06,487 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | ClusterSingletonManager | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Singleton actor [akka://opendaylight-cluster-data/system/singletonManagerOwnerSupervisor/OwnerSupervisor] was terminated 2024-07-30T19:38:06,493 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-30 | Cluster | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Cluster Node [akka://opendaylight-cluster-data@127.0.0.1:2550] - Exiting completed 2024-07-30T19:38:06,494 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | Cluster | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Cluster Node [akka://opendaylight-cluster-data@127.0.0.1:2550] - Shutting down... 2024-07-30T19:38:06,495 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-26 | Cluster | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Cluster Node [akka://opendaylight-cluster-data@127.0.0.1:2550] - Successfully shut down 2024-07-30T19:38:16,529 | WARN | opendaylight-cluster-data-akka.actor.default-dispatcher-23 | CoordinatedShutdown | 130 - org.opendaylight.controller.repackaged-akka - 8.0.6 | Coordinated shutdown phase [actor-system-terminate] timed out after 10000 milliseconds

which leads to SFT hang, eventually timing out.

Environment

None

Activity

Show:
Done

Details

Assignee

Reporter

Labels

Components

Fix versions

Affects versions

Priority

Created July 30, 2024 at 11:49 PM
Updated October 8, 2024 at 5:33 PM
Resolved October 8, 2024 at 5:33 PM