[GENIUS-58] DataStoreJobCoordinator ModifiedNodeDoesNotExistException: Node /(urn:ietf:params:xml:ns:yang:ietf-interfaces?revision=2014-05-08)interfaces-state/interface does not exist. Cannot apply modification to its children. Created: 07/Mar/17  Updated: 19/Oct/17  Resolved: 09/Mar/17

Status: Resolved
Project: genius
Component/s: General
Affects Version/s: (unspecified)
Fix Version/s: None

Type: Bug
Reporter: Michael Vorburger Assignee: Unassigned
Resolution: Cannot Reproduce 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: 7917

 Description   

[Not sure which project to file this in; perhaps rather genius than controller?]

Like OPNFLWPLUG-866 (probably totally unrelated),

I'm hitting a bunch of the following exceptions, after simply doing,
as of f6bda1bdfd01a44948fe154883140538c2558151:

cd netvirt/vpnservice/distribution/karaf
mvn clean package

cd target/assembly/bin
./karaf

opendaylight-user@root>feature:install odl-netvirt-openstack

I've also hit http://localhost:8181/controller/nb/v2/neutron/ in a Browser (which 404s), and I'm not sure that's what causes the NPEs or the mere start up.

2017-03-07 14:03:03,878 | WARN | CommitFutures-0 | DataStoreJobCoordinator | 328 - org.opendaylight.genius.mdsalutil-api - 0.2.0.SNAPSHOT | Job: JobEntry{key='119556424750016:br-int', mainWorker=InterfaceStateRemoveWorker{nodeConnectorIdNew=Uri [_value=openflow:119556424750016:LOCAL], nodeConnectorIdOld=null, fcNodeConnectorOld=FlowCapableNodeConnector{getAdvertisedFeatures=PortFeatures [_tenMbHd=false, _tenMbFd=false, _hundredMbHd=false, _hundredMbFd=false, _oneGbHd=false, _oneGbFd=false, _tenGbFd=false, _fortyGbFd=false, _hundredGbFd=false, _oneTbFd=false, _other=false, _copper=false, _fiber=false, _autoeng=false, _pause=false, _pauseAsym=false], getConfiguration=PortConfig [_pORTDOWN=true, _nORECV=false, _nOFWD=false, _nOPACKETIN=false], getCurrentFeature=PortFeatures [_tenMbHd=false, _tenMbFd=false, _hundredMbHd=false, _hundredMbFd=false, _oneGbHd=false, _oneGbFd=false, _tenGbFd=false, _fortyGbFd=false, _hundredGbFd=false, _oneTbFd=false, _other=false, _copper=false, _fiber=false, _autoeng=false, _pause=false, _pauseAsym=false], getCurrentSpeed=0, getHardwareAddress=MacAddress [_value=6c:bc:66:3a:53:c0], getMaximumSpeed=0, getName=br-int, getPeerFeatures=PortFeatures [_tenMbHd=false, _tenMbFd=false, _hundredMbHd=false, _hundredMbFd=false, _oneGbHd=false, _oneGbFd=false, _tenGbFd=false, _fortyGbFd=false, _hundredGbFd=false, _oneTbFd=false, _other=false, _copper=false, _fiber=false, _autoeng=false, _pause=false, _pauseAsym=false], getPortNumber=PortNumberUni [_uint32=4294967294], getQueue=[], getState=State{isBlocked=false, isLinkDown=true, isLive=false, augmentations={}}, getSupported=PortFeatures [_tenMbHd=false, _tenMbFd=false, _hundredMbHd=false, _hundredMbFd=false, _oneGbHd=false, _oneGbFd=false, _tenGbFd=false, _fortyGbFd=false, _hundredGbFd=false, _oneTbFd=false, _other=false, _copper=false, _fiber=false, _autoeng=false, _pause=false, _pauseAsym=false]}, interfaceName='119556424750016:br-int'}, rollbackWorker=null, retryCount=6, futures=[org.opendaylight.controller.cluster.databroker.ConcurrentDOMDataBroker$AsyncNotifyingSettableFuture@b31a18f]} failed
TransactionCommitFailedException

{message=Data did not pass validation., errorList=[RpcError [message=Data did not pass validation., severity=ERROR, errorType=APPLICATION, tag=operation-failed, applicationTag=null, info=null, cause=org.opendaylight.yangtools.yang.data.api.schema.tree.ModifiedNodeDoesNotExistException: Node /(urn:ietf:params:xml:ns:yang:ietf-interfaces?revision=2014-05-08)interfaces-state/interface does not exist. Cannot apply modification to its children.]]}

at org.opendaylight.controller.cluster.datastore.ShardDataTree.lambda$processNextPendingTransaction$0(ShardDataTree.java:691)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.ShardDataTree.processNextPending(ShardDataTree.java:720)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.ShardDataTree.processNextPendingTransaction(ShardDataTree.java:667)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.ShardDataTree.startCanCommit(ShardDataTree.java:746)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.SimpleShardDataTreeCohort.canCommit(SimpleShardDataTreeCohort.java:76)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.CohortEntry.canCommit(CohortEntry.java:97)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.ShardCommitCoordinator.handleCanCommit(ShardCommitCoordinator.java:236)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.ShardCommitCoordinator.handleReadyLocalTransaction(ShardCommitCoordinator.java:200)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.Shard.handleReadyLocalTransaction(Shard.java:573)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.Shard.handleNonRaftCommand(Shard.java:296)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.raft.RaftActor.handleCommand(RaftActor.java:268)[214:org.opendaylight.controller.sal-akka-raft:1.5.0.SNAPSHOT]
at org.opendaylight.controller.cluster.common.actor.AbstractUntypedPersistentActor.onReceiveCommand(AbstractUntypedPersistentActor.java:31)[213:org.opendaylight.controller.sal-clustering-commons:1.5.0.SNAPSHOT]
at akka.persistence.UntypedPersistentActor.onReceive(PersistentActor.scala:170)[193:com.typesafe.akka.persistence:2.4.17]
at org.opendaylight.controller.cluster.common.actor.MeteringBehavior.apply(MeteringBehavior.java:104)[213:org.opendaylight.controller.sal-clustering-commons:1.5.0.SNAPSHOT]
at akka.actor.ActorCell$$anonfun$become$1.applyOrElse(ActorCell.scala:544)[186:com.typesafe.akka.actor:2.4.17]
at akka.actor.Actor$class.aroundReceive(Actor.scala:497)[186:com.typesafe.akka.actor:2.4.17]
at akka.persistence.UntypedPersistentActor.akka$persistence$Eventsourced$$super$aroundReceive(PersistentActor.scala:168)[193:com.typesafe.akka.persistence:2.4.17]
at akka.persistence.Eventsourced$$anon$1.stateReceive(Eventsourced.scala:664)[193:com.typesafe.akka.persistence:2.4.17]
at akka.persistence.Eventsourced$class.aroundReceive(Eventsourced.scala:183)[193:com.typesafe.akka.persistence:2.4.17]
at akka.persistence.UntypedPersistentActor.aroundReceive(PersistentActor.scala:168)[193:com.typesafe.akka.persistence:2.4.17]
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:526)[186:com.typesafe.akka.actor:2.4.17]
at akka.actor.ActorCell.invoke(ActorCell.scala:495)[186:com.typesafe.akka.actor:2.4.17]
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:257)[186:com.typesafe.akka.actor:2.4.17]
at akka.dispatch.Mailbox.run(Mailbox.scala:224)[186:com.typesafe.akka.actor:2.4.17]
at akka.dispatch.Mailbox.exec(Mailbox.scala:234)[186:com.typesafe.akka.actor:2.4.17]
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)[182:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)[182:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)[182:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)[182:org.scala-lang.scala-library:2.11.8.v20160304-115712-1706a37eb8]
Caused by: org.opendaylight.yangtools.yang.data.api.schema.tree.ModifiedNodeDoesNotExistException: Node /(urn:ietf:params:xml:ns:yang:ietf-interfaces?revision=2014-05-08)interfaces-state/interface does not exist. Cannot apply modification to its children.
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkTouchApplicable(AbstractNodeContainerModificationStrategy.java:281)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:125)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkChildPreconditions(AbstractNodeContainerModificationStrategy.java:305)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkTouchApplicable(AbstractNodeContainerModificationStrategy.java:288)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:125)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.StructuralContainerModificationStrategy.checkApplicable(StructuralContainerModificationStrategy.java:97)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkChildPreconditions(AbstractNodeContainerModificationStrategy.java:305)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractNodeContainerModificationStrategy.checkTouchApplicable(AbstractNodeContainerModificationStrategy.java:288)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.SchemaAwareApplyOperation.checkApplicable(SchemaAwareApplyOperation.java:125)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.RootModificationApplyOperation.checkApplicable(RootModificationApplyOperation.java:72)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.yangtools.yang.data.impl.schema.tree.AbstractDataTreeTip.validate(AbstractDataTreeTip.java:35)[108:org.opendaylight.yangtools.yang-data-impl:1.1.0.SNAPSHOT]
at org.opendaylight.controller.cluster.datastore.ShardDataTree.lambda$processNextPendingTransaction$0(ShardDataTree.java:674)[220:org.opendaylight.controller.sal-distributed-datastore:1.5.0.SNAPSHOT]
... 28 more

 Comments   
Comment by Tom Pantelis [ 09/Mar/17 ]

Looks like someone is trying to write a node where at least part of the parent path doesn't exist. This indicates an application-side issue.

Comment by Michael Vorburger [ 09/Mar/17 ]

> write a node where at least part of the parent path doesn't exist
> This indicates an application-side issue

agreed, and would love to move the issue and dig more in another project than controller, BUT don't we have a .. "traceability issue" here - it's impossible to tell, from this stack trace, where this originally came from?!

I do understand this is related to async lambda stuff, but... there must be a solution to this, how does async FMKs typically deal with this? Capture the stack of the caller submitting the lambda, and filling it as root (or additional via setStackTrace()) of such exceptions? This common problem must have a general solution, no?

Comment by Tom Pantelis [ 09/Mar/17 ]

The InterfaceStateRemoveWorker toString gives a clue as to the originator - it's open flow-related so but should be moved there.

Adding appropriate info in the caller's mainWorker toString would help to identify the originator. However I think capturing the caller's stack trace would be too expensive in production although it could be done in a debug mode.

Comment by Michael Vorburger [ 09/Mar/17 ]

> The InterfaceStateRemoveWorker toString gives a clue as to the originator
> it's open flow-related so but should be moved there.

OK, thanks for the tip; moved bug from project controller to openflowplugin.

> Adding appropriate info in the caller's mainWorker toString would help to
> identify the originator. However I think capturing the caller's stack trace
> would be too expensive in production although it could be done in a debug mod

==> INFRAUTILS-8

PS: I now realized that DataStoreJobCoordinator JobEntry mainWorker is project genius/infrautils related, not controller.

Comment by Robert Varga [ 09/Mar/17 ]

The only way to capture caller identity is to capture it via a Throwable. That is going to hurt performance a lot.

Clean way of achieving this is to route the failure back to the requestor – which can then identify itself and provide any useful context.

I mean, at the end of the day, the requestor needs to know about the failure, right?

Comment by Michael Vorburger [ 09/Mar/17 ]

Robert, thanks for feedback! More discussions about this in INFRAUTILS-8 .. Let's leave this bug for the openflowplugin project to fix this particular problem (and INFRAUTILS-8 to see what we can do about the "traceability" of this kind of problem more in general).

Comment by Anil Vishnoi [ 09/Mar/17 ]

Please don't look at it as i want to throw it out of my plate , but looks like DataStoreJobCoordinator is trying to write on Node /(urn:ietf:params:xml:ns:yang:ietf-interfaces?revision=2014-05-08)interfaces-state/interface and fails. As far as i know openflowplugin don't use ietf-interfaces model and moreover it's an issue related to writing to the data store and DataStoreJobCoordinator belongs to genius project.

@Genius-project, please have a look at the issue and if you think it's an issue with the plugin, please queue it back to openflowplugin project.

Comment by Michael Vorburger [ 09/Mar/17 ]

Anil, no this is (almost) certainly not an issue in genius, genius just provides this DataStoreJobCoordinator infra, but something else (we suspect openflowplugin, or perhaps openflowjava? I admit I barely understand the difference) actually submitted a job doing this write..

Comment by Michael Vorburger [ 09/Mar/17 ]

> as of f6bda1bdfd01a44948fe154883140538c2558151

I've just tried to reproduce it, with a fresh Karaf rebuilt today (with mvn -U), and currently don't see it anymore... so either I did additional steps yesterday, or it's just been solved?! Closing for now, anyone seeing this again should re-open it.

Comment by Anil Vishnoi [ 09/Mar/17 ]

(In reply to Michael Vorburger from comment #8)
> Anil, no this is (almost) certainly not an issue in genius, genius just
> provides this DataStoreJobCoordinator infra, but something else (we suspect
> openflowplugin, or perhaps openflowjava? I admit I barely understand the
> difference) actually submitted a job doing this write..

Openflowplugin or openflowjava both are not using anything from genius project. The task that is submitted to DataStoreJobCoordinator was InterfaceStateRemoveWorker (belong to genius) and looks like it's trying to remove interface from the data store and encountering this issue

List<InterfaceChildEntry> interfaceChildEntries = getInterfaceChildEntries(dataBroker, interfaceName);
for (InterfaceChildEntry interfaceChildEntry : interfaceChildEntries)

{ // Fetch all interfaces on this port and trigger remove worker for each of them InterfaceStateRemoveWorker interfaceStateRemoveWorker = new InterfaceStateRemoveWorker(idManager, nodeConnectorIdNew, nodeConnectorIdOld, fcNodeConnectorOld, interfaceChildEntry.getChildInterface(), interfaceName, isNodePresent, isNetworkEvent, false); DataStoreJobCoordinator.getInstance().enqueueJob(interfaceName, interfaceStateRemoveWorker); }

That's why i believe it's good if genius project look at it issue first and queue it to whoever is submitting this job.

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