postfix sasl2 pam_mysql on Debian Sarge

Mon Mar 12 16:43:43 EST 2007

* Nicolas <nicolas at skypro.be>:
> I'm sorry, I thought Thunderbird was going to prompt me for plain text
> before sending, but it didn't. Here it is.
> 
> Nicolas
> 
> ===
> 
> 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"

You are planning to run Postfix chrooted, right?

> 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

Where's the socket?

> 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?

I don't know. I didn't know it was possible to tell saslauthd it should put
the socket in a special directory at all. All I know is: The socket directory
(run_path) is where saslauthd puts everything.

> 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 at address -p
> 
> password -f /var/run/saslauthd/mux -s smtp
> execve("/usr/sbin/testsaslauthd", ["/usr/sbin/testsaslauthd", "-u",
> "email at 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"},

The socket is in "/var/run/saslauthd/mux" and not in the location you
specified in /etc/default/saslauthd.

> 110saslauthd[4666] :rel_accept_lock : released accept lock
> saslauthd[4667] :get_accept_lock : acquired accept lock
> ) = 0
> writev(3, [{"\0\17email at address\0\10password\0\4smt"..., 35}], 1) = 35
> read(3, saslauthd[4666] :do_auth         : auth failure:
> [user=email at 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 at address] [service=smtp] [realm=] [mech=pam] [reason=PAM auth
> error]

PAM has a problem. My guess (!) is, its with the pam_mysql settings you've
given.

> 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 at localhost on mail
>                      21 Init DB     mail
>                      21 Query       SELECT clear FROM postfix_users
> WHERE email = 'email at 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?

Get Postfix out of the way to simplify your debug setup. Start saslauthd from
commandline with the settings you want to gave in /etc/default/saslauthd AND
add "-d" to keep saslauthd attached to the screen in debug mode.

Then use testsaslauthd with at least the following options:

$ testsaslauthd -f /var/spool/postfix/var/run/saslauthd -r -s smtp -u <user> -p <pass>

PAM modules can be set to log verbose. IIRC its the "debug" option you need to
set. The pam_mysql module should report more then.

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

Which is the default on Debian and complicates things a lot. Test without
Postfix, then with Postfix. If it fails with Postfix, get it out of the
chroot. Then test again. On Debian Postfix must be in the sasl group to be
permitted to enter the saslauthd socket dir.

> 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

This /etc/postfix/sasl/smtpd.conf won't work. Either you use saslauthd and
PAM with encrypted passwords or you use the auxprop sql plugin without crypted
passwords.

If you go for saslauthd do this:

/etc/postfix/sasl/smtpd.conf
pwcheck_method: saslauthd
mech_list: plain login

p at rick

-- 
The Book of Postfix
<http://www.postfix-book.com>
saslfinger (debugging SMTP AUTH):
<http://postfix.state-of-mind.de/patrick.koetter/saslfinger/>