zmmailboxd regularly crashing after latest update

Discuss your pilot or production implementation with other Zimbra admins or our engineers.
Post Reply
xorcz
Posts: 27
Joined: Fri Nov 20, 2015 6:48 am

zmmailboxd regularly crashing after latest update

Post by xorcz »

I updated zimbra and renewed certificate 2 days ago. Since then the process zmmailboxd stopped starting. It stops always at 00:42:10, but does not start again. Services can be started manually (zmcontrol restart).

rpm -qa | grep zimbra
https://pastebin.com/58eZrhQJ

zmmailboxd.out
https://pastebin.com/vyPbbjya

Services:

Code: Select all

[zimbra@mail ~]$ zmcontrol status
Host mail.anonymized.cz
	amavis                  Running
	antispam                Running
	antivirus               Running
	ldap                    Running
	logger                  Running
	mailbox                 Stopped
		zmmailboxdctl is not running.
	memcached               Running
	mta                     Running
	opendkim                Running
	proxy                   Stopped
		proxy is not running.
	service webapp          Stopped
		zmmailboxdctl is not running.
	snmp                    Running
	spell                   Running
	stats                   Running
	zimbra webapp           Stopped
		zmmailboxdctl is not running.
	zimbraAdmin webapp      Stopped
		zmmailboxdctl is not running.
	zimlet webapp           Stopped
		zmmailboxdctl is not running.
	zmconfigd               Running

zimbra.log - today

Code: Select all

Oct 19 00:42:15 mail zmmailboxdmgr[6913]: stop requested
Oct 19 00:42:15 mail zmmailboxdmgr[6913]: waiting for manager process 14215 to die
Oct 19 00:42:15 mail zmmailboxdmgr[14215]: shutdown requested, sending TERM signal to 14216
Oct 19 00:42:17 mail zmmailboxdmgr[14215]: mailboxd/JVM process exited (waitpid expected 14216 got 14216)
Oct 19 00:42:17 mail zmmailboxdmgr[14215]: manager woke up from wait on mailboxd/JVM with pid 14216
Oct 19 00:42:18 mail zmmailboxdmgr[6913]: manager process 14215 died, shutdown completed
Oct 19 00:42:18 mail zmconfigd[12371]: Fetching All configs
Oct 19 00:42:18 mail zmconfigd[12371]: All configs fetched in 0.08 seconds
Oct 19 00:42:23 mail zmmailboxdmgr[7154]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Oct 19 00:42:23 mail zmmailboxdmgr[7154]: assuming no other instance is running
Oct 19 00:42:23 mail zmmailboxdmgr[7154]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Oct 19 00:42:23 mail zmmailboxdmgr[7154]: assuming no other instance is running
Oct 19 00:42:23 mail zmmailboxdmgr[7154]: no manager process is running
Oct 19 00:42:23 mail zmconfigd[12371]: Service status change: mail.anonymized.cz mailbox changed from running to stopped
zimbra.log - requests to stop and start zmmailboxd. after the update, start request is missing

Code: Select all

Oct 15 00:42:15 mail zmmailboxdmgr[18366]: stop requested
Oct 15 00:42:15 mail zmmailboxdmgr[6402]: shutdown requested, sending TERM signal to 6403
Oct 15 00:42:49 mail zmmailboxdmgr[19380]: start requested
...
Oct 16 00:42:14 mail zmmailboxdmgr[31422]: stop requested
Oct 16 00:42:14 mail zmmailboxdmgr[19381]: shutdown requested, sending TERM signal to 19382
Oct 16 00:42:53 mail zmmailboxdmgr[32442]: start requested
Oct 16 04:02:46 mail zmmailboxdmgr[4476]: start requested
...
Oct 17 00:42:15 mail zmmailboxdmgr[11461]: stop requested
Oct 17 00:42:15 mail zmmailboxdmgr[4477]: shutdown requested, sending TERM signal to 4478
Oct 17 00:42:54 mail zmmailboxdmgr[12472]: start requested
...//update and cert renew
Oct 17 19:00:28 mail zmmailboxdmgr[18445]: stop requested
Oct 17 19:00:28 mail zmmailboxdmgr[12473]: shutdown requested, sending TERM signal to 12474
Oct 17 19:02:23 mail zmmailboxdmgr[21582]: start requested
Oct 17 19:16:07 mail zmmailboxdmgr[21583]: shutdown requested, sending TERM signal to 21589
Oct 17 19:18:35 mail zmmailboxdmgr[12522]: start requested
..
Oct 18 00:42:15 mail zmmailboxdmgr[9842]: stop requested
Oct 18 00:42:15 mail zmmailboxdmgr[12523]: shutdown requested, sending TERM signal to 12524
.. //manual starts
Oct 18 09:17:16 mail zmmailboxdmgr[9339]: start requested
Oct 18 10:45:33 mail zmmailboxdmgr[11223]: stop requested
Oct 18 10:45:33 mail zmmailboxdmgr[9340]: shutdown requested, sending TERM signal to 9341
Oct 18 10:47:00 mail zmmailboxdmgr[14214]: start requested
..
Oct 19 00:42:15 mail zmmailboxdmgr[6913]: stop requested
Oct 19 00:42:15 mail zmmailboxdmgr[14215]: shutdown requested, sending TERM signal to 14216
//manual start
Oct 19 02:26:16 mail zmmailboxdmgr[15285]: start requested

mailboxd.log

Code: Select all

2021-10-19 00:42:15,531 INFO  [Thread-11] [] filter - Destroying CSRF filter.
2021-10-19 00:42:15,531 INFO  [Thread-11] [] misc - ZimbraInvalidLoginFilter destroyed
2021-10-19 00:42:15,532 INFO  [Thread-11] [] AutoDiscoverServlet - Shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] StatsImageServlet - Servlet StatsImageServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] FileUploadServlet - Servlet FileUploadServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] PublicICalServlet - Servlet PublicICalServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] account - Servlet SpnegoAuthServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] account - Servlet CertAuthServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] account - Servlet ExternalUserProvServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] account - Servlet PreAuthServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] UserServlet - Shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] ContentServlet - Servlet ContentServlet shutting down
2021-10-19 00:42:15,532 INFO  [Thread-11] [] soap - Servlet AdminServlet shutting down
2021-10-19 00:42:15,533 INFO  [Thread-11] [] autoprov - shutdown() called, but auto provision thread is not running.
2021-10-19 00:42:15,533 INFO  [Thread-11] [] TcpServer/7025 - LmtpServer initiating shutdown
2021-10-19 00:42:15,533 INFO  [MailboxPurge] [] purge - Shutting down purge thread.
2021-10-19 00:42:15,534 INFO  [Thread-11] [] TcpServer/7025 - LmtpServer shutting down idle thread pool
2021-10-19 00:42:15,533 INFO  [LmtpServer] [] TcpServer/7025 - finished accept loop
2021-10-19 00:42:15,534 INFO  [Thread-11] [] pop - Initiating shutdown
2021-10-19 00:42:15,538 INFO  [Thread-11] [] pop - Initiating shutdown
2021-10-19 00:42:15,539 INFO  [Thread-11] [] imap - Initiating shutdown
2021-10-19 00:42:15,540 INFO  [Thread-11] [] imap - Initiating shutdown
2021-10-19 00:42:16,000 INFO  [Thread-11] [] redolog - waiting for FileLogWriter.FsyncThread-1634546847413 to finish.
2021-10-19 00:42:16,003 INFO  [FileLogWriter.FsyncThread-1634546847413] [] redolog - fsync thread exiting
2021-10-19 00:42:16,003 INFO  [Thread-11] [] redolog - FileLogWriter.FsyncThread-1634546847413 finished
2021-10-19 00:42:16,145 INFO  [Thread-11] [] redolog - Redo log rollover took 596ms
2021-10-19 00:42:16,145 INFO  [Thread-11] [] redolog - waiting for FileLogWriter.FsyncThread-1634596936144 to finish.
2021-10-19 00:42:16,145 INFO  [FileLogWriter.FsyncThread-1634596936144] [] redolog - Starting fsync thread with interval 10
2021-10-19 00:42:16,155 INFO  [FileLogWriter.FsyncThread-1634596936144] [] redolog - fsync thread exiting
2021-10-19 00:42:16,156 INFO  [Thread-11] [] redolog - FileLogWriter.FsyncThread-1634596936144 finished
2021-10-19 00:42:16,180 INFO  [Thread-11] [] redolog - Logged: 2148 items, 55.792ms/item
2021-10-19 00:42:16,180 INFO  [Thread-11] [] extensions - Destroying extensions
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension clamscanner: com.zimbra.clam.ClamScannerExt@com.zimbra.cs.extension.ZimbraExtensionClassLoader@69aa7d76
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Handler at /com_zimbra_bulkprovision/bulkdownload shutting down
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Handler at /com_zimbra_bulkprovision/search_results_download shutting down
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension com_zimbra_bulkprovision: com.zimbra.bp.ZimbraBulkProvisionExt@com.zimbra.cs.extension.ZimbraExtensionClassLoader@3913f206
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension com_zimbra_cert_manager: com.zimbra.cert.ZimbraCertMgrExt@com.zimbra.cs.extension.ZimbraExtensionClassLoader@41ccb3b9
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension clientUploader: com.zimbra.clientuploader.ZClientUploaderExt@com.zimbra.cs.extension.ZimbraExtensionClassLoader@5f59ea8c
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension com_zimbra_ssdb_ephemeral_store: com.zimbra.ssdb.SSDBEphemeralStoreExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@5d5a51b1
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension nginx-lookup: com.zimbra.cs.nginx.NginxLookupExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@42d6c12d
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension versioncheck: com.zimbra.cs.versioncheck.VersionCheckExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@56c8e6f0
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension zimbrasamba: com.zimbra.ldaputils.ZimbraLDAPUtilsExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@4fb56bea
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension zm-gql: com.zimbra.graphql.resources.GQLExtension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@17b016ac
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension zm-oauth-social: com.zimbra.oauth.resources.OAuth2Extension@com.zimbra.cs.extension.ZimbraExtensionClassLoader@415ef4d8
2021-10-19 00:42:16,181 INFO  [Thread-11] [] extensions - Destroyed extension AnnouncementsExt: tk.barrydegraaff.accounthistory.accountHistoryExt@com.zimbra.cs.extension.ZimbraExtensionClassLoader@66a53104
2021-10-19 00:42:16,182 INFO  [Thread-11] [] extensions - Destroyed extension AccountHistoryAdminExt: tk.barrydegraaff.AccountHistoryAdmin.AccountHistoryAdminExt@com.zimbra.cs.extension.ZimbraExtensionClassLoader@38ee7a9d
2021-10-19 00:42:16,215 INFO  [Thread-11] [] EhcacheManager - Cache 'sync-state-item-cache' removed from EhcacheManager.
2021-10-19 00:42:16,324 INFO  [Thread-11] [] EhcacheManager - Cache 'imap-active-session-cache' removed from EhcacheManager.
2021-10-19 00:42:16,822 INFO  [Thread-11] [] EhcacheManager - Cache 'imap-inactive-session-cache' removed from EhcacheManager.
2021-10-19 00:42:16,823 INFO  [IncomingDirectorySweeper] [] store - IncomingDirectorySweeper thread exiting
2021-10-19 00:42:16,834 INFO  [Thread-11] [] ZimbraHttpConnectionManager - shutting down http client idle connection reaper thread
2021-10-19 00:42:16,834 INFO  [Thread-11] [] ZimbraHttpConnectionManager - shutting down http client idle connection reaper thread
2021-10-19 00:42:16,835 INFO  [Thread-11] [] soap - Servlet SoapServlet shutting down
What could be broken?
xorcz
Posts: 27
Joined: Fri Nov 20, 2015 6:48 am

Re: zmmailboxd regularly crashing after latest update

Post by xorcz »

So there was indeed one cron job at 00:42, which I did not see in the late night :oops:

Code: Select all

# renew the certificate
42 0 * * * zimbra /opt/letsencrypt-zimbra/letsencrypt-zimbra.sh -q
https://github.com/VojtechMyslivec/lets ... /cron.conf
Post Reply