Win32-OpenSSH
Win32-OpenSSH copied to clipboard
PowerShell
Connection drops after authentication
"OpenSSH for Windows" version
V8.9.1.0p1-Beta
Server OperatingSystem
Windows 10 Pro 1909
Client OperatingSystem
Windows 10 Pro 1909 and Windows 10 Pro 21H2
What is failing
After successful authentication, the server crashes right after starting the child shell
probbable relevant log output: debug2: channel 0: read failed rfd 14 maxlen 32768: Broken pipe
Expected output After auth, a commandline appears.
Actual output After auth, connection drops (sshd crashes?)
sshd -ddd output
NOTE: added permissions for running as different user (output is the same when starting with psexec -s)
PS C:\Users\user\Downloads\OpenSSH-Win64> .\sshd.exe -ddd
debug2: load_server_config: filename __PROGRAMDATA__\\ssh/sshd_config
debug3: w32_fstat ERROR: bad fd: 3
debug2: load_server_config: done config len = 2242
debug2: parse_server_config_depth: config __PROGRAMDATA__\\ssh/sshd_config len 2242
debug3: __PROGRAMDATA__\\ssh/sshd_config:9 setting SyslogFacility LOCAL0
debug3: __PROGRAMDATA__\\ssh/sshd_config:10 setting LogLevel DEBUG3
debug3: __PROGRAMDATA__\\ssh/sshd_config:41 setting AuthorizedKeysFile .ssh/authorized_keys
debug3: __PROGRAMDATA__\\ssh/sshd_config:82 setting Subsystem sftp sftp-server.exe
debug3: checking syntax for 'Match Group administrators'
debug1: sshd version OpenSSH_for_Windows_8.9, LibreSSL 3.4.3
debug1: get_passwd: lookup_sid() failed: 1332.
debug1: private host key #0: ssh-rsa SHA256:Hu1w7DzyacLej3cHXFPFUoMvAAh3agbs3jwNwZK+I9w
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:G5OrfV8tuY/FNpsuFTqIvj+lPJ+RiYlD9qs0AtA+opc
debug1: private host key #2: ssh-ed25519 SHA256:JGBuevE21pfXU47/42SngszHxQFTi8qe13RUya8bxIM
debug1: rexec_argv[0]='C:\\Users\\user\\Downloads\\OpenSSH-Win64\\sshd.exe'
debug1: rexec_argv[1]='-ddd'
debug2: fd 3 setting O_NONBLOCK
debug3: sock_set_v6only: set socket 3 IPV6_V6ONLY
debug1: Bind to port 22 on ::.
Server listening on :: port 22.
debug2: fd 4 setting O_NONBLOCK
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug3: pselect: installing signal handler for 3, previous 00007FF64945C6C0
debug3: pselect: installing signal handler for 6, previous 00007FF64945C5C0
debug3: pselect: installing signal handler for 7, previous 00007FF64945C6B0
debug3: pselect: installing signal handler for 8, previous 00007FF64945C6B0
debug3: pselect_notify_setup: initializing
debug2: fd 7 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
debug3: pselect_notify_setup: pid 10548 saved 10548 pipe0 7 pipe1 5
debug3: fd 6 is not O_NONBLOCK
debug1: Server will not fork when running in debugging mode.
Connection from ::1 port 50773 on ::1 port 22
debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.9
debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_7.7
debug1: compat_banner: match: OpenSSH_for_Windows_7.7 pat OpenSSH* compat 0x04000000
debug2: fd 6 setting O_NONBLOCK
debug3: spawning "C:\\Users\\user\\Downloads\\OpenSSH-Win64\\sshd.exe" -ddd -y as user
debug2: Network child is on pid 1344
debug3: send_rexec_state: entering fd = 4 config len 2242
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: preauth child monitor started
debug3: append_hostkey_type: ssh-rsa key not permitted by HostkeyAlgorithms [preauth]
debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug3: send packet: type 20 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug3: receive packet: type 20 [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug2: local server KEXINIT proposal [preauth]
debug2: KEX algorithms: curve25519-sha256,[email protected],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]
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
debug2: MACs ctos: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
debug2: MACs stoc: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
debug2: compression ctos: none,[email protected] [preauth]
debug2: compression stoc: none,[email protected] [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: curve25519-sha256,[email protected],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,ext-info-c [preauth]
debug2: host key algorithms: [email protected],[email protected],[email protected],[email protected],[email protected],ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
debug2: MACs ctos: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
debug2: MACs stoc: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
debug2: compression ctos: none [preauth]
debug2: compression stoc: none [preauth]
debug2: languages ctos: [preauth]
debug2: languages stoc: [preauth]
debug2: first_kex_follows 0 [preauth]
debug2: reserved 0 [preauth]
debug1: kex: algorithm: curve25519-sha256 [preauth]
debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
debug1: kex: client->server cipher: [email protected] MAC: <implicit> compression: none [preauth]
debug1: kex: server->client cipher: [email protected] MAC: <implicit> compression: none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug3: receive packet: type 30 [preauth]
debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
debug3: mm_sshkey_sign: entering [preauth]
debug3: mm_request_send: entering, type 6 [preauth]
debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
debug3: mm_request_receive_expect: entering, type 7 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 6
debug3: mm_answer_sign: entering
debug3: mm_answer_sign: ecdsa-sha2-nistp256 KEX signature len=99
debug3: mm_request_send: entering, type 7
debug2: monitor_read: 6 used once, disabling now
debug3: send packet: type 31 [preauth]
debug3: send packet: type 21 [preauth]
debug2: ssh_set_newkeys: mode 1 [preauth]
debug1: rekey out after 134217728 blocks [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: Sending SSH2_MSG_EXT_INFO [preauth]
debug3: send packet: type 7 [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug3: receive packet: type 21 [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug2: ssh_set_newkeys: mode 0 [preauth]
debug1: rekey in after 134217728 blocks [preauth]
debug1: KEX done [preauth]
debug3: receive packet: type 5 [preauth]
debug3: send packet: type 6 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user domain\\\\user service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug3: mm_getpwnamallow: entering [preauth]
debug3: mm_request_send: entering, type 8 [preauth]
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
debug3: mm_request_receive_expect: entering, type 9 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 8
debug3: mm_answer_pwnamallow: entering
debug2: parse_server_config_depth: config reprocess config len 2242
debug3: checking match for 'Group administrators' user domain\\user host ::1 addr ::1 laddr ::1 lport 22
debug3: get_user_token - i am running as domain\\user, returning process token
debug1: user domain\\user matched group list administrators at line 90
debug3: match found
debug3: reprocess config:91 setting AuthorizedKeysFile __PROGRAMDATA__/ssh/administrators_authorized_keys
debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
debug3: mm_request_send: entering, type 9
debug2: monitor_read: 8 used once, disabling now
debug2: input_userauth_request: setting up authctxt for domain\\\\user [preauth]
debug3: mm_inform_authserv: entering [preauth]
debug3: mm_request_send: entering, type 4 [preauth]
debug2: input_userauth_request: try method none [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 78.101ms, delaying 7.894ms (requested 5.375ms) [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 4
debug3: mm_answer_authserv: service=ssh-connection, style=
debug2: monitor_read: 4 used once, disabling now
debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth]
debug3: send packet: type 51 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user domain\\\\user 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 domain\\\\user querying public key rsa-sha2-512 <pubkey> [preauth]
debug1: userauth_pubkey: publickey test pkalg rsa-sha2-512 pkblob RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E [preauth]
debug3: mm_key_allowed: entering [preauth]
debug3: mm_request_send: entering, type 22 [preauth]
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
debug3: mm_request_receive_expect: entering, type 23 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 22
debug3: mm_answer_keyallowed: entering
debug1: trying public key file __PROGRAMDATA__/ssh/administrators_authorized_keys
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: matching key found: RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rcx11-forwarding
Accepted key RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E found at __PROGRAMDATA__/ssh/administrators_authorized_keys:1
debug2: check_authkeys_file: __PROGRAMDATA__/ssh/administrators_authorized_keys: processed 1/1 lines
debug3: mm_answer_keyallowed: publickey authentication test: RSA key is allowed
debug3: mm_request_send: entering, type 23
debug3: send packet: type 60 [preauth]
debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 46.897ms, delaying 39.098ms (requested 5.375ms) [preauth]
Postponed publickey for domain\\\\user from ::1 port 50773 ssh2 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user domain\\\\user service ssh-connection method publickey [preauth]
debug1: attempt 2 failures 0 [preauth]
debug2: input_userauth_request: try method publickey [preauth]
debug2: userauth_pubkey: valid user domain\\\\user attempting public key rsa-sha2-512 <pubkey> [preauth]
debug3: userauth_pubkey: publickey have rsa-sha2-512 signature for RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E [preauth]
debug3: mm_key_allowed: entering [preauth]
debug3: mm_request_send: entering, type 22 [preauth]
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
debug3: mm_request_receive_expect: entering, type 23 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 22
debug3: mm_answer_keyallowed: entering
debug1: trying public key file __PROGRAMDATA__/ssh/administrators_authorized_keys
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: matching key found: RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rcx11-forwarding
Accepted key RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E found at __PROGRAMDATA__/ssh/administrators_authorized_keys:1
debug2: check_authkeys_file: __PROGRAMDATA__/ssh/administrators_authorized_keys: processed 1/1 lines
debug3: mm_answer_keyallowed: publickey authentication: RSA key is allowed
debug3: mm_request_send: entering, type 23
debug3: mm_sshkey_verify: entering [preauth]
debug3: mm_request_send: entering, type 24 [preauth]
debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
debug3: mm_request_receive_expect: entering, type 25 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 24
debug3: mm_answer_keyverify: publickey RSA signature using rsa-sha2-512 verified
debug1: auth_activate_options: setting new authentication options
debug3: mm_request_send: entering, type 25
Accepted publickey for domain\\user from ::1 port 50773 ssh2: RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug1: monitor_child_preauth: user domain\\user authenticated by privileged process
debug3: mm_get_keystate: Waiting for new keys
debug3: mm_request_receive_expect: entering, type 26
debug3: mm_request_receive: entering
debug3: mm_get_keystate: GOT new keys
debug1: auth_activate_options: setting new authentication options [preauth]
debug2: userauth_pubkey: authenticated 1 pkalg rsa-sha2-512 [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 62.497ms, delaying 23.498ms (requested 5.375ms) [preauth]
debug3: send packet: type 52 [preauth]
debug3: mm_request_send: entering, type 26 [preauth]
debug3: mm_send_keystate: Finished sending state [preauth]
debug3: ReadFileEx() ERROR:109, io:0000020A916EDE90
debug3: read - no more data, io:0000020A916EDE90
debug1: monitor_read_log: child log fd closed
debug3: get_user_token - i am running as domain\\user, returning process token
debug1: Not running as SYSTEM: skipping loading user profile
debug3: spawning "C:\\Users\\user\\Downloads\\OpenSSH-Win64\\sshd.exe" -ddd -z as user
User child is on pid 13600
debug3: send_rexec_state: entering fd = 8 config len 2242
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: monitor_recv_keystate: entering
debug3: ssh_msg_recv entering
debug3: monitor_recv_keystate: done
debug3: monitor_apply_keystate: packet_set_state
debug2: ssh_set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug2: ssh_set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: ssh_packet_set_postauth: called
debug3: ssh_packet_set_state: done
debug3: monitor_recv_authopt: entering
debug3: ssh_msg_recv entering
debug3: monitor_recv_authopt: done
debug3: notify_hostkeys: key 0: ssh-rsa SHA256:Hu1w7DzyacLej3cHXFPFUoMvAAh3agbs3jwNwZK+I9w
debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:G5OrfV8tuY/FNpsuFTqIvj+lPJ+RiYlD9qs0AtA+opc
debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:JGBuevE21pfXU47/42SngszHxQFTi8qe13RUya8bxIM
debug3: notify_hostkeys: sent 3 hostkeys
debug3: send packet: type 80
debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Entering interactive session for SSH2.
debug1: server_init_dispatch
debug3: pselect: installing signal handler for 3, previous 00007FF649455070
debug3: pselect_notify_setup: initializing
debug2: fd 10 setting O_NONBLOCK
debug2: fd 8 setting O_NONBLOCK
debug3: pselect_notify_setup: pid 13600 saved 13600 pipe0 10 pipe1 8
debug3: receive packet: type 90
debug1: server_input_channel_open: ctype session rchan 0 win 1048576 max 16384
debug1: input_session_request
debug1: channel 0: new [server-session]
debug2: session_new: allocate (allocated 0 max 10)
debug3: session_unused: session id 0 unused
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
debug3: send packet: type 91
debug3: receive packet: type 80
debug1: server_input_global_request: rtype [email protected] want_reply 0
debug3: receive packet: type 98
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.
debug3: fd 9 is not O_NONBLOCK
debug3: fd 11 is not O_NONBLOCK
debug1: session_pty_req: session 0 alloc windows-pty
debug3: send packet: type 99
debug3: receive packet: type 98
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 windows-pty for domain\\\\user from ::1 port 50773 id 0
debug2: fd 12 setting O_NONBLOCK
debug2: fd 13 setting O_NONBLOCK
debug2: fd 14 setting O_NONBLOCK
debug2: fd 15 setting O_NONBLOCK
debug2: fd 16 setting O_NONBLOCK
debug2: fd 17 setting O_NONBLOCK
debug3: shell: "c:\\\\windows\\\\system32\\\\windowspowershell\\\\v1.0\\\\powershell.exe"
debug3: shell_option: -c
debug3: This windows OS supports conpty
debug3: pty commandline: C:\\\\Windows\\\\system32\\\\conhost.exe --headless --width 120 --height 30 --signal 0x1c0 -- "c:\\\\windows\\\\system32\\\\windowspowershell\\\\v1.0\\\\powershell.exe"
debug2: fd 5 setting TCP_NODELAY
debug2: channel 0: rfd 14 isatty
debug3: fd 14 is O_NONBLOCK
debug3: fd 13 is O_NONBLOCK
debug3: send packet: type 99
debug2: channel 0: read failed rfd 14 maxlen 32768: Broken pipe
debug2: channel 0: read failed
debug2: chan_shutdown_read: channel 0: (i0 o0 sock -1 wfd 14 efd -1 [closed])
debug2: channel 0: input open -> drain
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug2: pselect_notify_done: reading
debug1: Received SIGCHLD.
debug1: session_by_pid: pid 12388
debug1: session_exit_message: session 0 channel 0 pid 12388
debug2: channel 0: request exit-status confirm 0
debug3: send packet: type 98
debug1: session_exit_message: release channel 0
debug2: channel 0: write failed
debug2: chan_shutdown_write: channel 0: (i3 o0 sock -1 wfd 13 efd -1 [closed])
debug2: channel 0: send eow
debug3: send packet: type 98
debug2: channel 0: output open -> closed
debug2: channel 0: send close
debug3: send packet: type 97
debug3: channel 0: will not send data after close
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: is dead
debug2: channel 0: gc: notify user
debug1: session_by_channel: session 0 channel 0
debug1: session_close_by_channel: channel 0 child 0
Close session: user domain\\\\user from ::1 port 50773 id 0
debug3: session_unused: session id 0 unused
debug2: channel 0: gc: user detached
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: server-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 server-session (t4 r0 i3/0 o3/0 e[closed]/0 fd -1/-1/-1 sock -1 cc -1 io 0x00/0x00)
debug3: WSARecv - WSARecv() ERROR: io:000001BE466A96E0 10054
debug3: recv - from CB ERROR:108, io:000001BE466A96E0
Read error from remote host ::1 port 50773: Unknown error
debug1: do_cleanup
debug3: mm_request_receive: entering
debug1: do_cleanup
PS C:\Users\user\Downloads\OpenSSH-Win64>
Please share the associated ssh client logs as well. Looks like ssh client is breaking the connection.
These are the client logs (output is the same on other versions of windows or a linux client).
C:\Users\user\Downloads\OpenSSH-Win64>ssh.exe -vvv localhost
OpenSSH_for_Windows_8.9p1, LibreSSL 3.4.3
debug3: Failed to open file:C:/Users/user/.ssh/config error:2
debug3: Failed to open file:C:/ProgramData/ssh/ssh_config error:2
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts' -> 'C:\\Users\\user/.ssh/known_hosts'
debug3: expanded UserKnownHostsFile '~/.ssh/known_hosts2' -> 'C:\\Users\\user/.ssh/known_hosts2'
debug2: resolving "localhost" port 22
debug3: resolve_host: lookup localhost:22
debug3: ssh_connect_direct: entering
debug1: Connecting to localhost [::1] port 22.
debug1: Connection established.
debug1: identity file C:\\Users\\user/.ssh/id_rsa type 0
debug3: Failed to open file:C:/Users/user/.ssh/id_rsa-cert error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_rsa-cert.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_rsa-cert error:2
debug1: identity file C:\\Users\\user/.ssh/id_rsa-cert type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ecdsa error:2
debug1: identity file C:\\Users\\user/.ssh/id_ecdsa type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa-cert error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa-cert.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ecdsa-cert error:2
debug1: identity file C:\\Users\\user/.ssh/id_ecdsa-cert type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa_sk error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa_sk.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ecdsa_sk error:2
debug1: identity file C:\\Users\\user/.ssh/id_ecdsa_sk type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa_sk-cert error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ecdsa_sk-cert.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ecdsa_sk-cert error:2
debug1: identity file C:\\Users\\user/.ssh/id_ecdsa_sk-cert type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519 error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ed25519 error:2
debug1: identity file C:\\Users\\user/.ssh/id_ed25519 type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519-cert error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519-cert.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ed25519-cert error:2
debug1: identity file C:\\Users\\user/.ssh/id_ed25519-cert type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519_sk error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519_sk.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ed25519_sk error:2
debug1: identity file C:\\Users\\user/.ssh/id_ed25519_sk type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519_sk-cert error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_ed25519_sk-cert.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_ed25519_sk-cert error:2
debug1: identity file C:\\Users\\user/.ssh/id_ed25519_sk-cert type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_xmss error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_xmss.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_xmss error:2
debug1: identity file C:\\Users\\user/.ssh/id_xmss type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_xmss-cert error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_xmss-cert.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_xmss-cert error:2
debug1: identity file C:\\Users\\user/.ssh/id_xmss-cert type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_dsa error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_dsa.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_dsa error:2
debug1: identity file C:\\Users\\user/.ssh/id_dsa type -1
debug3: Failed to open file:C:/Users/user/.ssh/id_dsa-cert error:2
debug3: Failed to open file:C:/Users/user/.ssh/id_dsa-cert.pub error:2
debug3: failed to open file:C:/Users/user/.ssh/id_dsa-cert error:2
debug1: identity file C:\\Users\\user/.ssh/id_dsa-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.9
debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.9
debug1: compat_banner: match: OpenSSH_for_Windows_8.9 pat OpenSSH* compat 0x04000000
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to localhost:22 as 'domain\\user'
debug3: record_hostkey: found key type ECDSA in file C:\\Users\\user/.ssh/known_hosts:2
debug3: record_hostkey: found key type RSA in file C:\\Users\\user/.ssh/known_hosts:3
debug3: record_hostkey: found key type ED25519 in file C:\\Users\\user/.ssh/known_hosts:4
debug3: load_hostkeys_file: loaded 3 keys from localhost
debug3: Failed to open file:C:/Users/user/.ssh/known_hosts2 error:2
debug1: load_hostkeys: fopen C:\\Users\\user/.ssh/known_hosts2: No such file or directory
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug1: load_hostkeys: fopen __PROGRAMDATA__\\ssh/ssh_known_hosts: No such file or directory
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug1: load_hostkeys: fopen __PROGRAMDATA__\\ssh/ssh_known_hosts2: No such file or directory
debug3: order_hostkeyalgs: have matching best-preference key type [email protected], using HostkeyAlgorithms verbatim
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,[email protected],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,ext-info-c
debug2: host key algorithms: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,[email protected],[email protected],rsa-sha2-512,rsa-sha2-256
debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected]
debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected]
debug2: MACs ctos: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,[email protected],zlib
debug2: compression stoc: none,[email protected],zlib
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug2: peer server KEXINIT proposal
debug2: KEX algorithms: curve25519-sha256,[email protected],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
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected]
debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected]
debug2: MACs ctos: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,[email protected]
debug2: compression stoc: none,[email protected]
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: [email protected] MAC: <implicit> compression: none
debug1: kex: client->server cipher: [email protected] MAC: <implicit> compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: SSH2_MSG_KEX_ECDH_REPLY received
debug1: Server host key: ssh-ed25519 SHA256:JGBuevE21pfXU47/42SngszHxQFTi8qe13RUya8bxIM
debug3: record_hostkey: found key type ECDSA in file C:\\Users\\user/.ssh/known_hosts:2
debug3: record_hostkey: found key type RSA in file C:\\Users\\user/.ssh/known_hosts:3
debug3: record_hostkey: found key type ED25519 in file C:\\Users\\user/.ssh/known_hosts:4
debug3: load_hostkeys_file: loaded 3 keys from localhost
debug3: Failed to open file:C:/Users/user/.ssh/known_hosts2 error:2
debug1: load_hostkeys: fopen C:\\Users\\user/.ssh/known_hosts2: No such file or directory
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts error:2
debug1: load_hostkeys: fopen __PROGRAMDATA__\\ssh/ssh_known_hosts: No such file or directory
debug3: Failed to open file:C:/ProgramData/ssh/ssh_known_hosts2 error:2
debug1: load_hostkeys: fopen __PROGRAMDATA__\\ssh/ssh_known_hosts2: No such file or directory
debug1: Host 'localhost' is known and matches the ED25519 host key.
debug1: Found key in C:\\Users\\user/.ssh/known_hosts:4
debug3: send packet: type 21
debug2: ssh_set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: receive packet: type 21
debug1: SSH2_MSG_NEWKEYS received
debug2: ssh_set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug3: unable to connect to pipe \\\\.\\pipe\\openssh-ssh-agent, error: 2
debug1: get_agent_identities: ssh_get_authentication_socket: No such file or directory
debug1: Will attempt key: C:\\Users\\user/.ssh/id_rsa RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug1: Will attempt key: C:\\Users\\user/.ssh/id_ecdsa
debug1: Will attempt key: C:\\Users\\user/.ssh/id_ecdsa_sk
debug1: Will attempt key: C:\\Users\\user/.ssh/id_ed25519
debug1: Will attempt key: C:\\Users\\user/.ssh/id_ed25519_sk
debug1: Will attempt key: C:\\Users\\user/.ssh/id_xmss
debug1: Will attempt key: C:\\Users\\user/.ssh/id_dsa
debug2: pubkey_prepare: done
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,[email protected],ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,[email protected],[email protected]>
debug1: kex_input_ext_info: [email protected]=<0>
debug3: receive packet: type 6
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey,password,keyboard-interactive
debug3: start over, passed a different list publickey,password,keyboard-interactive
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: C:\\Users\\user/.ssh/id_rsa RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: C:\\Users\\user/.ssh/id_rsa RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug3: sign_and_send_pubkey: using [email protected] with RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug3: sign_and_send_pubkey: signing using rsa-sha2-512 SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug3: send packet: type 50
debug3: receive packet: type 52
Authenticated to localhost ([::1]:22) using "publickey".
debug1: channel 0: new [client-session]
debug3: ssh_session2_open: channel_new: 0
debug2: channel 0: send open
debug3: send packet: type 90
debug1: Requesting [email protected]
debug3: send packet: type 80
debug1: Entering interactive session.
debug1: pledge: filesystem
debug3: This windows OS supports conpty
debug1: console doesn't support the ansi parsing
debug3: receive packet: type 80
debug1: client_input_global_request: rtype [email protected] want_reply 0
debug3: client_input_hostkeys: received RSA key SHA256:Hu1w7DzyacLej3cHXFPFUoMvAAh3agbs3jwNwZK+I9w
debug3: client_input_hostkeys: received ECDSA key SHA256:G5OrfV8tuY/FNpsuFTqIvj+lPJ+RiYlD9qs0AtA+opc
debug3: client_input_hostkeys: received ED25519 key SHA256:JGBuevE21pfXU47/42SngszHxQFTi8qe13RUya8bxIM
debug1: client_input_hostkeys: searching C:\\Users\\user/.ssh/known_hosts for localhost / (none)
debug3: hostkeys_foreach: reading file "C:\\Users\\user/.ssh/known_hosts"
debug3: hostkeys_find: found ecdsa-sha2-nistp256 key at C:\\Users\\user/.ssh/known_hosts:2
debug3: hostkeys_find: found ssh-rsa key at C:\\Users\\user/.ssh/known_hosts:3
debug3: hostkeys_find: found ssh-ed25519 key at C:\\Users\\user/.ssh/known_hosts:4
debug1: client_input_hostkeys: searching C:\\Users\\user/.ssh/known_hosts2 for localhost / (none)
debug3: Failed to open file:C:/Users/user/.ssh/known_hosts2 error:2
debug1: client_input_hostkeys: hostkeys file C:\\Users\\user/.ssh/known_hosts2 does not exist
debug3: client_input_hostkeys: 3 server keys: 0 new, 3 retained, 0 incomplete match. 0 to remove
debug1: client_input_hostkeys: no new or deprecated keys from server
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: fd 3 setting TCP_NODELAY
debug2: client_session2_setup: id 0
debug2: channel 0: request pty-req confirm 1
debug3: send packet: type 98
debug2: channel 0: request shell confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: PTY allocation request accepted on channel 0
debug2: channel 0: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: shell request accepted on channel 0
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: chan_shutdown_write: channel 0: (i0 o1 sock -1 wfd 5 efd 6 [write])
debug2: channel 0: output drain -> closed
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype [email protected] reply 0
debug2: channel 0: rcvd eow
debug2: chan_shutdown_read: channel 0: (i0 o3 sock -1 wfd 4 efd 6 [write])
debug2: channel 0: input open -> closed
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug3: send packet: type 97
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/6 sock -1 cc -1 io 0x00/0x00)
debug3: send packet: type 1
Connection to localhost closed.
Transferred: sent 3712, received 3040 bytes, in 0.3 seconds
Bytes per second: sent 10789.1, received 8835.9
debug1: Exit status -2147024809
C:\Users\user\Downloads\OpenSSH-Win64>
Same SSHD version (OpenSSH-x64-v8.9.1.0.msi) on Windows 10 Professional 21H2 build 19044.1620.
Same problem, but only with the use sftp command, ssh command works fine.
sshd_logs using sftp command (sftp sftp@localhost, local user name is sftp):
8688 2022-04-01 13:29:47.232 debug2: fd 3 setting O_NONBLOCK
8688 2022-04-01 13:29:47.232 debug1: Bind to port 22 on 0.0.0.0.
8688 2022-04-01 13:29:47.232 Server listening on 0.0.0.0 port 22.
8688 2022-04-01 13:29:47.232 debug3: pselect: installing signal handler for 3, previous 00007FF78DF0C6C0
8688 2022-04-01 13:29:47.232 debug3: pselect: installing signal handler for 6, previous 00007FF78DF0C5C0
8688 2022-04-01 13:29:47.232 debug3: pselect: installing signal handler for 7, previous 00007FF78DF0C6B0
8688 2022-04-01 13:29:47.232 debug3: pselect: installing signal handler for 8, previous 00007FF78DF0C6B0
8688 2022-04-01 13:29:47.232 debug3: pselect_notify_setup: initializing
8688 2022-04-01 13:29:47.232 debug2: fd 6 setting O_NONBLOCK
8688 2022-04-01 13:29:47.232 debug2: fd 4 setting O_NONBLOCK
8688 2022-04-01 13:29:47.232 debug3: pselect_notify_setup: pid 8688 saved 8688 pipe0 6 pipe1 4
8688 2022-04-01 13:29:59.373 debug3: fd 5 is not O_NONBLOCK
8688 2022-04-01 13:29:59.373 debug3: spawning "C:\\Program Files\\OpenSSH\\sshd.exe" -R as subprocess
8688 2022-04-01 13:29:59.388 debug3: send_rexec_state: entering fd = 9 config len 2491
8688 2022-04-01 13:29:59.388 debug3: ssh_msg_send: type 0
8688 2022-04-01 13:29:59.388 debug3: send_rexec_state: done
2072 2022-04-01 13:29:59.435 debug1: inetd sockets after dupping: 4, 4
2072 2022-04-01 13:29:59.435 Connection from 127.0.0.1 port 49883 on 127.0.0.1 port 22
2072 2022-04-01 13:29:59.435 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.9
2072 2022-04-01 13:29:59.435 debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.1
2072 2022-04-01 13:29:59.435 debug1: compat_banner: match: OpenSSH_for_Windows_8.1 pat OpenSSH* compat 0x04000000
2072 2022-04-01 13:29:59.435 debug2: fd 4 setting O_NONBLOCK
2072 2022-04-01 13:29:59.466 debug3: spawning "C:\\Program Files\\OpenSSH\\sshd.exe" -y as user
2072 2022-04-01 13:29:59.466 debug2: Network child is on pid 4416
2072 2022-04-01 13:29:59.466 debug3: send_rexec_state: entering fd = 6 config len 2491
2072 2022-04-01 13:29:59.466 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.466 debug3: send_rexec_state: done
2072 2022-04-01 13:29:59.466 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.466 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.466 debug3: preauth child monitor started
2072 2022-04-01 13:29:59.513 debug1: list_hostkey_types: ssh-ed25519 [preauth]
2072 2022-04-01 13:29:59.513 debug3: send packet: type 20 [preauth]
2072 2022-04-01 13:29:59.513 debug1: SSH2_MSG_KEXINIT sent [preauth]
2072 2022-04-01 13:29:59.513 debug3: receive packet: type 20 [preauth]
2072 2022-04-01 13:29:59.513 debug1: SSH2_MSG_KEXINIT received [preauth]
2072 2022-04-01 13:29:59.513 debug2: local server KEXINIT proposal [preauth]
2072 2022-04-01 13:29:59.513 debug2: KEX algorithms: curve25519-sha256,[email protected],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]
2072 2022-04-01 13:29:59.513 debug2: host key algorithms: ssh-ed25519 [preauth]
2072 2022-04-01 13:29:59.513 debug2: ciphers ctos: [email protected],[email protected],aes256-ctr,aes192-ctr,aes128-ctr [preauth]
2072 2022-04-01 13:29:59.513 debug2: ciphers stoc: [email protected],[email protected],aes256-ctr,aes192-ctr,aes128-ctr [preauth]
2072 2022-04-01 13:29:59.513 debug2: MACs ctos: [email protected],[email protected],hmac-sha2-256 [preauth]
2072 2022-04-01 13:29:59.513 debug2: MACs stoc: [email protected],[email protected],hmac-sha2-256 [preauth]
2072 2022-04-01 13:29:59.513 debug2: compression ctos: none,[email protected] [preauth]
2072 2022-04-01 13:29:59.529 debug2: compression stoc: none,[email protected] [preauth]
2072 2022-04-01 13:29:59.529 debug2: languages ctos: [preauth]
2072 2022-04-01 13:29:59.529 debug2: languages stoc: [preauth]
2072 2022-04-01 13:29:59.529 debug2: first_kex_follows 0 [preauth]
2072 2022-04-01 13:29:59.529 debug2: reserved 0 [preauth]
2072 2022-04-01 13:29:59.529 debug2: peer client KEXINIT proposal [preauth]
2072 2022-04-01 13:29:59.529 debug2: KEX algorithms: curve25519-sha256,[email protected],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,diffie-hellman-group14-sha1,ext-info-c [preauth]
2072 2022-04-01 13:29:59.529 debug2: host key algorithms: ssh-ed25519,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,ssh-rsa [preauth]
2072 2022-04-01 13:29:59.529 debug2: ciphers ctos: [email protected],[email protected],aes256-ctr,aes192-ctr,aes128-ctr [preauth]
2072 2022-04-01 13:29:59.529 debug2: ciphers stoc: [email protected],[email protected],aes256-ctr,aes192-ctr,aes128-ctr [preauth]
2072 2022-04-01 13:29:59.529 debug2: MACs ctos: [email protected],[email protected],hmac-sha2-256 [preauth]
2072 2022-04-01 13:29:59.529 debug2: MACs stoc: [email protected],[email protected],hmac-sha2-256 [preauth]
2072 2022-04-01 13:29:59.529 debug2: compression ctos: none,[email protected],zlib [preauth]
2072 2022-04-01 13:29:59.529 debug2: compression stoc: none,[email protected],zlib [preauth]
2072 2022-04-01 13:29:59.529 debug2: languages ctos: [preauth]
2072 2022-04-01 13:29:59.529 debug2: languages stoc: [preauth]
2072 2022-04-01 13:29:59.529 debug2: first_kex_follows 0 [preauth]
2072 2022-04-01 13:29:59.529 debug2: reserved 0 [preauth]
2072 2022-04-01 13:29:59.529 debug1: kex: algorithm: curve25519-sha256 [preauth]
2072 2022-04-01 13:29:59.529 debug1: kex: host key algorithm: ssh-ed25519 [preauth]
2072 2022-04-01 13:29:59.529 debug1: kex: client->server cipher: [email protected] MAC: <implicit> compression: none [preauth]
2072 2022-04-01 13:29:59.529 debug1: kex: server->client cipher: [email protected] MAC: <implicit> compression: none [preauth]
2072 2022-04-01 13:29:59.529 debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
2072 2022-04-01 13:29:59.529 debug3: receive packet: type 30 [preauth]
2072 2022-04-01 13:29:59.529 debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
2072 2022-04-01 13:29:59.529 debug3: mm_sshkey_sign: entering [preauth]
2072 2022-04-01 13:29:59.529 debug3: mm_request_send: entering, type 6 [preauth]
2072 2022-04-01 13:29:59.529 debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
2072 2022-04-01 13:29:59.529 debug3: mm_request_receive_expect: entering, type 7 [preauth]
2072 2022-04-01 13:29:59.529 debug3: mm_request_receive: entering [preauth]
2072 2022-04-01 13:29:59.529 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.529 debug3: monitor_read: checking request 6
2072 2022-04-01 13:29:59.529 debug3: mm_answer_sign: entering
2072 2022-04-01 13:29:59.544 debug3: mm_answer_sign: ssh-ed25519 KEX signature len=83
2072 2022-04-01 13:29:59.544 debug3: mm_request_send: entering, type 7
2072 2022-04-01 13:29:59.544 debug2: monitor_read: 6 used once, disabling now
2072 2022-04-01 13:29:59.544 debug3: send packet: type 31 [preauth]
2072 2022-04-01 13:29:59.544 debug3: send packet: type 21 [preauth]
2072 2022-04-01 13:29:59.544 debug2: ssh_set_newkeys: mode 1 [preauth]
2072 2022-04-01 13:29:59.544 debug1: rekey out after 4294967296 blocks [preauth]
2072 2022-04-01 13:29:59.544 debug1: SSH2_MSG_NEWKEYS sent [preauth]
2072 2022-04-01 13:29:59.544 debug1: Sending SSH2_MSG_EXT_INFO [preauth]
2072 2022-04-01 13:29:59.544 debug3: send packet: type 7 [preauth]
2072 2022-04-01 13:29:59.544 debug1: expecting SSH2_MSG_NEWKEYS [preauth]
2072 2022-04-01 13:29:59.560 debug3: receive packet: type 21 [preauth]
2072 2022-04-01 13:29:59.560 debug1: SSH2_MSG_NEWKEYS received [preauth]
2072 2022-04-01 13:29:59.560 debug2: ssh_set_newkeys: mode 0 [preauth]
2072 2022-04-01 13:29:59.560 debug1: rekey in after 4294967296 blocks [preauth]
2072 2022-04-01 13:29:59.560 debug1: KEX done [preauth]
2072 2022-04-01 13:29:59.591 debug3: receive packet: type 5 [preauth]
2072 2022-04-01 13:29:59.591 debug3: send packet: type 6 [preauth]
2072 2022-04-01 13:29:59.607 debug3: receive packet: type 50 [preauth]
2072 2022-04-01 13:29:59.607 debug1: userauth-request for user sftp service ssh-connection method none [preauth]
2072 2022-04-01 13:29:59.607 debug1: attempt 0 failures 0 [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_getpwnamallow: entering [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_request_send: entering, type 8 [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_request_receive_expect: entering, type 9 [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_request_receive: entering [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.607 debug3: monitor_read: checking request 8
2072 2022-04-01 13:29:59.607 debug3: mm_answer_pwnamallow: entering
2072 2022-04-01 13:29:59.607 debug2: parse_server_config_depth: config reprocess config len 2491
2072 2022-04-01 13:29:59.607 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
2072 2022-04-01 13:29:59.607 debug3: mm_request_send: entering, type 9
2072 2022-04-01 13:29:59.607 debug2: monitor_read: 8 used once, disabling now
2072 2022-04-01 13:29:59.607 debug2: input_userauth_request: setting up authctxt for sftp [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_inform_authserv: entering [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_request_send: entering, type 4 [preauth]
2072 2022-04-01 13:29:59.607 debug2: input_userauth_request: try method none [preauth]
2072 2022-04-01 13:29:59.607 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
2072 2022-04-01 13:29:59.607 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 7.560ms (requested 7.560ms) [preauth]
2072 2022-04-01 13:29:59.607 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.607 debug3: monitor_read: checking request 4
2072 2022-04-01 13:29:59.607 debug3: mm_answer_authserv: service=ssh-connection, style=
2072 2022-04-01 13:29:59.607 debug2: monitor_read: 4 used once, disabling now
2072 2022-04-01 13:29:59.623 debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth]
2072 2022-04-01 13:29:59.623 debug3: send packet: type 51 [preauth]
2072 2022-04-01 13:29:59.623 debug3: receive packet: type 50 [preauth]
2072 2022-04-01 13:29:59.623 debug1: userauth-request for user sftp service ssh-connection method publickey [preauth]
2072 2022-04-01 13:29:59.623 debug1: attempt 1 failures 0 [preauth]
2072 2022-04-01 13:29:59.623 debug2: input_userauth_request: try method publickey [preauth]
2072 2022-04-01 13:29:59.623 debug2: userauth_pubkey: valid user sftp querying public key ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIB7kNeq8O1mw4gakmn9nq4pqbpM75Yvp1PjXHEeYVsqw [preauth]
2072 2022-04-01 13:29:59.623 debug1: userauth_pubkey: publickey test pkalg ssh-ed25519 pkblob ED25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU [preauth]
2072 2022-04-01 13:29:59.623 debug3: mm_key_allowed: entering [preauth]
2072 2022-04-01 13:29:59.623 debug3: mm_request_send: entering, type 22 [preauth]
2072 2022-04-01 13:29:59.623 debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
2072 2022-04-01 13:29:59.623 debug3: mm_request_receive_expect: entering, type 23 [preauth]
2072 2022-04-01 13:29:59.623 debug3: mm_request_receive: entering [preauth]
2072 2022-04-01 13:29:59.623 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.623 debug3: monitor_read: checking request 22
2072 2022-04-01 13:29:59.623 debug3: mm_answer_keyallowed: entering
2072 2022-04-01 13:29:59.623 debug3: ssh_krl_from_blob: not a KRL
2072 2022-04-01 13:29:59.623 debug1: trying public key file C:\\Users\\sftp\\.ssh/authorized_keys
2072 2022-04-01 13:29:59.623 debug1: C:\\Users\\sftp\\.ssh/authorized_keys:1: matching key found: ED25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU
2072 2022-04-01 13:29:59.623 debug1: C:\\Users\\sftp\\.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
2072 2022-04-01 13:29:59.623 Accepted key ED25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU found at C:\\Users\\sftp\\.ssh/authorized_keys:1
2072 2022-04-01 13:29:59.623 debug2: check_authkeys_file: C:\\Users\\sftp\\.ssh/authorized_keys: processed 1/2 lines
2072 2022-04-01 13:29:59.623 debug3: mm_answer_keyallowed: publickey authentication test: ED25519 key is allowed
2072 2022-04-01 13:29:59.623 debug3: mm_request_send: entering, type 23
2072 2022-04-01 13:29:59.623 debug3: send packet: type 60 [preauth]
2072 2022-04-01 13:29:59.623 debug2: userauth_pubkey: authenticated 0 pkalg ssh-ed25519 [preauth]
2072 2022-04-01 13:29:59.623 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
2072 2022-04-01 13:29:59.623 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 7.560ms (requested 7.560ms) [preauth]
2072 2022-04-01 13:29:59.638 Postponed publickey for sftp from 127.0.0.1 port 49883 ssh2 [preauth]
2072 2022-04-01 13:29:59.638 debug3: receive packet: type 50 [preauth]
2072 2022-04-01 13:29:59.638 debug1: userauth-request for user sftp service ssh-connection method publickey [preauth]
2072 2022-04-01 13:29:59.638 debug1: attempt 2 failures 0 [preauth]
2072 2022-04-01 13:29:59.638 debug2: input_userauth_request: try method publickey [preauth]
2072 2022-04-01 13:29:59.638 debug2: userauth_pubkey: valid user sftp attempting public key ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIB7kNeq8O1mw4gakmn9nq4pqbpM75Yvp1PjXHEeYVsqw [preauth]
2072 2022-04-01 13:29:59.638 debug3: userauth_pubkey: publickey have ssh-ed25519 signature for ED25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_key_allowed: entering [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_send: entering, type 22 [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_receive_expect: entering, type 23 [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_receive: entering [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.638 debug3: monitor_read: checking request 22
2072 2022-04-01 13:29:59.638 debug3: mm_answer_keyallowed: entering
2072 2022-04-01 13:29:59.638 debug3: ssh_krl_from_blob: not a KRL
2072 2022-04-01 13:29:59.638 debug1: trying public key file C:\\Users\\sftp\\.ssh/authorized_keys
2072 2022-04-01 13:29:59.638 debug1: C:\\Users\\sftp\\.ssh/authorized_keys:1: matching key found: ED25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU
2072 2022-04-01 13:29:59.638 debug1: C:\\Users\\sftp\\.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
2072 2022-04-01 13:29:59.638 Accepted key ED25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU found at C:\\Users\\sftp\\.ssh/authorized_keys:1
2072 2022-04-01 13:29:59.638 debug2: check_authkeys_file: C:\\Users\\sftp\\.ssh/authorized_keys: processed 1/2 lines
2072 2022-04-01 13:29:59.638 debug3: mm_answer_keyallowed: publickey authentication: ED25519 key is allowed
2072 2022-04-01 13:29:59.638 debug3: mm_request_send: entering, type 23
2072 2022-04-01 13:29:59.638 debug3: mm_sshkey_verify: entering [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_send: entering, type 24 [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_receive_expect: entering, type 25 [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_receive: entering [preauth]
2072 2022-04-01 13:29:59.638 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.638 debug3: monitor_read: checking request 24
2072 2022-04-01 13:29:59.654 debug3: mm_answer_keyverify: publickey ED25519 signature using ssh-ed25519 verified
2072 2022-04-01 13:29:59.654 debug1: auth_activate_options: setting new authentication options
2072 2022-04-01 13:29:59.654 debug3: mm_request_send: entering, type 25
2072 2022-04-01 13:29:59.654 Accepted publickey for sftp from 127.0.0.1 port 49883 ssh2: ED25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU
2072 2022-04-01 13:29:59.654 debug1: monitor_child_preauth: user sftp authenticated by privileged process
2072 2022-04-01 13:29:59.654 debug3: mm_get_keystate: Waiting for new keys
2072 2022-04-01 13:29:59.654 debug3: mm_request_receive_expect: entering, type 26
2072 2022-04-01 13:29:59.654 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.670 debug3: mm_get_keystate: GOT new keys
2072 2022-04-01 13:29:59.670 debug1: auth_activate_options: setting new authentication options [preauth]
2072 2022-04-01 13:29:59.670 debug2: userauth_pubkey: authenticated 1 pkalg ssh-ed25519 [preauth]
2072 2022-04-01 13:29:59.670 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
2072 2022-04-01 13:29:59.670 debug3: ensure_minimum_time_since: elapsed 15.600ms, delaying 14.638ms (requested 7.560ms) [preauth]
2072 2022-04-01 13:29:59.670 debug3: send packet: type 52 [preauth]
2072 2022-04-01 13:29:59.670 debug3: mm_request_send: entering, type 26 [preauth]
2072 2022-04-01 13:29:59.670 debug3: mm_send_keystate: Finished sending state [preauth]
2072 2022-04-01 13:29:59.670 debug1: monitor_read_log: child log fd closed
2072 2022-04-01 13:29:59.685 debug3: LsaLogonUser Succeeded (Impersonation: 1)
2072 2022-04-01 13:29:59.701 debug3: spawning "C:\\Program Files\\OpenSSH\\sshd.exe" -z as user
2072 2022-04-01 13:29:59.701 User child is on pid 6972
2072 2022-04-01 13:29:59.701 debug3: send_rexec_state: entering fd = 5 config len 2491
2072 2022-04-01 13:29:59.701 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.701 debug3: send_rexec_state: done
2072 2022-04-01 13:29:59.701 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.701 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.701 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.701 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.701 debug3: ssh_msg_send: type 0
2072 2022-04-01 13:29:59.763 debug3: monitor_recv_keystate: entering
2072 2022-04-01 13:29:59.763 debug3: ssh_msg_recv entering
2072 2022-04-01 13:29:59.763 debug3: monitor_recv_keystate: done
2072 2022-04-01 13:29:59.763 Changed root directory to "c:\\\\sftp\\\\"
2072 2022-04-01 13:29:59.763 debug3: monitor_apply_keystate: packet_set_state
2072 2022-04-01 13:29:59.763 debug2: ssh_set_newkeys: mode 0
2072 2022-04-01 13:29:59.763 debug1: rekey in after 4294967296 blocks
2072 2022-04-01 13:29:59.763 debug2: ssh_set_newkeys: mode 1
2072 2022-04-01 13:29:59.763 debug1: rekey out after 4294967296 blocks
2072 2022-04-01 13:29:59.763 debug1: ssh_packet_set_postauth: called
2072 2022-04-01 13:29:59.763 debug3: ssh_packet_set_state: done
2072 2022-04-01 13:29:59.763 debug3: monitor_recv_authopt: entering
2072 2022-04-01 13:29:59.763 debug3: ssh_msg_recv entering
2072 2022-04-01 13:29:59.763 debug3: monitor_recv_authopt: done
2072 2022-04-01 13:29:59.763 debug3: notify_hostkeys: key 0: ssh-ed25519 SHA256:BepkyLkqbRhLFjY2a2m8068Ty/Nr+b9rk5HCb7JHkOU
2072 2022-04-01 13:29:59.763 debug3: notify_hostkeys: sent 1 hostkeys
2072 2022-04-01 13:29:59.763 debug3: send packet: type 80
2072 2022-04-01 13:29:59.763 debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
2072 2022-04-01 13:29:59.763 debug1: Entering interactive session for SSH2.
2072 2022-04-01 13:29:59.763 debug1: server_init_dispatch
2072 2022-04-01 13:29:59.763 debug3: pselect: installing signal handler for 3, previous 00007FF78DF05070
2072 2022-04-01 13:29:59.763 debug3: pselect_notify_setup: initializing
2072 2022-04-01 13:29:59.763 debug2: fd 10 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug2: fd 8 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug3: pselect_notify_setup: pid 6972 saved 6972 pipe0 10 pipe1 8
2072 2022-04-01 13:29:59.763 debug3: receive packet: type 90
2072 2022-04-01 13:29:59.763 debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
2072 2022-04-01 13:29:59.763 debug1: input_session_request
2072 2022-04-01 13:29:59.763 debug1: channel 0: new [server-session]
2072 2022-04-01 13:29:59.763 debug2: session_new: allocate (allocated 0 max 10)
2072 2022-04-01 13:29:59.763 debug3: session_unused: session id 0 unused
2072 2022-04-01 13:29:59.763 debug1: session_new: session 0
2072 2022-04-01 13:29:59.763 debug1: session_open: channel 0
2072 2022-04-01 13:29:59.763 debug1: session_open: session 0: link with channel 0
2072 2022-04-01 13:29:59.763 debug1: server_input_channel_open: confirm session
2072 2022-04-01 13:29:59.763 debug3: send packet: type 91
2072 2022-04-01 13:29:59.763 debug3: receive packet: type 80
2072 2022-04-01 13:29:59.763 debug1: server_input_global_request: rtype [email protected] want_reply 0
2072 2022-04-01 13:29:59.763 debug3: receive packet: type 98
2072 2022-04-01 13:29:59.763 debug1: server_input_channel_req: channel 0 request subsystem reply 1
2072 2022-04-01 13:29:59.763 debug1: session_by_channel: session 0 channel 0
2072 2022-04-01 13:29:59.763 debug1: session_input_channel_req: session 0 req subsystem
2072 2022-04-01 13:29:59.763 debug2: subsystem request for sftp by user sftp
2072 2022-04-01 13:29:59.763 debug1: subsystem: internal-sftp
2072 2022-04-01 13:29:59.763 Starting session: forced-command (config) 'internal-sftp' for sftp from 127.0.0.1 port 49883 id 0
2072 2022-04-01 13:29:59.763 debug2: fd 9 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug2: fd 11 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug2: fd 12 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug2: fd 13 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug2: fd 14 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug2: fd 15 setting O_NONBLOCK
2072 2022-04-01 13:29:59.763 debug3: shell: "c:\\\\windows\\\\system32\\\\cmd.exe"
2072 2022-04-01 13:29:59.763 debug3: shell_option: /c
2072 2022-04-01 13:29:59.763 debug3: exec_command: sftp-server.exe
2072 2022-04-01 13:29:59.763 debug3: arg escape option: TRUE
2072 2022-04-01 13:29:59.763 debug3: spawn_argv[0]: "c:\\\\windows\\\\system32\\\\cmd.exe" /c "sftp-server.exe"
2072 2022-04-01 13:29:59.763 debug3: spawning "c:\\\\windows\\\\system32\\\\cmd.exe" /c "sftp-server.exe" as subprocess
2072 2022-04-01 13:29:59.779 debug2: fd 5 setting TCP_NODELAY
2072 2022-04-01 13:29:59.779 debug3: fd 12 is O_NONBLOCK
2072 2022-04-01 13:29:59.779 debug3: fd 11 is O_NONBLOCK
2072 2022-04-01 13:29:59.779 debug3: fd 14 is O_NONBLOCK
2072 2022-04-01 13:29:59.779 debug3: send packet: type 99
2072 2022-04-01 13:29:59.904 debug2: channel 0: read 12884902019 from efd 14
2072 2022-04-01 13:29:59.904 debug3: channel 0: discard efd
2072 2022-04-01 13:29:59.904 debug2: channel 0: read failed rfd 12 maxlen 32768: Broken pipe
2072 2022-04-01 13:29:59.904 debug2: channel 0: read failed
2072 2022-04-01 13:29:59.904 debug2: chan_shutdown_read: channel 0: (i0 o0 sock -1 wfd 12 efd 14 [ignore])
2072 2022-04-01 13:29:59.904 debug2: channel 0: input open -> drain
2072 2022-04-01 13:29:59.904 debug2: channel 0: read 12884901888 from efd 14
2072 2022-04-01 13:29:59.904 debug2: channel 0: closing read-efd 14
2072 2022-04-01 13:29:59.904 debug2: channel 0: ibuf empty
2072 2022-04-01 13:29:59.904 debug2: channel 0: send eof
2072 2022-04-01 13:29:59.904 debug3: send packet: type 96
2072 2022-04-01 13:29:59.904 debug2: channel 0: input drain -> closed
2072 2022-04-01 13:29:59.904 debug2: pselect_notify_done: reading
2072 2022-04-01 13:29:59.904 debug1: Received SIGCHLD.
2072 2022-04-01 13:29:59.904 debug1: session_by_pid: pid 3704
2072 2022-04-01 13:29:59.904 debug1: session_exit_message: session 0 channel 0 pid 3704
2072 2022-04-01 13:29:59.904 debug2: channel 0: request exit-status confirm 0
2072 2022-04-01 13:29:59.904 debug3: send packet: type 98
2072 2022-04-01 13:29:59.904 debug1: session_exit_message: release channel 0
2072 2022-04-01 13:29:59.904 debug2: channel 0: write failed
2072 2022-04-01 13:29:59.904 debug2: chan_shutdown_write: channel 0: (i3 o0 sock -1 wfd 11 efd -1 [closed])
2072 2022-04-01 13:29:59.904 debug2: channel 0: send eow
2072 2022-04-01 13:29:59.904 debug3: send packet: type 98
2072 2022-04-01 13:29:59.904 debug2: channel 0: output open -> closed
2072 2022-04-01 13:29:59.904 debug2: channel 0: send close
2072 2022-04-01 13:29:59.904 debug3: send packet: type 97
2072 2022-04-01 13:29:59.904 debug3: channel 0: will not send data after close
2072 2022-04-01 13:29:59.904 debug3: receive packet: type 97
2072 2022-04-01 13:29:59.904 debug2: channel 0: rcvd close
2072 2022-04-01 13:29:59.904 debug3: channel 0: will not send data after close
2072 2022-04-01 13:29:59.904 debug2: channel 0: is dead
2072 2022-04-01 13:29:59.904 debug2: channel 0: gc: notify user
2072 2022-04-01 13:29:59.904 debug1: session_by_channel: session 0 channel 0
2072 2022-04-01 13:29:59.904 debug1: session_close_by_channel: channel 0 child 0
2072 2022-04-01 13:29:59.904 Close session: user sftp from 127.0.0.1 port 49883 id 0
2072 2022-04-01 13:29:59.904 debug3: session_unused: session id 0 unused
2072 2022-04-01 13:29:59.904 debug2: channel 0: gc: user detached
2072 2022-04-01 13:29:59.904 debug2: channel 0: is dead
2072 2022-04-01 13:29:59.904 debug2: channel 0: garbage collecting
2072 2022-04-01 13:29:59.904 debug1: channel 0: free: server-session, nchannels 1
2072 2022-04-01 13:29:59.904 debug3: channel 0: status: The following connections are open:\\r\\n #0 server-session (t4 r0 i3/0 o3/0 e[closed]/0 fd -1/-1/-1 sock -1 cc -1 io 0x00/0x00)\\r\\n
2072 2022-04-01 13:29:59.904 debug3: WSARecv - WSARecv() ERROR: io:0000017C128ABAD0 10054
2072 2022-04-01 13:29:59.904 debug3: recv - from CB ERROR:108, io:0000017C128ABAD0
2072 2022-04-01 13:29:59.904 Read error from remote host 127.0.0.1 port 49883: Unknown error
2072 2022-04-01 13:29:59.904 debug1: do_cleanup
2072 2022-04-01 13:29:59.920 debug3: mm_request_receive: entering
2072 2022-04-01 13:29:59.920 debug1: do_cleanup
8688 2022-04-01 13:29:59.951 debug2: pselect_notify_done: reading
sftp client do not have a verbose option (-vvv) like ssh does. So I don't have any client logs to provide.
Here is my sshd_config:
# This is the sshd server system-wide configuration file. See
# sshd_config(5) for more information.
##### GENERAL #####
# IPv4 only
AddressFamily inet
# Listening IP address
ListenAddress 0.0.0.0
# Listening port, should be change (<1024) if the system is connected to unsecure network
Port 22
# Resolve host names, that can be used in authorized_keys file
UseDNS no
##### AUTHENTICATION TYPE #####
# Disallow password authentication
PasswordAuthentication yes
# Allow public key authentication
PubkeyAuthentication yes
##### KEYS, CIPHER AND MAC #####
# List of available key algorithms provided by the ssh server (server-side offer)
HostKeyAlgorithms ssh-ed25519
# List of available key algorithms accepted by the server (client-side offer)
PubkeyAcceptedKeyTypes ssh-ed25519,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,ssh-rsa
# Private Key used for authentication
HostKey __PROGRAMDATA__/ssh/ssh_host_ed25519_key
# List of allowed public key owner to connect
AuthorizedKeysFile .ssh/authorized_keys
# Key revocation list
RevokedKeys __PROGRAMDATA__/ssh/revoked_keys
# List of supported symmetric ciphers to bring in negotiation
# Used to cipher the flow
Ciphers [email protected],[email protected],aes256-ctr,aes192-ctr,aes128-ctr
# List of supported MAC (Message Authentication Code) to bring in negotiation
# Used to check the integrity of each message
# ETM (Encrypt-Then-MAC) is the a newer and more secure version of MAC, but is only supported by OpenSSH 6.3+
MACs [email protected],[email protected],hmac-sha2-256
##### ADDITIONAL CHECKS #####
# Number of connection attempts before refusing any more connection try
MaxAuthTries 3
# Time given (in seconds) to enter the client key passphrase (if any)
LoginGraceTime 30
# Ciphers and keying
RekeyLimit default none
# Override default of no subsystems
Subsystem sftp internal-sftp
##### RESTRICTIONS #####
# Disallow connection empty password account
PermitEmptyPasswords no
# Disallow TCP forwarding that could lead to bouncing attack
AllowTcpForwarding no
# Restrict SFTP subsystem to the following drive/directory
ChrootDirectory c:\sftp\
# Force the use of SFTP subsystem, disabling the standard SSH program
ForceCommand internal-sftp
##### INFORMATION DISPLAY #####
# Disable message of the day
PrintMotd no
# Logging type
SyslogFacility LOCAL0
# Logging level
LogLevel DEBUG3
##### PATTERNS #####
# List of users allowed to connect
AllowUsers sftp
@Stormrice, do you have the win32-openssh folder path in the SYSTEM PATH environment variable. If yes, can you share the sftp-server.log.
@janleskovec - There is no clue in the ssh client, ssh server logs on why the connection is closed. Can you remove the default shell as powershell and try the scenario again?
@janleskovec - Can you check if the issue can be reproduced with older win32-openssh versions may be V8.6?
@janleskovec - There is no clue in the ssh client, ssh server logs on why the connection is closed. Can you remove the default shell as powershell and try the scenario again?
@janleskovec - Can you check if the issue can be reproduced with older win32-openssh versions may be V8.6?
I also tried the 32 bit version, but it does the same. Could it be connected to the users being office365 users? I mean I doubt it as auth seems to succeed, but still...
PS C:\OpenSSH-Win64> psexec -s c:\openssh-win64\sshd.exe -ddd
PsExec v2.34 - Execute processes remotely
Copyright (C) 2001-2021 Mark Russinovich
Sysinternals - www.sysinternals.com
debug2: load_server_config: filename __PROGRAMDATA__\\ssh/sshd_config
debug3: w32_fstat ERROR: bad fd: 3
debug2: load_server_config: done config len = 292
debug2: parse_server_config_depth: config __PROGRAMDATA__\\ssh/sshd_config len 292
debug3: __PROGRAMDATA__\\ssh/sshd_config:9 setting SyslogFacility LOCAL0
debug3: __PROGRAMDATA__\\ssh/sshd_config:10 setting LogLevel DEBUG3
debug3: __PROGRAMDATA__\\ssh/sshd_config:41 setting AuthorizedKeysFile .ssh/authorized_keys
debug3: __PROGRAMDATA__\\ssh/sshd_config:82 setting Subsystem sftp sftp-server.exe
debug3: checking syntax for 'Match Group administrators'
debug1: sshd version OpenSSH_for_Windows_8.6, LibreSSL 3.3.3
debug1: get_passwd: lookup_sid() failed: 1332.
debug1: private host key #0: ssh-rsa SHA256:Hu1w7DzyacLej3cHXFPFUoMvAAh3agbs3jwNwZK+I9w
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:G5OrfV8tuY/FNpsuFTqIvj+lPJ+RiYlD9qs0AtA+opc
debug1: private host key #2: ssh-ed25519 SHA256:JGBuevE21pfXU47/42SngszHxQFTi8qe13RUya8bxIM
debug1: rexec_argv[0]='c:\\openssh-win64\\sshd.exe'
debug1: rexec_argv[1]='-ddd'
debug2: fd 3 setting O_NONBLOCK
debug3: sock_set_v6only: set socket 3 IPV6_V6ONLY
debug1: Bind to port 22 on ::.
Server listening on :: port 22.
debug2: fd 4 setting O_NONBLOCK
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug3: fd 5 is not O_NONBLOCK
debug1: Server will not fork when running in debugging mode.
debug3: send_rexec_state: entering fd = 8 config len 292
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
Connection from ::1 port 52965 on ::1 port 22
debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.6
debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_7.7
debug1: compat_banner: match: OpenSSH_for_Windows_7.7 pat OpenSSH* compat 0x04000000
debug2: fd 5 setting O_NONBLOCK
debug3: spawning "c:\\openssh-win64\\sshd.exe" -ddd -y as user
debug2: Network child is on pid 12856
debug3: send_rexec_state: entering fd = 4 config len 292
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: preauth child monitor started
debug3: recv_rexec_state: entering fd = 3
debug3: ssh_msg_recv entering
debug3: recv_rexec_state: done
debug2: parse_server_config_depth: config __PROGRAMDATA__\\ssh/sshd_config len 292
debug3: __PROGRAMDATA__\\ssh/sshd_config:9 setting SyslogFacility LOCAL0
debug3: __PROGRAMDATA__\\ssh/sshd_config:10 setting LogLevel DEBUG3
debug3: __PROGRAMDATA__\\ssh/sshd_config:41 setting AuthorizedKeysFile .ssh/authorized_keys
debug3: __PROGRAMDATA__\\ssh/sshd_config:82 setting Subsystem sftp sftp-server.exe
debug3: checking syntax for 'Match Group administrators'
debug1: sshd version OpenSSH_for_Windows_8.6, LibreSSL 3.3.3
debug1: get_passwd: lookup_sid() failed: 1332.
debug3: recv_hostkeys_state: entering fd = 3
debug3: ssh_msg_recv entering
debug3: recv_hostkeys_state: done
debug3: recv_idexch_state: entering fd = 3
debug3: ssh_msg_recv entering
debug3: recv_idexch_state: done
debug2: fd 5 setting O_NONBLOCK
debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug3: send packet: type 20 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug3: receive packet: type 20 [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug2: local server KEXINIT proposal [preauth]
debug2: KEX algorithms: curve25519-sha256,[email protected],ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-n
istp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-
group14-sha256 [preauth]
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],aes256-gcm@o
penssh.com [preauth]
debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],aes256-gcm@o
penssh.com [preauth]
debug2: MACs ctos: [email protected],[email protected],[email protected],hmac-sha2-512-etm@open
ssh.com,[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preaut
h]
debug2: MACs stoc: [email protected],[email protected],[email protected],hmac-sha2-512-etm@open
ssh.com,[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preaut
h]
debug2: compression ctos: none,[email protected] [preauth]
debug2: compression stoc: none,[email protected] [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: curve25519-sha256,[email protected],ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-n
istp521,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,ext-info-c [preauth]
debug2: host key algorithms: [email protected],[email protected],ecdsa-sha
[email protected],[email protected],[email protected],ecdsa-sha2-nistp256,ecdsa-
sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],aes256-gcm@o
penssh.com [preauth]
debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],aes256-gcm@o
penssh.com [preauth]
debug2: MACs ctos: [email protected],[email protected],[email protected],hmac-sha2-512-etm@open
ssh.com,[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preaut
h]
debug2: MACs stoc: [email protected],[email protected],[email protected],hmac-sha2-512-etm@open
ssh.com,[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preaut
h]
debug2: compression ctos: none [preauth]
debug2: compression stoc: none [preauth]
debug2: languages ctos: [preauth]
debug2: languages stoc: [preauth]
debug2: first_kex_follows 0 [preauth]
debug2: reserved 0 [preauth]
debug1: kex: algorithm: curve25519-sha256 [preauth]
debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
debug1: kex: client->server cipher: [email protected] MAC: <implicit> compression: none [preauth]
debug1: kex: server->client cipher: [email protected] MAC: <implicit> compression: none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug3: receive packet: type 30 [preauth]
debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
debug3: mm_sshkey_sign: entering [preauth]
debug3: mm_request_send: entering, type 6 [preauth]
debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
debug3: mm_request_receive_expect: entering, type 7 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 6
debug3: mm_answer_sign: entering
debug3: mm_answer_sign: KEX signature 00000259D909A8A0(100)
debug3: mm_request_send: entering, type 7
debug2: monitor_read: 6 used once, disabling now
debug3: send packet: type 31 [preauth]
debug3: send packet: type 21 [preauth]
debug2: set_newkeys: mode 1 [preauth]
debug1: rekey out after 134217728 blocks [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: Sending SSH2_MSG_EXT_INFO [preauth]
debug3: send packet: type 7 [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug3: receive packet: type 21 [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug2: set_newkeys: mode 0 [preauth]
debug1: rekey in after 134217728 blocks [preauth]
debug1: KEX done [preauth]
debug3: receive packet: type 5 [preauth]
debug3: send packet: type 6 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user domain\\\\user service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug3: mm_getpwnamallow: entering [preauth]
debug3: mm_request_send: entering, type 8 [preauth]
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
debug3: mm_request_receive_expect: entering, type 9 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 8
debug3: mm_answer_pwnamallow: entering
debug2: parse_server_config_depth: config reprocess config len 292
debug3: checking match for 'Group administrators' user domain\\user host ::1 addr ::1 laddr ::1 lport 22
debug3: lookup_principal_name: Successfully discovered explicit principal name: 'domain\\user'=>'[email protected]'
debug3: LsaLogonUser Succeeded (Impersonation: 0)
debug1: user domain\\user matched group list administrators at line 90
debug3: match found
debug3: reprocess config:91 setting AuthorizedKeysFile __PROGRAMDATA__/ssh/administrators_authorized_keys
debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
debug3: mm_request_send: entering, type 9
debug2: monitor_read: 8 used once, disabling now
debug2: input_userauth_request: setting up authctxt for domain\\\\user [preauth]
debug3: mm_inform_authserv: entering [preauth]
debug3: mm_request_send: entering, type 4 [preauth]
debug2: input_userauth_request: try method none [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 46.841ms, delaying 39.154ms (requested 5.375ms) [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 4
debug3: mm_answer_authserv: service=ssh-connection, style=
debug2: monitor_read: 4 used once, disabling now
debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth]
debug3: send packet: type 51 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user domain\\\\user 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 domain\\\\user querying public key rsa-sha2-512 <pubkey> [preauth]
debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E [preauth]
debug3: mm_key_allowed: entering [preauth]
debug3: mm_request_send: entering, type 22 [preauth]
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
debug3: mm_request_receive_expect: entering, type 23 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 22
debug3: mm_answer_keyallowed: entering
debug3: mm_answer_keyallowed: key_from_blob: 00000259D909BF10
debug1: trying public key file __PROGRAMDATA__/ssh/administrators_authorized_keys
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: matching key found: RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5
NmnQDDSEggUboU8E
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc
x11-forwarding
Accepted key RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E found at __PROGRAMDATA__/ssh/administrators_authoriz
ed_keys:1
debug3: mm_answer_keyallowed: publickey authentication test: RSA key is allowed
debug3: mm_request_send: entering, type 23
debug3: send packet: type 60 [preauth]
debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 5.375ms (requested 5.375ms) [preauth]
Postponed publickey for domain\\\\user from ::1 port 52965 ssh2 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user domain\\\\user service ssh-connection method publickey [preauth]
debug1: attempt 2 failures 0 [preauth]
debug2: input_userauth_request: try method publickey [preauth]
debug2: userauth_pubkey: valid user domain\\\\user attempting public key <pubkey> [preauth]
debug3: userauth_pubkey: have rsa-sha2-512 signature for RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E [preauth]
debug3: mm_key_allowed: entering [preauth]
debug3: mm_request_send: entering, type 22 [preauth]
debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
debug3: mm_request_receive_expect: entering, type 23 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 22
debug3: mm_answer_keyallowed: entering
debug3: mm_answer_keyallowed: key_from_blob: 00000259D909BF10
debug1: trying public key file __PROGRAMDATA__/ssh/administrators_authorized_keys
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: matching key found: RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5
NmnQDDSEggUboU8E
debug1: __PROGRAMDATA__/ssh/administrators_authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc
x11-forwarding
Accepted key RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E found at __PROGRAMDATA__/ssh/administrators_authoriz
ed_keys:1
debug3: mm_answer_keyallowed: publickey authentication: RSA key is allowed
debug3: mm_request_send: entering, type 23
debug3: mm_sshkey_verify: entering [preauth]
debug3: mm_request_send: entering, type 24 [preauth]
debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
debug3: mm_request_receive_expect: entering, type 25 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 24
debug3: mm_answer_keyverify: publickey 00000259D909C330 signature verified
debug1: auth_activate_options: setting new authentication options
debug3: mm_request_send: entering, type 25
Accepted publickey for domain\\user from ::1 port 52965 ssh2: RSA SHA256:98TEqbx6/3wXGGToGBv1NAjf5O5NmnQDDSEggUboU8E
debug1: monitor_child_preauth: user domain\\user authenticated by privileged process
debug3: mm_get_keystate: Waiting for new keys
debug3: mm_request_receive_expect: entering, type 26
debug3: mm_request_receive: entering
debug3: mm_get_keystate: GOT new keys
debug1: auth_activate_options: setting new authentication options [preauth]
debug2: userauth_pubkey: authenticated 1 pkalg rsa-sha2-512 [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 9.507ms, delaying 1.242ms (requested 5.375ms) [preauth]
debug3: send packet: type 52 [preauth]
debug3: mm_request_send: entering, type 26 [preauth]
debug3: mm_send_keystate: Finished sending state [preauth]
debug3: ReadFileEx() ERROR:109, io:00000259D90758C0
debug3: read - no more data, io:00000259D90758C0
debug1: monitor_read_log: child log fd closed
debug3: lookup_principal_name: Successfully discovered explicit principal name: 'domain\\user'=>'[email protected]'
debug3: LsaLogonUser Succeeded (Impersonation: 1)
debug3: spawning "c:\\openssh-win64\\sshd.exe" -ddd -z as user
User child is on pid 11980
debug3: send_rexec_state: entering fd = 6 config len 292
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: ssh_msg_send: type 0
debug3: recv_rexec_state: entering fd = 3
debug3: ssh_msg_recv entering
debug3: recv_rexec_state: done
debug2: parse_server_config_depth: config __PROGRAMDATA__\\ssh/sshd_config len 292
debug3: __PROGRAMDATA__\\ssh/sshd_config:9 setting SyslogFacility LOCAL0
debug3: __PROGRAMDATA__\\ssh/sshd_config:10 setting LogLevel DEBUG3
debug3: __PROGRAMDATA__\\ssh/sshd_config:41 setting AuthorizedKeysFile .ssh/authorized_keys
debug3: __PROGRAMDATA__\\ssh/sshd_config:82 setting Subsystem sftp sftp-server.exe
debug3: checking syntax for 'Match Group administrators'
debug1: sshd version OpenSSH_for_Windows_8.6, LibreSSL 3.3.3
debug1: get_passwd: lookup_sid() failed: 1332.
debug3: recv_hostkeys_state: entering fd = 3
debug3: ssh_msg_recv entering
debug3: recv_hostkeys_state: done
debug3: recv_idexch_state: entering fd = 3
debug3: ssh_msg_recv entering
debug3: recv_idexch_state: done
debug2: fd 4 setting O_NONBLOCK
debug3: recv_autxctx_state: entering fd = 3
debug3: ssh_msg_recv entering
debug3: recv_autxctx_state: done
debug2: parse_server_config_depth: config reprocess config len 292
debug3: checking match for 'Group administrators' user domain\\user host ::1 addr ::1 laddr ::1 lport 22
debug3: get_user_token - i am running as domain\\user, returning process token
debug1: user domain\\user matched group list administrators at line 90
debug3: match found
debug3: reprocess config:91 setting AuthorizedKeysFile __PROGRAMDATA__/ssh/administrators_authorized_keys
debug3: monitor_recv_keystate: entering
debug3: ssh_msg_recv entering
debug3: monitor_recv_keystate: done
debug3: monitor_apply_keystate: packet_set_state
debug2: set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug2: set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: ssh_packet_set_postauth: called
debug3: ssh_packet_set_state: done
debug3: monitor_recv_authopt: entering
debug3: ssh_msg_recv entering
debug3: monitor_recv_authopt: done
debug3: notify_hostkeys: key 0: ssh-rsa SHA256:Hu1w7DzyacLej3cHXFPFUoMvAAh3agbs3jwNwZK+I9w
debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:G5OrfV8tuY/FNpsuFTqIvj+lPJ+RiYlD9qs0AtA+opc
debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:JGBuevE21pfXU47/42SngszHxQFTi8qe13RUya8bxIM
debug3: notify_hostkeys: sent 3 hostkeys
debug3: send packet: type 80
debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Entering interactive session for SSH2.
debug2: fd 7 setting O_NONBLOCK
debug2: fd 8 setting O_NONBLOCK
debug1: server_init_dispatch
debug3: receive packet: type 90
debug1: server_input_channel_open: ctype session rchan 0 win 1048576 max 16384
debug1: input_session_request
debug1: channel 0: new [server-session]
debug2: session_new: allocate (allocated 0 max 10)
debug3: session_unused: session id 0 unused
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
debug3: send packet: type 91
debug3: receive packet: type 80
debug1: server_input_global_request: rtype [email protected] want_reply 0
debug3: receive packet: type 98
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.
debug3: fd 9 is not O_NONBLOCK
debug3: fd 10 is not O_NONBLOCK
debug1: session_pty_req: session 0 alloc windows-pty
debug3: send packet: type 99
debug3: receive packet: type 98
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 windows-pty for domain\\user from ::1 port 52965 id 0
debug2: fd 11 setting O_NONBLOCK
debug2: fd 12 setting O_NONBLOCK
debug2: fd 13 setting O_NONBLOCK
debug2: fd 14 setting O_NONBLOCK
debug2: fd 15 setting O_NONBLOCK
debug2: fd 16 setting O_NONBLOCK
debug3: shell: "c:\\windows\\system32\\cmd.exe"
debug3: shell_option: /c
debug3: This windows OS supports conpty
debug3: pty commandline: C:\\Windows\\system32\\conhost.exe --headless --width 120 --height 30 --signal 0x2a0 -- "c:\\wi
ndows\\system32\\cmd.exe"
debug2: fd 4 setting TCP_NODELAY
debug2: channel 0: rfd 13 isatty
debug3: fd 13 is O_NONBLOCK
debug3: fd 12 is O_NONBLOCK
debug3: send packet: type 99
debug2: channel 0: read<=0 rfd 13 len 0
debug2: channel 0: read failed
debug2: chan_shutdown_read: channel 0: (i0 o0 sock -1 wfd 13 efd -1 [closed])
debug2: channel 0: input open -> drain
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug2: notify_done: reading
debug1: Received SIGCHLD.
debug1: session_by_pid: pid 13688
debug1: session_exit_message: session 0 channel 0 pid 13688
debug2: channel 0: request exit-status confirm 0
debug3: send packet: type 98
debug1: session_exit_message: release channel 0
debug2: channel 0: write failed
debug2: chan_shutdown_write: channel 0: (i3 o0 sock -1 wfd 12 efd -1 [closed])
debug2: channel 0: send eow
debug3: send packet: type 98
debug2: channel 0: output open -> closed
debug2: channel 0: send close
debug3: send packet: type 97
debug3: channel 0: will not send data after close
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: is dead
debug2: channel 0: gc: notify user
debug1: session_by_channel: session 0 channel 0
debug1: session_close_by_channel: channel 0 child 0
Close session: user domain\\user from ::1 port 52965 id 0
debug3: session_unused: session id 0 unused
debug2: channel 0: gc: user detached
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: server-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 server-session (t4 r0 i3/0 o3/0 e[closed]/0 fd -1/-1/-1 sock -1 cc -1)
debug3: receive packet: type 1
Received disconnect from ::1 port 52965:11: disconnected by user
Disconnected from ::1 port 52965
debug1: do_cleanup
debug3: mm_request_receive: entering
debug1: do_cleanup
c:\openssh-win64\sshd.exe exited on <HOSTNAME> with error code 255.
Tried version 7.7 and it works!
https://github.com/PowerShell/Win32-OpenSSH/releases/download/v7.7.0.0p1-Beta/OpenSSH-Win64.zip
v7.7 will probbably be fine for me but the question remains why are the newer versions not working
Could it be something with conhost? I see this line is different in sshd 7.7:
debug1: Executing command: "c:\\openssh-win64\\ssh-shellhost.exe" "C:\\Windows\\System32\\cmd.exe"
@Stormrice, do you have the win32-openssh folder path in the SYSTEM PATH environment variable. If yes, can you share the sftp-server.log.
C:\Windows\System32\OpenSSH is already in the System Path folder.
However, I cannot find a file named sftp-server.log, the only one is C:\ProgramData\ssh\logs\sshd.log that I already posted in my previous comment.
Thanks
@Stormrice , @janleskovec , for sftp-server.log please follow,
-
Add the below configuration to $env:programdata\ssh\sshd_config file
ForceCommand internal-sftp -f LOCAL0 -l DEBUG3 -
restart the ssh service.
net stop sshd net start sshd
To debug this issue, we need to see the sftp-server.log and sftp-client log (sftp user@ip -vvv). There is no error in the ssh client, ssh server logs.
Ok so, I mistaken, C:\Windows\System32\OpenSSH was already is the System path variable, but this folder is the one related to OpenSSH client shipped with Microsoft by default (old version).
The actual path of the Github version (lastest) is C:\Program Files\OpenSSH, and was not is the System path variable.
After, adding it, It resolved the problem, and I can finally log in with SFTP.
Maybe, the problem was sftp.exe from the old version is incompatible with the sftp server from the new version ?
Also, adding -f LOCAL0 -l DEBUG3 to "ForceCommand internal-sftp" did not create the sftp-server.log. The only way to create that file is to start sftp-server.exe manually in a cmd prompt.
Tried version 7.7 and it works!
https://github.com/PowerShell/Win32-OpenSSH/releases/download/v7.7.0.0p1-Beta/OpenSSH-Win64.zip
v7.7 will probbably be fine for me but the question remains why are the newer versions not working
Could it be something with conhost? I see this line is different in sshd 7.7:
debug1: Executing command: "c:\\openssh-win64\\ssh-shellhost.exe" "C:\\Windows\\System32\\cmd.exe"
Ran into the same problem today, scratching my head for hours until I found this thread. Thank you for saying v7.7 works, it indeed does, and I also like to know why it is broken in the latest version.
Ok so, I mistaken, C:\Windows\System32\OpenSSH was already is the System path variable, but this folder is the one related to OpenSSH client shipped with Microsoft by default (old version).
The actual path of the Github version (lastest) is C:\Program Files\OpenSSH, and was not is the System path variable.
After, adding it, It resolved the problem, and I can finally log in with SFTP.
Maybe, the problem was sftp.exe from the old version is incompatible with the sftp server from the new version ?
Also, adding -f LOCAL0 -l DEBUG3 to "ForceCommand internal-sftp" did not create the sftp-server.log. The only way to create that file is to start sftp-server.exe manually in a cmd prompt.
Thanks so much...as soon as I added C:\Program Files\OpenSSH to the system path variable sftp was working
I have same issue with OpenSSH 7.7, the connection drop after authentication success i tried from different clients and same issue
Server Log:
6584 2022-10-30 10:48:05.741 debug3: fd 5 is not O_NONBLOCK
6584 2022-10-30 10:48:05.741 debug3: spawning "C:\Program Files\OpenSSH-Win64\sshd.exe" "-R"
6584 2022-10-30 10:48:05.756 debug3: send_rexec_state: entering fd = 8 config len 167
6584 2022-10-30 10:48:05.756 debug3: ssh_msg_send: type 0
6584 2022-10-30 10:48:05.756 debug3: send_rexec_state: done
7340 2022-10-30 10:48:05.913 debug1: inetd sockets after dupping: 3, 3
7340 2022-10-30 10:48:05.913 Connection from 172.19.213.250 port 51018 on 10.90.15.3 port 22
7340 2022-10-30 10:48:05.913 debug1: Client protocol version 2.0; client software version OpenSSH_8.6
7340 2022-10-30 10:48:05.913 debug1: match: OpenSSH_8.6 pat OpenSSH* compat 0x04000000
7340 2022-10-30 10:48:05.913 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_7.7
7340 2022-10-30 10:48:05.913 debug2: fd 3 setting O_NONBLOCK
7340 2022-10-30 10:48:05.960 debug3: spawning "C:\Program Files\OpenSSH-Win64\sshd.exe" "-y"
7340 2022-10-30 10:48:05.975 debug2: Network child is on pid 8868
7340 2022-10-30 10:48:05.975 debug3: send_rexec_state: entering fd = 6 config len 167
7340 2022-10-30 10:48:05.975 debug3: ssh_msg_send: type 0
7340 2022-10-30 10:48:05.975 debug3: send_rexec_state: done
7340 2022-10-30 10:48:05.975 debug3: ssh_msg_send: type 0
7340 2022-10-30 10:48:05.975 debug3: ssh_msg_send: type 0
7340 2022-10-30 10:48:05.975 debug3: preauth child monitor started
7340 2022-10-30 10:48:06.038 debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
7340 2022-10-30 10:48:06.038 debug3: send packet: type 20 [preauth]
7340 2022-10-30 10:48:06.038 debug1: SSH2_MSG_KEXINIT sent [preauth]
7340 2022-10-30 10:48:06.038 debug3: receive packet: type 20 [preauth]
7340 2022-10-30 10:48:06.038 debug1: SSH2_MSG_KEXINIT received [preauth]
7340 2022-10-30 10:48:06.038 debug2: local server KEXINIT proposal [preauth]
7340 2022-10-30 10:48:06.038 debug2: KEX algorithms: curve25519-sha256,[email protected],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,diffie-hellman-group14-sha1 [preauth]
7340 2022-10-30 10:48:06.038 debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
7340 2022-10-30 10:48:06.038 debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
7340 2022-10-30 10:48:06.038 debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
7340 2022-10-30 10:48:06.038 debug2: MACs ctos: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
7340 2022-10-30 10:48:06.038 debug2: MACs stoc: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
7340 2022-10-30 10:48:06.038 debug2: compression ctos: none [preauth]
7340 2022-10-30 10:48:06.038 debug2: compression stoc: none [preauth]
7340 2022-10-30 10:48:06.038 debug2: languages ctos: [preauth]
7340 2022-10-30 10:48:06.038 debug2: languages stoc: [preauth]
7340 2022-10-30 10:48:06.038 debug2: first_kex_follows 0 [preauth]
7340 2022-10-30 10:48:06.038 debug2: reserved 0 [preauth]
7340 2022-10-30 10:48:06.038 debug2: peer client KEXINIT proposal [preauth]
7340 2022-10-30 10:48:06.038 debug2: KEX algorithms: curve25519-sha256,[email protected],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,ext-info-c [preauth]
7340 2022-10-30 10:48:06.038 debug2: host key algorithms: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,[email protected],[email protected],rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
7340 2022-10-30 10:48:06.038 debug2: ciphers ctos: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
7340 2022-10-30 10:48:06.038 debug2: ciphers stoc: [email protected],aes128-ctr,aes192-ctr,aes256-ctr,[email protected],[email protected] [preauth]
7340 2022-10-30 10:48:06.038 debug2: MACs ctos: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
7340 2022-10-30 10:48:06.038 debug2: MACs stoc: [email protected],[email protected],[email protected],[email protected],[email protected],[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
7340 2022-10-30 10:48:06.038 debug2: compression ctos: none,[email protected],zlib [preauth]
7340 2022-10-30 10:48:06.038 debug2: compression stoc: none,[email protected],zlib [preauth]
7340 2022-10-30 10:48:06.038 debug2: languages ctos: [preauth]
7340 2022-10-30 10:48:06.038 debug2: languages stoc: [preauth]
7340 2022-10-30 10:48:06.038 debug2: first_kex_follows 0 [preauth]
7340 2022-10-30 10:48:06.038 debug2: reserved 0 [preauth]
7340 2022-10-30 10:48:06.038 debug1: kex: algorithm: curve25519-sha256 [preauth]
7340 2022-10-30 10:48:06.038 debug1: kex: host key algorithm: ssh-ed25519 [preauth]
7340 2022-10-30 10:48:06.038 debug1: kex: client->server cipher: [email protected] MAC:
Client Log
debug3: receive packet: type 96 debug2: channel 0: rcvd eof debug2: channel 0: output open -> drain debug2: channel 0: obuf empty debug2: chan_shutdown_write: channel 0: (i0 o1 sock -1 wfd 5 efd 6 [write]) debug2: channel 0: output drain -> closed debug3: receive packet: type 98 debug1: client_input_channel_req: channel 0 rtype exit-status reply 0 debug3: receive packet: type 97 debug2: channel 0: rcvd close debug2: chan_shutdown_read: channel 0: (i0 o3 sock -1 wfd 4 efd 6 [write]) debug2: channel 0: input open -> closed debug3: channel 0: will not send data after close debug2: channel 0: almost dead debug2: channel 0: gc: notify user debug2: channel 0: gc: user detached debug2: channel 0: send close debug3: send packet: type 97 debug2: channel 0: is dead debug2: channel 0: garbage collecting debug1: channel 0: free: client-session, nchannels 1 debug3: channel 0: status: The following connections are open: #0 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/6 sock -1 cc -1)
debug3: send packet: type 1 debug3: fd 1 is not O_NONBLOCK Connection to 10.90.15.3 closed. Transferred: sent 2784, received 2436 bytes, in 0.5 seconds Bytes per second: sent 6005.0, received 5254.4 debug1: Exit status 1
PS C:\WINDOWS\system32> sshd -ddd debug2: load_server_config: filename PROGRAMDATA\ssh/sshd_config debug2: load_server_config: done config len = 200 debug2: parse_server_config: config PROGRAMDATA\ssh/sshd_config len 200 debug3: PROGRAMDATA\ssh/sshd_config:23 setting SyslogFacility LOCAL0 debug3: PROGRAMDATA\ssh/sshd_config:24 setting LogLevel DEBUG3 debug3: PROGRAMDATA\ssh/sshd_config:51 setting PasswordAuthentication yes debug3: PROGRAMDATA\ssh/sshd_config:70 setting ChrootDirectory C:\med debug3: PROGRAMDATA\ssh/sshd_config:78 setting Subsystem sftp sftp-server.exe debug1: sshd version OpenSSH_for_Windows_7.7, LibreSSL 2.6.5 debug1: private host key #0: ssh-rsa SHA256:IaoL1LrvmPA5dkF7AnYlvvidR4g/Qw5Q/bBVWAl8iKw debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:ttqBIDlRgfua2joEmcEnutdiuvSijKkF1L2aYJEyrFg debug1: private host key #2: ssh-ed25519 SHA256:O0o4vHj+X8Me/GS6hFzygQeCRb8TS6KLv0ipb4+mJd0 debug1: rexec_argv[0]='C:\Windows\System32\OpenSSH\sshd.exe' debug1: rexec_argv[1]='-ddd' debug2: fd 3 setting O_NONBLOCK debug3: sock_set_v6only: set socket 3 IPV6_V6ONLY debug1: Bind to port 22 on ::. Server listening on :: port 22. debug2: fd 4 setting O_NONBLOCK debug1: Bind to port 22 on 0.0.0.0. Server listening on 0.0.0.0 port 22.
For anyone who had that issue please to Configuring the default shell for OpenSSH in Windows by the command below
New-ItemProperty -Path "HKLM:\SOFTWARE\OpenSSH" -Name DefaultShell -Value "C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe" -PropertyType String -Force
Reference https://learn.microsoft.com/en-us/windows-server/administration/openssh/openssh_server_configuration
For anyone who had that issue please to Configuring the default shell for OpenSSH in Windows by the command below
New-ItemProperty -Path "HKLM:\SOFTWARE\OpenSSH" -Name DefaultShell -Value "C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe" -PropertyType String -ForceReference https://learn.microsoft.com/en-us/windows-server/administration/openssh/openssh_server_configuration
You saved my life!
scp provides an option `-O' (capital) to support this case.
Example
scp -O file_to_copy [email protected]:~/
