Loading...

XML

Word

Printable

Type: Improvement
Resolution: Done
Priority: Medium
Fix Version/s: None
Affects Version/s: None
Component/s: clustering
Labels:
None

This request is to add context to exceptions that are logged so that troubleshooting is easier.

Example below, notice the exception OptimisticLockFailedException followed with Caused By: "ConflictingModificationAppliedException: Node children was modified by other transaction". It would be very helpful if the Node also contained the path so we know what node had the issue. The example below we were lucky that the application code logged a WARN also, but there are other places where that does not happen. This requires manually looking at the log to find the context which is error prone.

We are adding tooling to look for new exceptions in the tests and this will help with that tooling to identify the bugs for known issues and to create new bugs.

https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netvirt-csit-1node-openstack-queens-upstream-stateful-fluorine/470/odl_1/odl1_karaf.log.gz

2018-05-19T06:16:04,756 | WARN  | opendaylight-cluster-data-shard-dispatcher-251 | ShardDataTree                    | 246 - org.opendaylight.controller.sal-distributed-datastore - 1.8.0.SNAPSHOT | member-1-shard-default-operational: Store Tx member-1-datastore-operational-fe-0-txn-48385-0: Conflicting modification for path /(urn:opendaylight:netvirt:l3vpn?revision=2013-09-11)vpn-instance-op-data/vpn-instance-op-data-entry/vpn-instance-op-data-entry[{(urn:opendaylight:netvirt:l3vpn?revision=2013-09-11)vrf-id=051870b4-8979-4acc-a270-c154c758c6e4}]/vpn-to-dpn-list/vpn-to-dpn-list[{(urn:opendaylight:netvirt:l3vpn?revision=2013-09-11)dpnId=185202793875339}].
2018-05-19T06:16:04,762 | INFO  | ForkJoinPool-1-worker-6 | UpdateIdEntryJob                 | 267 - org.opendaylight.genius.idmanager-impl - 0.5.0.SNAPSHOT | Updated id entry with idValues [], idKey 051870b4-8979-4acc-a270-c154c758c6e4.10.0.0.2/32, pool vpnservices.169781785
2018-05-19T06:16:04,757 | ERROR | opendaylight-cluster-data-akka.actor.default-dispatcher-262 | LocalThreePhaseCommitCohort      | 246 - org.opendaylight.controller.sal-distributed-datastore - 1.8.0.SNAPSHOT | Failed to prepare transaction member-1-datastore-operational-fe-0-txn-48385-0 on backend
org.opendaylight.mdsal.common.api.OptimisticLockFailedException: Optimistic lock failed.
	at org.opendaylight.controller.cluster.datastore.ShardDataTree.lambda$processNextPendingTransaction$0(ShardDataTree.java:740) ~[246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.ShardDataTree.processNextPending(ShardDataTree.java:778) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.ShardDataTree.processNextPendingTransaction(ShardDataTree.java:725) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.ShardDataTree.startCanCommit(ShardDataTree.java:808) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.SimpleShardDataTreeCohort.canCommit(SimpleShardDataTreeCohort.java:84) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.CohortEntry.canCommit(CohortEntry.java:97) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.ShardCommitCoordinator.handleCanCommit(ShardCommitCoordinator.java:236) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.ShardCommitCoordinator.handleReadyLocalTransaction(ShardCommitCoordinator.java:200) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.Shard.handleReadyLocalTransaction(Shard.java:731) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.datastore.Shard.handleNonRaftCommand(Shard.java:333) [246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.raft.RaftActor.handleCommand(RaftActor.java:270) [230:org.opendaylight.controller.sal-akka-raft:1.8.0.SNAPSHOT]
	at org.opendaylight.controller.cluster.common.actor.AbstractUntypedPersistentActor.onReceiveCommand(AbstractUntypedPersistentActor.java:44) [238:org.opendaylight.controller.sal-clustering-commons:1.8.0.SNAPSHOT]
	at akka.persistence.UntypedPersistentActor.onReceive(PersistentActor.scala:275) [43:com.typesafe.akka.persistence:2.5.11]
	at org.opendaylight.controller.cluster.common.actor.MeteringBehavior.apply(MeteringBehavior.java:104) [238:org.opendaylight.controller.sal-clustering-commons:1.8.0.SNAPSHOT]
	at akka.actor.ActorCell$$anonfun$become$1.applyOrElse(ActorCell.scala:608) [40:com.typesafe.akka.actor:2.5.11]
	at akka.actor.Actor.aroundReceive(Actor.scala:517) [40:com.typesafe.akka.actor:2.5.11]
	at akka.actor.Actor.aroundReceive$(Actor.scala:515) [40:com.typesafe.akka.actor:2.5.11]
	at akka.persistence.UntypedPersistentActor.akka$persistence$Eventsourced$$super$aroundReceive(PersistentActor.scala:273) [43:com.typesafe.akka.persistence:2.5.11]
	at akka.persistence.Eventsourced$$anon$1.stateReceive(Eventsourced.scala:691) [43:com.typesafe.akka.persistence:2.5.11]
	at akka.persistence.Eventsourced.aroundReceive(Eventsourced.scala:192) [43:com.typesafe.akka.persistence:2.5.11]
	at akka.persistence.Eventsourced.aroundReceive$(Eventsourced.scala:191) [43:com.typesafe.akka.persistence:2.5.11]
	at akka.persistence.UntypedPersistentActor.aroundReceive(PersistentActor.scala:273) [43:com.typesafe.akka.persistence:2.5.11]
	at akka.actor.ActorCell.receiveMessage(ActorCell.scala:590) [40:com.typesafe.akka.actor:2.5.11]
	at akka.actor.ActorCell.invoke(ActorCell.scala:559) [40:com.typesafe.akka.actor:2.5.11]
	at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:257) [40:com.typesafe.akka.actor:2.5.11]
	at akka.dispatch.Mailbox.run(Mailbox.scala:224) [40:com.typesafe.akka.actor:2.5.11]
	at akka.dispatch.Mailbox.exec(Mailbox.scala:234) [40:com.typesafe.akka.actor:2.5.11]
	at akka.dispatch.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260) [40:com.typesafe.akka.actor:2.5.11]
	at akka.dispatch.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339) [40:com.typesafe.akka.actor:2.5.11]
	at akka.dispatch.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979) [40:com.typesafe.akka.actor:2.5.11]
	at akka.dispatch.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107) [40:com.typesafe.akka.actor:2.5.11]
Caused by: org.opendaylight.yangtools.yang.data.api.schema.tree.ConflictingModificationAppliedException: Node children was modified by other transaction
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkConflicting(SchemaAwareApplyOperation.java:81) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkNotConflicting(SchemaAwareApplyOperation.java:114) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkWriteApplicable(SchemaAwareApplyOperation.java:178) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:135) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkChildPreconditions(AbstractNodeContainerModificationStrategy.java:307) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkMergeApplicable(AbstractNodeContainerModificationStrategy.java:315) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:138) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkChildPreconditions(AbstractNodeContainerModificationStrategy.java:307) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkMergeApplicable(AbstractNodeContainerModificationStrategy.java:315) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:138) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkChildPreconditions(AbstractNodeContainerModificationStrategy.java:307) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkMergeApplicable(AbstractNodeContainerModificationStrategy.java:315) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:138) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkChildPreconditions(AbstractNodeContainerModificationStrategy.java:307) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkMergeApplicable(AbstractNodeContainerModificationStrategy.java:315) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:138) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.StructuralContainerModificationStrategy.checkApplicable(StructuralContainerModificationStrategy.java:101) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkChildPreconditions(AbstractNodeContainerModificationStrategy.java:307) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkTouchApplicable(AbstractNodeContainerModificationStrategy.java:290) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:132) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.RootModificationApplyOperation.checkApplicable(RootModificationApplyOperation.java:72) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractDataTreeTip.validate(AbstractDataTreeTip.java:35) ~[446:org.opendaylight.yangtools.yang-data-impl:2.0.3]
	at org.opendaylight.controller.cluster.datastore.ShardDataTree.lambda$processNextPendingTransaction$0(ShardDataTree.java:732) ~[246:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
	... 30 more

Assignee:: Unassigned

Reporter:: Sam Hague

Votes:: 0 Vote for this issue

Watchers:: 6 Start watching this issue

Created:: 19/May/18 4:27 PM

Updated:: 22/May/18 12:17 PM

Resolved:: 22/May/18 12:17 PM

Details

Description

Attachments

Activity

People

Dates