ProFTPD + Mysql / VHCS

[peja]

Hi,

versuche schon seit 2 Tagen herauszufinden, wieso der FTP-Login auf meiner Kiste nicht funtzt.

Das SQL-Log sagt folgendes:

Code:

Jul 24 15:31:29 mod_sql/4.11[25639]: backend module 'mod_sql_mysql/4.04'
Jul 24 15:31:29 mod_sql/4.11[25639]: backend api    'mod_sql_api_v1'
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> sql_getconf
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_defineconnection
Jul 24 15:31:29 mod_sql/4.11[25639]:  name: 'default'
Jul 24 15:31:29 mod_sql/4.11[25639]:  user: 'root'
Jul 24 15:31:29 mod_sql/4.11[25639]:  host: 'localhost'
Jul 24 15:31:29 mod_sql/4.11[25639]:    db: 'vhcs2'
Jul 24 15:31:29 mod_sql/4.11[25639]:  port: '3306'
Jul 24 15:31:29 mod_sql/4.11[25639]:   ttl: '0'
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_defineconnection
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' opened
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: backend successfully connected.
Jul 24 15:31:29 mod_sql/4.11[25639]: mod_sql status     : on
Jul 24 15:31:29 mod_sql/4.11[25639]: negative_cache     : off
Jul 24 15:31:29 mod_sql/4.11[25639]: authenticate       : users groups userset groupset
Jul 24 15:31:29 mod_sql/4.11[25639]: usertable          : ftp_users
Jul 24 15:31:29 mod_sql/4.11[25639]: userid field       : userid
Jul 24 15:31:29 mod_sql/4.11[25639]: password field     : passwd
Jul 24 15:31:29 mod_sql/4.11[25639]: uid field          : uid
Jul 24 15:31:29 mod_sql/4.11[25639]: gid field          : gid
Jul 24 15:31:29 mod_sql/4.11[25639]: homedir field      : shell
Jul 24 15:31:29 mod_sql/4.11[25639]: shell field        : homedir
Jul 24 15:31:29 mod_sql/4.11[25639]: homedirondemand    : false
Jul 24 15:31:29 mod_sql/4.11[25639]: group table        : ftp_group
Jul 24 15:31:29 mod_sql/4.11[25639]: groupname field    : groupname
Jul 24 15:31:29 mod_sql/4.11[25639]: grp gid field      : gid
Jul 24 15:31:29 mod_sql/4.11[25639]: grp members field  : members
Jul 24 15:31:29 mod_sql/4.11[25639]: SQLMinUserUID      : 2000
Jul 24 15:31:29 mod_sql/4.11[25639]: SQLMinUserGID      : 2000
Jul 24 15:31:29 mod_sql/4.11[25639]: SQLDefaultUID      : 65533
Jul 24 15:31:29 mod_sql/4.11[25639]: SQLDefaultGID      : 65533
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< sql_getconf
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_endpwent
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_endpwent
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_endgrent
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_endgrent
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_getgroups
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_escapestring
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_escapestring
Jul 24 15:31:29 mod_sql/4.11[25639]: cache miss for user 'wichspass@wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: : entering         mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 2
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: query "SELECT userid, passwd, uid, gid, shell, homedir FROM ftp_users WHERE (userid='wichspass@wichs-pass.com') LIMIT 1"
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: cache miss for user 'wichspass@wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: user 'wichspass@wichs-pass.com' cached
Jul 24 15:31:29 mod_sql/4.11[25639]: + pwd.pw_name  : wichspass@wichs-pass.com
Jul 24 15:31:29 mod_sql/4.11[25639]: + pwd.pw_uid   : 2004
Jul 24 15:31:29 mod_sql/4.11[25639]: + pwd.pw_gid   : 2004
Jul 24 15:31:29 mod_sql/4.11[25639]: + pwd.pw_dir   : /bin/bash
Jul 24 15:31:29 mod_sql/4.11[25639]: + pwd.pw_shell : /var/www/html/wichs-pass.com
Jul 24 15:31:29 mod_sql/4.11[25639]: cache miss for gid '2004'
Jul 24 15:31:29 mod_sql/4.11[25639]: : entering         mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 2
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: query "SELECT groupname FROM ftp_group WHERE (gid = 2004) LIMIT 1"
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: : entering         mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 2
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: query "SELECT groupname, gid, members FROM ftp_group WHERE (groupname = 'wichs-pass.com')"
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: cache miss for group 'wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: group 'wichs-pass.com' cached
Jul 24 15:31:29 mod_sql/4.11[25639]: + grp.gr_name : wichs-pass.com
Jul 24 15:31:29 mod_sql/4.11[25639]: + grp.gr_gid  : 2004
Jul 24 15:31:29 mod_sql/4.11[25639]: + grp.gr_mem  : wichspass@wichs-pass.com
Jul 24 15:31:29 mod_sql/4.11[25639]: : entering         mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 2
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: query "SELECT groupname, gid, members FROM ftp_group WHERE (members = 'wichspass@wichs-pass.com' OR members LIKE 'wichspass@wichs-pass.com,%' OR members LIKE '%,wichspass@wichs-pass.com' OR members LIKE '%,wichspass@wichs-pass.com,%')"
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: cache hit for group 'wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_getgroups
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_endpwent
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_endpwent
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_endgrent
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_endgrent
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_getgroups
Jul 24 15:31:29 mod_sql/4.11[25639]: cache hit for user 'wichspass@wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: cache hit for group wichs-pass.com
Jul 24 15:31:29 mod_sql/4.11[25639]: : entering         mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 2
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:29 mod_sql/4.11[25639]: query "SELECT groupname, gid, members FROM ftp_group WHERE (members = 'wichspass@wichs-pass.com' OR members LIKE 'wichspass@wichs-pass.com,%' OR members LIKE '%,wichspass@wichs-pass.com' OR members LIKE '%,wichspass@wichs-pass.com,%')"
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_select
Jul 24 15:31:29 mod_sql/4.11[25639]: cache hit for group 'wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_getgroups
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_getpwnam
Jul 24 15:31:29 mod_sql/4.11[25639]: cache hit for user 'wichspass@wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_getpwnam
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_gid2name
Jul 24 15:31:29 mod_sql/4.11[25639]: cache hit for group wichs-pass.com
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_gid2name
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_auth
Jul 24 15:31:29 mod_sql/4.11[25639]: entering   mysql cmd_escapestring
Jul 24 15:31:29 mod_sql/4.11[25639]: exiting    mysql cmd_escapestring
Jul 24 15:31:29 mod_sql/4.11[25639]: cache hit for user 'wichspass@wichs-pass.com'
Jul 24 15:31:29 mod_sql/4.11[25639]: >>> cmd_check
Jul 24 15:31:29 mod_sql/4.11[25639]: checking auth_type Crypt
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_check
Jul 24 15:31:29 mod_sql/4.11[25639]: <<< cmd_auth
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_endpwent
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_endpwent
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_endgrent
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_endgrent
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_getgroups
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for user 'wichspass@wichs-pass.com'
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for group wichs-pass.com
Jul 24 15:31:34 mod_sql/4.11[25639]: : entering         mysql cmd_select
Jul 24 15:31:34 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:34 mod_sql/4.11[25639]: connection 'default' count is now 2
Jul 24 15:31:34 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:34 mod_sql/4.11[25639]: query "SELECT groupname, gid, members FROM ftp_group WHERE (members = 'wichspass@wichs-pass.com' OR members LIKE 'wichspass@wichs-pass.com,%' OR members LIKE '%,wichspass@wichs-pass.com' OR members LIKE '%,wichspass@wichs-pass.com,%')"
Jul 24 15:31:34 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:34 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:34 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:34 mod_sql/4.11[25639]: exiting    mysql cmd_select
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for group 'wichs-pass.com'
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_getgroups
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_endpwent
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_endpwent
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_endgrent
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_endgrent
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_getgroups
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for user 'wichspass@wichs-pass.com'
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for group wichs-pass.com
Jul 24 15:31:34 mod_sql/4.11[25639]: : entering         mysql cmd_select
Jul 24 15:31:34 mod_sql/4.11[25639]: entering   mysql cmd_open
Jul 24 15:31:34 mod_sql/4.11[25639]: connection 'default' count is now 2
Jul 24 15:31:34 mod_sql/4.11[25639]: exiting    mysql cmd_open
Jul 24 15:31:34 mod_sql/4.11[25639]: query "SELECT groupname, gid, members FROM ftp_group WHERE (members = 'wichspass@wichs-pass.com' OR members LIKE 'wichspass@wichs-pass.com,%' OR members LIKE '%,wichspass@wichs-pass.com' OR members LIKE '%,wichspass@wichs-pass.com,%')"
Jul 24 15:31:34 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:34 mod_sql/4.11[25639]: connection 'default' count is now 1
Jul 24 15:31:34 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:34 mod_sql/4.11[25639]: exiting    mysql cmd_select
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for group 'wichs-pass.com'
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_getgroups
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_getpwnam
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for user 'wichspass@wichs-pass.com'
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_getpwnam
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_gid2name
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for group wichs-pass.com
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_gid2name
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_auth
Jul 24 15:31:34 mod_sql/4.11[25639]: entering   mysql cmd_escapestring
Jul 24 15:31:34 mod_sql/4.11[25639]: exiting    mysql cmd_escapestring
Jul 24 15:31:34 mod_sql/4.11[25639]: cache hit for user 'wichspass@wichs-pass.com'
Jul 24 15:31:34 mod_sql/4.11[25639]: >>> cmd_check
Jul 24 15:31:34 mod_sql/4.11[25639]: checking auth_type Crypt
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_check
Jul 24 15:31:34 mod_sql/4.11[25639]: <<< cmd_auth
Jul 24 15:31:36 mod_sql/4.11[25639]: entering   mysql cmd_close
Jul 24 15:31:36 mod_sql/4.11[25639]: connection 'default' closed
Jul 24 15:31:36 mod_sql/4.11[25639]: connection 'default' count is now 0
Jul 24 15:31:36 mod_sql/4.11[25639]: exiting    mysql cmd_close
Jul 24 15:31:36 mod_sql/4.11[25639]: >>> cmd_endpwent
Jul 24 15:31:36 mod_sql/4.11[25639]: <<< cmd_endpwent
Jul 24 15:31:36 mod_sql/4.11[25639]: >>> cmd_endgrent
Jul 24 15:31:36 mod_sql/4.11[25639]: <<< cmd_endgrent

In der /etc/proftpd.conf:

Code:

SQLAuthTypes            Crypt
SQLAuthenticate         on
SQLConnectInfo          vhcs2@localhost root xxxxxx
SQLUserInfo             ftp_users userid passwd uid gid shell homedir
SQLGroupInfo            ftp_group groupname gid members
SQLMinID                2000
SQLLOGFILE              /var/log/proftpd.sql

Die Zugangsdaten sind auch alle korrekt. Muss dazu sagen, dass es so von der Software VHCS erfordert wird.

In der /var/log/messages (wieso auch immer es da drin steht):

Code:

Jul 24 15:31:23 host01-dk proftpd: proftpd startup succeeded
Jul 24 15:31:23 host01-dk proftpd[25636]: host01-dk - ProFTPD 1.2.10 (stable) (built Sat Jul 23 01:37:37 CEST 2005) standalone mode STARTUP
Jul 24 15:31:29 host01-dk proftpd[25639]: host01-dk (xx-xx-xx-xx.user.ono.com[xx.xx.xx.xx]) - FTP session opened.
Jul 24 15:31:36 host01-dk proftpd[25639]: host01-dk (xx-xx-xx-xx.user.ono.com[xx.xx.xx.xx]) - FTP session closed.

Ansonsten finde ich niergends weitere Meldungen zu ProFTPd bzw. Mysql-Zugriffen. Kann mir jemand bei diesem Problem bitte helfen?

[stonki]

und nun noch dein proftpd debug log....

proftpd mit "-n -d5" starten

[peja]

Ah sorry... hab das ganz vergessen
Hab mal das vorne weg (Datum,Uhrzeit,etc.) weggeschnibbelt.

Code:

performing ident lookup
ident connection failed: Connection refused
ident lookup returned 'UNKNOWN'
connected - local  : 212.112.218.2:21
connected - remote : 62.43.26.22:63705
FTP session opened.
dispatching PRE_CMD command 'USER wichspass@wichs-pass.com' to mod_core
dispatching PRE_CMD command 'USER wichspass@wichs-pass.com' to mod_core
dispatching PRE_CMD command 'USER wichspass@wichs-pass.com' to mod_auth
dispatching auth request "endpwent" to module mod_sql
dispatching auth request "endpwent" to module mod_auth_file
dispatching auth request "endpwent" to module mod_auth_unix
dispatching auth request "endgrent" to module mod_sql
dispatching auth request "endgrent" to module mod_auth_file
dispatching auth request "endgrent" to module mod_auth_unix
dispatching CMD command 'USER wichspass@wichs-pass.com' to mod_auth
dispatching auth request "getgroups" to module mod_sql
dispatching POST_CMD command 'USER wichspass@wichs-pass.com' to mod_sql
dispatching LOG_CMD command 'USER wichspass@wichs-pass.com' to mod_sql
dispatching LOG_CMD command 'USER wichspass@wichs-pass.com' to mod_log
dispatching PRE_CMD command 'PASS (hidden)' to mod_core
dispatching PRE_CMD command 'PASS (hidden)' to mod_core
dispatching PRE_CMD command 'PASS (hidden)' to mod_auth
dispatching auth request "endpwent" to module mod_sql
dispatching auth request "endpwent" to module mod_auth_file
dispatching auth request "endpwent" to module mod_auth_unix
dispatching auth request "endgrent" to module mod_sql
dispatching auth request "endgrent" to module mod_auth_file
dispatching auth request "endgrent" to module mod_auth_unix
dispatching CMD command 'PASS (hidden)' to mod_auth
dispatching auth request "getgroups" to module mod_sql
dispatching auth request "getpwnam" to module mod_sql
dispatching auth request "gid_name" to module mod_sql
dispatching auth request "auth" to module mod_sql
dispatching auth request "check" to module mod_sql
dispatching auth request "check" to module mod_auth_file
dispatching auth request "check" to module mod_auth_unix
dispatching auth request "auth" to module mod_auth_file
dispatching auth request "auth" to module mod_auth_unix
USER wichspass@wichs-pass.com (Login failed): No such user found.
dispatching POST_CMD_ERR command 'PASS (hidden)' to mod_sql
dispatching LOG_CMD_ERR command 'PASS (hidden)' to mod_sql
dispatching LOG_CMD_ERR command 'PASS (hidden)' to mod_log
dispatching LOG_CMD_ERR command 'PASS (hidden)' to mod_auth
dispatching PRE_CMD command 'QUIT' to mod_core
dispatching PRE_CMD command 'QUIT' to mod_core
dispatching PRE_CMD command 'QUIT' to mod_sql
dispatching PRE_CMD command 'QUIT' to mod_log
dispatching CMD command 'QUIT' to mod_core
dispatching auth request "endpwent" to module mod_sql
dispatching auth request "endpwent" to module mod_auth_file
dispatching auth request "endpwent" to module mod_auth_unix
dispatching auth request "endgrent" to module mod_sql
dispatching auth request "endgrent" to module mod_auth_file
dispatching auth request "endgrent" to module mod_auth_unix
FTP session closed.

Der Witz ist, dass der User so aber auch im DB-Field 'userid' exisitiert und SQLUserInfo in der proftpd.conf auch korrekt ist.