SSH time increased significantly after upgrade to OpenSSH 9.6p1

radiatejava radiatejava at gmail.com
Sun Jul 28 22:22:06 AEST 2024


Team,
We upgraded sshd in our product from OpenSSH 8.6 to OpenSSH 9,.6.
After the upgrade, clients are seeing significant increase in time to
do ssh to the listener. Normally, a single ssh does not matter much
but some of our workflows involve about 3000 to 4000 ssh connect and
close and this is hitting us hard,

I enabled logging on the server side. I see the most of the increase
is here in receiving 'SSH2_MSG_KEX_ECDH_INIT received'. There is
increase of about 336221 - 150435 = ~185 msec. In contrast, we do not
see such delay in receiving 'SSH2_MSG_KEX_ECDH_INIT received' with
OpenSSH 8.6p1

Please let me know if you have any info on this.

//OpenSSH 9.6p1 logs
Jul 23 17:42:50.131032 ifav87-apic2 sshd[1089880]: debug1: Forked child 1090464.
Jul 23 17:42:50.131409 ifav87-apic2 sshd[1090464]: debug1: Set
/proc/self/oom_score_adj to 0
Jul 23 17:42:50.131668 ifav87-apic2 sshd[1090464]: debug1: rexec start
in 4 out 4 newsock 4 pipe 6 sock 7
Jul 23 17:42:50.146955 ifav87-apic2 sshd[1090464]: debug1: inetd
sockets after dupping: 4, 4
Jul 23 17:42:50.147065 ifav87-apic2 sshd[1090464]: Connection from
10.0.0.1 port 35782 on 10.0.0.2 port 1022 rdomain ""
Jul 23 17:42:50.147151 ifav87-apic2 sshd[1090464]: debug1: Local
version string SSH-2.0-OpenSSH_9.6
Jul 23 17:42:50.147256 ifav87-apic2 sshd[1090464]: debug1: Remote
protocol version 2.0, remote software version OpenSSH_9.6
Jul 23 17:42:50.147292 ifav87-apic2 sshd[1090464]: debug1:
compat_banner: match: OpenSSH_9.6 pat OpenSSH* compat 0x04000000
Jul 23 17:42:50.149097 ifav87-apic2 sshd[1090464]: debug1:
permanently_set_uid: 106/65534 [preauth]
Jul 23 17:42:50.150050 ifav87-apic2 sshd[1090464]: debug1:
list_hostkey_types: ssh-rsa [preauth]
Jul 23 17:42:50.150134 ifav87-apic2 sshd[1090464]: debug1:
SSH2_MSG_KEXINIT sent [preauth]
Jul 23 17:42:50.150251 ifav87-apic2 sshd[1090464]: debug1:
SSH2_MSG_KEXINIT received [preauth]
Jul 23 17:42:50.150288 ifav87-apic2 sshd[1090464]: debug1: kex:
algorithm: sntrup761x25519-sha512 at openssh.com [preauth]
Jul 23 17:42:50.150323 ifav87-apic2 sshd[1090464]: debug1: kex: host
key algorithm: ssh-rsa [preauth]
Jul 23 17:42:50.150363 ifav87-apic2 sshd[1090464]: debug1: kex:
client->server cipher: aes128-ctr MAC: hmac-sha1 compression: none
[preauth]
Jul 23 17:42:50.150401 ifav87-apic2 sshd[1090464]: debug1: kex:
server->client cipher: aes128-ctr MAC: hmac-sha1 compression: none
[preauth]
Jul 23 17:42:50.150435 ifav87-apic2 sshd[1090464]: debug1: expecting
SSH2_MSG_KEX_ECDH_INIT [preauth]
Jul 23 17:42:50.336221 ifav87-apic2 sshd[1090464]: debug1:
SSH2_MSG_KEX_ECDH_INIT received [preauth]
Jul 23 17:42:50.387724 ifav87-apic2 sshd[1090464]: debug1:
ssh_packet_send2_wrapped: resetting send seqnr 3 [preauth]

//OpenSSH 8.6p1
Jul 23 17:32:24.910905 apic2 sshd[338663]: debug1: Forked child 342983.
Jul 23 17:32:24.911310 apic2 sshd[342983]: debug1: Set
/proc/self/oom_score_adj to 0
Jul 23 17:32:24.911493 apic2 sshd[342983]: debug1: rexec start in 4
out 4 newsock 4 pipe 6 sock 7
Jul 23 17:32:24.928441 apic2 sshd[342983]: debug1: inetd sockets after
dupping: 4, 4
Jul 23 17:32:24.928629 apic2 sshd[342983]: Connection from 40.40.0.1
port 42382 on 40.40.0.2 port 1022 rdomain ""
Jul 23 17:32:24.928734 apic2 sshd[342983]: debug1: Local version
string SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.9
Jul 23 17:32:24.928814 apic2 sshd[342983]: debug1: Remote protocol
version 2.0, remote software version OpenSSH_8.9
Jul 23 17:32:24.928847 apic2 sshd[342983]: debug1: match: OpenSSH_8.9
pat OpenSSH* compat 0x04000000
Jul 23 17:32:24.930547 apic2 sshd[342983]: debug1:
permanently_set_uid: 106/65534 [preauth]
Jul 23 17:32:24.932011 apic2 sshd[342983]: debug1: list_hostkey_types:
ssh-rsa [preauth]
Jul 23 17:32:24.932058 apic2 sshd[342983]: debug1: SSH2_MSG_KEXINIT
sent [preauth]
Jul 23 17:32:24.932097 apic2 sshd[342983]: debug1: SSH2_MSG_KEXINIT
received [preauth]
Jul 23 17:32:24.932126 apic2 sshd[342983]: debug1: kex: algorithm:
curve25519-sha256 [preauth]
Jul 23 17:32:24.932155 apic2 sshd[342983]: debug1: kex: host key
algorithm: ssh-rsa [preauth]
Jul 23 17:32:24.932191 apic2 sshd[342983]: debug1: kex: client->server
cipher: aes128-ctr MAC: hmac-sha1 compression: none [preauth]
Jul 23 17:32:24.932221 apic2 sshd[342983]: debug1: kex: server->client
cipher: aes128-ctr MAC: hmac-sha1 compression: none [preauth]
Jul 23 17:32:24.932251 apic2 sshd[342983]: debug1: expecting
SSH2_MSG_KEX_ECDH_INIT [preauth]
Jul 23 17:32:24.959072 apic2 sshd[342983]: debug1: rekey out after
4294967296 blocks [preauth]
Jul 23 17:32:24.959116 apic2 sshd[342983]: debug1: SSH2_MSG_NEWKEYS
sent [preauth]
Jul 23 17:32:24.959145 apic2 sshd[342983]: debug1: Sending
SSH2_MSG_EXT_INFO [preauth]
Jul 23 17:32:24.959172 apic2 sshd[342983]: debug1: expecting
SSH2_MSG_NEWKEYS [preauth]
Jul 23 17:32:24.964578 apic2 sshd[342983]: debug1: SSH2_MSG_NEWKEYS
received [preauth]
Jul 23 17:32:24.964625 apic2 sshd[342983]: debug1: rekey in after
4294967296 blocks [preauth]
Jul 23 17:32:24.964671 apic2 sshd[342983]: debug1: KEX done [preauth]
Jul 23 17:32:25.006163 apic2 sshd[342983]: debug1: userauth-request
for user root service ssh-connection method none [preauth]
Jul 23 17:32:25.006208 apic2 sshd[342983]: debug1: attempt 0 failures
0 [preauth]


More information about the openssh-unix-dev mailing list