Securing a server means hardening the SSH server settings, but doing so can also cause issues with ssh clients. Finding the cipher or algorithm causing a failled connection can be tricky. Depending on the client used, the error message might be very generic like “Failed to start SSH session”.
Using a openssh client will allow increasing the log level (-v) until the cause of the problem shows up in the output. Experience has shown that most issues are not related to openssh client configuration but closed source or third-party applications that provide less details via their user interface. In the case explained here it was an iPad/iPhone app, which had updated its ssh library. The app did not provide full details about the error as space is limited.
From the first error message “Failed to start SSH session: Unable to exchange encryption keys.” it was clear that there was a fundamental issue with the connection setup, but without any details from the client debugging had to be performed on the server side.
To debug the connection issue from the ssh daemon, the following log needs to be monitored on CentOS (other distributions might log to a different file).
$ tail /var/log/secure
In debian based distributions like Ubuntu, the log file for the ssh daemon is the following.
$ tail -f /var/log/auth.log
No matching MAC algorithem
The following line should be under the last lines of the log, indicating what the initial error message already suggested. Client and server could not setup a session as they could not agree on a MAC (message authentication code) algorithm.
... sshd[5176]: fatal: no matching mac found: client hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com server hmac-sha2-512,hmac-sha2-256
But this error message already shows us more detail. It lists the client and server offered MACs. The client offered 6 MACs and the server offered 2, but no MAC is in both lists.
To continue debugging the connection issues the following MAC algorithm was enabled in the ssh daemon configuration, chosen at random from the client offered MAC algorithms. The resulting ssh daemon configuration after applying the settings from hardening the SSH server settings and with the added MAC algorithm looks like this.
# Hardening SSH configuration KexAlgorithms ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group-exchange-sha256 MACs hmac-sha2-512,hmac-sha2-256,hmac-ripemd160 Ciphers aes256-ctr,aes192-ctr,aes128-ctr
After changing the configuration of the ssh daemon, sshd needs to be instructed to reload its configuration.
$ service sshd reload
The next connection attempt shows the agreed MAC algorithm in “hmac-ripemd160” the log clearly.
... sshd[634]: debug2: mac_setup: found hmac-ripemd160
No matching KEX algorithm
Even with the MAC algorithm agreed, the next problem might arise when the KEX (Key EXchange) algorithm can not be negotiated. The situation about the KEX negotiation is indicated very clearly.
... sshd[6260]: fatal: Unable to negotiate a key exchange method
Sadly this message does not provide any details about the proposed KEX algorithms from either side of the connection. To debug the connection on CentOS 6 running the OpenSSH 5.3 daemon, the debug level DEBUG2 is needed. To enable the logging on the ssh server, the following line of configuration has to be added to the /etc/ssh/sshd_config. It will not alter the behaviour of the ssh daemon itself, except to add additional logging to understand the decissions made during the connection setup. This configuration should be used with care on a busy ssh daemon as it increases the amount of logging significantly.
LogLevel DEBUG2
After changing the configuration of the ssh daemon, sshd needs to be instructed to reload its configuration again. The second command will open the log file to follow the login attempt.
$ service sshd reload $ tail /var/log/secure
With the increased log level, a connection attempt will look similar to this example (here I have removed the beginning of each line where there would normally be a timestamp and the host name).
sshd[621]: debug1: Forked child 634. sshd[634]: Set /proc/self/oom_score_adj to 0 sshd[634]: debug1: rexec start in 7 out 7 newsock 7 pipe 9 sock 10 sshd[634]: debug1: inetd sockets after dupping: 3, 3 sshd[634]: Connection from 123.123.123.123 port 36462 sshd[634]: debug1: Client protocol version 2.0; client software version libssh2_1.7.0_DEV sshd[634]: debug1: no match: libssh2_1.7.0_DEV sshd[634]: debug1: Enabling compatibility mode for protocol 2.0 sshd[634]: debug1: Local version string SSH-2.0-OpenSSH_5.3 sshd[634]: debug2: fd 3 setting O_NONBLOCK sshd[634]: debug2: Network child is on pid 634 sshd[634]: debug1: permanently_set_uid: 74/74 sshd[634]: debug1: list_hostkey_types: ssh-rsa,ssh-dss sshd[634]: debug1: SSH2_MSG_KEXINIT sent sshd[634]: debug1: SSH2_MSG_KEXINIT received sshd[634]: debug2: kex_parse_kexinit: ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group-exchange-sha256 sshd[634]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss sshd[634]: debug2: kex_parse_kexinit: aes256-ctr,aes192-ctr,aes128-ctr sshd[634]: debug2: kex_parse_kexinit: aes256-ctr,aes192-ctr,aes128-ctr sshd[634]: debug2: kex_parse_kexinit: hmac-sha2-512,hmac-sha2-256,hmac-ripemd160 sshd[634]: debug2: kex_parse_kexinit: hmac-sha2-512,hmac-sha2-256,hmac-ripemd160 sshd[634]: debug2: kex_parse_kexinit: none,zlib@openssh.com sshd[634]: debug2: kex_parse_kexinit: none,zlib@openssh.com sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: first_kex_follows 0 sshd[634]: debug2: kex_parse_kexinit: reserved 0 sshd[634]: debug2: kex_parse_kexinit: diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1 sshd[634]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss sshd[634]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc sshd[634]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc sshd[634]: debug2: kex_parse_kexinit: hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com sshd[634]: debug2: kex_parse_kexinit: hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com sshd[634]: debug2: kex_parse_kexinit: none sshd[634]: debug2: kex_parse_kexinit: none sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: first_kex_follows 0 sshd[634]: debug2: kex_parse_kexinit: reserved 0 sshd[634]: debug2: mac_setup: found hmac-ripemd160 sshd[634]: debug1: kex: client->server aes128-ctr hmac-ripemd160 none sshd[634]: debug2: mac_setup: found hmac-ripemd160 sshd[634]: debug1: kex: server->client aes128-ctr hmac-ripemd160 none sshd[634]: fatal: Unable to negotiate a key exchange method sshd[634]: debug1: do_cleanup sshd[634]: debug1: do_cleanup
There is no clear indication on the offered KEX algorithms in the log. To read this information out of the log, a deeper look into where the log lines come from is necessary. What’s interesting at this point are the log lines containing the “debug2: kex_parse_kexinit:”.
Digging into the logs
A quick peek into the function kex_buf2prop() of the file kex.c on branch V_5_3 of OpenSSH reads (shortened slightly) like this.
...
for (...) {
debug2("kex_parse_kexinit: %s", proposal[i]);
}
debug2("kex_parse_kexinit: first_kex_follows %d ", i);
debug2("kex_parse_kexinit: reserved %u ", i);
...
The function is called from kex_choose_conf() found in the same file. As the simplified example shows, this function is calling the above method twice.
... my = kex_buf2prop(&kex->my, NULL); peer = kex_buf2prop(&kex->peer, &first_kex_follows); ...
Without digging deeper, the name of the parameters suggest, first the function is called with the locally configured algorithms and second with the offered algorithms from the remote. In this case, that would indicate that first the proposal from the ssh deamon is logged and the second block contains the proposal from the (remote) connecting client.
As such, the “kex_parse_kexinit” lines can be seperated into the following two blocks. The first one is the ssh daemon side.
sshd[634]: debug2: kex_parse_kexinit: ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group-exchange-sha256 sshd[634]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss sshd[634]: debug2: kex_parse_kexinit: aes256-ctr,aes192-ctr,aes128-ctr sshd[634]: debug2: kex_parse_kexinit: aes256-ctr,aes192-ctr,aes128-ctr sshd[634]: debug2: kex_parse_kexinit: hmac-sha2-512,hmac-sha2-256,hmac-ripemd160 sshd[634]: debug2: kex_parse_kexinit: hmac-sha2-512,hmac-sha2-256,hmac-ripemd160 sshd[634]: debug2: kex_parse_kexinit: none,zlib@openssh.com sshd[634]: debug2: kex_parse_kexinit: none,zlib@openssh.com sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: first_kex_follows 0 sshd[634]: debug2: kex_parse_kexinit: reserved 0
- The 1st line appears to be the configured KEX algorithms (sshd_config option “KexAlgorithms”).
- The 2nd line appears to be the configured host key algorithms (sshd_config option “HostKeyAlgorithms”).
- The 3rd & 4th lines appear to be the configured ciphers (sshd_config option “Ciphers”).
- The 5th & 6th lines appear to be the configured MAC algorithms (sshd_config option “MACs”).
For some reason, which would probably require a deeper understanding of the source, the cipher and MAC list is shown twice. The block of “kex_parse_kexinit” lines ends with the line “kex_parse_kexinit: reserved 0”.
The second block is the proposals from the remote side, which is the ssh client trying to connect.
sshd[634]: debug2: kex_parse_kexinit: diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1 sshd[634]: debug2: kex_parse_kexinit: ssh-rsa,ssh-dss sshd[634]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc sshd[634]: debug2: kex_parse_kexinit: aes128-ctr,aes192-ctr,aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-cbc,aes128-cbc,blowfish-cbc,arcfour128,arcfour,cast128-cbc,3des-cbc sshd[634]: debug2: kex_parse_kexinit: hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com sshd[634]: debug2: kex_parse_kexinit: hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com sshd[634]: debug2: kex_parse_kexinit: none sshd[634]: debug2: kex_parse_kexinit: none sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: sshd[634]: debug2: kex_parse_kexinit: first_kex_follows 0 sshd[634]: debug2: kex_parse_kexinit: reserved 0
Knowing this, we can see that the KEX algorithms from the ssh daemon and the client’s proposed KEX algorithms do not have any algorithms in common, which causes the error message we saw earlier.
Of course, enabling one of the client’s proposed KEX algorithms would allow the client to login, but enabling one of these MAC or KEX algorithms needs to be handled with care. Many of the disabled ciphers and algorithms might be disabled for security reasons as described in Harden the SSH server settings.
As a proof, one of the client’s proposed KEX algorithms (I randomly chose “diffie-hellman-group-exchange-sha1”) can be enabled in the shh daemon. The configuration might look like this with the additional KEX algorithm.
# Hardening SSH configuration KexAlgorithms ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1 MACs hmac-sha2-512,hmac-sha2-256,hmac-ripemd160 Ciphers aes256-ctr,aes192-ctr,aes128-ctr
After changing the configuration of the ssh daemon, sshd needs to be instructed to reload its configuration again.
$ service sshd reload
The next login attempt from the client should succeed as the MAC and KEX algorithms the client proposes are enabled for the ssh daemon.
Modern distributions, different log
The above explanation about interpreting the log information to find the KEX that were offered applies to conservative distributions like CentOS 6 / RHEL 6 (Red Hat Enterprise Linux) and possibly Debian. But what about modern distributions? Modern distributions like Ubuntu and possibly more recent versions of CentOS and RHEL use a more up-to-date version of OpenSSH. At the time of writing Ubuntu uses OpenSSH 7.2 where the logging is more self explanatory.
sshd[3685]: debug2: local server KEXINIT proposal [preauth] sshd[3685]: debug2: KEX algorithms: ecdh-sha2-nistp521,ecdh-sha2-nistp384,ecdh-sha2-nistp256,diffie-hellman-group-exchange-sha256 [preauth] sshd[3685]: debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] sshd[3685]: debug2: ciphers ctos: aes256-ctr,aes192-ctr,aes128-ctr [preauth] sshd[3685]: debug2: ciphers stoc: aes256-ctr,aes192-ctr,aes128-ctr [preauth] sshd[3685]: debug2: MACs ctos: hmac-sha2-512,hmac-sha2-256 [preauth] sshd[3685]: debug2: MACs stoc: hmac-sha2-512,hmac-sha2-256 [preauth] sshd[3685]: debug2: compression ctos: none,zlib@openssh.com [preauth] sshd[3685]: debug2: compression stoc: none,zlib@openssh.com [preauth] sshd[3685]: debug2: languages ctos: [preauth] sshd[3685]: debug2: languages stoc: [preauth] sshd[3685]: debug2: first_kex_follows 0 [preauth] sshd[3685]: debug2: reserved 0 [preauth] sshd[3685]: debug2: peer client KEXINIT proposal [preauth] sshd[3685]: debug2: KEX algorithms: diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1 [preauth] sshd[3685]: debug2: host key algorithms: ssh-rsa-cert-v01@openssh.com,ssh-dss-cert-v01@openssh.com,ssh-rsa-cert-v00@openssh.com,ssh-dss-cert-v00@openssh.com,ssh-rsa,ssh-dss [preauth] sshd[3685]: debug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se [preauth] sshd[3685]: debug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se [preauth] sshd[3685]: debug2: MACs ctos: hmac-sha2-512 [preauth] sshd[3685]: debug2: MACs stoc: hmac-sha2-512 [preauth] sshd[3685]: debug2: compression ctos: none,zlib@openssh.com,zlib [preauth] sshd[3685]: debug2: compression stoc: none,zlib@openssh.com,zlib [preauth] sshd[3685]: debug2: languages ctos: [preauth] sshd[3685]: debug2: languages stoc: [preauth] sshd[3685]: debug2: first_kex_follows 0 [preauth] sshd[3685]: debug2: reserved 0 [preauth]
The above example shows that instead of the “kex_parse_kexinit” log lines, the log identifies the offered algorithms. This makes it much easier to identify the MAC, KEX and ciphers offered from both sides. There is even a line between the blocks identifying the origin of the offer.
sshd[3685]: debug2: local server KEXINIT proposal [preauth] ... sshd[3685]: debug2: peer client KEXINIT proposal [preauth]
This way, guessing and digging in the source to understand the log is not needed any more. Sady not all distributions use the newer version of OpenSSH. With CentOS 6, OpenSSH 5.3 is still the latest, patched version available in the default repositories.
Read more of my posts on my blog at https://blog.tinned-software.net/.
