postfix sasl2 pam_mysql on Debian Sarge

Hello list,

I am looking for a few pointers to make saslauthd authenticate over a pam mechanism against a mysql database. All packages in this setup are from Debian Sarge, they are

libsasl2 libsasl2-modules libsasl2-modules-sql sasl2-bin libpam-mysql postfix postfix-mysql mysql-client mysql-server openssl libmysqlclient15

Though there's a wealth of "tutorials" that copy this setup from one another, documentation on how these mechanisms work seems very scarce, and I'm getting a bit stuck while trying to debug my config. Here are the facts:


Per advice of a zillion tutorials, /etc/default/saslauthd looks like this:

START=yes

PARAMS="-m /var/spool/postfix/var/run/saslauthd -r"

MECHANISMS="pam


... and in the same line of thought I modified the saslauthd pidfile in /etc/init.d/saslauthd as such

PIDFILE="/var/spool/postfix/var/run/${NAME}/saslauthd.pid"


/etc/pam.d/smtp contains the following lines:

auth required pam_mysql.so user=username passwd=password host=127.0.0.1 db=mail table=postfix_users usercolumn=email passwdcolumn=clear crypt=1

account sufficient pam_mysql.so user=username passwd=password host=127.0.0.1 db=mail table=postfix_users usercolumn=email passwdcolumn=clear crypt=1



1. The first thing I notice is that when I start the saslauth daemon (via # /etc/init.d/saslauthd start) the pid file is actually located in

/var/run/saslauthd/saslauthd.pid


These are the running processes:

igloo:/etc/postfix# ps aux|grep sasl
root      4666  0.0  1.1   7196  2212 pts/1    S    16:25   0:00 /usr/sbin/saslauthd -d -a pam
root      4667  0.0  1.1   7196  2212 pts/1    S    16:25   0:00 /usr/sbin/saslauthd -d -a pam
root      4668  0.0  1.1   7196  2212 pts/1    S    16:25   0:00 /usr/sbin/saslauthd -d -a pam
root      4669  0.0  1.1   7196  2212 pts/1    S    16:25   0:00 /usr/sbin/saslauthd -d -a pam
root      4670  0.0  1.1   7196  2212 pts/1    S    16:25   0:00 /usr/sbin/saslauthd -d -a pam


The permissions of the folder in de postfix tree are:

igloo:/etc/postfix# ls -l /var/spool/postfix/var/run/          total 4    drwxr-xr-x 2 root root 4096 2007-03-12 01:18 saslauthd

I also pasted the result of saslfinger below, for not burrying my second question.  So my first question is: how come the pid file is not in /var/spool/postfix/var/run/saslauthd?



2. Next, the pam mechanism that saslauthd invokes is returning an error. Here's what I get when I strace testsaslauthd:


igloo:/etc/postfix# strace /usr/sbin/testsaslauthd -u email@address -p

password -f /var/run/saslauthd/mux -s smtp
execve("/usr/sbin/testsaslauthd", ["/usr/sbin/testsaslauthd", "-u", "email@address", "-p", "password", "-f", "/var/run/saslauthd/mux", "-s", "smtp"], [/* 17 vars */]) = 0
uname({sys="Linux", node="igloo", ...}) = 0
brk(0)                                  = 0x804b000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40017000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=21217, ...}) = 0
mmap2(NULL, 21217, PROT_READ, MAP_PRIVATE, 3, 0) = 0x40019000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/tls/libresolv.so.2", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\260$\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=67364, ...}) = 0
mmap2(NULL, 75976, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x4001f000
mmap2(0x4002e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xf) = 0x4002e000
mmap2(0x40030000, 6344, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40030000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/tls/libc.so.6", O_RDONLY)    = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\240O\1"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=1241392, ...}) = 0
mmap2(NULL, 1251484, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x40032000
mmap2(0x4015a000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x127) = 0x4015a000
mmap2(0x40161000, 10396, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40161000
close(3)                                = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40164000
mprotect(0x4015a000, 20480, PROT_READ)  = 0
set_thread_area({entry_number:-1 -> 6, base_addr:0x401646c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
munmap(0x40019000, 21217)               = 0
fstat64(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 1), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40019000
socket(PF_FILE, SOCK_STREAM, 0)         = 3
connect(3, {sa_family=AF_FILE, path="/var/run/saslauthd/mux"}, 110saslauthd[4666] :rel_accept_lock : released accept lock
saslauthd[4667] :get_accept_lock : acquired accept lock
) = 0
writev(3, [{"\0\17email@address\0\10password\0\4smt"..., 35}], 1) = 35
read(3, saslauthd[4666] :do_auth         : auth failure: [user=email@address] [service=smtp] [realm=] [mech=pam] [reason=PAM auth error]
"\0\21", 2)                     = 2
read(3, "NO PAM auth error", 17)        = 17
close(3)                                = 0
write(1, "0: NO \"authentication failed\"\n", 300: NO "authentication failed"
) = 30
munmap(0x40019000, 4096)                = 0
exit_group(-1)                          = ?
Process 4691 detached



same story in /var/log/auth.log...


igloo:/etc/postfix# tail /var/log/auth.log

Mar 12 16:43:52 igloo saslauthd[4670]: rel_accept_lock : released accept lock
Mar 12 16:43:52 igloo saslauthd[4666]: get_accept_lock : acquired accept lock
Mar 12 16:43:52 igloo saslauthd[4670]: DEBUG: auth_pam: pam_authenticate failed: Authentication failure
Mar 12 16:43:52 igloo saslauthd[4670]: do_auth         : auth failure: [user=email@address] [service=smtp] [realm=] [mech=pam] [reason=PAM auth error]


A correct mysql query is logged in mysql.log. The same query over courier's imap-ssl / authlib works just fine.

igloo:/etc/postfix# tail /var/log/mysql/mysql.log

070312 16:43:52      21 Connect     vmailuser@localhost on mail
                     21 Init DB     mail
                     21 Query       SELECT clear FROM postfix_users WHERE email = 'email@address'
                     21 Quit



So my second question is: since (I think) postfix is not involved when testsaslauthd in invoked, and a valid mysql query seems to be logged, can I assume that there is also a sasl/pam problem, and how should I debug it?


Here's the output I get from saslfinger, you will notice that postfix is chrooted:

igloo:/etc/postfix# saslfinger -s
saslfinger - postfix Cyrus sasl configuration Mon Mar 12 17:41:02 CET 2007
version: 1.0.1
mode: server-side SMTP AUTH

-- basics --
Postfix: 2.3.7
System: Debian GNU/Linux 4.0 \n \l

-- smtpd is linked to --
        libsasl2.so.2 => /usr/lib/libsasl2.so.2 (0x40205000)

-- active SMTP AUTH and TLS parameters for smtpd --
broken_sasl_auth_clients = yes
smtpd_sasl_auth_enable = yes
smtpd_sasl_local_domain =
smtpd_sasl_security_options = noanonymous
smtpd_tls_cert_file = /etc/postfix/smtpd.cert
smtpd_tls_key_file = /etc/postfix/smtpd.key
smtpd_tls_loglevel = 3
smtpd_tls_received_header = yes
smtpd_tls_session_cache_timeout = 3600s
smtpd_use_tls = yes


-- listing of /usr/lib/sasl2 --
total 796
drwxr-xr-x  2 root root  4096 2007-03-12 10:06 .
drwxr-xr-x 58 root root 16384 2007-03-12 10:06 ..
-rw-r--r--  1 root root 13304 2006-12-13 22:26 libanonymous.a
-rw-r--r--  1 root root   855 2006-12-13 22:26 libanonymous.la
-rw-r--r--  1 root root 12844 2006-12-13 22:26 libanonymous.so
-rw-r--r--  1 root root 12844 2006-12-13 22:26 libanonymous.so.2
-rw-r--r--  1 root root 12844 2006-12-13 22:26 libanonymous.so.2.0.22
-rw-r--r--  1 root root 15502 2006-12-13 22:26 libcrammd5.a
-rw-r--r--  1 root root   841 2006-12-13 22:26 libcrammd5.la
-rw-r--r--  1 root root 15052 2006-12-13 22:26 libcrammd5.so
-rw-r--r--  1 root root 15052 2006-12-13 22:26 libcrammd5.so.2
-rw-r--r--  1 root root 15052 2006-12-13 22:26 libcrammd5.so.2.0.22
-rw-r--r--  1 root root 46320 2006-12-13 22:26 libdigestmd5.a
-rw-r--r--  1 root root   864 2006-12-13 22:26 libdigestmd5.la
-rw-r--r--  1 root root 43040 2006-12-13 22:26 libdigestmd5.so
-rw-r--r--  1 root root 43040 2006-12-13 22:26 libdigestmd5.so.2
-rw-r--r--  1 root root 43040 2006-12-13 22:26 libdigestmd5.so.2.0.22
-rw-r--r--  1 root root 13482 2006-12-13 22:26 liblogin.a
-rw-r--r--  1 root root   835 2006-12-13 22:26 liblogin.la
-rw-r--r--  1 root root 13384 2006-12-13 22:26 liblogin.so
-rw-r--r--  1 root root 13384 2006-12-13 22:26 liblogin.so.2
-rw-r--r--  1 root root 13384 2006-12-13 22:26 liblogin.so.2.0.22
-rw-r--r--  1 root root 29300 2006-12-13 22:26 libntlm.a
-rw-r--r--  1 root root   829 2006-12-13 22:26 libntlm.la
-rw-r--r--  1 root root 28776 2006-12-13 22:26 libntlm.so
-rw-r--r--  1 root root 28776 2006-12-13 22:26 libntlm.so.2
-rw-r--r--  1 root root 28776 2006-12-13 22:26 libntlm.so.2.0.22
-rw-r--r--  1 root root 13818 2006-12-13 22:26 libplain.a
-rw-r--r--  1 root root   835 2006-12-13 22:26 libplain.la
-rw-r--r--  1 root root 13992 2006-12-13 22:26 libplain.so
-rw-r--r--  1 root root 13992 2006-12-13 22:26 libplain.so.2
-rw-r--r--  1 root root 13992 2006-12-13 22:26 libplain.so.2.0.22
-rw-r--r--  1 root root 21726 2006-12-13 22:26 libsasldb.a
-rw-r--r--  1 root root   856 2006-12-13 22:25 libsasldb.la
-rw-r--r--  1 root root 17980 2006-12-13 22:26 libsasldb.so
-rw-r--r--  1 root root 17980 2006-12-13 22:26 libsasldb.so.2
-rw-r--r--  1 root root 17980 2006-12-13 22:26 libsasldb.so.2.0.22
-rw-r--r--  1 root root 23576 2006-12-13 22:26 libsql.a
-rw-r--r--  1 root root   964 2006-12-13 22:26 libsql.la
-rw-r--r--  1 root root 23072 2006-12-13 22:26 libsql.so
-rw-r--r--  1 root root 23072 2006-12-13 22:26 libsql.so.2
-rw-r--r--  1 root root 23072 2006-12-13 22:26 libsql.so.2.0.22




-- content of /etc/postfix/sasl/smtpd.conf --
pwcheck_method: saslauthd
mech_list: plain login
allow_plaintext: true
auxprop_plugin: sql
sql_hostnames: 127.0.0.1
sql_user: --- replaced ---
sql_passwd: --- replaced ---
sql_database: mail
sql_select: select password from users where email = '%u'
#saslauthd_path: /var/run/saslauthd


-- active services in /etc/postfix/master.cf --
# service type  private unpriv  chroot  wakeup  maxproc command + args
#               (yes)   (yes)   (yes)   (never) (100)
smtp      inet  n       -       -       -       -       smtpd
pickup    fifo  n       -       -       60      1       pickup
cleanup   unix  n       -       -       -       0       cleanup
qmgr      fifo  n       -       n       300     1       qmgr
tlsmgr    unix  -       -       -       1000?   1       tlsmgr
rewrite   unix  -       -       -       -       -       trivial-rewrite
bounce    unix  -       -       -       -       0       bounce
defer     unix  -       -       -       -       0       bounce
trace     unix  -       -       -       -       0       bounce
verify    unix  -       -       -       -       1       verify
flush     unix  n       -       -       1000?   0       flush
proxymap  unix  -       -       n       -       -       proxymap
smtp      unix  -       -       -       -       -       smtp
relay     unix  -       -       -       -       -       smtp
        -o fallback_relay=
showq     unix  n       -       -       -       -       showq
error     unix  -       -       -       -       -       error
discard   unix  -       -       -       -       -       discard
local     unix  -       n       n       -       -       local
virtual   unix  -       n       n       -       -       virtual
lmtp      unix  -       -       -       -       -       lmtp
anvil     unix  -       -       -       -       1       anvil
scache    unix  -       -       -       -       1       scache
maildrop  unix  -       n       n       -       -       pipe
  flags=Rhu user=vmail argv=/usr/local/bin/maildrop -d ${recipient}
uucp      unix  -       n       n       -       -       pipe
  flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
ifmail    unix  -       n       n       -       -       pipe
  flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp     unix  -       n       n       -       -       pipe
  flags=Fq. user=bsmtp argv=/usr/lib/bsmtp/bsmtp -t$nexthop -f$sender $recipient
scalemail-backend unix  -       n       n       -       2       pipe
  flags=R user=scalemail argv=/usr/lib/scalemail/bin/scalemail-store ${nexthop} ${user} ${extension}
mailman   unix  -       n       n       -       -       pipe
  flags=FR user=list argv=/usr/lib/mailman/bin/postfix-to-mailman.py
  ${nexthop} ${user}

-- mechanisms on localhost --
250-AUTH PLAIN LOGIN
250-AUTH=PLAIN LOGIN



-- end of saslfinger output --






Thanks,


Nicolas