ZCS FOSS upgrade from NE trial and now zmmailboxdctl is not running...

[ArTT Vandelay]

immediately after the upgrade, the server was working fine, except for the license zimlet. removed that, and re-enabled ssl for imap (i had disabled it). after restarting for the ssl re-enable, the mailbox won't start, can't use webadmin or mailboxes, zmcontrol status says zmmailboxdctl and stats are not running...

I have log files tailed, which would you like?

[uxbod]

zimbra.log and mailbox.log straight after ZCS was started please.

[ArTT Vandelay]

mailbox.log
2008-07-28 23:03:52,827 INFO [main] [] soap - Servlet SoapServlet starting up
2008-07-28 23:03:52,854 INFO [main] [] soap - Adding service AccountService to SoapServlet
2008-07-28 23:03:53,218 INFO [main] [] soap - Adding service MailService to SoapServlet
2008-07-28 23:03:53,372 INFO [main] [] soap - Adding service IMService to SoapServlet
2008-07-28 23:03:53,381 INFO [main] [] misc - version=5.0.8_GA_2462.MACOSXx86_10.5 release=20080709161017 builddate=20080709-1611 buildhost=build09.re.zimbra.com
2008-07-28 23:03:53,383 INFO [main] [] misc - LANG environment is set to: en_US.UTF-8
2008-07-28 23:03:53,384 INFO [main] [] misc - System property java.home=/System/Library/Frameworks/JavaVM.framework/Versions/1.5.0/Home
2008-07-28 23:03:53,384 INFO [main] [] misc - System property java.runtime.version=1.5.0_13-b05-237
2008-07-28 23:03:53,384 INFO [main] [] misc - System property java.version=1.5.0_13
2008-07-28 23:03:53,384 INFO [main] [] misc - System property java.vm.info=mixed mode
2008-07-28 23:03:53,384 INFO [main] [] misc - System property java.vm.name=Java HotSpot(TM) Client VM
2008-07-28 23:03:53,384 INFO [main] [] misc - System property java.vm.version=1.5.0_13-119
2008-07-28 23:03:53,384 INFO [main] [] misc - System property os.arch=i386
2008-07-28 23:03:53,384 INFO [main] [] misc - System property os.name=Mac OS X
2008-07-28 23:03:53,384 INFO [main] [] misc - System property os.version=10.5.4
2008-07-28 23:03:53,384 INFO [main] [] misc - System property sun.arch.data.model=32
2008-07-28 23:03:53,384 INFO [main] [] misc - System property sun.cpu.endian=little
2008-07-28 23:03:53,384 INFO [main] [] misc - System property sun.cpu.isalist=
2008-07-28 23:03:53,384 INFO [main] [] misc - System property sun.os.patch.level=unknown
2008-07-28 23:03:53,418 INFO [main] [] system - Setting mysql connector property: maxActive=100
2008-07-28 23:03:53,419 INFO [main] [] system - Setting mysql connector property: maxActive=100
2008-07-28 23:03:53,879 FATAL [main] [] system - Config initialization failed
com.zimbra.common.service.ServiceException: system failure: getting all config entries
ExceptionId:main:1217311433877:eac4898a4405bd83
Code:service.FAILURE
at com.zimbra.common.service.ServiceException.FAILURE (ServiceException.java:253)
at com.zimbra.cs.db.DbConfig.getAll(DbConfig.java:166 )
at com.zimbra.cs.util.Config.init(Config.java:66)
at com.zimbra.cs.util.Config.initConfig(Config.java:9 1)
at com.zimbra.cs.util.Config.getString(Config.java:10 3)
at com.zimbra.cs.db.Versions.checkDBVersion(Versions. java:77)
at com.zimbra.cs.db.Versions.checkVersions(Versions.j ava:73)
at com.zimbra.cs.util.Zimbra.startup(Zimbra.java:156)
at com.zimbra.cs.util.Zimbra.startup(Zimbra.java:129)
at com.zimbra.soap.SoapServlet.init(SoapServlet.java: 114)
at javax.servlet.GenericServlet.init(GenericServlet.j ava:241)
at org.mortbay.jetty.servlet.ServletHolder.initServle t(ServletHolder.java:433)
at org.mortbay.jetty.servlet.ServletHolder.doStart(Se rvletHolder.java:256)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:40)
at org.mortbay.jetty.servlet.ServletHandler.initializ e(ServletHandler.java:612)
at org.mortbay.jetty.servlet.Context.startContext(Con text.java:139)
at org.mortbay.jetty.webapp.WebAppContext.startContex t(WebAppContext.java:1222)
at org.mortbay.jetty.handler.ContextHandler.doStart(C ontextHandler.java:501)
at org.mortbay.jetty.webapp.WebAppContext.doStart(Web AppContext.java:449)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:40)
at org.mortbay.jetty.handler.HandlerCollection.doStar t(HandlerCollection.java:147)
at org.mortbay.jetty.handler.ContextHandlerCollection .doStart(ContextHandlerCollection.java:161)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:40)
at org.mortbay.jetty.handler.HandlerCollection.doStar t(HandlerCollection.java:147)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:40)
at org.mortbay.jetty.handler.HandlerWrapper.doStart(H andlerWrapper.java:117)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:40)
at org.mortbay.jetty.handler.HandlerWrapper.doStart(H andlerWrapper.java:117)
at org.mortbay.jetty.Server.doStart(Server.java:217)
at org.mortbay.setuid.SetUIDServer.doStart(SetUIDServ er.java:100)
at org.mortbay.component.AbstractLifeCycle.start(Abst ractLifeCycle.java:40)
at org.mortbay.xml.XmlConfiguration.main(XmlConfigura tion.java:979)
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:585)
at org.mortbay.start.Main.invokeMain(Main.java:183)
at org.mortbay.start.Main.start(Main.java:497)
at org.mortbay.start.Main.main(Main.java:115)
Caused by: java.sql.SQLException: Incorrect information in file: './zimbra/config.frm'

Query being executed when exception was thrown:

SELECT * FROM config
at com.mysql.jdbc.SQLError.createSQLException(SQLErro r.java:946)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.ja va:2870)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:15 73)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java :1665)
at com.mysql.jdbc.Connection.execSQL(Connection.java: 3124)
at com.mysql.jdbc.PreparedStatement.executeInternal(P reparedStatement.java:1149)
at com.mysql.jdbc.PreparedStatement.executeQuery(Prep aredStatement.java:1262)
at org.apache.commons.dbcp.DelegatingPreparedStatemen t.executeQuery(DelegatingPreparedStatement.java:20 5)
at com.zimbra.cs.db.DbConfig.getAll(DbConfig.java:160 )
... 37 more

zimbra.log
Jul 28 23:03:02 zmail slapd[7857]: conn=145 fd=10 ACCEPT from IP=192.168.1.55:50059 (IP=192.168.1.55:389)
Jul 28 23:03:02 zmail slapd[7857]: conn=145 op=0 STARTTLS
Jul 28 23:03:02 zmail slapd[7857]: conn=145 op=0 RESULT oid= err=0 text=
Jul 28 23:03:03 zmail slapd[7857]: conn=145 fd=10 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:03 zmail slapd[7857]: conn=145 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:03 zmail slapd[7857]: conn=145 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:03 zmail slapd[7857]: conn=145 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:03 zmail slapd[7857]: conn=145 op=2 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)"
Jul 28 23:03:03 zmail slapd[7857]: conn=145 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:03 zmail slapd[7857]: conn=146 fd=16 ACCEPT from IP=192.168.1.55:50062 (IP=192.168.1.55:389)
Jul 28 23:03:03 zmail slapd[7857]: conn=146 op=0 STARTTLS
Jul 28 23:03:03 zmail slapd[7857]: conn=146 op=0 RESULT oid= err=0 text=
Jul 28 23:03:03 zmail slapd[7857]: conn=145 fd=10 closed (connection lost)
Jul 28 23:03:03 zmail slapd[7857]: conn=146 fd=16 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:03 zmail slapd[7857]: conn=146 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:03 zmail slapd[7857]: conn=146 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:03 zmail slapd[7857]: conn=146 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:03 zmail slapd[7857]: conn=146 op=2 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)"
Jul 28 23:03:03 zmail slapd[7857]: conn=146 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:04 zmail slapd[7857]: conn=146 fd=16 closed (connection lost)
Jul 28 23:03:04 zmail slapd[7857]: conn=147 fd=10 ACCEPT from IP=192.168.1.55:50065 (IP=192.168.1.55:389)
Jul 28 23:03:04 zmail slapd[7857]: conn=147 op=0 STARTTLS
Jul 28 23:03:04 zmail slapd[7857]: conn=147 op=0 RESULT oid= err=0 text=
Jul 28 23:03:05 zmail slapd[7857]: conn=147 fd=10 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:05 zmail slapd[7857]: conn=147 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:05 zmail slapd[7857]: conn=147 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:05 zmail slapd[7857]: conn=147 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:05 zmail slapd[7857]: conn=147 op=2 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(objectClass=zimbraServer)"
Jul 28 23:03:05 zmail slapd[7857]: conn=147 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:05 zmail slapd[7857]: conn=148 fd=16 ACCEPT from IP=192.168.1.55:50066 (IP=192.168.1.55:389)
Jul 28 23:03:05 zmail slapd[7857]: conn=148 op=0 STARTTLS
Jul 28 23:03:05 zmail slapd[7857]: conn=148 op=0 RESULT oid= err=0 text=
Jul 28 23:03:05 zmail slapd[7857]: conn=148 fd=16 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:05 zmail slapd[7857]: conn=148 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:05 zmail slapd[7857]: conn=148 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:05 zmail slapd[7857]: conn=148 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:05 zmail slapd[7857]: conn=148 op=2 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)"
Jul 28 23:03:05 zmail slapd[7857]: conn=148 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:05 zmail slapd[7857]: conn=149 fd=21 ACCEPT from IP=192.168.1.55:50069 (IP=192.168.1.55:389)
Jul 28 23:03:05 zmail slapd[7857]: conn=149 op=0 STARTTLS
Jul 28 23:03:05 zmail slapd[7857]: conn=149 op=0 RESULT oid= err=0 text=
Jul 28 23:03:05 zmail slapd[7857]: conn=148 fd=16 closed (connection lost)
Jul 28 23:03:05 zmail slapd[7857]: conn=147 fd=10 closed (connection lost)
Jul 28 23:03:06 zmail slapd[7857]: conn=149 fd=21 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:06 zmail slapd[7857]: conn=149 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:06 zmail slapd[7857]: conn=149 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:06 zmail slapd[7857]: conn=149 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:06 zmail slapd[7857]: conn=149 op=2 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(objectClass=zimbraServer)"
Jul 28 23:03:06 zmail slapd[7857]: conn=149 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:06 zmail slapd[7857]: conn=150 fd=10 ACCEPT from IP=192.168.1.55:50070 (IP=192.168.1.55:389)
Jul 28 23:03:06 zmail slapd[7857]: conn=150 op=0 STARTTLS
Jul 28 23:03:06 zmail slapd[7857]: conn=150 op=0 RESULT oid= err=0 text=
Jul 28 23:03:06 zmail slapd[7857]: conn=150 fd=10 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:06 zmail slapd[7857]: conn=150 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:06 zmail slapd[7857]: conn=150 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:06 zmail slapd[7857]: conn=150 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:06 zmail slapd[7857]: conn=150 op=2 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)"
Jul 28 23:03:06 zmail slapd[7857]: conn=150 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:06 zmail slapd[7857]: conn=150 fd=10 closed (connection lost)
Jul 28 23:03:06 zmail slapd[7857]: conn=149 fd=21 closed (connection lost)
Jul 28 23:03:07 zmail slapd[7857]: conn=151 fd=10 ACCEPT from IP=192.168.1.55:50073 (IP=192.168.1.55:389)
Jul 28 23:03:07 zmail slapd[7857]: conn=151 op=0 STARTTLS
Jul 28 23:03:07 zmail slapd[7857]: conn=151 op=0 RESULT oid= err=0 text=
Jul 28 23:03:07 zmail slapd[7857]: conn=151 fd=10 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:07 zmail slapd[7857]: conn=151 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:07 zmail slapd[7857]: conn=151 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:07 zmail slapd[7857]: conn=151 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:07 zmail slapd[7857]: conn=151 op=2 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(objectClass=zimbraServer)"
Jul 28 23:03:07 zmail slapd[7857]: conn=151 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:07 zmail slapd[7857]: conn=152 fd=16 ACCEPT from IP=192.168.1.55:50074 (IP=192.168.1.55:389)
Jul 28 23:03:07 zmail slapd[7857]: conn=152 op=0 STARTTLS
Jul 28 23:03:07 zmail slapd[7857]: conn=152 op=0 RESULT oid= err=0 text=
Jul 28 23:03:07 zmail slapd[7857]: conn=152 fd=16 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:07 zmail slapd[7857]: conn=152 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:07 zmail slapd[7857]: conn=152 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:07 zmail slapd[7857]: conn=152 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:07 zmail slapd[7857]: conn=152 op=2 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)"
Jul 28 23:03:07 zmail slapd[7857]: conn=152 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:07 zmail slapd[7857]: conn=153 fd=21 ACCEPT from IP=192.168.1.55:50077 (IP=192.168.1.55:389)
Jul 28 23:03:07 zmail slapd[7857]: conn=153 op=0 STARTTLS
Jul 28 23:03:07 zmail slapd[7857]: conn=153 op=0 RESULT oid= err=0 text=
Jul 28 23:03:07 zmail slapd[7857]: conn=152 fd=16 closed (connection lost)
Jul 28 23:03:07 zmail slapd[7857]: conn=151 fd=10 closed (connection lost)
Jul 28 23:03:08 zmail slapd[7857]: conn=153 fd=21 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:08 zmail slapd[7857]: conn=153 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:08 zmail slapd[7857]: conn=153 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:08 zmail slapd[7857]: conn=153 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:08 zmail slapd[7857]: conn=153 op=2 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(objectClass=zimbraServer)"
Jul 28 23:03:08 zmail slapd[7857]: conn=153 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:08 zmail slapd[7857]: conn=154 fd=10 ACCEPT from IP=192.168.1.55:50078 (IP=192.168.1.55:389)
Jul 28 23:03:08 zmail slapd[7857]: conn=154 op=0 STARTTLS
Jul 28 23:03:08 zmail slapd[7857]: conn=154 op=0 RESULT oid= err=0 text=
Jul 28 23:03:08 zmail slapd[7857]: conn=154 fd=10 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:08 zmail slapd[7857]: conn=154 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:08 zmail slapd[7857]: conn=154 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:08 zmail slapd[7857]: conn=154 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:08 zmail slapd[7857]: conn=154 op=2 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)"
Jul 28 23:03:08 zmail slapd[7857]: conn=154 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
Jul 28 23:03:08 zmail slapd[7857]: conn=154 fd=10 closed (connection lost)
Jul 28 23:03:08 zmail slapd[7857]: conn=153 fd=21 closed (connection lost)
Jul 28 23:03:09 zmail slapd[7857]: conn=155 fd=10 ACCEPT from IP=192.168.1.55:50081 (IP=192.168.1.55:389)
Jul 28 23:03:09 zmail slapd[7857]: conn=155 op=0 STARTTLS
Jul 28 23:03:09 zmail slapd[7857]: conn=155 op=0 RESULT oid= err=0 text=
Jul 28 23:03:09 zmail slapd[7857]: conn=155 fd=10 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:09 zmail slapd[7857]: conn=155 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:09 zmail slapd[7857]: conn=155 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:09 zmail slapd[7857]: conn=155 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:09 zmail slapd[7857]: conn=155 op=2 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(&(objectClass=zimbraServer)(zimbraServiceEnabled=im approxy))"
Jul 28 23:03:09 zmail slapd[7857]: conn=155 op=2 SEARCH RESULT tag=101 err=0 nentries=0 text=
Jul 28 23:03:09 zmail slapd[7857]: conn=155 fd=10 closed (connection lost)
Jul 28 23:03:09 zmail slapd[7857]: conn=156 fd=10 ACCEPT from IP=192.168.1.55:50084 (IP=192.168.1.55:389)
Jul 28 23:03:09 zmail slapd[7857]: conn=156 op=0 STARTTLS
Jul 28 23:03:09 zmail slapd[7857]: conn=156 op=0 RESULT oid= err=0 text=
Jul 28 23:03:10 zmail slapd[7857]: conn=156 fd=10 TLS established tls_ssf=128 ssf=128
Jul 28 23:03:10 zmail slapd[7857]: conn=156 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128
Jul 28 23:03:10 zmail slapd[7857]: conn=156 op=1 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0
Jul 28 23:03:10 zmail slapd[7857]: conn=156 op=1 RESULT tag=97 err=0 text=
Jul 28 23:03:10 zmail slapd[7857]: conn=156 op=2 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(&(objectClass=zimbraServer)(zimbraServiceEnabled=im approxy))"
Jul 28 23:03:10 zmail slapd[7857]: conn=156 op=2 SEARCH RESULT tag=101 err=0 nentries=0 text=
Jul 28 23:03:10 zmail slapd[7857]: conn=156 fd=10 closed (connection lost)

[ArTT Vandelay]

Incidentally, followed this thread [SOLVED] Upgrade from 5.06 to 5.07 - zmmailboxdctl is not running to change the java mem allocation. Stats is now running, but mailboxdctl is still stopped...

[ArTT Vandelay]

more info...

reran zmsetup.pl and things worked. however, it went back to the no ssl for imap setting i had applied yesterday (which is not the default). Also, as soon as i requested the briefcase tab, mailbox and snmp crashed. they come back with a zmcontrol stop/start, but this is odd.

just ordered more RAM.

dammit dammit