[Web-cyradm] PAM_MYSQL SASL Problem -- always authenticates,
even with bad username/password combination]
Jeff Beaver
jeff at beavertechnologies.com
Tue Apr 20 20:36:37 CEST 2004
Any help with this is appreciated.
I seem to have everything working with one major problem. For some
reason when pam queries the DB no matter what it returns sasl
authenticates it. I think the problem is somewhere in how pam is doing
its query or maybe how it returns the info back to sasl. I haven't
found any good docs on how this exchange works and only have my logs to
work with.
This is what I'm running:
- FreeBSD 5.2
- pam_mysql-0.5_1
- mysql-server-5.0.0_2
- cyrus-imapd-2.2.3_3
- cyrus-sasl-2.1.18
- cyrus-sasl-saslauthd-2.1.18_1
- db42-4.2.52_2
As I said, besides the authentication everything else is working
correctly. I can send/receive and create mailboxes with no problems.
I'm going to include here what I think is relevant, if I miss anything
that would be helpful let me know and I'll post it.
Here's the startup for saslauthd
- saslauthd_flags="-d -a pam"
Here's the contents of imap file from pam.d directory
auth sufficient pam_mysql.so user=mail passwd=**** host=localhost
db=mail table=accountuser usercolumn=username passwdcolumn=password
crypt=1 logtable=log logmsgcolumn=msg logusercolumn=user
loghostcolumn=host logpidcolumn=pid logtimecolumn=time
account required pam_mysql.so user=mail passwd=**** host=localhost
db=mail table=accountuser usercolumn=username passwdcolumn=password
crypt=1 logtable=log logmsgcolumn=msg logusercolumn=user
loghostcolumn=host logpidcolumn=pid logtimecolumn=time
Here's what I see when saslauthd is started
Starting saslauthd.
saslauthd[13036] :main : num_procs : 5
saslauthd[13036] :main : mech_option: NULL
saslauthd[13036] :main : run_path : /var/state/saslauthd
saslauthd[13036] :main : auth_mech : pam
saslauthd[13036] :ipc_init : using accept lock file:
/var/state/saslauthd/mux.accept saslauthd[13036] :detach_tty :
master pid is: 0
saslauthd[13036] :ipc_init : listening on socket:
/var/state/saslauthd/mux saslauthd[13036] :main : using
process model
saslauthd[13036] :have_baby : forked child: 13037
saslauthd[13037] :get_accept_lock : acquired accept lock
saslauthd[13036] :have_baby : forked child: 13038
saslauthd[13036] :have_baby : forked child: 13039
saslauthd[13036] :have_baby : forked child: 13040
When I run testsaslauthd -uasdf -padsf (where adsf are both invalid
username and password) I see
saslauthd[13038] :get_accept_lock :
acquired accept lock
saslauthd[13037] :rel_accept_lock : released accept lock
saslauthd[13037] :do_auth : auth success: [user=asdf]
[service=imap] [realm=] [mech=pam] saslauthd[13037] :do_request :
response: OK
Here's the tail from /var/log/messages
Apr 15 17:13:47 testsystem saslauthd[15979]: pam_sm_authenticate called.
Apr 15 17:13:47 testsystem saslauthd[15979]: dbuser changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: dbpasswd changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: host changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: database changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: table changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: usercolumn changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: passwdcolumn changed. Apr
15 17:13:47 testsystem saslauthd[15979]: crypt changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: logtable changed.
Apr 15 17:13:47 testsystem saslauthd[15979]: logmsgcolumn changed. Apr
15 17:13:47 testsystem saslauthd[15979]: logusercolumn changed. Apr 15
17:13:47 testsystem saslauthd[15979]: loghostcolumn changed. Apr 15
17:13:47 testsystem saslauthd[15979]: logpidcolumn changed. Apr 15
17:13:47 testsystem saslauthd[15979]: logtimecolumn changed. Apr 15
17:13:47 testsystem saslauthd[15979]: db_connect called.
Apr 15 17:13:47 testsystem saslauthd[15979]: returning 0 .
Apr 15 17:13:47 testsystem saslauthd[15979]: db_checkpasswd called. Apr
15 17:13:47 testsystem saslauthd[15979]: pam_mysql: where clause = Apr
15 17:13:47 testsystem saslauthd[15979]: SELECT password FROM
accountuser WHERE username='asdf'
Apr 15 17:13:47 testsystem saslauthd[15979]: pam_mysql: select returned
more than one result
Apr 15 17:13:47 testsystem saslauthd[15979]: returning 9 after
db_checkpasswd.
I realize it says that select returned more than one result but looking
at the table there is only one entry and running the query manually only
returns one result.
Here's the above test when a valid username and password are used
saslauthd[13114] :get_accept_lock : acquired accept lock
saslauthd[13113] :rel_accept_lock : released accept lock
saslauthd[13113] :do_auth : auth success: [user=test0001]
[service=imap] [realm=] [mech=pam]
saslauthd[13113] :do_request : response: OK
... and log messages...
Apr 15 17:15:51 testsystem saslauthd[15975]: pam_sm_authenticate called.
Apr 15 17:15:51 testsystem saslauthd[15975]: dbuser changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: dbpasswd changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: host changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: database changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: table changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: usercolumn changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: passwdcolumn changed. Apr
15 17:15:51 testsystem saslauthd[15975]: crypt changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: logtable changed.
Apr 15 17:15:51 testsystem saslauthd[15975]: logmsgcolumn changed. Apr
15 17:15:51 testsystem saslauthd[15975]: logusercolumn changed. Apr 15
17:15:51 testsystem saslauthd[15975]: loghostcolumn changed. Apr 15
17:15:51 testsystem saslauthd[15975]: logpidcolumn changed. Apr 15
17:15:51 testsystem saslauthd[15975]: logtimecolumn changed. Apr 15
17:15:51 testsystem saslauthd[15975]: db_connect called.
Apr 15 17:15:51 testsystem saslauthd[15975]: returning 0 .
Apr 15 17:15:51 testsystem saslauthd[15975]: db_checkpasswd called. Apr
15 17:15:51 testsystem saslauthd[15975]: pam_mysql: where clause = Apr
15 17:15:51 testsystem saslauthd[15975]: SELECT password FROM
accountuser WHERE username='test0001'
Apr 15 17:15:51 testsystem saslauthd[15975]: sqlLog called.
Apr 15 17:15:51 testsystem saslauthd[15975]: insert into log (msg, user,
host, pid, time) values('AUTH SUCCESSFUL', 'test0001', '', '15975',
NOW()) Apr 15 17:15:51 testsystem saslauthd[15975]: Returning 0
Apr 15 17:15:51 testsystem saslauthd[15975]: returning 0 .
Apr 15 17:15:51 testsystem saslauthd[15975]: returning 0.
In case you want to see it here is main.cf from postfix
queue_directory = /var/spool/postfix
command_directory = /usr/local/sbin
daemon_directory = /usr/local/libexec/postfix
mail_owner = postfix
mydomain = twistedtechie.com
myorigin = $mydomain
inet_interfaces = all
mydestination = $myhostname localhost.$mydomain $mydomain,
mysql:/usr/local/etc/postfix/mysql-mydestination.cf
unknown_local_recipient_reject_code = 450
alias_maps = hash:/etc/mail/aliases
mailbox_transport = cyrus
debug_peer_level = 10
debugger_command =
PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin
xxgdb $daemon_directory/$process_name $process_id & sleep 5
sendmail_path = /usr/local/sbin/sendmail
newaliases_path = /usr/local/bin/newaliases
mailq_path = /usr/local/bin/mailq
setgid_group = maildrop
manpage_directory = /usr/local/man
sample_directory = /usr/local/etc/postfix
readme_directory = no
virtual_maps = mysql:/usr/local/etc/postfix/mysql-virtual.cf
sender_canonical_maps = mysql:/usr/local/etc/postfix/mysql-canonical.cf
smtp_sasl_auth_enable = yes
smtpd_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/etc/sasldb2
smtpd_recipient_restrictions = permit_sasl_authenticated,
permit_mynetworks, reject_unauth_destination
smtpd_sasl_security_options = noanonymous
smtpd_sasl_local_domain =
broken_sasl_auth_clients = yes
Here is /usr/local/etc/imap.conf
postmaster: postmaster
configdirectory: /var/imap
partition-default: /var/spool/imap
admins: cyrus
allowanonymouslogin: no
allowplaintext: yes
sasl_mech_list: PLAIN
servername: twistedtechie.com
autocreatequota: 10000
reject8bit: no
quotawarn: 90
timeout: 30
poptimeout: 10
dracinterval: 0
drachost: localhost
sasl_pwcheck_method: saslauthd
sievedir: /usr/sieve
sendmail: /usr/sbin/sendmail
sieve_maxscriptsize: 32
sieve_maxscripts: 5
#unixhierarchysep: yes
tls_ca_file: /var/imap/server.pem
tls_cert_file: /var/imap/server.pem
tls_key_file: /var/imap/server.pem
Well, I hope that's enough info. I imagine if you seen this before you
may know what the problem is right off the bat. I've been stumped on
this for the last couple of weeks and have been spending way too much
time on it.
Thanks for the help,
Jeff
More information about the Web-cyradm
mailing list