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.