Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

get_passwd: LookupAccountName() failed: 1332. #1476

Closed
heaths opened this issue Oct 6, 2019 · 31 comments
Closed

get_passwd: LookupAccountName() failed: 1332. #1476

heaths opened this issue Oct 6, 2019 · 31 comments

Comments

@heaths
Copy link

heaths commented Oct 6, 2019

"OpenSSH for Windows" version
((Get-Item (Get-Command sshd).Source).VersionInfo.FileVersion)
7.7.2.2

Server OperatingSystem
((Get-ItemProperty "HKLM:\SOFTWARE\Microsoft\Windows nt\CurrentVersion\" -Name ProductName).ProductName)
Windows 10 Enterprise

Client OperatingSystem
Windows 10 build 1903

What is failing
I cannot ssh into my machine. I've set this up before, but this time my laptop is not domain-joined, but instead AAD-joined (Intune managed), which seems to be part of the problem from what information I could find about LookupAccountName and error 1332.

My sshd_config is nearly default. I set PasswordAuthentication to no, but apart from that (and temporarily logging DEBUG3 server output), nothing else is different.

From the debug log, I see:

10276 2019-10-06 12:32:39.152 debug1: get_passwd: LookupAccountName() failed: 1332.
10276 2019-10-06 12:32:39.152 debug2: parse_server_config: config reprocess config len 336
10276 2019-10-06 12:32:39.152 debug3: checking match for 'Group administrators' user heaths host fe80::6c5d:4766:1774:b485%16 addr fe80::6c5d:4766:1774:b485%16 laddr fe80::6c5d:4766:1774:b485%16 lport 22
10276 2019-10-06 12:32:39.152 debug1: get_passwd: LookupAccountName() failed: 1332.
10276 2019-10-06 12:32:39.152 debug1: Can't match group at line 84 because user heaths does not exist
10276 2019-10-06 12:32:39.152 debug3: match not found

My $ProgramData\ssh\administrators_authorized_keys contains my public key, as does my ~.ssh\authorized_keys. icacls shows appropriate ownership and DACLs.

Basically, everything is set up as I've done before except that I'm not domain joined (normally do, but was having some unrelated problems setting up a new machine).

Expected output
I can log in via ssh.

Actual output
I'm denied access.

@heaths
Copy link
Author

heaths commented Oct 7, 2019

To add, this same setup and ACLs (different SIDs, obviously, but "same" accounts) works on my other laptop that also does not belong to a domain, though it's not AAD-joined either (personal machine with only an associated MSA).

@NoMoreFood
Copy link

Can you try the latest version and provide the debug DEBUG3 logs for those?

@matthewfcarlson
Copy link

I'm seeing something similar with the latest version.

2520 2020-02-28 15:17:38.098 debug3: sock_set_v6only: set socket 3 IPV6_V6ONLY
2520 2020-02-28 15:17:38.098 debug1: Bind to port 22 on ::.
2520 2020-02-28 15:17:38.098 Server listening on :: port 22.
2520 2020-02-28 15:17:38.098 debug2: fd 4 setting O_NONBLOCK
2520 2020-02-28 15:17:38.098 debug1: Bind to port 22 on 0.0.0.0.
2520 2020-02-28 15:17:38.098 Server listening on 0.0.0.0 port 22.
2520 2020-02-28 15:17:43.535 debug3: fd 5 is not O_NONBLOCK
2520 2020-02-28 15:17:43.551 debug3: spawning "C:\\Program Files\\OpenSSH\\sshd.exe" -R
2520 2020-02-28 15:17:43.551 debug3: send_rexec_state: entering fd = 8 config len 297
2520 2020-02-28 15:17:43.551 debug3: ssh_msg_send: type 0
2520 2020-02-28 15:17:43.551 debug3: send_rexec_state: done
6780 2020-02-28 15:17:43.614 debug1: inetd sockets after dupping: 4, 4
6780 2020-02-28 15:17:43.614 Connection from fe80::cd23:df1c:3817:f30e%10 port 1756 on fe80::541e:a3df:a4ec:f5c9%10 port 22
6780 2020-02-28 15:17:43.614 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1
6780 2020-02-28 15:17:43.614 debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_7.7
6780 2020-02-28 15:17:43.614 debug1: match: OpenSSH_for_Windows_7.7 pat OpenSSH* compat 0x04000000
6780 2020-02-28 15:17:43.614 debug2: fd 4 setting O_NONBLOCK
6780 2020-02-28 15:17:43.629 debug3: spawning "C:\\Program Files\\OpenSSH\\sshd.exe" -y
6780 2020-02-28 15:17:43.629 debug2: Network child is on pid 9092
6780 2020-02-28 15:17:43.629 debug3: send_rexec_state: entering fd = 6 config len 297
6780 2020-02-28 15:17:43.629 debug3: ssh_msg_send: type 0
6780 2020-02-28 15:17:43.629 debug3: send_rexec_state: done
6780 2020-02-28 15:17:43.629 debug3: ssh_msg_send: type 0
6780 2020-02-28 15:17:43.629 debug3: ssh_msg_send: type 0
6780 2020-02-28 15:17:43.629 debug3: preauth child monitor started
6780 2020-02-28 15:17:43.676 debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256 [preauth]
6780 2020-02-28 15:17:43.676 debug3: send packet: type 20 [preauth]
6780 2020-02-28 15:17:43.676 debug1: SSH2_MSG_KEXINIT sent [preauth]
6780 2020-02-28 15:17:43.676 debug3: receive packet: type 20 [preauth]
6780 2020-02-28 15:17:43.676 debug1: SSH2_MSG_KEXINIT received [preauth]
6780 2020-02-28 15:17:43.676 debug2: local server KEXINIT proposal [preauth]
6780 2020-02-28 15:17:43.676 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]
6780 2020-02-28 15:17:43.676 debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256 [preauth]
6780 2020-02-28 15:17:43.676 debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
6780 2020-02-28 15:17:43.676 debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
6780 2020-02-28 15:17:43.676 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]
6780 2020-02-28 15:17:43.676 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]
6780 2020-02-28 15:17:43.676 debug2: compression ctos: none,zlib@openssh.com [preauth]
6780 2020-02-28 15:17:43.676 debug2: compression stoc: none,zlib@openssh.com [preauth]
6780 2020-02-28 15:17:43.676 debug2: languages ctos:  [preauth]
6780 2020-02-28 15:17:43.676 debug2: languages stoc:  [preauth]
6780 2020-02-28 15:17:43.676 debug2: first_kex_follows 0  [preauth]
6780 2020-02-28 15:17:43.676 debug2: reserved 0  [preauth]
6780 2020-02-28 15:17:43.676 debug2: peer client KEXINIT proposal [preauth]
6780 2020-02-28 15:17:43.676 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-group-exchange-sha1,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,ext-info-c [preauth]
6780 2020-02-28 15:17:43.676 debug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
6780 2020-02-28 15:17:43.676 debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
6780 2020-02-28 15:17:43.676 debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
6780 2020-02-28 15:17:43.676 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]
6780 2020-02-28 15:17:43.676 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]
6780 2020-02-28 15:17:43.676 debug2: compression ctos: none [preauth]
6780 2020-02-28 15:17:43.676 debug2: compression stoc: none [preauth]
6780 2020-02-28 15:17:43.676 debug2: languages ctos:  [preauth]
6780 2020-02-28 15:17:43.676 debug2: languages stoc:  [preauth]
6780 2020-02-28 15:17:43.676 debug2: first_kex_follows 0  [preauth]
6780 2020-02-28 15:17:43.676 debug2: reserved 0  [preauth]
6780 2020-02-28 15:17:43.676 debug1: kex: algorithm: curve25519-sha256 [preauth]
6780 2020-02-28 15:17:43.676 debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
6780 2020-02-28 15:17:43.676 debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
6780 2020-02-28 15:17:43.676 debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
6780 2020-02-28 15:17:43.676 debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
6780 2020-02-28 15:17:43.676 debug3: receive packet: type 30 [preauth]
6780 2020-02-28 15:17:43.676 debug3: mm_sshkey_sign entering [preauth]
6780 2020-02-28 15:17:43.676 debug3: mm_request_send entering: type 6 [preauth]
6780 2020-02-28 15:17:43.676 debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
6780 2020-02-28 15:17:43.676 debug3: mm_request_receive_expect entering: type 7 [preauth]
6780 2020-02-28 15:17:43.676 debug3: mm_request_receive entering [preauth]
6780 2020-02-28 15:17:43.676 debug3: mm_request_receive entering
6780 2020-02-28 15:17:43.676 debug3: monitor_read: checking request 6
6780 2020-02-28 15:17:43.676 debug3: mm_answer_sign
6780 2020-02-28 15:17:43.676 debug3: mm_answer_sign: KEX signature 00000192EBB9FD20(100)
6780 2020-02-28 15:17:43.676 debug3: mm_request_send entering: type 7
6780 2020-02-28 15:17:43.676 debug2: monitor_read: 6 used once, disabling now
6780 2020-02-28 15:17:43.676 debug3: send packet: type 31 [preauth]
6780 2020-02-28 15:17:43.676 debug3: send packet: type 21 [preauth]
6780 2020-02-28 15:17:43.676 debug2: set_newkeys: mode 1 [preauth]
6780 2020-02-28 15:17:43.676 debug1: rekey out after 134217728 blocks [preauth]
6780 2020-02-28 15:17:43.676 debug1: SSH2_MSG_NEWKEYS sent [preauth]
6780 2020-02-28 15:17:43.676 debug1: Sending SSH2_MSG_EXT_INFO [preauth]
6780 2020-02-28 15:17:43.676 debug3: send packet: type 7 [preauth]
6780 2020-02-28 15:17:43.676 debug1: expecting SSH2_MSG_NEWKEYS [preauth]
6780 2020-02-28 15:17:43.692 debug3: receive packet: type 21 [preauth]
6780 2020-02-28 15:17:43.692 debug1: SSH2_MSG_NEWKEYS received [preauth]
6780 2020-02-28 15:17:43.692 debug2: set_newkeys: mode 0 [preauth]
6780 2020-02-28 15:17:43.692 debug1: rekey in after 134217728 blocks [preauth]
6780 2020-02-28 15:17:43.692 debug1: KEX done [preauth]
6780 2020-02-28 15:17:43.739 debug3: receive packet: type 5 [preauth]
6780 2020-02-28 15:17:43.739 debug3: send packet: type 6 [preauth]
6780 2020-02-28 15:17:43.739 debug3: receive packet: type 50 [preauth]
6780 2020-02-28 15:17:43.739 debug1: userauth-request for user macarl service ssh-connection method none [preauth]
6780 2020-02-28 15:17:43.739 debug1: attempt 0 failures 0 [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_getpwnamallow entering [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_request_send entering: type 8 [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_request_receive_expect entering: type 9 [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_request_receive entering [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_request_receive entering
6780 2020-02-28 15:17:43.739 debug3: monitor_read: checking request 8
6780 2020-02-28 15:17:43.739 debug3: mm_answer_pwnamallow
6780 2020-02-28 15:17:43.739 debug1: get_passwd: LookupAccountName() failed: 1332.
6780 2020-02-28 15:17:43.739 debug2: parse_server_config: config reprocess config len 297
6780 2020-02-28 15:17:43.739 Invalid user macarl from fe80::cd23:df1c:3817:f30e%10 port 1756
6780 2020-02-28 15:17:43.739 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 0
6780 2020-02-28 15:17:43.739 debug3: mm_request_send entering: type 9
6780 2020-02-28 15:17:43.739 debug2: monitor_read: 8 used once, disabling now
6780 2020-02-28 15:17:43.739 debug3: mm_inform_authserv entering [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_request_send entering: type 4 [preauth]
6780 2020-02-28 15:17:43.739 debug2: input_userauth_request: try method none [preauth]
6780 2020-02-28 15:17:43.739 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
6780 2020-02-28 15:17:43.739 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 6.654ms (requested 6.654ms) [preauth]
6780 2020-02-28 15:17:43.739 debug3: mm_request_receive entering
6780 2020-02-28 15:17:43.739 debug3: monitor_read: checking request 4
6780 2020-02-28 15:17:43.739 debug3: mm_answer_authserv: service=ssh-connection, style=
6780 2020-02-28 15:17:43.739 debug2: monitor_read: 4 used once, disabling now
6780 2020-02-28 15:17:43.754 debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-with-mic,password,keyboard-interactive" [preauth]
6780 2020-02-28 15:17:43.754 debug3: send packet: type 51 [preauth]
6780 2020-02-28 15:17:43.754 debug3: receive packet: type 50 [preauth]
6780 2020-02-28 15:17:43.754 debug1: userauth-request for user macarl service ssh-connection method publickey [preauth]
6780 2020-02-28 15:17:43.754 debug1: attempt 1 failures 0 [preauth]
6780 2020-02-28 15:17:43.754 debug2: input_userauth_request: try method publickey [preauth]
6780 2020-02-28 15:17:43.754 debug2: userauth_pubkey: invalid user macarl querying public key rsa-sha2-512 AAAAB3NzaC1yc2EAAAADAQABAAACAQDQC/D2kSYz6LLWATEVZXu2cWLJ2BRN3cy46ogELWqui3Vsjj1xw04c066c5mDSZjd3Opf5MD7liN/rG0ACR4Tan+DTrq8DVsXYCww+9kSTzI+N6J9dSwGqfnU78mhw36Qy5K3AfsUYEaEywQD7KXbFfdGv0q29sXYZgoS5NcRSxLERgF9uZ4y1sJwxcdMK/iTfvWaN3n/iaspkPhbBTKPA35kASGHKoTSi+u+OKWp0vhdyqYCJNwTglq3jzdDagleaYGZ9NMYFyFbB+YXukW4ijWsYMyHYsh2oXT0kaX5zr6+WWXd4PSO5AblrsutA3Je0wGptCf7e8VkxEQyRVKCPkPu7t7ke8QMr8RghDauxmXHDmYXxPh9nF9jrYUzwMgrbt/vVo333FvvAQ64klLWj1JxXmyMCc8cBhZscPVChL2T7+G4t5LXZy2jVlo/c0Gn9dbGpagDPb0qwnt9Ecs6dX8OK314YoclrvnM52sMcrYulWNLvb8RB1k9RY2oT6IOgkjZT3JuAczfEKrmfStf5sR7S7xCYnu1L/dsj0Rnk6nUURwC36pPoAfhTcEp9i413F7vulhUfnwsO3Z2gW+VtC8zvaWKfUhdc96DgwBdVg24ahNniYilqzfRgUwV/M/HnpGoMnA+1hRrV8UYusaLT3rwpHOxp3+G2XFIu7MizRQ== [preauth]
6780 2020-02-28 15:17:43.754 debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:er4Hn6mfUpc8MaMhN0PK8AqX/59FkIeDvWyU4XxIl4s [preauth]
6780 2020-02-28 15:17:43.754 debug2: userauth_pubkey: disabled because of invalid user [preauth]
6780 2020-02-28 15:17:43.754 debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth]
6780 2020-02-28 15:17:43.754 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
6780 2020-02-28 15:17:43.754 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 6.654ms (requested 6.654ms) [preauth]
6780 2020-02-28 15:17:43.770 debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-with-mic,password,keyboard-interactive" [preauth]
6780 2020-02-28 15:17:43.770 debug3: send packet: type 51 [preauth]
6780 2020-02-28 15:17:43.770 debug3: receive packet: type 50 [preauth]
6780 2020-02-28 15:17:43.770 debug1: userauth-request for user macarl service ssh-connection method keyboard-interactive [preauth]
6780 2020-02-28 15:17:43.770 debug1: attempt 2 failures 1 [preauth]
6780 2020-02-28 15:17:43.770 debug2: input_userauth_request: try method keyboard-interactive [preauth]
6780 2020-02-28 15:17:43.770 debug1: keyboard-interactive devs  [preauth]
6780 2020-02-28 15:17:43.770 debug1: auth2_challenge: user=macarl devs= [preauth]
6780 2020-02-28 15:17:43.770 debug1: kbdint_alloc: devices '' [preauth]
6780 2020-02-28 15:17:43.770 debug2: auth2_challenge_start: devices  [preauth]
6780 2020-02-28 15:17:43.770 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
6780 2020-02-28 15:17:43.770 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 6.654ms (requested 6.654ms) [preauth]
6780 2020-02-28 15:17:43.785 debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-with-mic,password,keyboard-interactive" [preauth]
6780 2020-02-28 15:17:43.785 debug3: send packet: type 51 [preauth]
6780 2020-02-28 15:17:46.770 debug3: receive packet: type 50 [preauth]
6780 2020-02-28 15:17:46.770 debug1: userauth-request for user macarl service ssh-connection method password [preauth]
6780 2020-02-28 15:17:46.770 debug1: attempt 3 failures 2 [preauth]
6780 2020-02-28 15:17:46.770 debug2: input_userauth_request: try method password [preauth]
6780 2020-02-28 15:17:46.770 debug3: mm_auth_password entering [preauth]
6780 2020-02-28 15:17:46.770 debug3: mm_request_send entering: type 12 [preauth]
6780 2020-02-28 15:17:46.770 debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth]
6780 2020-02-28 15:17:46.770 debug3: mm_request_receive_expect entering: type 13 [preauth]
6780 2020-02-28 15:17:46.770 debug3: mm_request_receive entering [preauth]
6780 2020-02-28 15:17:46.770 debug3: mm_request_receive entering
6780 2020-02-28 15:17:46.770 debug3: monitor_read: checking request 12
6780 2020-02-28 15:17:46.770 debug1: Windows authentication failed for user: NOUSER domain: . error: 1326
6780 2020-02-28 15:17:46.770 debug3: mm_answer_authpassword: sending result 0
6780 2020-02-28 15:17:46.770 debug3: mm_request_send entering: type 13
6780 2020-02-28 15:17:46.770 Failed password for invalid user macarl from fe80::cd23:df1c:3817:f30e%10 port 1756 ssh2
6780 2020-02-28 15:17:46.770 debug3: mm_auth_password: user not authenticated [preauth]
6780 2020-02-28 15:17:46.770 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
6780 2020-02-28 15:17:46.770 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 6.654ms (requested 6.654ms) [preauth]
6780 2020-02-28 15:17:46.786 debug3: userauth_finish: failure partial=0 next methods="publickey,gssapi-with-mic,password,keyboard-interactive" [preauth]
6780 2020-02-28 15:17:46.786 debug3: send packet: type 51 [preauth]
6780 2020-02-28 15:17:47.348 debug3: recv - from CB ERROR:10054, io:000002509F639170 [preauth]
6780 2020-02-28 15:17:47.348 Connection reset by invalid user macarl fe80::cd23:df1c:3817:f30e%10 port 1756 [preauth]
6780 2020-02-28 15:17:47.348 debug1: do_cleanup [preauth]
6780 2020-02-28 15:17:47.348 debug1: monitor_read_log: child log fd closed
6780 2020-02-28 15:17:47.348 debug3: mm_request_receive entering
6780 2020-02-28 15:17:47.348 debug1: do_cleanup
6780 2020-02-28 15:17:47.348 debug1: Killing privsep child 9092

@heaths
Copy link
Author

heaths commented Feb 29, 2020

I'm not sure if it's related, but in another product we ran into a problem with AAD-joined accounts where GetWindowsAccountDomainSid (called indirectly via System.Security.Principal.WindowsIdentity.GetCurrent().User) did not return a RID for the domain, whereas for AD domain-joined machines it did and, for local accounts, was the RID of the local machine.

@heaths
Copy link
Author

heaths commented Jun 11, 2020

This problem still occurs and, since we're all working remotely apart from Redmond campus of Microsoft, I had to AAD-join and cannot SSH into my machines after setting up a new machine.

@bagajjal
Copy link
Collaborator

bagajjal commented Jun 11, 2020

@heaths - There is a proposed feature request to ssh using AAD credentials. Windows AAD team is supposed to make this change in next semister.

However, I have a workaround.

  1. In $env:programdata\ssh\sshd_config comment out all match block such as
    Match Group administrators
    AuthorizedKeysFile PROGRAMDATA/ssh/administrators_authorized_keys

  2. Any changes to sshd_config requires a sshd service restart
    net stop sshd
    net start sshd

  3. Always use the format
    ssh azuread\user@microsoft.com@ipaddress

Please note only password based authentication will work.

@heaths
Copy link
Author

heaths commented Jun 11, 2020

Will those plans include supporting PubkeyAuthentication? I use a Yubikey normally, which is much more secure.

@bagajjal
Copy link
Collaborator

bagajjal commented Jun 11, 2020

@heaths - Yeah, the feature request is to generate the token for AAD user using a WIN32 API.
We use this for key based authentication (or) to retrieve user groups.

@matthewfcarlson
Copy link

matthewfcarlson commented Jun 13, 2020

That work around worked flawlessly :)
I'm very much looking forward to the real solution coming out

@heaths
Copy link
Author

heaths commented Jun 15, 2020

But the feature request will still require AAD authentication? Won't that still be a problem between domain-joined machines like my workstation back in the office and my AAD-joined laptop? Especially if the key changes since it's generated, or is that a one-time (or seldom, at most) generation?

@bagajjal
Copy link
Collaborator

@heaths - I didn't get your questions.

Password based authentication with AAD credential works now.

SSHD service runs as local system so it should be able to generate token for any user without their credentials. In case of public key authentication, after SSHD verifies the keys it will retrieve the token for the user and spawn the subsequent child processes in user context.

@heaths
Copy link
Author

heaths commented Jun 15, 2020

I don't want to use PasswordAuthentication. I have a Yubikey I use for MFA using PubkeyAuthentication, which is far more secure. What I wasn't clear on your reply (hence my question, which I'll try to clarify) is how what you described solves the problem.

Is the feature ask to generate a key pair on the fly based on AAD credentials, then send the public key to SSHD for authentication? Is a key pair generated once if it doesn't exist, or does this happen every time, or seldomly? How would we save the pub key to ~/.ssh/authorized_keys if it's generated?

If a future feature would resolve this somehow, great! But this seems like a bug-level fix now if it's the same problem I experienced on my previous team I helped fix: that LookupAccountName expects a domain, with AAD-joined accounts don't have, it seems, in a form that LookupAccountName expects (missing a matching domain RID, perhaps?).

@heaths heaths closed this as completed Jun 15, 2020
@heaths heaths reopened this Jun 15, 2020
@bagajjal
Copy link
Collaborator

@heaths - We are not dong any changes to key based authentication i.e., the keys are not generated on fly. User is responsible for generation of keys and storing them at respective places with right ACLs.

@maertendMSFT maertendMSFT added this to the vNext milestone Jul 9, 2020
@marvhen
Copy link

marvhen commented Aug 16, 2020

@bagajjal 's workaround isn't working for me...

I did stop-service sshd and then ran sshd.exe -ddd to see if I could tell what was going on and I was then able to connect using PubkeyAuthentication!

This makes me think it is is something to do with the account the service is started as.

@janegilring
Copy link

janegilring commented Aug 16, 2020

I'm running Windows 10 2004 (10.0.19041) and tried the workaround as well:

  1. In $env:programdata\ssh\sshd_config comment out all match block such as
    Match Group administrators
    AuthorizedKeysFile PROGRAMDATA/ssh/administrators_authorized_keys

  2. Any changes to sshd_config requires a sshd service restart
    net stop sshd
    net start sshd

  3. Always use the format
    ssh azuread\user@microsoft.com@ipaddress

Without any luck:

ssh.exe AzureAD\jan.egil.ring@contoso.com@10.0.1.203 -vvv -i C:\Users\adminjer.ssh\id_rsa

debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: RSA SHA256:2v6iH3yZUP3QnovEZ1vyL9SFJLf8ulReuia0uyKTSi4 C:\Users\adminjer\.ssh\id_rsa
debug3: send_pubkey_test
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: pkalg rsa-sha2-512 blen 535
debug2: input_userauth_pk_ok: fp SHA256:2v6iH3yZUP3QnovEZ1vyL9SFJLf8ulReuia0uyKTSi4
debug3: sign_and_send_pubkey: RSA SHA256:2v6iH3yZUP3QnovEZ1vyL9SFJLf8ulReuia0uyKTSi4
debug3: send packet: type 50
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to 10.0.1.203 ([10.0.1.203]:22).
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 no-more-sessions@openssh.com
debug3: send packet: type 80
debug1: Entering interactive session.
debug1: pledge: network
debug1: console supports the ansi parsing
debug3: Successfully set console output code page from:850 to 65001
debug3: Successfully set console input code page from:850 to 65001
debug3: recv - from CB ERROR:10054, io:0000020393DE5660
debug3: send packet: type 1
debug3: send - WSASend() ERROR:10054, io:0000020393DE5660
Connection reset by 10.0.1.203 port 22
debug3: Successfully set console output code page from 65001 to 850
debug3: Successfully set console input code page from 65001 to 850

Server side log (C:\ProgramData\ssh\logs\sshd.log):

24884 2020-08-16 21:55:45.099 Accepted publickey for AzureAD\jan.egil.ring@contoso.com from 10.0.1.22 port 59126 ssh2: RSA SHA256:2v6iH3yZUP3QnovEZ1vyL9SFJLf8ulReuia0uyKTSi4
24884 2020-08-16 21:55:45.099 debug1: monitor_child_preauth: AzureAD\jan.egil.ring@contoso.com has been authenticated by privileged process
24884 2020-08-16 21:55:45.099 debug3: mm_get_keystate: Waiting for new keys
24884 2020-08-16 21:55:45.099 debug3: mm_request_receive_expect entering: type 26
24884 2020-08-16 21:55:45.099 debug3: mm_request_receive entering
24884 2020-08-16 21:55:45.100 debug3: mm_get_keystate: GOT new keys
24884 2020-08-16 21:55:45.100 debug1: auth_activate_options: setting new authentication options [preauth]
24884 2020-08-16 21:55:45.100 debug2: userauth_pubkey: authenticated 1 pkalg rsa-sha2-512 [preauth]
24884 2020-08-16 21:55:45.100 debug3: send packet: type 52 [preauth]
24884 2020-08-16 21:55:45.100 debug3: mm_request_send entering: type 26 [preauth]
24884 2020-08-16 21:55:45.100 debug3: mm_send_keystate: Finished sending state [preauth]
24884 2020-08-16 21:55:45.111 debug1: monitor_read_log: child log fd closed
24884 2020-08-16 21:56:12.387 error: lookup_principal_name: User principal name lookup failed for user 'contoso\janring' (explicit: 1355, implicit: 1355)
24884 2020-08-16 21:56:12.390 debug1: generate_s4u_user_token: LsaLogonUser() failed. User 'contoso\janring' Status: 0xC0000062 SubStatus 0.
24884 2020-08-16 21:56:12.390 debug3: get_user_token - unable to generate token for user contoso\janring
24884 2020-08-16 21:56:39.657 error: lookup_principal_name: User principal name lookup failed for user 'contoso\janring' (explicit: 1355, implicit: 1355)
24884 2020-08-16 21:56:39.661 debug1: generate_s4u_user_token: LsaLogonUser() failed. User 'contoso\janring' Status: 0xC0000062 SubStatus 0.
24884 2020-08-16 21:56:39.661 error: get_user_token - unable to generate token on 2nd attempt for user contoso\janring
24884 2020-08-16 21:56:39.661 error: unable to get security token for user contoso\janring
24884 2020-08-16 21:56:39.662 fatal: fork of unprivileged child failed
24884 2020-08-16 21:56:39.662 debug1: do_cleanup

Any ETA for when Azure AD support for OpenSSH in Windows will become available? Is it likely to be released in the next Windows Feature release later this year? Or could it also come in a Cumulative Update?

@heaths
Copy link
Author

heaths commented Aug 17, 2020

@bagajjal sorry for the late reply, but having re-read the last few comments back and forth, you seemed to indicate that key-based authentication should work. That's exactly what doesn't. In the initial comment when opening this bug, I mentioned that I set PasswordAuthentication to no and have no desire to enable it. PubkeyAuthentication is far more secure, especially when used with MFA devices like my YubiKey. Even when using PubkeyAuthenciation, I still get the error in the subject.

As mentioned, I suspect this is because AAD doesn't actually have a domain, and LookupAccountName expects one. The machine is not domain-joined or non-domain-joined, but somewhere oddly in the middle from what I could tell when, on my previous team in Microsoft, we discovered a similar error with this same function based on user feedback and telemetry.

Have you tried the repro?

  1. Join machine to AAD
  2. Change sshd_config to disable PasswordAuthentication and make sure PubkeyAuthentication is enabled
  3. Either disable administrators_authorized_keys or just match against a group (the latter is what I always do - easier to maintain in Windows).
  4. Log in from a domain-joined or non-domain-joined (e.g. personal) machine.

This fails with the error in the subject.

@GongT
Copy link

GongT commented Aug 20, 2020

I got debug1: get_passwd: LookupAccountName() failed: 1332. too

It only fail when I run sshd as a service, login is ok when I run sshd.exe manually.

@glima
Copy link

glima commented Mar 2, 2021

Also facing this issue, very frustrating :(

@asheroto
Copy link

asheroto commented Mar 11, 2021

Revised: My original comment was targeted for a different audience and does not apply to this specific issue, but keeping the information for reference.

If you are facing public key authentication in general and are unsure if this issue is related, here's a link to gist that will confirm public key authentication is set up correctly.

@demdante
Copy link

demdante commented Mar 27, 2021

I got debug1: get_passwd: LookupAccountName() failed: 1332. too

It only fail when I run sshd as a service, login is ok when I run sshd.exe manually.

Having the exact same issue as described by @GongT . Very frustrating. All permissions correctly set on all files. Following sshd file:

# This is the sshd server system-wide configuration file.  See
# sshd_config(5) for more information.

# The strategy used for options in the default sshd_config shipped with
# OpenSSH is to specify options with their default value where
# possible, but leave them commented.  Uncommented options override the
# default value.

#Port 22
#AddressFamily any
#ListenAddress 0.0.0.0
#ListenAddress ::

#HostKey __PROGRAMDATA__/ssh/ssh_host_rsa_key
#HostKey __PROGRAMDATA__/ssh/ssh_host_dsa_key
#HostKey __PROGRAMDATA__/ssh/ssh_host_ecdsa_key
#HostKey __PROGRAMDATA__/ssh/ssh_host_ed25519_key

# Ciphers and keying
#RekeyLimit default none

# Logging
SyslogFacility LOCAL0
LogLevel DEBUG3

# Authentication:

#LoginGraceTime 2m
#PermitRootLogin prohibit-password
#StrictModes yes
#MaxAuthTries 6
#MaxSessions 10

PubkeyAuthentication yes

# The default is to check both .ssh/authorized_keys and .ssh/authorized_keys2
# but this is overridden so installations will only check .ssh/authorized_keys
AuthorizedKeysFile	.ssh/authorized_keys

#AuthorizedPrincipalsFile none

# For this to work you will also need host keys in %programData%/ssh/ssh_known_hosts
#HostbasedAuthentication no
# Change to yes if you don't trust ~/.ssh/known_hosts for
# HostbasedAuthentication
#IgnoreUserKnownHosts no
# Don't read the user's ~/.rhosts and ~/.shosts files
#IgnoreRhosts yes

# To disable tunneled clear text passwords, change to no here!
PasswordAuthentication yes
#PermitEmptyPasswords no

# GSSAPI options
#GSSAPIAuthentication no

AllowAgentForwarding yes
AllowTcpForwarding yes
#GatewayPorts no
PermitTTY yes
#PrintMotd yes
#PrintLastLog yes
#TCPKeepAlive yes
#UseLogin no
#PermitUserEnvironment no
#ClientAliveInterval 0
#ClientAliveCountMax 3
#UseDNS no
#PidFile /var/run/sshd.pid
#MaxStartups 10:30:100
#PermitTunnel no
#ChrootDirectory none
#VersionAddendum none

# no default banner path
#Banner none

# override default of no subsystems
Subsystem	sftp	sftp-server.exe

# Example of overriding settings on a per-user basis
#Match User anoncvs
#	AllowTcpForwarding no
#	PermitTTY no
#	ForceCommand cvs server

#Match Group administrators
#       AuthorizedKeysFile __PROGRAMDATA__/ssh/administrators_authorized_keys

And this is the generated debug log when attempting to connect via public key authentication (That means you, @asheroto):

4576 2021-03-27 23:42:05.729 debug2: fd 3 setting O_NONBLOCK
4576 2021-03-27 23:42:05.729 debug3: sock_set_v6only: set socket 3 IPV6_V6ONLY
4576 2021-03-27 23:42:05.729 debug1: Bind to port 22 on ::.
4576 2021-03-27 23:42:05.744 Server listening on :: port 22.
4576 2021-03-27 23:42:05.744 debug2: fd 4 setting O_NONBLOCK
4576 2021-03-27 23:42:05.744 debug1: Bind to port 22 on 0.0.0.0.
4576 2021-03-27 23:42:05.744 Server listening on 0.0.0.0 port 22.
4576 2021-03-27 23:42:27.916 debug3: fd 5 is not O_NONBLOCK
4576 2021-03-27 23:42:27.916 debug3: spawning "C:\\Program Files\\OpenSSH-Win64\\sshd.exe" -R
4576 2021-03-27 23:42:27.932 debug3: send_rexec_state: entering fd = 8 config len 303
4576 2021-03-27 23:42:27.932 debug3: ssh_msg_send: type 0
4576 2021-03-27 23:42:27.948 debug3: send_rexec_state: done
4336 2021-03-27 23:42:27.994 debug1: inetd sockets after dupping: 4, 4
4336 2021-03-27 23:42:27.994 Connection from 172.31.172.183 port 11382 on 10.5.197.196 port 22
4336 2021-03-27 23:42:27.994 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1
4336 2021-03-27 23:42:28.041 debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.1
4336 2021-03-27 23:42:28.041 debug1: match: OpenSSH_for_Windows_8.1 pat OpenSSH* compat 0x04000000
4336 2021-03-27 23:42:28.041 debug2: fd 4 setting O_NONBLOCK
4336 2021-03-27 23:42:28.073 debug3: spawning "C:\\Program Files\\OpenSSH-Win64\\sshd.exe" -y
4336 2021-03-27 23:42:28.088 debug2: Network child is on pid 9868
4336 2021-03-27 23:42:28.088 debug3: send_rexec_state: entering fd = 6 config len 303
4336 2021-03-27 23:42:28.088 debug3: ssh_msg_send: type 0
4336 2021-03-27 23:42:28.088 debug3: send_rexec_state: done
4336 2021-03-27 23:42:28.088 debug3: ssh_msg_send: type 0
4336 2021-03-27 23:42:28.088 debug3: ssh_msg_send: type 0
4336 2021-03-27 23:42:28.088 debug3: preauth child monitor started
4336 2021-03-27 23:42:28.119 debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
4336 2021-03-27 23:42:28.119 debug3: send packet: type 20 [preauth]
4336 2021-03-27 23:42:28.119 debug1: SSH2_MSG_KEXINIT sent [preauth]
4336 2021-03-27 23:42:28.119 debug3: receive packet: type 20 [preauth]
4336 2021-03-27 23:42:28.119 debug1: SSH2_MSG_KEXINIT received [preauth]
4336 2021-03-27 23:42:28.119 debug2: local server KEXINIT proposal [preauth]
4336 2021-03-27 23:42:28.119 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]
4336 2021-03-27 23:42:28.119 debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
4336 2021-03-27 23:42:28.119 debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
4336 2021-03-27 23:42:28.119 debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
4336 2021-03-27 23:42:28.119 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]
4336 2021-03-27 23:42:28.119 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]
4336 2021-03-27 23:42:28.119 debug2: compression ctos: none,zlib@openssh.com [preauth]
4336 2021-03-27 23:42:28.119 debug2: compression stoc: none,zlib@openssh.com [preauth]
4336 2021-03-27 23:42:28.119 debug2: languages ctos:  [preauth]
4336 2021-03-27 23:42:28.119 debug2: languages stoc:  [preauth]
4336 2021-03-27 23:42:28.119 debug2: first_kex_follows 0  [preauth]
4336 2021-03-27 23:42:28.119 debug2: reserved 0  [preauth]
4336 2021-03-27 23:42:28.119 debug2: peer client KEXINIT proposal [preauth]
4336 2021-03-27 23:42:28.119 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,ext-info-c [preauth]
4336 2021-03-27 23:42:28.119 debug2: host key algorithms: ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,ssh-ed25519-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
4336 2021-03-27 23:42:28.119 debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
4336 2021-03-27 23:42:28.119 debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
4336 2021-03-27 23:42:28.119 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]
4336 2021-03-27 23:42:28.119 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]
4336 2021-03-27 23:42:28.119 debug2: compression ctos: none,zlib@openssh.com,zlib [preauth]
4336 2021-03-27 23:42:28.119 debug2: compression stoc: none,zlib@openssh.com,zlib [preauth]
4336 2021-03-27 23:42:28.119 debug2: languages ctos:  [preauth]
4336 2021-03-27 23:42:28.119 debug2: languages stoc:  [preauth]
4336 2021-03-27 23:42:28.119 debug2: first_kex_follows 0  [preauth]
4336 2021-03-27 23:42:28.119 debug2: reserved 0  [preauth]
4336 2021-03-27 23:42:28.119 debug1: kex: algorithm: curve25519-sha256 [preauth]
4336 2021-03-27 23:42:28.119 debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth]
4336 2021-03-27 23:42:28.119 debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
4336 2021-03-27 23:42:28.119 debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
4336 2021-03-27 23:42:28.119 debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
4336 2021-03-27 23:42:28.307 debug3: receive packet: type 30 [preauth]
4336 2021-03-27 23:42:28.323 debug3: mm_sshkey_sign entering [preauth]
4336 2021-03-27 23:42:28.323 debug3: mm_request_send entering: type 6 [preauth]
4336 2021-03-27 23:42:28.323 debug3: mm_request_receive entering
4336 2021-03-27 23:42:28.323 debug3: monitor_read: checking request 6
4336 2021-03-27 23:42:28.323 debug3: mm_answer_sign
4336 2021-03-27 23:42:28.323 debug3: mm_answer_sign: KEX signature 000001FCC5F3E3B0(99)
4336 2021-03-27 23:42:28.323 debug3: mm_request_send entering: type 7
4336 2021-03-27 23:42:28.323 debug2: monitor_read: 6 used once, disabling now
4336 2021-03-27 23:42:28.323 debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
4336 2021-03-27 23:42:28.323 debug3: mm_request_receive_expect entering: type 7 [preauth]
4336 2021-03-27 23:42:28.323 debug3: mm_request_receive entering [preauth]
4336 2021-03-27 23:42:28.323 debug3: send packet: type 31 [preauth]
4336 2021-03-27 23:42:28.323 debug3: send packet: type 21 [preauth]
4336 2021-03-27 23:42:28.323 debug2: set_newkeys: mode 1 [preauth]
4336 2021-03-27 23:42:28.323 debug1: rekey out after 134217728 blocks [preauth]
4336 2021-03-27 23:42:28.323 debug1: SSH2_MSG_NEWKEYS sent [preauth]
4336 2021-03-27 23:42:28.323 debug1: Sending SSH2_MSG_EXT_INFO [preauth]
4336 2021-03-27 23:42:28.323 debug3: send packet: type 7 [preauth]
4336 2021-03-27 23:42:28.323 debug1: expecting SSH2_MSG_NEWKEYS [preauth]
4336 2021-03-27 23:42:28.494 debug3: receive packet: type 21 [preauth]
4336 2021-03-27 23:42:28.494 debug1: SSH2_MSG_NEWKEYS received [preauth]
4336 2021-03-27 23:42:28.494 debug2: set_newkeys: mode 0 [preauth]
4336 2021-03-27 23:42:28.494 debug1: rekey in after 134217728 blocks [preauth]
4336 2021-03-27 23:42:28.494 debug1: KEX done [preauth]
4336 2021-03-27 23:42:28.557 debug3: receive packet: type 5 [preauth]
4336 2021-03-27 23:42:28.557 debug3: send packet: type 6 [preauth]
4336 2021-03-27 23:42:28.573 debug3: receive packet: type 50 [preauth]
4336 2021-03-27 23:42:28.573 debug1: userauth-request for user galileo\\\\john.terry service ssh-connection method none [preauth]
4336 2021-03-27 23:42:28.573 debug1: attempt 0 failures 0 [preauth]
4336 2021-03-27 23:42:28.573 debug3: mm_getpwnamallow entering [preauth]
4336 2021-03-27 23:42:28.573 debug3: mm_request_send entering: type 8 [preauth]
4336 2021-03-27 23:42:28.573 debug3: mm_request_receive entering
4336 2021-03-27 23:42:28.573 debug3: monitor_read: checking request 8
4336 2021-03-27 23:42:28.573 debug3: mm_answer_pwnamallow
4336 2021-03-27 23:42:28.588 debug2: parse_server_config: config reprocess config len 303
4336 2021-03-27 23:42:28.588 debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
4336 2021-03-27 23:42:28.588 debug3: mm_request_send entering: type 9
4336 2021-03-27 23:42:28.588 debug2: monitor_read: 8 used once, disabling now
4336 2021-03-27 23:42:28.588 debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
4336 2021-03-27 23:42:28.588 debug3: mm_request_receive_expect entering: type 9 [preauth]
4336 2021-03-27 23:42:28.588 debug3: mm_request_receive entering [preauth]
4336 2021-03-27 23:42:28.588 debug2: input_userauth_request: setting up authctxt for galileo\\\\john.terry [preauth]
4336 2021-03-27 23:42:28.588 debug3: mm_inform_authserv entering [preauth]
4336 2021-03-27 23:42:28.588 debug3: mm_request_send entering: type 4 [preauth]
4336 2021-03-27 23:42:28.588 debug3: mm_request_receive entering
4336 2021-03-27 23:42:28.588 debug3: monitor_read: checking request 4
4336 2021-03-27 23:42:28.588 debug3: mm_answer_authserv: service=ssh-connection, style=
4336 2021-03-27 23:42:28.588 debug2: monitor_read: 4 used once, disabling now
4336 2021-03-27 23:42:28.588 debug2: input_userauth_request: try method none [preauth]
4336 2021-03-27 23:42:28.588 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
4336 2021-03-27 23:42:28.588 debug3: ensure_minimum_time_since: elapsed 15.611ms, delaying 2.876ms (requested 9.243ms) [preauth]
4336 2021-03-27 23:42:28.604 debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth]
4336 2021-03-27 23:42:28.604 debug3: send packet: type 51 [preauth]
4336 2021-03-27 23:42:28.619 debug3: receive packet: type 50 [preauth]
4336 2021-03-27 23:42:28.619 debug1: userauth-request for user galileo\\\\john.terry service ssh-connection method publickey [preauth]
4336 2021-03-27 23:42:28.619 debug1: attempt 1 failures 0 [preauth]
4336 2021-03-27 23:42:28.619 debug2: input_userauth_request: try method publickey [preauth]
4336 2021-03-27 23:42:28.635 debug2: userauth_pubkey: valid user galileo\\\\john.terry querying public key rsa-sha2-512 AAAAB3NzaC1yc2EAAAADAQABAAABAQDMaBcuB6WrShSv6cx6PMGRC01i8rDft673oXCa8+CQtSLKxHNoYd4bPTRM9/xuXJ6tU3G8AXHtaS4rgT4KLfH6q8gpuf/3hyUlmlDkIF8+hlE7Y+vjv5Jwqax1YyZeR0P/INZ1n+VpPc4hKejI1yJYKASZzOtyaivYeNQCzX1RxAp5rmGOSiA6u0CiBLriJE6ESpWH/A95lUyTjiVtg1S6NyFQ5JDV0VR1j3sWQCzLhPEboJwf8ZNqk+jXdhBZ5FeDrOO+ziFOT1Vu6AZ/lDJXRSyLvHpyaNAGszLJQ7Mg2ae+u2GZD59k6jIeKhLy8qf0tANOMiB9wbywLXAJGPZ7 [preauth]
4336 2021-03-27 23:42:28.635 debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:EpMHrsviixg9YHynwnM3kvwF1BoVEto9ktt0l4q+AmE [preauth]
4336 2021-03-27 23:42:28.635 debug3: mm_key_allowed entering [preauth]
4336 2021-03-27 23:42:28.635 debug3: mm_request_send entering: type 22 [preauth]
4336 2021-03-27 23:42:28.635 debug3: mm_request_receive entering
4336 2021-03-27 23:42:28.635 debug3: monitor_read: checking request 22
4336 2021-03-27 23:42:28.635 debug3: mm_answer_keyallowed entering
4336 2021-03-27 23:42:28.635 debug3: mm_answer_keyallowed: key_from_blob: 000001FCC5F704D0
4336 2021-03-27 23:42:28.635 debug1: trying public key file C:\\Users\\john.terry\\.ssh/authorized_keys
4336 2021-03-27 23:42:28.635 debug1: C:\\Users\\john.terry\\.ssh/authorized_keys:1: matching key found: RSA SHA256:EpMHrsviixg9YHynwnM3kvwF1BoVEto9ktt0l4q+AmE
4336 2021-03-27 23:42:28.635 debug1: C:\\Users\\john.terry\\.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
4336 2021-03-27 23:42:28.635 Accepted key RSA SHA256:EpMHrsviixg9YHynwnM3kvwF1BoVEto9ktt0l4q+AmE found at C:\\Users\\john.terry\\.ssh/authorized_keys:1
4336 2021-03-27 23:42:28.635 debug3: mm_answer_keyallowed: publickey authentication test: RSA key is allowed
4336 2021-03-27 23:42:28.635 debug3: mm_request_send entering: type 23
4336 2021-03-27 23:42:28.635 debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
4336 2021-03-27 23:42:28.635 debug3: mm_request_receive_expect entering: type 23 [preauth]
4336 2021-03-27 23:42:28.635 debug3: mm_request_receive entering [preauth]
4336 2021-03-27 23:42:28.635 debug3: send packet: type 60 [preauth]
4336 2021-03-27 23:42:28.635 debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth]
4336 2021-03-27 23:42:28.635 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
4336 2021-03-27 23:42:28.635 debug3: ensure_minimum_time_since: elapsed 15.613ms, delaying 2.874ms (requested 9.243ms) [preauth]
4336 2021-03-27 23:42:28.651 Postponed publickey for galileo\\\\john.terry from 172.31.172.183 port 11382 ssh2 [preauth]
4336 2021-03-27 23:42:28.666 debug3: receive packet: type 50 [preauth]
4336 2021-03-27 23:42:28.666 debug1: userauth-request for user galileo\\\\john.terry service ssh-connection method publickey [preauth]
4336 2021-03-27 23:42:28.666 debug1: attempt 2 failures 0 [preauth]
4336 2021-03-27 23:42:28.666 debug2: input_userauth_request: try method publickey [preauth]
4336 2021-03-27 23:42:28.666 debug2: userauth_pubkey: valid user galileo\\\\john.terry attempting public key rsa-sha2-512 AAAAB3NzaC1yc2EAAAADAQABAAABAQDMaBcuB6WrShSv6cx6PMGRC01i8rDft673oXCa8+CQtSLKxHNoYd4bPTRM9/xuXJ6tU3G8AXHtaS4rgT4KLfH6q8gpuf/3hyUlmlDkIF8+hlE7Y+vjv5Jwqax1YyZeR0P/INZ1n+VpPc4hKejI1yJYKASZzOtyaivYeNQCzX1RxAp5rmGOSiA6u0CiBLriJE6ESpWH/A95lUyTjiVtg1S6NyFQ5JDV0VR1j3sWQCzLhPEboJwf8ZNqk+jXdhBZ5FeDrOO+ziFOT1Vu6AZ/lDJXRSyLvHpyaNAGszLJQ7Mg2ae+u2GZD59k6jIeKhLy8qf0tANOMiB9wbywLXAJGPZ7 [preauth]
4336 2021-03-27 23:42:28.666 debug3: userauth_pubkey: have rsa-sha2-512 signature for RSA SHA256:EpMHrsviixg9YHynwnM3kvwF1BoVEto9ktt0l4q+AmE [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_key_allowed entering [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_request_send entering: type 22 [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_request_receive entering
4336 2021-03-27 23:42:28.666 debug3: monitor_read: checking request 22
4336 2021-03-27 23:42:28.666 debug3: mm_answer_keyallowed entering
4336 2021-03-27 23:42:28.666 debug3: mm_answer_keyallowed: key_from_blob: 000001FCC5F703B0
4336 2021-03-27 23:42:28.666 debug1: trying public key file C:\\Users\\john.terry\\.ssh/authorized_keys
4336 2021-03-27 23:42:28.666 debug1: C:\\Users\\john.terry\\.ssh/authorized_keys:1: matching key found: RSA SHA256:EpMHrsviixg9YHynwnM3kvwF1BoVEto9ktt0l4q+AmE
4336 2021-03-27 23:42:28.666 debug1: C:\\Users\\john.terry\\.ssh/authorized_keys:1: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
4336 2021-03-27 23:42:28.666 Accepted key RSA SHA256:EpMHrsviixg9YHynwnM3kvwF1BoVEto9ktt0l4q+AmE found at C:\\Users\\john.terry\\.ssh/authorized_keys:1
4336 2021-03-27 23:42:28.666 debug3: mm_answer_keyallowed: publickey authentication: RSA key is allowed
4336 2021-03-27 23:42:28.666 debug3: mm_request_send entering: type 23
4336 2021-03-27 23:42:28.666 debug3: mm_key_allowed: waiting for MONITOR_ANS_KEYALLOWED [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_request_receive_expect entering: type 23 [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_request_receive entering [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_sshkey_verify entering [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_request_send entering: type 24 [preauth]
4336 2021-03-27 23:42:28.666 debug3: mm_request_receive entering
4336 2021-03-27 23:42:28.666 debug3: monitor_read: checking request 24
4336 2021-03-27 23:42:28.666 debug3: mm_answer_keyverify: publickey 000001FCC5F6F990 signature verified
4336 2021-03-27 23:42:28.666 debug1: auth_activate_options: setting new authentication options
4336 2021-03-27 23:42:28.666 debug3: mm_request_send entering: type 25
4336 2021-03-27 23:42:28.666 Accepted publickey for galileo\\john.terry from 172.31.172.183 port 11382 ssh2: RSA SHA256:EpMHrsviixg9YHynwnM3kvwF1BoVEto9ktt0l4q+AmE
4336 2021-03-27 23:42:28.666 debug1: monitor_child_preauth: galileo\\john.terry has been authenticated by privileged process
4336 2021-03-27 23:42:28.666 debug3: mm_get_keystate: Waiting for new keys
4336 2021-03-27 23:42:28.666 debug3: mm_request_receive_expect entering: type 26
4336 2021-03-27 23:42:28.666 debug3: mm_request_receive entering
4336 2021-03-27 23:42:28.682 debug3: mm_get_keystate: GOT new keys
4336 2021-03-27 23:42:28.682 debug3: mm_sshkey_verify: waiting for MONITOR_ANS_KEYVERIFY [preauth]
4336 2021-03-27 23:42:28.682 debug3: mm_request_receive_expect entering: type 25 [preauth]
4336 2021-03-27 23:42:28.682 debug3: mm_request_receive entering [preauth]
4336 2021-03-27 23:42:28.682 debug1: auth_activate_options: setting new authentication options [preauth]
4336 2021-03-27 23:42:28.682 debug2: userauth_pubkey: authenticated 1 pkalg rsa-sha2-512 [preauth]
4336 2021-03-27 23:42:28.682 debug3: user_specific_delay: user specific delay 0.000ms [preauth]
4336 2021-03-27 23:42:28.682 debug3: ensure_minimum_time_since: elapsed 0.000ms, delaying 9.243ms (requested 9.243ms) [preauth]
4336 2021-03-27 23:42:28.682 debug3: send packet: type 52 [preauth]
4336 2021-03-27 23:42:28.682 debug3: mm_request_send entering: type 26 [preauth]
4336 2021-03-27 23:42:28.682 debug3: mm_send_keystate: Finished sending state [preauth]
4336 2021-03-27 23:42:28.682 debug1: monitor_read_log: child log fd closed
4336 2021-03-27 23:42:28.713 debug3: lookup_principal_name: Successfully discovered explicit principal name: 'galileo\\john.terry'=>'john.terry@travelport.com'
4336 2021-03-27 23:42:28.729 debug1: generate_s4u_user_token: LsaLogonUser() failed. User 'galileo\\john.terry' Status: 0xC000006D SubStatus 0.
4336 2021-03-27 23:42:28.729 debug3: get_user_token - unable to generate token for user galileo\\john.terry
4336 2021-03-27 23:42:28.838 debug3: lookup_principal_name: Successfully discovered explicit principal name: 'galileo\\john.terry'=>'john.terry@travelport.com'
4336 2021-03-27 23:42:28.838 debug1: generate_s4u_user_token: LsaLogonUser() failed. User 'galileo\\john.terry' Status: 0xC000006D SubStatus 0.
4336 2021-03-27 23:42:28.838 error: get_user_token - unable to generate token on 2nd attempt for user galileo\\john.terry
4336 2021-03-27 23:42:28.838 error: unable to get security token for user galileo\\john.terry
4336 2021-03-27 23:42:28.838 fatal: fork of unprivileged child failed
4336 2021-03-27 23:42:28.838 debug1: do_cleanup

@demdante
Copy link

demdante commented Mar 27, 2021

Also, as for @asheroto , your solution really isn't a solution if it requires disabling password authentication. Public key authentication should be able to work alongside password authentication, not at its expense. Afraid that solution is wholly inadequate.

@asheroto
Copy link

asheroto commented Mar 27, 2021

My comment was targeted for ensuring that public key authentication works. Password authentication, at least with the settings I described, works fine alongside public key authentication so long as you enable it in your config.

Are you saying you're still facing an issue authenticating even if enabled?

With public+password enabled I still receive the error described by the original poster, even though both forms of authentication are working.

@demdante
Copy link

demdante commented Mar 27, 2021

@asheroto I also followed your instructions, and it doesn't work. Feel free to see the debug log posted above. There are also reports throughout this issue that public key authentication does not work if you encounter this particular issue:

@bagajjal sorry for the late reply, but having re-read the last few comments back and forth, you seemed to indicate that key-based authentication should work. That's exactly what doesn't. In the initial comment when opening this bug, I mentioned that I set PasswordAuthentication to no and have no desire to enable it. PubkeyAuthentication is far more secure, especially when used with MFA devices like my YubiKey. Even when using PubkeyAuthenciation, I still get the error in the subject.

As mentioned, I suspect this is because AAD doesn't actually have a domain, and LookupAccountName expects one. The machine is not domain-joined or non-domain-joined, but somewhere oddly in the middle from what I could tell when, on my previous team in Microsoft, we discovered a similar error with this same function based on user feedback and telemetry.

Have you tried the repro?

1. Join machine to AAD

2. Change sshd_config to disable `PasswordAuthentication` and make sure `PubkeyAuthentication` is enabled

3. Either disable administrators_authorized_keys or just match against a group (the latter is what I always do - easier to maintain in Windows).

4. Log in from a domain-joined or non-domain-joined (e.g. personal) machine.

This fails with the error in the subject.

@heaths - There is a proposed feature request to ssh using AAD credentials. Windows AAD team is supposed to make this change in next semister.

However, I have a workaround.

1. In $env:programdata\ssh\sshd_config comment out all match block such as
   Match Group administrators
   AuthorizedKeysFile **PROGRAMDATA**/ssh/administrators_authorized_keys

2. Any changes to sshd_config requires a sshd service restart
   net stop sshd
   net start sshd

3. Always use the format
   ssh azuread\user@microsoft.com@ipaddress

Please note only password based authentication will work.

So, if you were able to authenticate with public key authentication, you do not have the same issue that everyone else has.

@asheroto
Copy link

@demdante

No worries, I revised my comment with a link for reference, but explained that it was mistargeted as it doesn't specifically apply to this issue.

Thanks for letting me know

@glima
Copy link

glima commented Mar 28, 2021 via email

@heaths
Copy link
Author

heaths commented Mar 29, 2021

All solutions here

They're also not solutions, but work arounds that don't solve the underlying problem: keeping password authentication disabled while relying on hardware security keys (MFA: something you have, plus something you know - e.g. the PIN on the key).

The original bug with LookupAccountName() can be solved. We had to work around this same issue in the Visual Studio installer when setting up scheduled tasks for updates for machines that were joined to an AAD.

@bagajjal
Copy link
Collaborator

@heaths - Please refer to my comment #1543 (comment).

@bagajjal
Copy link
Collaborator

Related to
#1543

@bagajjal
Copy link
Collaborator

bagajjal commented May 5, 2021

Closing this issue. Created a new issue for AAD support, #1787

@bagajjal bagajjal closed this as completed May 5, 2021
@bagajjal
Copy link
Collaborator

bagajjal commented May 5, 2021

For future reference, the error "LookupAccountName() failed: 1332" can happen because of multiple reasons. Please don't comment on this issue. Request you to open a new issue.

@chen-chao
Copy link

@bagajjal The password based authentication works for me. Thanks for the workaround!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests