[SOLVED] Partial Failure - zmsaslauthdctl fails

[the_griz]

In the past three weeks, this has happened twice. Shutting down and restarting the service (zmcontrol stop;zmcontrol start) seems to fix the issue, but I would like assistance in determining the root cause. Any help would be greatly appreciated.

Issue
Some, but not all, users who send email through our zimbra server were not authenticating and their email messages would just queue up in Outlook. All of the users having problems were using IMAP configured Outlook accounts and not ZImbra/Outlook Connector configured accounts.

Evidence of an Issue
[zimbra@mail conf]$ zmcontrol status
Host mail.myserver.com
antispam Running
antivirus Running
convertd Running
imapproxy Running
ldap Running
logger Running
mailbox Running
memcached Running
mta Stopped
zmsaslauthdctl is not running
snmp Running
spell Running
stats Running
zmconfigd Running

/var/log/maillog example:
May 9 07:26:32 mail postfix/qmgr[15059]: 62091D9E00AB: removed
May 9 07:26:33 mail postfix/smtpd[6151]: connect from vpat.appliedonline.net[204.155.62.5]
May 9 07:26:33 mail postfix/smtpd[6151]: setting up TLS connection from vpat.appliedonline.net[204.155.62.5]
May 9 07:26:33 mail postfix/smtpd[6151]: Anonymous TLS connection established from vpat.appliedonline.net[204.155.62.5]: TLSv1 with cipher RC4-MD5 (128/128 bits)
May 9 07:26:33 mail postfix/smtpd[6151]: warning: SASL authentication failure: cannot connect to saslauthd server: No such file or directory
May 9 07:26:33 mail postfix/smtpd[6151]: warning: vpat.appliedonline.net[204.155.62.5]: SASL LOGIN authentication failed: generic failure
May 9 07:26:33 mail postfix/smtpd[6151]: lost connection after AUTH from vpat.appliedonline.net[204.155.62.5]
May 9 07:26:33 mail postfix/smtpd[6151]: disconnect from vpat.appliedonline.net[204.155.62.5]
May 9 07:26:39 mail postfix/smtpd[6151]: connect from vpat.appliedonline.net[204.155.62.5]
May 9 07:26:39 mail postfix/smtpd[6151]: setting up TLS connection from vpat.appliedonline.net[204.155.62.5]
May 9 07:26:39 mail postfix/smtpd[6151]: Anonymous TLS connection established from vpat.appliedonline.net[204.155.62.5]: TLSv1 with cipher RC4-MD5 (128/128 bits)
May 9 07:26:39 mail postfix/smtpd[6151]: warning: SASL authentication failure: cannot connect to saslauthd server: No such file or directory
May 9 07:26:39 mail postfix/smtpd[6151]: warning: vpat.appliedonline.net[204.155.62.5]: SASL LOGIN authentication failed: generic failure
May 9 07:26:39 mail postfix/smtpd[6151]: lost connection after AUTH from vpat.appliedonline.net[204.155.62.5]

Errors in /opt.zimbra/log/zmconfigd.log:
2011-05-09 04:27:45,444 zmconfigd WARNING [6874-MainThread] Fetching All configs
Starting zmconfigd...zmconfigd is already running.
Exception in thread mc:Traceback (most recent call last):
File "/opt/zimbra/lib/jars/jython-2.5.1.jar/Lib/threading.py", line 178, in _Thread__bootstrap
self.run()
File "/opt/zimbra/lib/jars/jython-2.5.1.jar/Lib/threading.py", line 169, in run
self._target(*self._args, **self._kwargs)
File "/opt/zimbra/zimbramon/pylibs/state.py", line 298, in getMiscConfig
self.miscconfig.load()
File "/opt/zimbra/zimbramon/pylibs/miscconfig.py", line 32, in load
self.doCommand(cm);
File "/opt/zimbra/zimbramon/pylibs/miscconfig.py", line 44, in doCommand
rc = c.execute();
File "/opt/zimbra/zimbramon/pylibs/commands.py", line 107, in execute
(rc, output, error) = cm(self.args, a)
File "/opt/zimbra/zimbramon/pylibs/commands.py", line 176, in garpu
for server in P.getAllServers():
File "/opt/zimbra/zimbramon/pylibs/commands.py", line 176, in garpu
for server in P.getAllServers():
ServiceException: com.zimbra.common.service.ServiceException: system failure: ZimbraLdapContext
ExceptionId:mc:1304929700395:f937cfb3e93c6832
Code:service.FAILURE
2011-05-09 04:28:20,660 zmconfigd WARNING [6874-MainThread] All configs fetched in 35.22 seconds
2011-05-09 04:28:21,002 zmconfigd WARNING [6874-MainThread] Var getAllMtaAuthURLs changed from 'https://mail.myserver.com:7071/service/admin/soap/' to no longer defined.
2011-05-09 04:28:21,006 zmconfigd WARNING [6874-MainThread] Var getAllMemcachedServers changed from 'mail.myserver.com:11211' to no longer defined.
2011-05-09 04:28:21,023 zmconfigd WARNING [6874-MainThread] Var getAllReverseProxyURLs changed from 'mail.myserver.com:7072/service/extension/nginx-lookup' to no longer defined.
2011-05-09 04:28:21,026 zmconfigd WARNING [6874-MainThread] Var getAllReverseProxyBackends changed from ' server localhost:8080;' to no longer defined.
[] INFO: Loading server object: mail.myserver.com
2011-05-09 04:28:21,187 zmconfigd WARNING [6874-rewrites] Rewrote: /opt/zimbra/cyrus-sasl-2.1.23.3z/etc/saslauthd.conf with mode 440 (0.15 sec)
[] WARN: Upstream: Ignoring server:mail.myserver.com because its mail mode is:redirect
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.template to file:/opt/zimbra/conf/nginx.conf
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.main.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.main
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.memcache.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.memcache
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imap.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imap
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imap.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imap.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imaps.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imaps
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imaps.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imaps.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3s.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3s
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3s.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3s.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-http.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-http
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-https.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-https
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-both.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-both
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-redirect.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-redirect
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-mixed.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-mixed
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-http.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-http
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-https.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-https
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-both.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-both
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-redirect.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-redirect
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-mixed.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-mixed
[] INFO: Proxy configuration files are generated successfully
2011-05-09 04:28:21,536 zmconfigd WARNING [6874-MainThread] All rewrite threads completed in 0.50 sec
2011-05-09 04:28:21,538 zmconfigd WARNING [6874-MainThread] controlProcess imapproxy restart (-1)
2011-05-09 04:28:21,538 zmconfigd WARNING [6874-MainThread] CONTROL imapproxy: bin/zmproxyctl restart norewrite
2011-05-09 04:28:21,539 zmconfigd CRITICAL [6874-MainThread] imapproxy restart initiated from zmconfigd
2011-05-09 04:28:28,456 zmconfigd WARNING [6874-MainThread] controlProcess mta restart (-1)
2011-05-09 04:28:28,457 zmconfigd WARNING [6874-MainThread] CONTROL mta: bin/postfix reload norewrite
2011-05-09 04:28:28,457 zmconfigd CRITICAL [6874-MainThread] mta reload initiated from zmconfigd
2011-05-09 04:28:30,197 zmconfigd WARNING [6874-MainThread] controlProcess sasl restart (-1)
2011-05-09 04:28:30,197 zmconfigd WARNING [6874-MainThread] CONTROL sasl: bin/zmsaslauthdctl restart norewrite
2011-05-09 04:28:30,197 zmconfigd CRITICAL [6874-MainThread] sasl restart initiated from zmconfigd
Starting zmconfigd...zmconfigd is already running.
2011-05-09 04:29:01,838 zmconfigd ERROR [6874-MainThread] Executed: /opt/zimbra/bin/zmsaslauthdctl restart norewrite returned 1 (56 - 74) (31.64 sec)
2011-05-09 04:29:01,838 zmconfigd ERROR [6874-MainThread] Failed to restart sasl rc=1
2011-05-09 04:29:01,839 zmconfigd WARNING [6874-MainThread] controlProcess sasl restart (-1)
2011-05-09 04:29:01,839 zmconfigd WARNING [6874-MainThread] CONTROL sasl: bin/zmsaslauthdctl restart norewrite
2011-05-09 04:29:01,841 zmconfigd CRITICAL [6874-MainThread] sasl restart initiated from zmconfigd
2011-05-09 04:29:33,802 zmconfigd ERROR [6874-MainThread] Executed: /opt/zimbra/bin/zmsaslauthdctl restart norewrite returned 1 (55 - 74) (31.93 sec)
2011-05-09 04:29:33,867 zmconfigd ERROR [6874-MainThread] Failed to restart sasl rc=1
2011-05-09 04:29:33,867 zmconfigd WARNING [6874-MainThread] controlProcess sasl restart (-1)
2011-05-09 04:29:33,868 zmconfigd WARNING [6874-MainThread] CONTROL sasl: bin/zmsaslauthdctl restart norewrite
2011-05-09 04:29:33,868 zmconfigd CRITICAL [6874-MainThread] sasl restart initiated from zmconfigd
Starting zmconfigd...zmconfigd is already running.

[quanah]

This is a known issue fixed in ZCS 7.1.1.

[the_griz]

When will 7.1.1 be released?

[phoenix]

Originally Posted by the_griz

When will 7.1.1 be released?

The usual answer is 'when it's ready'. Product release are not pre-announced and you'll see an announcement in the forums (and perhaps the Product Portal) when it's available.

[the_griz]

Thanks Guys!

[nepco]

I am having the same problem. I usually have to stop and restart zimbra once a day or email stops working. I'm on the network version and pay good money so hope it gets resolved soon. I guess I should have never upgrade to version 7. I will give it a few and if not resolved soon I will either move back to version 6 or look for a different email solution.

Thanks.

[robtain]

Originally Posted by quanah

This is a known issue fixed in ZCS 7.1.1.

Can we please have even a rough timeline for a fix?

I just recently migrated to Zimbra OCS 7 and now our authenticated SMTP fails almost daily.

We have set up a cron job to restart the zimbra service daily, but it sometimes suffers random failures anyway.

We have 150+ users as well as several hundred users subscribed to Mailman lists who are experiencing service outages on an all too frequent basis.

It's unacceptable and embarrassing.

[quanah]

Just copy over saslauthd.conf.in with a working saslauthd.conf, this will prevent it from overwriting saslauthd.conf in a non-working fashion.

[rbreck]

I'm having this issue as well -- do you know where a working saslauthd.conf could be found?

[portscanner]

I administer three different sites running version 7.1.3 and occasionally have this problem. I have found that the problem is the line that starts with "zimbra_url:" in /opt/zimbra/cyrus-sasl/etc/saslauthd.conf has no data. To correct that issue, add https://my.server.com:7071/service/admin/soap/ (replacing my.server.com with the FQDN of your server) after zimbra_url:

If you are running multiple servers, add a "https://my.server.com:7071/service/admin/soap" for each of your servers on that same line, separated by spaces