| View previous topic :: View next topic |
| Author |
Message |
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
 Posted: Mon Jan 10, 2022 7:41 pm Post subject: Unable to use internal-sftp |
 |
|
Hello all,
I haven't changed anything about my configuration for OpenSSH or the internal-sftp directives to allow for SFTP-only chrooted users:
| Code: |
## override default of no subsystems
Subsystem sftp internal-sftp
## sftp connections
Match Group sftponly
ChrootDirectory %h
ForceCommand internal-sftp
AllowTcpForwarding no
PermitTunnel no
X11Forwarding no
|
or the permissions on the directories:
| Code: |
# ls -lh / | grep home
drwxr-xr-x 18 root root 4.0K Jun 10 2021 home
# ls -lh /home | grep sftp
drwxr-xr-x 16 root root 4.0K May 9 2020 sftpaccts
|
However, now any users in the 'sftponly' group fail to connect. I tested by temporarily removing a user from the group, and then SFTP works. Adding the user back into the 'sftponly' group causes the connection to immediately terminate after starting. I don't see anything helpful in the logs on the server side, but I do see an exit code of 134 from the client side:
| Code: |
sftp -vvv user@site
<snip>
debug1: Sending subsystem: sftp
debug2: channel_request_start: channel 0: request subsystem 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: subsystem request accepted on channel 0
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: chan_shutdown_write: channel 0: (i0 o1 sock -1 wfd 5 efd 6 [write])
debug2: channel 0: output drain -> closed
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype exit-signal reply 0
debug3: client_input_channel_req: remote killed by signal 'ABRT'
debug3: receive packet: type 98
debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0
debug2: channel 0: rcvd eow
debug2: chan_shutdown_read: channel 0: (i0 o3 sock -1 wfd 4 efd 6 [write])
debug1: fd 4 clearing O_NONBLOCK
debug2: channel 0: input open -> closed
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
Transferred: sent 2228, received 2776 bytes, in 0.1 seconds
Bytes per second: sent 15769.3, received 19647.9
debug1: Exit status 134
Connection closed.
Connection closed
|
Any suggestions on where to look next?
Thank you!
Cheers,
Nathan Zachary
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
 |
szatox
Advocate
Joined: 27 Aug 2013
Posts: 3131
|
| Posted: Mon Jan 10, 2022 8:46 pm Post subject: |
|
|
You're setting it up as a new thing, right? I mean, it didn't suddenly stop working?
| Quote: | | ChrootDirectory %h |
Is user's home owned by root? It is a common pitfall. The whole path must be owned by root. No idea why, seems dumb to me, but sshd won't chroot into user-owned directory.
To make it behave reasonably, you need either /home/user/home/user or /home/user/chroot/home/user. The first case will make user's ~/.ssh accessible to the session as /.ssh (if you want the user to update authorized_keys for example), and the last case will let you hide user's config files from him.
What else... Anything interesting in server-side log? And I mean sshd log? |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Mon Jan 10, 2022 9:48 pm Post subject: |
|
|
Actually, no, I have had this setup in place for years and it worked just fine. Unfortunately, though, I'm not certain when it stopped working. Probably within the last couple of months. I do have the /home/sftpaccts/ (and user directories there) owned by root. I don't see anything interesting in the sshd log, but here is an example of the failed login if you would like to see it:
| Code: |
Jan 10 16:44:23 [sshd] Postponed keyboard-interactive/pam for $USER from $IP port 56202 ssh2 [preauth]
Jan 10 16:44:23 [sshd] debug3: receive packet: type 61 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_sshpam_respond: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 108 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_sshpam_respond: waiting for MONITOR_ANS_PAM_RESPOND [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive_expect: entering, type 109 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering
Jan 10 16:44:23 [sshd] debug3: monitor_read: checking request 108
Jan 10 16:44:23 [sshd] debug3: mm_answer_pam_respond: entering
Jan 10 16:44:23 [sshd] debug2: sshpam_respond: PAM entering, 0 responses
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 109
Jan 10 16:44:23 [sshd] debug2: monitor_read: 108 used once, disabling now
Jan 10 16:44:23 [sshd] debug3: mm_sshpam_respond: pam_respond returned 0 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_sshpam_free_ctx: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 110 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_sshpam_free_ctx: waiting for MONITOR_ANS_PAM_FREE_CTX [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive_expect: entering, type 111 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering
Jan 10 16:44:23 [sshd] debug3: monitor_read: checking request 110
Jan 10 16:44:23 [sshd] debug3: mm_answer_pam_free_ctx: entering
Jan 10 16:44:23 [sshd] debug3: sshpam_free_ctx: PAM entering
Jan 10 16:44:23 [sshd] debug3: sshpam_thread_cleanup: PAM entering
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 111
Jan 10 16:44:23 [sshd] debug2: monitor_read: 110 used once, disabling now
Jan 10 16:44:23 [sshd] debug3: mm_request_receive_expect: entering, type 102
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering
Jan 10 16:44:23 [sshd] debug1: do_pam_account: called
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 103
Jan 10 16:44:23 [sshd] Accepted keyboard-interactive/pam for $USER from $IP port 56202 ssh2
Jan 10 16:44:23 [sshd] debug1: monitor_child_preauth: user $USER authenticated by privileged process
Jan 10 16:44:23 [sshd] debug3: mm_get_keystate: waiting for new keys
Jan 10 16:44:23 [sshd] debug3: mm_request_receive_expect: entering, type 26
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering
Jan 10 16:44:23 [sshd] debug3: mm_get_keystate: got new keys
Jan 10 16:44:23 [sshd] debug3: mm_do_pam_account: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 102 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive_expect: entering, type 103 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_do_pam_account: returning 1 [preauth]
Jan 10 16:44:23 [sshd] debug3: send packet: type 52 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 26 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_send_keystate: finished sending state [preauth]
Jan 10 16:44:23 [sshd] debug1: monitor_read_log: child log fd closed
Jan 10 16:44:23 [sshd] debug3: ssh_sandbox_parent_finish: finished
Jan 10 16:44:23 [sshd] debug1: PAM: establishing credentials
Jan 10 16:44:23 [sshd] debug3: PAM: opening session
Jan 10 16:44:23 [sshd] debug2: do_pam_session: auth information in SSH_AUTH_INFO_0
Jan 10 16:44:23 [sshd] pam_unix(sshd:session): session opened for user $USER(uid=2010) by (uid=0)
Jan 10 16:44:23 [sshd] debug3: sshpam_store_conv: PAM called with 1 messages
Jan 10 16:44:23 [sshd] User child is on pid 12774
Jan 10 16:44:23 [sshd] debug1: PAM: establishing credentials
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/'
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/home/'
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/home/sftpaccts/'
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/home/sftpaccts/$USER'
Jan 10 16:44:23 [sshd] debug3: receive packet: type 20 [preauth]
Jan 10 16:44:23 [sshd] debug1: SSH2_MSG_KEXINIT received [preauth]
Jan 10 16:44:23 [sshd] debug2: local server KEXINIT proposal [preauth]
Jan 10 16:44:23 [sshd] 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 [preauth]
Jan 10 16:44:23 [sshd] debug2: host key algorithms: ssh-rsa,rsa-sha2-256,rsa-sha2-512,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
Jan 10 16:44:23 [sshd] debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Jan 10 16:44:23 [sshd] debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
Jan 10 16:44:23 [sshd] 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 [preauth]
Jan 10 16:44:23 [sshd] 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 [preauth]
Jan 10 16:44:23 [sshd] debug2: compression ctos: none,zlib@openssh.com [preauth]
Jan 10 16:44:23 [sshd] debug2: compression stoc: none,zlib@openssh.com [preauth]
Jan 10 16:44:23 [sshd] debug2: languages ctos: [preauth]
Jan 10 16:44:23 [sshd] debug2: languages stoc: [preauth]
Jan 10 16:44:23 [sshd] debug2: first_kex_follows 0 [preauth]
Jan 10 16:44:23 [sshd] debug2: reserved 0 [preauth]
Jan 10 16:44:23 [sshd] debug2: peer client KEXINIT proposal [preauth]
Jan 10 16:44:23 [sshd] debug2: KEX algorithms: curve25519-sha256,curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group18-sha512,diffie-hellman-group16-sha512,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha256,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1,ext-info-c [preauth]
Jan 10 16:44:23 [sshd] debug2: host key algorithms: ssh-ed25519,ecdsa-sha2-nistp521,ecdsa-sha2-nistp384,ecdsa-sha2-nistp256,rsa-sha2-512,rsa-sha2-256,ssh-rsa,ssh-dss [preauth]
Jan 10 16:44:23 [sshd] debug2: ciphers ctos: aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-cbc [preauth]
Jan 10 16:44:23 [sshd] debug2: ciphers stoc: aes256-gcm@openssh.com,aes128-gcm@openssh.com,aes256-ctr,aes192-ctr,aes128-ctr,aes256-cbc,aes192-cbc,aes128-cbc,3des-cbc [preauth]
Jan 10 16:44:23 [sshd] debug2: MACs ctos: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
Jan 10 16:44:23 [sshd] debug2: MACs stoc: hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1 [preauth]
Jan 10 16:44:23 [sshd] debug2: compression ctos: none [preauth]
Jan 10 16:44:23 [sshd] debug2: compression stoc: none [preauth]
Jan 10 16:44:23 [sshd] debug2: languages ctos: [preauth]
Jan 10 16:44:23 [sshd] debug2: languages stoc: [preauth]
Jan 10 16:44:23 [sshd] debug2: first_kex_follows 0 [preauth]
Jan 10 16:44:23 [sshd] debug2: reserved 0 [preauth]
Jan 10 16:44:23 [sshd] debug1: kex: algorithm: curve25519-sha256 [preauth]
Jan 10 16:44:23 [sshd] debug1: kex: host key algorithm: ssh-ed25519 [preauth]
Jan 10 16:44:23 [sshd] debug1: kex: client->server cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none [preauth]
Jan 10 16:44:23 [sshd] debug1: kex: server->client cipher: aes256-gcm@openssh.com MAC: <implicit> compression: none [preauth]
Jan 10 16:44:23 [sshd] debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering
Jan 10 16:44:23 [sshd] debug1: do_cleanup
Jan 10 16:44:23 [sshd] debug1: PAM: cleanup
Jan 10 16:44:23 [sshd] debug1: PAM: closing session
Jan 10 16:44:23 [sshd] pam_unix(sshd:session): session closed for user $USER
Jan 10 16:44:23 [sshd] debug1: PAM: deleting credentials
Jan 10 16:44:23 [sshd] debug3: sshpam_thread_cleanup: PAM entering
Jan 10 16:44:23 [sshd] debug3: receive packet: type 30 [preauth]
Jan 10 16:44:23 [sshd] debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_Xkey_sign: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 6 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_Xkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive_expect: entering, type 7 [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering [preauth]
Jan 10 16:44:23 [sshd] debug3: mm_request_receive: entering
Jan 10 16:44:23 [sshd] debug3: monitor_read: checking request 6
Jan 10 16:44:23 [sshd] debug3: mm_answer_sign: entering
Jan 10 16:44:23 [sshd] debug3: Xkey_sign: return 0
Jan 10 16:44:23 [sshd] debug3: mm_answer_sign: ssh-ed25519 KEX signature len=83
Jan 10 16:44:23 [sshd] debug3: mm_request_send: entering, type 7
Jan 10 16:44:23 [sshd] debug2: monitor_read: 6 used once, disabling now
Jan 10 16:44:23 [sshd] debug3: send packet: type 31 [preauth]
Jan 10 16:44:23 [sshd] debug3: send packet: type 21 [preauth]
Jan 10 16:44:23 [sshd] debug2: ssh_set_newkeys: mode 1/out [preauth]
Jan 10 16:44:23 [sshd] debug1: rekey out after 4294967296 blocks [preauth]
Jan 10 16:44:23 [sshd] debug1: SSH2_MSG_NEWKEYS sent [preauth]
Jan 10 16:44:23 [sshd] debug1: expecting SSH2_MSG_NEWKEYS [preauth]
Jan 10 16:44:23 [sshd] debug1: Sending SSH2_MSG_EXT_INFO [preauth]
Jan 10 16:44:23 [sshd] debug3: send packet: type 7 [preauth]
Jan 10 16:44:23 [sshd] debug3: receive packet: type 21 [preauth]
Jan 10 16:44:23 [sshd] debug1: SSH2_MSG_NEWKEYS received [preauth]
Jan 10 16:44:23 [sshd] debug2: ssh_set_newkeys: mode 0/in [preauth]
Jan 10 16:44:23 [sshd] debug1: rekey in after 4294967296 blocks [preauth]
Jan 10 16:44:23 [sshd] debug1: KEX done [preauth]
Jan 10 16:44:24 [sshd] debug3: receive packet: type 5 [preauth]
Jan 10 16:44:24 [sshd] debug3: send packet: type 6 [preauth]
Jan 10 16:44:24 [sshd] debug3: receive packet: type 50 [preauth]
Jan 10 16:44:24 [sshd] debug1: userauth-request for user mine service ssh-connection method publickey [preauth]
Jan 10 16:44:24 [sshd] debug1: attempt 0 failures 0 [preauth]
Jan 10 16:44:24 [sshd] debug3: mm_getpwnamallow: entering [preauth]
Jan 10 16:44:24 [sshd] debug3: mm_request_send: entering, type 8 [preauth]
Jan 10 16:44:24 [sshd] debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
Jan 10 16:44:24 [sshd] debug3: mm_request_receive_expect: entering, type 9 [preauth]
Jan 10 16:44:24 [sshd] debug3: mm_request_receive: entering [preauth]
Jan 10 16:44:24 [sshd] debug3: mm_request_receive: entering
Jan 10 16:44:24 [sshd] debug3: monitor_read: checking request 8
Jan 10 16:44:24 [sshd] debug3: mm_answer_pwnamallow: entering
Jan 10 16:44:24 [sshd] debug2: parse_server_config_depth: config reprocess config len 6653
|
Thank you for your suggestions.
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Tue Jan 11, 2022 1:09 am Post subject: |
|
|
Interestingly, if I start another instance of sshd on a different port (2222 in this case), and I try to connect via SFTP, it actually kills the newly-spawned sshd:
| Code: |
# /usr/sbin/sshd -p 2222 -d
debug1: ssh_set_validator: ignore responder url
announced algorithms: x509v3-ecdsa-sha2-nistp256,x509v3-ecdsa-sha2-nistp384,x509v3-ecdsa-sha2-nistp521,x509v3-rsa2048-sha256,x509v3-ssh-rsa,x509v3-sign-rsa,x509v3-ssh-dss,x509v3-sign-dss,ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
debug1: sshd version OpenSSH_8.8p1-PKIXSSH-13.2.3, OpenSSL 1.1.1m 14 Dec 2021
debug1: private host key #0: ssh-rsa SHA256:fHPqxHgJ5Sxfn9BkHFYDhaKE9WqFkXqK61SVv9Ktr+M
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:3/BEtm/lIeL6kHxpve4fgUColERoeiwHXf2HeSFuqKM
debug1: private host key #2: ssh-ed25519 SHA256:O5B6iN2OJ4V3JlkbQNGlqciZ0Lkx0+T9K5+adOYt6fI
debug1: rexec_argv[0]='/usr/sbin/sshd'
debug1: rexec_argv[1]='-p'
debug1: rexec_argv[2]='2222'
debug1: rexec_argv[3]='-d'
debug1: Set /proc/self/oom_score_adj from 0 to -1000
debug1: Bind to port 2222 on 0.0.0.0.
Server listening on 0.0.0.0 port 2222.
debug1: Bind to port 2222 on ::.
Server listening on :: port 2222.
debug1: Server will not fork when running in debugging mode.
debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8
debug1: ssh_set_validator: ignore responder url
announced algorithms: x509v3-ecdsa-sha2-nistp256,x509v3-ecdsa-sha2-nistp384,x509v3-ecdsa-sha2-nistp521,x509v3-rsa2048-sha256,x509v3-ssh-rsa,x509v3-sign-rsa,x509v3-ssh-dss,x509v3-sign-dss,ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
debug1: sshd version OpenSSH_8.8p1-PKIXSSH-13.2.3, OpenSSL 1.1.1m 14 Dec 2021
debug1: private host key #0: ssh-rsa SHA256:fHPqxHgJ5Sxfn9BkHFYDhaKE9WqFkXqK61SVv9Ktr+M
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:3/BEtm/lIeL6kHxpve4fgUColERoeiwHXf2HeSFuqKM
debug1: private host key #2: ssh-ed25519 SHA256:O5B6iN2OJ4V3JlkbQNGlqciZ0Lkx0+T9K5+adOYt6fI
debug1: inetd sockets after dupping: 3, 3
Connection from $IP port 58456 on 199.48.130.90 port 2222 rdomain ""
debug1: Local version string SSH-2.0-OpenSSH_8.8p1-PKIXSSH-13.2.3 PKIX[13.2.3]
debug1: Remote protocol version 2.0, remote software version OpenSSH_8.8p1-PKIXSSH-13.2.3-hpn15v2 PKIX[13.2.3]
debug1: match: OpenSSH_8.8p1-PKIXSSH-13.2.3-hpn15v2 PKIX[13.2.3] pat OpenSSH* compat 0x04000000
debug1: x.509 compatibility rfc6187_missing_key_identifier=no: pattern 'OpenSSH*PKIX[??.*' match 'OpenSSH_8.8p1-PKIXSSH-13.2.3-hpn15v2 PKIX[13.2.3]'
debug1: x.509 compatibility rfc6187_asn1_opaque_ecdsa_signature=no: pattern 'OpenSSH*PKIX[??.*' match 'OpenSSH_8.8p1-PKIXSSH-13.2.3-hpn15v2 PKIX[13.2.3]'
debug1: x.509 compatibility broken list with accepted publickey algorithms=no: pattern 'OpenSSH*PKIX*' match 'OpenSSH_8.8p1-PKIXSSH-13.2.3-hpn15v2 PKIX[13.2.3]'
debug1: permanently_set_uid: 22/22 [preauth]
debug1: list_hostkey_types: ssh-rsa,rsa-sha2-256,rsa-sha2-512,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug1: kex: algorithm: curve25519-sha256 [preauth]
debug1: kex: host key algorithm: ssh-ed25519 [preauth]
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
debug1: rekey out after 134217728 blocks [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug1: Sending SSH2_MSG_EXT_INFO [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug1: rekey in after 134217728 blocks [preauth]
debug1: KEX done [preauth]
debug1: userauth-request for user $USER service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug1: user $USER matched group list sftponly at line 206
debug1: PAM: initializing for "$USER"
debug1: PAM: setting PAM_RHOST to "$IP"
debug1: PAM: setting PAM_TTY to "ssh"
debug1: userauth-request for user $USER service ssh-connection method keyboard-interactive [preauth]
debug1: attempt 1 failures 0 [preauth]
debug1: keyboard-interactive devs [preauth]
debug1: auth2_challenge: user=$USER devs= [preauth]
debug1: kbdint_alloc: devices 'pam' [preauth]
debug1: auth2_challenge_start: trying authentication method 'pam' [preauth]
Postponed keyboard-interactive for $USER from $IP port 58456 ssh2 [preauth]
debug1: do_pam_account: called
debug1: PAM: num PAM env strings 2
Postponed keyboard-interactive/pam for $USER from $IP port 58456 ssh2 [preauth]
debug1: do_pam_account: called
Accepted keyboard-interactive/pam for $USER from $IP port 58456 ssh2
debug1: monitor_child_preauth: user $USER authenticated by privileged process
debug1: monitor_read_log: child log fd closed
debug1: PAM: establishing credentials
User child is on pid 27402
debug1: PAM: establishing credentials
Changed root directory to "/home/sftpaccts/$USER"
debug1: permanently_set_uid: 2010/2010
debug1: rekey in after 134217728 blocks
debug1: rekey out after 134217728 blocks
debug1: ssh_packet_set_postauth: called
debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Entering interactive session for SSH2.
debug1: server_init_dispatch
debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
debug1: input_session_request
debug1: channel 0: new [server-session]
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug1: server_input_channel_req: channel 0 request subsystem reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req subsystem
debug1: subsystem: internal-sftp
Starting session: forced-command (config) 'internal-sftp' for $USER from $IP port 58456 id 0
debug1: Received SIGCHLD.
debug1: session_by_pid: pid 27403
debug1: session_exit_message: session 0 channel 0 pid 27403
debug1: session_exit_message: release channel 0
Received disconnect from $IP port 58456: reason 11 - disconnected by user
Disconnected from user $USER $IP port 58456
debug1: do_cleanup
debug1: do_cleanup
debug1: PAM: cleanup
debug1: PAM: closing session
debug1: PAM: deleting credentials
|
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Tue Jan 11, 2022 5:49 am Post subject: |
|
|
I found one more clue. If I remove the 'ChrootDirectory' directive from sshd_config, then I am able to connect via SFTP. Obviously, though, that then allows the user to traverse directories above their designated home directory chroot. If I then put the 'ChrootDirectory %h' directive back in place, the connection immediately closes. So, it must be something related to the chroot, but I can't figure out what. The permissions seem to be correct.
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
szatox
Advocate
Joined: 27 Aug 2013
Posts: 3131
|
| Posted: Tue Jan 11, 2022 3:14 pm Post subject: |
|
|
Huh.... What happens if you replace %h with an actual path to user's home?
If the above fails, does it work with a new directory (created by root) directly under root?
What if you leave chroot jail in place and disable force-command instead? |
|
| Back to top |
|
|
pingtoo
l33t
Joined: 10 Sep 2021
Posts: 920
Location: Richmond Hill, Canada
|
| Posted: Tue Jan 11, 2022 4:41 pm Post subject: |
|
|
I use your setting set a test, it work for me. so let's compare notes to see what may cause the issue.
My sshd_config -- generated/modified from gentoo's stock openssh package with your setting (modified with my test account/group)
| Code: | pi-3 /tmp # sed '/^#/d' </etc/ssh/sshd_config > /tmp/sshd_config
#
# paste in your sftp setting
#
pi-3 /tmp # cat /tmp/sshd_config
PasswordAuthentication no
UsePAM yes
PrintMotd no
PrintLastLog no
Subsystem sftp internal-sftp
## sftp connections
Match Group me
ChrootDirectory %h
ForceCommand internal-sftp
AllowTcpForwarding no
PermitTunnel no
X11Forwarding no
AcceptEnv LANG LC_ALL LC_COLLATE LC_CTYPE LC_MESSAGES LC_MONETARY LC_NUMERIC LC_TIME LANGUAGE LC_ADDRESS LC_IDENTIFICATION LC_MEASUREMENT LC_NAME LC_PAPER LC_TELEPHONE
AcceptEnv COLORTERM
pi-3 /tmp # |
Start new sshd with alternaltive port and config
| Code: | | /usr/sbin/sshd -ddd -p 22222 -f /tmp/sshd_config |
ssd session output
| Code: | pi-3 /tmp # /usr/sbin/sshd -ddd -p 22222 -f /tmp/sshd_config
debug2: load_server_config: filename /tmp/sshd_config
debug2: load_server_config: done config len = 428
debug2: parse_server_config_depth: config /tmp/sshd_config len 428
debug3: /tmp/sshd_config:16 setting PasswordAuthentication no
debug3: /tmp/sshd_config:21 setting UsePAM yes
debug3: /tmp/sshd_config:23 setting PrintMotd no
debug3: /tmp/sshd_config:24 setting PrintLastLog no
debug3: /tmp/sshd_config:27 setting Subsystem sftp internal-sftp
debug3: checking syntax for 'Match Group me'
debug1: sshd version OpenSSH_8.6, OpenSSL 1.1.1k 25 Mar 2021
debug1: private host key #0: ssh-rsa SHA256:XXXXXXXXXXXXX
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:XXXXXXXXXXXXXXXXX
debug1: private host key #2: ssh-ed25519 SHA256:XXXXXXXXXXXXXXXXX
debug1: rexec_argv[0]='/usr/sbin/sshd'
debug1: rexec_argv[1]='-ddd'
debug1: rexec_argv[2]='-p'
debug1: rexec_argv[3]='22222'
debug1: rexec_argv[4]='-f'
debug1: rexec_argv[5]='/tmp/sshd_config'
debug3: oom_adjust_setup
debug1: Set /proc/self/oom_score_adj from 0 to -1000
debug2: fd 3 setting O_NONBLOCK
debug1: Bind to port 22222 on 0.0.0.0.
Server listening on 0.0.0.0 port 22222.
debug2: fd 4 setting O_NONBLOCK
debug3: sock_set_v6only: set socket 4 IPV6_V6ONLY
debug1: Bind to port 22222 on ::.
Server listening on :: port 22222.
debug3: fd 5 is not O_NONBLOCK
debug1: Server will not fork when running in debugging mode.
debug3: send_rexec_state: entering fd = 8 config len 428
debug3: ssh_msg_send: type 0
debug3: send_rexec_state: done
debug1: rexec start in 5 out 5 newsock 5 pipe -1 sock 8
debug3: recv_rexec_state: entering fd = 5
debug3: ssh_msg_recv entering
debug3: recv_rexec_state: done
debug2: parse_server_config_depth: config rexec len 428
debug3: rexec:16 setting PasswordAuthentication no
debug3: rexec:21 setting UsePAM yes
debug3: rexec:23 setting PrintMotd no
debug3: rexec:24 setting PrintLastLog no
debug3: rexec:27 setting Subsystem sftp internal-sftp
debug3: checking syntax for 'Match Group me'
debug1: sshd version OpenSSH_8.6, OpenSSL 1.1.1k 25 Mar 2021
debug1: private host key #0: ssh-rsa SHA256:XXXXXXXXXXXXXXXXXXXXXX
debug1: private host key #1: ecdsa-sha2-nistp256 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXX
debug1: private host key #2: ssh-ed25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXX
debug1: inetd sockets after dupping: 3, 3
Connection from ::1 port 54938 on ::1 port 22222 rdomain ""
debug1: Local version string SSH-2.0-OpenSSH_8.6
debug1: Remote protocol version 2.0, remote software version OpenSSH_8.6
debug1: compat_banner: match: OpenSSH_8.6 pat OpenSSH* compat 0x04000000
debug2: fd 3 setting O_NONBLOCK
debug3: ssh_sandbox_init: preparing seccomp filter sandbox
debug2: Network child is on pid 11887
debug3: preauth child monitor started
debug3: privsep user:group 22:22 [preauth]
debug1: permanently_set_uid: 22/22 [preauth]
debug3: ssh_sandbox_child: setting PR_SET_NO_NEW_PRIVS [preauth]
debug3: ssh_sandbox_child: attaching seccomp filter program [preauth]
debug1: list_hostkey_types: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug3: send packet: type 20 [preauth]
debug1: SSH2_MSG_KEXINIT sent [preauth]
debug3: receive packet: type 20 [preauth]
debug1: SSH2_MSG_KEXINIT received [preauth]
debug2: local server KEXINIT proposal [preauth]
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 [preauth]
debug2: host key algorithms: rsa-sha2-512,rsa-sha2-256,ssh-rsa,ecdsa-sha2-nistp256,ssh-ed25519 [preauth]
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
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 [preauth]
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 [preauth]
debug2: compression ctos: none,zlib@openssh.com [preauth]
debug2: compression stoc: none,zlib@openssh.com [preauth]
debug2: languages ctos: [preauth]
debug2: languages stoc: [preauth]
debug2: first_kex_follows 0 [preauth]
debug2: reserved 0 [preauth]
debug2: peer client KEXINIT proposal [preauth]
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 [preauth]
debug2: host key algorithms: ssh-ed25519-cert-v01@openssh.com,ecdsa-sha2-nistp256-cert-v01@openssh.com,ecdsa-sha2-nistp384-cert-v01@openssh.com,ecdsa-sha2-nistp521-cert-v01@openssh.com,sk-ssh-ed25519-cert-v01@openssh.com,sk-ecdsa-sha2-nistp256-cert-v01@openssh.com,rsa-sha2-512-cert-v01@openssh.com,rsa-sha2-256-cert-v01@openssh.com,ssh-rsa-cert-v01@openssh.com,ssh-ed25519,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521,sk-ssh-ed25519@openssh.com,sk-ecdsa-sha2-nistp256@openssh.com,rsa-sha2-512,rsa-sha2-256,ssh-rsa [preauth]
debug2: ciphers ctos: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
debug2: ciphers stoc: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com [preauth]
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 [preauth]
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 [preauth]
debug2: compression ctos: none,zlib@openssh.com,zlib [preauth]
debug2: compression stoc: none,zlib@openssh.com,zlib [preauth]
debug2: languages ctos: [preauth]
debug2: languages stoc: [preauth]
debug2: first_kex_follows 0 [preauth]
debug2: reserved 0 [preauth]
debug1: kex: algorithm: curve25519-sha256 [preauth]
debug1: kex: host key algorithm: ssh-ed25519 [preauth]
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: none [preauth]
debug1: expecting SSH2_MSG_KEX_ECDH_INIT [preauth]
debug3: receive packet: type 30 [preauth]
debug1: SSH2_MSG_KEX_ECDH_INIT received [preauth]
debug3: mm_sshkey_sign: entering [preauth]
debug3: mm_request_send: entering, type 6 [preauth]
debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN [preauth]
debug3: mm_request_receive_expect: entering, type 7 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 6
debug3: mm_answer_sign: entering
debug3: mm_answer_sign: KEX signature 0x556539e570(83)
debug3: mm_request_send: entering, type 7
debug2: monitor_read: 6 used once, disabling now
debug3: send packet: type 31 [preauth]
debug3: send packet: type 21 [preauth]
debug2: set_newkeys: mode 1 [preauth]
debug1: rekey out after 134217728 blocks [preauth]
debug1: SSH2_MSG_NEWKEYS sent [preauth]
debug1: Sending SSH2_MSG_EXT_INFO [preauth]
debug3: send packet: type 7 [preauth]
debug1: expecting SSH2_MSG_NEWKEYS [preauth]
debug3: receive packet: type 21 [preauth]
debug1: SSH2_MSG_NEWKEYS received [preauth]
debug2: set_newkeys: mode 0 [preauth]
debug1: rekey in after 134217728 blocks [preauth]
debug1: KEX done [preauth]
debug3: receive packet: type 5 [preauth]
debug3: send packet: type 6 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user me service ssh-connection method none [preauth]
debug1: attempt 0 failures 0 [preauth]
debug3: mm_getpwnamallow: entering [preauth]
debug3: mm_request_send: entering, type 8 [preauth]
debug3: mm_getpwnamallow: waiting for MONITOR_ANS_PWNAM [preauth]
debug3: mm_request_receive_expect: entering, type 9 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 8
debug3: mm_answer_pwnamallow: entering
debug2: parse_server_config_depth: config reprocess config len 428
debug3: checking match for 'Group me' user me host ::1 addr ::1 laddr ::1 lport 22222
debug1: user me matched group list me at line 30
debug3: match found
debug3: reprocess config:31 setting ChrootDirectory %h
debug3: reprocess config:32 setting ForceCommand internal-sftp
debug3: reprocess config:33 setting AllowTcpForwarding no
debug3: reprocess config:34 setting PermitTunnel no
debug3: reprocess config:35 setting X11Forwarding no
debug3: reprocess config:38 setting AcceptEnv LANG LC_ALL LC_COLLATE LC_CTYPE LC_MESSAGES LC_MONETARY LC_NUMERIC LC_TIME LANGUAGE LC_ADDRESS LC_IDENTIFICATION LC_MEASUREMENT LC_NAME LC_PAPER LC_TELEPHONE
debug3: reprocess config:40 setting AcceptEnv COLORTERM
debug3: mm_answer_pwnamallow: sending MONITOR_ANS_PWNAM: 1
debug3: mm_request_send: entering, type 9
debug2: monitor_read: 8 used once, disabling now
debug2: input_userauth_request: setting up authctxt for me [preauth]
debug3: mm_start_pam entering [preauth]
debug3: mm_request_send: entering, type 100 [preauth]
debug3: mm_inform_authserv: entering [preauth]
debug3: mm_request_send: entering, type 4 [preauth]
debug2: input_userauth_request: try method none [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 3.912ms, delaying 1.682ms (requested 5.594ms) [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 100
debug1: PAM: initializing for "me"
debug1: PAM: setting PAM_RHOST to "::1"
debug1: PAM: setting PAM_TTY to "ssh"
debug2: monitor_read: 100 used once, disabling now
debug3: userauth_finish: failure partial=0 next methods="publickey,keyboard-interactive" [preauth]
debug3: send packet: type 51 [preauth]
debug3: receive packet: type 50 [preauth]
debug1: userauth-request for user me service ssh-connection method keyboard-interactive [preauth]
debug1: attempt 1 failures 0 [preauth]
debug2: input_userauth_request: try method keyboard-interactive [preauth]
debug1: keyboard-interactive devs [preauth]
debug1: auth2_challenge: user=me devs= [preauth]
debug1: kbdint_alloc: devices 'pam' [preauth]
debug2: auth2_challenge_start: devices pam [preauth]
debug2: kbdint_next_device: devices <empty> [preauth]
debug1: auth2_challenge_start: trying authentication method 'pam' [preauth]
debug3: mm_sshpam_init_ctx [preauth]
debug3: mm_request_send: entering, type 104 [preauth]
debug3: mm_sshpam_init_ctx: waiting for MONITOR_ANS_PAM_INIT_CTX [preauth]
debug3: mm_request_receive_expect: entering, type 105 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 4
debug3: mm_answer_authserv: service=ssh-connection, style=
debug2: monitor_read: 4 used once, disabling now
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 104
debug3: mm_answer_pam_init_ctx
debug3: PAM: sshpam_init_ctx entering
debug2: sshpam_init_ctx: auth information in SSH_AUTH_INFO_0
debug3: mm_request_send: entering, type 105
debug2: monitor_read: 104 used once, disabling now
debug3: mm_sshpam_query [preauth]
debug3: mm_request_send: entering, type 106 [preauth]
debug3: mm_sshpam_query: waiting for MONITOR_ANS_PAM_QUERY [preauth]
debug3: mm_request_receive_expect: entering, type 107 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 106
debug3: mm_answer_pam_query
debug3: PAM: sshpam_query entering
debug3: ssh_msg_recv entering
debug3: PAM: sshpam_thread_conv entering, 1 messages
debug3: ssh_msg_send: type 1
debug3: ssh_msg_recv entering
debug3: mm_request_send: entering, type 107
debug3: mm_sshpam_query: pam_query returned 0 [preauth]
debug3: send packet: type 60 [preauth]
debug3: user_specific_delay: user specific delay 0.000ms [preauth]
debug3: ensure_minimum_time_since: elapsed 7.628ms, delaying 3.560ms (requested 5.594ms) [preauth]
Postponed keyboard-interactive for me from ::1 port 54938 ssh2 [preauth]
debug3: receive packet: type 61 [preauth]
debug3: mm_sshpam_respond [preauth]
debug3: mm_request_send: entering, type 108 [preauth]
debug3: mm_sshpam_respond: waiting for MONITOR_ANS_PAM_RESPOND [preauth]
debug3: mm_request_receive_expect: entering, type 109 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 108
debug3: mm_answer_pam_respond
debug2: PAM: sshpam_respond entering, 1 responses
debug3: ssh_msg_send: type 6
debug3: mm_request_send: entering, type 109
debug2: monitor_read: 108 used once, disabling now
debug3: mm_sshpam_respond: pam_respond returned 1 [preauth]
debug3: mm_sshpam_query [preauth]
debug3: mm_request_send: entering, type 106 [preauth]
debug3: mm_sshpam_query: waiting for MONITOR_ANS_PAM_QUERY [preauth]
debug3: mm_request_receive_expect: entering, type 107 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 106
debug3: mm_answer_pam_query
debug3: PAM: sshpam_query entering
debug3: ssh_msg_recv entering
debug1: do_pam_account: called
debug2: do_pam_account: auth information in SSH_AUTH_INFO_0
debug3: PAM: do_pam_account pam_acct_mgmt = 0 (Success)
debug3: ssh_msg_send: type 0
debug3: PAM: import_environments entering
debug3: sshpam_password_change_required 0
debug3: PAM: num env strings 0
debug1: PAM: num PAM env strings 2
debug3: mm_request_send: entering, type 107
debug3: mm_sshpam_query: pam_query returned 0 [preauth]
debug3: send packet: type 60 [preauth]
Postponed keyboard-interactive/pam for me from ::1 port 54938 ssh2 [preauth]
debug3: receive packet: type 61 [preauth]
debug3: mm_sshpam_respond [preauth]
debug3: mm_request_send: entering, type 108 [preauth]
debug3: mm_sshpam_respond: waiting for MONITOR_ANS_PAM_RESPOND [preauth]
debug3: mm_request_receive_expect: entering, type 109 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 108
debug3: mm_answer_pam_respond
debug2: PAM: sshpam_respond entering, 0 responses
debug3: mm_request_send: entering, type 109
debug2: monitor_read: 108 used once, disabling now
debug3: mm_sshpam_respond: pam_respond returned 0 [preauth]
debug3: mm_sshpam_free_ctx [preauth]
debug3: mm_request_send: entering, type 110 [preauth]
debug3: mm_sshpam_free_ctx: waiting for MONITOR_ANS_PAM_FREE_CTX [preauth]
debug3: mm_request_receive_expect: entering, type 111 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 110
debug3: mm_answer_pam_free_ctx
debug3: PAM: sshpam_free_ctx entering
debug3: PAM: sshpam_thread_cleanup entering
debug3: mm_request_send: entering, type 111
debug2: monitor_read: 110 used once, disabling now
debug3: mm_request_receive_expect: entering, type 102
debug3: mm_request_receive: entering
debug1: do_pam_account: called
debug3: mm_request_send: entering, type 103
Accepted keyboard-interactive/pam for me from ::1 port 54938 ssh2
debug1: monitor_child_preauth: user me authenticated by privileged process
debug3: mm_get_keystate: Waiting for new keys
debug3: mm_request_receive_expect: entering, type 26
debug3: mm_request_receive: entering
debug3: mm_get_keystate: GOT new keys
debug3: mm_do_pam_account entering [preauth]
debug3: mm_request_send: entering, type 102 [preauth]
debug3: mm_request_receive_expect: entering, type 103 [preauth]
debug3: mm_request_receive: entering [preauth]
debug3: mm_do_pam_account returning 1 [preauth]
debug3: send packet: type 52 [preauth]
debug3: mm_request_send: entering, type 26 [preauth]
debug3: mm_send_keystate: Finished sending state [preauth]
debug1: monitor_read_log: child log fd closed
debug3: ssh_sandbox_parent_finish: finished
debug1: PAM: establishing credentials
debug3: PAM: opening session
debug2: do_pam_session: auth information in SSH_AUTH_INFO_0
User child is on pid 11890
debug1: PAM: establishing credentials
debug3: safely_chroot: checking '/'
debug3: safely_chroot: checking '/home/'
debug3: safely_chroot: checking '/home/me'
Changed root directory to "/home/me"
debug1: permanently_set_uid: 1001/1001
debug3: monitor_apply_keystate: packet_set_state
debug2: set_newkeys: mode 0
debug1: rekey in after 134217728 blocks
debug2: set_newkeys: mode 1
debug1: rekey out after 134217728 blocks
debug1: ssh_packet_set_postauth: called
debug3: ssh_packet_set_state: done
debug3: notify_hostkeys: key 0: ssh-rsa SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXX
debug3: notify_hostkeys: key 1: ecdsa-sha2-nistp256 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXX
debug3: notify_hostkeys: key 2: ssh-ed25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXX
debug3: notify_hostkeys: sent 3 hostkeys
debug3: send packet: type 80
debug1: active: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Entering interactive session for SSH2.
debug2: fd 7 setting O_NONBLOCK
debug2: fd 8 setting O_NONBLOCK
debug1: server_init_dispatch
debug3: receive packet: type 90
debug1: server_input_channel_open: ctype session rchan 0 win 2097152 max 32768
debug1: input_session_request
debug1: channel 0: new [server-session]
debug2: session_new: allocate (allocated 0 max 10)
debug3: session_unused: session id 0 unused
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug3: send packet: type 91
debug3: receive packet: type 80
debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
debug3: receive packet: type 80
debug1: server_input_global_request: rtype hostkeys-prove-00@openssh.com want_reply 1
debug3: mm_sshkey_sign: entering
debug3: mm_request_send: entering, type 6
debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN
debug3: mm_request_receive: entering
debug3: mm_request_receive_expect: entering, type 7
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 6
debug3: mm_answer_sign: entering
debug3: mm_answer_sign: hostkey proof signature 0x55653a74a0(399)
debug3: mm_request_send: entering, type 7
debug3: mm_sshkey_sign: entering
debug3: mm_request_send: entering, type 6
debug3: mm_sshkey_sign: waiting for MONITOR_ANS_SIGN
debug3: mm_request_receive: entering
debug3: mm_request_receive_expect: entering, type 7
debug3: mm_request_receive: entering
debug3: monitor_read: checking request 6
debug3: mm_answer_sign: entering
debug3: mm_answer_sign: hostkey proof signature 0x556538d1a0(100)
debug3: mm_request_send: entering, type 7
debug3: send packet: type 81
debug3: receive packet: type 98
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug2: Setting env 0: COLORTERM=truecolor
debug3: receive packet: type 98
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug2: Setting env 1: LANG=en_CA.utf8
debug3: receive packet: type 98
debug1: server_input_channel_req: channel 0 request subsystem reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req subsystem
debug2: subsystem request for sftp by user me
debug1: subsystem: internal-sftp
Starting session: forced-command (config) 'internal-sftp' for me from ::1 port 54938 id 0
debug2: fd 3 setting TCP_NODELAY
debug3: set_sock_tos: set socket 3 IPV6_TCLASS 0x20
debug2: fd 11 setting O_NONBLOCK
debug2: fd 10 setting O_NONBLOCK
debug2: fd 13 setting O_NONBLOCK
debug3: send packet: type 99
debug2: channel 0: read 557 from efd 13
debug3: channel 0: discard efd
debug2: channel 0: read 822 from efd 13
debug3: channel 0: discard efd
debug2: channel 0: read 394 from efd 13
debug3: channel 0: discard efd
debug2: channel 0: read 294 from efd 13
debug3: channel 0: discard efd
debug2: channel 0: read 1331 from efd 13
debug3: channel 0: discard efd
debug2: channel 0: read 247 from efd 13
debug3: channel 0: discard efd
debug3: receive packet: type 96
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: chan_shutdown_write: channel 0: (i0 o1 sock -1 wfd 10 efd 13 [ignore])
debug2: channel 0: output drain -> closed
debug2: channel 0: read<=0 rfd 11 len 0
debug2: channel 0: read failed
debug2: chan_shutdown_read: channel 0: (i0 o3 sock -1 wfd 11 efd 13 [ignore])
debug2: channel 0: input open -> drain
debug2: channel 0: read 0 from efd 13
debug2: channel 0: closing read-efd 13
debug2: channel 0: ibuf empty
debug2: channel 0: send eof
debug3: send packet: type 96
debug2: channel 0: input drain -> closed
debug2: notify_done: reading
debug1: Received SIGCHLD.
debug1: session_by_pid: pid 11891
debug1: session_exit_message: session 0 channel 0 pid 11891
debug2: channel 0: request exit-status confirm 0
debug3: send packet: type 98
debug1: session_exit_message: release channel 0
debug2: channel 0: send close
debug3: send packet: type 97
debug3: channel 0: will not send data after close
debug3: receive packet: type 97
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: is dead
debug2: channel 0: gc: notify user
debug1: session_by_channel: session 0 channel 0
debug1: session_close_by_channel: channel 0 child 0
Close session: user me from ::1 port 54938 id 0
debug3: session_unused: session id 0 unused
debug2: channel 0: gc: user detached
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: server-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 server-session (t4 r0 i3/0 o3/0 e[closed]/0 fd -1/-1/-1 sock -1 cc -1)
debug3: receive packet: type 1
Received disconnect from ::1 port 54938:11: disconnected by user
Disconnected from user me ::1 port 54938
debug1: do_cleanup
debug3: PAM: sshpam_thread_cleanup entering
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 |
|
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Tue Jan 11, 2022 4:55 pm Post subject: |
|
|
Thank you for your reply. I don't see anything different about my sshd_config that would cause the problem:
| Code: |
# grep -v '^$\|^#' /etc/ssh/sshd_config
LogLevel INFO
PasswordAuthentication no
UsePAM yes
PrintMotd no
PrintLastLog no
UseDNS no
AcceptEnv LANG LC_ALL LC_COLLATE LC_CTYPE LC_MESSAGES LC_MONETARY LC_NUMERIC LC_TIME LANGUAGE LC_ADDRESS LC_IDENTIFICATION LC_MEASUREMENT LC_NAME LC_PAPER LC_TELEPHONE
AcceptEnv COLORTERM
DenyUsers root admin oracle mysqladmin test nagios pgsql postgres print
Subsystem sftp internal-sftp
Match Group sftponly
ChrootDirectory %h
ForceCommand internal-sftp
AllowTcpForwarding no
PermitTunnel no
X11Forwarding no
|
No change from switching %h to an actual home directory. No change when I created /chroottest and set it as the 'ChrootDirectory'. No change when I disabled the 'ForceCommand' but left the 'ChrootDirectory'.
So it does seem to be directly related to the ChrootDirectory directive, but I'm not sure why. 
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Tue Jan 11, 2022 5:12 pm Post subject: |
|
|
As another test, I decided to just issue the chroot command directly, and found this rather alarming error:
| Code: |
# chroot /home/sftpaccts/$USER/
chroot: failed to run command ‘/bin/bash’: No such file or directory
|
Yet, BASH is clearly there and functioning as intended:
| Code: |
# which bash
/bin/bash
# /bin/bash --version
GNU bash, version 5.1.16(1)-release (x86_64-pc-linux-gnu)
Copyright (C) 2020 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software; you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
|
I know that it is really looking for /home/sftpaccts/$USER/bin/bash, but I thought that was the point of using the OpenSSH built-in 'internal-sftp' command: no additional configuration should be needed, right?
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
Hu
Moderator
Joined: 06 Mar 2007
Posts: 21607
|
| Posted: Tue Jan 11, 2022 5:57 pm Post subject: |
|
|
| Correct. internal-sftp should work even in a chroot that has no libc. |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Tue Jan 11, 2022 6:02 pm Post subject: |
|
|
Thank you for confirming, Hu. Any suggestions on where to look next?
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
szatox
Advocate
Joined: 27 Aug 2013
Posts: 3131
|
| Posted: Tue Jan 11, 2022 6:20 pm Post subject: |
|
|
| Quote: | | As another test, I decided to just issue the chroot command directly, and found this rather alarming error: |
It is working as intended ™
| Quote: | | I know that it is really looking for /home/sftpaccts/$USER/bin/bash, but I thought that was the point of using the OpenSSH built-in 'internal-sftp' command: no additional configuration should be needed, right? |
Right.
Internal-sftp uses code that is already loaded before entering chroot. It does not attempt to start shell nor anything else from within the chroot, making your last test completely irrelevant. Unless the chroot call itself fails for whatever reason, like selinux. Which reminds me of dmesg... But nothing really makes sense here. After all, the other sshd says it did chroot into the directory.
The funny thing I noticed is that your previous tests show different behavior between ssh running as a service and launched on a non-standard port though.
| Quote: | Jan 10 16:44:23 [sshd] debug1: PAM: establishing credentials
Jan 10 16:44:23 [sshd] debug3: PAM: opening session
Jan 10 16:44:23 [sshd] debug2: do_pam_session: auth information in SSH_AUTH_INFO_0
Jan 10 16:44:23 [sshd] pam_unix(sshd:session): session opened for user $USER(uid=2010) by (uid=0)
Jan 10 16:44:23 [sshd] debug3: sshpam_store_conv: PAM called with 1 messages
Jan 10 16:44:23 [sshd] User child is on pid 12774
Jan 10 16:44:23 [sshd] debug1: PAM: establishing credentials
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/'
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/home/'
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/home/sftpaccts/'
Jan 10 16:44:23 [sshd] debug3: safely_chroot: checking '/home/sftpaccts/$USER'
Jan 10 16:44:23 [sshd] debug3: receive packet: type 20 [preauth]
Jan 10 16:44:23 [sshd] debug1: SSH2_MSG_KEXINIT received [preauth] |
| Quote: | debug1: PAM: establishing credentials
User child is on pid 27402
debug1: PAM: establishing credentials
Changed root directory to "/home/sftpaccts/$USER"
debug1: permanently_set_uid: 2010/2010 |
Even if we only take debug1 into account, these 2 appear to do different things.
Have you restarted your ssh service after changing configs? I wonder what other differences there are between those 2 sessions. |
|
| Back to top |
|
|
pingtoo
l33t
Joined: 10 Sep 2021
Posts: 920
Location: Richmond Hill, Canada
|
| Posted: Tue Jan 11, 2022 7:38 pm Post subject: |
|
|
NathanZachary
Do your sftp client is an automated process? could it be the client close the connection?
The reason I am asking is because in my test setup I have to set the chrooted directory permission be 700 and own by root or else sshd always failed with *fatal: bad ownership or modes for chroot directory "/home/me"*
but when the permission is set to 700 the sftp client cannot do anything other than *pwd*. So because client issue command got bad answer so it close?
Also in your post (that ran sshd on port 2222) that seems to be working because | NathanZachary wrote: | # /usr/sbin/sshd -p 2222 -d
debug1: ssh_set_validator: ignore responder url
announced algorithms: x509v3-ecdsa-sha2-nistp256,x509v3-ecdsa-sha2-nistp384,x509v3-ecdsa-sha2-nistp521,x509v3-rsa2048-sha256,x509v3-ssh-rsa,x509v3-sign-rsa,x509v3-ssh-dss,x509v3-sign-dss,ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
debug1: sshd version OpenSSH_8.8p1-PKIXSSH-13.2.3, OpenSSL 1.1.1m 14 Dec 2021
...
debug1: channel 0: new [server-session]
debug1: session_new: session 0
debug1: session_open: channel 0
debug1: session_open: session 0: link with channel 0
debug1: server_input_channel_open: confirm session
debug1: server_input_global_request: rtype no-more-sessions@openssh.com want_reply 0
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug1: server_input_channel_req: channel 0 request env reply 0
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req env
debug1: server_input_channel_req: channel 0 request subsystem reply 1
debug1: session_by_channel: session 0 channel 0
debug1: session_input_channel_req: session 0 req subsystem
debug1: subsystem: internal-sftp
Starting session: forced-command (config) 'internal-sftp' for $USER from $IP port 58456 id 0
debug1: Received SIGCHLD.
debug1: session_by_pid: pid 27403
debug1: session_exit_message: session 0 channel 0 pid 27403
debug1: session_exit_message: release channel 0
Received disconnect from $IP port 58456: reason 11 - disconnected by user <--- seems client close connection
Disconnected from user $USER $IP port 58456
debug1: do_cleanup
debug1: do_cleanup
debug1: PAM: cleanup
debug1: PAM: closing session
debug1: PAM: deleting credentials |
Also could you re-run a new sshd -ddd -p 2222 and share the output? |
|
| Back to top |
|
|
NathanZachary
Moderator
Joined: 30 Jan 2007
Posts: 2605
|
| Posted: Tue Jan 11, 2022 7:40 pm Post subject: |
|
|
Okay, so I guess I will never know what the actual problem was. I rebooted the host, and didn't change anything thereafter, but SFTP works just fine now. The host had been online for ~3 years, so maybe it was time (and as a bonus, I got to update the kernel from 5.1.x). 
Thank you to all who offered help with troubleshooting!
Cheers,
Nathan Zachary
_________________
“Truth, like infinity, is to be forever approached but never reached.” --Jean Ayres (1972)
---avatar cropped from =AimanStudio--- |
|
| Back to top |
|
|
|
|
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
|
|
Networking & Security
