SFTP suddenly failing for chroot accounts on Amazon Linux

Frustratingly, SFTP users suddenly stopped being able to connect to my Amazon Linux server.

The /var/log/secure shows the following error:

sshd[7291]: fatal: safely_chroot: stat("/chroot/uhleeka"): Permission denied [postauth]

/var/log/secure:

==> /var/log/secure <==
Nov 21 23:49:23 amzl-lamp sshd[7291]: Accepted password for uhleeka from 172.31.0.254 port 47170 ssh2
Nov 21 23:49:24 amzl-lamp sshd[7291]: pam_unix(sshd:session): session opened for user uhleeka by (uid=0)
Nov 21 23:49:24 amzl-lamp sshd[7291]: fatal: safely_chroot: stat("/chroot/uhleeka"): Permission denied [postauth]
Nov 21 23:49:24 amzl-lamp sshd[7291]: pam_unix(sshd:session): session closed for user uhleeka

Debug output from SSHD:

$ /usr/sbin/sshd -ddd -p 33333
...
debug1: SELinux support disabled
debug1: PAM: establishing credentials
debug3: PAM: opening session
debug1: monitor_reinit: /dev/log doesn't exist in /chroot/%u chroot - will try to log via monitor using [postauth] suffix
User child is on pid 6655
debug1: PAM: establishing credentials [postauth]
debug3: safely_chroot: checking '/' [postauth]
debug3: safely_chroot: checking '/chroot/' [postauth]
debug3: safely_chroot: checking '/chroot/uhleeka' [postauth]
safely_chroot: stat("/chroot/uhleeka"): Permission denied [postauth]
debug1: do_cleanup [postauth]
debug3: PAM: sshpam_thread_cleanup entering [postauth]
debug3: mm_request_send entering: type 124 [postauth]
debug3: mm_request_receive entering
debug3: monitor_read: checking request 124
debug3: mm_request_receive entering
debug1: do_cleanup
debug1: PAM: cleanup
debug1: PAM: closing session
debug1: PAM: deleting credentials
debug3: PAM: sshpam_thread_cleanup entering

SELinux is disabled:

$ sestatus
SELinux status:                 disabled

$ ls -lZ /chroot/uhleeka/
drwxr-x--- root root      ?                                .
drwx--x--- root sftp-only ?                                ..
drwx--x--- root sftp-only ?                                etc
drwxr-xr-x root sftp-only ?                                home

There have been no configuration changes or permissions changes, but yum update was run yesterday:

$ rpm -qa --last
system-release-2016.09-0.8.noarch             Mon 21 Nov 2016 04:34:40 PM UTC
cloud-init-0.7.6-2.14.amzn1.noarch            Mon 21 Nov 2016 04:34:40 PM UTC
python26-botocore-1.4.74-1.60.amzn1.noarch    Mon 21 Nov 2016 04:34:39 PM UTC
openssh-server-6.6.1p1-31.62.amzn1.x86_64     Mon 21 Nov 2016 04:34:39 PM UTC
openssh-clients-6.6.1p1-31.62.amzn1.x86_64    Mon 21 Nov 2016 04:34:39 PM UTC
aws-cli-1.11.17-1.43.amzn1.noarch             Mon 21 Nov 2016 04:34:39 PM UTC
python27-botocore-1.4.74-1.60.amzn1.noarch    Mon 21 Nov 2016 04:34:38 PM UTC
bind-utils-9.8.2-0.47.rc1.51.amzn1.x86_64     Mon 21 Nov 2016 04:34:38 PM UTC
bind-libs-9.8.2-0.47.rc1.51.amzn1.x86_64      Mon 21 Nov 2016 04:34:38 PM UTC
openssh-6.6.1p1-31.62.amzn1.x86_64            Mon 21 Nov 2016 04:34:37 PM UTC
...

Regarding the openssh update: https://alas.aws.amazon.com/ALAS-2016-770.html

It was discovered that the OpenSSH sshd daemon fetched PAM environment settings before running the login program. In configurations with UseLogin=yes and the pam_env PAM module configured to read user environment settings, a local user could use this flaw to execute arbitrary code as root.

/etc/ssh/sshd_config has:

UsePAM yes
#UseLogin no
#PermitUserEnvironment no

The latest updates seem like the most likely culprit. Is there a configuration issue that would cause only chroot users to suddenly stop be denied access with the latest openssh?

Solution 1:

Edit: This should be fixed in openssh-6.6.1p1-32.el7 per https://bugzilla.redhat.com/show_bug.cgi?id=1398569

It appears after the OpenSSH-6.6.1p1-31 update, only the user's primary group is checked for authentication during the SFTP connection attempt. With root and the user's primary group owning the home directory and at least 710 permissions, connection attempts should succeed.

Repro steps:

$ groups sftpuser  
sftpuser : sftpgroup sftpuser  
$ ls -ld /home/sftpuser/  
drwx--x--- 2 root sftpuser 4096 Nov 22 18:31 sftpuser/  
$ sftp sftpuser@localhost  
sftpuser@localhost's password:  
Write failed: Broken pipe  
Couldn't read packet: Connection reset by peer  
$ chgrp sftpgroup sftpuser/  
$ ls -ld /home/sftpuser/  
drwx--x--- 2 root sftpgroup 4096 Nov 22 18:31 sftpuser/  
$ sftp sftpuser@localhost  
sftpuser@localhost's password:  
Connected to localhost.  
sftp> exit  
  

Failed connection with secondary group owning home directory (from /var/log/secure):

sshd[31640]: Accepted password for sftpuser from 127.0.0.1 port 34380 ssh2
sshd[31640]: pam_unix(sshd:session): session opened for user sftpuser by (uid=0)
sshd[31640]: fatal: Unable to chdir to chroot path "/home/sftpuser": Permission denied [postauth]
sshd[31640]: pam_unix(sshd:session): session closed for user sftpuser
  

sshd[31647]: Accepted password for sftpuser from 127.0.0.1 port 34382 ssh2
sshd[31647]: pam_unix(sshd:session): session opened for user sftpuser by (uid=0)
sshd[31647]: session opened for local user sftpuser from [127.0.0.1] [postauth]
sshd[31647]: session closed for local user sftpuser from [127.0.0.1] [postauth]
sshd[31647]: Received disconnect from 127.0.0.1: 11: disconnected by user [postauth]
sshd[31647]: pam_unix(sshd:session): session closed for user sftpuser