Excessive delay at ssh connection to remote host

[James Moe]

On 2026-09-29 23:01, Damien Miller wrote:

> If these options help then the problem may be aggressive NAT timeouts.
> 
This is on a local network. There is no NOT activity between the two hosts.

>> What may cause the further delay for the password prompt?
> It's almost impossible to tell without server logs here. Are you able
> to get debug logs from the server?

I have attached a log file. I am unable to decipher its information, especially
since there are no timestamps.

-- 
James Moe
moe dot james at sohnen-moe dot com
520.743.3936
Think.
-------------- next part --------------
debug1: sshd version OpenSSH_10.5, OpenSSL 3.5.3 16 Sep 2025
debug2: load_server_config: filename /usr/etc/ssh/sshd_config
debug2: load_server_config: done config len = 4123
debug2: parse_server_config_depth: config /usr/etc/ssh/sshd_config len 4123
debug2: /usr/etc/ssh/sshd_config line 12: new include /etc/ssh/sshd_config.d/*.conf
debug2: /usr/etc/ssh/sshd_config line 12: no match for /etc/ssh/sshd_config.d/*.conf
debug2: /usr/etc/ssh/sshd_config line 18: new include /usr/etc/ssh/sshd_config.d/*.conf
debug2: /usr/etc/ssh/sshd_config line 18: including /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf
debug2: load_server_config: filename /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf
debug2: load_server_config: done config len = 413
debug2: parse_server_config_depth: config /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf len 413
debug2: /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf line 6: new include /etc/crypto-policies/back-ends/opensshserver.config
debug2: /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf line 6: including /etc/crypto-policies/back-ends/opensshserver.config
debug2: load_server_config: filename /etc/crypto-policies/back-ends/opensshserver.config
debug2: load_server_config: done config len = 2331
debug2: parse_server_config_depth: config /etc/crypto-policies/back-ends/opensshserver.config len 2331
debug1: private host key #0: ssh-rsa SHA256:8Hej8HhXYFgbbfCkxdP8BBJ9fa2mB0BHukafK2p+SDM
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:fCfJ8NV2n/ynC0TXxsHWYSnqEv0lmXrp0fFj/F8tJ34
debug1: private host key #2: ssh-ed25519 SHA256:afPTJUksIP6UOXoEyloLZD0T30pUOdLVecTrHjsYI00
debug1: private host key #3: ssh-mldsa44-ed25519 at openssh.com SHA256:BBHy+cX+3ZzAjLldyj3H3Wq8KK5ZnPMc20T5iSx0los
debug1: rexec_argv[1]='-d'
debug1: rexec_argv[2]='-d'
debug1: rexec_argv[3]='-E'
debug1: rexec_argv[4]='tmp1/ssh-debug.txt'
debug1: Set /proc/self/oom_score_adj from 200 to -1000
debug2: fd 7 setting O_NONBLOCK
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug2: fd 8 setting O_NONBLOCK
debug1: Bind to port 22 on ::.
Server listening on :: port 22.
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 9 out 9 newsock 9 config_s 10/11
debug1: sshd version OpenSSH_10.5, OpenSSL 3.5.3 16 Sep 2025
debug2: load_server_config: filename /usr/etc/ssh/sshd_config
debug2: load_server_config: done config len = 4123
debug2: parse_server_config_depth: config /usr/etc/ssh/sshd_config len 4123
debug2: /usr/etc/ssh/sshd_config line 12: new include /etc/ssh/sshd_config.d/*.conf
debug2: /usr/etc/ssh/sshd_config line 12: no match for /etc/ssh/sshd_config.d/*.conf
debug2: /usr/etc/ssh/sshd_config line 18: new include /usr/etc/ssh/sshd_config.d/*.conf
debug2: /usr/etc/ssh/sshd_config line 18: including /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf
debug2: load_server_config: filename /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf
debug2: load_server_config: done config len = 413
debug2: parse_server_config_depth: config /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf len 413
debug2: /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf line 6: new include /etc/crypto-policies/back-ends/opensshserver.config
debug2: /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf line 6: including /etc/crypto-policies/back-ends/opensshserver.config
debug2: load_server_config: filename /etc/crypto-policies/back-ends/opensshserver.config
debug2: load_server_config: done config len = 2331
debug2: parse_server_config_depth: config /etc/crypto-policies/back-ends/opensshserver.config len 2331
debug1: private host key #0: ssh-rsa SHA256:8Hej8HhXYFgbbfCkxdP8BBJ9fa2mB0BHukafK2p+SDM
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:fCfJ8NV2n/ynC0TXxsHWYSnqEv0lmXrp0fFj/F8tJ34
debug1: private host key #2: ssh-ed25519 SHA256:afPTJUksIP6UOXoEyloLZD0T30pUOdLVecTrHjsYI00
debug1: private host key #3: ssh-mldsa44-ed25519 at openssh.com SHA256:BBHy+cX+3ZzAjLldyj3H3Wq8KK5ZnPMc20T5iSx0los
debug1: rexec_argv[1]='-d'
debug1: rexec_argv[2]='-d'
debug1: rexec_argv[3]='-E'
debug1: rexec_argv[4]='/home/sma-user1/tmp1/ssh-debug.txt'
debug1: Set /proc/self/oom_score_adj from 200 to -1000
debug2: fd 7 setting O_NONBLOCK
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug2: fd 8 setting O_NONBLOCK
debug1: Bind to port 22 on ::.
Server listening on :: port 22.
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 9 out 9 newsock 9 config_s 10/11
debug2: parse_hostkeys: privkey 0: ssh-rsa
debug2: parse_hostkeys: pubkey 0: ssh-rsa
debug2: parse_hostkeys: privkey 1: ecdsa-sha2-nistp256
debug2: parse_hostkeys: pubkey 1: ecdsa-sha2-nistp256
debug2: parse_hostkeys: privkey 2: ssh-ed25519
debug2: parse_hostkeys: pubkey 2: ssh-ed25519
debug2: parse_hostkeys: privkey 3: ssh-mldsa44-ed25519 at openssh.com
debug2: parse_hostkeys: pubkey 3: ssh-mldsa44-ed25519 at openssh.com
debug2: parse_server_config_depth: config rexec len 4123
debug2: parse_server_config_depth: config  len 0
debug2: parse_server_config_depth: config /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf len 413
debug2: parse_server_config_depth: config /etc/crypto-policies/back-ends/opensshserver.config len 2331
debug1: sshd-session version OpenSSH_10.5, OpenSSL 3.5.3 16 Sep 2025
debug1: network sockets: 7, 7
debug2: fd 7 setting TCP_NODELAY
Connection from 192.168.69.115 port 44146 on 192.168.69.109 port 22 rdomain ""
debug2: fd 7 setting O_NONBLOCK
debug2: Network child is on pid 477406
debug1: network sockets: 5, 5 [preauth]
debug1: mm_answer_state: config len 4123
debug2: monitor_read: 51 used once, disabling now
debug2: parse_hostkeys: key 0: ssh-rsa [preauth]
debug2: parse_hostkeys: key 1: ecdsa-sha2-nistp256 [preauth]
debug2: parse_hostkeys: key 2: ssh-ed25519 [preauth]
debug2: parse_hostkeys: key 3: ssh-mldsa44-ed25519 at openssh.com [preauth]
debug2: fd 5 is TCP_NODELAY [preauth]
debug1: sshd-auth version OpenSSH_10.5, OpenSSL 3.5.3 16 Sep 2025 [preauth]
debug1: SELinux support disabled [preauth]
debug1: permanently_set_uid: 495/494 [preauth]
debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug1: Local version string SSH-2.0-OpenSSH_10.5 [preauth]
debug1: Remote protocol version 2.0, remote software version OpenSSH_10.5 [preauth]
debug1: compat_banner: match: OpenSSH_10.5 pat OpenSSH* compat 0x04000000 [preauth]
debug2: monitor_read: 18 used once, disabling now
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug2: local server KEXINIT proposal [preauth]
debug2: KEX algorithms: sntrup761x25519-sha512,sntrup761x25519-sha512 at openssh.com,mlkem768x25519-sha256,curve25519-sha256,curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,ext-info-s,kex-strict-s-v00 at openssh.com [preauth]
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug2: ciphers ctos: aes256-gcm at openssh.com,chacha20-poly1305 at openssh.com,aes256-ctr,aes128-gcm at openssh.com,aes128-ctr [preauth]
debug2: ciphers stoc: aes256-gcm at openssh.com,chacha20-poly1305 at openssh.com,aes256-ctr,aes128-gcm at openssh.com,aes128-ctr [preauth]
debug2: MACs ctos: hmac-sha2-256-etm at openssh.com,hmac-sha1-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512 [preauth]
debug2: MACs stoc: hmac-sha2-256-etm at openssh.com,hmac-sha1-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512 [preauth]
debug2: compression ctos: none,zlib at openssh.com [preauth]
debug2: compression stoc: none,zlib at openssh.com [preauth]
debug2: languages ctos:  [preauth]
debug2: languages stoc:  [preauth]
debug2: first_kex_follows 0  [preauth]
debug2: reserved 0  [preauth]
debug2: peer client KEXINIT proposal [preauth]
debug2: KEX algorithms: sntrup761x25519-sha512,sntrup761x25519-sha512 at openssh.com,mlkem768x25519-sha256,curve25519-sha256,curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,ext-info-c,kex-strict-c-v00 at openssh.com [preauth]
debug2: host key algorithms: ssh-ed25519-cert-v01 at openssh.com,ecdsa-sha2-nistp256-cert-v01 at openssh.com,ecdsa-sha2-nistp384-cert-v01 at openssh.com,ecdsa-sha2-nistp521-cert-v01 at openssh.com,sk-ssh-ed25519-cert-v01 at openssh.com,sk-ecdsa-sha2-nistp256-cert-v01 at openssh.com,webauthn-sk-ecdsa-sha2-nistp256-cert-v01 at openssh.com,rsa-sha2-512-cert-v01 at openssh.com,rsa-sha2-256-cert-v01 at openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519 at openssh.com,sk-ecdsa-sha2-nistp256 at openssh.com,webauthn-sk-ecdsa-sha2-nistp256 at openssh.com,rsa-sha2-512,rsa-sha2-256 [preauth]
debug2: ciphers ctos: aes256-gcm at openssh.com,chacha20-poly1305 at openssh.com,aes256-ctr,aes128-gcm at openssh.com,aes128-ctr [preauth]
debug2: ciphers stoc: aes256-gcm at openssh.com,chacha20-poly1305 at openssh.com,aes256-ctr,aes128-gcm at openssh.com,aes128-ctr [preauth]
debug2: MACs ctos: hmac-sha2-256-etm at openssh.com,hmac-sha1-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512 [preauth]
debug2: MACs stoc: hmac-sha2-256-etm at openssh.com,hmac-sha1-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512 [preauth]
debug2: compression ctos: none,zlib at openssh.com [preauth]
debug2: compression stoc: none,zlib at openssh.com [preauth]
debug2: languages ctos:  [preauth]
debug2: languages stoc:  [preauth]
debug2: first_kex_follows 0  [preauth]
debug2: reserved 0  [preauth]
debug1: kex: algorithm: sntrup761x25519-sha512 [preauth]
debug1: kex: host key algorithm: ssh-ed25519 [preauth]
debug1: kex: client->server cipher: aes256-gcm at openssh.com MAC: <implicit> compression: none [preauth]
debug1: kex: server->client cipher: aes256-gcm at openssh.com MAC: <implicit> compression: none [preauth]
debug1: kex: sntrup761x25519-sha512 need=32 dh_need=32 [preauth]
debug1: kex: sntrup761x25519-sha512 need=32 dh_need=32 [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
debug1: mm_answer_sign: hostkey ssh-ed25519 index 2
debug2: monitor_read: 6 used once, disabling now
debug1: ssh_packet_send2_wrapped: resetting send seqnr 3 [preauth]
debug2: ssh_set_newkeys: mode 1 [preauth]
debug1: rekey out after 4294967296 blocks [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: Sending SSH2_MSG_EXT_INFO [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug1: ssh_packet_read_poll2: resetting read seqnr 3 [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug2: ssh_set_newkeys: mode 0 [preauth]
debug1: rekey in after 4294967296 blocks [preauth]
debug2: KEX algorithms: sntrup761x25519-sha512,sntrup761x25519-sha512 at openssh.com,mlkem768x25519-sha256,curve25519-sha256,curve25519-sha256 at libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,ext-info-s,kex-strict-s-v00 at openssh.com [preauth]
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug2: ciphers ctos: aes256-gcm at openssh.com,chacha20-poly1305 at openssh.com,aes256-ctr,aes128-gcm at openssh.com,aes128-ctr [preauth]
debug2: ciphers stoc: aes256-gcm at openssh.com,chacha20-poly1305 at openssh.com,aes256-ctr,aes128-gcm at openssh.com,aes128-ctr [preauth]
debug2: MACs ctos: hmac-sha2-256-etm at openssh.com,hmac-sha1-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512 [preauth]
debug2: MACs stoc: hmac-sha2-256-etm at openssh.com,hmac-sha1-etm at openssh.com,hmac-sha2-512-etm at openssh.com,hmac-sha2-256,hmac-sha1,hmac-sha2-512 [preauth]
debug2: compression ctos: none,zlib at openssh.com [preauth]
debug2: compression stoc: none,zlib at openssh.com [preauth]
debug2: languages ctos:  [preauth]
debug2: languages stoc:  [preauth]
debug2: first_kex_follows 0  [preauth]
debug2: reserved 0  [preauth]
debug1: KEX done [preauth]
debug1: SSH2_MSG_EXT_INFO received [preauth]
debug1: kex_ext_info_check_ver: ext-info-in-auth at openssh.com=<0> [preauth]
debug1: userauth-request for user sma-user1 service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug2: parse_server_config_depth: config reprocess config len 4123
debug2: parse_server_config_depth: config  len 0
debug2: parse_server_config_depth: config /usr/etc/ssh/sshd_config.d/40-suse-crypto-policies.conf len 413
debug2: parse_server_config_depth: config /etc/crypto-policies/back-ends/opensshserver.config len 2331
debug2: monitor_read: 8 used once, disabling now
debug2: input_userauth_request: setting up authctxt for sma-user1 [preauth]
debug1: PAM: initializing for "sma-user1" with service "sshd"
debug1: PAM: setting PAM_RHOST to "192.168.69.115"
debug1: PAM: setting PAM_TTY to "ssh"
debug2: monitor_read: 100 used once, disabling now
debug1: kex_server_update_ext_info: Sending SSH2_MSG_EXT_INFO [preauth]
debug2: input_userauth_request: try method none [preauth]
debug1: userauth-request for user sma-user1 service ssh-connection method publickey [preauth]
debug1: attempt 1 failures 0 [preauth]
debug2: input_userauth_request: try method publickey [preauth]
debug2: userauth_pubkey: valid user sma-user1 querying public key ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHbvlLCXAXcBRsuF52OsOmnE4dLhT0ua+HsqW6+dDxPG [preauth]
debug1: userauth_pubkey: publickey test pkalg ssh-ed25519 pkblob ED25519 SHA256:gaxKqY1KfNtIUVs2IAMReWmhsg7ZITBKh7HDS96mQPI [preauth]
debug2: monitor_read: 4 used once, disabling now
debug2: monitor_read: 80 used once, disabling now
debug1: temporarily_use_uid: 1000/100 (e=0/0)
debug1: restore_uid: 0/0
debug1: temporarily_use_uid: 1000/100 (e=0/0)
debug1: trying public key file /home/sma-user1/.ssh/authorized_keys
debug1: fd 8 clearing O_NONBLOCK
debug2: auth_check_authkeys_file: /home/sma-user1/.ssh/authorized_keys: processed 1/1 lines
debug1: restore_uid: 0/0
Failed publickey for sma-user1 from 192.168.69.115 port 44146 ssh2: ED25519 SHA256:gaxKqY1KfNtIUVs2IAMReWmhsg7ZITBKh7HDS96mQPI
debug2: userauth_pubkey: authenticated 0 pkalg ssh-ed25519 [preauth]
debug1: userauth-request for user sma-user1 service ssh-connection method password [preauth]
debug1: attempt 2 failures 1 [preauth]
debug2: input_userauth_request: try method password [preauth]
debug2: sshpam_auth_passwd: auth information in SSH_AUTH_INFO_0
debug1: PAM: password authentication accepted for sma-user1
debug1: do_pam_account: called
debug2: do_pam_account: auth information in SSH_AUTH_INFO_0
Accepted password for sma-user1 from 192.168.69.115 port 44146 ssh2
debug1: monitor_child_preauth: user sma-user1 authenticated by privileged process
debug1: monitor_read_log: child log fd closed
debug1: audit_event: unhandled event 2
debug1: SELinux support disabled
debug1: PAM: establishing credentials
debug2: do_pam_session: auth information in SSH_AUTH_INFO_0
User child is on pid 477425
debug1: PAM: establishing credentials
debug1: permanently_set_uid: 1000/100
debug2: ssh_set_newkeys: mode 0
debug1: rekey in after 4294967296 blocks
debug2: ssh_set_newkeys: mode 1
debug1: rekey out after 4294967296 blocks
debug1: ssh_packet_set_postauth: called
debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Entering interactive session for SSH2.
debug1: server_init_dispatch
debug2: process_output: session QoS is now interactive
debug1: server_input_channel_open: ctype session rchan 0 win 1048576 max 16384
debug1: input_session_request
debug1: channel 0: new session [server-session] (inactive timeout: 0)
debug2: session_new: allocate (allocated 0 max 10)
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.
debug2: session_new: allocate (allocated 0 max 10)
debug1: session_new: session 0
debug1: SELinux support disabled
debug1: session_pty_req: session 0 alloc /dev/pts/4
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug2: Setting env 0: COLORTERM=truecolor
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug2: Setting env 1: LANG=en_US.UTF-8
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
debug2: channel_set_xtype: labeled channel 0 as session:shell (inactive timeout 0)
Starting session: shell on pts/4 for sma-user1 from 192.168.69.115 port 44146 id 0
debug2: channel 0: rfd 13 isatty
debug2: fd 13 setting O_NONBLOCK
debug1: Setting controlling tty using TIOCSCTTY.
debug2: channel 0: rcvd adjust 49211
debug1: server_input_global_request: rtype keepalive at openssh.com want_reply 1
debug2: channel 0: rcvd adjust 49255
debug2: channel 0: rcvd adjust 49273
mm_reap: child terminated by signal 9
debug1: do_cleanup
debug1: PAM: cleanup
debug1: PAM: closing session
debug1: PAM: deleting credentials
debug1: temporarily_use_uid: 1000/100 (e=0/0)
debug1: restore_uid: 0/0
debug1: session_pty_cleanup2: session 0 release /dev/pts/4
syslogin_perform_logout: logout() returned an error