ssh/sftp 5.3 chroot

Hi Everyone,

I am having some huge problems here. I am trying to use the newest openssh (5.3) on suse10 so that I can match a user and Chroot them with SFTP into a directory.

Currently, I have compiled it as such

$ ./configure --prefix=/usr/local --with-pam --with-md5-passwords

And my sshd configuration file is as such:


PidFile /var/run/sshd.pid
UsePrivilegeSeparation no
PrintLastLog yes
UsePAM yes
ChallengeResponseAuthentication yes
SyslogFacility AUTH
LogLevel DEBUG3
Protocol 2
Port 2122
AddressFamily any
ListenAddress 0.0.0.0

Subsystem       sftp    internal-sftp

Match User test
        ForceCommand /usr/local/libexec/sftp-server
        ChrootDirectory /store/drop/test

The ForceCommand part works fine and gets executed perfectly. My problem is that when I try to utilize the ChrootDirectory directiove, the user is automatically disconnected from the server.

I can not see anything with it being permissions issues or anything of that sort. In fact, the log file says this when that user logs in:


Dec  9 09:40:01 livedemo sshd[4723]: debug3: safely_chroot: checking '/'
Dec  9 09:40:01 livedemo sshd[4723]: debug3: safely_chroot: checking '/store/'
Dec  9 09:40:01 livedemo sshd[4723]: debug3: safely_chroot: checking '/store/drop/'
Dec  9 09:40:01 livedemo sshd[4723]: debug3: safely_chroot: checking '/store/drop/test

So, my primary issue is this exactly:

  • When a user connects when utilizing the ChrootDirectory directive in the sshd_config file, they are automatically disconnected from the server. Removing the ChrootDirectory directive allows them to connect via SFTP (and not ssh, which is what I want) but still allows them to traverse my entire system.

Anyone have any idea? Here is the log file from /var/log/messages POST the password authentication.


Dec  9 09:50:21 livedemo sshd[4800]: debug2: PAM: sshpam_respond entering, 1 responses
Dec  9 09:50:21 livedemo sshd[4800]: debug3: ssh_msg_send: type 6
Dec  9 09:50:21 livedemo sshd[4800]: debug3: PAM: sshpam_query entering
Dec  9 09:50:21 livedemo sshd[4800]: debug3: ssh_msg_recv entering
Dec  9 09:50:22 livedemo sshd[4801]: debug1: do_pam_account: called
Dec  9 09:50:22 livedemo sshd[4801]: debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
Dec  9 09:50:22 livedemo sshd[4801]: debug3: ssh_msg_send: type 0
Dec  9 09:50:22 livedemo sshd[4800]: debug3: PAM: import_environments entering
Dec  9 09:50:22 livedemo sshd[4800]: debug3: sshpam_password_change_required 0
Dec  9 09:50:22 livedemo sshd[4800]: debug3: PAM: num env strings 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: PAM: num PAM env strings 0
Dec  9 09:50:22 livedemo sshd[4800]: debug3: Wrote 48 bytes for a total of 1997
Dec  9 09:50:22 livedemo sshd[4800]: Postponed keyboard-interactive/pam for test from 192.168.1.111 port 38279 ssh2
Dec  9 09:50:22 livedemo sshd[4800]: debug2: PAM: sshpam_respond entering, 0 responses
Dec  9 09:50:22 livedemo sshd[4800]: debug3: PAM: sshpam_free_ctx entering
Dec  9 09:50:22 livedemo sshd[4800]: debug3: PAM: sshpam_thread_cleanup entering
Dec  9 09:50:22 livedemo sshd[4800]: debug1: do_pam_account: called
Dec  9 09:50:22 livedemo sshd[4800]: Accepted keyboard-interactive/pam for test from 192.168.1.111 port 38279 ssh2
Dec  9 09:50:22 livedemo sshd[4800]: debug3: Wrote 32 bytes for a total of 2029
Dec  9 09:50:22 livedemo sshd[4800]: debug1: PAM: establishing credentials
Dec  9 09:50:22 livedemo sshd[4800]: debug3: PAM: opening session
Dec  9 09:50:22 livedemo sshd[4800]: debug1: Entering interactive session for SSH2.
Dec  9 09:50:22 livedemo sshd[4800]: debug2: fd 4 setting O_NONBLOCK
Dec  9 09:50:22 livedemo sshd[4800]: debug2: fd 5 setting O_NONBLOCK
Dec  9 09:50:22 livedemo sshd[4800]: debug1: server_init_dispatch_20
Dec  9 09:50:22 livedemo sshd[4800]: debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
Dec  9 09:50:22 livedemo sshd[4800]: debug1: input_session_request
Dec  9 09:50:22 livedemo sshd[4800]: debug1: channel 0: new [server-session]
Dec  9 09:50:22 livedemo sshd[4800]: debug2: session_new: allocate (allocated 0 max 10)
Dec  9 09:50:22 livedemo sshd[4800]: debug3: session_unused: session id 0 unused
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_new: session 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_open: channel 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_open: session 0: link with channel 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: server_input_channel_open: confirm session
Dec  9 09:50:22 livedemo sshd[4800]: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
Dec  9 09:50:22 livedemo sshd[4800]: debug3: Wrote 48 bytes for a total of 2077
Dec  9 09:50:22 livedemo sshd[4800]: debug1: server_input_channel_req: channel 0 request env reply 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_by_channel: session 0 channel 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_input_channel_req: session 0 req env
Dec  9 09:50:22 livedemo sshd[4800]: debug2: Ignoring env request LANG: disallowed name
Dec  9 09:50:22 livedemo sshd[4800]: debug1: server_input_channel_req: channel 0 request subsystem reply 1
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_by_channel: session 0 channel 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_input_channel_req: session 0 req subsystem
Dec  9 09:50:22 livedemo sshd[4800]: subsystem request for sftp
Dec  9 09:50:22 livedemo sshd[4800]: debug1: subsystem: exec() internal-sftp
Dec  9 09:50:22 livedemo sshd[4800]: debug1: Forced command (config) '/usr/local/libexec/sftp-server'
Dec  9 09:50:22 livedemo sshd[4802]: debug1: PAM: reinitializing credentials
Dec  9 09:50:22 livedemo sshd[4802]: debug3: safely_chroot: checking '/'
Dec  9 09:50:22 livedemo sshd[4802]: debug3: safely_chroot: checking '/store/'
Dec  9 09:50:22 livedemo sshd[4802]: debug3: safely_chroot: checking '/store/drop/'
Dec  9 09:50:22 livedemo sshd[4802]: debug3: safely_chroot: checking '/store/drop/test'
Dec  9 09:50:22 livedemo sshd[4800]: debug2: fd 3 setting TCP_NODELAY
Dec  9 09:50:22 livedemo sshd[4800]: debug2: fd 8 setting O_NONBLOCK
Dec  9 09:50:22 livedemo sshd[4800]: debug2: fd 7 setting O_NONBLOCK
Dec  9 09:50:22 livedemo sshd[4800]: debug3: Wrote 80 bytes for a total of 2157
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: read<=0 rfd 8 len 0
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: read failed
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: close_read
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: input open -> drain
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: ibuf empty
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: send eof
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: input drain -> closed
Dec  9 09:50:22 livedemo sshd[4800]: debug2: notify_done: reading
Dec  9 09:50:22 livedemo sshd[4800]: debug1: Received SIGCHLD.
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_by_pid: pid 4802
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_exit_message: session 0 channel 0 pid 4802
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: request exit-signal confirm 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_exit_message: release channel 0
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: write failed
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: close_write
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: send eow
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: output open -> closed
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: send close
Dec  9 09:50:22 livedemo sshd[4800]: debug3: Wrote 192 bytes for a total of 2349
Dec  9 09:50:22 livedemo sshd[4800]: debug3: channel 0: will not send data after close
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: rcvd close
Dec  9 09:50:22 livedemo sshd[4800]: debug3: channel 0: will not send data after close
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: is dead
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: gc: notify user
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_by_channel: session 0 channel 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_close_by_channel: channel 0 child 0
Dec  9 09:50:22 livedemo sshd[4800]: debug1: session_close: session 0 pid 0
Dec  9 09:50:22 livedemo sshd[4800]: debug3: session_unused: session id 0 unused
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: gc: user detached
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: is dead
Dec  9 09:50:22 livedemo sshd[4800]: debug2: channel 0: garbage collecting
Dec  9 09:50:22 livedemo sshd[4800]: debug1: channel 0: free: server-session, nchannels 1
Dec  9 09:50:22 livedemo sshd[4800]: debug3: channel 0: status: The following connections are open:
  #0 server-session (t4 r0 i3/0 o3/0 fd -1/-1 cfd -1)

Dec  9 09:50:22 livedemo sshd[4800]: debug3: channel 0: close_fds r -1 w -1 e -1 c -1
Dec  9 09:50:22 livedemo sshd[4800]: Connection closed by 192.168.1.111
Dec  9 09:50:22 livedemo sshd[4800]: debug1: do_cleanup
Dec  9 09:50:22 livedemo sshd[4800]: debug1: PAM: cleanup
Dec  9 09:50:22 livedemo sshd[4800]: debug1: PAM: closing session
Dec  9 09:50:22 livedemo sshd[4800]: debug1: PAM: deleting credentials
Dec  9 09:50:22 livedemo sshd[4800]: debug3: PAM: sshpam_thread_cleanup entering
Dec  9 09:50:22 livedemo sshd[4800]: Transferred: sent 2120, received 1856 bytes
Dec  9 09:50:22 livedemo sshd[4800]: Closing connection to 192.168.1.111 port 38279

And, when not using the ChrootDirective. This is what the log looks like on a successful login POST password authentication:


Dec  9 09:52:13 livedemo sshd[4821]: debug2: PAM: sshpam_respond entering, 1 responses
Dec  9 09:52:13 livedemo sshd[4821]: debug3: ssh_msg_send: type 6
Dec  9 09:52:13 livedemo sshd[4821]: debug3: PAM: sshpam_query entering
Dec  9 09:52:13 livedemo sshd[4821]: debug3: ssh_msg_recv entering
Dec  9 09:52:13 livedemo sshd[4822]: debug1: do_pam_account: called
Dec  9 09:52:13 livedemo sshd[4822]: debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
Dec  9 09:52:13 livedemo sshd[4822]: debug3: ssh_msg_send: type 0
Dec  9 09:52:13 livedemo sshd[4821]: debug3: PAM: import_environments entering
Dec  9 09:52:13 livedemo sshd[4821]: debug3: sshpam_password_change_required 0
Dec  9 09:52:13 livedemo sshd[4821]: debug3: PAM: num env strings 0
Dec  9 09:52:13 livedemo sshd[4821]: debug1: PAM: num PAM env strings 0
Dec  9 09:52:13 livedemo sshd[4821]: debug3: Wrote 48 bytes for a total of 1997
Dec  9 09:52:13 livedemo sshd[4821]: Postponed keyboard-interactive/pam for test from 192.168.1.111 port 38281 ssh2
Dec  9 09:52:13 livedemo sshd[4821]: debug2: PAM: sshpam_respond entering, 0 responses
Dec  9 09:52:13 livedemo sshd[4821]: debug3: PAM: sshpam_free_ctx entering
Dec  9 09:52:13 livedemo sshd[4821]: debug3: PAM: sshpam_thread_cleanup entering
Dec  9 09:52:13 livedemo sshd[4821]: debug1: do_pam_account: called
Dec  9 09:52:13 livedemo sshd[4821]: Accepted keyboard-interactive/pam for test from 192.168.1.111 port 38281 ssh2
Dec  9 09:52:13 livedemo sshd[4821]: debug3: Wrote 32 bytes for a total of 2029
Dec  9 09:52:13 livedemo sshd[4821]: debug1: PAM: establishing credentials
Dec  9 09:52:13 livedemo sshd[4821]: debug3: PAM: opening session
Dec  9 09:52:13 livedemo sshd[4821]: debug1: Entering interactive session for SSH2.
Dec  9 09:52:13 livedemo sshd[4821]: debug2: fd 4 setting O_NONBLOCK
Dec  9 09:52:13 livedemo sshd[4821]: debug2: fd 5 setting O_NONBLOCK
Dec  9 09:52:13 livedemo sshd[4821]: debug1: server_init_dispatch_20
Dec  9 09:52:13 livedemo sshd[4821]: debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
Dec  9 09:52:13 livedemo sshd[4821]: debug1: input_session_request
Dec  9 09:52:13 livedemo sshd[4821]: debug1: channel 0: new [server-session]
Dec  9 09:52:13 livedemo sshd[4821]: debug2: session_new: allocate (allocated 0 max 10)
Dec  9 09:52:13 livedemo sshd[4821]: debug3: session_unused: session id 0 unused
Dec  9 09:52:13 livedemo sshd[4821]: debug1: session_new: session 0
Dec  9 09:52:13 livedemo sshd[4821]: debug1: session_open: channel 0
Dec  9 09:52:13 livedemo sshd[4821]: debug1: session_open: session 0: link with channel 0
Dec  9 09:52:13 livedemo sshd[4821]: debug1: server_input_channel_open: confirm session
Dec  9 09:52:13 livedemo sshd[4821]: debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
Dec  9 09:52:13 livedemo sshd[4821]: debug3: Wrote 48 bytes for a total of 2077
Dec  9 09:52:13 livedemo sshd[4821]: debug1: server_input_channel_req: channel 0 request env reply 0
Dec  9 09:52:13 livedemo sshd[4821]: debug1: session_by_channel: session 0 channel 0
Dec  9 09:52:13 livedemo sshd[4821]: debug1: session_input_channel_req: session 0 req env
Dec  9 09:52:13 livedemo sshd[4821]: debug2: Ignoring env request LANG: disallowed name
Dec  9 09:52:13 livedemo sshd[4821]: debug1: server_input_channel_req: channel 0 request subsystem reply 1
Dec  9 09:52:13 livedemo sshd[4821]: debug1: session_by_channel: session 0 channel 0
Dec  9 09:52:13 livedemo sshd[4821]: debug1: session_input_channel_req: session 0 req subsystem
Dec  9 09:52:13 livedemo sshd[4821]: subsystem request for sftp
Dec  9 09:52:13 livedemo sshd[4821]: debug1: subsystem: exec() internal-sftp
Dec  9 09:52:13 livedemo sshd[4821]: debug1: Forced command (config) '/usr/local/libexec/sftp-server'
Dec  9 09:52:13 livedemo sshd[4823]: debug1: PAM: reinitializing credentials
Dec  9 09:52:13 livedemo sshd[4823]: debug1: permanently_set_uid: 1002/9994
Dec  9 09:52:13 livedemo sshd[4823]: debug3: channel 0: close_fds r -1 w -1 e -1 c -1
Dec  9 09:52:13 livedemo sshd[4821]: debug2: fd 3 setting TCP_NODELAY
Dec  9 09:52:13 livedemo sshd[4821]: debug2: fd 8 setting O_NONBLOCK
Dec  9 09:52:13 livedemo sshd[4821]: debug2: fd 7 setting O_NONBLOCK
Dec  9 09:52:13 livedemo sshd[4821]: debug3: Wrote 80 bytes for a total of 2157
Dec  9 09:52:13 livedemo sshd[4821]: debug3: Wrote 144 bytes for a total of 2301
Dec  9 09:52:13 livedemo sshd[4821]: debug3: Wrote 112 bytes for a total of 2413

The above log is when the ChrootDirectory directive is not used. This is where a user is not allowed ssh and only can use sftp.

When you say suse10, do you mean SLES/SLED 10 or some openSUSE 10 level?

For SLES/SLED you may be better served at SUSE Linux Enterprise Desktop (SLED) - NOVELL FORUMS or SUSE Linux Enterprise Server (SLES) - NOVELL FORUMS.

When you mean openSUSE, you better upgrade to 11.2, because all 10 levels are out of support now.

Thank you for your response.

My apologies. Yes, I am using SLES10. I can not upgrade as this is what has been given to me for the company I work for and its what I have to work with.

We really need the chroot functionality of OpenSSH 5.3 and on a fresh install of SLES10 32-bit (and 64-bit as well), it seems to create the aforementioned problem where the user is automatically disconnected.

Although, I do know the ForceCommand works and have since deviated it is just the ChrootDirectory that seems to be causing a issue.

I think it only works with internal sftp otherwise you have to provide a chroot environment (various /dev and /etc files) at the target chroot directory. I have forcecommand chroot sftp working fine with the stock ssh package since 11.1.

I have also done “ForceCommand internal-sftp” but it still seems whenever I use the ChrootDirectory directive, it always acts up.

According to documentation, tutorials, and countless posts I’ve seen on the internet…the “ChrootDirectory” is supposed to chroot a user without having to go through all of the dirty tricks that you used to need to do (make_jail.sh, copy libs/bins/etc/, etc…).

Its supposed to, according to documentation, just “work” and chroot a user or group.

I don’t see how it could work without a properly set up jail if using an external sftp program. That’s exactly the reason the internal-sftp was provided, to make it simple. Here are my directives, which work with the ssh 5.1 in 11.1:

Match User alice,bob,charlie
ChrootDirectory %h
X11Forwarding no
AllowTcpForwarding no
ForceCommand internal-sftp
Match

Exactly my point. There is no need to setup a jailed environment anymore with the internal-sftp.

As previously stated, I have tried it the way you have just displayed in your post but I have received the same results. Tutorials on doing this have described it just the way you have and that was the initial try I did. Later debugging and troubleshooting proved whenever a call to the ChrootDirectory occurs, something fails. The log messages dont provide any real information though.

Also, I should note that when I try to use ChrootDirectory in a global option (which is possible as well) it errors out for every user that logs in. I used that as a test case to ensure it was a call to the ChrootDirectory directive.

Wow. Alright.

I guess I missed something along the way because it works fine.

:x:shame:

Sorry to bother.

I honestly don’t know what it was. I think it may have been the way my other SA had setup the original server I tried to do this on. I have gotten this to successfully work on a completely new installation of SLES10.

Nice you got it working.

But please do not tell the guys over there on SLES that we on openSUSE know also the SLES answers. lol!

Alright, will do lol!

Thanks again for all your help guys. I wish I had a more definitive answer as to why its now working so if anyone googles the same issues, they have can find this.

Good day, gentlemen!