SMTP AUTH error on multi server configuration

Discuss your pilot or production implementation with other Zimbra admins or our engineers.
inigoml
Advanced member
Advanced member
Posts: 97
Joined: Fri Sep 12, 2014 10:14 pm

SMTP AUTH error on multi server configuration

Postby inigoml » Tue Nov 02, 2010 9:37 am

Last week we deployed a second server in our Zimbra NE installation (6.0.8) in order to test zmmailbox and perform a server-to-server migration in a future instead of full backup & restore.
We have dealed with some problems regarding logging and other strage behaviours, but fortunately all of them have been solved.
However, there is a problem that we cannot address.
When sending an email from main server vía SMTP (auth) we ramdonly get an error form saslauth.

It appears that our main server (serverA) is trying to authenticate via soap in serverB, and in serverB there is no account for thist user. After retrying once or twice, user authenticate and email is sent properly.
Nov  2 11:02:19 serverA postfix/smtpd[8397]: connect from V0000261.foo.bar[XX.XX.XX.24]

Nov 2 11:02:19 serverA postfix/smtpd[8397]: setting up TLS connection from V0000261.foo.bar[XX.XX.XX.24]

Nov 2 11:02:19 serverA postfix/smtpd[8397]: Anonymous TLS connection established from V0000261.foo.bar[XX.XX.XX.24]: TLSv1 with cipher AES256-SHA (256/256 bits)

Nov 2 11:02:20 serverA saslauthd[12188]: zmauth: authenticating against elected url 'https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap/' ...

Nov 2 11:02:20 serverA slapd[3961]: slap_queue_csn: queing 0x44005320 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverA slapd[3961]: slap_queue_csn: queing 0xa074650 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverB slapd[1103]: do_syncrep2: rid=100 cookie=rid=100,csn=20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverB slapd[1103]: slap_queue_csn: queing 0x6fd1b5b 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverA slapd[3961]: syncprov_sendresp: cookie=rid=100,csn=20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverA slapd[3961]: slap_graduate_commit_csn: removing 0x8bc94e0 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverB slapd[1103]: slap_graduate_commit_csn: removing 0x8405300 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverB slapd[1103]: syncrepl_message_to_op: rid=100 be_modify uid=csaiz,ou=people,dc=vectorsf,dc=com (0)

Nov 2 11:02:20 serverB slapd[1103]: slap_queue_csn: queing 0x85de510 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverB slapd[1103]: slap_graduate_commit_csn: removing 0x8823750 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverA slapd[3961]: slap_graduate_commit_csn: removing 0x8aa3a50 20101102100224.133680Z#000000#000#000000

Nov 2 11:02:20 serverA saslauthd[12188]: zmpost: url='https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap/' returned buffer->data='http://www.w3.org/2003/05/soap-envelope">">http://www.w3.org/2003/05/soap-envelope"> xmlns="urn:zimbra"/>soap:Senderauthentication failed for csaizaccount.AUTH_FAILEDcom.zimbra.cs.account.AccountServiceException$AuthFailedServiceException: authentication failed for csaiz ExceptionId:btpool0-6://serverB.foo.bar:7071/service/admin/soap/:1288692140148:d5cfb0002ea62c49 Code:account.AUTH_FAILED #011at com.zimbra.cs.account.AccountServiceException$AuthFailedServiceException.AUTH_FAILED(AccountServiceException.java:130) #011at com.zimbra.cs.account.AccountServiceException$AuthFailedServiceException.AUTH_FAILED(AccountServiceException.java:126) #011at com.zimbra.cs.account.auth.AuthMechanism$ZimbraAuth.do

Nov 2 11:02:20 serverA saslauthd[12188]: auth_zimbra: csaiz auth failed: authentication failed for csaiz

Nov 2 11:02:20 serverA saslauthd[12188]: do_auth : auth failure: [user=csaiz] [service=smtp] [realm=] [mech=zimbra] [reason=Unknown]

Nov 2 11:02:20 serverA postfix/smtpd[8397]: warning: SASL authentication failure: Password verification failed

Nov 2 11:02:20 serverA postfix/smtpd[8397]: warning: V0000261.foo.bar[XX.XX.XX.24]: SASL PLAIN authentication failed: authentication failure

Nov 2 11:02:20 serverA saslauthd[12187]: zmauth: authenticating against elected url 'https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap/' ...

Nov 2 11:02:20 serverA saslauthd[12187]: zmpost: url='https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap">https://serverB.foo.bar:7071/service/admin/soap/' returned buffer->data='http://www.w3.org/2003/05/soap-envelope">">http://www.w3.org/2003/05/soap-envelope"> xmlns="urn:zimbra"/>soap:Senderauthentication failed for csaizaccount.AUTH_FAILEDcom.zimbra.cs.account.AccountServiceException$AuthFailedServiceException: authentication failed for csaiz ExceptionId:btpool0-6://serverB.foo.bar:7071/service/admin/soap/:1288692140468:d5cfb0002ea62c49 Code:account.AUTH_FAILED #011at com.zimbra.cs.account.AccountServiceException$AuthFailedServiceException.AUTH_FAILED(AccountServiceException.java:130) #011at com.zimbra.cs.account.AccountServiceException$AuthFailedServiceException.AUTH_FAILED(AccountServiceException.java:126) #011at com.zimbra.cs.account.auth.AuthMechanism$ZimbraAuth.do

Nov 2 11:02:20 serverA saslauthd[12187]: auth_zimbra: csaiz auth failed: authentication failed for csaiz

Nov 2 11:02:20 serverA saslauthd[12187]: do_auth : auth failure: [user=csaiz] [service=smtp] [realm=] [mech=zimbra] [reason=Unknown]

Nov 2 11:02:20 serverA postfix/smtpd[8397]: warning: V0000261.foo.bar[XX.XX.XX.24]: SASL LOGIN authentication failed: authentication failure



And mailbox.log



2010-11-02 11:02:20,067 INFO [btpool0-6://serverB.foo.bar:7071/service/admin/soap/] [ip=XX.XX.XX.30;] soap - AuthRequest

2010-11-02 11:02:20,147 WARN [btpool0-6://serverB.foo.bar:7071/service/admin/soap/] [name=csaiz@foo.bar;ip=XX.XX.XX.30;] account - ldap auth for domain foo.bar failed, fall back to zimbra default auth mechanism

com.zimbra.common.service.ServiceException: system failure: sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target

ExceptionId:btpool0-6://serverB.foo.bar:7071/service/admin/soap/:1288692140147:d5cfb0002ea62c49

Code:service.FAILURE

at com.zimbra.common.service.ServiceException.FAILURE(ServiceException.java:248)

at com.zimbra.cs.account.ldap.LdapProvisioning.externalLdapAuth(LdapProvisioning.java:3556)

at com.zimbra.cs.account.auth.AuthMechanism$LdapAuth.doAuth(AuthMechanism.java:165)

at com.zimbra.cs.account.ldap.LdapProvisioning.verifyPasswordInternal(LdapProvisioning.java:3600)

at com.zimbra.cs.account.ldap.LdapProvisioning.verifyPassword(LdapProvisioning.java:3573)

at com.zimbra.cs.account.ldap.LdapProvisioning.authAccount(LdapProvisioning.java:3439)

at com.zimbra.cs.account.ldap.LdapProvisioning.authAccount(LdapProvisioning.java:3418)

at com.zimbra.cs.service.account.Auth.handle(Auth.java:118)

at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:420)

at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:274)

at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:158)

at com.zimbra.soap.SoapServlet.doWork(SoapServlet.java:291)

at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:212)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)

at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:181)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)

at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)

at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)

at com.zimbra.cs.servlet.SetHeaderFilter.doFilter(SetHeaderFilter.java:79)

at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)

at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)

at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:155)

at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)

at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)

at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)

at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)

at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)

at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)

at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)

at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)

at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)

at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:230)

at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)

at org.mortbay.jetty.handler.DebugHandler.handle(DebugHandler.java:77)

at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)

at org.mortbay.jetty.Server.handle(Server.java:326)

at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:543)

at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:939)

at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)

at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)

at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:405)

at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:413)

at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)

Caused by: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target

at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:174)

at com.sun.net.ssl.internal.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1623)

at com.sun.net.ssl.internal.ssl.Handshaker.fatalSE(Handshaker.java:198)

at com.sun.net.ssl.internal.ssl.Handshaker.fatalSE(Handshaker.java:192)

at com.sun.net.ssl.internal.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1074)

at com.sun.net.ssl.internal.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:128)

at com.sun.net.ssl.internal.ssl.Handshaker.processLoop(Handshaker.java:529)

at com.sun.net.ssl.internal.ssl.Handshaker.process_record(Handshaker.java:465)

at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:884)

at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1120)

at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1147)

at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1131)

at com.sun.jndi.ldap.ext.StartTlsResponseImpl.startHandshake(StartTlsResponseImpl.java:344)

at com.sun.jndi.ldap.ext.StartTlsResponseImpl.negotiate(StartTlsResponseImpl.java:208)

at com.sun.jndi.ldap.ext.StartTlsResponseImpl.negotiate(StartTlsResponseImpl.java:161)

at com.zimbra.cs.account.ldap.ZimbraLdapContext.tlsNegotiate(ZimbraLdapContext.java:359)

at com.zimbra.cs.account.ldap.ZimbraLdapContext.(ZimbraLdapContext.java:492)

at com.zimbra.cs.account.ldap.ZimbraLdapContext.(ZimbraLdapContext.java:426)

at com.zimbra.cs.account.ldap.LdapUtil.ldapAuthenticate(LdapUtil.java:120)

at com.zimbra.cs.account.ldap.LdapProvisioning.externalLdapAuth(LdapProvisioning.java:3537)

... 41 more

Caused by: sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target

at sun.security.validator.PKIXValidator.doBuild(PKIXValidator.java:325)

at sun.security.validator.PKIXValidator.engineValidate(PKIXValidator.java:219)

at sun.security.validator.Validator.validate(Validator.java:218)

at com.sun.net.ssl.internal.ssl.X509TrustManagerImpl.validate(X509TrustManagerImpl.java:126)

at com.sun.net.ssl.internal.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:209)

at com.sun.net.ssl.internal.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:249)

at com.sun.net.ssl.internal.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1053)

... 56 more

Caused by: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target

at sun.security.provider.certpath.SunCertPathBuilder.engineBuild(SunCertPathBuilder.java:174)

at java.security.cert.CertPathBuilder.build(CertPathBuilder.java:238)

at sun.security.validator.PKIXValidator.doBuild(PKIXValidator.java:320)

... 62 more

2010-11-02 11:02:20,513 INFO [btpool0-6://serverB.foo.bar:7071/service/admin/soap/] [name=csaiz@foo.bar;ip=XX.XX.XX.30;] SoapEngine - handler exception: authentication failed for csaiz, invalid password

2010-11-02 11:02:20,515 WARN [btpool0-6] [] log - SSL renegotiate denied: java.nio.channels.SocketChannel[connected local=/XX.XX.XX.130:7071 remote=/XX.XX.XX.30:50901]

2



inigoml
Advanced member
Advanced member
Posts: 97
Joined: Fri Sep 12, 2014 10:14 pm

SMTP AUTH error on multi server configuration

Postby inigoml » Tue Nov 02, 2010 11:42 am

I've fixed this problem by editing /opt/zimbra/cyrus-sals/conf/salsauthd.conf.in and modifying zimbra_url parameter.



zimbra_url: %%getAllMtaAuthURLs%%


for


zimbra_url: zimbra_url: https://serverA.foo.bar:7071/service/admin/soap/


Anyway, I don't this to be an elegant solution...

Return to “Administrators”

Who is online

Users browsing this forum: No registered users and 11 guests