Operating System: All
Platform: All

After deleting the flow and before restarting the controller are you able to see the flow in the datastore?

No, the flow adds/removes with no issues before the restart.

On which version did you encounter this problem? Is it reproducible on stable/lithium?

both stable/lithium and master.

I have just reproduced with latest stable/lithium distro from Nexus.

https://nexus.opendaylight.org/content/repositories/opendaylight.snapshot/org/opendaylight/integration/distribution-karaf/0.3.2-SNAPSHOT/distribution-karaf-0.3.2-20150925.203437-84.zip

BR/Luis

See CONTROLLER-1297 - It was fixed in helium by changing the journal-recovery batch size to 1.

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

The workaround on stable/lithium for this particular bug right now is to set shard-journal-recovery-log-batch-size to 1 in etc/org.opendaylight.controller.cluster.datastore.cfg. The bug however appears to be in the underlying DataTree code I presume because when we do the operations described in this bug in separate transactions it produces a different output than when we do the same set of operations in a single transaction on recovery.

we do similar bug in ovsdb plugin as well, when bridge related config data pops up again in the data store, after restart. I will try this workaround and see if it works.

Workaround suggested by Moiz works, at least for the issue reported.

Not an MD-SAL issue, but rather CDS.

Robert were you able to test out DataTree in this scenario (add, delete, add, delete of the same node) to confirm that this is not a DataTree issue?

Note that the issue is when we take four operations that were done in separate transactions and put it on a single transaction then this problem happens - and not when they are replayed on a single transaction.

Well, no, as there is no description of what the operations on DataTree are. Given that CDS data tree recovery is not a single write, but rather a series of operations from the journal, it is not clear what the before-state, DataTreeModification and after-state looks like.

The test case is simple,

Tx1 -> Add Flow 1 -> DTC 1
Tx2 -> Remove Flow 1 -> DTC 2
Tx3 -> Add Flow 1 -> DTC 3
Tx3 -> Remove Flow 1 -> DTC 4

Each transaction yields a DataTreeCandidate which we store in the journal.

On recovery,

Tx1 -> Apply (DTC1, DTC2, DTC3, DTC4) -> This triggers the bug

If instead we do the following,

Tx1 -> Apply DTC1
Tx2 -> Apply DTC2
Tx3 -> Apply DTC3
Tx4 -> Apply DTC4

This works just fine.

I am trying to reproduce the bug in a test case - so stay tuned.

I've reproduced this problem using a unit test

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

I believe this shows the issue with the DataTree.

As the data tree candididates are applied, the modification to be applied looks like this:

MutableDataTree [modification=NodeModification [identifier=(urn:ietf:params:xml:ns:netconf:base:1.0)data, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars, modificationType=WRITE, childModification={}]}]]

MutableDataTree [modification=NodeModification [identifier=(urn:ietf:params:xml:ns:netconf:base:1.0)data, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars, modificationType=WRITE, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car[

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car[

], modificationType=DELETE, childModification={}]}]}]}]]

MutableDataTree [modification=NodeModification [identifier=(urn:ietf:params:xml:ns:netconf:base:1.0)data, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars, modificationType=WRITE, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car[

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car[

], modificationType=WRITE, childModification={}]}]}]}]]

MutableDataTree [modification=NodeModification [identifier=(urn:ietf:params:xml:ns:netconf:base:1.0)data, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)cars, modificationType=WRITE, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car, modificationType=TOUCH, childModification={(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car[

]=NodeModification [identifier=(urn:opendaylight:params:xml:ns:yang:controller:md:sal:dom:store:test:cars?revision=2014-03-13)car[

], modificationType=NONE, childModification={}]}]}]}]]

The important thing to note is that the top-level write after the first transaction already contains the 'altima' node in its data. Note that for second operation we carry a DELETE operation, for third we have an explicit WRITE.

So when the second DELETE operation comes along, it sees a WRITE operation on non-preexisting data and turns it into a NONE operation. When we then apply this modification, WRITE is processed as usual and the other operations turn out to be no-ops – hence altima looks like it's been resurrected.

The problem is that the original node is resolved from the underlying snapshot, not the WRITE operation into which the modification is nested. In theory we should be able to set the before-state to the data from that write operation, which should have the effect of the fourth operation seeing this as a DELETE on data we wrote, but which has pre-existing data – thus resolving to a DELETE node (not NONE), hence achieving the same state we see after two operations.

Be: https://git.opendaylight.org/gerrit/27924

Merged in Beryllium and stable/lithium (Lithium SR-3)