[NETCONF-879] netconf-mdsal fails and affects both testtool and ODL as netconf server Created: 24/May/22  Updated: 27/Jun/22  Resolved: 09/Jun/22

Status: Resolved
Project: netconf
Component/s: netconf
Affects Version/s: 3.0.0, 3.0.3, 3.0.4
Fix Version/s: 4.0.0, 3.0.5

Type: Bug Priority: Medium
Reporter: Robert Varga Assignee: Robert Varga
Resolution: Done Votes: 0
Labels: pt
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Relates
relates to NETCONF-818 Eliminate use of SchemaNode.getPath()... Resolved

 Description   

Found in CSIT: https://s3-logs.opendaylight.org/logs/releng/vex-yul-odl-jenkins-1/netconf-csit-1node-userfeatures-rfc8040-all-master/81/

reports:

07:02:22.113 [nioEventLoopGroup-2-3] DEBUG o.o.m.d.s.s.SnapshotBackedReadWriteTransaction - Tx: DOM-OPER-1 Read: /(urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)netconf-state/schemas
07:02:22.114 [nioEventLoopGroup-2-3] DEBUG o.o.n.m.c.TransactionProvider - Aborting current running Transaction
07:02:22.116 [nioEventLoopGroup-2-3] DEBUG o.o.m.d.s.s.SnapshotBackedWriteTransaction - Store transaction: DOM-OPER-1 : Closed
07:02:22.116 [nioEventLoopGroup-2-3] DEBUG o.o.m.d.s.i.InMemoryDOMDataStore - Tx: DOM-OPER-1 is closed.
07:02:22.116 [nioEventLoopGroup-2-3] DEBUG o.o.m.d.s.s.SnapshotBackedWriteTransaction - Store transaction: DOM-CFG-1 : Closed
07:02:22.116 [nioEventLoopGroup-2-3] DEBUG o.o.m.d.s.i.InMemoryDOMDataStore - Tx: DOM-CFG-1 is closed.
07:02:22.124 [nioEventLoopGroup-2-3] ERROR o.o.n.i.o.NetconfOperationRouterImpl - Unexpected exception during netconf operation execution
java.lang.RuntimeException: java.io.IOException: Failed to find child (urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)netconf-state in parent EmptyContainerEffectiveStatement{argument=(urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)schemas}
	at org.opendaylight.netconf.mdsal.connector.ops.get.AbstractGet.transformNormalizedNode(AbstractGet.java:101)
	at org.opendaylight.netconf.mdsal.connector.ops.get.AbstractGet.serializeNodeWithParentStructure(AbstractGet.java:148)
	at org.opendaylight.netconf.mdsal.connector.ops.get.Get.handleWithNoSubsequentOperations(Get.java:64)
	at org.opendaylight.netconf.util.mapping.AbstractSingletonNetconfOperation.handle(AbstractSingletonNetconfOperation.java:26)
	at org.opendaylight.netconf.util.mapping.AbstractNetconfOperation.handle(AbstractNetconfOperation.java:102)
	at org.opendaylight.netconf.impl.osgi.NetconfOperationRouterImpl$NetconfOperationExecution.execute(NetconfOperationRouterImpl.java:188)
	at org.opendaylight.netconf.impl.osgi.NetconfOperationRouterImpl.executeOperationWithHighestPriority(NetconfOperationRouterImpl.java:129)
	at org.opendaylight.netconf.impl.osgi.NetconfOperationRouterImpl.onNetconfMessage(NetconfOperationRouterImpl.java:103)
	at org.opendaylight.netconf.impl.NetconfServerSessionListener.processDocument(NetconfServerSessionListener.java:125)
	at org.opendaylight.netconf.impl.NetconfServerSessionListener.onMessage(NetconfServerSessionListener.java:90)
	at org.opendaylight.netconf.impl.NetconfServerSessionListener.onMessage(NetconfServerSessionListener.java:33)
	at org.opendaylight.netconf.nettyutil.AbstractNetconfSession.handleMessage(AbstractNetconfSession.java:65)
	at org.opendaylight.netconf.nettyutil.AbstractNetconfSession.channelRead0(AbstractNetconfSession.java:186)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.local.LocalChannel.readInbound(LocalChannel.java:299)
	at io.netty.channel.local.LocalChannel.finishPeerRead0(LocalChannel.java:445)
	at io.netty.channel.local.LocalChannel.access$400(LocalChannel.java:50)
	at io.netty.channel.local.LocalChannel$5.run(LocalChannel.java:403)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.io.IOException: Failed to find child (urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)netconf-state in parent EmptyContainerEffectiveStatement{argument=(urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)schemas}
	at org.opendaylight.yangtools.yang.data.api.schema.stream.YangInstanceIdentifierWriter.open(YangInstanceIdentifierWriter.java:184)
	at org.opendaylight.netconf.mdsal.connector.ops.get.AbstractGet.transformNormalizedNode(AbstractGet.java:88)
	... 41 common frames omitted

Testing ODL as netconf server, same errors found in ODL karaf log

022-06-02T09:03:32,546 | WARN  | globalWorkerGroup-3-7 | NetconfDeviceCommunicator        | 297 - org.opendaylight.netconf.sal-netconf-connector - 4.0.0.SNAPSHOT | RemoteDevice{test-device}: Error reply from remote device, request: <rpc message-id="m-0" xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
    <get>
        <filter xmlns:ns0="urn:ietf:params:xml:ns:netconf:base:1.0" ns0:type="subtree">
            <netconf-state xmlns="urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring">
                <schemas/>
            </netconf-state>
        </filter>
    </get>
</rpc>
, response: <rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="m-0">
    <rpc-error>
        <error-type>application</error-type>
        <error-tag>operation-failed</error-tag>
        <error-severity>error</error-severity>
        <error-message>Unexpected error</error-message>
        <error-info>
            <error>java.lang.RuntimeException: java.io.IOException: Failed to find child (urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)netconf-state in parent EmptyContainerEffectiveStatement{argument=(urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)schemas}</error>
        </error-info>
    </rpc-error>
</rpc-reply>

org.opendaylight.netconf.api.NetconfDocumentedException: Unexpected error
	at org.opendaylight.netconf.api.NetconfDocumentedException.fromXMLDocument(NetconfDocumentedException.java:55) ~[bundleFile:?]
	at org.opendaylight.netconf.sal.connect.netconf.util.NetconfMessageTransformUtil.checkSuccessReply(NetconfMessageTransformUtil.java:303) ~[bundleFile:?]
	at org.opendaylight.netconf.sal.connect.netconf.listener.NetconfDeviceCommunicator.processMessage(NetconfDeviceCommunicator.java:341) [bundleFile:?]
	at org.opendaylight.netconf.sal.connect.netconf.listener.NetconfDeviceCommunicator.onMessage(NetconfDeviceCommunicator.java:282) [bundleFile:?]
	at org.opendaylight.netconf.sal.connect.netconf.listener.NetconfDeviceCommunicator.onMessage(NetconfDeviceCommunicator.java:50) [bundleFile:?]
	at org.opendaylight.netconf.nettyutil.AbstractNetconfSession.handleMessage(AbstractNetconfSession.java:65) [bundleFile:?]
	at org.opendaylight.netconf.nettyutil.AbstractNetconfSession.channelRead0(AbstractNetconfSession.java:186) [bundleFile:?]
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:99) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [bundleFile:4.1.76.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327) [bundleFile:4.1.76.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [bundleFile:4.1.76.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327) [bundleFile:4.1.76.Final]
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:61) [bundleFile:4.1.76.Final]
	at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:370) [bundleFile:4.1.76.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [bundleFile:4.1.76.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) [bundleFile:4.1.76.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:503) [bundleFile:4.1.76.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) [bundleFile:4.1.76.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.76.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.76.Final]
	at java.lang.Thread.run(Thread.java:829) [?:?]
2022-06-02T09:03:32,546 | WARN  | remote-connector-processing-executor-12 | NetconfStateSchemas              | 297 - org.opendaylight.netconf.sal-netconf-connector - 4.0.0.SNAPSHOT | RemoteDevice{test-device}: Unable to detect available schemas, get to /(urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)netconf-state/schemas failed, [RpcError [message=Unexpected error, severity=ERROR, errorType=APPLICATION, tag=operation-failed, applicationTag=null, info=<error>java.lang.RuntimeException: java.io.IOException: Failed to find child (urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)netconf-state in parent EmptyContainerEffectiveStatement{argument=(urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)schemas}</error>, cause=null]]
2022-06-02T09:03:32,547 | WARN  | remote-connector-processing-executor-12 | NetconfDevice                    | 297 - org.opendaylight.netconf.sal-netconf-connector - 4.0.0.SNAPSHOT | RemoteDevice{test-device}: Netconf device does not provide all yang models reported in hello message capabilities, required but not provided: [(urn:opendaylight:params:xml:ns:yang:controller:config:sal-clustering-it:people?revision=2014-08-18)people, 



 Comments   
Comment by Sangwook Ha [ 08/Jun/22 ]

This has not been resolved: netconf-csit-1node-userfeatures-rfc8040-all-master/93

java.lang.IllegalArgumentException: Data tree child (urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)schemas not present in schema parent (urn:ietf:params:xml:ns:yang:ietf-netconf-monitoring?revision=2010-10-04)schemas
	at org.opendaylight.yangtools.yang.model.util.SchemaInferenceStack.notPresent(SchemaInferenceStack.java:1058) ~[bundleFile:?]
	at org.opendaylight.yangtools.yang.model.util.SchemaInferenceStack.lambda$pushData$6(SchemaInferenceStack.java:861) ~[bundleFile:?]
	at java.util.Optional.orElseThrow(Optional.java:408) ~[?:?]
	at org.opendaylight.yangtools.yang.model.util.SchemaInferenceStack.pushData(SchemaInferenceStack.java:861) ~[bundleFile:?]
	at org.opendaylight.yangtools.yang.model.util.SchemaInferenceStack.pushData(SchemaInferenceStack.java:855) ~[bundleFile:?]
	at org.opendaylight.yangtools.yang.model.util.SchemaInferenceStack.pushData(SchemaInferenceStack.java:849) ~[bundleFile:?]
	at org.opendaylight.yangtools.yang.model.util.SchemaInferenceStack.enterDataTree(SchemaInferenceStack.java:530) ~[bundleFile:?]
	at org.opendaylight.yangtools.yang.data.util.NormalizedNodeStreamWriterStack.enterDataTree(NormalizedNodeStreamWriterStack.java:204) ~[?:?]
	at org.opendaylight.yangtools.yang.data.util.NormalizedNodeStreamWriterStack.startContainerNode(NormalizedNodeStreamWriterStack.java:276) ~[?:?]
	at org.opendaylight.yangtools.yang.data.codec.xml.SchemaAwareXMLStreamNormalizedNodeStreamWriter.startContainerNode(SchemaAwareXMLStreamNormalizedNodeStreamWriter.java:125) ~[?:?]
	at org.opendaylight.yangtools.yang.data.api.schema.stream.NormalizedNodeWriter.wasProcessedAsCompositeNode(NormalizedNodeWriter.java:204) ~[bundleFile:?]
	at org.opendaylight.yangtools.yang.data.api.schema.stream.NormalizedNodeWriter.write(NormalizedNodeWriter.java:102) ~[bundleFile:?]
	at org.opendaylight.netconf.mdsal.connector.ops.get.AbstractGet.writeRootElement(AbstractGet.java:101) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.ops.get.AbstractGet.transformNormalizedNode(AbstractGet.java:72) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.ops.get.AbstractGet.serializeNodeWithParentStructure(AbstractGet.java:118) ~[?:?]

There is still a mismatch and it's complaining that schemas is not present, instead of netconf-state, in the parent.

Generated at Wed Feb 07 20:16:08 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.