All,
I'm attempting to configure ProFTPD to authenticate against the Galaxy database. I appear to be able to connect to the database, but can't authenticate a registered user via FTP.
Here are the relevant entries for the ProFTPD configuration:
[root@login002 proftpd-1.3.4d]# grep SQL etc/proftpd.conf
SQLPasswordEngine on
SQLPasswordEncoding hex
SQLEngine on
SQLBackend postgres
SQLConnectInfo galaxydb galaxyftp galaxyftp_password
SQLAuthTypes SHA1
SQLAuthenticate users
SQLDefaultHomedir /var/opt/local/proftpd
SQLLogFile /home/galaxy/proftpd-1.3.4d/var/sql.log
SQLUserInfo custom:/LookupGalaxyUser
SQLNamedQuery LookupGalaxyUser SELECT "email,password,'4630','1108','/home/galaxy/galaxy-dist/database/files/ftp/%U','/bin/bash' FROM galaxy_user WHERE email='%U'"
I'm starting the daemon with maximum verbosity:
[root@login002 proftpd-1.3.4d]# ./sbin/proftpd -n -d 10
The logs appear to be OK:
Jun 18 12:37:09 mod_sql/4.3[987]: defaulting to 'postgres' backend
Jun 18 12:37:09 mod_sql/4.3[987]: backend module 'mod_sql_postgres/4.0.4'
Jun 18 12:37:09 mod_sql/4.3[987]: backend api 'mod_sql_api_v1'
Jun 18 12:37:09 mod_sql/4.3[987]: >>> sql_sess_init
Jun 18 12:37:09 mod_sql/4.3[987]: entering postgres cmd_defineconnection
Jun 18 12:37:09 mod_sql/4.3[987]: name: 'default'
Jun 18 12:37:09 mod_sql/4.3[987]: user: 'galaxyftp'
Jun 18 12:37:09 mod_sql/4.3[987]: host: 'localhost'
Jun 18 12:37:09 mod_sql/4.3[987]: db: 'galaxydb'
Jun 18 12:37:09 mod_sql/4.3[987]: port: '5432'
Jun 18 12:37:09 mod_sql/4.3[987]: ttl: '0'
Jun 18 12:37:09 mod_sql/4.3[987]: exiting postgres cmd_defineconnection
Jun 18 12:37:09 mod_sql/4.3[987]: connection 'default' successfully established
Jun 18 12:37:09 mod_sql/4.3[987]: mod_sql engine : on
Jun 18 12:37:09 mod_sql/4.3[987]: negative_cache : off
Jun 18 12:37:09 mod_sql/4.3[987]: authenticate : users
Jun 18 12:37:09 mod_sql/4.3[987]: usertable : users
Jun 18 12:37:09 mod_sql/4.3[987]: userid field : userid
Jun 18 12:37:09 mod_sql/4.3[987]: password field : passwd
Jun 18 12:37:09 mod_sql/4.3[987]: UID field : uid
Jun 18 12:37:09 mod_sql/4.3[987]: GID field : gid
Jun 18 12:37:09 mod_sql/4.3[987]: homedir field : homedir
Jun 18 12:37:09 mod_sql/4.3[987]: homedir(default) : '/var/opt/local/proftpd'
Jun 18 12:37:09 mod_sql/4.3[987]: shell field : shell
Jun 18 12:37:09 mod_sql/4.3[987]: SQLMinUserUID : 999
Jun 18 12:37:09 mod_sql/4.3[987]: SQLMinUserGID : 999
Jun 18 12:37:09 mod_sql/4.3[987]: <<< sql_sess_init
Jun 18 12:37:15 mod_sql/4.3[987]: >>> sql_pre_pass
Jun 18 12:37:15 mod_sql/4.3[987]: <<< sql_pre_pass
Jun 18 12:37:15 mod_sql/4.3[987]: >>> cmd_getpwnam
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: Postgres server version: 8.1.23
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' opened
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 2
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 1
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: cache miss for user 'mtobias@wustl.edu'
Jun 18 12:37:15 mod_sql/4.3[987]: >>> sql_lookup
Jun 18 12:37:15 mod_sql/4.3[987]: >>> process_named_query 'LookupGalaxyUser'
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 2
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 1
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 2
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 1
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_select
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 2
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: query "SELECT email,password,'4630','1108','/home/galaxy/galaxy-dist/database/files/ftp/mtobias@wustl.edu','/bin/bash' FROM galaxy_user WHERE email='mtobias@wustl.edu'"
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 1
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_select
Jun 18 12:37:15 mod_sql/4.3[987]: <<< process_named_query 'LookupGalaxyUser'
Jun 18 12:37:15 mod_sql/4.3[987]: <<< sql_lookup
Jun 18 12:37:15 mod_sql/4.3[987]: cache miss for user 'mtobias@wustl.edu'
Jun 18 12:37:15 mod_sql/4.3[987]: user 'mtobias@wustl.edu' cached
Jun 18 12:37:15 mod_sql/4.3[987]: + pwd.pw_name : mtobias@wustl.edu
Jun 18 12:37:15 mod_sql/4.3[987]: + pwd.pw_uid : 4630
Jun 18 12:37:15 mod_sql/4.3[987]: + pwd.pw_gid : 1108
Jun 18 12:37:15 mod_sql/4.3[987]: + pwd.pw_dir : /home/galaxy/galaxy-dist/database/files/ftp/mtobias@wustl.edu
Jun 18 12:37:15 mod_sql/4.3[987]: + pwd.pw_shell : /bin/bash
Jun 18 12:37:15 mod_sql/4.3[987]: <<< cmd_getpwnam
Jun 18 12:37:15 mod_sql/4.3[987]: >>> cmd_auth
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 2
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_open
Jun 18 12:37:15 mod_sql/4.3[987]: entering postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: connection 'default' count is now 1
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_close
Jun 18 12:37:15 mod_sql/4.3[987]: exiting postgres cmd_escapestring
Jun 18 12:37:15 mod_sql/4.3[987]: cache hit for user 'mtobias@wustl.edu'
Jun 18 12:37:15 mod_sql/4.3[987]: >>> cmd_check
Jun 18 12:37:15 mod_sql/4.3[987]: checking password using SQLAuthType 'sha1'
Jun 18 12:37:15 mod_sql/4.3[987]: 'sha1' SQLAuthType handler reports failure
Jun 18 12:37:15 mod_sql/4.3[987]: <<< cmd_check
Jun 18 12:37:15 mod_sql/4.3[987]: <<< cmd_auth
At the same time, I'm seeing from the command line:
login002 proftpd[987] login002 (10.28.56.101[10.28.56.101]): mod_sql_passwd/0.4: expected 'PBKDF2$sha256$10000$8h/4HmD1Eu6NTc7F$Slb1H5a9YJvR6A3cUnZCUfh7tOWKfRuh', got 'cc0ef515d684386aaa500bf6499d9f512dfb332c'
It almost looks like it's expecting a longer string, maybe with a salt and I'm not sure why it's expecting SHA256 as I thought all of Galaxy was using SHA1? I tried changing SQLAuthTypes to SHA256 without luck.
Any suggestions on what to look at to debug this further?
Thanks,
Malcolm
--
Malcolm Tobias
314.362.1594