[SOLVED] ZCS 5.0.8 MTA failing with Unable to set STARTTLS

Printable View

08-05-2008, 07:57 AM
aromu

[SOLVED] ZCS 5.0.8 MTA failing with Unable to set STARTTLS

Hi all,

I know this issue has been addressed several times both at the Zimbra Wiki and here at forums and I've tried all the magic including disabling the tls.

Could you please walk me through this one.

Here's what I get to the logs

mail.info

Code:

Aug 5 17:50:11 localhost zmmailboxdmgr[26565]: status requested Aug 5 17:50:11 localhost zmmailboxdmgr[26565]: status OK Aug 5 17:50:12 localhost postfix/smtpd[11511]: warning: problem talking to service rewrite: Success Aug 5 17:50:12 localhost postfix/master[5801]: warning: process /opt/zimbra/postfix/libexec/trivial-rewrite pid 26321 exit status 1 Aug 5 17:50:12 localhost postfix/smtpd[11975]: warning: problem talking to service rewrite: Connection reset by peer Aug 5 17:51:12 localhost postfix/trivial-rewrite[26606]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error Aug 5 17:51:12 localhost last message repeated 2 times Aug 5 17:51:12 localhost postfix/trivial-rewrite[26606]: fatal: ldap:/opt/zimbra/conf/ldap-vad.cf(0,lock|fold_fix): table lookup problem Aug 5 17:51:13 localhost postfix/smtpd[19710]: warning: problem talking to service rewrite: Connection reset by peer Aug 5 17:51:13 localhost postfix/smtpd[19709]: warning: problem talking to service rewrite: Success Aug 5 17:51:13 localhost postfix/master[5801]: warning: process /opt/zimbra/postfix/libexec/trivial-rewrite pid 26606 exit status 1 Aug 5 17:51:13 localhost postfix/master[5801]: warning: /opt/zimbra/postfix/libexec/trivial-rewrite: bad command startup -- throttling Aug 5 17:51:14 localhost postfix/trivial-rewrite[26640]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error Aug 5 17:51:14 localhost last message repeated 2 times

mail.err

Code:

Aug 5 17:52:15 localhost postfix/trivial-rewrite[27280]: fatal: ldap:/opt/zimbra/conf/ldap-vad.cf(0,lock|fold_fix): table lookup problem Aug 5 17:52:17 localhost postfix/trivial-rewrite[27281]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error Aug 5 17:52:17 localhost last message repeated 2 times

The ldap seems to be answering correctly:

Code:

# ldapsearch -x -ZZ -h "FQDN" -b "" -s base # extended LDIF # # LDAPv3 # base <> with scope baseObject # filter: (objectclass=*) # requesting: ALL # # dn: objectClass: top objectClass: OpenLDAProotDSE # search result search: 3 result: 0 Success # numResponses: 2 # numEntries: 1

Best regards:
Aapo
08-05-2008, 08:10 AM
phoenix

Have you seen this wiki article and you've verified that it and the related certificate articles check out OK?
08-05-2008, 12:06 PM
aromu

Hi phoenix and thank you for your answer

There was some information missing from my first post that could help you to pinpoint the problem but first I'll answer to your question:

I started solving the issue with forum thread
http://www.zimbra.com/forums/install...y-failure.html

Then I went through the following articles step by step

Error (MTA): Unable to set STARTTLS - Zimbra :: Wiki
Problem with Certificate can cause MTA Failure - Zimbra :: Wiki
SSL Certificate Problems - Zimbra :: Wiki

I especially paid attention to the last one since it seemed to be the most complete answer. However I tried all of them step by step.

There was also the bug Bug 22468 – new LDAP user testing in menu installer but I wasn't able to get much help out of that.

I forgot to mention that the Zimbra installation I'm trying to get working is a fresh one and the exact package I'm using is: zcs-5.0.8_GA_2462.UBUNTU6_64.20080709205157

The system is Ubuntu Server 7.10 64bit (I used some other threads from forum to get the installer working and to solve the issue with Apache already running on the server)

I'm also thinking if it can be possible that for some reason the Zimbra postfix is not actually using the open LDAP provided by the Zimbra package. The authentication at the server is done with external LDAP server (let's call it ldap.mycompany.com). The system allows also local account information and it is possible to log in using those local accounts.

The reason I'm thinking of this is the messages at /var/log/auth.log (replaced the actual ldap server with fake name)

Code:

Aug 5 21:57:31 localhost postfix/trivial-rewrite[21397]: nss_ldap: could not search LDAP server - Server is unavailable Aug 5 21:57:51 localhost sudo: zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmmailboxdmgr status Aug 5 21:57:51 localhost sudo: zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmmtastatus Aug 5 21:57:51 localhost sudo: zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmmailboxdmgr status Aug 5 21:58:01 localhost CRON[21820]: pam_unix(cron:session): session opened for user zimbra by (uid=0) Aug 5 21:58:05 localhost sudo: zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmmailboxdmgr status Aug 5 21:58:05 localhost sudo: zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmmtastatus Aug 5 21:58:06 localhost CRON[21820]: pam_unix(cron:session): session closed for user zimbra Aug 5 21:58:30 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server Aug 5 21:58:30 localhost postfix/trivial-rewrite[22076]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server Aug 5 21:58:30 localhost postfix/trivial-rewrite[22076]: nss_ldap: reconnecting to LDAP server... Aug 5 21:58:30 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server Aug 5 21:58:30 localhost postfix/trivial-rewrite[22076]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server Aug 5 21:58:30 localhost postfix/trivial-rewrite[22076]: nss_ldap: reconnecting to LDAP server (sleeping 1 seconds)... Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not search LDAP server - Server is unavailable Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: reconnecting to LDAP server... Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: reconnecting to LDAP server (sleeping 1 seconds)... Aug 5 21:58:32 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server Aug 5 21:58:32 localhost postfix/trivial-rewrite[22076]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server Aug 5 21:58:32 localhost postfix/trivial-rewrite[22076]: nss_ldap: could not search LDAP server - Server is unavailable Aug 5 21:58:32 localhost postfix/trivial-rewrite[22080]: nss_ldap: could not connect to any LDAP server as (null) - Can't contact LDAP server Aug 5 21:58:32 localhost postfix/trivial-rewrite[22080]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server

The zmlocalconfig shows though (replaced the actual domain with mymaildomain.net):

Code:

$ zmlocalconfig | grep ldap ldap_amavis_password = * ldap_bind_url = ldap_cache_account_maxage = 15 ldap_cache_account_maxsize = 20000 ldap_cache_cos_maxage = 15 ldap_cache_cos_maxsize = 100 ldap_cache_domain_maxage = 15 ldap_cache_domain_maxsize = 100 ldap_cache_group_maxage = 15 ldap_cache_group_maxsize = 200 ldap_cache_server_maxage = 15 ldap_cache_server_maxsize = 100 ldap_cache_timezone_maxsize = 100 ldap_cache_zimlet_maxage = 15 ldap_cache_zimlet_maxsize = 100 ldap_connect_pool_debug = false ldap_connect_pool_initsize = 1 ldap_connect_pool_master = false ldap_connect_pool_maxsize = 50 ldap_connect_pool_prefsize = 0 ldap_connect_pool_timeout = 120000 ldap_connect_timeout = 30000 ldap_deref_aliases = always ldap_host = mail.mymaildomain.net ldap_is_master = true ldap_log_level = 49152 ldap_master_url = ldap://mail.mymaildomain.net:389 ldap_port = 389 ldap_postfix_password = * ldap_read_timeout = 30000 ldap_replication_password = * ldap_require_tls = false ldap_root_password = * ldap_starttls_supported = 1 ldap_url = ldap://mail.mymaildomain.net:389 postfix_sender_canonical_maps = ldap:${zimbra_home}/conf/ldap-scm.cf postfix_transport_maps = ldap:${zimbra_home}/conf/ldap-transport.cf postfix_virtual_alias_domains = ldap:${zimbra_home}/conf/ldap-vad.cf postfix_virtual_alias_maps = ldap:${zimbra_home}/conf/ldap-vam.cf postfix_virtual_mailbox_domains = ldap:${zimbra_home}/conf/ldap-vmd.cf postfix_virtual_mailbox_maps = ldap:${zimbra_home}/conf/ldap-vmm.cf zimbra_class_provisioning = com.zimbra.cs.account.ldap.LdapProvisioning zimbra_ldap_password = * zimbra_ldap_user = zimbra zimbra_ldap_userdn = uid=zimbra,cn=admins,cn=zimbra zimbra_zmprov_default_to_ldap = FALSE

Best regards:
Aapo
08-05-2008, 12:39 PM
aromu

Hi phoenix.

There seems to be some weird behavior on this forum system. The answers I try to send you are displaying and then disappearing.

I'll try to post the correct answer again tomorrow if this system will then work. I'll already tried ten times tonight. Using new reply and quick reply and making web pages of the answer to you. They all vanished from this forum.

BR:
Aapo
08-05-2008, 01:14 PM
aromu

I double checked that the start_tls = no was correctly set in files

:~/conf$ ls -al ldap*
-rw-r----- 1 zimbra zimbra 441 Aug 5 23:12 ldap-scm.cf
-rw-r----- 1 zimbra zimbra 369 Aug 5 23:12 ldap-transport.cf
-rw-r----- 1 zimbra zimbra 357 Aug 5 23:12 ldap-vad.cf
-rw-r----- 1 zimbra zimbra 500 Aug 5 23:12 ldap-vam.cf
-rw-r----- 1 zimbra zimbra 357 Aug 5 23:12 ldap-vmd.cf
-rw-r----- 1 zimbra zimbra 351 Aug 5 23:12 ldap-vmm.cf

it actually was not but fixing it and restart did not help. The mail.err still displays:

Aug 5 23:12:28 localhost postfix/cleanup[29941]: fatal: too many errors - program terminated
Aug 5 23:12:34 localhost postfix/trivial-rewrite[29991]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error
Aug 5 23:12:34 localhost postfix/trivial-rewrite[29991]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error
Aug 5 23:12:34 localhost postfix/cleanup[29943]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error
Aug 5 23:12:34 localhost last message repeated 12 times
08-06-2008, 02:47 AM
aromu

Hi,

Would you have any suggestion / thoughts about the postfix ldap configuration since it really seems that for some reason postfix is trying to contact wrong ldap server as indicated by the auth.log

Aug 5 21:58:31 localhost postfix/trivial-rewrite[22076]: nss_ldap: failed to bind to LDAP server ldaps://ldap.mycompany.com/: Can't contact LDAP server

The ldap configurations at /opt/zimbra/conf however point to ldap://mail.mymaildomain.net:389

BR:
Aapo
08-06-2008, 07:38 AM
aromu

Tried again the wiki article - still not working

Hi,

In the meanwhile waiting for your comments for my posts I corrected the problem of the antispam not running (commented ldap entry out from the /etc/nssswitch.conf shadow: row)

Now all the services are running as reported by zmcontrol status

Code:

antispam Running antivirus Running ldap Running logger Running mailbox Running mta Running snmp Running spell Running stats Running

I also tried the suggested wiki document again with procedure below. It did not help.

Code:

Workaround [5.0.1_GA or later] For Single-server and Multi-server ldap masters (a) Run as root: /opt/zimbra/bin/zmcertmgr createca -new (b) Run as root: /opt/zimbra/bin/zmcertmgr deployca (c) Run as root: /opt/zimbra/bin/zmcertmgr deploycrt self -new (d) Run as root: su - zimbra zmcontrol stop; su - zimbra zmcontrol start * Note, for zcs version 5.0.6 (c) should be Run as root: /opt/zimbra/bin/zmcertmgr deploycrt self

BR:
Aapo
08-06-2008, 12:38 PM
aromu

Hi,

I installed ZCS 5.0.6 because I thought it could make a difference. The symptoms are the same. I also tried instructions on the mentioned wiki page without any success. I also tried the instructions for 5.0.0 with the ldapmodify commands. No go.

However there is a lot more output from ldap in the zimbra log. Perhaps it helps you to figure out what is the actual problem.

I would really appreciate if anyone would help me on this one.

Code:

Aug 6 22:27:50 localhost postfix/pickup[13849]: 9B1541E880E5: uid=50033 from=<zimbra> Aug 6 22:27:51 localhost slapd[11477]: conn=63 fd=15 ACCEPT from IP=127.0.0.1:43108 (IP=127.0.0.1:389) Aug 6 22:27:51 localhost slapd[11477]: conn=63 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128 Aug 6 22:27:51 localhost slapd[11477]: conn=63 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0 Aug 6 22:27:51 localhost slapd[11477]: conn=63 op=0 RESULT tag=97 err=0 text= Aug 6 22:27:51 localhost slapd[11477]: conn=63 op=1 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)" Aug 6 22:27:51 localhost slapd[11477]: conn=63 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= Aug 6 22:27:52 localhost slapd[11477]: conn=64 fd=18 ACCEPT from IP=127.0.0.1:43110 (IP=127.0.0.1:389) Aug 6 22:27:52 localhost slapd[11477]: conn=64 op=0 STARTTLS Aug 6 22:27:52 localhost slapd[11477]: conn=64 op=0 RESULT oid= err=0 text= Aug 6 22:27:52 localhost postfix/trivial-rewrite[14164]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error Aug 6 22:27:52 localhost slapd[11477]: conn=64 fd=18 closed (TLS negotiation failure) Aug 6 22:27:52 localhost slapd[11477]: conn=65 fd=18 ACCEPT from IP=127.0.0.1:43111 (IP=127.0.0.1:389) Aug 6 22:27:52 localhost slapd[11477]: conn=65 op=0 STARTTLS Aug 6 22:27:52 localhost slapd[11477]: conn=65 op=0 RESULT oid= err=0 text= Aug 6 22:27:52 localhost slapd[11477]: conn=65 fd=18 closed (TLS negotiation failure) Aug 6 22:27:52 localhost slapd[11477]: conn=66 fd=18 ACCEPT from IP=127.0.0.1:43112 (IP=127.0.0.1:389) Aug 6 22:27:52 localhost slapd[11477]: conn=66 op=0 STARTTLS Aug 6 22:27:52 localhost slapd[11477]: conn=66 op=0 RESULT oid= err=0 text= Aug 6 22:27:52 localhost postfix/trivial-rewrite[14164]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error Aug 6 22:27:52 localhost postfix/cleanup[13873]: error: dict_ldap_connect: Unable to set STARTTLS: -11: Connect error
08-07-2008, 05:18 AM
aromu

Installed Debian 4 under VMWare and ZCS 5.0.8 works out of the box

Hi all,

Since I don't have the choice of operating system on the original host I requested for a new public ip, installed Debian 4 under the VMWare and ZCS 5.0.8 for Debian 4 worked right out of the box.

-Aapo