Authentication via pkey throws unable to generate user token for <user> as i am not running as system

[bisato]

I try to connect with username/password, and everything runs fine.
But trying to connect with pkey file generates this output

debug2: load_server_config: filename PROGRAMDATA\ssh/sshd_config
debug2: load_server_config: done config len = 291
debug2: parse_server_config: config PROGRAMDATA\ssh/sshd_config len 291
debug3: PROGRAMDATA\ssh/sshd_config:34 setting PubkeyAuthentication yes
debug3: PROGRAMDATA\ssh/sshd_config:55 setting GSSAPIAuthentication yes
debug3: PROGRAMDATA\ssh/sshd_config:66 setting ClientAliveInterval 300
debug3: PROGRAMDATA\ssh/sshd_config:72 setting ChrootDirectory E:\Transfer_LIKV
debug3: PROGRAMDATA\ssh/sshd_config:79 setting Subsystem sftp sftp-server.exe
debug3: PROGRAMDATA\ssh/sshd_config:88 setting AuthorizedKeysFile PROGRAMDATA/ssh/administrators_authorized_key
s
debug1: sshd version OpenSSH_for_Windows_8.0, LibreSSL 2.6.5
debug1: private host key #0: ssh-rsa SHA256:4ID8Ug1sK1WyNbTRdt+/d7tez7nGEETT4Acblx7H1CY
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:OkLtG4SfX06jhSyakTySfnCX6bupqzTrRucPXE+HKtg
debug1: private host key #2: ssh-ed25519 SHA256:BYOi+zuy8R9R0m+v5xuqcUA8+k29Sj4ZQPy+F3cdAC8
debug1: rexec_argv[0]='C:\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.
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 291
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
Connection from 10.2.80.233 port 50727 on 10.2.181.17 port 22
debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.0
debug1: Remote protocol version 2.0, remote software version OpenSSH_6.2p2+sftpfilecontrol-v1.3-hpn13v12
debug1: match: OpenSSH_6.2p2+sftpfilecontrol-v1.3-hpn13v12 pat OpenSSH* compat 0x04000000
debug2: fd 5 setting O_NONBLOCK
debug3: spawning "C:\OpenSSH\sshd.exe" -ddd -y
debug2: Network child is on pid 11168
debug3: send_rexec_state: entering fd = 4 config len 291
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: config PROGRAMDATA\ssh/sshd_config len 291
debug3: PROGRAMDATA\ssh/sshd_config:34 setting PubkeyAuthentication yes
debug3: PROGRAMDATA\ssh/sshd_config:55 setting GSSAPIAuthentication yes
debug3: PROGRAMDATA\ssh/sshd_config:66 setting ClientAliveInterval 300
debug3: PROGRAMDATA\ssh/sshd_config:72 setting ChrootDirectory E:\Transfer_LIKV
debug3: PROGRAMDATA\ssh/sshd_config:79 setting Subsystem sftp sftp-server.exe
debug3: PROGRAMDATA\ssh/sshd_config:88 setting AuthorizedKeysFile PROGRAMDATA/ssh/administrators_authorized_key
s
debug1: sshd version OpenSSH_for_Windows_8.0, LibreSSL 2.6.5
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,diffie-hellman-group14-sha1 [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 [preauth]
debug2: compression stoc: none [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: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,di
ffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1 [preauth]
debug2: host key algorithms: [email protected],[email protected],ecdsa-sha
[email protected],ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,[email protected]
,[email protected],[email protected],[email protected],ssh-rsa,ssh-dss [preauth]
debug2: ciphers ctos: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,[email protected],[email protected]
om,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,[email protected] [preauth]
debug2: ciphers stoc: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,[email protected],[email protected]
om,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,[email protected] [preauth]
debug2: MACs ctos: [email protected],[email protected],[email protected],[email protected],h
[email protected],[email protected],[email protected],[email protected],h
[email protected],hmac-md5,hmac-sha1,[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-
ripemd160,[email protected],hmac-sha1-96,hmac-md5-96 [preauth]
debug2: MACs stoc: [email protected],[email protected],[email protected],[email protected],h
[email protected],[email protected],[email protected],[email protected],h
[email protected],hmac-md5,hmac-sha1,[email protected],[email protected],hmac-sha2-256,hmac-sha2-512,hmac-
ripemd160,[email protected],hmac-sha1-96,hmac-md5-96 [preauth]
debug2: compression ctos: none,[email protected],zlib [preauth]
debug2: compression stoc: none,[email protected],zlib [preauth]
debug2: languages ctos: [preauth]
debug2: languages stoc: [preauth]
debug2: first_kex_follows 0 [preauth]
debug2: reserved 0 [preauth]
debug1: kex: algorithm: ecdh-sha2-nistp256 [preauth]
debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
debug1: kex: client->server cipher: aes128-ctr MAC: [email protected] compression: none [preauth]
debug1: kex: server->client cipher: aes128-ctr MAC: [email protected] compression: none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug3: receive packet: type 30 [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
debug3: mm_answer_sign: hostkey proof signature 0000014FC4C49DF0(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 4294967296 blocks [preauth]
debug1: SSH2_MSG_NEWKEYS sent [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 4294967296 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 lvt_itpr 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
debug2: parse_server_config: config reprocess config len 291
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 lvt_itpr [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 17.999ms, delaying 14.272ms (requested 8.068ms) [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,gssapi-with-mic,password,keyboard-interactive" [preau
th]
debug3: send packet: type 51 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user lvt_itpr 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 lvt_itpr querying public key ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAIEA8CXJRT8Nnm3MkuD7x+s
Neonob/5f4iRlm+x+lxvDrw/trEmmsBTW+SGC3JDPp2TFQRX+sH0hDc/W7W/71X1ZAyj7Kbi5qpLe7I6snh7nMW9ySgELhe2VaHdqsll6XMCdLzQl6KpVJLE
rm9QuTkhUk3WwLyWN4teCu5aet+wlmi0= [preauth]
debug1: userauth_pubkey: test pkalg ssh-rsa pkblob RSA SHA256:jVBb2S1V0QEoqu/RQDghStskGKnuxq66vNgtBBPScqg [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: 0000014FC4C49A00
debug1: trying public key file PROGRAMDATA/ssh/administrators_authorized_keys
debug1: PROGRAMDATA/ssh/administrators_authorized_keys:3: matching key found: RSA SHA256:jVBb2S1V0QEoqu/RQDghStskGKn
uxq66vNgtBBPScqg
debug1: PROGRAMDATA/ssh/administrators_authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc
x11-forwarding
Accepted key RSA SHA256:jVBb2S1V0QEoqu/RQDghStskGKnuxq66vNgtBBPScqg found at PROGRAMDATA/ssh/administrators_authoriz
ed_keys:3
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 ssh-rsa [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 21.995ms, delaying 10.276ms (requested 8.068ms) [preauth]
Postponed publickey for lvt_itpr from 10.2.80.233 port 50727 ssh2 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user lvt_itpr 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 lvt_itpr attempting public key ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAIEA8CXJRT8Nnm3MkuD7x
+sNeonob/5f4iRlm+x+lxvDrw/trEmmsBTW+SGC3JDPp2TFQRX+sH0hDc/W7W/71X1ZAyj7Kbi5qpLe7I6snh7nMW9ySgELhe2VaHdqsll6XMCdLzQl6KpVJ
LErm9QuTkhUk3WwLyWN4teCu5aet+wlmi0= [preauth]
debug3: userauth_pubkey: have ssh-rsa signature for RSA SHA256:jVBb2S1V0QEoqu/RQDghStskGKnuxq66vNgtBBPScqg [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: 0000014FC4C49AE0
debug1: trying public key file PROGRAMDATA/ssh/administrators_authorized_keys
debug1: PROGRAMDATA/ssh/administrators_authorized_keys:3: matching key found: RSA SHA256:jVBb2S1V0QEoqu/RQDghStskGKn
uxq66vNgtBBPScqg
debug1: PROGRAMDATA/ssh/administrators_authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc
x11-forwarding
Accepted key RSA SHA256:jVBb2S1V0QEoqu/RQDghStskGKnuxq66vNgtBBPScqg found at PROGRAMDATA/ssh/administrators_authoriz
ed_keys:3
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 0000014FC4C49AE0 signature verified
debug1: auth_activate_options: setting new authentication options
debug3: mm_request_send entering: type 25
Accepted publickey for lvt_itpr from 10.2.80.233 port 50727 ssh2: RSA SHA256:jVBb2S1V0QEoqu/RQDghStskGKnuxq66vNgtBBPScqg
debug1: monitor_child_preauth: lvt_itpr has been 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 ssh-rsa [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 32.014ms, delaying 0.257ms (requested 8.068ms) [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:0000014FC4C2DDE0
debug3: read - no more data, io:0000014FC4C2DDE0
debug1: monitor_read_log: child log fd closed
debug1: ssh_gssapi_storecreds: Not a GSSAPI mechanism
debug1: get_user_token - unable to generate user token for zdvw2k\lvt_itpr as i am not running as system
unable to get security token for user zdvw2k\lvt_itpr
fork of unprivileged child failed
debug1: do_cleanup

"OpenSSH for Windows" version
v8.0.0.0p1-Beta

Server OperatingSystem
Windows Server 2016 DataCenter

Client OperatingSystem
Windows 10

Actual output
lvtsu006:/home/likv_usr # ssh lvt_itpr@ -v
OpenSSH_6.2p2+sftpfilecontrol-v1.3-hpn13v12, OpenSSL 1.0.1p 9 Jul 2015
HP-UX Secure Shell-A.06.20.030, HP-UX Secure Shell version
debug1: Reading configuration data /opt/ssh/etc/ssh_config
debug1: Connecting to [10.2.181.17] port 22.
debug1: Connection established.
debug1: identity file /home/likv_usr/.ssh/identity type -1
debug1: identity file /home/likv_usr/.ssh/identity-cert type -1
debug1: identity file /home/likv_usr/.ssh/id_rsa type 1
debug1: identity file /home/likv_usr/.ssh/id_rsa-cert type -1
debug1: identity file /home/likv_usr/.ssh/id_dsa type -1
debug1: identity file /home/likv_usr/.ssh/id_dsa-cert type -1
debug1: identity file /home/likv_usr/.ssh/id_ecdsa type -1
debug1: identity file /home/likv_usr/.ssh/id_ecdsa-cert type -1
debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.0
debug1: match: OpenSSH_for_Windows_8.0 pat OpenSSH*
debug1: Remote is NON-HPN aware
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_6.2p2+sftpfilecontrol-v1.3-hpn13v12
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: AUTH STATE IS 0
debug1: REQUESTED ENC.NAME is 'aes128-ctr'
debug1: kex: server->client aes128-ctr [email protected] none
debug1: REQUESTED ENC.NAME is 'aes128-ctr'
debug1: kex: client->server aes128-ctr [email protected] none
debug1: sending SSH2_MSG_KEX_ECDH_INIT
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ECDSA 82:02:35:5f:41:d3:24:49:8f:a9:c4:0d:75:da:9f:c2
debug1: Host 'lvtsvintra.zdv.liebherr.i' is known and matches the ECDSA host key.
debug1: Found key in /home/likv_usr/.ssh/known_hosts:35
debug1: ssh_ecdsa_verify: signature correct
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: Roaming not allowed by server
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,gssapi-with-mic,password,keyboard-interactive
debug1: Next authentication method: publickey
debug1: Trying private key: /home/likv_usr/.ssh/identity
debug1: Offering RSA public key: /home/likv_usr/.ssh/id_rsa
debug1: Server accepts key: pkalg ssh-rsa blen 149
debug1: read PEM private key done: type RSA
debug1: Authentication succeeded (publickey).
Authenticated to ([10.2.181.17]:22).
debug1: HPN to Non-HPN Connection
debug1: Final hpn_buffer_size = 131072
debug1: HPN Disabled: 1, HPN Buffer Size: 131072
debug1: channel 0: new [client-session]
debug1: Requesting [email protected]
debug1: Entering interactive session.
Write failed: Broken pipe

[bisato]

The Error "unable to generate user token for" was in our case thrown, because the user was deactivated in AD.

[bagajjal]

@bisato - Are you running the sshd in debug mode (.\sshd.exe -ddd)?
If yes then it's by design.

[bisato]

@bagajjal
I think I made this not clear enough.
My issue was resolved by re-activating the user who tried to login.
I just want this to stay here for people running into the same problem.

btw: even with debug mode "-ddd" it was working with activated user. But now it runs as service.