PowerShell / Win32-OpenSSH

Win32 port of OpenSSH
7.43k stars 761 forks source link

SCP Fails 100% of times if the shell profile outputs anything #2271

Closed ku4eto closed 1 month ago

ku4eto commented 2 months ago

Prerequisites

Steps to reproduce

  1. Install PowerShell 7.4.5
  2. Set DefaultShell to PowerShell 7.4.5
  3. Create a Shell Profile in C:\Program Files\PowerShell\7\profile.ps1 with the following content:
    
    function history_func
    {
    cat (Get-PSReadLineOption).HistorySavePath
    }

New-Alias -Name "history" -Value history_func -PassThru -Force -Option AllScope -Scope Global

*NOTE* : ANY kind of Alias creation will work, this is an example one that i use.
4. Try to use `scp` from a Linux machine to transfer some file to any location on the Windows machine

### Expected behavior

```console
Start of file transfer

Actual behavior

Silent failure if `scp` verbosity is not increased. If `profile.ps1` has `Write-Host ""`, it will print out 1 line of the text and then fail.

Error details

On receiving machine, `sshd` logs show successful authentication and then connection close.

Increasing the verbosity on the machine from where i am trying to transfer the file, i get the following:

scp -vvvv webapp.zip Administrator@10.15.6.40:\C\webapp.zip
Executing: program /usr/bin/ssh host 10.15.6.40, user Administrator, command scp -v -t Cwebapp.zip
OpenSSH_8.2p1 Ubuntu-4ubuntu0.11, OpenSSL 1.1.1f  31 Mar 2020
debug1: Reading configuration data /home/ku4eto/.ssh/config
debug3: kex names ok: [diffie-hellman-group1-sha1]
debug3: kex names ok: [diffie-hellman-group1-sha1]
debug3: kex names ok: [diffie-hellman-group1-sha1]
debug3: kex names ok: [diffie-hellman-group1-sha1]
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/*.conf matched no files
debug1: /etc/ssh/ssh_config line 21: Applying options for *
debug2: resolve_canonicalize: hostname 10.15.6.40 is address
debug2: ssh_connect_direct
debug1: Connecting to 10.15.6.40 [10.15.6.40] port 22.
debug1: Connection established.
debug1: identity file /home/ku4eto/.ssh/id_rsa type 0
debug1: identity file /home/ku4eto/.ssh/id_rsa-cert type -1
debug1: identity file /home/ku4eto/.ssh/id_dsa type -1
debug1: identity file /home/ku4eto/.ssh/id_dsa-cert type -1
debug1: identity file /home/ku4eto/.ssh/id_ecdsa type -1
debug1: identity file /home/ku4eto/.ssh/id_ecdsa-cert type -1
debug1: identity file /home/ku4eto/.ssh/id_ecdsa_sk type -1
debug1: identity file /home/ku4eto/.ssh/id_ecdsa_sk-cert type -1
debug1: identity file /home/ku4eto/.ssh/id_ed25519 type -1
debug1: identity file /home/ku4eto/.ssh/id_ed25519-cert type -1
debug1: identity file /home/ku4eto/.ssh/id_ed25519_sk type -1
debug1: identity file /home/ku4eto/.ssh/id_ed25519_sk-cert type -1
debug1: identity file /home/ku4eto/.ssh/id_xmss type -1
debug1: identity file /home/ku4eto/.ssh/id_xmss-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.11
debug1: Remote protocol version 2.0, remote software version OpenSSH_for_Windows_8.1
debug1: match: OpenSSH_for_Windows_8.1 pat OpenSSH* compat 0x04000000
debug2: fd 3 setting O_NONBLOCK
debug1: Authenticating to 10.15.6.40:22 as 'Administrator'
debug3: hostkeys_foreach: reading file "/home/ku4eto/.ssh/known_hosts"
debug3: record_hostkey: found key type ECDSA in file /home/ku4eto/.ssh/known_hosts:667
debug3: load_hostkeys: loaded 1 keys from 10.15.6.40
debug3: order_hostkeyalgs: have matching best-preference key type ecdsa-sha2-nistp256-cert-v01@openssh.com, using HostkeyAlgorithms verbatim
debug3: send packet: type 20
debug1: SSH2_MSG_KEXINIT sent
debug3: receive packet: type 20
debug1: SSH2_MSG_KEXINIT received
debug2: local client KEXINIT proposal
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,ext-info-c,kex-strict-c-v00@openssh.com
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,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,ssh-ed25519-cert-v01@openssh.com,sk-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,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ecdsa-sha2-nistp256@openssh.com,ssh-ed25519,sk-ssh-ed25519@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
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
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
debug2: compression ctos: none,zlib@openssh.com,zlib
debug2: compression stoc: none,zlib@openssh.com,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@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
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
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
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
debug2: compression ctos: none,zlib@openssh.com
debug2: compression stoc: none,zlib@openssh.com
debug2: languages ctos: 
debug2: languages stoc: 
debug2: first_kex_follows 0 
debug2: reserved 0 
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ecdsa-sha2-nistp256
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none
debug3: send packet: type 30
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug3: receive packet: type 31
debug1: Server host key: ecdsa-sha2-nistp256 SHA256:/3wBkhlYNe3WZdaNn7lMoxqLls07kXD8IIXpl59ar4E
debug3: hostkeys_foreach: reading file "/home/ku4eto/.ssh/known_hosts"
debug3: record_hostkey: found key type ECDSA in file /home/ku4eto/.ssh/known_hosts:667
debug3: load_hostkeys: loaded 1 keys from 10.15.6.40
debug1: Host '10.15.6.40' is known and matches the ECDSA host key.
debug1: Found key in /home/ku4eto/.ssh/known_hosts:667
debug3: send packet: type 21
debug2: set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug3: receive packet: type 21
debug1: SSH2_MSG_NEWKEYS received
debug2: set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug1: Will attempt key: /home/ku4eto/.ssh/id_rsa RSA SHA256:X83sj0gTvGARXfGy5p6yvHy+tu+Dc0aS2QMXsTs1mW0 agent
debug1: Will attempt key: /home/ku4eto/.ssh/id_dsa 
debug1: Will attempt key: /home/ku4eto/.ssh/id_ecdsa 
debug1: Will attempt key: /home/ku4eto/.ssh/id_ecdsa_sk 
debug1: Will attempt key: /home/ku4eto/.ssh/id_ed25519 
debug1: Will attempt key: /home/ku4eto/.ssh/id_ed25519_sk 
debug1: Will attempt key: /home/ku4eto/.ssh/id_xmss 
debug2: pubkey_prepare: done
debug3: send packet: type 5
debug3: receive packet: type 7
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521>
debug3: receive packet: type 6
debug2: service_accept: ssh-userauth
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug3: send packet: type 50
debug3: receive packet: type 51
debug1: Authentications that can continue: publickey,password,keyboard-interactive
debug3: start over, passed a different list publickey,password,keyboard-interactive
debug3: preferred gssapi-with-mic,publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod_is_enabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /home/ku4eto/.ssh/id_rsa RSA SHA256:X83sj0gTvGARXfGy5p6yvHy+tu+Dc0aS2QMXsTs1mW0 agent
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: /home/ku4eto/.ssh/id_rsa RSA SHA256:X83sj0gTvGARXfGy5p6yvHy+tu+Dc0aS2QMXsTs1mW0 agent
debug3: sign_and_send_pubkey: RSA SHA256:X83sj0gTvGARXfGy5p6yvHy+tu+Dc0aS2QMXsTs1mW0
debug3: sign_and_send_pubkey: signing using rsa-sha2-512 SHA256:X83sj0gTvGARXfGy5p6yvHy+tu+Dc0aS2QMXsTs1mW0
debug3: send packet: type 50
debug3: receive packet: type 52
debug1: Authentication succeeded (publickey).
Authenticated to 10.15.6.40 ([10.15.6.40]:22).
debug2: fd 4 setting O_NONBLOCK
debug2: fd 5 setting O_NONBLOCK
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
debug3: receive packet: type 80
debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0
debug3: receive packet: type 91
debug2: channel_input_open_confirmation: channel 0: callback start
debug2: fd 3 setting TCP_NODELAY
debug3: ssh_packet_set_tos: set IP_TOS 0x08
debug2: client_session2_setup: id 0
debug1: Sending environment.
debug3: Ignored env SHELL
debug3: Ignored env SESSION_MANAGER
debug3: Ignored env QT_ACCESSIBILITY
debug3: Ignored env COLORTERM
debug3: Ignored env XDG_CONFIG_DIRS
debug3: Ignored env XDG_SESSION_PATH
debug3: Ignored env GNOME_DESKTOP_SESSION_ID
debug3: Ignored env LANGUAGE
debug3: Ignored env MANDATORY_PATH
debug1: Sending env LC_ADDRESS = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug1: Sending env LC_NAME = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env SSH_AUTH_SOCK
debug3: Ignored env DESKTOP_SESSION
debug1: Sending env LC_MONETARY = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env SSH_AGENT_PID
debug3: Ignored env GTK_MODULES
debug3: Ignored env XDG_SEAT
debug3: Ignored env PWD
debug3: Ignored env LOGNAME
debug3: Ignored env XDG_SESSION_DESKTOP
debug3: Ignored env QT_QPA_PLATFORMTHEME
debug3: Ignored env XDG_SESSION_TYPE
debug3: Ignored env GPG_AGENT_INFO
debug3: Ignored env XAUTHORITY
debug3: Ignored env XDG_GREETER_DATA_DIR
debug3: Ignored env GDM_LANG
debug3: Ignored env HOME
debug1: Sending env LC_PAPER = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug1: Sending env LANG = en_US.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env LS_COLORS
debug3: Ignored env XDG_CURRENT_DESKTOP
debug3: Ignored env VTE_VERSION
debug3: Ignored env XDG_SEAT_PATH
debug3: Ignored env GNOME_TERMINAL_SCREEN
debug3: Ignored env LESSCLOSE
debug3: Ignored env XDG_SESSION_CLASS
debug3: Ignored env TERM
debug1: Sending env LC_IDENTIFICATION = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env GTK_OVERLAY_SCROLLING
debug3: Ignored env DEFAULTS_PATH
debug3: Ignored env LESSOPEN
debug3: Ignored env USER
debug3: Ignored env GNOME_TERMINAL_SERVICE
debug3: Ignored env DISPLAY
debug3: Ignored env SHLVL
debug1: Sending env LC_TELEPHONE = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug1: Sending env LC_MEASUREMENT = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env XDG_VTNR
debug3: Ignored env DESKTOP_AUTOSTART_ID
debug3: Ignored env XDG_SESSION_ID
debug3: Ignored env XDG_RUNTIME_DIR
debug1: Sending env LC_TIME = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env GTK3_MODULES
debug3: Ignored env XDG_DATA_DIRS
debug3: Ignored env PATH
debug3: Ignored env GDMSESSION
debug3: Ignored env DBUS_SESSION_BUS_ADDRESS
debug3: Ignored env test
debug1: Sending env LC_NUMERIC = bg_BG.UTF-8
debug2: channel 0: request env confirm 0
debug3: send packet: type 98
debug3: Ignored env OLDPWD
debug3: Ignored env _
debug1: Sending command: scp -v -t Cwebapp.zip
debug2: channel 0: request exec confirm 1
debug3: send packet: type 98
debug2: channel_input_open_confirmation: channel 0: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug3: receive packet: type 99
debug2: channel_input_status_confirm: type 99 id 0
debug2: exec request accepted on channel 0

debug2: channel 0: read<=0 rfd 4 len 0
debug2: channel 0: read failed
debug2: channel 0: chan_shutdown_read (i0 o0 sock -1 wfd 4 efd 6 [write])
debug2: channel 0: input open -> drain
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug2: channel 0: write failed
debug2: channel 0: chan_shutdown_write (i3 o0 sock -1 wfd 5 efd 6 [write])
debug2: channel 0: send eow
debug3: send packet: type 98
debug2: channel 0: output open -> closed
receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug3: send packet: type 97
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
  #0 client-session (t4 r0 i3/0 o3/0 e[write]/0 fd -1/-1/6 sock -1 cc -1)

debug3: send packet: type 1
debug1: fd 0 clearing O_NONBLOCK
debug3: fd 1 is not O_NONBLOCK
Transferred: sent 4260, received 3440 bytes, in 0.8 seconds
Bytes per second: sent 5177.6, received 4181.0
debug1: Exit status 0


### Environment data

Windows Server 2022 Standard, with September 2024 CU installed.
OpenSSH Server installed via Optional Features (`OpenSSH_For_Windows_8.1.p1, LibreSSL 3.0.2`).
`PowerShell v7.4.5`
`profile.ps1` set in the PowerShell 7 directory.
`HKEY_LOCAL_MACHINE\SOFTWARE\OpenSSH\DefaultShell` set to PowerShell v7.4.5.

`scp` on remoting in machine: `openssh-client/focal-updates,focal-security,now 1:8.2p1-4ubuntu0.11 amd64`

### Version

`OpenSSH_For_Windows_8.1.p1, LibreSSL 3.0.2`

### Visuals

_No response_
ku4eto commented 2 months ago

Tested as well from pure Ubuntu 22.04 and from OracleLinux 9.3. Both fail as well. On OL 9 at least there is a bit more of a information:

Received message too long 1416128883
Ensure the remote shell produces no output for non-interactive sessions.

OL9 version openssh-clients.x86_64 8.7p1-38.0.2.el9_4.4 @ol9_baseos_latest

maertendMSFT commented 1 month ago

This is by design from OpenSSH upstream. This issue is not specific to Win32-OpenSSH.

ku4eto commented 1 month ago

@maertendMSFT That may be so, but the behavior differs from the Linux experience. scp in Linux is by default using a non-interactive login shell. But it seems like opening an scp towards Win32-OpenSSH server with PowerShell as default shell, opens up an INTERACTIVE login shell. Since scp expects no output returned, if you have ANY output from your PowerShell profile, it will fail (which is not the same for Linux systems, as output from the remote host is not present, due to the correct shell session type). The question here is - is Win32-OpenSSH supposed to manage what kind of shell session is opened? If yes - sounds like Win32-OpenSSH issue to me. If this is not an OpenSSH-Win32 issue, then its a PowerShell issue and as such please confirm it, so i can open a issue in that repository.