Uploaded image for project: 'netconf'
  1. netconf
  2. NETCONF-552

Controller can not establish netconf connection with testtool

    XMLWordPrintable

Details

    • Bug
    • Status: Resolved
    • Medium
    • Resolution: Cannot Reproduce
    • Fluorine
    • Fluorine
    • netconf
    • None

    Description

      I built the netconf connection in this way as before, but it suddenly failed:

      PUT    http://10.10.19.15:8181/restconf/config/network-topology:network-topology/topology/topology-netconf/node/node1

      <node xmlns="urn:TBD:params:xml:ns:yang:network-topology">
      <node-id>node1</node-id>
      <host xmlns="urn:opendaylight:netconf-node-topology">10.10.19.15</host>
      <port xmlns="urn:opendaylight:netconf-node-topology">17830</port>
      <username xmlns="urn:opendaylight:netconf-node-topology">admin</username>
      <password xmlns="urn:opendaylight:netconf-node-topology">admin</password>
      <tcp-only xmlns="urn:opendaylight:netconf-node-topology">false</tcp-only>
      <keepalive-delay xmlns="urn:opendaylight:netconf-node-topology">0</keepalive-delay>
      </node>

      I think it is a bug. I use the testtool with version 1.4.3-SNAPSHOT in Netconf master branch and controller with feature odl-netconf-console 1.5.0-SNAPSHOT, the karaf log shows:

      2018-08-01T09:34:49,377 | DEBUG | nioEventLoopGroupCloseable-4-1 | AsyncSshHandler | 281 - org.opendaylight.netconf.netty-util - 1.5.0.SNAPSHOT | Starting SSH to /10.96.33.30:17830 on channel: [id: 0x7024df42]
      2018-08-01T09:34:49,377 | DEBUG | nioEventLoopGroupCloseable-4-1 | DefaultConfigFileHostEntryResolver | 54 - org.apache.sshd.core - 1.6.0 | resolveEffectiveHost(admin@10.96.33.30:17830) => null
      2018-08-01T09:34:49,378 | DEBUG | nioEventLoopGroupCloseable-4-1 | SshClient | 54 - org.apache.sshd.core - 1.6.0 | connect(admin@10.96.33.30:17830) no overrides
      2018-08-01T09:34:49,381 | DEBUG | nioEventLoopGroupCloseable-4-1 | Nio2Connector | 54 - org.apache.sshd.core - 1.6.0 | Connecting to /10.96.33.30:17830
      2018-08-01T09:34:49,385 | DEBUG | nioEventLoopGroupCloseable-4-1 | Nio2Connector | 54 - org.apache.sshd.core - 1.6.0 | setOption(SO_REUSEADDR)[true] from property=socket-reuseaddr
      2018-08-01T09:34:49,397 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | Creating IoSession on /172.20.68.20:49994 from /10.96.33.30:17830
      2018-08-01T09:34:49,430 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | Client session created: Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]
      2018-08-01T09:34:49,434 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientUserAuthService | 54 - org.apache.sshd.core - 1.6.0 | ClientUserAuthService(ClientSessionImpl[null@/10.96.33.30:17830]) client methods: [publickey, keyboard-interactive, password]
      2018-08-01T09:34:49,454 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | sendIdentification(ClientSessionImpl[null@/10.96.33.30:17830]): SSH-2.0-SSHD-CORE-1.6.0
      2018-08-01T09:34:49,454 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | Writing 25 bytes
      2018-08-01T09:34:49,457 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | handleCompletedWriteCycle(Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]) finished writing len=25
      2018-08-01T09:34:49,458 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | sendKexInit(ClientSessionImpl[null@/10.96.33.30:17830]) Send SSH_MSG_KEXINIT
      2018-08-01T09:34:49,459 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | Writing 592 bytes
      2018-08-01T09:34:49,460 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | handleCompletedWriteCycle(Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]) finished writing len=592
      2018-08-01T09:34:49,484 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | addPasswordIdentity(ClientSessionImpl[admin@/10.96.33.30:17830]) SHA256:jGl25bVBBBW96Qi9Te4V37Fnqchz/Eu4qB9vKrRIqRg
      2018-08-01T09:34:49,486 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientUserAuthService | 54 - org.apache.sshd.core - 1.6.0 | auth(ClientSessionImpl[admin@/10.96.33.30:17830])[ssh-connection] send SSH_MSG_USERAUTH_REQUEST for 'none'
      2018-08-01T09:34:49,496 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | writePacket(ClientSessionImpl[admin@/10.96.33.30:17830])[SSH_MSG_USERAUTH_REQUEST] Start flagging packets as pending until key exchange is done
      2018-08-01T09:34:49,502 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | handleReadCycleCompletion(Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]) read 25 bytes
      2018-08-01T09:34:49,502 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | doReadIdentification(ClientSessionImpl[admin@/10.96.33.30:17830]) line='SSH-2.0-SSHD-CORE-1.6.0'
      2018-08-01T09:34:49,503 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-1 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | readIdentification(ClientSessionImpl[admin@/10.96.33.30:17830]) Server version string: SSH-2.0-SSHD-CORE-1.6.0
      2018-08-01T09:34:49,902 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | handleReadCycleCompletion(Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]) read 552 bytes
      2018-08-01T09:34:49,902 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | handleKexInit(ClientSessionImpl[admin@/10.96.33.30:17830]) SSH_MSG_KEXINIT
      2018-08-01T09:34:49,905 | DEBUG | sshd-SshClient[675d4333]nio2-thread-2 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | setNegotiationResult(ClientSessionImpl[admin@/10.96.33.30:17830]) Kex: server>client aes128-ctr hmac-md5 none
      2018-08-01T09:34:49,905 | DEBUG | sshd-SshClient[675d4333]nio2-thread-2 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | setNegotiationResult(ClientSessionImpl[admin@/10.96.33.30:17830]) Kex: client>server aes128-ctr hmac-md5 none
      2018-08-01T09:34:50,775 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | DHGClient | 54 - org.apache.sshd.core - 1.6.0 | init(DHGClient[ecdh-sha2-nistp521])[ClientSessionImpl[admin@/10.96.33.30:17830]] Send SSH_MSG_KEXDH_INIT
      2018-08-01T09:34:50,777 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | Writing 152 bytes
      2018-08-01T09:34:50,777 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | handleCompletedWriteCycle(Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]) finished writing len=152
      2018-08-01T09:34:50,779 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | handleReadCycleCompletion(Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]) Socket has been disconnected (result=-1), closing IoSession now
      2018-08-01T09:34:50,779 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | Nio2Session | 54 - org.apache.sshd.core - 1.6.0 | close(Nio2Session[local=/172.20.68.20:49994, remote=/10.96.33.30:17830]) Closing immediately
      2018-08-01T09:34:50,780 | DEBUG | sshd-SshClient[675d4333]-nio2-thread-2 | ClientSessionImpl | 54 - org.apache.sshd.core - 1.6.0 | close(ClientSessionImpl[admin@/10.96.33.30:17830]) Closing immediately
      2018-08-01T09:34:50,780 | WARN | sshd-SshClient[675d4333]-nio2-thread-2 | AsyncSshHandler | 281 - org.opendaylight.netconf.netty-util - 1.5.0.SNAPSHOT | Unable to setup SSH connection on channel: [id: 0x7024df42]
      org.apache.sshd.common.SshException: Session is being closed
      at org.apache.sshd.client.session.ClientSessionImpl.preClose(ClientSessionImpl.java:126) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:80) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.sessionClosed(AbstractSessionIoHandler.java:48) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2Session.doCloseImmediately(Nio2Session.java:216) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:81) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:298) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:264) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:261) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38) ~[54:org.apache.sshd.core:1.6.0]
      at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
      at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37) ~[54:org.apache.sshd.core:1.6.0]
      at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) ~[?:?]
      at sun.nio.ch.Invoker.invokeDirect(Invoker.java:157) ~[?:?]
      at sun.nio.ch.UnixAsynchronousSocketChannelImpl.implRead(UnixAsynchronousSocketChannelImpl.java:553) ~[?:?]
      at sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:276) ~[?:?]
      at sun.nio.ch.AsynchronousSocketChannelImpl.read(AsynchronousSocketChannelImpl.java:297) ~[?:?]
      at org.apache.sshd.common.io.nio2.Nio2Session.doReadCycle(Nio2Session.java:312) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:288) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:264) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:261) ~[54:org.apache.sshd.core:1.6.0]
      at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38) ~[54:org.apache.sshd.core:1.6.0]
      at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
      at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37) [54:org.apache.sshd.core:1.6.0]
      at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126) [?:?]
      at sun.nio.ch.Invoker$2.run(Invoker.java:218) [?:?]
      at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112) [?:?]
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
      at java.lang.Thread.run(Thread.java:748) [?:?]

      Attachments

        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

        Activity

          People

            wsx25289 wang senxiao
            wsx25289 wang senxiao
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: