Error Msg: ex protocol error: type 7 seq

Last Updated on

This seems to be a common / uncommon bug in SSH.  I have notice its appearance during the transfer of large files via SFTP.  Was initially wondering (still am?) if it had to do with bad sectors on the target disk.

http://lists.mindrot.org/pipermail/openssh-unix-dev/2016-August/035350.html

kex protocol error: type 7 seq xxx error message

Aris Adamantiadis aris at 0xbadc0de.be
Tue Aug 30 06:27:55 AEST 2016


I copy the content of the pasetbin because it's about to expire.

Aris

aris at MacBook-Pro-de-Aris[master]:~/git/openssh-portable$ $(which sshd) -p 2222 -Dd -o UsePrivilegeSeparation=no
debug1: sshd version OpenSSH_7.3, OpenSSL 1.0.2h  3 May 2016
debug1: private host key #0: ssh-rsa SHA256:RshcDcsrjxblhEKqY41SVjaknD5Y+5ItWoL0kUZzAto
debug1: private host key #1: ssh-dss SHA256:abOvTYhsvsk1wP8zgmhctRASjh2w/6VT2QYhCetQilo
debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:Ub1fnRft89IfzrANU6giRV6o6BxHU9gOOuyT+vyJssw
debug1: private host key #3: ssh-ed25519 SHA256:ZDLir2+iDMnLGLpHz4objxkuIKK2fyOwjlrlr5IvcxE
debug1: setgroups() failed: Operation not permitted
debug1: rexec_argv[0]='/usr/local/sbin/sshd'
debug1: rexec_argv[1]='-p'
debug1: rexec_argv[2]='2222'
debug1: rexec_argv[3]='-Dd'
debug1: rexec_argv[4]='-o'
debug1: rexec_argv[5]='UsePrivilegeSeparation=no'
debug1: Bind to port 2222 on 0.0.0.0.
Server listening on 0.0.0.0 port 2222.
debug1: Bind to port 2222 on ::.
Server listening on :: port 2222.
debug1: fd 6 clearing O_NONBLOCK
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 6 out 6 newsock 6 pipe -1 sock 9
debug1: inetd sockets after dupping: 5, 5
Connection from ::1 port 54145 on ::1 port 2222
debug1: Client protocol version 2.0; client software version OpenSSH_7.3
debug1: match: OpenSSH_7.3 pat OpenSSH* compat 0x04000000
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_7.3
debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256 at libssh.org
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: client->server cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none
debug1: kex: server->client cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none
debug1: expecting SSH2_MSG_KEX_ECDH_INIT
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS received
debug1: KEX done
debug1: userauth-request for user aris service ssh-connection method none
debug1: attempt 0 failures 0
Failed none for aris from ::1 port 54145 ssh2
debug1: userauth-request for user aris service ssh-connection method publickey
debug1: attempt 1 failures 0
debug1: userauth_pubkey: test whether pkalg/pkblob are acceptable for RSA SHA256:dKXKoU9kSKpA5JtMuxbu5vUlL2F6YwOvZi6dz9/9XoY
debug1: temporarily_use_uid: 501/20 (e=501/20)
debug1: trying public key file /Users/aris/.ssh/authorized_keys
debug1: fd 6 clearing O_NONBLOCK
debug1: matching key found: file /Users/aris/.ssh/authorized_keys, line 1 RSA SHA256:dKXKoU9kSKpA5JtMuxbu5vUlL2F6YwOvZi6dz9/9XoY
debug1: restore_uid: (unprivileged)
Postponed publickey for aris from ::1 port 54145 ssh2
debug1: userauth-request for user aris service ssh-connection method publickey
debug1: attempt 2 failures 0
debug1: temporarily_use_uid: 501/20 (e=501/20)
debug1: trying public key file /Users/aris/.ssh/authorized_keys
debug1: fd 6 clearing O_NONBLOCK
debug1: matching key found: file /Users/aris/.ssh/authorized_keys, line 1 RSA SHA256:dKXKoU9kSKpA5JtMuxbu5vUlL2F6YwOvZi6dz9/9XoY
debug1: restore_uid: (unprivileged)
Accepted publickey for aris from ::1 port 54145 ssh2: RSA SHA256:dKXKoU9kSKpA5JtMuxbu5vUlL2F6YwOvZi6dz9/9XoY
debug1: Entering interactive session for SSH2.
debug1: server_init_dispatch_20
debug1: server_input_channel_open: ctype session rchan 0 win 1048576 max 16384
debug1: input_session_request
debug1: channel 0: new [server-session]
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug1: server_input_global_request: rtype no-more-sessions at openssh.com want_reply 0
debug1: server_input_channel_req: channel 0 request pty-req reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req pty-req
debug1: Allocating pty.
debug1: session_pty_req: session 0 alloc /dev/ttys005
debug1: server_input_channel_req: channel 0 request shell reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req shell
Starting session: shell on ttys005 for aris from ::1 port 54145 id 0
debug1: Setting controlling tty using TIOCSCTTY.
debug1: SSH2_MSG_KEXINIT received
debug1: SSH2_MSG_KEXINIT sent
debug1: kex: algorithm: curve25519-sha256 at libssh.org
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: client->server cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none
debug1: kex: server->client cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none
debug1: expecting SSH2_MSG_KEX_ECDH_INIT
debug1: set_newkeys: rekeying, input 4856 bytes 405 blocks, output 5408 bytes 0 blocks
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: set_newkeys: rekeying, input 4868 bytes 0 blocks, output 5476 bytes 8 blocks
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS received
debug1: Received SSH2_MSG_UNIMPLEMENTED for 43
debug1: SSH2_MSG_KEXINIT received
debug1: SSH2_MSG_KEXINIT sent
debug1: kex: algorithm: curve25519-sha256 at libssh.org
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: client->server cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none
debug1: kex: server->client cipher: chacha20-poly1305 at openssh.com MAC: <implicit> compression: none
debug1: expecting SSH2_MSG_KEX_ECDH_INIT
debug1: set_newkeys: rekeying, input 6360 bytes 185 blocks, output 6808 bytes 0 blocks
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: set_newkeys: rekeying, input 6372 bytes 0 blocks, output 6876 bytes 8 blocks
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS received
debug1: Received SSH2_MSG_UNIMPLEMENTED for 47
debug1: server_input_global_request: rtype keepalive at openssh.com want_reply 1
debug1: server_input_global_request: rtype keepalive at openssh.com want_reply 1
debug1: server_input_global_request: rtype keepalive at openssh.com want_reply 1





aris at MacBook-Pro-de-Aris[master]:~/git/openssh-portable$ ssh -p 2222 localhost
The authenticity of host '[localhost]:2222 ([::1]:2222)' can't be established.
ECDSA key fingerprint is SHA256:Ub1fnRft89IfzrANU6giRV6o6BxHU9gOOuyT+vyJssw.
Are you sure you want to continue connecting (yes/no)? yes
Warning: Permanently added '[localhost]:2222' (ECDSA) to the list of known hosts.
Attempt to write login records by non-root user (aborting)
Last login: Tue Aug 16 17:56:10 2016
Environment:
  USER=aris
  LOGNAME=aris
  HOME=/Users/aris
  PATH=/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/Cellar/openssh/7.3p1/bin
  MAIL=/var/mail/aris
  SHELL=/bin/bash
  SSH_CLIENT=::1 50924 2222
  SSH_CONNECTION=::1 50924 ::1 2222
  SSH_TTY=/dev/ttys005
  TERM=xterm-256color
aris at MacBook-Pro-de-Aris:~$ exit
logout
Connection to localhost closed.
aris at MacBook-Pro-de-Aris[master]:~/git/openssh-portable$ man ssh_config
aris at MacBook-Pro-de-Aris[master]:~/git/openssh-portable$ ssh -p 2222 -o EscapeChar=* localhost
ssh: connect to host localhost port 2222: Connection refused
aris at MacBook-Pro-de-Aris[master]:~/git/openssh-portable$ ssh -p 2222 -o EscapeChar=* localhost
Attempt to write login records by non-root user (aborting)
Last login: Tue Aug 16 17:56:10 2016
Environment:
  USER=aris
  LOGNAME=aris
  HOME=/Users/aris
  PATH=/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/Cellar/openssh/7.3p1/bin
  MAIL=/var/mail/aris
  SHELL=/bin/bash
  SSH_CLIENT=::1 54145 2222
  SSH_CONNECTION=::1 54145 ::1 2222
  SSH_TTY=/dev/ttys005
  TERM=xterm-256color
aris at MacBook-Pro-de-Aris:~$
aris at MacBook-Pro-de-Aris:~$
aris at MacBook-Pro-de-Aris:~$ *?
Supported escape sequences:
 *.   - terminate connection (and any multiplexed sessions)
 *B   - send a BREAK to the remote system
 *C   - open a command line
 *R   - request rekey
 *V/v - decrease/increase verbosity (LogLevel)
 *^Z  - suspend ssh
 *#   - list forwarded connections
 *&   - background ssh (when waiting for connections to terminate)
 *?   - this message
 **   - send the escape character by typing it twice
(Note that escapes are only recognized immediately after newline.)
kex protocol error: type 7 seq 43
kex protocol error: type 7 seq 47

aris at MacBook-Pro-de-Aris:~$ ssh -V
OpenSSH_7.3p1, OpenSSL 1.0.2h  3 May 2016
aris at MacBook-Pro-de-Aris:~$ exit
logout
Connection to localhost closed.
aris at MacBook-Pro-de-Aris[master]:~/git/openssh-portable$

On 24/08/16 21:53, mancha wrote:
> On Wed, Aug 24, 2016 at 07:06:29PM +0200, Aris Adamantiadis wrote:
>> Hi,
>>
>> mancha and me debugged a problem with OpenSSH 7.3p1 that was reported
>> on the #openssh freenode channel. Symptoms were that this message was
>> popping on the console during a busy X11 session: kex protocol error:
>> type 7 seq 1234
>>
>> I managed to reproduce the problem, it is related to the SSH_EXT_INFO
>> packet that is send by the server every time it is sending an
>> SSH_NEWKEYS packet, hence after every rekeying. I reproduced it on my
>> system with OpenSSH 7.3p1 and manually rekeying with escape R
>>
>> [SNIP] 
>>
>> Mancha couldn't reproduce the issue, despite running both OpenSSH
>> 7.3p1 client & server from upstream, with an empty configuration file.
>> At this point I don't know why he's not affected.
> Hello.
>
> I can shed a bit of light on why Aris hit the bug while I didn't when we
> both used 7.3p1.
>
> When sshd 7.3 *does* use privilege separation (UsePrivilegeSeparation),
> ssh->kex->ext_info_c == 0 on re-keys whether or not the client added
> ext-info-c to its kex algos in KEXINIT of first key exchange (setting
> ssh->kex->ext_info_c).
>
> When sshd 7.3 *does not* use privilege separation, if a client adds
> ext-info-c in KEXINIT for its first key exchange, ssh->kex->ext_info_c
> == 1 persists through re-keys and you get a client-side "kex protocol
> error: type 7 seq XX" response to the server sending a "server-sig-algs"
> SSH2_MSG_EXT_INFO packet after every SSH2_MSG_NEWKEYS.
>
> Operative code: kex.c:kex_send_newkeys()
>
>         if (ssh->kex->ext_info_c)
>                 if ((r = kex_send_ext_info(ssh)) != 0)
>                         return r;
>
> Ref: http://cvsweb.openbsd.org/cgi-bin/cvsweb/src/usr.bin/ssh/kex.c.diff?r1=1.112&r2=1.113
>
> Cheers,
>
> --mancha

 

 

Lima

About the author

Lima is the visual nautical indicator for "stop instantly."

Leave a Reply