kex protocol error: type 7 seq xxx error message

[Aris Adamantiadis]

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
http://pastebin.com/Xk0dF0mc

on the client side:
sshconnect2.c:
void
ssh_userauth2(const char *local_user, const char *server_user, char *host,
Sensitive *sensitive)
{
...
ssh_dispatch_set(ssh, SSH2_MSG_EXT_INFO, &input_userauth_ext_info);
ssh_dispatch_set(ssh, SSH2_MSG_SERVICE_ACCEPT,
&input_userauth_service_accept);
ssh_dispatch_run(ssh, DISPATCH_BLOCK, &authctxt.success,
&authctxt); /* loop until success */

pubkey_cleanup(&authctxt);
ssh_dispatch_range(ssh, SSH2_MSG_USERAUTH_MIN,
SSH2_MSG_USERAUTH_MAX, NULL);

debug("Authentication succeeded (%s).", authctxt.method->name);
}

Is the only place where the dispatch for that packet is set. However in
kex.c:
int
kex_input_ext_info(int type, u_int32_t seq, void *ctxt)
{
...
debug("SSH2_MSG_EXT_INFO received");
ssh_dispatch_set(ssh, SSH2_MSG_EXT_INFO, &kex_protocol_error);
...
}

Ensuring this packet will only be accepted before authentication.
However the server side is different:
int
kex_send_newkeys(struct ssh *ssh)
{
...
debug("SSH2_MSG_NEWKEYS sent");
debug("expecting SSH2_MSG_NEWKEYS");
ssh_dispatch_set(ssh, SSH2_MSG_NEWKEYS, &kex_input_newkeys);
if (ssh->kex->ext_info_c)
if ((r = kex_send_ext_info(ssh)) != 0)
return r;
return 0;
}

There doesn't seem to have any logic in the client side that restricts
sending ext-info-c in the list of kex algorithms after the first key
exchange. However I couldn't find it in my kexinit proposal (even the
first one):
debug2: local client KEXINIT proposal
debug2: KEX algorithms:
curve255...@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1
debug2: host key algorithms:
ecdsa-sha2-nis...@openssh.com,ecdsa-sha2-nis...@openssh.com,ecdsa-sha2-nis...@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed2551...@openssh.com,ssh-rsa-...@openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug2: ciphers ctos:
chacha20...@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes12...@openssh.com,aes25...@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc
debug2: ciphers stoc:
chacha20...@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes12...@openssh.com,aes25...@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc,3des-cbc
debug2: MACs ctos:
umac-...@openssh.com,umac-1...@openssh.com,hmac-sha...@openssh.com,hmac-sha...@openssh.com,hmac-s...@openssh.com,uma...@openssh.com,umac...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc:
umac-...@openssh.com,umac-1...@openssh.com,hmac-sha...@openssh.com,hmac-sha...@openssh.com,hmac-s...@openssh.com,uma...@openssh.com,umac...@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zl...@openssh.com,zlib
debug2: compression stoc: none,zl...@openssh.com,zlib
debug2: languages ctos:
debug2: languages stoc:

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.

This bug is not very important anyway because the packet is simply
dropped with no consequence.

Aris

_______________________________________________
openssh-unix-dev mailing list
openssh-...@mindrot.org
https://lists.mindrot.org/mailman/listinfo/openssh-unix-dev

[mancha]

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

[Aris Adamantiadis]

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

Aris

aris@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: curve255...@libssh.org
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: client->server cipher: chacha20...@openssh.com MAC: <implicit> compression: none
debug1: kex: server->client cipher: chacha20...@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-...@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: curve255...@libssh.org
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: client->server cipher: chacha20...@openssh.com MAC: <implicit> compression: none
debug1: kex: server->client cipher: chacha20...@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: curve255...@libssh.org
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: client->server cipher: chacha20...@openssh.com MAC: <implicit> compression: none
debug1: kex: server->client cipher: chacha20...@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 keep...@openssh.com want_reply 1
debug1: server_input_global_request: rtype keep...@openssh.com want_reply 1
debug1: server_input_global_request: rtype keep...@openssh.com want_reply 1





aris@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@MacBook-Pro-de-Aris:~$ exit
logout
Connection to localhost closed.
aris@MacBook-Pro-de-Aris[master]:~/git/openssh-portable$ man ssh_config
aris@MacBook-Pro-de-Aris[master]:~/git/openssh-portable$ ssh -p 2222 -o EscapeChar=* localhost
ssh: connect to host localhost port 2222: Connection refused
aris@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@MacBook-Pro-de-Aris:~$
aris@MacBook-Pro-de-Aris:~$
aris@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@MacBook-Pro-de-Aris:~$ ssh -V
OpenSSH_7.3p1, OpenSSL 1.0.2h 3 May 2016
aris@MacBook-Pro-de-Aris:~$ exit
logout
Connection to localhost closed.
aris@MacBook-Pro-de-Aris[master]:~/git/openssh-portable$

[Markus Friedl]

thanks for analyzing the issue.

this should fix it:

--- kex.c
+++ kex.c
@@ -753,10 +753,8 @@ kex_choose_conf(struct ssh *ssh)
char *ext;

ext = match_list("ext-info-c", peer[PROPOSAL_KEX_ALGS], NULL);
- if (ext) {
- kex->ext_info_c = 1;
- free(ext);
- }
+ kex->ext_info_c = (ext != NULL);
+ free(ext);
}

/* Algorithm Negotiation */
--