[#CONTROLLER-1731] it provider: produce-transactions does not close itemProducer on success

[CONTROLLER-1731] it provider: produce-transactions does not close itemProducer on success Created: 29/Jun/17 Updated: 25/Jul/23 Resolved: 12/Jul/17
Status:	Resolved
Project:	controller
Component/s:	clustering
Affects Version/s:	None
Fix Version/s:	None

Type:

Bug

Reporter:

Vratko Polak

Assignee:

Vratko Polak

Resolution:

Done

Votes:

Labels:

None

Remaining Estimate:

Not Specified

Time Spent:

Not Specified

Original Estimate:

Not Specified

Environment:

Operating System: All
Platform: All

External issue ID:

8768

Description

This is similar to ~~CONTROLLER-1681~~ but now it does not concern the scenario where producer fails. Instead, when producer finishes successfully, it prevents another produce-transactions call with the same id.

This leads [0] to the same "is attached to producer" error message.

[0] https://logs.opendaylight.org/sandbox/jenkins091/controller-csit-3node-clustering-li-only-carbon/10/log.html.gz#s1-s4-t3-k2-k25-k1-k8

Comments

Comment by Vratko Polak [ 29/Jun/17 ]

Attempt [1] to fix.

[1] https://git.opendaylight.org/gerrit/59649

Comment by Vratko Polak [ 30/Jun/17 ]

Sandbox [2] shows this is not fixed enough.

[2] https://logs.opendaylight.org/sandbox/jenkins091/controller-csit-3node-clustering-li-only-carbon/17/log.html.gz#s1-s4-t1-k2-k25-k1-k9-k1-k1-k1

Comment by Vratko Polak [ 03/Jul/17 ]

This week Sandbox: [3].
Well, in this case the close is missing on an expected RequestTimeoutException [4], but the previous fix should have handled all rpc results.

[3] https://logs.opendaylight.org/sandbox/jenkins091/controller-csit-3node-clustering-li-only-carbon/1/log.html.gz#s1-s4-t1-k2-k25-k1-k8
[4] https://logs.opendaylight.org/sandbox/jenkins091/controller-csit-3node-clustering-li-only-carbon/1/log.html.gz#s1-s4-t1-k2-k25-k1-k1

Comment by Vratko Polak [ 11/Jul/17 ]

Looking at the code, I believe the thinko is not in transaction producers, but in ShardedDOMDataTree (the Mdsal one).

Specifically, this change [5] of findProducer() implementation went from explicitly looking for producers registered for sub-trees of the "subtree" argument, to delegating to lookup(), which was later [6] documented to return producers registered at super-trees of the given prefix.

I think we need to split findProducer, as both usages (making sure no sub-producer is claimed and finding the nearest super-producer) are valid.

P.S.: What is the recommended language when talking about one node being within the subtree rooted at another node?

[5] https://git.opendaylight.org/gerrit/#/c/26244/5/dom/mdsal-dom-broker/src/main/java/org/opendaylight/mdsal/dom/broker/ShardedDOMDataTree.java
[6] https://git.opendaylight.org/gerrit/#/c/31411/3/dom/mdsal-dom-spi/src/main/java/org/opendaylight/mdsal/dom/spi/DOMDataTreePrefixTable.java

Comment by Robert Varga [ 11/Jul/17 ]

Ad the PS, this maps to 'descendant' XPath axis, as defined in https://www.w3schools.com/xml/xpath_axes.asp.

Hence "node A, which is part of the subtree rooted at node B" maps to "A is descendant of B".

Comment by Vratko Polak [ 12/Jul/17 ]

Sandbox run with logging changes [7][8]. Robot failure: [9]. Big karaf.log: [10].

The first status change related to data producers is at 11:53:00,632, the initialization seems to end at 11:56:04,115.

After the expected RequestTimeoutException, producer is being closed at 11:58:10,514:
...
2017-07-11 11:58:10,515 | TRACE | ult-dispatcher-6 | DOMDataTreePrefixTableEntry | 93 - org.opendaylight.mdsal.dom-spi - 2.2.1.SNAPSHOT | Deleting value org.opendaylight.mdsal.dom.broker.ShardedDOMDataTreeProducer@11ac4117
2017-07-11 11:58:10,515 | TRACE | ult-dispatcher-6 | DOMDataTreePrefixTableEntry | 93 - org.opendaylight.mdsal.dom-spi - 2.2.1.SNAPSHOT | Child org.opendaylight.mdsal.dom.spi.DOMDataTreePrefixTableEntry@24b7aa9b reported empty, removing from children
2017-07-11 11:58:10,515 | TRACE | ult-dispatcher-6 | DOMDataTreePrefixTableEntry | 93 - org.opendaylight.mdsal.dom-spi - 2.2.1.SNAPSHOT | Children after removal: {(tag:opendaylight.org,2017:controller:yang:lowlevel:target?revision=2017-02-15)id-int[

{(tag:opendaylight.org,2017:controller:yang:lowlevel:target?revision=2017-02-15)id=prefix-2}

]=org.opendaylight.mdsal.dom.spi.DOMDataTreePrefixTableEntry@71172d08, (tag:opendaylight.org,2017:controller:yang:lowlevel:target?revision=2017-02-15)id-int[

{(tag:opendaylight.org,2017:controller:yang:lowlevel:target?revision=2017-02-15)id=prefix-1}

]=org.opendaylight.mdsal.dom.spi.DOMDataTreePrefixTableEntry@76e1e46b}
2017-07-11 11:58:10,515 | TRACE | ult-dispatcher-6 | DOMDataTreePrefixTableEntry | 93 - org.opendaylight.mdsal.dom-spi - 2.2.1.SNAPSHOT | Child org.opendaylight.mdsal.dom.spi.DOMDataTreePrefixTableEntry@7da25b48 reported non-empty, keeping it.
2017-07-11 11:58:10,515 | TRACE | ult-dispatcher-6 | DOMDataTreePrefixTableEntry | 93 - org.opendaylight.mdsal.dom-spi - 2.2.1.SNAPSHOT | Child org.opendaylight.mdsal.dom.spi.DOMDataTreePrefixTableEntry@604e5597 reported non-empty, keeping it.

When next producer on the same member is created:
2017-07-11 11:58:31,266 | TRACE | qtp138207402-77 | DOMDataTreePrefixTableEntry | 93 - org.opendaylight.mdsal.dom-spi - 2.2.1.SNAPSHOT | Looking up identifier /(tag:opendaylight.org,2017:controller:yang:lowlevel:target?revision=2017-02-15)id-ints/id-int/id-int[