Medium org.opendaylight.mdsal.common.api.OptimisticLockFailedException: Optimistic lock failed for path /(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2018-03-29)bgp-rib/rib/rib[
{(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2018-03-29)id=example-bgp-rib}]/peer/peer[
{(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2018-03-29)peer-id=bgp://127.0.0.11}]/adj-rib-in/tables
Seems to be an internal race condition between DS modification submision.
Steps for replicate the bug
- cherry-pick https://git.opendaylight.org/gerrit/#/c/72568/
- cherry-pick https://git.opendaylight.org/gerrit/#/c/72566/ (BGP with some changes adding logs and removing changes for an easy of log investigation)
- run ODL
- feature:install odl-restconf odl-bgpcep-bgp odl-bgpcep-bgp-config-example
- ./configureall.py
- ./manypeersibgp.sh ( run for a few seconds, when seeing INFO BGP-Dummy-4: Iteration: 2000 - total remaining prefixes: 98000, should be enough for kill it Ctrl+c)
- check error on logs
Observation resume
- Peers write route via Dom chain
- Routes session is closed,
- dom chain is closed
- Peer removes table from DS via binding chain
- binding chain is closed
Changes coming from 1 [0] clashes with changes coming from 4.
The interesting part is that even 1 is done and submitted before 4 ( the main reason to arrive to this conclusion is because 4 doesn't fail to close)
seems that 4 is somehow executed before full 1 has been executed.
Logs attached.
[0] AdjRibInWriter | 224 - org.opendaylight.bgpcep.bgp-rib-impl - 0.10.0.SNAPSHOT | Write routes failed
2018-06-01T15:28:26,038 | ERROR | CommitFutures-4 | AdjRibInWriter | 224 - org.opendaylight.bgpcep.bgp-rib-impl - 0.10.0.SNAPSHOT | Write routes failed
org.opendaylight.controller.md.sal.common.api.data.OptimisticLockFailedException: Optimistic lock failed for path /(urn:opendaylight:params:xml:ns:yang:bgp-rib?revision=2018-03-29)bgp-rib/rib/rib[
]/peer/peer[
]/adj-rib-in/tables
at org.opendaylight.controller.cluster.databroker.compat.LegacyDOMDataBrokerAdapter$1.newWithCause(LegacyDOMDataBrokerAdapter.java:66) [270:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
at org.opendaylight.controller.cluster.databroker.compat.LegacyDOMDataBrokerAdapter$1.newWithCause(LegacyDOMDataBrokerAdapter.java:62) [270:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
at org.opendaylight.yangtools.util.concurrent.ExceptionMapper.apply(ExceptionMapper.java:106) [343:org.opendaylight.yangtools.util:2.0.3]
at org.opendaylight.controller.cluster.databroker.compat.LegacyDOMDataBrokerAdapter$DOMDataTransactionAdapter$1.onFailure(LegacyDOMDataBrokerAdapter.java:301) [270:org.opendaylight.controller.sal-distributed-datastore:1.8.0.SNAPSHOT]
at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1387) [75:com.google.guava:23.6.0.jre]
at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:398) [75:com.google.guava:23.6.0.jre]
at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1015) [75:com.google.guava:23.6.0.jre]
at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:868) [75:com.google.guava:23.6.0.jre]
at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:713) [75:com.google.guava:23.6.0.jre]
at com.google.common.util.concurrent.AbstractTransformFuture.run(AbstractTransformFuture.java:94) [75:com.google.guava:23.6.0.jre]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: org.opendaylight.yangtools.yang.data.api.schema.tree.ConflictingModificationAppliedException: Node was deleted by other transaction.
