Windows SSH – Fix Key Based Authentication Refusal

On Windows 10 1809, I have enabled the in-built SSH server, and have configured it.

On another machine, I have used WinSCP and PuTTy generator to generate an authentication key. I copied the public key portion and appended that to the .ssh\authorized_keys file of my SSH server user. I fixed file permissions as required, to only my user, i.e., the logged in user, for the key file.

On the client machine, I used the .PPK private key, with WinSCP to try and connect into an SFTP session with my server, but I get a message that the server refused the key which I had selected.

I am able to authenticate using password, but the key pair isn't working out. Digging through the sshd logs generated on the server, I see this:

10200 2019-06-07 01:38:16.376 debug1: attempt 1 failures 0 [preauth]
10200 2019-06-07 01:38:16.376 debug2: input_userauth_request: try method publickey [preauth]
10200 2019-06-07 01:38:16.376 debug1: userauth_pubkey: test pkalg ssh-rsa pkblob RSA SHA256:B6s0omPbz6HJB2cIZf3+5MKHU42wp+JfOTyAM+EVqoY [preauth]
10200 2019-06-07 01:38:16.376 debug2: userauth_pubkey: disabled because of invalid user [preauth]

I am not sure what happened here, and if this is the reason why connection was refused. Firewall cannot be an issue since I am able to log into the server using password authentication. The client machine, and WinScp are being recognized on the server, it's just that the server refuses the provided key.

Is the key generated by PuTTy (or the key content copied with public key) not supported in either place? There's no passphrase associated with the key, but I don't suppose that should be an issue.

There's only one user on the server machine, which is the logged in user. The sshd service is running under LOCAL SYSTEM account. Should it run under a user account (I tried that but the service does not start at all, Event logs complain of a missing privilege…)

EDIT – More information

I commented out the following in sshd_config:

 #Match Group administrators  
 #      AuthorizedKeysFile __PROGRAMDATA__/ssh/administrators_authorized_keys

But now, a connection attempt complains that authorized_keys has bad permission. The machine only has one user, and the authorized_keys within the .ssh folder of that user only that one user access. I tried using Repair-AuthorizedKeyPermission on the key file, which added SYSTEM and sshd (NT Service user) as users to the key file, sshd having read access. But now, a connection attempt complains that bad permission has been set for user S-1-5-80 which is the same NT Service user sshd added by Repair-AutorizedKeyFile. Removing read permission (only permission) for this user again gives the old error, saying Access Denied.

EDIT – sshd.exe Logs from a connection attempt :

> 2696 2019-06-10 03:57:09.020 debug2: fd 3 setting O_NONBLOCK
> 
> 2696 2019-06-10 03:57:09.020 debug3: sock_set_v6only: set socket 3
> IPV6_V6ONLY
> 
> 2696 2019-06-10 03:57:09.020 debug1: Bind to port 22 on ::.
> 
> 2696 2019-06-10 03:57:09.020 Server listening on :: port 22.
> 
> 2696 2019-06-10 03:57:09.020 debug2: fd 4 setting O_NONBLOCK
> 
> 2696 2019-06-10 03:57:09.020 debug1: Bind to port 22 on 0.0.0.0.
> 
> 2696 2019-06-10 03:57:09.020 Server listening on 0.0.0.0 port 22.
> 
> 2696 2019-06-10 03:57:35.475 debug3: fd 5 is not O_NONBLOCK
> 
> 2696 2019-06-10 03:57:35.477 debug3: spawning
> "C:\\WINDOWS\\System32\\OpenSSH\\sshd.exe" "-R"
> 
> 2696 2019-06-10 03:57:35.483 debug3: send_rexec_state: entering fd = 8
> config len 287
> 
> 2696 2019-06-10 03:57:35.484 debug3: ssh_msg_send: type 0
> 
> 2696 2019-06-10 03:57:35.485 debug3: send_rexec_state: done
> 
> 9428 2019-06-10 03:57:35.556 debug1: inetd sockets after dupping: 3, 3
> 
> 9428 2019-06-10 03:57:35.556 Connection from 130.147.168.135 port
> 64534 on 161.85.17.107 port 22
> 
> 9428 2019-06-10 03:57:35.556 debug1: Client protocol version 2.0;
> client software version WinSCP_release_5.15.2
> 
> 9428 2019-06-10 03:57:35.556 debug1: no match: WinSCP_release_5.15.2
> 
> 9428 2019-06-10 03:57:35.556 debug1: Local version string
> SSH-2.0-OpenSSH_for_Windows_7.7
> 
> 9428 2019-06-10 03:57:35.556 debug2: fd 3 setting O_NONBLOCK
> 
> 9428 2019-06-10 03:57:35.568 debug3: spawning
> "C:\\WINDOWS\\System32\\OpenSSH\\sshd.exe" "-y"
> 
> 9428 2019-06-10 03:57:35.572 debug2: Network child is on pid 6944
> 
> 9428 2019-06-10 03:57:35.573 debug3: send_rexec_state: entering fd = 6
> config len 287
> 
> 9428 2019-06-10 03:57:35.573 debug3: ssh_msg_send: type 0
> 
> 9428 2019-06-10 03:57:35.575 debug3: send_rexec_state: done
> 
> 9428 2019-06-10 03:57:35.575 debug3: ssh_msg_send: type 0
> 
> 9428 2019-06-10 03:57:35.576 debug3: ssh_msg_send: type 0
> 
> 9428 2019-06-10 03:57:35.576 debug3: preauth child monitor started
> 
> 9428 2019-06-10 03:57:35.607 debug1: list_hostkey_types:
> ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
> [preauth]
> 
> 9428 2019-06-10 03:57:35.607 debug3: send packet: type 20 [preauth]
> 
> 9428 2019-06-10 03:57:35.607 debug1: SSH2_MSG_KEXINIT sent [preauth]
> 
> 9428 2019-06-10 03:57:35.794 debug3: receive packet: type 20 [preauth]
> 
> 9428 2019-06-10 03:57:35.794 debug1: SSH2_MSG_KEXINIT received
> [preauth]
> 
> 9428 2019-06-10 03:57:35.795 debug2: local server KEXINIT proposal
> [preauth]
> 
> 9428 2019-06-10 03:57:35.796 debug2: KEX algorithms:
> curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1
> [preauth]
> 
> 9428 2019-06-10 03:57:35.797 debug2: host key algorithms:
> ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
> [preauth]
> 
> 9428 2019-06-10 03:57:35.798 debug2: ciphers ctos:
> chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
> [preauth]
> 
> 9428 2019-06-10 03:57:35.798 debug2: ciphers stoc:
> chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
> [preauth]
> 
> 9428 2019-06-10 03:57:35.798 debug2: MACs ctos:
> umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
> [preauth]
> 
> 9428 2019-06-10 03:57:35.798 debug2: MACs stoc:
> umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
> [preauth]
> 
> 9428 2019-06-10 03:57:35.798 debug2: compression ctos: none [preauth]
> 
> 9428 2019-06-10 03:57:35.798 debug2: compression stoc: none [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: languages ctos:  [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: languages stoc:  [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: first_kex_follows 0  [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: reserved 0  [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: peer client KEXINIT proposal
> [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: KEX algorithms:
> curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,rsa2048-sha256,rsa1024-sha1,diffie-hellman-group1-sha1
> [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: host key algorithms:
> ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-rsa,ssh-dss [preauth]
> 
> 9428 2019-06-10 03:57:35.799 debug2: ciphers ctos:
> aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,chacha20-poly1305@openssh.com,blowfish-ctr,blowfish-cbc,3des-ctr,3des-cbc,arcfour256,arcfour128
> [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: ciphers stoc:
> aes256-ctr,aes256-cbc,rijndael-cbc@lysator.liu.se,aes192-ctr,aes192-cbc,aes128-ctr,aes128-cbc,chacha20-poly1305@openssh.com,blowfish-ctr,blowfish-cbc,3des-ctr,3des-cbc,arcfour256,arcfour128
> [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: MACs ctos:
> hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-etm@openssh.com [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: MACs stoc:
> hmac-sha2-256,hmac-sha1,hmac-sha1-96,hmac-md5,hmac-sha2-256-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha1-96-etm@openssh.com,hmac-md5-etm@openssh.com [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: compression ctos: none,zlib
> [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: compression stoc: none,zlib
> [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: languages ctos:  [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: languages stoc:  [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: first_kex_follows 0  [preauth]
> 
> 9428 2019-06-10 03:57:35.800 debug2: reserved 0  [preauth]
> 
> 9428 2019-06-10 03:57:35.801 debug1: kex: algorithm:
> curve25519-sha256@libssh.org [preauth]
> 
> 9428 2019-06-10 03:57:35.801 debug1: kex: host key algorithm:
> ssh-ed25519 [preauth]
> 
> 9428 2019-06-10 03:57:35.801 debug1: kex: client->server cipher:
> aes256-ctr MAC: hmac-sha2-256 compression: none [preauth]
> 
> 9428 2019-06-10 03:57:35.801 debug1: kex: server->client cipher:
> aes256-ctr MAC: hmac-sha2-256 compression: none [preauth]
> 
> 9428 2019-06-10 03:57:35.801 debug1: expecting SSH2_MSG_KEX_ECDH_INIT
> [preauth]
> 
> 9428 2019-06-10 03:57:35.834 debug3: receive packet: type 30 [preauth]
> 
> 9428 2019-06-10 03:57:35.843 debug3: mm_key_sign entering [preauth]
> 
> 9428 2019-06-10 03:57:35.843 debug3: mm_request_send entering: type 6
> [preauth]
> 
> 9428 2019-06-10 03:57:35.843 debug3: mm_key_sign: waiting for
> MONITOR_ANS_SIGN [preauth]
> 
> 9428 2019-06-10 03:57:35.843 debug3: mm_request_receive_expect
> entering: type 7 [preauth]
> 
> 9428 2019-06-10 03:57:35.843 debug3: mm_request_receive entering
> [preauth]
> 
> 9428 2019-06-10 03:57:35.843 debug3: mm_request_receive entering
> 
> 9428 2019-06-10 03:57:35.843 debug3: monitor_read: checking request 6
> 
> 9428 2019-06-10 03:57:35.843 debug3: mm_answer_sign
> 
> 9428 2019-06-10 03:57:35.846 debug3: mm_answer_sign: hostkey proof
> signature 0000029369ED8600(83)
> 
> 9428 2019-06-10 03:57:35.846 debug3: mm_request_send entering: type 7
> 
> 9428 2019-06-10 03:57:35.846 debug2: monitor_read: 6 used once,
> disabling now
> 
> 9428 2019-06-10 03:57:35.846 debug3: send packet: type 31 [preauth]
> 
> 9428 2019-06-10 03:57:35.846 debug3: send packet: type 21 [preauth]
> 
> 9428 2019-06-10 03:57:35.846 debug2: set_newkeys: mode 1 [preauth]
> 
> 9428 2019-06-10 03:57:35.846 debug1: rekey after 4294967296 blocks
> [preauth]
> 
> 9428 2019-06-10 03:57:35.846 debug1: SSH2_MSG_NEWKEYS sent [preauth]
> 
> 9428 2019-06-10 03:57:35.846 debug1: expecting SSH2_MSG_NEWKEYS
> [preauth]
> 
> 9428 2019-06-10 03:57:36.356 debug3: receive packet: type 21 [preauth]
> 
> 9428 2019-06-10 03:57:36.356 debug1: SSH2_MSG_NEWKEYS received
> [preauth]
> 
> 9428 2019-06-10 03:57:36.356 debug2: set_newkeys: mode 0 [preauth]
> 
> 9428 2019-06-10 03:57:36.356 debug1: rekey after 4294967296 blocks
> [preauth]
> 
> 9428 2019-06-10 03:57:36.356 debug1: KEX done [preauth]
> 
> 9428 2019-06-10 03:57:36.399 debug3: receive packet: type 5 [preauth]
> 
> 9428 2019-06-10 03:57:36.399 debug3: send packet: type 6 [preauth]
> 
> 9428 2019-06-10 03:57:36.435 debug3: receive packet: type 50 [preauth]
> 
> 9428 2019-06-10 03:57:36.435 debug1: userauth-request for user
> TestUser service ssh-connection method none [preauth]
> 
> 9428 2019-06-10 03:57:36.435 debug1: attempt 0 failures 0 [preauth]
> 
> 9428 2019-06-10 03:57:36.435 debug3: mm_getpwnamallow entering
> [preauth]
> 
> 9428 2019-06-10 03:57:36.436 debug3: mm_request_send entering: type 8
> [preauth]
> 
> 9428 2019-06-10 03:57:36.436 debug3: mm_getpwnamallow: waiting for
> MONITOR_ANS_PWNAM [preauth]
> 
> 9428 2019-06-10 03:57:36.436 debug3: mm_request_receive_expect
> entering: type 9 [preauth]
> 
> 9428 2019-06-10 03:57:36.436 debug3: mm_request_receive entering
> [preauth]
> 
> 9428 2019-06-10 03:57:36.436 debug3: mm_request_receive entering
> 
> 9428 2019-06-10 03:57:36.436 debug3: monitor_read: checking request 8
> 
> 9428 2019-06-10 03:57:36.436 debug3: mm_answer_pwnamallow
> 
> 9428 2019-06-10 03:57:36.439 debug2: parse_server_config: config
> reprocess config len 287
> 
> 9428 2019-06-10 03:57:36.439 debug3: checking match for 'Group
> administrators' user TestUser host 130.147.168.135 addr
> 130.147.168.135 laddr 161.85.17.107 lport 22
> 
> 9428 2019-06-10 03:57:36.446 debug3: LsaLogonUser Succeeded
> (Impersonation: 0)
> 
> 9428 2019-06-10 03:57:36.448 debug1: user TestUser matched group list
> administrators at line 84
> 
> 9428 2019-06-10 03:57:36.448 debug3: match found
> 
> 9428 2019-06-10 03:57:36.448 debug3: reprocess config:85 setting
> AuthorizedKeysFile __PROGRAMDATA__/ssh/administrators_authorized_keys
> 
> 9428 2019-06-10 03:57:36.449 debug3: mm_answer_pwnamallow: sending
> MONITOR_ANS_PWNAM: 1
> 
> 9428 2019-06-10 03:57:36.449 debug3: mm_request_send entering: type 9
> 
> 9428 2019-06-10 03:57:36.450 debug2: monitor_read: 8 used once,
> disabling now
> 
> 9428 2019-06-10 03:57:36.450 debug2: input_userauth_request: setting
> up authctxt for TestUser [preauth]
> 
> 9428 2019-06-10 03:57:36.450 debug3: mm_inform_authserv entering
> [preauth]
> 
> 9428 2019-06-10 03:57:36.450 debug3: mm_request_send entering: type 4
> [preauth]
> 
> 9428 2019-06-10 03:57:36.451 debug3: mm_request_receive entering
> 
> 9428 2019-06-10 03:57:36.451 debug3: monitor_read: checking request 4
> 
> 9428 2019-06-10 03:57:36.451 debug3: mm_answer_authserv:
> service=ssh-connection, style=
> 
> 9428 2019-06-10 03:57:36.451 debug2: monitor_read: 4 used once,
> disabling now
> 
> 9428 2019-06-10 03:57:36.451 debug2: input_userauth_request: try
> method none [preauth]
> 
> 9428 2019-06-10 03:57:36.452 debug3: userauth_finish: failure
> partial=0 next methods="publickey,password,keyboard-interactive"
> [preauth]
> 
> 9428 2019-06-10 03:57:36.452 debug3: send packet: type 51 [preauth]
> 
> 9428 2019-06-10 03:57:36.453 debug3: receive packet: type 50 [preauth]
> 
> 9428 2019-06-10 03:57:36.453 debug1: userauth-request for user
> TestUser service ssh-connection method publickey [preauth]
> 
> 9428 2019-06-10 03:57:36.453 debug1: attempt 1 failures 0 [preauth]
> 
> 9428 2019-06-10 03:57:36.454 debug2: input_userauth_request: try
> method publickey [preauth]
> 
> 9428 2019-06-10 03:57:36.454 debug1: userauth_pubkey: test pkalg
> ssh-rsa pkblob RSA SHA256:ospJEFHH81sy96YBMFEySGGUokk1KZHV+AbgNTFRrjE
> [preauth]
> 
> 9428 2019-06-10 03:57:36.455 debug3: mm_key_allowed entering [preauth]
> 
> 9428 2019-06-10 03:57:36.455 debug3: mm_request_send entering: type 22
> [preauth]
> 
> 9428 2019-06-10 03:57:36.455 debug3: mm_request_receive entering
> 
> 9428 2019-06-10 03:57:36.455 debug3: monitor_read: checking request 22
> 
> 9428 2019-06-10 03:57:36.456 debug3: mm_answer_keyallowed entering
> 
> 9428 2019-06-10 03:57:36.456 debug3: mm_answer_keyallowed:
> key_from_blob: 0000029369F0D8B0
> 
> 9428 2019-06-10 03:57:36.456 debug1: trying public key file
> __PROGRAMDATA__/ssh/administrators_authorized_keys
> 
> 9428 2019-06-10 03:57:36.456 debug3: Failed to open
> file:C:/ProgramData/ssh/administrators_authorized_keys error:2
> 
> 9428 2019-06-10 03:57:36.456 debug1: Could not open authorized keys
> '__PROGRAMDATA__/ssh/administrators_authorized_keys': No such file or
> directory
> 
> 9428 2019-06-10 03:57:36.456 debug3: mm_answer_keyallowed: publickey
> authentication test: RSA key is not allowed
> 
> 9428 2019-06-10 03:57:36.456 Failed publickey for TestUser from
> 130.147.168.135 port 64534 ssh2: RSA SHA256:ospJEFHH81sy96YBMFEySGGUokk1KZHV+AbgNTFRrjE
> 
> 9428 2019-06-10 03:57:36.456 debug3: mm_request_send entering: type 23
> 
> 9428 2019-06-10 03:57:36.457 debug3: mm_key_allowed: waiting for
> MONITOR_ANS_KEYALLOWED [preauth]
> 
> 9428 2019-06-10 03:57:36.457 debug3: mm_request_receive_expect
> entering: type 23 [preauth]
> 
> 9428 2019-06-10 03:57:36.457 debug3: mm_request_receive entering
> [preauth]
> 
> 9428 2019-06-10 03:57:36.457 debug2: userauth_pubkey: authenticated 0
> pkalg ssh-rsa [preauth]
> 
> 9428 2019-06-10 03:57:36.457 debug3: userauth_finish: failure
> partial=0 next methods="publickey,password,keyboard-interactive"
> [preauth]
> 
> 9428 2019-06-10 03:57:36.457 debug3: send packet: type 51 [preauth]
> 
> 9428 2019-06-10 03:57:36.482 debug3: receive packet: type 50 [preauth]
> 
> 9428 2019-06-10 03:57:36.482 debug1: userauth-request for user
> TestUser service ssh-connection method keyboard-interactive [preauth]
> 
> 9428 2019-06-10 03:57:36.482 debug1: attempt 2 failures 1 [preauth]
> 
> 9428 2019-06-10 03:57:36.482 debug2: input_userauth_request: try
> method keyboard-interactive [preauth]
> 
> 9428 2019-06-10 03:57:36.482 debug1: keyboard-interactive devs 
> [preauth]
> 
> 9428 2019-06-10 03:57:36.483 debug1: auth2_challenge: user=TestUser
> devs= [preauth]
> 
> 9428 2019-06-10 03:57:36.483 debug1: kbdint_alloc: devices ''
> [preauth]
> 
> 9428 2019-06-10 03:57:36.483 debug2: auth2_challenge_start: devices 
> [preauth]
> 
> 9428 2019-06-10 03:57:36.483 debug3: userauth_finish: failure
> partial=0 next methods="publickey,password,keyboard-interactive"
> [preauth]
> 
> 9428 2019-06-10 03:57:36.483 debug3: send packet: type 51 [preauth]