The connection is too slow and always timeout

[jufeng2006]

"OpenSSH for Windows" version 8.6.0.0

Server OperatingSystem Window7 64bit

Client OperatingSystem Windows Embedded Standard

What is failing I use SSHD as the service, the connection would task more than 5 minutes via putty or SSH client directly, it always timeout until I modify the time out from 2 minutes to 10 minutes. I highlight the steps that takes long time as below(always some performance in many attempts). Any suggestion would thanks a lot.

Below is the full log(I hid my personal information).

5128 2021-11-17 00:26:50.692 Connection from xxx.xxx.xxx.xx port 62587 on 192.168.111.102 port 22 5128 2021-11-17 00:26:50.692 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.6 5128 2021-11-17 00:26:50.692 debug1: Remote protocol version 2.0, remote software version PuTTY_Release_0.75 5128 2021-11-17 00:26:50.692 debug1: compat_banner: no match: PuTTY_Release_0.75 5128 2021-11-17 00:26:50.692 debug2: fd 4 setting O_NONBLOCK 5128 2021-11-17 00:26:50.693 debug3: unable to load module api-ms-win-security-lsapolicy-l1-1-0.dll at run time, error: 126 5128 2021-11-17 00:26:50.693 debug3: unable to load module api-ms-win-security-lsapolicy-l1-1-0.dll at run time, error: 126 5128 2021-11-17 00:26:50.693 debug3: unable to load module api-ms-win-security-lsapolicy-l1-1-0.dll at run time, error: 126 5128 2021-11-17 00:26:50.732 debug3: unable to load module api-ms-win-security-lsapolicy-l1-1-0.dll at run time, error: 126 5128 2021-11-17 00:26:50.742 debug3: unable to load module api-ms-win-security-lsapolicy-l1-1-0.dll at run time, error: 126 5128 2021-11-17 00:26:50.743 debug3: spawning "C:\Program Files\OpenSSH\sshd.exe" -y as user 5128 2021-11-17 00:26:50.743 debug2: Network child is on pid 5960 5128 2021-11-17 00:26:50.743 debug3: send_rexec_state: enxxxxing fd = 6 config len 339 5128 2021-11-17 00:26:50.743 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:26:50.743 debug3: send_rexec_state: done 5128 2021-11-17 00:26:50.743 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:26:50.743 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:26:50.744 debug3: preauth child monitor started 5128 2021-11-17 00:29:00.179 debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] 5128 2021-11-17 00:29:00.179 debug3: send packet: type 20 [preauth] 5128 2021-11-17 00:29:00.179 debug1: SSH2_MSG_KEXINIT sent [preauth] 5128 2021-11-17 00:29:00.179 debug3: receive packet: type 20 [preauth] 5128 2021-11-17 00:29:00.179 debug1: SSH2_MSG_KEXINIT received [preauth] 5128 2021-11-17 00:29:00.179 debug2: local server KEXINIT proposal [preauth] 5128 2021-11-17 00:29:00.179 debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@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-group14-sha256 [preauth] 5128 2021-11-17 00:29:00.179 debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] 5128 2021-11-17 00:29:00.179 debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: MACs ctos: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] 5128 2021-11-17 00:29:00.179 debug2: MACs stoc: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth] 5128 2021-11-17 00:29:00.179 debug2: compression ctos: none,zlib@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: compression stoc: none,zlib@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: languages ctos: [preauth] 5128 2021-11-17 00:29:00.179 debug2: languages stoc: [preauth] 5128 2021-11-17 00:29:00.179 debug2: first_kex_follows 0 [preauth] 5128 2021-11-17 00:29:00.179 debug2: reserved 0 [preauth] 5128 2021-11-17 00:29:00.179 debug2: peer client KEXINIT proposal [preauth] 5128 2021-11-17 00:29:00.179 debug2: KEX algorithms: gss-gex-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-group14-sha1-toWM5Slw5Ew8Mqkay+al2g==,gss-group1-sha1-toWM5Slw5Ew8Mqkay+al2g==,curve448-sha512,curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,rsa2048-sha256,rsa1024-sha1,diffie-hellman-group1-sha1,ext-info-c [preauth] 5128 2021-11-17 00:29:00.179 debug2: host key algorithms: ssh-ed25519,ssh-ed448,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-dss,null [preauth] 5128 2021-11-17 00:29:00.179 debug2: ciphers ctos: aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,chacha20-poly1305@openssh.com,3des-ctr,3des-cbc,blowfish-ctr,blowfish-cbc,arcfour256,arcfour128 [preauth] 5128 2021-11-17 00:29:00.179 debug2: ciphers stoc: aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,chacha20-poly1305@openssh.com,3des-ctr,3des-cbc,blowfish-ctr,blowfish-cbc,arcfour256,arcfour128 [preauth] 5128 2021-11-17 00:29:00.179 debug2: MACs ctos: hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-etm@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: MACs stoc: hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-etm@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: compression ctos: none,zlib,zlib@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: compression stoc: none,zlib,zlib@openssh.com [preauth] 5128 2021-11-17 00:29:00.179 debug2: languages ctos: [preauth] 5128 2021-11-17 00:29:00.179 debug2: languages stoc: [preauth] 5128 2021-11-17 00:29:00.179 debug2: first_kex_follows 0 [preauth] 5128 2021-11-17 00:29:00.179 debug2: reserved 0 [preauth] 5128 2021-11-17 00:29:00.179 debug1: kex: algorithm: curve25519-sha256 [preauth] 5128 2021-11-17 00:29:00.179 debug1: kex: host key algorithm: ssh-ed25519 [preauth] 5128 2021-11-17 00:29:00.179 debug1: kex: client->server cipher: aes256-ctr MAC: hmac-sha2-256 compression: none [preauth] 5128 2021-11-17 00:29:00.179 debug1: kex: server->client cipher: aes256-ctr MAC: hmac-sha2-256 compression: none [preauth] 5128 2021-11-17 00:29:00.179 debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] 5128 2021-11-17 00:29:00.530 debug3: receive packet: type 30 [preauth] 5128 2021-11-17 00:29:00.530 debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth] 5128 2021-11-17 00:29:00.534 debug3: mm_sshkey_sign: enxxxxing [preauth] 5128 2021-11-17 00:29:00.534 debug3: mm_request_send: enxxxxing, type 6 [preauth] 5128 2021-11-17 00:29:00.534 debug3: mm_request_receive: enxxxxing 5128 2021-11-17 00:29:00.534 debug3: monitor_read: checking request 6 5128 2021-11-17 00:29:00.534 debug3: mm_answer_sign: enxxxxing 5128 2021-11-17 00:29:00.535 debug3: mm_answer_sign: KEX signature 0000000000419000(83) 5128 2021-11-17 00:29:00.535 debug3: mm_request_send: enxxxxing, type 7 5128 2021-11-17 00:29:00.535 debug2: monitor_read: 6 used once, disabling now 5128 2021-11-17 00:29:00.535 debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth] 5128 2021-11-17 00:29:00.535 debug3: mm_request_receive_expect: enxxxxing, type 7 [preauth] 5128 2021-11-17 00:29:00.535 debug3: mm_request_receive: enxxxxing [preauth] 5128 2021-11-17 00:29:00.535 debug3: send packet: type 31 [preauth] 5128 2021-11-17 00:29:00.535 debug3: send packet: type 21 [preauth] 5128 2021-11-17 00:29:00.535 debug2: set_newkeys: mode 1 [preauth] 5128 2021-11-17 00:29:00.535 debug1: rekey out afxxxx 4294967296 blocks [preauth] 5128 2021-11-17 00:29:00.535 debug1: SSH2_MSG_NEWKEYS sent [preauth] 5128 2021-11-17 00:29:00.535 debug1: Sending SSH2_MSG_EXT_INFO [preauth] 5128 2021-11-17 00:29:00.535 debug3: send packet: type 7 [preauth] 5128 2021-11-17 00:29:00.535 debug1: expecting SSH2_MSG_NEWKEYS [preauth] 5128 2021-11-17 00:29:09.711 debug3: receive packet: type 21 [preauth] 5128 2021-11-17 00:29:09.711 debug1: SSH2_MSG_NEWKEYS received [preauth] 5128 2021-11-17 00:29:09.711 debug2: set_newkeys: mode 0 [preauth] 5128 2021-11-17 00:29:09.711 debug1: rekey in afxxxx 4294967296 blocks [preauth] 5128 2021-11-17 00:29:09.711 debug1: KEX done [preauth] 5128 2021-11-17 00:29:09.711 debug3: receive packet: type 5 [preauth] 5128 2021-11-17 00:29:09.711 debug3: send packet: type 6 [preauth] 5128 2021-11-17 00:29:27.457 debug3: receive packet: type 50 [preauth] 5128 2021-11-17 00:29:27.457 debug1: userauth-request for user xxxx\\xxxx service ssh-connection method none [preauth] 5128 2021-11-17 00:29:27.457 debug1: attempt 0 failures 0 [preauth] 5128 2021-11-17 00:29:27.457 debug3: mm_getpwnamallow: enxxxxing [preauth] 5128 2021-11-17 00:29:27.457 debug3: mm_request_send: enxxxxing, type 8 [preauth] 5128 2021-11-17 00:29:27.457 debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth] 5128 2021-11-17 00:29:27.457 debug3: mm_request_receive_expect: enxxxxing, type 9 [preauth] 5128 2021-11-17 00:29:27.457 debug3: mm_request_receive: enxxxxing [preauth] 5128 2021-11-17 00:29:27.457 debug3: mm_request_receive: enxxxxing 5128 2021-11-17 00:29:27.457 debug3: monitor_read: checking request 8 5128 2021-11-17 00:29:27.457 debug3: mm_answer_pwnamallow: enxxxxing 5128 2021-11-17 00:29:27.458 debug2: parse_server_config_depth: config reprocess config len 339 5128 2021-11-17 00:29:27.458 debug3: checking match for 'Group administrators' user xxxx\xxxx host 132.223.130.14 addr 132.223.130.14 laddr 192.168.111.102 lport 22 5128 2021-11-17 00:29:27.474 debug3: lookup_principal_name: Successfully discovered explicit principal name: 'xxxx\xxxx'=>'xxxx@xxxx.xxxxadyne.com' 5128 2021-11-17 00:29:27.482 debug3: LsaLogonUser Succeeded (Impersonation: 0) 5128 2021-11-17 00:29:27.482 debug1: user xxxx\xxxx matched group list administrators at line 87 5128 2021-11-17 00:29:27.482 debug3: match found 5128 2021-11-17 00:29:27.482 debug3: reprocess config:88 setting AuthorizedKeysFile PROGRAMDATA/ssh/administrators_authorized_keys 5128 2021-11-17 00:29:27.483 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1 5128 2021-11-17 00:29:27.483 debug3: mm_request_send: enxxxxing, type 9 5128 2021-11-17 00:29:27.483 debug2: monitor_read: 8 used once, disabling now 5128 2021-11-17 00:29:27.484 debug2: input_userauth_request: setting up authctxt for xxxx\\xxxx [preauth] 5128 2021-11-17 00:29:27.484 debug3: mm_inform_authserv: enxxxxing [preauth] 5128 2021-11-17 00:29:27.484 debug3: mm_request_send: enxxxxing, type 4 [preauth] 5128 2021-11-17 00:29:27.484 debug2: input_userauth_request: try method none [preauth] 5128 2021-11-17 00:29:27.484 debug3: mm_request_receive: enxxxxing 5128 2021-11-17 00:29:27.484 debug3: monitor_read: checking request 4 5128 2021-11-17 00:29:27.484 debug3: mm_answer_authserv: service=ssh-connection, style= 5128 2021-11-17 00:29:27.484 debug2: monitor_read: 4 used once, disabling now 5128 2021-11-17 00:29:27.484 debug3: user_specific_delay: user specific delay 0.000ms [preauth] 5128 2021-11-17 00:29:27.484 debug3: ensure_minimum_time_since: elapsed 27.002ms, delaying 23.382ms (requested 6.298ms) [preauth] 5128 2021-11-17 00:29:27.508 debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-inxxxxactive" [preauth] 5128 2021-11-17 00:29:27.508 debug3: send packet: type 51 [preauth] 5128 2021-11-17 00:29:27.852 debug3: receive packet: type 50 [preauth] 5128 2021-11-17 00:29:27.852 debug1: userauth-request for user xxxx\\xxxx service ssh-connection method keyboard-inxxxxactive [preauth] 5128 2021-11-17 00:29:27.852 debug1: attempt 1 failures 0 [preauth] 5128 2021-11-17 00:29:27.852 debug2: input_userauth_request: try method keyboard-inxxxxactive [preauth] 5128 2021-11-17 00:29:27.852 debug1: keyboard-inxxxxactive devs [preauth] 5128 2021-11-17 00:29:27.852 debug1: auth2_challenge: user=xxxx\\xxxx devs= [preauth] 5128 2021-11-17 00:29:27.852 debug1: kbdint_alloc: devices '' [preauth] 5128 2021-11-17 00:29:27.852 debug2: auth2_challenge_start: devices [preauth] 5128 2021-11-17 00:29:27.852 debug3: user_specific_delay: user specific delay 0.000ms [preauth] 5128 2021-11-17 00:29:27.852 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 6.298ms (requested 6.298ms) [preauth] 5128 2021-11-17 00:29:27.859 debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-inxxxxactive" [preauth] 5128 2021-11-17 00:29:27.859 debug3: send packet: type 51 [preauth] 5128 2021-11-17 00:29:32.977 debug3: receive packet: type 2 [preauth] 5128 2021-11-17 00:29:32.977 debug3: Received SSH2_MSG_IGNORE [preauth] 5128 2021-11-17 00:29:32.977 debug3: receive packet: type 50 [preauth] 5128 2021-11-17 00:29:32.977 debug1: userauth-request for user xxxx\\xxxx service ssh-connection method password [preauth] 5128 2021-11-17 00:29:32.977 debug1: attempt 2 failures 1 [preauth] 5128 2021-11-17 00:29:32.977 debug2: input_userauth_request: try method password [preauth] 5128 2021-11-17 00:29:32.977 debug3: mm_auth_password: enxxxxing [preauth] 5128 2021-11-17 00:29:32.977 debug3: mm_request_send: enxxxxing, type 12 [preauth] 5128 2021-11-17 00:29:32.977 debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth] 5128 2021-11-17 00:29:32.977 debug3: mm_request_receive_expect: enxxxxing, type 13 [preauth] 5128 2021-11-17 00:29:32.977 debug3: mm_request_receive: enxxxxing [preauth] 5128 2021-11-17 00:29:32.977 debug3: mm_request_receive: enxxxxing 5128 2021-11-17 00:29:32.977 debug3: monitor_read: checking request 12 5128 2021-11-17 00:29:32.983 debug3: lookup_principal_name: Successfully discovered explicit principal name: 'xxxx\xxxx'=>'xxxx@xxxx.xxxxadyne.com' 5128 2021-11-17 00:29:33.001 debug3: mm_answer_authpassword: sending result 1 5128 2021-11-17 00:29:33.001 debug3: mm_answer_authpassword: sending result 1 5128 2021-11-17 00:29:33.001 debug3: mm_request_send: enxxxxing, type 13 5128 2021-11-17 00:29:33.001 Accepted password for xxxx\xxxx from xxx.xxx.xxx.xxx port 62587 ssh2 5128 2021-11-17 00:29:33.001 debug1: monitor_child_preauth: user xxxx\xxxx authenticated by privileged process 5128 2021-11-17 00:29:33.001 debug3: mm_get_keystate: Waiting for new keys 5128 2021-11-17 00:29:33.001 debug3: mm_request_receive_expect: enxxxxing, type 26 5128 2021-11-17 00:29:33.001 debug3: mm_request_receive: enxxxxing 5128 2021-11-17 00:29:33.003 debug3: mm_get_keystate: GOT new keys 5128 2021-11-17 00:29:33.003 debug3: mm_auth_password: user authenticated [preauth] 5128 2021-11-17 00:29:33.003 debug3: user_specific_delay: user specific delay 0.000ms [preauth] 5128 2021-11-17 00:29:33.003 debug3: ensure_minimum_time_since: elapsed 24.001ms, delaying 1.191ms (requested 6.298ms) [preauth] 5128 2021-11-17 00:29:33.003 debug3: send packet: type 52 [preauth] 5128 2021-11-17 00:29:33.003 debug3: mm_request_send: enxxxxing, type 26 [preauth] 5128 2021-11-17 00:29:33.003 debug3: mm_send_keystate: Finished sending state [preauth] 5128 2021-11-17 00:29:33.003 debug1: monitor_read_log: child log fd closed 5128 2021-11-17 00:29:33.019 debug3: spawning "C:\Program Files\OpenSSH\sshd.exe" -z as user 5128 2021-11-17 00:29:33.019 User child is on pid 3836 5128 2021-11-17 00:29:33.019 debug3: send_rexec_state: enxxxxing fd = 5 config len 339 5128 2021-11-17 00:29:33.019 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:29:33.019 debug3: send_rexec_state: done 5128 2021-11-17 00:29:33.019 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:29:33.019 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:29:33.019 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:29:33.019 debug3: ssh_msg_send: type 0 5128 2021-11-17 00:29:33.019 debug3: ssh_msg_send: type 0 3836 2021-11-17 00:31:59.772 debug3: recv_idexch_state: enxxxxing fd = 3 3836 2021-11-17 00:31:59.772 debug3: ssh_msg_recv enxxxxing 3836 2021-11-17 00:31:59.772 debug3: recv_idexch_state: done 3836 2021-11-17 00:31:59.772 debug2: fd 4 setting O_NONBLOCK 3836 2021-11-17 00:31:59.772 debug3: recv_autxctx_state: enxxxxing fd = 3 3836 2021-11-17 00:31:59.772 debug3: ssh_msg_recv enxxxxing 3836 2021-11-17 00:31:59.772 debug3: recv_autxctx_state: done 3836 2021-11-17 00:31:59.773 debug2: parse_server_config_depth: config reprocess config len 339 3836 2021-11-17 00:31:59.773 debug3: checking match for 'Group administrators' user xxxx\xxxx host xxx.xxx.xxx.xxx addr xxx.xxx.xxx.xxx laddr 192.168.111.102 lport 22 3836 2021-11-17 00:31:59.774 debug3: get_user_token - i am running as xxxx\xxxx, returning process token 3836 2021-11-17 00:31:59.774 debug1: user xxxx\xxxx matched group list administrators at line 87 3836 2021-11-17 00:31:59.774 debug3: match found 3836 2021-11-17 00:31:59.774 debug3: reprocess config:88 setting AuthorizedKeysFile PROGRAMDATA/ssh/administrators_authorized_keys 3836 2021-11-17 00:31:59.775 debug3: monitor_recv_keystate: enxxxxing 3836 2021-11-17 00:31:59.775 debug3: ssh_msg_recv enxxxxing 3836 2021-11-17 00:31:59.775 debug3: monitor_recv_keystate: done 3836 2021-11-17 00:31:59.775 debug3: monitor_apply_keystate: packet_set_state 3836 2021-11-17 00:31:59.775 debug2: set_newkeys: mode 0 3836 2021-11-17 00:31:59.775 debug1: rekey in afxxxx 4294967296 blocks 3836 2021-11-17 00:31:59.775 debug2: set_newkeys: mode 1 3836 2021-11-17 00:31:59.775 debug1: rekey out afxxxx 4294967296 blocks 3836 2021-11-17 00:31:59.775 debug1: ssh_packet_set_postauth: called 3836 2021-11-17 00:31:59.775 debug3: ssh_packet_set_state: done 3836 2021-11-17 00:31:59.775 debug3: monitor_recv_authopt: enxxxxing 3836 2021-11-17 00:31:59.775 debug3: ssh_msg_recv enxxxxing 3836 2021-11-17 00:31:59.775 debug3: monitor_recv_authopt: done 3836 2021-11-17 00:31:59.775 debug3: notify_hostkeys: key 0: ssh-rsa SHA256:MjZYhMhcVlQhE3BT4ZZQeNigfFpehvVy5VeRC3ja6FI 3836 2021-11-17 00:31:59.775 debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:X6Qt8evE0joCL2uKKMz65hjPz2USWDJF52NXDQCAHIU 3836 2021-11-17 00:31:59.775 debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:mfq+4X6/4+qI4ncXwWbVkILsSFn/7ohixE7ndnqB4AY 3836 2021-11-17 00:31:59.775 debug3: notify_hostkeys: sent 3 hostkeys 3836 2021-11-17 00:31:59.775 debug3: send packet: type 80 3836 2021-11-17 00:31:59.775 debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding 3836 2021-11-17 00:31:59.775 debug1: Enxxxxing inxxxxactive session for SSH2. 3836 2021-11-17 00:31:59.775 debug2: fd 7 setting O_NONBLOCK 3836 2021-11-17 00:31:59.775 debug2: fd 8 setting O_NONBLOCK 3836 2021-11-17 00:31:59.775 debug1: server_init_dispatch 3836 2021-11-17 00:31:59.776 debug3: receive packet: type 90 3836 2021-11-17 00:31:59.776 debug1: server_input_channel_open: ctype session rchan 256 win 16384 max 16384 3836 2021-11-17 00:31:59.776 debug1: input_session_request 3836 2021-11-17 00:31:59.776 debug1: channel 0: new [server-session] 3836 2021-11-17 00:31:59.776 debug2: session_new: allocate (allocated 0 max 10) 3836 2021-11-17 00:31:59.776 debug3: session_unused: session id 0 unused 3836 2021-11-17 00:31:59.776 debug1: session_new: session 0 3836 2021-11-17 00:31:59.776 debug1: session_open: channel 0 3836 2021-11-17 00:31:59.776 debug1: session_open: session 0: link with channel 0 3836 2021-11-17 00:31:59.776 debug1: server_input_channel_open: confirm session 3836 2021-11-17 00:31:59.776 debug3: send packet: type 91 3836 2021-11-17 00:32:00.506 debug3: receive packet: type 98 3836 2021-11-17 00:32:00.506 debug1: server_input_channel_req: channel 0 request pty-req reply 1 3836 2021-11-17 00:32:00.506 debug1: session_by_channel: session 0 channel 0 3836 2021-11-17 00:32:00.506 debug1: session_input_channel_req: session 0 req pty-req 3836 2021-11-17 00:32:00.506 debug1: Allocating pty. 3836 2021-11-17 00:32:00.506 debug3: fd 9 is not O_NONBLOCK 3836 2021-11-17 00:32:00.506 debug3: fd 10 is not O_NONBLOCK 3836 2021-11-17 00:32:00.506 debug1: session_pty_req: session 0 alloc windows-pty 3836 2021-11-17 00:32:00.506 debug1: Ignoring unsupported tty mode opcode 3 (0x3) 3836 2021-11-17 00:32:00.506 debug1: Ignoring unsupported tty mode opcode 42 (0x2a) 3836 2021-11-17 00:32:00.506 debug3: send packet: type 99 3836 2021-11-17 00:32:00.506 debug3: receive packet: type 98 3836 2021-11-17 00:32:00.506 debug1: server_input_channel_req: channel 0 request shell reply 1 3836 2021-11-17 00:32:00.506 debug1: session_by_channel: session 0 channel 0 3836 2021-11-17 00:32:00.506 debug1: session_input_channel_req: session 0 req shell 3836 2021-11-17 00:32:00.506 Starting session: shell on windows-pty for xxxx\xxxx from xxx.xxx.xxx.xxx port 62587 id 0 3836 2021-11-17 00:32:00.507 debug2: fd 11 setting O_NONBLOCK 3836 2021-11-17 00:32:00.507 debug2: fd 12 setting O_NONBLOCK 3836 2021-11-17 00:32:00.507 debug2: fd 13 setting O_NONBLOCK 3836 2021-11-17 00:32:00.507 debug2: fd 14 setting O_NONBLOCK 3836 2021-11-17 00:32:00.507 debug2: fd 15 setting O_NONBLOCK 3836 2021-11-17 00:32:00.507 debug2: fd 16 setting O_NONBLOCK 3836 2021-11-17 00:32:00.507 debug3: shell: "c:\windows\system32\cmd.exe" 3836 2021-11-17 00:32:00.507 debug3: shell_option: /c 3836 2021-11-17 00:32:00.507 debug3: couldn't find CreatePseudoConsole() in kernel32.dll dll 3836 2021-11-17 00:32:00.507 debug3: This windows OS doesn't support conpty 3836 2021-11-17 00:32:00.507 debug3: pty commandline: "C:\Program Files\OpenSSH\ssh-shellhost.exe" ---pty "c:\windows\system32\cmd.exe" 3836 2021-11-17 00:32:00.508 debug2: fd 4 setting TCP_NODELAY 3836 2021-11-17 00:32:00.508 debug2: channel 0: rfd 13 isatty 3836 2021-11-17 00:32:00.508 debug3: fd 13 is O_NONBLOCK 3836 2021-11-17 00:32:00.509 debug3: fd 12 is O_NONBLOCK 3836 2021-11-17 00:32:00.509 debug3: send packet: type 99 3836 2021-11-17 00:42:36.411 Connection closed by xxx.xxx.xxx.xxx port 62587 3836 2021-11-17 00:42:36.411 debug1: channel 0: free: server-session, nchannels 1 3836 2021-11-17 00:42:36.411 debug3: channel 0: status: The following connections are open:\r\n #0 server-session (t4 r256 i0/0 o0/0 e[closed]/0 fd 13/12/-1 sock -1 cc -1)\r\n 3836 2021-11-17 00:42:36.411 Close session: user xxxx\xxxx from xxx.xxx.xxx.xxx port 62587 id 0 3836 2021-11-17 00:42:36.411 debug3: session_unused: session id 0 unused 3836 2021-11-17 00:42:36.411 debug1: do_cleanup 3836 2021-11-17 00:42:36.411 Transferred: sent 3952, received 2016 bytes 3836 2021-11-17 00:42:36.411 Closing connection to xxx.xxx.xxx.xxx port 62587

[bagajjal]

can you also provide us ssh client logs..

[jufeng2006]

Hi bagajjal, Thanks for your reply, Below is the client log. There is a magical thing, on a computer(service side) I uninstalled 8.6 and then install the earlier version v7.6.0.0p1-Beta, it work smoothly and the connection speed is very fast, followed I thought v7.6 is too old and not release version, I uninstall it and install V8.1, it also work smoothly. On another computer(service side, the some performance as the issue I described above) I uninstalled 8.6 and install V8.1 directly, it still doesn't work, then repeated the steps install V7.6->uninstall V7.6->install V8.1, it is working.

C:\Windows\system32>"C:\Program Files\OpenSSH\ssh" -vvv remote-machine-xxx OpenSSH_for_Windows_8.1p1, LibreSSL 2.9.2 debug3: Failed to open file:C:/Users/xxxx/.ssh/config error:2 debug3: Failed to open file:C:/ProgramData/ssh/ssh_config error:2 debug2: resolving "remote-machine-xxx" port 22 debug2: ssh_connect_direct debug1: Connecting to remote-machine-xxx [192.168.111.105] port 22. debug1: Connection established. debug3: Failed to open file:C:/Users/xxxx/.ssh/id_rsa error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_rsa.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_rsa type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_rsa-cert error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_rsa-cert.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_rsa-cert type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_dsa error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_dsa.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_dsa type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_dsa-cert error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_dsa-cert.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_dsa-cert type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ecdsa error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ecdsa.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_ecdsa type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ecdsa-cert error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ecdsa-cert.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_ecdsa-cert type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ed25519 error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ed25519.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_ed25519 type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ed25519-cert error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_ed25519-cert.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_ed25519-cert type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_xmss error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_xmss.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_xmss type -1 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_xmss-cert error:2 debug3: Failed to open file:C:/Users/xxxx/.ssh/id_xmss-cert.pub error:2 debug1: identity file C:\Users\xxxx/.ssh/id_xmss-cert type -1 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1 debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.6 debug1: match: OpenSSH_for_Windows_8.6 pat OpenSSH* compat 0x04000000 debug2: fd 3 setting O_NONBLOCK debug1: Authenticating to remote-machine-xxx:22 as 'xxx\xxxx' debug3: hostkeys_foreach: reading file "C:\Users\xxxx/.ssh/known_hosts" debug3: Failed to open file:C:/Users/xxxx/.ssh/known_hosts2 error:2 debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2 debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2 debug3: send packet: type 20 debug1: SSH2_MSG_KEXINIT sent debug3: recv - from CB ERROR:10054, io:000001A2B064AEE0 Connection reset by 192.168.111.105 port 22

[jufeng2006]

Hi bagajjal, One more thing, after below log output on client side, there was a stagnation of about two minutes. debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1

Another stagnation appeared after below log output debug1: SSH2_MSG_KEXINIT sent

The whole procession above is about 4 minutes.

[jufeng2006]

Hi, I did more testing about this issue, On a fresh machine(Win7),
Step1, no matter while you firstly install the release version from 7.9 to 8.6, some performance as above and always timeout in default 2 minutes. Setp2, Uninstall and install the release version 7.7.2, it works. Step3, Uninstall 7.7.2 and try to install 7.9 to 8.6, all of them would be working.

Have wasted a lot of time on this issue but still can't figure the root issue, any help would be greatly appreciated. In the step1, I also noticed that while I start or restart the sshd service on serve side, at the begin within about 2 minutes I try to connect it at client side, It is shown "Connection refused" which meaning the sshd service still in the process of starting, but in Step2 and Step3, once I start or restart the sshd service on serve side, I could connect successfully immediate via below command and it seems no delay.

C:\Windows\system32>"C:\Program Files\OpenSSH\ssh" -vvv MyMachine OpenSSH_for_Windows_8.1p1, LibreSSL 2.9.2 debug3: Failed to open file:C:/Users/xxx/.ssh/config error:2 debug3: Failed to open file:C:/ProgramData/ssh/ssh_config error:2 debug2: resolving "MyMachine" port 22 debug2: ssh_connect_direct debug1: Connecting to MyMachine [xxx.xxx.xxx.xxx] port 22. debug3: finish_connect - ERROR: async io completed with error: 10061, io:00000248C185AD30 debug1: connect to address xxx.xxx.xxx.xxx port 22: Connection refused ssh: connect to host MyMachine port 22: Connection refused

[jufeng2006]

Hi bagajjal, How are you? One more thing, At client side there is a about more than 1 minutes block after output below message, debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1 And then continue to output below message, debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.6

[tiger7z]

Hi bagajjal, How are you? One more thing, At client side there is a about more than 1 minutes block after output below message, debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1 And then continue to output below message, debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.6

I had the same problem in OpenSSH_for_Windows_8.9