[NETCONF-445] N: GET for netconf device mount point responded with 500 Created: 31/Jul/17  Updated: 15/Mar/19  Resolved: 10/Aug/17

Status: Resolved
Project: netconf
Component/s: netconf
Affects Version/s: None
Fix Version/s: None

Type: Bug
Reporter: Peter Gubka Assignee: Jakub Morvay
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All


Issue Links:
Duplicate
duplicates YANGTOOLS-805 Cannot mount netconf device Verified
External issue ID: 8916

 Description   

tested odl: https://nexus.opendaylight.org/content/repositories/opendaylight.snapshot/org/opendaylight/integration/karaf/0.7.0-SNAPSHOT/karaf-0.7.0-20170731.112540-1487.zip

Readiness suite configures netconf device and access it's mount mount.
https://logs.opendaylight.org/sandbox/jenkins091/netconf-csit-1node-userfeatures-only-nitrogen/3/log.html.gz#s1-s1-s1-t1-k3-k1-k1-k1-k1-k4-k1-k5-k1-k3-k4-k1

The returned exception is caused by java.lang.IllegalArgumentException: Could not find module for namespace urn:opendaylight:params:xml:ns:yang:controller:netty:eventexecutor

Checking the karaf.log there are more exceptions prior to this one.
https://logs.opendaylight.org/sandbox/jenkins091/netconf-csit-1node-userfeatures-only-nitrogen/3/odl1_karaf.log.gz
2017-07-31 15:15:54,459 | INFO | nsole user karaf | core | 173 - org.apache.karaf.log.core - 4.0.9 | ROBOT MESSAGE: Starting test Check_Whether_Netconf_Topology_Is_Ready

Similar results are expected in https://jenkins.opendaylight.org/releng/view/netconf/job/netconf-csit-1node-userfeatures-only-nitrogen/95 (in the queue at the moment of creating this bug)



 Comments   
Comment by Vratko Polak [ 01/Aug/17 ]

> Similar results are expected in

The symptom has occurred [4] as expected.

> there are more exceptions prior to this one

Some suspicious lines from karaf.log [5]:

2017-07-31 18:50:29,055 | WARN | c]-nio2-thread-3 | ServerSession | 190 - org.apache.sshd.core - 0.14.0 | Exception caught
java.lang.IllegalStateException: Unsupported command 90
at org.apache.sshd.common.session.AbstractSession.doHandleMessage(AbstractSession.java:434)[190:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.session.AbstractSession.handleMessage(AbstractSession.java:326)[190:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.session.AbstractSession.decode(AbstractSession.java:780)[190:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.session.AbstractSession.messageReceived(AbstractSession.java:308)[190:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:54)[190:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:184)[190:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:170)[190:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:32)
at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_131]
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:30)[190:org.apache.sshd.core:0.14.0]
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)[:1.8.0_131]
at sun.nio.ch.Invoker$2.run(Invoker.java:218)[:1.8.0_131]
at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)[:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_131]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_131]
at java.lang.Thread.run(Thread.java:748)[:1.8.0_131]

2017-07-31 18:50:31,268 | ERROR | on-dispatcher-48 | AAAEncryptionServiceImpl | 230 - org.opendaylight.aaa.encrypt-service - 0.6.0.SNAPSHOT | Failed to decrypt encoded data
javax.crypto.IllegalBlockSizeException: Input length must be multiple of 16 when decrypting with padded cipher

2017-07-31 18:50:31,403 | WARN | on-dispatcher-48 | NetconfClientConfiguration | 298 - org.opendaylight.netconf.client - 1.3.0.SNAPSHOT | Unexpected protocol: SSH in netconf client configuration.

2017-07-31 18:50:31,440 | WARN | on-dispatcher-48 | NetconfClientConfiguration | 298 - org.opendaylight.netconf.client - 1.3.0.SNAPSHOT | Unexpected protocol: SSH in netconf client configuration.
2017-07-31 18:50:31,432 | WARN | ventExecutor-1-1 | DefaultPromise | 15 - io.netty.common - 4.1.8.Final | An exception was thrown by org.opendaylight.protocol.framework.ReconnectPromise$$Lambda$308/1141312437.operationComplete()
java.lang.IllegalStateException: complete already: ReconnectPromise@66a6b47c(failure: java.util.concurrent.CancellationException)
at io.netty.util.concurrent.DefaultPromise.setFailure(DefaultPromise.java:116)[15:io.netty.common:4.1.8.Final]
at org.opendaylight.protocol.framework.ReconnectPromise.lambda$connect$1(ReconnectPromise.java:58)[28:org.opendaylight.controller.protocol-framework:0.10.0.SNAPSHOT]
at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:507)[15:io.netty.common:4.1.8.Final]
at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:481)[15:io.netty.common:4.1.8.Final]
at io.netty.util.concurrent.DefaultPromise.access$000(DefaultPromise.java:34)[15:io.netty.common:4.1.8.Final]
at io.netty.util.concurrent.DefaultPromise$1.run(DefaultPromise.java:431)[15:io.netty.common:4.1.8.Final]
at io.netty.util.concurrent.GlobalEventExecutor$TaskRunner.run(GlobalEventExecutor.java:233)[15:io.netty.common:4.1.8.Final]
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)[15:io.netty.common:4.1.8.Final]
at java.lang.Thread.run(Thread.java:748)[:1.8.0_131]
Caused by: java.util.concurrent.CancellationException
at io.netty.util.concurrent.DefaultPromise.cancel(...)(Unknown Source)[15:io.netty.common:4.1.8.Final]

2017-07-31 18:50:49,271 | WARN | sing-executor-11 | NetconfDevice | 311 - org.opendaylight.netconf.sal-netconf-connector - 1.6.0.SNAPSHOT | RemoteDevice

{test-device}

: Unable to build schema context, unsatisfied imports {
...
}, will reattempt with resolved only

Maybe ssh was not initialized properly? Although I do not see anything wrong in netconf-testtool log [].

[4] https://logs.opendaylight.org/sandbox/jenkins091/netconf-csit-1node-userfeatures-only-nitrogen/3/log.html.gz#s1-s1-s1-t1-k3-k1-k1-k1-k1-k4-k1-k5-k1-k3-k4-k1
[5] https://logs.opendaylight.org/releng/jenkins092/netconf-csit-1node-userfeatures-only-nitrogen/95/odl1_karaf.log.gz
[6] https://logs.opendaylight.org/releng/jenkins092/netconf-csit-1node-userfeatures-only-nitrogen/95/testtool--netconf-userfeatures-txt-CRUD-CRUD.log.gz

Comment by Jakub Morvay [ 10/Aug/17 ]

This seems to be duplicate of YANGTOOLS-805.

What happened in above mentioned issues is that ODL cannot properly mount either testtool or CSS server. Because of the YANGTOOLS-805, some schemas from mountpoint are not properly parsed and hence, are not part of the mountpoint's schema context.

Therefore you can see errors like "java.lang.IllegalArgumentException: Could not find module for namespace urn:opendaylight:params:xml:ns:yang:controller:netty:eventexecutor" because ODL cannot properly parse responses from mounted device due to its incomplete mountpoint's schema context.

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