[scponly] Filezilla: "Fatal: unable to initialise SFTP: could not connect"

Mon Jan 23 01:42:46 EST 2006

On 1/23/06, Hideyuki KURASHINA <rushani at bl.mmtr.or.jp> wrote:

    >>> On Sun, 22 Jan 2006 23:29:10 -0500, Frappy John <
frappyjohn at gmail.com> said:

    > Apparently the uid=0 in the system log refers to the owner of the sshd
    > process, not the user connecting via ssh. (I tested this with a couple
of
    > users to verify it.)

    OK.

    I noticed that you showed only sshd logs, i.e. scponly related logs
    didn't appeared.  So, my suggestions to you are as follows:

      1) before trying scponly, check FileZilla works with normal shells.
         Note that Filezilla seems to be supported only password
         authentication.

      2) if 1) is OK, try scponly by increasing its debugging level
         by

            echo 1 > /usr/local/etc/scponly/debuglevel

         it will bring you to lots of information.

    For the record, FileZilla 2.2.18 using

      * Servertype = SFTP using SSH2
      * Logontype = Normal

    works with OpenSSH's sshd 4.2p1 on FreeBSD 6.0.

    Hope this helps,

    -- rushani

Thanks again, rushani!

I do use Filezilla successfully as an ordinary user logging into this same
server.

Yes, setting the debuglevel to 1 did produce some useful outout in my
/var/log/secure log:

On my first iteration, I found a permissions problem:

Jan 23 00:44:54 myserver sshd[2334]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50297 ssh2
Jan 23 00:44:54 myserver sshd[2335]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50297 ssh2
Jan 23 00:44:54 myserver sshd[2336]: subsystem request for sftp
Jan 23 00:44:54 myserver scponly[2337]: chrooted binary in place, will
chroot()
Jan 23 00:44:54 myserver scponly[2337]: 3 arguments in total.
Jan 23 00:44:54 myserver scponly[2337]:    arg 0 is scponlyc
Jan 23 00:44:54 myserver scponly[2337]:    arg 1 is -c
Jan 23 00:44:54 myserver scponly[2337]:    arg 2 is
/usr/libexec/openssh/sftp-server
Jan 23 00:44:54 myserver scponly[2337]: opened log at LOG_AUTHPRIV, opts
0x00000009
Jan 23 00:44:54 myserver scponly[2337]: retrieved home directory of
"/home/mytestuser" for user "mytestuser"
Jan 23 00:44:54 myserver scponly[2337]: chrooting to dir: "/home/mytestuser"
Jan 23 00:44:54 myserver scponly[2337]: chroot: Permission denied
Jan 23 00:44:54 myserver scponly[2337]: couldn't chroot to /home/mytestuser
[username: mytestuser(520), IP/port: ::ffff:261.179.21.75 50297 22]

... so I changed the permissions on /home/mytestuser from this:
drwx------   8 root          root          4096 Jan 18 17:41 mytestuser
to this:
drwx---r-x   8 root          root          4096 Jan 18 17:41 mytestuser

On the second iteration, I got an "Operation not permitted" on the log:
Jan 23 00:51:32 myserver sshd[2363]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50298 ssh2
Jan 23 00:51:32 myserver sshd[2364]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50298 ssh2
Jan 23 00:51:32 myserver sshd[2365]: subsystem request for sftp
Jan 23 00:51:32 myserver scponly[2366]: chrooted binary in place, will
chroot()
Jan 23 00:51:32 myserver scponly[2366]: 3 arguments in total.
Jan 23 00:51:32 myserver scponly[2366]:    arg 0 is scponlyc
Jan 23 00:51:32 myserver scponly[2366]:    arg 1 is -c
Jan 23 00:51:32 myserver scponly[2366]:    arg 2 is
/usr/libexec/openssh/sftp-server
Jan 23 00:51:32 myserver scponly[2366]: opened log at LOG_AUTHPRIV, opts
0x00000009
Jan 23 00:51:32 myserver scponly[2366]: retrieved home directory of
"/home/mytestuser" for user "mytestuser"
Jan 23 00:51:32 myserver scponly[2366]: chrooting to dir: "/home/mytestuser"
Jan 23 00:51:32 myserver scponly[2366]: chroot: Operation not permitted
Jan 23 00:51:32 myserver scponly[2366]: couldn't chroot to /home/mytestuser
[username: mytestuser(520), IP/port: ::ffff:261.179.21.75 50298 22]

I guessed that perhaps the problem was that the /home/mytestuser directory
should not be owned by root but by the user himself, so I changed the
ownership and permissions to:
dr-x------   8 mytestuser   mytestuser  4096 Jan 18 17:41 mytestuser

but then, on the third iteration, I got "chroot dir not owned by root" on
the log:
Jan 23 00:55:44 myserver sshd[2389]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50303 ssh2
Jan 23 00:55:44 myserver sshd[2390]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50303 ssh2
Jan 23 00:55:45 myserver sshd[2391]: subsystem request for sftp
Jan 23 00:55:45 myserver scponly[2392]: chrooted binary in place, will
chroot()
Jan 23 00:55:45 myserver scponly[2392]: 3 arguments in total.
Jan 23 00:55:45 myserver scponly[2392]:    arg 0 is scponlyc
Jan 23 00:55:45 myserver scponly[2392]:    arg 1 is -c
Jan 23 00:55:45 myserver scponly[2392]:    arg 2 is
/usr/libexec/openssh/sftp-server
Jan 23 00:55:45 myserver scponly[2392]: opened log at LOG_AUTHPRIV, opts
0x00000009
Jan 23 00:55:45 myserver scponly[2392]: retrieved home directory of
"/home/mytestuser" for user "mytestuser"
Jan 23 00:55:45 myserver scponly[2392]: chroot dir not owned by root:
/home/mytestuser

So I erred in changing the owner from root to the user.
I have now changed that back to:
drwxr-xr-x   8 root          root          4096 Jan 18 17:41 mytestuser

and now I am back to "Operation not permitted" on the log:

Jan 23 01:14:32 myserver sshd[2415]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50349 ssh2
Jan 23 01:14:32 myserver sshd[2416]: Accepted password for mytestuser from
::ffff:261.179.21.75 port 50349 ssh2
Jan 23 01:14:33 myserver sshd[2417]: subsystem request for sftp
Jan 23 01:14:33 myserver scponly[2418]: chrooted binary in place, will
chroot()
Jan 23 01:14:33 myserver scponly[2418]: 3 arguments in total.
Jan 23 01:14:33 myserver scponly[2418]:    arg 0 is scponlyc
Jan 23 01:14:33 myserver scponly[2418]:    arg 1 is -c
Jan 23 01:14:33 myserver scponly[2418]:    arg 2 is
/usr/libexec/openssh/sftp-server
Jan 23 01:14:33 myserver scponly[2418]: opened log at LOG_AUTHPRIV, opts
0x00000009
Jan 23 01:14:33 myserver scponly[2418]: retrieved home directory of
"/home/mytestuser" for user "mytestuser"
Jan 23 01:14:33 myserver scponly[2418]: chrooting to dir: "/home/mytestuser"
Jan 23 01:14:33 myserver scponly[2418]: chroot: Operation not permitted
Jan 23 01:14:33 myserver scponly[2418]: couldn't chroot to /home/mytestuser
[username: mytestuser(520), IP/port: ::ffff:261.179.21.75 50349 22]

A Google search tells me that one reason for the "Operation not permitted"
error is that chroot is not being run by the superuser. Do you think that is
the problem? If so, It looks like chroot is being run by the scponly
process. How would I go about changing the owner of the scponly process to
root?

Thanks once again.

John
-------------- next part --------------
HTML attachment scrubbed and removed