saslauthd: Permission denied (external SMTP AUTH broken)

[Miz]

And because I'm feeling verbose...

$ ls -lR /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/lib
/opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/lib:
total 284
-rwxr-xr-x  1 zimbra zimbra    829 Oct 19 16:13 libsasl2.la
lrwxrwxrwx  1 root   zimbra     18 Jan 18 10:23 libsasl2.so -> libsasl2.so.2.0.21
lrwxrwxrwx  1 root   zimbra     18 Jan 18 10:23 libsasl2.so.2 -> libsasl2.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra 277559 Oct 19 16:13 libsasl2.so.2.0.21
drwxr-xr-x  2 zimbra zimbra   4096 Jan 18 10:23 sasl2

/opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/lib/sasl2:
total 608
-rwxr-xr-x  1 zimbra zimbra    855 Oct 19 16:13 libanonymous.la
lrwxrwxrwx  1 root   zimbra     22 Jan 18 10:23 libanonymous.so -> libanonymous.so.2.0.21
lrwxrwxrwx  1 root   zimbra     22 Jan 18 10:23 libanonymous.so.2 -> libanonymous.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra  53724 Oct 19 16:13 libanonymous.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra    843 Oct 19 16:13 libcrammd5.la
lrwxrwxrwx  1 root   zimbra     20 Jan 18 10:23 libcrammd5.so -> libcrammd5.so.2.0.21
lrwxrwxrwx  1 root   zimbra     20 Jan 18 10:23 libcrammd5.so.2 -> libcrammd5.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra  60395 Oct 19 16:13 libcrammd5.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra    864 Oct 19 16:13 libdigestmd5.la
lrwxrwxrwx  1 root   zimbra     22 Jan 18 10:23 libdigestmd5.so -> libdigestmd5.so.2.0.21
lrwxrwxrwx  1 root   zimbra     22 Jan 18 10:23 libdigestmd5.so.2 -> libdigestmd5.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra 124812 Oct 19 16:13 libdigestmd5.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra    891 Oct 19 16:13 libgssapiv2.la
lrwxrwxrwx  1 root   zimbra     21 Jan 18 10:23 libgssapiv2.so -> libgssapiv2.so.2.0.21
lrwxrwxrwx  1 root   zimbra     21 Jan 18 10:23 libgssapiv2.so.2 -> libgssapiv2.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra  77952 Oct 19 16:13 libgssapiv2.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra    839 Oct 19 16:13 liblogin.la
lrwxrwxrwx  1 root   zimbra     18 Jan 18 10:23 liblogin.so -> liblogin.so.2.0.21
lrwxrwxrwx  1 root   zimbra     18 Jan 18 10:23 liblogin.so.2 -> liblogin.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra  55068 Oct 19 16:13 liblogin.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra    828 Oct 19 16:13 libotp.la
lrwxrwxrwx  1 root   zimbra     16 Jan 18 10:23 libotp.so -> libotp.so.2.0.21
lrwxrwxrwx  1 root   zimbra     16 Jan 18 10:23 libotp.so.2 -> libotp.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra 117351 Oct 19 16:13 libotp.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra    839 Oct 19 16:13 libplain.la
lrwxrwxrwx  1 root   zimbra     18 Jan 18 10:23 libplain.so -> libplain.so.2.0.21
lrwxrwxrwx  1 root   zimbra     18 Jan 18 10:23 libplain.so.2 -> libplain.so.2.0.21
-rwxr-xr-x  1 zimbra zimbra  55086 Oct 19 16:13 libplain.so.2.0.21
-r--r--r--  1 zimbra zimbra    167 Jan 18 16:19 smtpd.conf

[Miz]

There's one. Just had to try SMTP'ing again.

Same as 'master', looks-like.

pmap output

b7d33000     76K r-x--  /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/lib/libsasl2.so.2.0.21
b7d46000      4K rw---  /opt/zimbra/cyrus-sasl-2.1.21.ZIMBRA/lib/libsasl2.so.2.0.21

[anand]

I looked through the cyrus-sasl sources, and the only place your original error message ("cannot connect to saslauthd server: Permission denied") is created is when the connect(3) on the "mux" file fails. Note that the error is EPERM, and not ENOENT. Unfortunately there is no logging we can turn on for the SASL client library. Also the perms on the "mux" socket file looks right, and "postfix" user should be able to connect to that file. I am stumped by this as is Bobby.

By any chance do you have selinux enabled or configured enough to get in the way here?

The only other thing I can think of to track this down is configure postfix to launch only one smtpd server, and then make a test connection (so the smtpd process will be up started for you find its pid), strace that pid, and kick off tbird and see why the connect(3) is failing, and more importantly what path the connect(3) is trying to connect to.

See also:

http://www.postfix.org/DEBUG_README.html

[Miz]

Ouch, I would have preferred if I WERE insane and just overlooking something.


For reference (SELinux),

# getenforce
Disabled

Trace, yay.

Thanks for the suggestions guys, I'll see what I can see.

[Miz]

Well, this confirms suspicions. That line of code is getting hit:

Process 15115 attached - interrupt to quit
select(14, [13], NULL, [13], {285, 130000}) = 1 (in [13], left {281, 480000})
read(13, "\27\3\1\0P", 5)               = 5
select(14, [13], NULL, [13], {300, 0})  = 1 (in [13], left {300, 0})
read(13, "\250+.\21q\3678\355\264\342\260\262\206u\275\337V\2\357"..., 80) = 80
time(NULL)                              = 1169166639
socket(PF_FILE, SOCK_STREAM, 0)         = 15
connect(15, {sa_family=AF_FILE, path="/opt/zimbra/cyrus-sasl/state/mux"}, 110) = -1 EACCES (Permission denied)
close(15)                               = 0
time([1169166639])                      = 1169166639
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1267, ...}) = 0
send(7, "<20>Jan 18 19:30:39 postfix/smtp"..., 133, MSG_NOSIGNAL) = 133

Unfortunately, that doesn't seem to shed any light at all...

srwxrwxrwx  1 zimbra zimbra 0 Jan 18 17:27 /opt/zimbra/cyrus-sasl/state/mux

[Miz]

I started wreaking havok on file permissions like a bad-person, chowning this, chowning that... naturally I broke Zimbra, but a quick zmfixperms (handy) got services started again, at least.

This is severely obscure...

[Miz]

Moved my existing installation off to the side, completely uninstalled the rpm's.

Fresh install 4.5, for some reason I needed to run /opt/zimbra/libexec/zmmyinit
as the zimbra user (I didn't pay attention as to why, just that I needed to) but after all services were up -- no smtp auth, after creating a user. IMAP/TLS worked dandy.

Just a shot in the dark... can this be remotely umask-related? I'm shooting in the dark here, considering the files seem to have proper owner/perms when started...

[anand]

Originally Posted by Miz

can this be remotely umask-related? I'm shooting in the dark here, considering the files seem to have proper owner/perms when started...

Why do you ask? Is there something strange about your umask?

Since no one is creating this socket at runtime, there should not be an umask issue.

[Miz]

I ... beg to differ?

$ zmcontrol stop
Host mail.whatever.tld
        Stopping mta...Done
        Stopping spell...Done
        Stopping snmp...Done
        Stopping antivirus...Done
        Stopping antispam...Done
        Stopping imapproxy...Done
        Stopping mailbox...Done
        Stopping logger...Done
        Stopping ldap...Done
[zimbra@mail ~]$ cd cyrus-sasl/state
[zimbra@mail state]$ pwd
/opt/zimbra/cyrus-sasl/state
[zimbra@mail state]$ ls -l
total 0

[zimbra@mail state]$ zmcontrol start
Host mail.whatever.tld
        Starting ldap...Done.
        Starting logger...Done.
        Starting mailbox...Done.
        Starting antispam...Done.
        Starting antivirus...Done.
        Starting snmp...Done.
        Starting spell...Done.
        Starting mta...Done.
[zimbra@mail state]$ ls -l
total 4
srwxrwxrwx  1 zimbra zimbra 0 Jan 19 21:56 mux
-rw-------  1 zimbra zimbra 0 Jan 19 21:56 mux.accept
-rw-------  1 zimbra zimbra 6 Jan 19 21:56 saslauthd.pid
[zimbra@mail state]$

I'll mess with it a little more... I'm fast running out of ideas.

[anand]

What does id on postfix/zimbra users say? I've got:

# id zimbra
uid=507(zimbra) gid=510(zimbra) groups=510(zimbra),4(adm),5(tty),508(postfix)

# id postfix
uid=506(postfix) gid=508(postfix) groups=508(postfix)