[SOLVED] mailboxmanager does not start

[jrefl5]

Rebooted the Zimbra server, and now I can't get mailboxmanager to run.

 zmcontrol start; zmcontrol status
Host email.My.com
        Starting ldap...Done.
        Starting logger...Done.
        Starting mailbox...Done.
        Starting antispam...Done.
        Starting antivirus...Done.
        Starting snmp...Done.
        Starting spell...Done.
        Starting mta...Done.
        Starting stats...Done.
Host email.sb.state.az.us
        antispam                Running
        antivirus               Running
        ldap                    Running
        logger                  Running
        mailbox                 Stopped
                zmmailboxdctl is not running
        mta                     Running
        snmp                    Running
        spell                   Running
        stats                   Running
[zimbra@email ~]$ zmcontrol -v


Release 5.0.9_GA_2533.RHEL5_20080815101705 CentOS5 NETWORK edition

and the edited zimbra.log to follow

[jrefl5]

Mar 17 07:04:03 email zimbramon[5413]: 5413:info: Starting services initiated by zmcontrol 
Mar 17 07:04:03 email slapd[5510]: @(#) $OpenLDAP: slapd 2.3.42 (Jul  8 2008 15:31:41) $ 	build@build10.re.zimbra.com:/home/build/p4/main/ThirdParty/openldap/openldap-2.3.42.8z/servers/slapd 
Mar 17 07:04:03 email slapd[5511]: slapd starting 
Mar 17 07:04:09 email zimbramon[5413]: 5413:info: Rewriting configs  antispam amavis antivirus amavis   webxml mailbox amavis antispam antivirus mta sasl    
Mar 17 07:04:15 email zimbramon[5413]: 5413:info: Starting logger via zmcontrol 
Mar 17 07:04:15 email zimbramon[5413]: 5413:info: Starting mailbox via zmcontrol 
Mar 17 07:04:22 email zimbramon[6453]: 6453:info: zmmtaconfig: zmmtaconfig started on email.email.My.com with loglevel=3 pid=6453 
Mar 17 07:04:37 email zmmailboxdmgr[7645]: status requested
Mar 17 07:04:37 email zmmailboxdmgr[7645]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Mar 17 07:04:37 email zmmailboxdmgr[7645]: assuming no other instance is running
Mar 17 07:04:37 email zmmailboxdmgr[7645]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:04:37 email zmmailboxdmgr[7645]: assuming no other instance is running
Mar 17 07:04:37 email zmmailboxdmgr[7645]: no manager process is running
Mar 17 07:04:37 email zmmailboxdmgr[7652]: start requested
Mar 17 07:04:37 email zmmailboxdmgr[7652]: checking if another instance of manager is already running
Mar 17 07:04:37 email zmmailboxdmgr[7652]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Mar 17 07:04:37 email zmmailboxdmgr[7652]: assuming no other instance is running
Mar 17 07:04:37 email zmmailboxdmgr[7652]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:04:37 email zmmailboxdmgr[7652]: assuming no other instance is running
Mar 17 07:04:37 email zmmailboxdmgr[7655]: wrote manager pid 7655 to /opt/zimbra/log/zmmailboxd_manager.pid
Mar 17 07:04:37 email zmmailboxdmgr[7656]: wrote java pid 7656 to /opt/zimbra/log/zmmailboxd_java.pid
Mar 17 07:04:37 email zmmailboxdmgr[7655]: manager started mailboxd/JVM with pid 7656
Mar 17 07:04:37 email zimbramon[5413]: 5413:info: Starting antispam via zmcontrol 
Mar 17 07:04:37 email zmmailboxdmgr[7655]: manager woke up from wait on mailboxd/JVM with pid 7656
Mar 17 07:04:37 email zmmailboxdmgr[7659]: wrote java pid 7659 to /opt/zimbra/log/zmmailboxd_java.pid
Mar 17 07:04:37 email zmmailboxdmgr[7655]: manager started mailboxd/JVM with pid 7659
Mar 17 07:04:37 email zmmailboxdmgr[7655]: manager woke up from wait on mailboxd/JVM with pid 7659
Mar 17 07:04:37 email zmmailboxdmgr[7655]: mailboxd/JVM exited twice in 0 seconds (tolerance=60)
Mar 17 07:04:37 email zimbramon[7688]: 7688:info: zmmtaconfig: zmmtaconfig already running at 6453 
Mar 17 07:04:37 email amavis[7743]: starting.  /opt/zimbra/amavisd/sbin/amavisd at email.email.My.com amavisd-new-2.5.4 (20080312), Unicode aware, LANG="en_US.UTF-8"
Mar 17 07:04:37 email amavis[7743]: user=501, EUID: 501 (501);  group=, EGID: 501 502 501 5 4 (501 502 501 5 4)
Mar 17 07:04:37 email amavis[7743]: Perl version               5.008008
Mar 17 07:04:38 email amavis[7743]: SpamControl: init_pre_chroot done
Mar 17 07:04:38 email amavis[7745]: Net::Server: Process Backgrounded
Mar 17 07:04:38 email amavis[7745]: Net::Server: 2009/03/17-07:04:38 Amavis (type Net::Server::PreForkSimple) starting! pid(7745)
Mar 17 07:04:38 email amavis[7745]: Net::Server: Binding to UNIX socket file /opt/zimbra/data/amavisd/amavisd.sock using SOCK_STREAM
Mar 17 07:04:38 email amavis[7745]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1
Mar 17 07:04:38 email amavis[7745]: Net::Server: Group Not Defined.  Defaulting to EGID '501 502 501 5 4'
Mar 17 07:04:38 email amavis[7745]: Net::Server: User Not Defined.  Defaulting to EUID '501'
Mar 17 07:04:38 email amavis[7745]: Module Amavis::Conf        2.094
.
.
.
.
.
Mar 17 07:04:38 email amavis[7745]: Using primary internal av scanner code for ClamAV-clamd
Mar 17 07:04:38 email amavis[7745]: SpamControl: initializing Mail::SpamAssassin
Mar 17 07:04:38 email amavis[7745]: SpamControl: init_pre_fork done
Mar 17 07:04:42 email zimbramon[5413]: 5413:info: Starting antivirus via zmcontrol 
Mar 17 07:04:42 email zimbramon[7787]: 7787:info: zmmtaconfig: zmmtaconfig already running at 6453 
Mar 17 07:04:42 email clamd[7852]: clamd daemon 0.93.3 (OS: linux-gnu, ARCH: i386, CPU: i686) 
Mar 17 07:04:42 email clamd[7852]: Log file size limited to 20971520 bytes. 
Mar 17 07:04:42 email clamd[7852]: Reading databases from /opt/zimbra/data/clamav/db 
Mar 17 07:04:42 email clamd[7852]: Not loading PUA signatures. 
Mar 17 07:04:44 email clamd[7852]: Loaded 520683 signatures. 
Mar 17 07:04:44 email clamd[7852]: TCP: Bound to port 3310 
Mar 17 07:04:44 email clamd[7852]: TCP: Setting connection queue length to 15 
Mar 17 07:04:44 email clamd[7855]: Limits: Global size limit set to 104857600 bytes. 
Mar 17 07:04:44 email clamd[7855]: Limits: File size limit set to 104857600 bytes. 
Mar 17 07:04:44 email clamd[7855]: Limits: Recursion level limit set to 16. 
Mar 17 07:04:44 email clamd[7855]: Limits: Files limit set to 10000. 
Mar 17 07:04:44 email clamd[7855]: Archive support enabled. 
Mar 17 07:04:44 email clamd[7855]: Archive: Blocking encrypted archives. 
Mar 17 07:04:44 email clamd[7855]: Algorithmic detection enabled. 
Mar 17 07:04:44 email clamd[7855]: Portable Executable support enabled. 
Mar 17 07:04:44 email clamd[7855]: ELF support enabled. 
Mar 17 07:04:44 email clamd[7855]: Mail files support enabled. 
Mar 17 07:04:44 email clamd[7855]: OLE2 support enabled. 
Mar 17 07:04:44 email clamd[7855]: PDF support disabled. 
Mar 17 07:04:44 email clamd[7855]: HTML support enabled. 
Mar 17 07:04:44 email clamd[7855]: Self checking every 1800 seconds. 
Mar 17 07:04:47 email zimbramon[5413]: 5413:info: Starting snmp via zmcontrol 
Mar 17 07:04:47 email zimbramon[5413]: 5413:info: Starting spell via zmcontrol 
Mar 17 07:04:48 email zimbramon[5413]: 5413:info: Starting mta via zmcontrol 
Mar 17 07:04:48 email zimbramon[7917]: 7917:info: zmmtaconfig: zmmtaconfig already running at 6453 
Mar 17 07:04:56 email postfix/postfix-script[8412]: warning: not owned by root: /opt/zimbra/postfix-2.4.7.5z/conf/main.cf
Mar 17 07:04:56 email postfix/postfix-script[8419]: warning: not owned by group postdrop: /opt/zimbra/postfix-2.4.3.4z/sbin/postqueue
Mar 17 07:04:56 email postfix/postfix-script[8420]: warning: not owned by group postdrop: /opt/zimbra/postfix-2.4.3.4z/sbin/postdrop
Mar 17 07:04:56 email postfix/postfix-script[8422]: warning: not set-gid or not owner+group+world executable: /opt/zimbra/postfix-2.4.3.4z/sbin/postqueue
Mar 17 07:04:56 email postfix/postfix-script[8423]: warning: not set-gid or not owner+group+world executable: /opt/zimbra/postfix-2.4.3.4z/sbin/postdrop
Mar 17 07:04:56 email postfix/postfix-script[8430]: starting the Postfix mail system
Mar 17 07:04:56 email postfix/master[8431]: daemon started -- version 2.4.3, configuration /opt/zimbra/postfix-2.4.7.5z/conf
Mar 17 07:04:56 email postfix/qmgr[8435]: 0F79B36B1571: from=<terryp@paquetteelectric.com>, size=1981, nrcpt=1 (queue active)
Mar 17 07:04:56 email postfix/qmgr[8435]: 6B39236B1575: from=<gschellhorn@email.My.com>, size=5080, nrcpt=1 (queue active)
.
.
.
Mar 17 07:04:56 email saslauthd[8450]: detach_tty      : master pid is: 8450
Mar 17 07:04:56 email saslauthd[8450]: ipc_init        : listening on socket: /opt/zimbra/cyrus-sasl-2.1.22.3z/state/mux
Mar 17 07:04:56 email zimbramon[5413]: 5413:info: Starting stats via zmcontrol 
.
.
.Mar 17 07:04:59 email zmmailboxdmgr[9166]: status requested
Mar 17 07:04:59 email zmmailboxdmgr[9166]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:04:59 email zmmailboxdmgr[9166]: assuming no other instance is running
Mar 17 07:04:59 email zmmailboxdmgr[9166]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:04:59 email zmmailboxdmgr[9166]: assuming no other instance is running
Mar 17 07:04:59 email zmmailboxdmgr[9166]: no manager process is running
Mar 17 07:05:33 email zmmailboxdmgr[9869]: status requested
Mar 17 07:05:33 email zmmailboxdmgr[9869]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:05:33 email zmmailboxdmgr[9869]: assuming no other instance is running
Mar 17 07:05:33 email zmmailboxdmgr[9869]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:05:33 email zmmailboxdmgr[9869]: assuming no other instance is running
Mar 17 07:05:33 email zmmailboxdmgr[9869]: no manager process is running
Mar 17 07:05:34 email zmmailboxdmgr[9943]: status requested
Mar 17 07:05:34 email zmmailboxdmgr[9943]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:05:34 email zmmailboxdmgr[9943]: assuming no other instance is running
Mar 17 07:05:34 email zmmailboxdmgr[9943]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:05:34 email zmmailboxdmgr[9943]: assuming no other instance is running
Mar 17 07:05:34 email zmmailboxdmgr[9943]: no manager process is running
.
.
.
Mar 17 07:06:02 email zmmailboxdmgr[10273]: status requested
Mar 17 07:06:02 email zmmailboxdmgr[10273]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:06:02 email zmmailboxdmgr[10273]: assuming no other instance is running
Mar 17 07:06:02 email zmmailboxdmgr[10273]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:06:02 email zmmailboxdmgr[10273]: assuming no other instance is running
Mar 17 07:06:02 email zmmailboxdmgr[10273]: no manager process is running
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: antispam: Running 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: antivirus: Running 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: ldap: Running 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: logger: Running 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: mailbox: Stopped 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: mta: Running 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: snmp: Running 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: spell: Running 
Mar 17 07:06:03 email zimbramon[10028]: 10028:info: 2009-03-17 07:06:01, STATUS: email.email.My.com: stats: Running 
.
.
.
.
Mar 17 07:06:40 email zmmailboxdmgr[10803]: status requested
Mar 17 07:06:40 email zmmailboxdmgr[10803]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:06:40 email zmmailboxdmgr[10803]: assuming no other instance is running
Mar 17 07:06:40 email zmmailboxdmgr[10803]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:06:40 email zmmailboxdmgr[10803]: assuming no other instance is running
Mar 17 07:06:40 email zmmailboxdmgr[10803]: no manager process is running
Mar 17 07:06:41 email zmmailboxdmgr[10877]: status requested
Mar 17 07:06:41 email zmmailboxdmgr[10877]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:06:41 email zmmailboxdmgr[10877]: assuming no other instance is running
Mar 17 07:06:41 email zmmailboxdmgr[10877]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:06:41 email zmmailboxdmgr[10877]: assuming no other instance is running
Mar 17 07:06:41 email zmmailboxdmgr[10877]: no manager process is running
.
.
.
Mar 17 07:07:47 email zmmailboxdmgr[11333]: status requested
Mar 17 07:07:47 email zmmailboxdmgr[11333]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:07:47 email zmmailboxdmgr[11333]: assuming no other instance is running
Mar 17 07:07:47 email zmmailboxdmgr[11333]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:07:47 email zmmailboxdmgr[11333]: assuming no other instance is running
Mar 17 07:07:47 email zmmailboxdmgr[11333]: no manager process is running
Mar 17 07:07:47 email zmmailboxdmgr[11407]: status requested
Mar 17 07:07:47 email zmmailboxdmgr[11407]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:07:47 email zmmailboxdmgr[11407]: assuming no other instance is running
Mar 17 07:07:47 email zmmailboxdmgr[11407]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:07:47 email zmmailboxdmgr[11407]: assuming no other instance is running
Mar 17 07:07:47 email zmmailboxdmgr[11407]: no manager process is running
Mar 17 07:08:03 email zmmailboxdmgr[11727]: status requested
Mar 17 07:08:03 email zmmailboxdmgr[11727]: stale pid 7655 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Mar 17 07:08:03 email zmmailboxdmgr[11727]: assuming no other instance is running
Mar 17 07:08:03 email zmmailboxdmgr[11727]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Mar 17 07:08:03 email zmmailboxdmgr[11727]: assuming no other instance is running
Mar 17 07:08:03 email zmmailboxdmgr[11727]: no manager process is running
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: antispam: Running 
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: antivirus: Running 
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: ldap: Running 
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: logger: Running 
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: mailbox: Stopped <<<<<<<<<<
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: mta: Running 
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: snmp: Running 
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: spell: Running 
Mar 17 07:08:03 email zimbramon[11479]: 11479:info: 2009-03-17 07:08:01, STATUS: email.email.My.com: stats: Running

[uxbod]

Would you check /opt/zimbra/log/mailboxd.log aswell please for any error messages ?

[jrefl5]

It has not been updated since 6:30am local time, ie no entries surring the restarts.

tail mailbox.log
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension license: com.zimbra.cs.network.license.LicenseExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@9abce9
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension zimbrasync: com.zimbra.zimbrasync.ZimbraSync@com.zimbra.cs.extension.ZimbraExtensionClassLoader@1b11b79
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension : com.zimbra.cs.network.NetworkInitializer@com.zimbra.cs.extension.ZimbraExtensionClassLoader@9c176c
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension zimbra_xmbxsearch: com.zimbra.xmbxsearch.ZimbraXMbxSearchExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@c2cf83
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension com_zimbra_cert_manager: com.zimbra.cert.ZimbraCertMgrExt@com.zimbra.cs.extension.ZimbraExtensionClassLoader@159054d
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension hsm: com.zimbra.cs.hsm.HsmInitializer@com.zimbra.cs.extension.ZimbraExtensionClassLoader@79801c
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension clamscanner: com.zimbra.clam.ClamScanner@com.zimbra.cs.extension.ZimbraExtensionClassLoader@8c7be5
2009-03-17 06:30:56,976 INFO  [Shutdown] [] extensions - Destroyed extension ZimbraIMInterop: com.zimbra.iminterop.ZimbraInteropExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@309f9f
2009-03-17 06:30:56,976 INFO  [Shutdown] [] soap - Servlet SoapServlet shutting down
2009-03-17 06:30:57,078 INFO  [Shutdown] [] log - Shutdown hook complete

[uxbod]

Okay, shutdown ZCS and then ps aux | grep zimbra to see if there are any old processes running. If so kill them off (nicely) and then try restarting ZCS. Has anything changed on your server or infrastructure with respect to DNS ?

[jrefl5]

zimbra restart was first step.

zmcontrol stop ; ps -ef | grep zimbra

is my standard shutdown process.

It also appears that httpd is not starting as I can't access the Admin GUI.

[jrefl5]

Any ideas?
My users can't access their mail!!

Do I need to open a support ticket on this??

[uxbod]

cat /etc/hosts
cat /etc/resolv.conf
dig yourdomain mx
dig yourdomain any
host `hostname` <- note single ticks and not quotes

Just to check that your DNS is all okay.

[jrefl5]

It looks like a bug.

The only difference is that I was running on an SMP kernel (only 4GM of mem showing in free).

I switched to the PAE version of the same kernel in order to make the full system memory available (24GB).

I just booted back to the SMP version and every thing is back up.

I'll open a bug report on 5.0.9 and PAE for 24GB systems unless someone can point me in the direction of a config that I can update to prevent the problem.
I did not need to add a bug report its;
Bug 33485 – Limit max heap size on systems using 32-bit and PAE and greater than 4GB ram

I'll try dropping mailboxd_java_heap_memory_percent from 30 -> 10% and see what happens in the AM.

My users don't like to be without their e-mail.

uxbod. I see your reply below which jives with the bug report. Thanks

[uxbod]

su - zimbra
zmlocalconfig | grep mailboxd_java_heap_memory_percent

What is that value set to ? The default is 30% of the amount of system memory, so that may need to be tuned back.