in reply to Re: Net::OpenSSH multiple sessions and legacy KEX problem
in thread Net::OpenSSH multiple sessions and legacy KEX problem

I assumed that the first connection is up based on these logs

 
debug3: channel 2: status: The following connections are open:
  #1 client-session (t3 r-1 i0/0 o0/0 fd 5/6 cc -1)
  #2 mux-control (t16 r-1 i3/0 o3/0 fd 8/8 cc -1)

[download]

It doesn't mean it works and I can send commands to router. Right after Net::OpenSSH->new() I call open2pty() and then Telnet->new(). Calling Telnet->new() seems to cause kex warning log on remote side and closing the session

I hope the log can explain things better then I can

 tester@okon:~$ /tmp/get_prefixes.v01.pl /tmp/bg2
# open_ex: ['/opt/openssh/bin/ssh','-V']
# io3 mloop, cin: 0, cout: 1, cerr: 0
# io3 fast, cin: 0, cout: 1, cerr: 0
# stdout, bytes read: 60 at offset 0
#> 4f 70 65 6e 53 53 48 5f 37 2e 34 70 31 20 44 65 62 69 61 6e 2d 31 3
+0 2b 64 65 62 39 75 32 2c 20 | OpenSSH_7.4p1 Debian-10+deb9u2, 
#> 4f 70 65 6e 53 53 4c 20 31 2e 30 2e 32 6c 20 20 32 35 20 4d 61 79 2
+0 32 30 31 37 0a             | OpenSSL 1.0.2l  25 May 2017.
# io3 fast, cin: 0, cout: 1, cerr: 0
# stdout, bytes read: 0 at offset 60
# leaving _io3()
# _waitpid(9075) => pid: 9075, rc: 0, err: 
# OpenSSH version is 7.4p1
# ctl_path: /home/tester/.libnet-openssh-perl/63b73f6e4e5b8c80de38830e
+60d628b6, ctl_dir: /home/tester/.libnet-openssh-perl/
# _is_secure_path(dir: /home/tester/.libnet-openssh-perl, file mode: 1
+6832, file uid: 1001, euid: 1001
# _is_secure_path(dir: /home/tester, file mode: 16877, file uid: 1001,
+ euid: 1001
# set_error(0 - 0)
# call args: ['/opt/openssh/bin/ssh','-o','StrictHostKeyChecking=no','
+-o','UserKnownHostsFile=/dev/null','-o','NumberOfPasswordPrompts=1','
+-o','KexAlgorithms=diffie-hellman-group1-sha1','-o','HostKeyAlgorithm
+s=ssh-dss','-o','Ciphers=3des-cbc,blowfish-cbc','-o','PreferredAuthen
+tications=keyboard-interactive,password','-o','LogLevel=DEBUG3','-o',
+'ServerAliveInterval=30','-o','ControlPersist=no','-2MNx','-o','Numbe
+rOfPasswordPrompts=1','-o','PreferredAuthentications=keyboard-interac
+tive,password','-S','/home/tester/.libnet-openssh-perl/63b73f6e4e5b8c
+80de38830e60d628b6','-l','pwlodawi@adm','10.10.3.6','--']
# master state jumping from _STATE_START to _STATE_LOGIN
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
debug1: Reading configuration data /home/tester/.ssh/config
debug1: /home/tester/.ssh/config line 19: Applying options for 10.10.3
+.?
debug3: kex names ok: [diffie-hellman-group1-sha1]
debug3: kex names ok: [diffie-hellman-group-exchange-sha256,diffie-hel
+lman-group14-sha1,diffie-hellman-group1-sha1]
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: Applying options for *
debug2: resolving "10.10.3.6" port 22
debug2: ssh_connect_direct: needpriv 0
debug1: Connecting to 10.10.3.6 [10.10.3.6] port 22.
debug1: Connection established.
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_rsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_rsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_dsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_dsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_ecdsa type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_ecdsa-cert type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_ed25519 type -1
debug1: key_load_public: No such file or directory
debug1: identity file /home/tester/.ssh/id_ed25519-cert type -1
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.4p1 Debian-10+deb9u2
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
debug1: Remote protocol version 2.0, remote software version 2.0.12
debug1: match: 2.0.12 pat 2.0.11*,2.0.12* compat 0x0092227f
Server version "2.0.12" uses unsafe RSA signature scheme; disabling us
+e of RSA keys
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to 10.10.3.6:22 as 'pwlodawi@adm'
debug2: compat_pkalg_proposal: original public key proposal: ssh-dss
debug2: compat_pkalg_proposal: compat public key proposal: ssh-dss
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms: diffie-hellman-group1-sha1,ext-info-c
debug2: host key algorithms: ssh-dss
debug2: ciphers ctos: 3des-cbc,blowfish-cbc
debug2: ciphers stoc: 3des-cbc,blowfish-cbc
debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hm
+ac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-e
+tm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256
+,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hm
+ac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-e
+tm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256
+,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib@openssh.com,zlib
debug2: compression stoc: none,zlib@openssh.com,zlib
debug2: languages ctos: 
debug2: languages stoc: 
debug2: first_kex_follows 0 
debug2: reserved 0 
debug2: peer server KEXINIT proposal
debug2: KEX algorithms: diffie-hellman-group1-sha1
debug2: host key algorithms: ssh-dss
debug2: ciphers ctos: 3des-cbc,blowfish-cbc,twofish-cbc
debug2: ciphers stoc: 3des-cbc,blowfish-cbc,twofish-cbc
debug2: MACs ctos: hmac-sha1,hmac-sha1-96,hmac-md5
debug2: MACs stoc: hmac-sha1,hmac-sha1-96,hmac-md5
debug2: compression ctos: none
debug2: compression stoc: none
debug2: languages ctos: 
debug2: languages stoc: 
debug2: first_kex_follows 0 
debug2: reserved 0 
debug1: kex: algorithm: diffie-hellman-group1-sha1
debug1: kex: host key algorithm: ssh-dss
debug1: kex: server->client cipher: 3des-cbc MAC: hmac-sha1 compressio
+n: none
debug1: kex: client->server cipher: 3des-cbc MAC: hmac-sha1 compressio
+n: none
debug1: sending SSH2_MSG_KEXDH_INIT
debug2: bits set: 511/1024
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEXDH_REPLY
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
debug3: receive packet: type 31
debug1: Server host key: ssh-dss SHA256:SwtXDiFOd6VL+63BiCB3ECSLVl9+Ew
+yyNShkdOkv1qM
debug3: hostkeys_foreach: reading file "/dev/null"
Warning: Permanently added '10.10.3.6' (DSA) to the list of known host
+s.
debug2: bits set: 501/1024
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
debug3: receive packet: type 21
debug1: SSH2_MSG_NEWKEYS received
debug2: set_newkeys: mode 0
debug1: rekey after 134217728 blocks
debug2: key: /home/tester/.ssh/id_rsa ((nil))
debug2: key: /home/tester/.ssh/id_dsa ((nil))
debug2: key: /home/tester/.ssh/id_ecdsa ((nil))
debug2: key: /home/tester/.ssh/id_ed25519 ((nil))
debug3: send packet: type 5
debug3: receive packet: type 6
debug2: buggy server: service_accept w/o service
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_LOGIN
debug3: receive packet: type 51
debug1: Authentications that can continue: password
debug3: start over, passed a different list password
debug3: preferred keyboard-interactive,password
debug3: authmethod_lookup password
debug3: remaining preferred: ,password
debug3: authmethod_is_enabled password
debug1: Next authentication method: password
# passwd/passphrase requested (pwlodawi@adm@10.10.3.6's password:)
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_AWAITING_MUX
debug3: send packet: type 50
debug2: we sent a password packet, wait for reply
# file object not yet found at /home/tester/.libnet-openssh-perl/63b73
+f6e4e5b8c80de38830e60d628b6, state:_STATE_AWAITING_MUX
debug3: receive packet: type 52
debug1: Authentication succeeded (password).
Authenticated to 10.10.3.6 ([10.10.3.6]:22).
debug1: setting up multiplex master socket
debug3: muxserver_listen: temporary control path /home/tester/.libnet-
+openssh-perl/63b73f6e4e5b8c80de38830e60d628b6.c5hK9F4D2g1RgQ4O
debug2: fd 4 setting O_NONBLOCK
debug3: fd 4 is O_NONBLOCK
debug3: fd 4 is O_NONBLOCK
debug1: channel 0: new [/home/tester/.libnet-openssh-perl/63b73f6e4e5b
+8c80de38830e60d628b6]
debug3: muxserver_listen: mux listener channel 0 fd 4
debug1: channel 1: new [client-session]
debug3: ssh_session2_open: channel_new: 1
debug2: channel 1: send open
debug3: send packet: type 90
debug1: Entering interactive session.
debug1: pledge: id
# file object found at /home/tester/.libnet-openssh-perl/63b73f6e4e5b8
+c80de38830e60d628b6
# master state jumping from _STATE_AWAITING_MUX to _STATE_RUNNING
# call args: ['/opt/openssh/bin/ssh','-O','check','-T','-S','/home/tes
+ter/.libnet-openssh-perl/63b73f6e4e5b8c80de38830e60d628b6','-l','pwlo
+dawi@adm','10.10.3.6','--']
# open_ex: ['/opt/openssh/bin/ssh','-O','check','-T','-S','/home/teste
+r/.libnet-openssh-perl/63b73f6e4e5b8c80de38830e60d628b6','-l','pwloda
+wi@adm','10.10.3.6','--']
# io3 mloop, cin: 0, cout: 1, cerr: 0
# io3 fast, cin: 0, cout: 1, cerr: 0
debug1: multiplexing control connection
debug2: fd 8 setting O_NONBLOCK
debug3: fd 8 is O_NONBLOCK
debug1: channel 2: new [mux-control]
debug3: channel_post_mux_listener: new mux channel 2 fd 8
debug3: mux_master_read_cb: channel 2: hello sent
debug3: mux_master_read_cb: channel 2 packet type 0x00000001 len 4
debug2: process_mux_master_hello: channel 2 slave version 4
debug3: mux_master_read_cb: channel 2 packet type 0x10000004 len 4
debug2: process_mux_alive_check: channel 2: alive check
# stdout, bytes read: 27 at offset 0
#> 4d 61 73 74 65 72 20 72 75 6e 6e 69 6e 67 20 28 70 69 64 3d 39 30 3
+7 36 29 0d 0a                | Master running (pid=9076)..
# io3 fast, cin: 0, cout: 1, cerr: 0
debug2: channel 2: ctl read<=0 rfd 8 len 0
debug2: channel 2: read failed
debug2: channel 2: close_read
# debug2: channel 2: input open -> drain
stdout, bytes read: 0 at offset 27debug2: channel 2: ibuf empty

debug2: channel 2: input drain -> closed
debug2: channel 2: rcvd close
debug2: channel 2: output open -> drain
debug2: channel 2: obuf empty
debug2: channel 2: close_write
debug2: channel 2: output drain -> closed
# leaving _io3()debug2: channel 2: is dead (local)

debug2: channel 2: gc: notify user
debug3: mux_master_control_cleanup_cb: entering for channel 2
debug2: channel 2: gc: user detached
debug2: channel 2: is dead (local)
debug2: channel 2: garbage collecting
debug1: channel 2: free: mux-control, nchannels 3
debug3: channel 2: status: The following connections are open:
  #1 client-session (t3 r-1 i0/0 o0/0 fd 5/6 cc -1)
  #2 mux-control (t16 r-1 i3/0 o3/0 fd 8/8 cc -1)

# _waitpid(9078) => pid: 9078, rc: 0, err: 
Trying open2pty
# call args: ['/opt/openssh/bin/ssh','-qtt','-S','/home/tester/.libnet
+-openssh-perl/63b73f6e4e5b8c80de38830e60d628b6','-l','pwlodawi@adm','
+10.10.3.6','--']
# open_ex: ['/opt/openssh/bin/ssh','-qtt','-S','/home/tester/.libnet-o
+penssh-perl/63b73f6e4e5b8c80de38830e60d628b6','-l','pwlodawi@adm','10
+.10.3.6','--']
opening Telnet
debug1: multiplexing control connection
debug2: fd 8 setting O_NONBLOCK
debug3: fd 8 is O_NONBLOCK
debug1: channel 2: new [mux-control]
debug3: channel_post_mux_listener: new mux channel 2 fd 8
debug3: mux_master_read_cb: channel 2: hello sent
debug3: mux_master_read_cb: channel 2 packet type 0x00000001 len 4
debug2: process_mux_master_hello: channel 2 slave version 4
debug3: mux_master_read_cb: channel 2 packet type 0x10000004 len 4
debug2: process_mux_alive_check: channel 2: alive check
debug3: mux_master_read_cb: channel 2 packet type 0x10000002 len 70
debug2: process_mux_new_session: channel 2: request tty 1, X 0, agent 
+0, subsys 0, term "xterm-256color", cmd "", env 1
debug3: process_mux_new_session: got fds stdin 9, stdout 10, stderr 11
debug1: channel 3: new [client-session]
debug2: process_mux_new_session: channel_new: 3 linked to control chan
+nel 2
debug2: channel 3: send open
debug3: send packet: type 90
debug3: receive packet: type 91
debug2: channel 1: open confirm rwindow 12288 rmax 512
debug3: receive packet: type 1
Received disconnect from 10.10.3.6 port 22:2: Disconnect Protocol erro
+r
Disconnected from 10.10.3.6 port 22
eof read waiting for login prompt:  at /tmp/get_prefixes.v01.pl line 1
+02

# DESTROY(Net::OpenSSH=HASH(0x55b5b6855230), pid: 9076)
# sending exit control to master
# master 9076 exited, rc:65280, err: 
# set_error(1 - control command failed: master process exited unexpect
+edly)
# master state jumping from _STATE_RUNNING to _STATE_GONE
# master state jumping from _STATE_GONE to _STATE_GONE
tester@okon:~$

[download]

Thanks for your help

<Pawel

Replies are listed 'Best First'.
Re^3: Net::OpenSSH multiple sessions and legacy KEX problem
by salva (Canon) on Feb 16, 2018 at 13:58 UTC
    It seems the remote server has a broken SSH implementation: 
    debug3: send packet: type 90  
   # This was the request to open a new channel (SSH_MSG_CHANNEL_OPEN)

debug3: receive packet: type 91
debug2: channel 1: open confirm rwindow 12288 rmax 512
   # That was the Ok response (SSH_MSG_CHANNEL_OPEN_CONFIRMATION)

debug3: receive packet: type 1
Received disconnect from 10.10.3.6 port 22:2: Disconnect Protocol erro
+r
   # And then, suddenly, an unexpected disconnect message saying "Prot
+ocol error"

    [download]

    It is not completely uncommon for some SSH implementations, specially those found in network equipment, to not support more than just one session per connection or requiring it to be open at some specific time (i.e. just after the transport layer becomes ready). There is not much you can do to work-around these issues.

    Net::SSH::Any has the Ssh_Cmd backend which uses ssh in the common way, but then you can not combine it with Net::Telnet. At least, not easily. Net::SSH::Any provides the pipe method, which returns an object emulating a socket... maybe the emulation is good enough for Net::Telnet... I don't know, never tried!

[reply]
[d/l]
[select]

      Just to conclude, there is no way to use Net::OpenSSH with only one session ?

      OpenSSH command line client opens only one session and it works even with this buggy implementation.

      You are right that router's implementation is bad but I can do nothing about that. It's legacy device and there are no chances for new fixed version. I don't have to use Net::Telnet. Having it would make migrating some scripts easier but it's not a must have.

      What I don't like in Net::SSH::Any::Backend::Ssh_Cmd it that is going to open a new connection for each command. Right ?

      Anyway, thanks for your help

      Pawel

[reply]
        Just to conclude, there is no way to use Net::OpenSSH with only one session?

        You are not doing anything fanciful, the basic stuff just doesn't seem to work. I can not imagine how you could avoid that issue.

        What I don't like in Net::SSH::Any::Backend::Ssh_Cmd it that is going to open a new connection for each command. Right?

        Not exactly. Ssh_Cmd runs a new connection for every session. Usually, when the remote side is some server running some Unix/Linux, you run a command per session but in the case of network equipment frequently they provide some custom shell that requires running a conversation against it and executing all commands in the same session. The fact that you want to use Net::Telnet hints in that direction.

[reply]
[d/l]

In Section Seekers of Perl Wisdom