Hi,
I have a problem using the ssh client program that comes with Windows
10, which I am going to describe below. Maybe someone on the list can
provide advice on how to tackle this.
My setup consist of a Linux (Fedora 38) host acting as an ssh sever, and
several Linux clients (also Fedora 38). My primary goal was to create a
setup that provides maximum security. To achieve this, I implemented a
two-step authentication scheme consisting of hostbased authentication in
step one, then publickey authentication of the user in step two. I also
disabled known_hosts updates, all host keys are in /etc/ssh_known_hosts.
This all works just fine, as long as I only connect from the Linux
clients. Now I wanted to add a Windows 10 machine, and I wanted to use
the ssh client that it provides. So far I have had no success. Here is a
server-side log produced at debug level 3:
Okt 18 21:15:17 sarkovy systemd[1]: ssh-host-keys-migration.service -
Update OpenSSH host key permissions was skipped because of an unmet
condition check (ConditionPathExists=!/var/lib/.ssh-host-keys-migration).
Okt 18 21:15:17 sarkovy systemd[1]: Started
sshd@37-192.168.0.1:22-192.168.0.6:51154.service - OpenSSH
per-connection server daemon (192.168.0.6:51154).
Okt 18 21:15:17 sarkovy audit[1]: SERVICE_START pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=sshd@37-192.168.0.1:22-192.168.0.6:51154 comm="systemd"
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Okt 18 21:15:17 sarkovy audit[229367]: CRYPTO_KEY_USER pid=229367 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server
fp=SHA256:04:38:a5:ab:d0:22:05:fe:b6:7c:59:ae:15:65:a5:7b:ff:5a:1b:8a:fb:41:41:d9:e2:14:65:12:4b:4e:b8:0b
direction=? spid=229367 suid=0 exe="/usr/sbin/sshd" hostname=?
addr=192.168.0.6 terminal=? res=success'
Okt 18 21:15:17 sarkovy audit[229366]: CRYPTO_SESSION pid=229366 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start
direction=from-server cipher=chacha20-poly1305@xxxxxxxxxxx ksize=512
mac=<implicit> pfs=curve25519-sha256 spid=229367 suid=74 rport=51154
laddr=192.168.0.1 lport=22 exe="/usr/sbin/sshd" hostname=?
addr=192.168.0.6 terminal=? res=success'
Okt 18 21:15:17 sarkovy audit[229366]: CRYPTO_SESSION pid=229366 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=start
direction=from-client cipher=chacha20-poly1305@xxxxxxxxxxx ksize=512
mac=<implicit> pfs=curve25519-sha256 spid=229367 suid=74 rport=51154
laddr=192.168.0.1 lport=22 exe="/usr/sbin/sshd" hostname=?
addr=192.168.0.6 terminal=? res=success'
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: auth2_setup_methods_lists:
checking methods
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: authentication methods
list 0: hostbased,publickey
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_answer_pwnamallow:
sending MONITOR_ANS_PWNAM: 1
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_send: entering,
type 9
Okt 18 21:15:17 sarkovy sshd[229366]: debug2: monitor_read: 8 used once,
disabling now
Okt 18 21:15:17 sarkovy sshd[229366]: debug2: input_userauth_request:
setting up authctxt for thomas [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_start_pam entering
[preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_send: entering,
type 100 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_inform_authserv:
entering [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_send: entering,
type 4 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_inform_authrole:
entering [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_send: entering,
type 80 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: auth2_setup_methods_lists:
checking methods [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: authentication methods
list 0: hostbased,publickey [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: authmethod_lookup: method
none not allowed by AuthenticationMethods [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: user_specific_delay: user
specific delay 0.000ms [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: ensure_minimum_time_since:
elapsed 2.145ms, delaying 3.855ms (requested 6.000ms) [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive: entering
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: monitor_read: checking
request 100
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: PAM: initializing for "thomas"
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: PAM: setting PAM_RHOST to
"192.168.0.6"
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: PAM: setting PAM_TTY to "ssh"
Okt 18 21:15:17 sarkovy sshd[229366]: debug2: monitor_read: 100 used
once, disabling now
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive: entering
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: monitor_read: checking
request 4
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_answer_authserv:
service=ssh-connection, style=
Okt 18 21:15:17 sarkovy sshd[229366]: debug2: monitor_read: 4 used once,
disabling now
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive: entering
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: monitor_read: checking
request 80
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_answer_authrole: role=
Okt 18 21:15:17 sarkovy sshd[229366]: debug2: monitor_read: 80 used
once, disabling now
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: userauth_finish: failure
partial=0 next methods="hostbased" [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: send packet: type 51 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_send: entering,
type 122 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive_expect:
entering, type 123 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive:
entering [preauth]
Okt 18 21:15:17 sarkovy audit[229366]: CRYPTO_KEY_USER pid=229366 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy
kind=session fp=? direction=both spid=229367 suid=74 rport=51154
laddr=192.168.0.1 lport=22 exe="/usr/sbin/sshd" hostname=?
addr=192.168.0.6 terminal=? res=success'
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive: entering
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: monitor_read: checking
request 122
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_send: entering,
type 123
Okt 18 21:15:17 sarkovy audit[229366]: CRYPTO_KEY_USER pid=229366 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server
fp=SHA256:04:38:a5:ab:d0:22:05:fe:b6:7c:59:ae:15:65:a5:7b:ff:5a:1b:8a:fb:41:41:d9:e2:14:65:12:4b:4e:b8:0b
direction=? spid=229367 suid=74 exe="/usr/sbin/sshd" hostname=?
addr=192.168.0.6 terminal=? res=success'
Okt 18 21:15:17 sarkovy sshd[229366]: Connection reset by authenticating
user thomas 192.168.0.6 port 51154 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: do_cleanup [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: PAM: sshpam_thread_cleanup
entering [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_send: entering,
type 124 [preauth]
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive: entering
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: monitor_read: checking
request 124
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: monitor_read_log: child
log fd closed
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: mm_request_receive: entering
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: do_cleanup
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: PAM: cleanup
Okt 18 21:15:17 sarkovy audit[229366]: USER_ERR pid=229366 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=PAM:bad_ident
grantors=? acct="?" exe="/usr/sbin/sshd" hostname=192.168.0.6
addr=192.168.0.6 terminal=ssh res=failed'
Okt 18 21:15:17 sarkovy sshd[229366]: debug3: PAM: sshpam_thread_cleanup
entering
Okt 18 21:15:17 sarkovy sshd[229366]: debug1: Killing privsep child 229367
Okt 18 21:15:17 sarkovy audit[229366]: CRYPTO_KEY_USER pid=229366 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=destroy kind=server
fp=SHA256:04:38:a5:ab:d0:22:05:fe:b6:7c:59:ae:15:65:a5:7b:ff:5a:1b:8a:fb:41:41:d9:e2:14:65:12:4b:4e:b8:0b
direction=? spid=229366 suid=0 exe="/usr/sbin/sshd" hostname=?
addr=192.168.0.6 terminal=? res=success'
Okt 18 21:15:17 sarkovy audit[229366]: USER_LOGIN pid=229366 uid=0
auid=4294967295 ses=4294967295
subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=login acct="thomas"
exe="/usr/sbin/sshd" hostname=? addr=192.168.0.6 terminal=ssh res=failed'
Okt 18 21:15:17 sarkovy systemd[1]:
sshd@37-192.168.0.1:22-192.168.0.6:51154.service: Deactivated successfully.
Okt 18 21:15:17 sarkovy audit[1]: SERVICE_STOP pid=1 uid=0
auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0
msg='unit=sshd@37-192.168.0.1:22-192.168.0.6:51154 comm="systemd"
Here's what the client side log looks like:
OpenSSH_for_Windows_8.1p1, LibreSSL 3.0.2
debug1: Reading configuration data __PROGRAMDATA__\\ssh/ssh_config
debug2: resolving "sarkovy" port 22
debug2: ssh_connect_direct
debug1: Connecting to sarkovy [192.168.0.1] port 22.
debug1: Connection established.
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_rsa type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_rsa-cert
type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_dsa type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_dsa-cert
type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_ecdsa type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_ecdsa-cert
type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_ed25519
type -1
debug1: identity file C:\\Users\\Thomas
K\303\266ller/.ssh/id_ed25519-cert type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_xmss type -1
debug1: identity file C:\\Users\\Thomas K\303\266ller/.ssh/id_xmss-cert
type -1
debug1: Local version string SSH-2.0-OpenSSH_for_Windows_8.1
debug1: Remote protocol version 2.0, remote software version OpenSSH_9.0
debug1: match: OpenSSH_9.0 pat OpenSSH* compat 0x04000000
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to sarkovy:22 as 'thomas'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
debug2: KEX algorithms:
curve25519-sha256,curve25519-sha256@xxxxxxxxxx,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
debug2: host key algorithms:
ssh-ed25519-cert-v01@xxxxxxxxxxx,ssh-ed25519,ecdsa-sha2-nistp256-cert-v01@xxxxxxxxxxx,ecdsa-sha2-nistp384-cert-v01@xxxxxxxxxxx,ecdsa-sha2-nistp521-cert-v01@xxxxxxxxxxx,rsa-sha2-512-cert-v01@xxxxxxxxxxx,rsa-sha2-256-cert-v01@xxxxxxxxxxx,ssh-rsa-cert-v01@xxxxxxxxxxx,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug2: ciphers ctos:
chacha20-poly1305@xxxxxxxxxxx,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@xxxxxxxxxxx,aes256-gcm@xxxxxxxxxxx
debug2: ciphers stoc:
chacha20-poly1305@xxxxxxxxxxx,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@xxxxxxxxxxx,aes256-gcm@xxxxxxxxxxx
debug2: MACs ctos:
umac-64-etm@xxxxxxxxxxx,umac-128-etm@xxxxxxxxxxx,hmac-sha2-256-etm@xxxxxxxxxxx,hmac-sha2-512-etm@xxxxxxxxxxx,hmac-sha1-etm@xxxxxxxxxxx,umac-64@xxxxxxxxxxx,umac-128@xxxxxxxxxxx,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: MACs stoc:
umac-64-etm@xxxxxxxxxxx,umac-128-etm@xxxxxxxxxxx,hmac-sha2-256-etm@xxxxxxxxxxx,hmac-sha2-512-etm@xxxxxxxxxxx,hmac-sha1-etm@xxxxxxxxxxx,umac-64@xxxxxxxxxxx,umac-128@xxxxxxxxxxx,hmac-sha2-256,hmac-sha2-512,hmac-sha1
debug2: compression ctos: none,zlib@xxxxxxxxxxx,zlib
debug2: compression stoc: none,zlib@xxxxxxxxxxx,zlib
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug2: peer server KEXINIT proposal
debug2: KEX algorithms:
curve25519-sha256,curve25519-sha256@xxxxxxxxxx,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group16-sha512,diffie-hellman-group18-sha512
debug2: host key algorithms:
rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
debug2: ciphers ctos:
aes256-gcm@xxxxxxxxxxx,chacha20-poly1305@xxxxxxxxxxx,aes256-ctr,aes128-gcm@xxxxxxxxxxx,aes128-ctr
debug2: ciphers stoc:
aes256-gcm@xxxxxxxxxxx,chacha20-poly1305@xxxxxxxxxxx,aes256-ctr,aes128-gcm@xxxxxxxxxxx,aes128-ctr
debug2: MACs ctos:
hmac-sha2-256-etm@xxxxxxxxxxx,hmac-sha1-etm@xxxxxxxxxxx,umac-128-etm@xxxxxxxxxxx,hmac-sha2-512-etm@xxxxxxxxxxx,hmac-sha2-256,hmac-sha1,umac-128@xxxxxxxxxxx,hmac-sha2-512
debug2: MACs stoc:
hmac-sha2-256-etm@xxxxxxxxxxx,hmac-sha1-etm@xxxxxxxxxxx,umac-128-etm@xxxxxxxxxxx,hmac-sha2-512-etm@xxxxxxxxxxx,hmac-sha2-256,hmac-sha1,umac-128@xxxxxxxxxxx,hmac-sha2-512
debug2: compression ctos: none,zlib@xxxxxxxxxxx
debug2: compression stoc: none,zlib@xxxxxxxxxxx
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: chacha20-poly1305@xxxxxxxxxxx MAC:
<implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305@xxxxxxxxxxx MAC:
<implicit> compression: none
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ssh-ed25519
SHA256:BDilq9AiBf62fFmuFWWle/9aG4r7QUHZ4hRlEktOuAs
debug1: Host 'sarkovy' is known and matches the ED25519 host key.
debug1: Found key in __PROGRAMDATA__\\ssh/ssh_known_hosts:1
debug2: set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug2: set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug1: pubkey_prepare: ssh_get_authentication_socket: No such file or
directory
debug1: Will attempt key: C:\\Users\\Thomas K\303\266ller/.ssh/id_rsa
debug1: Will attempt key: C:\\Users\\Thomas K\303\266ller/.ssh/id_dsa
debug1: Will attempt key: C:\\Users\\Thomas K\303\266ller/.ssh/id_ecdsa
debug1: Will attempt key: C:\\Users\\Thomas K\303\266ller/.ssh/id_ed25519
debug1: Will attempt key: C:\\Users\\Thomas K\303\266ller/.ssh/id_xmss
debug2: pubkey_prepare: done
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info:
server-sig-algs=<ssh-ed25519,sk-ssh-ed25519@xxxxxxxxxxx,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@xxxxxxxxxxx,webauthn-sk-ecdsa-sha2-nistp256@xxxxxxxxxxx>
debug1: kex_input_ext_info: publickey-hostbound@xxxxxxxxxxx (unrecognised)
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: hostbased
debug1: Next authentication method: hostbased
debug1: No more client hostkeys for hostbased authentication.
debug2: we did not send a packet, disable method
debug1: No more authentication methods to try.
thomas@sarkovy: Permission denied (hostbased).
I also tried to compare these logs to the ones produced by a successful
connection from one of my Linux clients, but have been unable to
identify the source of the problem. Here's the config file used by the
Windows client. It is mostly identical to the one used by the Linux
clients, except for the two commented-out lines that the Windows client
complained about.
AddKeysToAgent no
AddressFamily any
EnableSSHKeysign yes
ForwardX11Trusted no
#HostbasedAcceptedAlgorithms ssh-ed25519,ssh-ed25519-cert-v01@xxxxxxxxxxx
HostbasedAuthentication yes
KbdInteractiveAuthentication no
PermitLocalCommand yes
#PubkeyAcceptedAlgorithms ssh-ed25519,ssh-ed25519-cert-v01@xxxxxxxxxxx
PubkeyAuthentication yes
RequestTTY auto
StrictHostKeyChecking yes
Tunnel no
UpdateHostKeys no
Any help or advice would be greatly appreciated!
Thomas
_______________________________________________
openssh-unix-dev mailing list
openssh-unix-dev@xxxxxxxxxxx
https://lists.mindrot.org/mailman/listinfo/openssh-unix-dev
