search

PowerShell / Win32-OpenSSH

Win32 port of OpenSSH
7.39k stars 759 forks source link

Key generated is not considered by ssh when connecting to server #1387

Closed eliassal closed 4 years ago

eliassal commented 5 years ago

"OpenSSH for Windows" version 7.7.2.2

Server OperatingSystem Win 2019

Client OperatingSystem win 10 64 bit and Centos 7 What is failing Keys are not recognized and password always requested Expected output when generating a Key with ssh-keygen on client machines or server, transfering it (copying content of .pub file to authorized_keys) to server from client or to client from server , then trying to ssh from client or server, normally it should not ask for password which is not the case, always asking for password Actual output server always asking for password

manojampalam commented 5 years ago

Follow trouble shooting steps at https://github.com/PowerShell/Win32-OpenSSH/wiki/Troubleshooting-Steps

If you are an admin, see if this helps: https://github.com/PowerShell/Win32-OpenSSH/wiki/sshd_config#authorizedkeysfile

eliassal commented 5 years ago

Manoj, I followed those instructions. First of all, what is interesting is that I can Enter-PSSession from the win 2k19 sever to Centos but not from Centos to win 2k19. So I ran

sshd -ddd

on win2k19 then switch to centos box, issued

Enter-PSSession -HostName 192.168.1.70 -SSHTransport -UserName salam@salam

Here is the output on the win 2k19 (I can understand that theres is authentication error but not able to find why), thanks for your help

debug2: load_server_config: filename PROGRAMDATA\ssh/sshd_config debug2: load_server_config: done config len = 331 debug2: parse_server_config: config PROGRAMDATA\ssh/sshd_config len 331 debug3: PROGRAMDATA\ssh/sshd_config:24 setting SyslogFacility LOCAL0 debug3: PROGRAMDATA\ssh/sshd_config:25 setting LogLevel DEBUG3 debug3: PROGRAMDATA\ssh/sshd_config:35 setting PubkeyAuthentication yes debug3: PROGRAMDATA\ssh/sshd_config:39 setting AuthorizedKeysFile .ssh/authorized_keys debug3: PROGRAMDATA\ssh/sshd_config:52 setting PasswordAuthentication yes debug3: PROGRAMDATA\ssh/sshd_config:77 setting Subsystem sftp sftp-server.exe debug3: PROGRAMDATA\ssh/sshd_config:78 setting Subsystem powershell c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile debug1: sshd version OpenSSH_for_Windows_7.7, LibreSSL 2.6.5 debug1: private host key #0: ssh-rsa SHA256:u66cloJQDc9UQ82WC/K1pldqeoayFGK1R6pRF6qgAO0 debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:OWPsQuxC6bO11y5LUHT9zxLafbl0DzEUttbzCBwOwjE debug1: private host key #2: ssh-ed25519 SHA256:FXvsJQwaNJqK67d08jNjKOjNYXmsJs6QxDvHBjkLcmQ debug1: rexec_argv[0]='C:\Windows\System32\OpenSSH\sshd.exe' debug1: rexec_argv[1]='-ddd' debug2: fd 3 setting O_NONBLOCK debug3: sock_set_v6only: set socket 3 IPV6_V6ONLY debug1: Bind to port 22 on ::. Server listening on :: port 22. debug2: fd 4 setting O_NONBLOCK debug1: Bind to port 22 on 0.0.0.0. Server listening on 0.0.0.0 port 22. 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 331 debug3: ssh_msg_send: type 0 debug3: send_rexec_state: done Connection from 192.168.2.12 port 41647 on 192.168.1.70 port 22 debug1: Client protocol version 2.0; client software version OpenSSH_7.4 debug1: match: OpenSSH_7.4 pat OpenSSH* compat 0x04000000 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_7.7 debug2: fd 5 setting O_NONBLOCK debug3: spawning "C:\Windows\System32\OpenSSH\sshd.exe" "-ddd" "-y" debug2: Network child is on pid 7372 debug3: recv_rexec_state: entering fd = 3 debug3: send_rexec_state: entering fd = 4 config len 331 debug3: ssh_msg_recv entering debug3: ssh_msg_send: type 0 debug3: recv_rexec_state: done debug3: send_rexec_state: done debug2: parse_server_config: config PROGRAMDATA\ssh/sshd_config len 331 debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:24 setting SyslogFacility LOCAL0 debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:25 setting LogLevel DEBUG3 debug3: preauth child monitor started debug3: PROGRAMDATA\ssh/sshd_config:35 setting PubkeyAuthentication yes debug3: PROGRAMDATA\ssh/sshd_config:39 setting AuthorizedKeysFile .ssh/authorized_keys debug3: PROGRAMDATA\ssh/sshd_config:52 setting PasswordAuthentication yes debug3: PROGRAMDATA\ssh/sshd_config:77 setting Subsystem sftp sftp-server.exe debug3: PROGRAMDATA\ssh/sshd_config:78 setting Subsystem powershell c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile debug1: sshd version OpenSSH_for_Windows_7.7, LibreSSL 2.6.5 debug3: ssh_msg_recv entering debug3: ssh_msg_recv entering debug2: fd 5 setting O_NONBLOCK debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug3: send packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT sent [preauth] debug3: receive packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT received [preauth] debug2: local server KEXINIT proposal [preauth] debug2: KEX algorithms: curve25519-sha256,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] debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 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] 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] 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: 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,diffie-hellman-group1-sha1,ext-info-c [preauth] 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-dss-cert-v01@openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-dss [preauth] debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth] debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth] 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] 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] debug2: compression ctos: none,zlib@openssh.com,zlib [preauth] debug2: compression stoc: none,zlib@openssh.com,zlib [preauth] debug2: languages ctos: [preauth] debug2: languages stoc: [preauth] debug2: first_kex_follows 0 [preauth] debug2: reserved 0 [preauth] debug1: kex: algorithm: curve25519-sha256 [preauth] debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth] debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none [preauth] debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none [preauth] debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] debug3: receive packet: type 30 [preauth] debug3: mm_key_sign entering [preauth] debug3: mm_request_send entering: type 6 [preauth] debug3: mm_key_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 000001B2C005C270(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 after 134217728 blocks [preauth] debug1: SSH2_MSG_NEWKEYS sent [preauth] debug1: expecting SSH2_MSG_NEWKEYS [preauth] debug3: send packet: type 7 [preauth] debug3: receive packet: type 21 [preauth] debug1: SSH2_MSG_NEWKEYS received [preauth] debug2: set_newkeys: mode 0 [preauth] debug1: rekey after 134217728 blocks [preauth] debug1: KEX done [preauth] debug3: receive packet: type 5 [preauth] debug3: send packet: type 6 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam 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 331 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 salam@salam [preauth] debug3: mm_inform_authserv entering [preauth] debug3: mm_request_send entering: type 4 [preauth] debug2: input_userauth_request: try method none [preauth] debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth] debug3: send packet: type 51 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam service ssh-connection method publickey [preauth] debug1: attempt 1 failures 0 [preauth] debug2: input_userauth_request: try method publickey [preauth] debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:epNPWfTpxjifjY9CdfF4Xz4Zl1ZKxemQEYnB8BJGvxQ [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 4 debug3: mm_answer_authserv: service=ssh-connection, style= debug2: monitor_read: 4 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 22 debug3: mm_answer_keyallowed entering debug3: mm_answer_keyallowed: key_from_blob: 000001B2C005C270 debug1: trying public key file C:\Users\salam\.ssh/authorized_keys debug3: mm_answer_keyallowed: publickey authentication test: RSA key is not allowed Failed publickey for salam@salam from 192.168.2.12 port 41647 ssh2: RSA SHA256:epNPWfTpxjifjY9CdfF4Xz4Zl1ZKxemQEYnB8BJGvxQ debug3: mm_request_send entering: type 23 debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth] debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth] debug3: send packet: type 51 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam service ssh-connection method keyboard-interactive [preauth] debug1: attempt 2 failures 1 [preauth] debug2: input_userauth_request: try method keyboard-interactive [preauth] debug1: keyboard-interactive devs [preauth] debug1: auth2_challenge: user=salam@salam devs= [preauth] debug1: kbdint_alloc: devices '' [preauth] debug2: auth2_challenge_start: devices [preauth] debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth] debug3: send packet: type 51 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam service ssh-connection method password [preauth] debug1: attempt 3 failures 2 [preauth] debug2: input_userauth_request: try method password [preauth] debug3: mm_auth_password entering [preauth] debug3: mm_request_send entering: type 12 [preauth] debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth] debug3: mm_request_receive_expect entering: type 13 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 12 debug3: lookup_principal_name: Successfully discovered explicit principal name: 'salam\salam'=>'salam@salam.net' debug3: mm_answer_authpassword: sending result 1 debug3: mm_request_send entering: type 13 Accepted password for salam@salam from 192.168.2.12 port 41647 ssh2 debug1: monitor_child_preauth: salam@salam 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 debug3: mm_auth_password: user authenticated [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:000001B2C005EAA0 debug3: read - no more data, io:000001B2C005EAA0 debug1: monitor_read_log: child log fd closed debug1: Not running as SYSTEM: skipping loading user profile debug3: spawning "C:\Windows\System32\OpenSSH\sshd.exe" "-ddd" "-z" CreateProcessAsUserW failed error:1314 fork of unprivileged child failed debug1: do_cleanup

eliassal commented 5 years ago

I forgot to mention that doing ssh directly from centos works perfectly

eliassal commented 5 years ago

Manoj, while debugging, I issued the following command on the win server

ls WSMan:\localhost\Plugin

I get several endpoints as follows (powershell and powershell core v 6.2)

Type Keys Name

Container {Name=Event Forwarding Plugin} Event Forwarding Plugin
Container {Name=microsoft.powershell} microsoft.powershell
Container {Name=microsoft.powershell.workf... microsoft.powershell.workflow
Container {Name=microsoft.powershell32} microsoft.powershell32
Container {Name=microsoft.windows.serverma... microsoft.windows.servermanagerworkflows
Container {Name=PowerShell.6} PowerShell.6
Container {Name=PowerShell.6.2.0} PowerShell.6.2.0
Container {Name=SEL Plugin} SEL Plugin
Container {Name=WMI Provider} WMI Provider

Can this be the source of the error?

manojampalam commented 5 years ago

In your latest traces, authentication succeeded, but since sshd is run interactively, there was a failure launching worker processes debug3: spawning "C:\Windows\System32\OpenSSH\sshd.exe" "-ddd" "-z" CreateProcessAsUserW failed error:1314

This is expected. Try doing psexec -s sshd -ddd and it should go past that stage.

eliassal commented 5 years ago

I ran this command on the target win2k19 but getting the following error (what is this psexec?)

psexec : The term 'psexec' is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try again. At line:1 char:1

  • psexec -s sshd -ddd
  • CategoryInfo : ObjectNotFound: (psexec:String) [], CommandNotFoundException
  • FullyQualifiedErrorId : CommandNotFoundException
eliassal commented 5 years ago

manoj, I managed to run the service with PSEXEC on the windows server as you indicated with PSEXEC, then from Centos I issue Enter-PSSession -HostName 192.168.1.70 -UserName salam@mydomain.net Following is the full debug on the win server

PsExec v2.2 - Execute processes remotely Copyright (C) 2001-2016 Mark Russinovich Sysinternals - www.sysinternals.com

debug2: load_server_config: filename PROGRAMDATA\ssh/sshd_config debug2: load_server_config: done config len = 307 debug2: parse_server_config: config PROGRAMDATA\ssh/sshd_config len 307 debug3: PROGRAMDATA\ssh/sshd_config:24 setting SyslogFacility LOCAL0 debug3: PROGRAMDATA\ssh/sshd_config:25 setting LogLevel DEBUG3 debug3: PROGRAMDATA\ssh/sshd_config:39 setting AuthorizedKeysFile .ssh/authorized_keys debug3: PROGRAMDATA\ssh/sshd_config:52 setting PasswordAuthentication yes debug3: PROGRAMDATA\ssh/sshd_config:77 setting Subsystem sftp sftp-server.exe debug3: PROGRAMDATA\ssh/sshd_config:78 setting Subsystem powershell c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile debug1: sshd version OpenSSH_for_Windows_7.7, LibreSSL 2.6.5 debug1: private host key #0: ssh-rsa SHA256:u66cloJQDc9UQ82WC/K1pldqeoayFGK1R6pRF6qgAO0 debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:OWPsQuxC6bO11y5LUHT9zxLafbl0DzEUttbzCBwOwjE debug1: private host key #2: ssh-ed25519 SHA256:FXvsJQwaNJqK67d08jNjKOjNYXmsJs6QxDvHBjkLcmQ debug1: rexec_argv[0]='sshd' 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 307 debug3: ssh_msg_send: type 0 debug3: send_rexec_state: done Connection from 192.168.2.12 port 40844 on 192.168.1.70 port 22 debug1: Client protocol version 2.0; client software version OpenSSH_7.4 debug1: match: OpenSSH_7.4 pat OpenSSH* compat 0x04000000 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_7.7 debug2: fd 5 setting O_NONBLOCK debug3: spawning "C:\Windows\System32\OpenSSH\sshd" "-ddd" "-y" debug2: Network child is on pid 9068 debug3: recv_rexec_state: entering fd = 3 debug3: send_rexec_state: entering fd = 4 config len 307 debug3: ssh_msg_recv entering debug3: ssh_msg_send: type 0 debug3: recv_rexec_state: done debug3: send_rexec_state: done debug2: parse_server_config: config PROGRAMDATA\ssh/sshd_config len 307 debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:24 setting SyslogFacility LOCAL0 debug3: PROGRAMDATA\ssh/sshd_config:25 setting LogLevel DEBUG3 debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:39 setting AuthorizedKeysFile .ssh/authorized_keys debug3: preauth child monitor started debug3: PROGRAMDATA\ssh/sshd_config:52 setting PasswordAuthentication yes debug3: PROGRAMDATA\ssh/sshd_config:77 setting Subsystem sftp sftp-server.exe debug3: PROGRAMDATA\ssh/sshd_config:78 setting Subsystem powershell c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile debug1: sshd version OpenSSH_for_Windows_7.7, LibreSSL 2.6.5 debug3: ssh_msg_recv entering debug3: ssh_msg_recv entering debug2: fd 5 setting O_NONBLOCK debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug3: send packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT sent [preauth] debug3: receive packet: type 20 [preauth] debug1: SSH2_MSG_KEXINIT received [preauth] debug2: local server KEXINIT proposal [preauth] debug2: KEX algorithms: curve25519-sha256,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] debug2: host key algorithms: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth] debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth] 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] 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] 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: 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,diffie-hellman-group1-sha1,ext-info-c [preauth] 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-dss-cert-v01@openssh.com,ssh-ed25519,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-dss [preauth] debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth] debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com,aes128-cbc,aes192-cbc,aes256-cbc [preauth] 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] 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] debug2: compression ctos: none,zlib@openssh.com,zlib [preauth] debug2: compression stoc: none,zlib@openssh.com,zlib [preauth] debug2: languages ctos: [preauth] debug2: languages stoc: [preauth] debug2: first_kex_follows 0 [preauth] debug2: reserved 0 [preauth] debug1: kex: algorithm: curve25519-sha256 [preauth] debug1: kex: host key algorithm: ecdsa-sha2-nistp256 [preauth] debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: compression: none [preauth] debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: compression: none [preauth] debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth] debug3: receive packet: type 30 [preauth] debug3: mm_key_sign entering [preauth] debug3: mm_request_send entering: type 6 [preauth] debug3: mm_key_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 00000183BDCDBFA0(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 after 134217728 blocks [preauth] debug1: SSH2_MSG_NEWKEYS sent [preauth] debug1: expecting SSH2_MSG_NEWKEYS [preauth] debug3: send packet: type 7 [preauth] debug3: receive packet: type 21 [preauth] debug1: SSH2_MSG_NEWKEYS received [preauth] debug2: set_newkeys: mode 0 [preauth] debug1: rekey after 134217728 blocks [preauth] debug1: KEX done [preauth] debug3: receive packet: type 5 [preauth] debug3: send packet: type 6 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam.net 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 307 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 salam@salam.net [preauth] debug3: mm_inform_authserv entering [preauth] debug3: mm_request_send entering: type 4 [preauth] debug2: input_userauth_request: try method none [preauth] debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth] debug3: send packet: type 51 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam.net service ssh-connection method publickey [preauth] debug1: attempt 1 failures 0 [preauth] debug2: input_userauth_request: try method publickey [preauth] debug1: userauth_pubkey: test pkalg rsa-sha2-512 pkblob RSA SHA256:epNPWfTpxjifjY9CdfF4Xz4Zl1ZKxemQEYnB8BJGvxQ [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 4 debug3: mm_answer_authserv: service=ssh-connection, style= debug2: monitor_read: 4 used once, disabling now debug3: mm_request_receive entering debug3: monitor_read: checking request 22 debug3: mm_answer_keyallowed entering debug3: mm_answer_keyallowed: key_from_blob: 00000183BDCDC5C0 debug1: trying public key file C:\Users\salam\.ssh/authorized_keys debug3: mm_answer_keyallowed: publickey authentication test: RSA key is not allowed Failed publickey for salam@salam.net from 192.168.2.12 port 40844 ssh2: RSA SHA256:epNPWfTpxjifjY9CdfF4Xz4Zl1ZKxemQEYnB8BJGvxQ debug3: mm_request_send entering: type 23 debug2: userauth_pubkey: authenticated 0 pkalg rsa-sha2-512 [preauth] debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth] debug3: send packet: type 51 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam.net service ssh-connection method keyboard-interactive [preauth] debug1: attempt 2 failures 1 [preauth] debug2: input_userauth_request: try method keyboard-interactive [preauth] debug1: keyboard-interactive devs [preauth] debug1: auth2_challenge: user=salam@salam.net devs= [preauth] debug1: kbdint_alloc: devices '' [preauth] debug2: auth2_challenge_start: devices [preauth] debug3: userauth_finish: failure partial=0 next methods="publickey,password,keyboard-interactive" [preauth] debug3: send packet: type 51 [preauth] debug3: receive packet: type 50 [preauth] debug1: userauth-request for user salam@salam.net service ssh-connection method password [preauth] debug1: attempt 3 failures 2 [preauth] debug2: input_userauth_request: try method password [preauth] debug3: mm_auth_password entering [preauth] debug3: mm_request_send entering: type 12 [preauth] debug3: mm_auth_password: waiting for MONITOR_ANS_AUTHPASSWORD [preauth] debug3: mm_request_receive_expect entering: type 13 [preauth] debug3: mm_request_receive entering [preauth] debug3: mm_request_receive entering debug3: monitor_read: checking request 12 debug3: lookup_principal_name: Successfully discovered explicit principal name: 'salam\salam'=>'salam@salam.net' debug3: mm_answer_authpassword: sending result 1 debug3: mm_request_send entering: type 13 Accepted password for salam@salam.net from 192.168.2.12 port 40844 ssh2 debug1: monitor_child_preauth: salam@salam.net 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 debug3: mm_auth_password: user authenticated [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:00000183BDD10200 debug3: read - no more data, io:00000183BDD10200 debug1: monitor_read_log: child log fd closed debug3: spawning "C:\Windows\System32\OpenSSH\sshd" "-ddd" "-z" User child is on pid 10176 debug3: recv_rexec_state: entering fd = 3 debug3: send_rexec_state: entering fd = 6 config len 307 debug3: ssh_msg_recv entering debug3: ssh_msg_send: type 0 debug3: recv_rexec_state: done debug3: send_rexec_state: done debug2: parse_server_config: config PROGRAMDATA\ssh/sshd_config len 307 debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:24 setting SyslogFacility LOCAL0 debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:25 setting LogLevel DEBUG3 debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:39 setting AuthorizedKeysFile .ssh/authorized_keys debug3: PROGRAMDATA\ssh/sshd_config:52 setting PasswordAuthentication yes debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:77 setting Subsystem sftp sftp-server.exe debug3: ssh_msg_send: type 0 debug3: PROGRAMDATA\ssh/sshd_config:78 setting Subsystem powershell c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile debug1: sshd version OpenSSH_for_Windows_7.7, LibreSSL 2.6.5 debug3: ssh_msg_recv entering debug3: ssh_msg_recv entering debug2: fd 4 setting O_NONBLOCK debug3: ssh_msg_recv entering debug2: parse_server_config: config reprocess config len 307 debug3: ssh_msg_recv entering debug3: monitor_apply_keystate: packet_set_state debug2: set_newkeys: mode 0 debug1: rekey after 134217728 blocks debug2: set_newkeys: mode 1 debug1: rekey after 134217728 blocks debug1: ssh_packet_set_postauth: called debug3: ssh_packet_set_state: done debug3: ssh_msg_recv entering debug3: notify_hostkeys: key 0: ssh-rsa SHA256:u66cloJQDc9UQ82WC/K1pldqeoayFGK1R6pRF6qgAO0 debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:OWPsQuxC6bO11y5LUHT9zxLafbl0DzEUttbzCBwOwjE debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:FXvsJQwaNJqK67d08jNjKOjNYXmsJs6QxDvHBjkLcmQ debug3: notify_hostkeys: sent 3 hostkeys debug3: send packet: type 80 debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding debug1: Entering interactive session for SSH2. debug2: fd 7 setting O_NONBLOCK debug2: fd 8 setting O_NONBLOCK debug1: server_init_dispatch debug3: receive packet: type 90 debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768 debug1: input_session_request debug1: channel 0: new [server-session] debug2: session_new: allocate (allocated 0 max 10) debug3: session_unused: session id 0 unused debug1: session_new: session 0 debug1: session_open: channel 0 debug1: session_open: session 0: link with channel 0 debug1: server_input_channel_open: confirm session debug3: send packet: type 91 debug3: receive packet: type 80 debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0 debug3: receive packet: type 98 debug1: server_input_channel_req: channel 0 request env reply 0 debug1: session_by_channel: session 0 channel 0 debug1: session_input_channel_req: session 0 req env debug2: Ignoring env request LANG: disallowed name debug3: receive packet: type 98 debug1: server_input_channel_req: channel 0 request subsystem reply 1 debug1: session_by_channel: session 0 channel 0 debug1: session_input_channel_req: session 0 req subsystem debug2: subsystem request for powershell by user salam\salam debug1: subsystem: cannot stat c:/program: No such file or directory debug1: subsystem: exec() c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile Starting session: subsystem 'powershell' for salam\salam from 192.168.2.12 port 40844 id 0 debug2: fd 9 setting O_NONBLOCK debug2: fd 10 setting O_NONBLOCK debug2: fd 11 setting O_NONBLOCK debug2: fd 12 setting O_NONBLOCK debug2: fd 13 setting O_NONBLOCK debug2: fd 14 setting O_NONBLOCK debug1: Executing command: "c:\windows\system32\cmd.exe" /c "c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile" with no pty debug2: fd 4 setting TCP_NODELAY debug3: fd 11 is O_NONBLOCK debug3: fd 10 is O_NONBLOCK debug3: fd 13 is O_NONBLOCK debug3: send packet: type 99 debug3: ReadFileEx() ERROR:109, io:000001D6D1E25050 debug2: notify_done: reading debug1: Received SIGCHLD. debug1: session_by_pid: pid 1956 debug1: session_exit_message: session 0 channel 0 pid 1956 debug2: channel 0: request exit-status confirm 0 debug3: send packet: type 98 debug1: session_exit_message: release channel 0 debug2: channel 0: write failed debug2: channel 0: close_write debug2: channel 0: send eow debug2: channel 0: output open -> closed debug2: channel 0: read<=0 rfd 11 len 0 debug2: channel 0: read failed debug2: channel 0: close_read debug2: channel 0: input open -> drain debug2: channel 0: read 101 from efd 13 debug3: channel 0: discard efd debug2: channel 0: ibuf empty debug2: channel 0: send eof debug3: send packet: type 96 debug2: channel 0: input drain -> closed debug2: channel 0: send close debug3: send packet: type 97 debug3: ReadFileEx() ERROR:109, io:000001D6D1E62F20 debug3: read - no more data, io:000001D6D1E62F20 debug2: channel 0: read 0 from efd 13 debug2: channel 0: closing read-efd 13 debug3: channel 0: will not send data after close debug3: channel 0: will not send data after close debug3: channel 0: will not send data after close debug3: receive packet: type 97 debug2: channel 0: rcvd close debug3: receive packet: type 1 Received disconnect from 192.168.2.12 port 40844:11: disconnected by user Disconnected from 192.168.2.12 port 40844 debug1: do_cleanup debug3: mm_request_receive entering debug1: do_cleanup sshd exited on SQL2K17 with error code 255.

eliassal commented 5 years ago

any idea Manoj?

manojampalam commented 5 years ago

debug1: Executing command: "c:\windows\system32\cmd.exe" /c "c:/program files/powershell/6/pwsh.exe -sshs -NoLogo -NoProfile" with no pty debug2: fd 4 setting TCP_NODELAY debug3: fd 11 is O_NONBLOCK debug3: fd 10 is O_NONBLOCK debug3: fd 13 is O_NONBLOCK debug3: send packet: type 99 debug3: ReadFileEx() ERROR:109, io:000001D6D1E25050 debug2: notify_done: reading debug1: Received SIGCHLD.

Subsystem process is exiting immediately. From https://docs.microsoft.com/en-us/powershell/scripting/learn/remoting/ssh-remoting-in-powershell-core?view=powershell-6

I believe you are hitting issue detailed in Step 3 in https://docs.microsoft.com/en-us/powershell/scripting/learn/remoting/ssh-remoting-in-powershell-core?view=powershell-6#set-up-on-windows-machine

eliassal commented 5 years ago

Yes, exact, it was step 3, OpenSSH for Windows that prevents spaces from working in subsystem executable paths. I was able to log after eliminating spaces. Thanks

eliassal commented 5 years ago

1 last question, when I was troubleshooting, I changed the following item SyslogFacility LOCAL0 in sshd config file, what does this mean? does it log to a file called LOCAL0?

manojampalam commented 5 years ago

https://github.com/PowerShell/Win32-OpenSSH/wiki/Logging-Facilities