zmmailboxdmgr refuses to run after 6.0.6 to 6.0.7 upgrade

[subversionpdx]

I just did an upgrade of ZCS from 6.0.6 GA (not sure of the minor numbers) to zcs-6.0.7_GA_2470.UBUNTU8_64.20100610213019 this morning.

This is a single server install of the Zimbra Community Edition

1 I have checked DNS / MX and hostname records - including /etc/hosts,tested with dig, etc.
2 Reissued new self-signed certs
3 Deleted the pid files and restarted zimbra
4 Reran the entire update installation
5 Checked for other things binding to ports zimbra needs - there are none, no other mta is installed on this server, when i close zimbra, all listening ports close with it

I did notice this:
zimbraLmtpBindOnStartup: FALSE
zimbraLmtpBindPort: 7025

Should it be TRUE? I can't find anyone who seems to know. In zimbra.log I see a lot of port 7025 connection refused errors. I am not using Zimbra Proxy or Memcache, I made sure they were not installed or selected.


I have scoured these forums and the web looking for other possible solutions but cannot find any.

Since this upgrade zmmailboxdmgr fails to start - output of various logs etc below:

zimbra@mail:~$ zmprov -l gs `zmhostname` | grep zimbraServiceEnabled
zimbraServiceEnabled: antivirus
zimbraServiceEnabled: antispam
zimbraServiceEnabled: logger
zimbraServiceEnabled: mailbox
zimbraServiceEnabled: mta
zimbraServiceEnabled: stats
zimbraServiceEnabled: ldap
zimbraServiceEnabled: spell

zimbra@mail:~$ zmprov -l gs `zmhostname` | grep zimbraServiceInstalled
zimbraServiceInstalled: antivirus
zimbraServiceInstalled: antispam
zimbraServiceInstalled: logger
zimbraServiceInstalled: mailbox
zimbraServiceInstalled: mta
zimbraServiceInstalled: stats
zimbraServiceInstalled: snmp
zimbraServiceInstalled: ldap
zimbraServiceInstalled: spell

zimbra@mail:~$ zmprov -l gs mail.nerdnet.com | grep Bind
zimbraImapBindOnStartup: TRUE
zimbraImapBindPort: 143
zimbraImapProxyBindPort: 7143
zimbraImapSSLBindOnStartup: TRUE
zimbraImapSSLBindPort: 993
zimbraImapSSLProxyBindPort: 7993
zimbraLmtpBindOnStartup: FALSE
zimbraLmtpBindPort: 7025
zimbraMemcachedBindPort: 11211
zimbraNotifyBindPort: 7035
zimbraNotifySSLBindPort: 7036
zimbraPop3BindAddress: 209.20.91.50
zimbraPop3BindOnStartup: TRUE
zimbraPop3BindPort: 110
zimbraPop3ProxyBindPort: 7110
zimbraPop3SSLBindOnStartup: TRUE
zimbraPop3SSLBindPort: 995
zimbraPop3SSLProxyBindPort: 7995

zimbra@mail:~$ zmcontrol status
Host mail.nerdnet.com
antispam Running
antivirus Running
ldap Running
logger Running
mailbox Stopped
zmmailboxdctl is not running.
mta Running
spell Running
stats Running


zimbra.log:

Jun 15 11:13:18 mail zmmailboxdmgr[21043]: status requested
Jun 15 11:13:18 mail zmmailboxdmgr[21043]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Jun 15 11:13:18 mail zmmailboxdmgr[21043]: assuming no other instance is running
Jun 15 11:13:18 mail zmmailboxdmgr[21043]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Jun 15 11:13:18 mail zmmailboxdmgr[21043]: assuming no other instance is running
Jun 15 11:13:18 mail zmmailboxdmgr[21043]: no manager process is running
Jun 15 11:13:18 mail zmmailboxdmgr[21050]: start requested
Jun 15 11:13:18 mail zmmailboxdmgr[21050]: checking if another instance of manager is already running
Jun 15 11:13:18 mail zmmailboxdmgr[21050]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Jun 15 11:13:18 mail zmmailboxdmgr[21050]: assuming no other instance is running
Jun 15 11:13:18 mail zmmailboxdmgr[21050]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Jun 15 11:13:18 mail zmmailboxdmgr[21050]: assuming no other instance is running
Jun 15 11:13:18 mail zmmailboxdmgr[21051]: wrote manager pid 21051 to /opt/zimbra/log/zmmailboxd_manager.pid
Jun 15 11:13:18 mail zmmailboxdmgr[21051]: manager started mailboxd/JVM with pid 21052
Jun 15 11:13:18 mail zmmailboxdmgr[21052]: wrote java pid 21052 to /opt/zimbra/log/zmmailboxd_java.pid
Jun 15 11:13:28 mail zmmailboxdmgr[21051]: manager woke up from wait on mailboxd/JVM with pid 21052
Jun 15 11:13:28 mail zmmailboxdmgr[21051]: manager started mailboxd/JVM with pid 21211
Jun 15 11:13:28 mail zmmailboxdmgr[21211]: wrote java pid 21211 to /opt/zimbra/log/zmmailboxd_java.pid
Jun 15 11:13:37 mail zmmailboxdmgr[21051]: manager woke up from wait on mailboxd/JVM with pid 21211
Jun 15 11:13:37 mail zmmailboxdmgr[21051]: mailboxd/JVM exited twice in 9 seconds (tolerance=60)
un 15 11:14:33 mail postfix/lmtp[23220]: connect to mail.nerdnet.com[209.20.91.50]:7025: Connection refused
Jun 15 11:14:33 mail zimbramon[17509]: 17509:info: Starting stats via zmcontrol
Jun 15 11:14:33 mail postfix/lmtp[23221]: connect to mail.nerdnet.com[209.20.91.50]:7025: Connection refused

zimbra@mail:~/log$ cat zmmailboxd.out
Zimbra server reserving server socket port=110 bindaddr=209.20.91.50 ssl=false
Zimbra server reserving server socket port=995 bindaddr=null ssl=true
Zimbra server reserving server socket port=143 bindaddr=null ssl=false
Zimbra server reserving server socket port=993 bindaddr=null ssl=true
Zimbra server reserving server socket port=7025 bindaddr=null ssl=false
1903 INFO [main] log - Setting umask=027
1905 INFO [main] log - Current rlimit_nofiles (soft=524288, hard=524288)
1906 INFO [main] log - Set rlimit_nofiles (soft=65536, hard=65536)
1906 INFO [main] log - Setting GID=1001
1906 INFO [main] log - Setting UID=1001
1907 INFO [main] log - jetty-6.1.22.z6
2119 INFO [main] log - No Transaction manager found - if your webapp requires one, please configure one.
### Excluding compile: org.apache.xerces.impl.XMLDocumentFragmentScannerI mpl$FragmentContentDispatcher::dispatch
Zimbra server process is running as uid=1001 euid=1001 gid=1001 egid=1001
4.459: [GC 4.459: [ParNew: 84480K->8063K(94976K), 0.0537730 secs] 84480K->8063K(413440K), 0.0539200 secs] [Times: user=0.13 sys=0.01, real=0.06 secs]
(tons of lines like these below, have no idea what they mean)
Total time for which application threads were stopped: 0.0004370 seconds
Total time for which application threads were stopped: 0.0005660 seconds
Total time for which application threads were stopped: 0.0006000 seconds
Total time for which application threads were stopped: 0.0012100 seconds
Total time for which application threads were stopped: 0.0004160 seconds
Heap
par new generation total 94976K, used 35891K [0x00007f0f16d20000, 0x00007f0f1d420000, 0x00007f0f1d420000)
eden space 84480K, 30% used [0x00007f0f16d20000, 0x00007f0f185ecce0, 0x00007f0f1bfa0000)
from space 10496K, 99% used [0x00007f0f1bfa0000, 0x00007f0f1c9dfff8, 0x00007f0f1c9e0000)
to space 10496K, 0% used [0x00007f0f1c9e0000, 0x00007f0f1c9e0000, 0x00007f0f1d420000)
concurrent mark-sweep generation total 318464K, used 17282K [0x00007f0f1d420000, 0x00007f0f30b20000, 0x00007f0f30b20000)
concurrent-mark-sweep perm gen total 131072K, used 32967K [0x00007f0f30b20000, 0x00007f0f38b20000, 0x00007f0f38b20000)

Anyway, any help or insight would be very appreciated.. the server has been offline for hours now while I try to correct this.

Thank you..
Joe


Just found this in mailbox.log (I have nothing bound or attempting to bind to Port 143 (imap) so something is clearly wrong here. I will reboot the server also)


2010-06-15 11:13:37,108 FATAL [main] [] system - Exception during startup, aborting server, please check your config
com.zimbra.common.service.ServiceException: system failure: Could not bind to port=143 bindaddr=209.20.91.50 ssl=false useChannels=false
ExceptionId:main:1276625617107:16f029dfc9cf1d18
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE (ServiceException.java:248)
at com.zimbra.common.util.NetUtil.getServerSocket(Net Util.java:70)
at com.zimbra.common.util.NetUtil.getTcpServerSocket( NetUtil.java:38)
at com.zimbra.cs.server.ServerConfig.getServerSocket( ServerConfig.java:128)
at com.zimbra.cs.tcpserver.TcpServer.<init>(TcpServer .java:45)
at com.zimbra.cs.imap.ImapServer.<init>(ImapServer.ja va:51)
at com.zimbra.cs.imap.ImapServer.startServer(ImapServ er.java:85)
at com.zimbra.cs.imap.ImapServer.startupImapServer(Im apServer.java:61)
at com.zimbra.cs.util.Zimbra.startup(Zimbra.java:241)
at com.zimbra.cs.util.Zimbra.startup(Zimbra.java:123)
at com.zimbra.soap.SoapServlet.init(SoapServlet.java: 125)
at javax.servlet.GenericServlet.init(GenericServlet.j ava:241)
at org.mortbay.jetty.servlet.ServletHolder.initServle t(ServletHolder.java:440)
at org.mortbay.jetty.servlet.ServletHolder.doStart(Se rvletHolder.java:263)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:50)
at org.mortbay.jetty.servlet.ServletHandler.initializ e(ServletHandler.java:685)
at org.mortbay.jetty.servlet.Context.startContext(Con text.java:140)
at org.mortbay.jetty.webapp.WebAppContext.startContex t(WebAppContext.java:1250)
at org.mortbay.jetty.handler.ContextHandler.doStart(C ontextHandler.java:517)
at org.mortbay.jetty.webapp.WebAppContext.doStart(Web AppContext.java:467)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:50)
at org.mortbay.jetty.handler.HandlerCollection.doStar t(HandlerCollection.java:152)
at org.mortbay.jetty.handler.ContextHandlerCollection .doStart(ContextHandlerCollection.java:156)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:50)
at org.mortbay.jetty.handler.HandlerCollection.doStar t(HandlerCollection.java:152)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:50)
at org.mortbay.jetty.handler.HandlerWrapper.doStart(H andlerWrapper.java:130)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:50)
at org.mortbay.jetty.handler.HandlerWrapper.doStart(H andlerWrapper.java:130)
at org.mortbay.jetty.handler.DebugHandler.doStart(Deb ugHandler.java:127)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:50)
at org.mortbay.jetty.handler.HandlerWrapper.doStart(H andlerWrapper.java:130)
at org.mortbay.jetty.Server.doStart(Server.java:224)
at org.mortbay.setuid.SetUIDServer.doStart(SetUIDServ er.java:158)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:50)
at org.mortbay.xml.XmlConfiguration.main(XmlConfigura tion.java:985)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Nativ e Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Native MethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(De legatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.mortbay.start.Main.invokeMain(Main.java:194)
at org.mortbay.start.Main.start(Main.java:534)
at org.mortbay.start.Main.start(Main.java:441)
at org.mortbay.start.Main.main(Main.java:119)
Caused by: java.net.BindException: Permission denied
at java.net.PlainSocketImpl.socketBind(Native Method)
at java.net.PlainSocketImpl.bind(PlainSocketImpl.java :365)
at java.net.ServerSocket.bind(ServerSocket.java:319)
at com.zimbra.common.util.NetUtil.newBoundServerSocke t(NetUtil.java:104)
at com.zimbra.common.util.NetUtil.getServerSocket(Net Util.java:68)
... 42 more

[gnyce]

SSL cert issue perhaps? See first post in this thread, also referring to port 143 and inability to bind/start....

[SOLVED] 32 -&gt; 64 bit disaster

[subversionpdx]

Thanks for the response... I've tried recreating the SSL Certs / CA a few times and it still fails... I'm not sure what the problem is or how test this error further.

It's port 143, nothing else is running or binding to it.. How is it Zimbra is able to bind to a port below 1024 when zimbra is not running as root?

2010-06-15 13:45:01,515 FATAL [main] [] system - Exception during startup, aborting server, please check your config
com.zimbra.common.service.ServiceException: system failure: Could not bind to port=143 bindaddr=209.20.91.50 ssl=false useChannels=false
ExceptionId:main:1276634701514:7da0032e49230adc
Code:service.FAILURE

[FritzBrause]

... same here: we did a full desaster recovery to revert to 6.0.5.

Doing a plain vanilla installation and following the steps according to Network Edition Disaster Recovery - Zimbra :: Wiki brought back our working 6.0.5 installation including new SSL Certificates.

Trying to upgrade to 6.0.7 again fails with exactly the same error message as described above.

[ddebiase]

Same here as well. CentOS 5 x64 6.06 -> 6.07 Community

[mthostenson]

We also had this happen. Reverted back to 6.0.6 for now.

CentOS 5 x64 6.0.6 -> 6.0.7 Open Source Edition

I should point out that we are running all of the latest stock updates available from the standard repos.

Performed the same upgrade on a Ubuntu 8.04 LTS which worked great.

Any pointers?

[Himanshu]

Upgrade from 6.0.6 to 6.0.7 was ok. This was on CentOS 4 x86_64

[subversionpdx]

Nothing I have tried works, this is on Ubuntu 8.04 LTS 64 bit.. I did a clean install of 6.0.7 and I can get that to start up and run fine (just dont know how to migrate my users and their data into it) but upgrading the 6.0.6 to 6.0.7 fails on me every time with what I posted above...

Still messing with it, hours later..
joe

[btrudeau]

I've had the same problem, its all from mailbox dying because it cannot bind port 143 which is not in use and there is no issue with the cert. So that leads me to believe its either a permission issue or from the fact that java is running as zimbra which cannot open such a low port. Now how to fix this, need a bit of brainstorming as I'm sleepy and out of ideas myself...

[centrex]

ZCS NE 6.0.6.1 -> ZCS NE 6.0.7 on RHEL 5.5 64-bit.

Same issue. mailbox not starting and we are down. I will open a support case.