CESNET / netopeer2

NETCONF toolset
BSD 3-Clause "New" or "Revised" License
301 stars 189 forks source link

SSH key exchange error #448

Closed anabel1012 closed 4 years ago

anabel1012 commented 5 years ago

Hi, My netopeer2-server crashes and I cannot resolve the problem. I'm using Netopeer2 (v0.7-r2), libyang (v0.16-r2), libnetconf2 (v0.12-r1) and sysrepo (v0.7.7). This occurs when I try to connect a client to the server. The error is the following:

[INF]: Listening on 0.0.0.0:830 for SSH connections. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/host-keys" created. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/host-keys/host-key[name='imported SSH key']/name" created. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/host-keys/host-key[name='imported SSH key']/public-key" created. [INF]: Accepted a connection on 0.0.0.0:830. [2019/07/31 07:58:29.301905, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/07/31 07:58:29.303280, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/07/31 07:58:29.303319, 1] ssh_socket_exception_callback: Socket error: disconnected [ERR]: SSH key exchange error (Socket error: disconnected). [INF]: Accepted a connection on 0.0.0.0:830. [2019/07/31 07:58:53.145836, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/07/31 07:58:53.147076, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/07/31 07:58:53.147107, 1] ssh_socket_exception_callback: Socket error: disconnected [ERR]: SSH key exchange error (Socket error: disconnected). [INF]: Accepted a connection on 0.0.0.0:830. [2019/07/31 07:58:53.154803, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/07/31 07:58:53.155948, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/07/31 07:58:53.155960, 1] ssh_socket_exception_callback: Socket error: disconnected [ERR]: SSH key exchange error (Socket error: disconnected). [INF]: Accepted a connection on 0.0.0.0:830. [2019/07/31 07:58:53.432362, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/07/31 07:58:53.448503, 1] ssh_server_connection_callback: SSH client banner: SSH-2.0-SSHD-UNKNOWN [2019/07/31 07:58:53.448520, 1] ssh_analyze_banner: Analyzing banner: SSH-2.0-SSHD-UNKNOWN [2019/07/31 07:58:53.448632, 2] ssh_kex_select_methods: Negotiated ecdh-sha2-nistp521,ssh-rsa,aes128-ctr,aes128-ctr,hmac-sha1,hmac-sha1,none,none,, [2019/07/31 07:58:53.468919, 2] ssh_server_ecdh_init: SSH_MSG_KEXDH_REPLY sent [2019/07/31 07:58:53.468948, 2] ssh_server_ecdh_init: SSH_MSG_NEWKEYS sent [2019/07/31 07:58:53.496701, 2] ssh_packet_newkeys: Received SSH_MSG_NEWKEYS [INF]: Received an SSH message "request-service" of subtype "ssh-userauth". [INF]: Received an SSH message "request-auth" of subtype "none". [INF]: Received an SSH message "request-auth" of subtype "publickey". [INF]: User "root" tried to use an unknown (unauthorized) public key. [INF]: Failed user "root" authentication attempt (#1). [INF]: Received an SSH message "request-auth" of subtype "interactive". [2019/07/31 07:58:53.811764, 2] ssh_message_auth_interactive_request: Warning: Got a keyboard-interactive response but it seems we didn't send the request. [INF]: Received an SSH message "request-auth" of subtype "interactive". [INF]: User "root" authenticated. [INF]: Received an SSH message "request-channel-open" of subtype "session". [INF]: Received an SSH message "request-channel" of subtype "subsystem". [2019/07/31 07:58:53.830315, 2] grow_window: growing window (channel 43:0) to 1280000 bytes [INF]: Generated new event (netconf-session-start). [INF]: Resolving unresolved data nodes and their constraints... [INF]: All data nodes and constraints resolved. [INF]: Resolving unresolved data nodes and their constraints... [INF]: All data nodes and constraints resolved. [INF]: Session 1: thread 0 event new RPC. ...

Any help will be greatly appreciated Thanks a lot

Ana

smalls12 commented 5 years ago

Which libssh are you using?

anabel1012 commented 5 years ago

I am using libssh 0.8.5 and I have tried it with 0.9.0 too.

smalls12 commented 5 years ago

And what is your "client" you are using to connect?

anabel1012 commented 5 years ago

I have an scenario with two netopeer2 servers and one client with an ONOS controller. The error occurs when ONOS registers the devices.

Thanks for your help.

smalls12 commented 5 years ago

I'm not familiar with ONOS :(

It looks like a standalone operating system.

Is netopeer2 running on the same box?

anabel1012 commented 5 years ago

No, I have three different instances on Openstack. Anyway, thanks a lot.

I don't know if someone could help to let me know what I am making wrong.

smalls12 commented 5 years ago

Can you connect with netopeer2-cli ?

smalls12 commented 5 years ago

Can you connect with netopeer2-cli ?

anabel1012 commented 5 years ago

yes, I can

smalls12 commented 5 years ago

Still trying to figure out your setup. Is it like this?

+----------------------------+      +----------------------------+      +----------------------------+
|      Ubuntu                |      |      Ubuntu                |      |      OSON                  |
+----------------------------+      +----------------------------+      +----------------------------+
|      Openstack             |      |      Openstack             |      |      Openstack             |
+----------------------------+      +----------------------------+      +----------------------------+
|                            |      |                            |      |                            |
|    +------------------+    |      |    +------------------+    |      |    +------------------+    |
|    | netopeer2-server |    |      |    | netopeer2-server |    |      |    |   some client    |    |
|    |                  |    |      |    |                  |    |      |    |                  |    |
|    +------------------+    |      |    +------------------+    |      |    +------------------+    |
|                            |      |                            |      |                            |
|    +------------------+    |      |    +------------------+    |      |                            |
|    |  netopeer2-cli   |    |      |    |  netopeer2-cli   |    |      |                            |
|    |                  |    |      |    |                  |    |      |                            |
|    +------------------+    |      |    +------------------+    |      |                            |
|                            |      |                            |      |                            |
+----------------------------+      +----------------------------+      +----------------------------+
anabel1012 commented 5 years ago

the figure is the following:

                  onos controller 
                    netopeer-cli>   
                    (10.0.1.200)  
                         |               
          /------------------------------\
         /                                \
        /                                  \
       /                                    \
    (10.0.1.204)                        (10.0.1.234)
 netopeer-server2_h1                  netopeer-server2_h2
  (192.168.0.100) -------------------- (192.168.0.200)
                     (192.168.0.0/24) 
smalls12 commented 5 years ago

Are you able to show the output from ldd for your netopeer2-cli on your onos controller? As well as the netoper2-servers/netopeer2-cli on your other machines ?

Also, can you post the logs from both in debug mode for your use case? netopeer2-server -d v3

For the client, type verb debug

anabel1012 commented 5 years ago

[INF]: (sr_connect:435) Connected to daemon Sysrepo Engine at socket=/tmp/sysrepod.sock [INF]: Netopeer2 connected to sysrepod. [INF]: Plugin "/usr/local/lib/libyang/extensions/libyang_ext_test.so" successfully loaded. [INF]: Plugin "/usr/local/lib/libyang/extensions/nacm.so" successfully loaded. [INF]: Plugin "/usr/local/lib/libyang/extensions/yangdata.so" successfully loaded. [INF]: Plugin "/usr/local/lib/libyang/extensions/metadata.so" successfully loaded. [INF]: Reading module "ietf-yang-metadata". [INF]: Module "ietf-yang-metadata@2016-08-05" successfully parsed as implemented. [INF]: Reading module "yang". [INF]: Resolving "yang" unresolved schema nodes and their constraints... [INF]: All "yang" schema nodes and constraints resolved. [INF]: Module "yang@2017-02-20" successfully parsed as implemented. [INF]: Reading module "ietf-inet-types". [INF]: Resolving derived type "union" failed, it will be attempted later. [INF]: Resolving derived type "union" failed, it will be attempted later. [INF]: Resolving derived type "union" failed, it will be attempted later. [INF]: Resolving derived type "union" failed, it will be attempted later. [INF]: Resolving "ietf-inet-types" unresolved schema nodes and their constraints... [INF]: All "ietf-inet-types" schema nodes and constraints resolved. [INF]: Module "ietf-inet-types@2013-07-15" successfully parsed as implemented. [INF]: Reading module "ietf-yang-types". [INF]: Module "ietf-yang-types@2013-07-15" successfully parsed as implemented. [INF]: Reading module "ietf-datastores". [INF]: Module "ietf-datastores@2017-08-17" successfully parsed as implemented. [INF]: Reading module "ietf-yang-library". [INF]: Module "ietf-yang-library@2018-01-17" successfully parsed as implemented. [INF]: Loading schema "ietf-netconf-notifications@2012-02-06" from sysrepo. [INF]: Reading module "ietf-netconf-notifications". [INF]: Reading module "ietf-netconf". [INF]: Reading module "ietf-netconf-acm". [INF]: Module "ietf-netconf-acm@2018-02-14" successfully parsed as imported. [INF]: Module "ietf-netconf@2011-06-01" successfully parsed as imported. [INF]: Resolving "ietf-netconf-notifications" unresolved schema nodes and their constraints... [INF]: All "ietf-netconf-notifications" schema nodes and constraints resolved. [INF]: Module "ietf-netconf-notifications@2012-02-06" successfully parsed as implemented. [INF]: Loading schema "ietf-netconf@2011-06-01" from sysrepo. [INF]: Module ietf-netconf@2011-06-01 already present in context. [INF]: Module "ietf-netconf@2011-06-01" now implemented. [INF]: Loading schema "ietf-netconf-acm@2018-02-14" from sysrepo. [INF]: Module ietf-netconf-acm@2018-02-14 already present in context. [INF]: Loading schema "nc-notifications@2008-07-14" from sysrepo. [INF]: Reading module "nc-notifications". [INF]: Reading module "notifications". [INF]: Module "notifications@2008-07-14" successfully parsed as imported. [INF]: Module "nc-notifications@2008-07-14" successfully parsed as implemented. [INF]: Loading schema "notifications@2008-07-14" from sysrepo. [INF]: Module notifications@2008-07-14 already present in context. [INF]: Module "notifications@2008-07-14" now implemented. [INF]: Loading schema "turing-machine@2013-12-27" from sysrepo. [INF]: Reading module "turing-machine". [INF]: Module "turing-machine@2013-12-27" successfully parsed as implemented. [INF]: Loading schema "iana-if-type@2014-05-08" from sysrepo. [INF]: Reading module "iana-if-type". [INF]: Reading module "ietf-interfaces". [INF]: Module "ietf-interfaces@2014-05-08" successfully parsed as imported. [INF]: Module "iana-if-type@2014-05-08" successfully parsed as implemented. [INF]: Loading schema "ietf-interfaces@2014-05-08" from sysrepo. [INF]: Module ietf-interfaces@2014-05-08 already present in context. [INF]: Module "ietf-interfaces@2014-05-08" now implemented. [INF]: Loading schema "ietf-ip@2014-06-16" from sysrepo. [INF]: Reading module "ietf-ip". [INF]: Module "ietf-ip@2014-06-16" successfully parsed as implemented. [INF]: Loading schema "ietf-x509-cert-to-name@2014-12-10" from sysrepo. [INF]: Reading module "ietf-x509-cert-to-name". [INF]: Module "ietf-x509-cert-to-name@2014-12-10" successfully parsed as implemented. [INF]: Loading schema "ietf-keystore@2016-10-31" from sysrepo. [INF]: Reading module "ietf-keystore". [INF]: Module "ietf-keystore@2016-10-31" successfully parsed as implemented. [INF]: Loading schema "ietf-netconf-with-defaults@2011-06-01" from sysrepo. [INF]: Reading module "ietf-netconf-with-defaults". [INF]: Module "ietf-netconf-with-defaults@2011-06-01" successfully parsed as implemented. [INF]: Loading schema "ietf-netconf-monitoring@2010-10-04" from sysrepo. [INF]: Reading module "ietf-netconf-monitoring". [INF]: Module "ietf-netconf-monitoring@2010-10-04" successfully parsed as implemented. [INF]: Loading schema "ietf-yang-library@2018-01-17" from sysrepo. [INF]: Module ietf-yang-library@2018-01-17 already present in context. [INF]: Loading schema "ietf-datastores@2017-08-17" from sysrepo. [INF]: Module ietf-datastores@2017-08-17 already present in context. [INF]: Loading schema "ietf-netconf-server@2016-11-02" from sysrepo. [INF]: Reading module "ietf-netconf-server". [INF]: Reading module "ietf-x509-cert-to-name". [INF]: Module "ietf-x509-cert-to-name@2014-12-10" already in context. [INF]: Module "ietf-x509-cert-to-name@2014-12-10" successfully parsed as implemented. [INF]: Reading module "ietf-ssh-server". [INF]: Reading module "ietf-keystore". [INF]: Module "ietf-keystore@2016-10-31" already in context. [INF]: Module "ietf-keystore@2016-10-31" successfully parsed as implemented. [INF]: Module "ietf-ssh-server@2016-11-02" successfully parsed as imported. [INF]: Reading module "ietf-tls-server". [INF]: Module "ietf-tls-server@2016-11-02" successfully parsed as imported. [INF]: Resolving "ietf-netconf-server" unresolved schema nodes and their constraints... [INF]: All "ietf-netconf-server" schema nodes and constraints resolved. [INF]: Module "ietf-netconf-server@2016-11-02" successfully parsed as implemented. [INF]: Loading schema "ietf-ssh-server@2016-11-02" from sysrepo. [INF]: Module ietf-ssh-server@2016-11-02 already present in context. [INF]: Loading schema "ietf-tls-server@2016-11-02" from sysrepo. [INF]: Module ietf-tls-server@2016-11-02 already present in context. [INF]: Loading schema "ietf-system@2014-08-06" from sysrepo. [INF]: Reading module "ietf-system". [INF]: Reading module "iana-crypt-hash". [INF]: Module "iana-crypt-hash@2014-08-06" successfully parsed as imported. [INF]: Resolving "ietf-system" unresolved schema nodes and their constraints... [INF]: All "ietf-system" schema nodes and constraints resolved. [INF]: Module "ietf-system@2014-08-06" successfully parsed as implemented. [INF]: Loading schema "iana-crypt-hash@2014-08-06" from sysrepo. [INF]: Module iana-crypt-hash@2014-08-06 already present in context. [INF]: Loading schema "ietf-ipsec@2018-10-24" from sysrepo. [INF]: Reading module "ietf-ipsec". [INF]: Resolving "ietf-ipsec" unresolved schema nodes and their constraints... [INF]: All "ietf-ipsec" schema nodes and constraints resolved. [INF]: Module "ietf-ipsec@2018-10-24" successfully parsed as implemented. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/name" created. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh" created. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/address" created. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/port" created. [INF]: Listening on 0.0.0.0:830 for SSH connections. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/host-keys" created. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/host-keys/host-key[name='imported SSH key']/name" created. [INF]: Path "/ietf-netconf-server:netconf-server/listen/endpoint[name='all-interfaces']/ssh/host-keys/host-key[name='imported SSH key']/public-key" created. [INF]: Accepted a connection on 0.0.0.0:830. [2019/08/01 09:44:15.893914, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/01 09:44:15.895539, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/01 09:44:15.895674, 1] ssh_socket_exception_callback: Socket error: disconnected [ERR]: SSH key exchange error (Socket error: disconnected). [INF]: Accepted a connection on 0.0.0.0:830. [2019/08/01 09:44:45.902064, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/01 09:44:45.903398, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/01 09:44:45.903426, 1] ssh_socket_exception_callback: Socket error: disconnected [ERR]: SSH key exchange error (Socket error: disconnected). [INF]: Accepted a connection on 0.0.0.0:830. [2019/08/01 09:45:05.436169, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [INF]: Accepted a connection on 0.0.0.0:830. [2019/08/01 09:45:05.436502, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/01 09:45:05.437425, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/01 09:45:05.437445, 1] ssh_socket_exception_callback: Socket error: disconnected [ERR]: SSH key exchange error (Socket error: disconnected). [2019/08/01 09:45:05.437727, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/01 09:45:05.437793, 1] ssh_socket_exception_callback: Socket error: disconnected [ERR]: SSH key exchange error (Socket error: disconnected). [INF]: Accepted a connection on 0.0.0.0:830. [2019/08/01 09:45:05.446883, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/01 09:45:05.448135, 1] ssh_server_connection_callback: SSH client banner: SSH-2.0-SSHD-UNKNOWN [2019/08/01 09:45:05.448252, 1] ssh_analyze_banner: Analyzing banner: SSH-2.0-SSHD-UNKNOWN [2019/08/01 09:45:05.448437, 2] ssh_kex_select_methods: Negotiated ecdh-sha2-nistp521,ssh-rsa,aes128-ctr,aes128-ctr,hmac-sha1,hmac-sha1,none,none,, [2019/08/01 09:45:05.455052, 2] ssh_server_ecdh_init: SSH_MSG_KEXDH_REPLY sent [2019/08/01 09:45:05.455171, 2] ssh_server_ecdh_init: SSH_MSG_NEWKEYS sent [2019/08/01 09:45:05.461627, 2] ssh_packet_newkeys: Received SSH_MSG_NEWKEYS [INF]: Received an SSH message "request-service" of subtype "ssh-userauth". [INF]: Received an SSH message "request-auth" of subtype "none". [INF]: Received an SSH message "request-auth" of subtype "publickey". [INF]: User "root" tried to use an unknown (unauthorized) public key. [INF]: Failed user "root" authentication attempt (#1). [INF]: Received an SSH message "request-auth" of subtype "interactive". [2019/08/01 09:45:05.547857, 2] ssh_message_auth_interactive_request: Warning: Got a keyboard-interactive response but it seems we didn't send the request. [INF]: Received an SSH message "request-auth" of subtype "interactive". [INF]: User "root" authenticated. [INF]: Received an SSH message "request-channel-open" of subtype "session". [INF]: Received an SSH message "request-channel" of subtype "subsystem". [2019/08/01 09:45:05.554113, 2] grow_window: growing window (channel 43:0) to 1280000 bytes [INF]: Resolving unresolved data nodes and their constraints... [INF]: All data nodes and constraints resolved. [INF]: Generated new event (netconf-session-start). [INF]: Resolving unresolved data nodes and their constraints... [INF]: All data nodes and constraints resolved.

michalvasko commented 5 years ago

Hi, I think this is your client's fault because the server simply reports that it was disconnected. Also, the session is created in the end based on the output, is it not?

Regards, Michal

anabel1012 commented 5 years ago

Sessions are created continuously and onos devices are connecting and disconnecting continuously too.

VERBOSE: Session 1: thread 1 event new RPC. VERBOSE: Accepted a connection on 0.0.0.0:830. [2019/08/05 13:46:46.186814, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/05 13:46:46.187948, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/05 13:46:46.187961, 1] ssh_socket_exception_callback: Socket error: disconnected ERROR: SSH key exchange error (Socket error: disconnected). VERBOSE: Accepted a connection on 0.0.0.0:830. [2019/08/05 13:46:46.193658, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false VERBOSE: Accepted a connection on 0.0.0.0:830. [2019/08/05 13:46:46.193747, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false VERBOSE: Accepted a connection on 0.0.0.0:830. [2019/08/05 13:46:46.193873, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/05 13:46:46.194773, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/05 13:46:46.194785, 1] ssh_socket_exception_callback: Socket error: disconnected ERROR: SSH key exchange error (Socket error: disconnected). [2019/08/05 13:46:46.194861, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/05 13:46:46.194869, 1] ssh_socket_exception_callback: Socket error: disconnected ERROR: SSH key exchange error (Socket error: disconnected). [2019/08/05 13:46:46.194937, 1] ssh_server_connection_callback: SSH client banner: SSH-2.0-SSHD-UNKNOWN [2019/08/05 13:46:46.194946, 1] ssh_analyze_banner: Analyzing banner: SSH-2.0-SSHD-UNKNOWN [2019/08/05 13:46:46.196057, 2] ssh_kex_select_methods: Negotiated ecdh-sha2-nistp521,ssh-rsa,aes128-ctr,aes128-ctr,hmac-sha1,hmac-sha1,none,none,, [2019/08/05 13:46:46.235068, 2] ssh_server_ecdh_init: SSH_MSG_KEXDH_REPLY sent [2019/08/05 13:46:46.235095, 2] ssh_server_ecdh_init: SSH_MSG_NEWKEYS sent [2019/08/05 13:46:46.251044, 2] ssh_packet_newkeys: Received SSH_MSG_NEWKEYS VERBOSE: Received an SSH message "request-service" of subtype "ssh-userauth". VERBOSE: Received an SSH message "request-auth" of subtype "none". VERBOSE: Received an SSH message "request-auth" of subtype "publickey". VERBOSE: User "root" tried to use an unknown (unauthorized) public key. VERBOSE: Failed user "root" authentication attempt (#1). VERBOSE: Received an SSH message "request-auth" of subtype "interactive". [2019/08/05 13:46:46.387951, 2] ssh_message_auth_interactive_request: Warning: Got a keyboard-interactive response but it seems we didn't send the request. VERBOSE: Received an SSH message "request-auth" of subtype "interactive". VERBOSE: User "root" authenticated. VERBOSE: Received an SSH message "request-channel-open" of subtype "session". VERBOSE: Received an SSH message "request-channel" of subtype "subsystem". [2019/08/05 13:46:46.392859, 2] grow_window: growing window (channel 43:0) to 1280000 bytes VERBOSE: Generated new event (netconf-session-start). VERBOSE: Resolving unresolved data nodes and their constraints... VERBOSE: All data nodes and constraints resolved. VERBOSE: Resolving unresolved data nodes and their constraints... VERBOSE: All data nodes and constraints resolved. VERBOSE: Session 2: thread 4 event new RPC. VERBOSE: Accepted a connection on 0.0.0.0:830. [2019/08/05 13:46:46.446348, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/05 13:46:46.447478, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/05 13:46:46.447491, 1] ssh_socket_exception_callback: Socket error: disconnected ERROR: SSH key exchange error (Socket error: disconnected). VERBOSE: Accepted a connection on 0.0.0.0:830. [2019/08/05 13:46:46.449192, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false VERBOSE: Accepted a connection on 0.0.0.0:830. [2019/08/05 13:46:46.449304, 2] ssh_pki_import_privkey_base64: Trying to decode privkey passphrase=false [2019/08/05 13:46:46.450293, 1] ssh_socket_exception_callback: Socket exception callback: 1 (0) [2019/08/05 13:46:46.450305, 1] ssh_socket_exception_callback: Socket error: disconnected ERROR: SSH key exchange error (Socket error: disconnected). [2019/08/05 13:46:46.450404, 1] ssh_server_connection_callback: SSH client banner: SSH-2.0-SSHD-UNKNOWN [2019/08/05 13:46:46.450414, 1] ssh_analyze_banner: Analyzing banner: SSH-2.0-SSHD-UNKNOWN [2019/08/05 13:46:46.450447, 2] ssh_kex_select_methods: Negotiated ecdh-sha2-nistp521,ssh-rsa,aes128-ctr,aes128-ctr,hmac-sha1,hmac-sha1,none,none,, [2019/08/05 13:46:46.457441, 2] ssh_server_ecdh_init: SSH_MSG_KEXDH_REPLY sent [2019/08/05 13:46:46.457470, 2] ssh_server_ecdh_init: SSH_MSG_NEWKEYS sent [2019/08/05 13:46:46.466001, 2] ssh_packet_newkeys: Received SSH_MSG_NEWKEYS VERBOSE: Received an SSH message "request-service" of subtype "ssh-userauth". VERBOSE: Received an SSH message "request-auth" of subtype "none". VERBOSE: Received an SSH message "request-auth" of subtype "publickey". VERBOSE: User "root" tried to use an unknown (unauthorized) public key. VERBOSE: Failed user "root" authentication attempt (#1). VERBOSE: Received an SSH message "request-auth" of subtype "interactive". [2019/08/05 13:46:46.632239, 2] ssh_message_auth_interactive_request: Warning: Got a keyboard-interactive response but it seems we didn't send the request. VERBOSE: Received an SSH message "request-auth" of subtype "interactive". VERBOSE: User "root" authenticated. VERBOSE: Received an SSH message "request-channel-open" of subtype "session". VERBOSE: Received an SSH message "request-channel" of subtype "subsystem". [2019/08/05 13:46:46.636517, 2] grow_window: growing window (channel 43:0) to 1280000 bytes VERBOSE: Generated new event (netconf-session-start). VERBOSE: Resolving unresolved data nodes and their constraints... VERBOSE: All data nodes and constraints resolved. VERBOSE: Resolving unresolved data nodes and their constraints... VERBOSE: All data nodes and constraints resolved. VERBOSE: Session 3: thread 2 event new RPC. VERBOSE: Accepted a connection on 0.0.0.0:830.

Could it be a problem with libssh?

michalvasko commented 5 years ago

The output does not include any error except for sudden disconnects of the client so I do not think even libssh is at fault. Even if the sessions are being created/terminated, the client should close each session correctly with <close-session>.

Regards, Michal

smalls12 commented 5 years ago

It looks like your system isn't actually using libssh based off of this line:

ssh_server_connection_callback: SSH client banner: SSH-2.0-SSHD-UNKNOWN
ssh_analyze_banner: Analyzing banner: SSH-2.0-SSHD-UNKNOWN

I'm used to ssh banners like this:

ssh_server_connection_callback: SSH client banner: SSH-2.0-libssh_0.8.7
ssh_analyze_banner: Analyzing banner: SSH-2.0-libssh_0.8.7

Maybe something, maybe nothing.

Aaru47527 commented 2 months ago

Hello,

I am experiencing an issue with my Netopeer2 server, which crashes whenever I attempt to connect a client. Here are the details of my setup and the problem:

Environment: Netopeer2 Version: 1.1.76 libyang Version: 1.0.240 libnetconf2 Version: 1.1.46 sysrepo Version: 1.4.140 OS: [Specify your operating system and version] Steps to Reproduce: Start the Netopeer2 server:

sudo systemctl start netopeer2-server.service Verify that the server is running:

sudo systemctl status netopeer2-server.service Attempt to connect using Netopeer2 CLI:

sudo netopeer2-cli

cert add /path/to/tls_cert/ca.pem cert replaceown /path/to/tls_cert/client.crt /path/to/tls_cert/client.key connect --host 127.0.0.1 --port 830 --cert /path/to/tls_cert/client.crt --key /path/to/tls_cert/client.key --trusted /path/totls_cert/ca.pem nc ERROR: SSL_connect failed (Success). cmd_connect: Connecting to the 127.0.0.1:830 failed.

Observed Behavior: The server accepts the connection and creates a session. Shortly after, the server crashes with the following error message in the logs: yaml [2024/07/16 11:39:33.100269, 1] ssh_socket_exception_callback: Socket exception callback: 2 (2) [ERR]: LN: SSH key exchange error (Socket error: No such file or directory). Server Logs: Jul 16 11:22:30 13266--SW--MCP7 netopeer2-server[11507]: [2024/07/16 11:22:30.632029, 1] ssh_socket_exception_callback: Socket exception cal> Jul 16 11:22:30 13266--SW--MCP7 netopeer2-server[11507]: Communication socket unexpectedly closed (libssh). Jul 16 11:22:30 13266--SW--MCP7 netopeer2-server[11507]: [ERR]: LN: Communication socket unexpectedly closed (libssh). Jul 16 11:39:33 13266--SW--MCP7 netopeer2-server[11507]: Accepted a connection on 0.0.0.0:830. Jul 16 11:39:33 13266--SW--MCP7 netopeer2-server[11507]: [INF]: LN: Accepted a connection on 0.0.0.0:830. Jul 16 11:39:33 13266--SW--MCP7 netopeer2-server[11507]: Session 70 (user "root", CID 2) created. Jul 16 11:39:33 13266--SW--MCP7 netopeer2-server[11507]: [INF]: SR: Session 70 (user "root", CID 2) created. Jul 16 11:39:33 13266--SW--MCP7 netopeer2-server[11507]: [2024/07/16 11:39:33.100269, 1] ssh_socket_exception_callback: Socket exception cal> Jul 16 11:39:33 13266--SW--MCP7 netopeer2-server[11507]: [ERR]: LN: SSH key exchange error (Socket error: No such file or directory). Jul 16 11:39:33 13266--SW--MCP7 netopeer2-server[11507]: SSH key exchange error (Socket error: No such file or directory). Additional Information: I have verified that the SSH key files exist and have the correct permissions:

sudo ls -l /etc/ssh/ssh_host_rsa_key sudo ls -l /etc/ssh/ssh_host_rsa_key.pub sudo chmod 600 /etc/ssh/ssh_host_rsa_key sudo chmod 644 /etc/ssh/ssh_host_rsa_key.pub

The Netopeer2 server configuration points to these key files: xml

default 830 /etc/ssh/ssh_host_rsa_key.pub /etc/ssh/ssh_host_rsa_key

Questions: Is there a specific configuration or step I might be missing to resolve the SSH key exchange error? Are there known issues with the versions of Netopeer2, libyang, libnetconf2, and sysrepo that I am using? Any additional debugging steps or logs I should provide to help diagnose this issue? Any help would be greatly appreciated. Thank you! Aarti

michalvasko commented 2 months ago

Sorry, you are using an old version that is no longer supported, I cannot help you.

Aaru47527 commented 2 months ago

For a solution, please suggest the latest version that works properly on our PC to establish a TLS connection.

michalvasko commented 2 months ago

You should always use the latest release.

Aaru47527 commented 2 months ago

I am facing an issue with the Netopeer2 server service on the latest version. The service fails to start and repeatedly exits with an exit code 127. Below are the details from the systemctl status netopeer2-server command:

ld$ sudo systemctl status netopeer2-server ● netopeer2-server.service - Netopeer2 Server Loaded: loaded (/etc/systemd/system/netopeer2-server.service; enabled; vendor preset: enabled) Active: failed (Result: exit-code) since Tue 2024-07-16 16:46:03 IST; 413ms ago Process: 221929 ExecStart=/usr/local/bin/netopeer2-server -d -v3 (code=exited, status=127) Main PID: 221929 (code=exited, status=127)

Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: netopeer2-server.service: Scheduled restart job, restart counter is at 5. Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: Stopped Netopeer2 Server. Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: netopeer2-server.service: Start request repeated too quickly. Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: netopeer2-server.service: Failed with result 'exit-code'. Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: Failed to start Netopeer2 Server. Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: netopeer2-server.service: Start request repeated too quickly. Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: netopeer2-server.service: Failed with result 'exit-code'. Jul 16 16:46:03 13266--SW--MCP7 systemd[1]: Failed to start Netopeer2 Server. 13266--SW--MCP7:~/Downloads/netopeer2-2.2.28/build$

netopeer2-cli

cert add /path/to/tls_cert/ca.pem Doing /root/.netopeer2-cli/certs

cert replaceown /path/to/tls_cert/client.crt /home/vvdn/tls_cert/client.key --host 127.0.0.1 --port 830 --cert /path/to/tls_cert/client.crt --key /path/to/tls_cert/client.key --trusted /path/to/tls_cert/ca.pem nc ERROR: Unable to connect to 127.0.0.1:830 (Connection refused). cmd_connect: Connecting to the 127.0.0.1:830 failed.

michalvasko commented 2 months ago

Look into journalctl to see server output, nothing from this output is interesting.