[galaxy-dev] ProFTPD integration with Galaxy

18 Jun 2013

      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