ChrootDirectory is inconsistent

[trillykins]

I have the following user configuration in sshd_config:

Match User sftpuser
	AllowTcpForwarding no
	ChrootDirectory C:\users\sftpuser\Downloads
	ForceCommand internal-sftp

I want the user to only see the folder specified in ChrootDirecory, however it's very inconsistent when it'll let the user wander around in the server's entire file directory of the server (e.g. I can look in system32) and sometimes it does it correctly.

EDIT:

Gif of using FileZilla to access

"OpenSSH for Windows" version
7.7.2.1

Server OperatingSystem
Windows Server 2019 Datacenter

[bagajjal]

Please share the server side logs (sshd.log file).

[trillykins]

Log of two logins, one with correct chroot direcory and another with read-access to everything:

3956 2019-10-30 08:19:43.440 debug1: Bind to port 22 on ::.
3956 2019-10-30 08:19:43.440 Server listening on :: port 22.
3956 2019-10-30 08:19:43.440 debug1: Bind to port 22 on 0.0.0.0.
3956 2019-10-30 08:19:43.440 Server listening on 0.0.0.0 port 22.
3916 2019-10-30 08:19:53.386 debug1: inetd sockets after dupping: 3, 3
3916 2019-10-30 08:19:53.386 Connection from 82.147.226.77 port 51938 on 10.0.0.7 port 22
3916 2019-10-30 08:19:53.386 debug1: Client protocol version 2.0; client software version FileZilla_3.45.1
3916 2019-10-30 08:19:53.386 debug1: no match: FileZilla_3.45.1
3916 2019-10-30 08:19:53.386 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_7.7
3916 2019-10-30 08:19:53.433 debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
3916 2019-10-30 08:19:53.433 debug1: SSH2_MSG_KEXINIT sent [preauth]
3916 2019-10-30 08:19:53.433 debug1: SSH2_MSG_KEXINIT received [preauth]
3916 2019-10-30 08:19:53.448 debug1: kex: algorithm: [email protected] [preauth]
3916 2019-10-30 08:19:53.448 debug1: kex: host key algorithm: ssh-ed25519 [preauth]
3916 2019-10-30 08:19:53.448 debug1: kex: client->server cipher: [email protected] MAC: compression: none [preauth]
3916 2019-10-30 08:19:53.448 debug1: kex: server->client cipher: [email protected] MAC: compression: none [preauth]
3916 2019-10-30 08:19:53.448 debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
3916 2019-10-30 08:19:53.480 debug1: rekey after 4294967296 blocks [preauth]
3916 2019-10-30 08:19:53.480 debug1: SSH2_MSG_NEWKEYS sent [preauth]
3916 2019-10-30 08:19:53.480 debug1: expecting SSH2_MSG_NEWKEYS [preauth]
3916 2019-10-30 08:19:53.761 debug1: SSH2_MSG_NEWKEYS received [preauth]
3916 2019-10-30 08:19:53.761 debug1: rekey after 4294967296 blocks [preauth]
3916 2019-10-30 08:19:53.761 debug1: KEX done [preauth]
3916 2019-10-30 08:19:53.792 debug1: userauth-request for user sftpuser1 service ssh-connection method none [preauth]
3916 2019-10-30 08:19:53.792 debug1: attempt 0 failures 0 [preauth]
3916 2019-10-30 08:19:53.792 debug1: user n does not match group list administrators at line 87
3916 2019-10-30 08:19:53.824 debug1: userauth-request for user sftpuser1 service ssh-connection method keyboard-interactive [preauth]
3916 2019-10-30 08:19:53.824 debug1: attempt 1 failures 0 [preauth]
3916 2019-10-30 08:19:53.824 debug1: keyboard-interactive devs [preauth]
3916 2019-10-30 08:19:53.824 debug1: auth2_challenge: user=sftpuser1 devs= [preauth]
3916 2019-10-30 08:19:53.824 debug1: kbdint_alloc: devices '' [preauth]
3916 2019-10-30 08:19:53.855 debug1: userauth-request for user sftpuser1 service ssh-connection method password [preauth]
3916 2019-10-30 08:19:53.855 debug1: attempt 2 failures 1 [preauth]
3916 2019-10-30 08:19:53.855 Accepted password for sftpuser1 from 82.147.226.77 port 51938 ssh2
3916 2019-10-30 08:19:53.855 debug1: monitor_child_preauth: sftpuser1 has been authenticated by privileged process
3916 2019-10-30 08:19:53.855 debug1: monitor_read_log: child log fd closed
3916 2019-10-30 08:19:53.902 User child is on pid 2820
3756 2019-10-30 08:19:54.995 debug1: inetd sockets after dupping: 3, 3
3756 2019-10-30 08:19:54.995 Connection from 82.147.226.77 port 51939 on 10.0.0.7 port 22
3756 2019-10-30 08:19:54.995 debug1: Client protocol version 2.0; client software version FileZilla_3.45.1
3756 2019-10-30 08:19:54.995 debug1: no match: FileZilla_3.45.1
3756 2019-10-30 08:19:54.995 debug1: Local version string SSH-2.0-OpenSSH_for_Windows_7.7
3756 2019-10-30 08:19:55.058 debug1: list_hostkey_types: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
3756 2019-10-30 08:19:55.058 debug1: SSH2_MSG_KEXINIT sent [preauth]
3756 2019-10-30 08:19:55.058 debug1: SSH2_MSG_KEXINIT received [preauth]
3756 2019-10-30 08:19:55.058 debug1: kex: algorithm: [email protected] [preauth]
3756 2019-10-30 08:19:55.058 debug1: kex: host key algorithm: ssh-ed25519 [preauth]
3756 2019-10-30 08:19:55.058 debug1: kex: client->server cipher: [email protected] MAC: compression: none [preauth]
3756 2019-10-30 08:19:55.058 debug1: kex: server->client cipher: [email protected] MAC: compression: none [preauth]
3756 2019-10-30 08:19:55.058 debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
3756 2019-10-30 08:19:55.105 debug1: rekey after 4294967296 blocks [preauth]
3756 2019-10-30 08:19:55.105 debug1: SSH2_MSG_NEWKEYS sent [preauth]
3756 2019-10-30 08:19:55.105 debug1: expecting SSH2_MSG_NEWKEYS [preauth]
3756 2019-10-30 08:19:55.388 debug1: SSH2_MSG_NEWKEYS received [preauth]
3756 2019-10-30 08:19:55.388 debug1: rekey after 4294967296 blocks [preauth]
3756 2019-10-30 08:19:55.388 debug1: KEX done [preauth]
3756 2019-10-30 08:19:55.404 debug1: userauth-request for user sftpuser1 service ssh-connection method none [preauth]
3756 2019-10-30 08:19:55.404 debug1: attempt 0 failures 0 [preauth]
3756 2019-10-30 08:19:55.419 debug1: user sftpuser1 does not match group list administrators at line 87
3756 2019-10-30 08:19:55.419 debug1: user sftpuser1 matched 'User sftpuser1' at line 90
3756 2019-10-30 08:19:55.451 debug1: userauth-request for user sftpuser1 service ssh-connection method keyboard-interactive [preauth]
3756 2019-10-30 08:19:55.451 debug1: attempt 1 failures 0 [preauth]
3756 2019-10-30 08:19:55.451 debug1: keyboard-interactive devs [preauth]
3756 2019-10-30 08:19:55.451 debug1: auth2_challenge: user=sftpuser1 devs= [preauth]
3756 2019-10-30 08:19:55.451 debug1: kbdint_alloc: devices '' [preauth]
3756 2019-10-30 08:19:55.466 debug1: userauth-request for user sftpuser1 service ssh-connection method password [preauth]
3756 2019-10-30 08:19:55.466 debug1: attempt 2 failures 1 [preauth]
3756 2019-10-30 08:19:55.482 Accepted password for sftpuser1 from 82.147.226.77 port 51939 ssh2
3756 2019-10-30 08:19:55.482 debug1: monitor_child_preauth: sftpuser1 has been authenticated by privileged process
3756 2019-10-30 08:19:55.482 debug1: monitor_read_log: child log fd closed
3756 2019-10-30 08:19:55.497 User child is on pid 3164

[bagajjal]

There is something wrong here
3916 2019-10-30 08:19:53.792 debug1: user n does not match group list administrators at line 87

Did you do any modifications to the log file?
Looks like both the connections are triggered from fileZilla. What is the difference between 1st and 2nd connection?

[trillykins]

@bagajjal No, the log is copy-pasted directly.

Don't know who used n is supposed to be. There is no difference between the two logins. I was using quick connect in FileZilla with the same username and password. Logging in the second time aborts the first connection and logs in anew.

[NoMoreFood]

There's a group matching bug in that version. Please re-baseline with the latest.

Reference: PowerShell/openssh-portable#380

[trillykins]

@NoMoreFood Okay, now it works.

Thanks!