[BGPCEP-645] Race condition when closing Peers and updating routes Created: 14/Mar/17  Updated: 03/Mar/19  Resolved: 15/May/17

Status: Resolved
Project: bgpcep
Component/s: BGP
Affects Version/s: Bugzilla Migration
Fix Version/s: Bugzilla Migration

Type: Bug
Reporter: Claudio David Gasparini Assignee: Claudio David Gasparini
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All

External issue ID: 7976

 Description   

https://logs.opendaylight.org/releng/jenkins092/bgpcep-csit-1node-periodic-bgp-ingest-only-boron/426/archives/log.html.gz

https://logs.opendaylight.org/releng/jenkins092/bgpcep-csit-1node-periodic-bgp-ingest-only-boron/426/archives/odl1_karaf.log.gz

7-03-14 00:34:52,280 | INFO | entLoopGroup-5-9 | AbstractBGPSessionNegotiator | 186 - org.opendaylight.bgpcep.bgp-rib-impl - 0.6.3.SNAPSHOT | BGP Session with peer [id: 0x07ffbb7a, L:/10.29.12.204:1790 - R:/127.0.1.180:17900] established successfully.
2017-03-14 00:34:52,310 | ERROR | lt-dispatcher-24 | TransactionChainProxy | 173 - org.opendaylight.controller.sal-distributed-datastore - 1.4.3.SNAPSHOT | Tx: member-1-datastore-operational-fe-0-chn-12-txn-244947 - ready future failed for previous Tx member-1-datastore-operational-fe-0-chn-12-txn-244947
2017-03-14 00:34:52,311 | WARN | ult-dispatcher-4 | ConcurrentDOMDataBroker | 173 - org.opendaylight.controller.sal-distributed-datastore - 1.4.3.SNAPSHOT | Tx: DOM-CHAIN-11-244949 Error during phase CAN_COMMIT, starting Abort
java.lang.IllegalArgumentException: Metadata not available for modification NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)peer[

{(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)peer-id=bgp://127.0.1.180}

], modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)adj-rib-out=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)adj-rib-out, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)tables=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)tables, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)tables[

{(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)afi=(urn:opendaylight:params:xml:ns:yang:bgp-types?revision=2013-09-19)ipv4-address-family, (urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)safi=(urn:opendaylight:params:xml:ns:yang:bgp-types?revision=2013-09-19)unicast-subsequent-address-family}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)tables[

{(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)afi=(urn:opendaylight:params:xml:ns:yang:bgp-types?revision=2013-09-19)ipv4-address-family, (urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)safi=(urn:opendaylight:params:xml:ns:yang:bgp-types?revision=2013-09-19)unicast-subsequent-address-family}

], modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)routes=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2013-09-25)routes, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-routes=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-routes, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.80/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.80/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.126.48.64/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.126.48.64/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.37.74.208/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.37.74.208/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.96/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.96/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.48/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.48/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.64/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.64/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.126.48.48/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.126.48.48/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.126.48.80/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.126.48.80/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.16/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.16/28}

], modificationType=DELETE, childModification={}], (urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.32/28}

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)ipv4-route[

{(urn:opendaylight:params:xml:ns:yang:bgp-inet?revision=2015-03-05)prefix=8.147.85.32/28}

], modificationType=DELETE, childModification={}]}]}]}]}]}]}]}]
at com.google.common.base.Preconditions.checkArgument(Preconditions.java:145)[38:com.google.guava:18.0.0]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.apply(SchemaAwareApplyOperation.java:198)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.mutateChildren(AbstractNodeContainerModificationStrategy.java:139)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.applyTouch(AbstractNodeContainerModificationStrategy.java:252)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.apply(SchemaAwareApplyOperation.java:200)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.mutateChildren(AbstractNodeContainerModificationStrategy.java:139)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.applyTouch(AbstractNodeContainerModificationStrategy.java:252)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.ListEntryModificationStrategy.applyTouch(ListEntryModificationStrategy.java:55)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.apply(SchemaAwareApplyOperation.java:200)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.mutateChildren(AbstractNodeContainerModificationStrategy.java:139)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.applyTouch(AbstractNodeContainerModificationStrategy.java:252)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.apply(SchemaAwareApplyOperation.java:200)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.mutateChildren(AbstractNodeContainerModificationStrategy.java:139)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.applyTouch(AbstractNodeContainerModificationStrategy.java:252)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.apply(SchemaAwareApplyOperation.java:200)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.StructuralContainerModificationStrategy.apply(StructuralContainerModificationStrategy.java:71)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.mutateChildren(AbstractNodeContainerModificationStrategy.java:139)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.applyTouch(AbstractNodeContainerModificationStrategy.java:252)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.apply(SchemaAwareApplyOperation.java:200)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.RootModificationApplyOperation.apply(RootModificationApplyOperation.java:78)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.InMemoryDataTreeModification.newModification(InMemoryDataTreeModification.java:192)[72:org.opendaylight.yangtools.yang-data-impl:1.0.3.SNAPSHOT]
at org.opendaylight.controller.sal.core.spi.data.SnapshotBackedWriteTransaction.<init>(SnapshotBackedWriteTransaction.java:50)[139:org.opendaylight.controller.sal-core-spi:1.4.3.SNAPSHOT]
at org.opendaylight.controller.sal.core.spi.data.SnapshotBackedReadWriteTransaction.<init>(SnapshotBackedReadWriteTransaction.java:35)[139:org.opendaylight.controller.sal-core-spi:1.4.3.SNAPSHOT]
at org.opendaylight.controller.sal.core.spi.data.AbstractSnapshotBackedTransactionChain.newReadWriteTransaction(AbstractSnapshotBackedTransactionChain.java:143)[139:org.opendaylight.controller.sal-core-spi:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.LocalTransactionChain.newReadWriteTransaction(LocalTransactionChain.java:75)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.AbstractTransactionContextFactory.createLocalTransactionContext(AbstractTransactionContextFactory.java:226)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.AbstractTransactionContextFactory.maybeCreateLocalTransactionContext(AbstractTransactionContextFactory.java:72)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.AbstractTransactionContextFactory.onFindPrimaryShardSuccess(AbstractTransactionContextFactory.java:91)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.AbstractTransactionContextFactory.access$000(AbstractTransactionContextFactory.java:37)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.AbstractTransactionContextFactory$1.onComplete(AbstractTransactionContextFactory.java:133)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.AbstractTransactionContextFactory$1.onComplete(AbstractTransactionContextFactory.java:129)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at akka.dispatch.OnComplete.internal(Future.scala:259)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.OnComplete.internal(Future.scala:256)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:186)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:183)[155:com.typesafe.akka.actor:2.4.7]
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply$mcV$sp(BatchingExecutor.scala:91)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.BatchingExecutor$BlockableBatch$$anonfun$run$1.apply(BatchingExecutor.scala:91)[155:com.typesafe.akka.actor:2.4.7]
at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:72)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:90)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:409)[155:com.typesafe.akka.actor:2.4.7]
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
2017-03-14 00:34:52,328 | ERROR | n-dispatcher-412 | DataTreeChangeListenerActor | 173 - org.opendaylight.controller.sal-distributed-datastore - 1.4.3.SNAPSHOT | Error notifying listener org.opendaylight.protocol.bgp.rib.impl.LocRibWriter@7a802c03
java.lang.IllegalStateException: Transaction chain has failed
at com.google.common.base.Preconditions.checkState(Preconditions.java:173)[38:com.google.guava:18.0.0]
at org.opendaylight.controller.cluster.databroker.DOMBrokerTransactionChain.checkNotFailed(DOMBrokerTransactionChain.java:73)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.databroker.DOMBrokerTransactionChain.submit(DOMBrokerTransactionChain.java:84)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.databroker.AbstractDOMBrokerWriteTransaction.submit(AbstractDOMBrokerWriteTransaction.java:139)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.md.sal.dom.broker.impl.PingPongTransactionChain.processTransaction(PingPongTransactionChain.java:235)[141:org.opendaylight.controller.sal-broker-impl:1.4.3.SNAPSHOT]
at org.opendaylight.controller.md.sal.dom.broker.impl.PingPongTransactionChain.processIfReady(PingPongTransactionChain.java:211)[141:org.opendaylight.controller.sal-broker-impl:1.4.3.SNAPSHOT]
at org.opendaylight.controller.md.sal.dom.broker.impl.PingPongTransactionChain.readyTransaction(PingPongTransactionChain.java:319)[141:org.opendaylight.controller.sal-broker-impl:1.4.3.SNAPSHOT]
at org.opendaylight.controller.md.sal.dom.broker.impl.PingPongTransactionChain$4.submit(PingPongTransactionChain.java:448)[141:org.opendaylight.controller.sal-broker-impl:1.4.3.SNAPSHOT]
at org.opendaylight.protocol.bgp.rib.impl.LocRibWriter.onDataTreeChanged(LocRibWriter.java:167)[186:org.opendaylight.bgpcep.bgp-rib-impl:0.6.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.DataTreeChangeListenerActor.dataChanged(DataTreeChangeListenerActor.java:58)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.DataTreeChangeListenerActor.handleReceive(DataTreeChangeListenerActor.java:40)[173:org.opendaylight.controller.sal-distributed-datastore:1.4.3.SNAPSHOT]
at org.opendaylight.controller.cluster.common.actor.AbstractUntypedActor.onReceive(AbstractUntypedActor.java:26)[167:org.opendaylight.controller.sal-clustering-commons:1.4.3.SNAPSHOT]
at akka.actor.UntypedActor$$anonfun$receive$1.applyOrElse(UntypedActor.scala:165)[155:com.typesafe.akka.actor:2.4.7]
at akka.actor.Actor$class.aroundReceive(Actor.scala:484)[155:com.typesafe.akka.actor:2.4.7]
at akka.actor.UntypedActor.aroundReceive(UntypedActor.scala:95)[155:com.typesafe.akka.actor:2.4.7]
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:526)[155:com.typesafe.akka.actor:2.4.7]
at akka.actor.ActorCell.invoke(ActorCell.scala:495)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:257)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.Mailbox.run(Mailbox.scala:224)[155:com.typesafe.akka.actor:2.4.7]
at akka.dispatch.Mailbox.exec(Mailbox.scala:234)[155:com.typesafe.akka.actor:2.4.7]
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)[151:org.scala-lang.scala-library:2.11.8.v20160304-115712-17

 Comments   
Comment by Milos Fabian [ 15/Mar/17 ]

Reminds me https://bugs.opendaylight.org/show_bug.cgi?id=4488
My theory:
When new peer ("A") connects, it register itself to the "ExportPolicyPeerTracker" (it's shared resource). Before the LocRibWriter gets a data change notification about peer "A", another peer ("B") has disconnected and it's routes are removed from Loc-RIB and from RIB-Outs of other peers (based on peers registered in ExportPolicyPeerTracker). So we are also trying to remove routes from peer "A" RIB-Out, however there no routes.

Simply it is a race condition on shared resource.

Comment by Milos Fabian [ 16/Mar/17 ]

(In reply to Milos Fabian from comment #1)
> Reminds me https://bugs.opendaylight.org/show_bug.cgi?id=4488
> My theory:
> When new peer ("A") connects, it register itself to the
> "ExportPolicyPeerTracker" (it's shared resource). Before the LocRibWriter
> gets a data change notification about peer "A", another peer ("B") has
> disconnected and it's routes are removed from Loc-RIB and from RIB-Outs of
> other peers (based on peers registered in ExportPolicyPeerTracker). So we
> are also trying to remove routes from peer "A" RIB-Out, however there no
> routes.
>
> Simply it is a race condition on shared resource.

This ExportPolicyPeerTracker registration change was done because of https://bugs.opendaylight.org/show_bug.cgi?id=6747
We might consider adding some additional flag to ExportPolicyPeerTracker, set when LocRibWriter discovers a new peer, until that peer is excluded from RIB-Out modification operations.

Comment by Claudio David Gasparini [ 17/Mar/17 ]

(In reply to Milos Fabian from comment #2)
> (In reply to Milos Fabian from comment #1)
> > Reminds me https://bugs.opendaylight.org/show_bug.cgi?id=4488
> > My theory:
> > When new peer ("A") connects, it register itself to the
> > "ExportPolicyPeerTracker" (it's shared resource). Before the LocRibWriter
> > gets a data change notification about peer "A", another peer ("B") has
> > disconnected and it's routes are removed from Loc-RIB and from RIB-Outs of
> > other peers (based on peers registered in ExportPolicyPeerTracker). So we
> > are also trying to remove routes from peer "A" RIB-Out, however there no
> > routes.
> >
> > Simply it is a race condition on shared resource.
>
> This ExportPolicyPeerTracker registration change was done because of
> https://bugs.opendaylight.org/show_bug.cgi?id=6747
> We might consider adding some additional flag to ExportPolicyPeerTracker,
> set when LocRibWriter discovers a new peer, until that peer is excluded from
> RIB-Out modification operations.

I don't think that is the cause of the issue, when we do remove something that doesn't exist there is no Exception error, indeed not change event is produced under RibOutListener since nothing has changed.
Indeed for check this, I

  • commented out addPathToDataStore -> therefore not path will be write under Loc
  • Post IPV4 Route via App Peer
  • Remove previously route

and as expected, AbstractRouteEntry#deleteRoute is executed and not exception is thrown even that path is not there.

I think the cause is removing when parent doesn't exist.
1- It can be because peer still going up.
2- Changes is listen meanwhile peer is closing.

Comment by Milos Fabian [ 17/Mar/17 ]

(In reply to Claudio D. Gasparini from comment #3)
> (In reply to Milos Fabian from comment #2)
> > (In reply to Milos Fabian from comment #1)
> > > Reminds me https://bugs.opendaylight.org/show_bug.cgi?id=4488
> > > My theory:
> > > When new peer ("A") connects, it register itself to the
> > > "ExportPolicyPeerTracker" (it's shared resource). Before the LocRibWriter
> > > gets a data change notification about peer "A", another peer ("B") has
> > > disconnected and it's routes are removed from Loc-RIB and from RIB-Outs of
> > > other peers (based on peers registered in ExportPolicyPeerTracker). So we
> > > are also trying to remove routes from peer "A" RIB-Out, however there no
> > > routes.
> > >
> > > Simply it is a race condition on shared resource.
> >
> > This ExportPolicyPeerTracker registration change was done because of
> > https://bugs.opendaylight.org/show_bug.cgi?id=6747
> > We might consider adding some additional flag to ExportPolicyPeerTracker,
> > set when LocRibWriter discovers a new peer, until that peer is excluded from
> > RIB-Out modification operations.
>
> I don't think that is the cause of the issue, when we do remove something
> that doesn't exist there is no Exception error, indeed not change event is
> produced under RibOutListener since nothing has changed.
> Indeed for check this, I
> - commented out addPathToDataStore -> therefore not path will be write under
> Loc
> - Post IPV4 Route via App Peer
> - Remove previously route
>
> and as expected, AbstractRouteEntry#deleteRoute is executed and not
> exception is thrown even that path is not there.
>
> I think the cause is removing when parent doesn't exist.
> 1- It can be because peer still going up.
> 2- Changes is listen meanwhile peer is closing.

Yeah, you are right, it is complaining because of missing parent.
Still, shared ExportPolicyPeerTracker is an issue.
So, the peer's empty tables (including RIB-Out) are created in RibInWriter, so peer's registration to ExportPolicyPeerTracker should be done once the tables are successfully written (write TX submit future is done)?

Comment by Claudio David Gasparini [ 20/Mar/17 ]

(In reply to Milos Fabian from comment #4)
> (In reply to Claudio D. Gasparini from comment #3)
> > (In reply to Milos Fabian from comment #2)
> > > (In reply to Milos Fabian from comment #1)
> > > > Reminds me https://bugs.opendaylight.org/show_bug.cgi?id=4488
> > > > My theory:
> > > > When new peer ("A") connects, it register itself to the
> > > > "ExportPolicyPeerTracker" (it's shared resource). Before the LocRibWriter
> > > > gets a data change notification about peer "A", another peer ("B") has
> > > > disconnected and it's routes are removed from Loc-RIB and from RIB-Outs of
> > > > other peers (based on peers registered in ExportPolicyPeerTracker). So we
> > > > are also trying to remove routes from peer "A" RIB-Out, however there no
> > > > routes.
> > > >
> > > > Simply it is a race condition on shared resource.
> > >
> > > This ExportPolicyPeerTracker registration change was done because of
> > > https://bugs.opendaylight.org/show_bug.cgi?id=6747
> > > We might consider adding some additional flag to ExportPolicyPeerTracker,
> > > set when LocRibWriter discovers a new peer, until that peer is excluded from
> > > RIB-Out modification operations.
> >
> > I don't think that is the cause of the issue, when we do remove something
> > that doesn't exist there is no Exception error, indeed not change event is
> > produced under RibOutListener since nothing has changed.
> > Indeed for check this, I
> > - commented out addPathToDataStore -> therefore not path will be write under
> > Loc
> > - Post IPV4 Route via App Peer
> > - Remove previously route
> >
> > and as expected, AbstractRouteEntry#deleteRoute is executed and not
> > exception is thrown even that path is not there.
> >
> > I think the cause is removing when parent doesn't exist.
> > 1- It can be because peer still going up.
> > 2- Changes is listen meanwhile peer is closing.
>
> Yeah, you are right, it is complaining because of missing parent.
> Still, shared ExportPolicyPeerTracker is an issue.
> So, the peer's empty tables (including RIB-Out) are created in RibInWriter,
> so peer's registration to ExportPolicyPeerTracker should be done once the
> tables are successfully written (write TX submit future is done)?

register the flag once tables are written is not possible, since
LocRib initialize Peer with existent routes once it detects that new table has been created, then it can be a race between adding the peer to registry and the route initialization itself under LocRib.
Best solution as you mentioned before is to add a flag under Registry.
Aside from that, this is not the issue of this bug ( I will create a bug for previous issue).
Here the race is when peers are going down. They close and do clean up, but at the same time LocRib listen changes from the others peers removal and try to remove routes.

Comment by Claudio David Gasparini [ 20/Mar/17 ]

https://logs.opendaylight.org/sandbox/jenkins091/bgpcep-csit-1node-periodic-bgp-ingest-only-boron/1/archives/odl1_karaf.log.gz

Comment by Claudio David Gasparini [ 21/Mar/17 ]

Issue Definition
-When peers close, its removed from DS
-LocRib is processing changes and try to update peer which has been removed in
the meanwhile processing changes.

AdjRibIn is in charge of remove Peer
LocRibIn is in charge of process changes.

1-Both have their own transactionChain, we want to keep it in this way, since
in case of tx fail session can be restarted per specific peer, no affecting
RIB.
2-Also closing and removing the peer returns a future, which is used to do a proper restart, avoiding race between deletion and creation of the peer.

Achieve a sync deletion with LocRib Update seems complicated without a shared tx.
Use some shared sync resource looks difficult because of 2.

Comment by Claudio David Gasparini [ 27/Mar/17 ]

https://git.opendaylight.org/gerrit/#/c/53810/

Generated at Wed Feb 07 19:13:42 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.