[scponly] SIGPIPE when trying to connect to chrooted scponly host
Mark Trolley
marktrolley at gmail.com
Sun Apr 5 18:29:23 EDT 2009
Sorry, didn't realize my reply went straight to you.
I don't know why it wasn't working but when I tried testing by
connecting locally (# sftp user at localhost) I got that in my log.
Here's what I get when I try from Filezilla from a remote host:
Apr 5 18:27:37 hanzy sshd[13625]: debug1: rexec start in 7 out 7
newsock 7 pipe 9 sock 10
Apr 5 18:27:37 hanzy sshd[13614]: debug1: Forked child 13625.
Apr 5 18:27:37 hanzy sshd[13625]: debug1: inetd sockets after dupping: 3, 3
Apr 5 18:27:37 hanzy sshd[13625]: Connection from 192.168.1.64 port 49302
Apr 5 18:27:37 hanzy sshd[13625]: debug1: Client protocol version
2.0; client software version PuTTY_Local:_Mar_25_2009_15:14:05
Apr 5 18:27:37 hanzy sshd[13625]: debug1: no match:
PuTTY_Local:_Mar_25_2009_15:14:05
Apr 5 18:27:37 hanzy sshd[13625]: debug1: Enabling compatibility mode
for protocol 2.0
Apr 5 18:27:37 hanzy sshd[13625]: debug1: Local version string
SSH-2.0-OpenSSH_5.1p1 Debian-5
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: initializing for "sftpuser"
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: setting PAM_RHOST to "wiggum"
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: setting PAM_TTY to "ssh"
Apr 5 18:27:38 hanzy sshd[13625]: Failed none for sftpuser from
192.168.1.64 port 49302 ssh2
Apr 5 18:27:38 hanzy sshd[13627]: debug1: do_pam_account: called
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: num PAM env strings 0
Apr 5 18:27:38 hanzy sshd[13625]: debug1: do_pam_account: called
Apr 5 18:27:38 hanzy sshd[13625]: Accepted keyboard-interactive/pam
for sftpuser from 192.168.1.64 port 49302 ssh2
Apr 5 18:27:38 hanzy sshd[13625]: debug1: monitor_child_preauth:
sftpuser has been authenticated by privileged process
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: establishing credentials
Apr 5 18:27:38 hanzy sshd[13625]: pam_unix(sshd:session): session
opened for user sftpuser by (uid=0)
Apr 5 18:27:38 hanzy sshd[13625]: User child is on pid 13628
Apr 5 18:27:38 hanzy sshd[13628]: debug1: SELinux support disabled
Apr 5 18:27:38 hanzy sshd[13628]: debug1: PAM: establishing credentials
Apr 5 18:27:38 hanzy sshd[13628]: debug1: permanently_set_uid: 1014/1015
Apr 5 18:27:38 hanzy sshd[13628]: debug1: Entering interactive
session for SSH2.
Apr 5 18:27:38 hanzy sshd[13628]: debug1: server_init_dispatch_20
Apr 5 18:27:38 hanzy sshd[13628]: debug1: server_input_channel_open:
ctype session rchan 256 win 2147483647 max 16384
Apr 5 18:27:38 hanzy sshd[13628]: debug1: input_session_request
Apr 5 18:27:38 hanzy sshd[13628]: debug1: channel 0: new [server-session]
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_new: session 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_open: channel 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_open: session 0:
link with channel 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: server_input_channel_open:
confirm session
Apr 5 18:27:38 hanzy sshd[13628]: debug1: server_input_channel_req:
channel 0 request simple at putty.projects.tartarus.org reply 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_by_channel: session
0 channel 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_input_channel_req:
session 0 req simple at putty.projects.tartarus.org
Apr 5 18:27:38 hanzy sshd[13628]: debug1: server_input_channel_req:
channel 0 request subsystem reply 1
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_by_channel: session
0 channel 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_input_channel_req:
session 0 req subsystem
Apr 5 18:27:38 hanzy sshd[13628]: subsystem request for sftp
Apr 5 18:27:38 hanzy sshd[13628]: debug1: subsystem: exec()
/usr/lib/sftp-server
Apr 5 18:27:38 hanzy scponly[13629]: chrooted binary in place, will chroot()
Apr 5 18:27:38 hanzy scponly[13629]: 3 arguments in total.
Apr 5 18:27:38 hanzy scponly[13629]: ^Iarg 0 is scponlyc
Apr 5 18:27:38 hanzy scponly[13629]: ^Iarg 1 is -c
Apr 5 18:27:38 hanzy scponly[13629]: ^Iarg 2 is /usr/lib/sftp-server
Apr 5 18:27:38 hanzy scponly[13629]: opened log at LOG_AUTHPRIV, opts
0x00000029
Apr 5 18:27:38 hanzy sshd[13628]: debug1: Received SIGCHLD.
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_by_pid: pid 13629
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_exit_message:
session 0 channel 0 pid 13629
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_exit_message:
release channel 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_by_channel: session
0 channel 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_close_by_channel:
channel 0 child 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: session_close: session 0 pid 0
Apr 5 18:27:38 hanzy sshd[13628]: debug1: channel 0: free:
server-session, nchannels 1
Apr 5 18:27:38 hanzy sshd[13628]: Connection closed by 192.168.1.64
Apr 5 18:27:38 hanzy sshd[13628]: debug1: do_cleanup
Apr 5 18:27:38 hanzy sshd[13628]: Transferred: sent 2520, received 2112 bytes
Apr 5 18:27:38 hanzy sshd[13628]: Closing connection to 192.168.1.64 port 49302
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: cleanup
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: deleting credentials
Apr 5 18:27:38 hanzy sshd[13625]: debug1: PAM: closing session
Apr 5 18:27:38 hanzy sshd[13625]: pam_unix(sshd:session): session
closed for user sftpuser
On Sun, Apr 5, 2009 at 2:54 PM, Kaleb Pederson <kaleb.pederson at gmail.com> wrote:
> Please respond to the list and include the scponly debug output. You can enable it with:
>
> echo 1 > $INSTALLDIR/etc/scponly/debuglevel
>
> The scponly debug output should show scponly as the process (rather than sshd).
>
> --Kaleb
>
> On Sunday 05 April 2009 08:06:02 am Mark Trolley wrote:
>> Thanks for the response. Here you go:
>>
>> Apr 5 11:04:19 hanzy sshd[12880]: debug1: rexec start in 7 out 7
>> newsock 7 pipe 9 sock 10
>> Apr 5 11:04:19 hanzy sshd[8606]: debug1: Forked child 12880.
>> Apr 5 11:04:19 hanzy sshd[12880]: debug1: inetd sockets after dupping: 3, 3
>> Apr 5 11:04:19 hanzy sshd[12880]: Connection from 127.0.0.1 port 2136
>> Apr 5 11:04:19 hanzy sshd[12880]: debug1: Client protocol version
>> 2.0; client software version OpenSSH_5.1p1 Debian-5
>> Apr 5 11:04:19 hanzy sshd[12880]: debug1: match: OpenSSH_5.1p1
>> Debian-5 pat OpenSSH*
>> Apr 5 11:04:19 hanzy sshd[12880]: debug1: Enabling compatibility mode
>> for protocol 2.0
>> Apr 5 11:04:19 hanzy sshd[12880]: debug1: Local version string
>> SSH-2.0-OpenSSH_5.1p1 Debian-5
>> Apr 5 11:04:26 hanzy sshd[12880]: debug1: PAM: initializing for "sftpuser"
>> Apr 5 11:04:26 hanzy sshd[12880]: debug1: PAM: setting PAM_RHOST to "hanzy"
>> Apr 5 11:04:26 hanzy sshd[12880]: debug1: PAM: setting PAM_TTY to "ssh"
>> Apr 5 11:04:26 hanzy sshd[12880]: Failed none for sftpuser from
>> 127.0.0.1 port 2136 ssh2
>> Apr 5 11:04:32 hanzy sshd[12882]: debug1: do_pam_account: called
>> Apr 5 11:04:32 hanzy sshd[12880]: debug1: PAM: num PAM env strings 0
>> Apr 5 11:04:32 hanzy sshd[12880]: debug1: do_pam_account: called
>> Apr 5 11:04:32 hanzy sshd[12880]: Accepted keyboard-interactive/pam
>> for sftpuser from 127.0.0.1 port 2136 ssh2
>> Apr 5 11:04:32 hanzy sshd[12880]: debug1: monitor_child_preauth:
>> sftpuser has been authenticated by privileged process
>> Apr 5 11:04:32 hanzy sshd[12880]: debug1: PAM: establishing credentials
>> Apr 5 11:04:32 hanzy sshd[12880]: pam_unix(sshd:session): session
>> opened for user sftpuser by (uid=0)
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: SELinux support disabled
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: PAM: establishing credentials
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: permanently_set_uid: 1014/1015
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: Entering interactive
>> session for SSH2.
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: server_init_dispatch_20
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: server_input_channel_open:
>> ctype session rchan 0 win 2097152 max 32768
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: input_session_request
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: channel 0: new [server-session]
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_new: session 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_open: channel 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_open: session 0:
>> link with channel 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: server_input_channel_open:
>> confirm session
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1:
>> server_input_global_request: rtype no-more-sessions at openssh.com
>> want_reply 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: server_input_channel_req:
>> channel 0 request env reply 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_by_channel: session
>> 0 channel 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_input_channel_req:
>> session 0 req env
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: server_input_channel_req:
>> channel 0 request subsystem reply 1
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_by_channel: session
>> 0 channel 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_input_channel_req:
>> session 0 req subsystem
>> Apr 5 11:04:32 hanzy sshd[12880]: User child is on pid 12883
>> Apr 5 11:04:32 hanzy sshd[12883]: subsystem request for sftp
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: subsystem: exec()
>> /usr/lib/sftp-server
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: Received SIGCHLD.
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_by_pid: pid 12884
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_exit_message:
>> session 0 channel 0 pid 12884
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_exit_message:
>> release channel 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_by_channel: session
>> 0 channel 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_close_by_channel:
>> channel 0 child 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: session_close: session 0 pid 0
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: channel 0: free:
>> server-session, nchannels 1
>> Apr 5 11:04:32 hanzy sshd[12883]: Connection closed by 127.0.0.1
>> Apr 5 11:04:32 hanzy sshd[12883]: debug1: do_cleanup
>> Apr 5 11:04:32 hanzy sshd[12883]: Transferred: sent 1800, received 1504 bytes
>> Apr 5 11:04:32 hanzy sshd[12883]: Closing connection to 127.0.0.1 port 2136
>> Apr 5 11:04:32 hanzy sshd[12880]: debug1: PAM: cleanup
>> Apr 5 11:04:32 hanzy sshd[12880]: debug1: PAM: deleting credentials
>> Apr 5 11:04:32 hanzy sshd[12880]: debug1: PAM: closing session
>> Apr 5 11:04:32 hanzy sshd[12880]: pam_unix(sshd:session): session
>> closed for user sftpuser
>>
>> On Sun, Apr 5, 2009 at 1:44 AM, Kaleb Pederson <kaleb.pederson at gmail.com> wrote:
>> > On Saturday 04 April 2009 11:31:49 am Mark Trolley wrote:
>> >> I'm having no luck whatsoever getting scponly to work again. I had it
>> >> working before upgrading Debian to lenny and now it doesn't. I've seen
>> >> the other mailing list posts about this problem so I know it's known,
>> >> so I decided to forgo using the Debian package and compile from source
>> >> instead. I did that and did all the setup but it still doesn't work.
>> >>
>> >> I compiled scponly from source using only the --enable-chrooted-binary
>> >> option. I then ran setup_chroot.sh and followed all the prompts. I
>> >> needed to copy /dev/null manually but otherwise everything went OK.
>> >
>> > Sounds good. That's probably the single most common thing that needs to be done.
>> >
>> >> Next I copied sh (and libs) into the chroot directory and can
>> >> successfully chroot there and run sftp-server:
>> >
>> > For testing purposes that's fine....
>> >
>> > [...snip...]
>> >> Any ideas what's wrong? I'm at my wit's end.
>> >
>> > I didn't see where scponly invoked the sftp-server. Could you attach the output from syslog when you connect with debugging enabled?
>> >
>> > Thanks.
>> >
>> > --Kaleb
>> >
>> >
>>
>
More information about the scponly
mailing list