Beefy Boxes and Bandwidth Generously Provided by pair Networks
more useful options
 
PerlMonks  

Re: Net::OpenSSH multiple sessions and legacy KEX problem

by salva (Canon)
on Feb 16, 2018 at 07:11 UTC ( [id://1209272]=note: print w/replies, xml ) Need Help??


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

It is not clear what the real problem is. You are talking about a protocol handshake issue, but then, if I understand you correctly, the first session works. That doesn't make sense.

Could you enable debugging for Net::OpenSSH too ($Net::OpenSSH::debug = (~512);) and post the full output?

Replies are listed 'Best First'.
Re^2: Net::OpenSSH multiple sessions and legacy KEX problem
by pwlodawi (Initiate) on Feb 16, 2018 at 09:03 UTC

    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)

    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:~$

    Thanks for your help

    <Pawel

      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"

      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!

        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

Log In?
Username:
Password:

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: note [id://1209272]
help
Chatterbox?
and the web crawler heard nothing...

How do I use this?Last hourOther CB clients
Other Users?
Others rifling through the Monastery: (4)
As of 2024-04-24 20:32 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    No recent polls found