Upgrade from 8.6 to 8.7.2 - services keep dying

Discuss your pilot or production implementation with other Zimbra admins or our engineers.
Post Reply
zecto
Posts: 4
Joined: Fri Feb 03, 2017 1:14 pm

Upgrade from 8.6 to 8.7.2 - services keep dying

Post by zecto »

After the upgrade from 8.6 to 8.7.2, everything seems normal. Then the services started dying and restarting themselfs. This occurs at around 5-10 min intervals.
I've tried rebooting the server to no avail.

Anyone experienced anything similar?

I also tried the same upgrade from 8.6 to 8.7 a few months ago with the same result.

Running Ubuntu 14.04.
User avatar
vavai
Advanced member
Advanced member
Posts: 174
Joined: Thu Nov 14, 2013 2:41 pm
Location: Indonesia
ZCS/ZD Version: 0
Contact:

Re: Upgrade from 8.6 to 8.7.2 - services keep dying

Post by vavai »

Hi,
zecto wrote:After the upgrade from 8.6 to 8.7.2, everything seems normal. Then the services started dying and restarting themselfs. This occurs at around 5-10 min intervals.
I've tried rebooting the server to no avail.

Anyone experienced anything similar?

I also tried the same upgrade from 8.6 to 8.7 a few months ago with the same result.

Running Ubuntu 14.04.
What is the relevant log on /opt/zimbra/log/mailbox.log and /var/log/zimbra.log?
zecto
Posts: 4
Joined: Fri Feb 03, 2017 1:14 pm

Re: Upgrade from 8.6 to 8.7.2 - services keep dying

Post by zecto »

Some snippets.

Code: Select all

2017-02-03 15:03:28,803 INFO  [Thread-12] [] AutoDiscoverServlet - Shutting down
2017-02-03 15:03:28,803 INFO  [Thread-12] [] StatsImageServlet - Servlet StatsImageServlet shutting down
2017-02-03 15:03:28,803 INFO  [Thread-12] [] FileUploadServlet - Servlet FileUploadServlet shutting down
2017-02-03 15:03:28,803 INFO  [Thread-12] [] PublicICalServlet - Servlet PublicICalServlet shutting down
2017-02-03 15:03:28,804 INFO  [Thread-12] [] account - Servlet SpnegoAuthServlet shutting down
2017-02-03 15:03:28,804 INFO  [Thread-12] [] account - Servlet CertAuthServlet shutting down
2017-02-03 15:03:28,804 INFO  [Thread-12] [] account - Servlet ExternalUserProvServlet shutting down
2017-02-03 15:03:28,804 INFO  [Thread-12] [] account - Servlet PreAuthServlet shutting down
2017-02-03 15:03:28,804 INFO  [Thread-12] [] UserServlet - Shutting down
2017-02-03 15:03:28,804 INFO  [Thread-12] [] ContentServlet - Servlet ContentServlet shutting down
2017-02-03 15:03:28,804 INFO  [Thread-12] [] soap - Servlet AdminServlet shutting down
2017-02-03 15:03:28,804 INFO  [MailboxPurge] [] purge - Shutting down purge thread.
2017-02-03 15:03:28,805 INFO  [Thread-12] [] autoprov - shutdown() called, but auto provision thread is not running.
2017-02-03 15:03:28,805 INFO  [Thread-12] [] TcpServer/7025 - LmtpServer initiating shutdown
2017-02-03 15:03:28,805 INFO  [LmtpServer] [] TcpServer/7025 - finished accept loop
2017-02-03 15:03:28,806 INFO  [Thread-12] [] TcpServer/7025 - LmtpServer shutting down idle thread pool
2017-02-03 15:03:28,806 INFO  [Thread-12] [] pop - Initiating shutdown
2017-02-03 15:03:28,809 INFO  [Thread-12] [] pop - Initiating shutdown
2017-02-03 15:03:28,810 INFO  [Thread-12] [] imap - Initiating shutdown
2017-02-03 15:03:28,810 INFO  [Thread-12] [] imap - Initiating shutdown
2017-02-03 15:03:29,056 INFO  [Thread-12] [] redolog - waiting for FileLogWriter.FsyncThread-1486130423023 to finish.
2017-02-03 15:03:29,061 INFO  [FileLogWriter.FsyncThread-1486130423023] [] redolog - fsync thread exiting
2017-02-03 15:03:29,061 INFO  [Thread-12] [] redolog - FileLogWriter.FsyncThread-1486130423023 finished
2017-02-03 15:03:29,157 INFO  [Thread-12] [] redolog - Redo log rollover took 342ms
2017-02-03 15:03:29,157 INFO  [Thread-12] [] redolog - waiting for FileLogWriter.FsyncThread-1486130609156 to finish.
2017-02-03 15:03:29,157 INFO  [FileLogWriter.FsyncThread-1486130609156] [] redolog - Starting fsync thread with interval 10
2017-02-03 15:03:29,167 INFO  [FileLogWriter.FsyncThread-1486130609156] [] redolog - fsync thread exiting
2017-02-03 15:03:29,173 INFO  [Thread-12] [] redolog - FileLogWriter.FsyncThread-1486130609156 finished
2017-02-03 15:03:29,207 INFO  [Thread-12] [] redolog - Logged: 100 items, 29.54ms/item
2017-02-03 15:03:29,207 INFO  [Thread-12] [] extensions - Destroying extensions
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Handler at /com_zimbra_bulkprovision/bulkdownload shutting down
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Destroyed extension com_zimbra_bulkprovision: com.zimbra.bp.ZimbraBulkProvisionExt@com.zimbra.cs.exten$
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Destroyed extension nginx-lookup: com.zimbra.cs.nginx.NginxLookupExtension@com.zimbra.cs.extension.Zim$
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Destroyed extension com_zimbra_cert_manager: com.zimbra.cert.ZimbraCertMgrExt@com.zimbra.cs.extension.$
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Destroyed extension clientUploader: com.zimbra.clientuploader.ZClientUploaderExt@com.zimbra.cs.extensi$
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Destroyed extension zimbrasamba: com.zimbra.ldaputils.ZimbraLDAPUtilsExtension@com.zimbra.cs.extension$
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Destroyed extension versioncheck: com.zimbra.cs.versioncheck.VersionCheckExtension@com.zimbra.cs.exten$
2017-02-03 15:03:29,208 INFO  [Thread-12] [] extensions - Destroyed extension clamscanner: com.zimbra.clam.ClamScannerExt@com.zimbra.cs.extension.ZimbraExtensio$
2017-02-03 15:03:29,214 WARN  [Thread-12] [] ConfigurationFactory - No configuration found. Configuring ehcache from ehcache-failsafe.xml  found in the classpat$
2017-02-03 15:03:29,231 INFO  [IncomingDirectorySweeper] [] store - IncomingDirectorySweeper thread exiting
2017-02-03 15:03:29,235 INFO  [Thread-12] [] ZimbraHttpConnectionManager - shutting down http client idle connection reaper thread
2017-02-03 15:03:29,236 INFO  [Thread-12] [] ZimbraHttpConnectionManager - shutting down http client idle connection reaper thread
2017-02-03 15:03:29,239 INFO  [Thread-12] [] soap - Servlet SoapServlet shutting down
2017-02-03 15:03:29,239 INFO  [Thread-12] [] filter - Destroying CSRF filter.
2017-02-03 15:03:29,239 INFO  [Thread-12] [] misc - ZimbraInvalidLoginFilter destroyed

Then it starts them up a min or so later it seems
2017-02-03 15:05:53,950 INFO  [FileLogWriter.FsyncThread-1486130753949] [] redolog - Starting fsync thread with interval 10
2017-02-03 15:05:53,952 INFO  [main] [] redolog - waiting for FileLogWriter.FsyncThread-1486130753949 to finish.
2017-02-03 15:05:53,961 INFO  [FileLogWriter.FsyncThread-1486130753949] [] redolog - fsync thread exiting
2017-02-03 15:05:53,961 INFO  [main] [] redolog - FileLogWriter.FsyncThread-1486130753949 finished
2017-02-03 15:05:53,992 INFO  [main] [] redolog - No uncommitted transactions to redo
2017-02-03 15:05:53,992 INFO  [FileLogWriter.FsyncThread-1486130753992] [] redolog - Starting fsync thread with interval 10
2017-02-03 15:05:53,992 INFO  [main] [] redolog - waiting for FileLogWriter.FsyncThread-1486130753992 to finish.
2017-02-03 15:05:54,002 INFO  [FileLogWriter.FsyncThread-1486130753992] [] redolog - fsync thread exiting
2017-02-03 15:05:54,003 INFO  [main] [] redolog - FileLogWriter.FsyncThread-1486130753992 finished
2017-02-03 15:05:54,020 INFO  [main] [] redolog - Finished pre-startup crash recovery
2017-02-03 15:05:54,034 INFO  [FileLogWriter.FsyncThread-1486130754034] [] redolog - Starting fsync thread with interval 10
2017-02-03 15:05:54,041 INFO  [main] [] misc - MINA setUseDirectBuffers(false)
2017-02-03 15:05:54,048 INFO  [main] [] lmtp - Adding LMTP callback: com.zimbra.cs.mailbox.Notification
2017-02-03 15:05:54,048 INFO  [main] [] lmtp - Adding LMTP callback: com.zimbra.cs.mailbox.QuotaWarning
2017-02-03 15:05:54,065 INFO  [LmtpServer] [] TcpServer/7025 - Starting accept loop: 1 core threads, 20 max threads.
2017-02-03 15:05:54,110 INFO  [main] [] pop - Starting Pop3Server on /0.0.0.0:7110
2017-02-03 15:05:54,121 INFO  [main] [] pop - Starting Pop3SSLServer on /0.0.0.0:7995
2017-02-03 15:05:54,127 INFO  [main] [] imap - Starting ImapServer on /0.0.0.0:7143
2017-02-03 15:05:54,129 INFO  [main] [] imap - Starting ImapSSLServer on /0.0.0.0:7993
2017-02-03 15:05:54,141 INFO  [main] [] scheduler - Loaded 1 scheduled data source tasks
2017-02-03 15:05:54,143 INFO  [main] [] purge - Starting purge thread with sleep interval 1m.
2017-02-03 15:05:54,151 INFO  [MailboxPurge] [] purge - Purge thread sleeping for 1800000ms before doing work.
2017-02-03 15:05:54,154 INFO  [main] [] extensions - Post-Initializing extensions
2017-02-03 15:05:54,162 INFO  [main] [] soap - Servlet AdminServlet starting up
2017-02-03 15:05:54,210 INFO  [main] [] soap - Adding service AdminService to AdminServlet
2017-02-03 15:05:54,244 INFO  [main] [] soap - Adding service AccountService to AdminServlet
2017-02-03 15:05:54,244 INFO  [main] [] soap - Adding service MailService to AdminServlet
2017-02-03 15:05:54,244 INFO  [main] [] soap - Adding service ZimbraBulkProvisionService to AdminServlet
2017-02-03 15:05:54,250 INFO  [main] [] soap - Adding service ZimbraCertMgrService to AdminServlet
2017-02-03 15:05:54,252 INFO  [main] [] soap - Adding service ZimbraLDAPUtilsService to AdminServlet
2017-02-03 15:05:54,253 INFO  [main] [] soap - Adding service VersionCheckService to AdminServlet
2017-02-03 15:05:54,256 INFO  [main] [] account - Servlet CertAuthServlet starting up
And zimbra.log

Code: Select all

Feb  3 15:03:16 mail zmconfigd[1265]: Fetching All configs
Feb  3 15:03:16 mail zmconfigd[1265]: All configs fetched in 0.04 seconds
Feb  3 15:03:17 mail sshd[32430]: message repeated 2 times: [ Failed password for root from 116.31.116.9 port 55280 ssh2]
Feb  3 15:03:18 mail sshd[32430]: Received disconnect from 116.31.116.9: 11:  [preauth]
Feb  3 15:03:20 mail zmconfigd[1265]: Watchdog: service antivirus status is OK.
Feb  3 15:03:20 mail zmconfigd[1265]: All rewrite threads completed in 0.01 sec
Feb  3 15:03:20 mail zmconfigd[1265]: All restarts completed in 0.00 sec
Feb  3 15:03:21 mail opendkim[31526]: OpenDKIM Filter: mi_stop=1
Feb  3 15:03:21 mail opendkim[31526]: OpenDKIM Filter v2.10.3 terminating with status 0, errno = 0
Feb  3 15:03:22 mail saslauthd[31117]: server_exit     : master exited: 31117
Feb  3 15:03:23 mail /postfix-script[452]: stopping the Postfix mail system
Feb  3 15:03:23 mail postfix/master[30587]: terminating on signal 15
Feb  3 15:03:26 mail clamd[26120]: Pid file removed.
Feb  3 15:03:26 mail clamd[26120]: --- Stopped at Fri Feb  3 15:03:26 2017
Feb  3 15:03:26 mail clamd[26120]: Socket file removed.
Feb  3 15:03:27 mail amavis[27810]: Net::Server: 2017/02/03-15:03:27 Server closing!
Feb  3 15:03:28 mail zmmailboxdmgr[723]: stop requested
Feb  3 15:03:28 mail zmmailboxdmgr[26931]: shutdown requested, sending TERM signal to 26936
Feb  3 15:03:28 mail zmmailboxdmgr[723]: waiting for manager process 26931 to die
Feb  3 15:03:29 mail zmmailboxdmgr[26931]: mailboxd/JVM process exited (waitpid expected 26936 got 26936)
Feb  3 15:03:29 mail zmmailboxdmgr[26931]: manager woke up from wait on mailboxd/JVM with pid 26936
Feb  3 15:03:30 mail zmmailboxdmgr[723]: manager process 26931 died, shutdown completed
Feb  3 15:03:32 mail amavis-mc[27051]: Master process shutting down
Feb  3 15:03:32 mail amavis-mc[27051]: Terminating process [27055] (/opt/zimbra/common/sbin/amavis-services msg-forwarder)
Feb  3 15:03:32 mail amavis-mc[27051]: Terminating process [27056] (/opt/zimbra/common/sbin/amavis-services childproc-minder)
Feb  3 15:03:32 mail amavis-mc[27051]: Terminating process [27057] (/opt/zimbra/common/sbin/amavis-services snmp-responder)
Feb  3 15:03:32 mail amavis-services[27055]: Task 'msg-forwarder' [27055] shutting down
Feb  3 15:00:23 mail amavis-services[27056]: childproc_minder: FLUSH process states
Feb  3 15:03:32 mail amavis-services[27056]: Task 'childproc-minder' [27056] shutting down
Feb  3 15:03:32 mail amavis-services[27055]: msg-forwarder closing inner socket
Feb  3 15:03:32 mail amavis-services[27056]: childproc-minder closing inner socket
Feb  3 15:03:32 mail amavis-services[27055]: msg-forwarder closing outer socket
Feb  3 15:03:32 mail amavis-services[27055]: msg-forwarder closing context
Feb  3 15:03:32 mail amavis-services[27056]: childproc-minder closing outer socket
Feb  3 15:03:32 mail amavis-services[27055]: Task 'msg-forwarder' [27055] exiting: TERM
Feb  3 15:03:32 mail amavis-services[27056]: childproc-minder closing context
Feb  3 15:03:32 mail amavis-services[27056]: Task 'childproc-minder' [27056] exiting: TERM
Feb  3 15:03:32 mail amavis-mc[27051]: Process [27055] exited (/opt/zimbra/common/sbin/amavis-services msg-forwarder) after 207.0 s: exit 0
Feb  3 15:03:32 mail amavis-mc[27051]: Process [27056] exited (/opt/zimbra/common/sbin/amavis-services childproc-minder) after 207.0 s: exit 0
Feb  3 15:03:36 mail sshd[692]: Failed password for root from 153.99.182.6 port 23775 ssh2
Feb  3 15:03:40 mail sshd[692]: message repeated 2 times: [ Failed password for root from 153.99.182.6 port 23775 ssh2]
Feb  3 15:03:41 mail sshd[692]: Received disconnect from 153.99.182.6: 11:  [preauth]
Feb  3 15:03:42 mail amavis-mc[27051]: Killing process [27057] (/opt/zimbra/common/sbin/amavis-services snmp-responder)
Feb  3 15:03:42 mail amavis-mc[27051]: Process [27057] exited (/opt/zimbra/common/sbin/amavis-services snmp-responder) after 217.0 s: KILLED, signal 9 (0009)
Feb  3 15:03:42 mail amavis-mc[27051]: Master process exiting: TERM
Feb  3 15:03:44 mail postfix/postqueue[783]: fatal: Queue report unavailable - mail system is down

Feb  3 15:04:14 mail postfix/postqueue[1177]: fatal: Queue report unavailable - mail system is down

Feb  3 15:05:33 mail zmconfigd[1265]: Fetching All configs
Feb  3 15:05:33 mail zmconfigd[1265]: All configs fetched in 0.06 seconds
Feb  3 15:05:34 mail zmconfigd[1265]: Processing rewrite request for sasl
Feb  3 15:05:34 mail zmconfigd[1265]: Processing rewrite request for webxml
Feb  3 15:05:34 mail zmconfigd[1265]: Processing rewrite request for mailbox
Feb  3 15:05:34 mail zmconfigd[1265]: Processing rewrite request for service
Feb  3 15:05:34 mail zmconfigd[1265]: Processing rewrite request for zimbra
Feb  3 15:05:34 mail zmconfigd[1265]: Processing rewrite request for zimbraAdmin
Feb  3 15:05:34 mail zmconfigd[1265]: Processing rewrite request for zimlet
Feb  3 15:05:35 mail sshd[1578]: message repeated 2 times: [ Failed password for root from 116.31.116.9 port 57874 ssh2]
Feb  3 15:05:35 mail sshd[1578]: Received disconnect from 116.31.116.9: 11:  [preauth]
Feb  3 15:05:36 mail zmconfigd[1265]: Service status change: mail.ricohnorge.no antivirus changed from stopped to running
Feb  3 15:05:36 mail zmconfigd[1265]: Tracking service antivirus
Feb  3 15:05:36 mail zmconfigd[1265]: Watchdog: service antivirus now available for watchdog.
Feb  3 15:05:36 mail zmmailboxdmgr[1952]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[1952]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[1952]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[1952]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[1952]: no manager process is running
Feb  3 15:05:36 mail zmmailboxdmgr[1966]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[1966]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[1966]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[1966]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[1966]: no manager process is running
Feb  3 15:05:36 mail zmmailboxdmgr[2016]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[2016]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[2016]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[2016]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[2016]: no manager process is running
Feb  3 15:05:36 mail zmmailboxdmgr[2077]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[2077]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[2077]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Feb  3 15:05:36 mail zmmailboxdmgr[2077]: assuming no other instance is running
Feb  3 15:05:36 mail zmmailboxdmgr[2077]: no manager process is running
Feb  3 15:05:37 mail zmmailboxdmgr[2092]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Feb  3 15:05:37 mail zmmailboxdmgr[2092]: assuming no other instance is running
Feb  3 15:05:37 mail zmmailboxdmgr[2092]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Feb  3 15:05:37 mail zmmailboxdmgr[2092]: assuming no other instance is running
Feb  3 15:05:37 mail zmmailboxdmgr[2092]: no manager process is running
Feb  3 15:05:37 mail zmmailboxdmgr[2106]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Feb  3 15:05:37 mail zmmailboxdmgr[2106]: assuming no other instance is running
Feb  3 15:05:37 mail zmmailboxdmgr[2106]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Feb  3 15:05:37 mail zmmailboxdmgr[2106]: assuming no other instance is running
Feb  3 15:05:37 mail zmmailboxdmgr[2106]: no manager process is running
User avatar
vavai
Advanced member
Advanced member
Posts: 174
Joined: Thu Nov 14, 2013 2:41 pm
Location: Indonesia
ZCS/ZD Version: 0
Contact:

Re: Upgrade from 8.6 to 8.7.2 - services keep dying

Post by vavai »

From the above logs, what is your main problem? Accessing mail with POP3/IMAP/Web or mostly problem with sending and receiving email?

If you got trouble with accessing mail, try to looking at /opt/zimbra/log/mysql_error.log but if you have trouble with mail transaction, better to see Postfix/Clamav configuration. Just a little case, incorrect setting on MTA Trusted Network may leads to problem on amavis/as/av and ended up with problem on Postfix.
zecto
Posts: 4
Joined: Fri Feb 03, 2017 1:14 pm

Re: Upgrade from 8.6 to 8.7.2 - services keep dying

Post by zecto »

vavai wrote:From the above logs, what is your main problem? Accessing mail with POP3/IMAP/Web or mostly problem with sending and receiving email?

If you got trouble with accessing mail, try to looking at /opt/zimbra/log/mysql_error.log but if you have trouble with mail transaction, better to see Postfix/Clamav configuration. Just a little case, incorrect setting on MTA Trusted Network may leads to problem on amavis/as/av and ended up with problem on Postfix.

Sorry for the late reply.

The main problem is that all the processes/modules are crashing and restarting, when they are up there is no problem getting mail or going to the webclient for example. The problem is they are up for 5 minutes then down for another few minutes trying to restart and the cycle continues forever.
User avatar
DualBoot
Elite member
Elite member
Posts: 1326
Joined: Mon Apr 18, 2016 8:18 pm
Location: France - Earth
ZCS/ZD Version: ZCS FLOSS - 8.8.15 Mutli servers
Contact:

Re: Upgrade from 8.6 to 8.7.2 - services keep dying

Post by DualBoot »

Maybe it is a JVM problem, look at this log : /opt/zimbra/log/zmmailboxd.out
Post your system configuration also.
zecto
Posts: 4
Joined: Fri Feb 03, 2017 1:14 pm

Re: Upgrade from 8.6 to 8.7.2 - services keep dying

Post by zecto »

DualBoot wrote:Maybe it is a JVM problem, look at this log : /opt/zimbra/log/zmmailboxd.out
Post your system configuration also.
This seems to be the only thing repeating itself in the zmmailboxd.out

Code: Select all

2017-02-06 12:52:07.395:INFO:oejs.ServerConnector:Thread-12: Stopped ServerConnector@33b37288{HTTP/1.1,[http/1.1]}{localhost:8080}
2017-02-06 12:52:07.399:INFO:oejs.ServerConnector:Thread-12: Stopped ServerConnector@45afc369{SSL,[ssl, http/1.1]}{0.0.0.0:8443}
2017-02-06 12:52:07.399:INFO:oejs.ServerConnector:Thread-12: Stopped ServerConnector@799d4f69{SSL,[ssl, http/1.1]}{0.0.0.0:7071}
2017-02-06 12:52:07.400:INFO:oejs.ServerConnector:Thread-12: Stopped ServerConnector@49c43f4e{SSL,[ssl, http/1.1]}{0.0.0.0:7073}
2017-02-06 12:52:07.400:INFO:oejs.ServerConnector:Thread-12: Stopped ServerConnector@290dbf45{SSL,[ssl, http/1.1]}{0.0.0.0:7072}
2017-02-06 12:52:07.442:INFO:oejsh.ContextHandler:Thread-12: Stopped o.e.j.w.WebAppContext@16ec5519{/zimlet,[file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/zimlet/, file:///opt/zimbra/zim$
2017-02-06 12:52:07.455:INFO:oejsh.ContextHandler:Thread-12: Stopped o.e.j.w.WebAppContext@50eac852{/zimbraAdmin,null,UNAVAILABLE}{/zimbraAdmin}
2017-02-06 12:52:07.462:INFO:oejsh.ContextHandler:Thread-12: Stopped o.e.j.w.WebAppContext@61df66b6{/,null,UNAVAILABLE}{/zimbra}
2017-02-06 12:52:09.167:INFO:oejsh.ContextHandler:Thread-12: Stopped o.e.j.w.WebAppContext@2c767a52{/service,null,UNAVAILABLE}{/service}
OpenJDK 64-Bit Server VM warning: .hotspot_compiler file is present but has been ignored.  Run with -XX:CompileCommandFile=.hotspot_compiler to load the file.
2017-02-06 12:54:21.543:INFO::main: Logging initialized @784ms
JettyMonitor monitoring thread pool qtp66233253{STOPPED,10<=0<=250,i=0,q=0}
JettyMonitor monitoring thread pool qtp66233253{STOPPED,10<=0<=250,i=0,q=0}
Zimbra server reserving server socket port=7110 bindaddr=null ssl=false
Zimbra server reserving server socket port=7995 bindaddr=null ssl=false
Zimbra server reserving server socket port=7143 bindaddr=null ssl=false
Zimbra server reserving server socket port=7993 bindaddr=null ssl=false
Zimbra server reserving server socket port=7025 bindaddr=null ssl=false
2017-02-06 12:54:23.160:INFO:oejs.SetUIDListener:main: Setting umask=027
2017-02-06 12:54:23.172:INFO:oejs.SetUIDListener:main: Current rlimit_nofiles (soft=524288, hard=524288)
2017-02-06 12:54:23.172:INFO:oejs.SetUIDListener:main: Set rlimit_nofiles (soft=65536, hard=65536)
2017-02-06 12:54:23.215:INFO:oejs.SetUIDListener:main: Opened ServerConnector@33b37288{HTTP/1.1,[http/1.1]}{localhost:8080}
2017-02-06 12:54:23.215:INFO:oejs.SetUIDListener:main: Opened ServerConnector@45afc369{SSL,[ssl, http/1.1]}{0.0.0.0:8443}
2017-02-06 12:54:23.215:INFO:oejs.SetUIDListener:main: Opened ServerConnector@799d4f69{SSL,[ssl, http/1.1]}{0.0.0.0:7071}
2017-02-06 12:54:23.215:INFO:oejs.SetUIDListener:main: Opened ServerConnector@49c43f4e{SSL,[ssl, http/1.1]}{0.0.0.0:7073}
2017-02-06 12:54:23.215:INFO:oejs.SetUIDListener:main: Opened ServerConnector@290dbf45{SSL,[ssl, http/1.1]}{0.0.0.0:7072}
2017-02-06 12:54:23.215:INFO:oejs.SetUIDListener:main: Setting GID=999
2017-02-06 12:54:23.228:INFO:oejs.SetUIDListener:main: Setting UID=999
2017-02-06 12:54:23.234:INFO:oejs.Server:main: jetty-9.3.5.v20151012
2017-02-06 12:54:29.621:WARN:oejs.SecurityHandler:main: ServletContext@o.e.j.w.WebAppContext@2c767a52{/service,file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/service/,STARTING}{/service} $
Zimbra server process is running as uid=999 euid=999 gid=999 egid=999
2017-02-06 12:54:32.363:INFO:oejsh.ContextHandler:main: Started o.e.j.w.WebAppContext@2c767a52{/service,file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/service/,AVAILABLE}{/service}
2017-02-06 12:54:33.939:WARN:oejpw.PlusDescriptorProcessor:main: No value for env-entry-name trustedIPs
2017-02-06 12:54:34.024:WARN:oejs.SecurityHandler:main: ServletContext@o.e.j.w.WebAppContext@61df66b6{/,file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/zimbra/,STARTING}{/zimbra} has uncov$
2017-02-06 12:54:34.303:INFO:oejsh.ContextHandler:main: Started o.e.j.w.WebAppContext@61df66b6{/,file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/zimbra/,AVAILABLE}{/zimbra}
2017-02-06 12:54:35.802:WARN:oejpw.PlusDescriptorProcessor:main: No value for env-entry-name trustedIPs
2017-02-06 12:54:35.856:WARN:oejs.SecurityHandler:main: ServletContext@o.e.j.w.WebAppContext@50eac852{/zimbraAdmin,file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/zimbraAdmin/,STARTING}{/z$
2017-02-06 12:54:36.383:INFO:oejsh.ContextHandler:main: Started o.e.j.w.WebAppContext@50eac852{/zimbraAdmin,file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/zimbraAdmin/,AVAILABLE}{/zimbraA$
2017-02-06 12:54:36.588:WARN:oejs.SecurityHandler:main: ServletContext@o.e.j.w.WebAppContext@16ec5519{/zimlet,[file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/zimlet/, file:///opt/zimbra/z$
2017-02-06 12:54:36.589:INFO:oejsh.ContextHandler:main: Started o.e.j.w.WebAppContext@16ec5519{/zimlet,[file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/webapps/zimlet/, file:///opt/zimbra/zimlets-$
2017-02-06 12:54:36.593:INFO:oejs.AbstractNCSARequestLog:main: Opened /opt/zimbra/log/access_log.2017-02-06
2017-02-06 12:54:36.597:INFO:oejm.ThreadMonitor:main: Thread Monitor started successfully
2017-02-06 12:54:36.617:INFO:oejs.ServerConnector:main: Started ServerConnector@33b37288{HTTP/1.1,[http/1.1]}{localhost:8080}
2017-02-06 12:54:36.624:INFO:oejus.SslContextFactory:main: x509=X509@69d45cca(jetty,h=[mail.ricohnorge.no],w=[]) for SslContextFactory@47d023b7(file:///opt/zimbra/jetty-distribution-9.3.5.v20151012/etc/$
2017-02-06 12:54:36.649:INFO:oejs.ServerConnector:main: Started ServerConnector@45afc369{SSL,[ssl, http/1.1]}{0.0.0.0:8443}
2017-02-06 12:54:36.658:INFO:oejs.ServerConnector:main: Started ServerConnector@799d4f69{SSL,[ssl, http/1.1]}{0.0.0.0:7071}
2017-02-06 12:54:36.668:INFO:oejs.ServerConnector:main: Started ServerConnector@49c43f4e{SSL,[ssl, http/1.1]}{0.0.0.0:7073}
2017-02-06 12:54:36.670:INFO:oejs.ServerConnector:main: Started ServerConnector@290dbf45{SSL,[ssl, http/1.1]}{0.0.0.0:7072}
2017-02-06 12:54:36.671:INFO:oejs.Server:main: Started @15912ms
I'm running this on a VM(Proxmox) with 2 cpus and 16GB ram
4.4.0-62-generic #83~14.04.1-Ubuntu SMP Wed Jan 18 18:10:30 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
AR84
Posts: 23
Joined: Mon Nov 06, 2017 5:12 am

Re: Upgrade from 8.6 to 8.7.2 - services keep dying

Post by AR84 »

Hi, did you find any solution for your problem?

I am having the same issue, i also upgraded from 8.6 to 8.7.11 and also by me the server us running fine for some time, and then out of nowhere the services stop working.
What was the issue in your case?

I moved from a CentOS 6 to a CentOS 7 Server.

Already trying for about 3 weeks almost everything. Server runs usually 1-2 days and then something crashes.

Here the log file zimbra.log with the relevant data:

Code: Select all

Nov 20 10:23:20 mail systemd-logind: Watching system buttons on /dev/input/event1 (Power Button)
Nov 20 10:23:20 mail systemd-logind: Watching system buttons on /dev/input/event2 (Fujitsu FUJ02E3)
Nov 20 10:23:20 mail systemd-logind: Watching system buttons on /dev/input/event0 (Power Button)
Nov 20 10:23:20 mail systemd-logind: New seat seat0.
Nov 20 10:23:25 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.9" (uid=0 pid=1028 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:25 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.9" (uid=0 pid=1028 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:25 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.9" (uid=0 pid=1028 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:25 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.9" (uid=0 pid=1028 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:25 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.9" (uid=0 pid=1028 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:25 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.9" (uid=0 pid=1028 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:28 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.12" (uid=0 pid=1108 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:28 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.12" (uid=0 pid=1108 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:28 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.12" (uid=0 pid=1108 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:28 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.12" (uid=0 pid=1108 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:28 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.12" (uid=0 pid=1108 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:28 mail dbus[758]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.2" (uid=0 pid=768 comm="/usr/bin/python -Es /usr/sbin/firewalld --nofork -") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.ServiceUnknown" requested_reply="0" destination=":1.12" (uid=0 pid=1108 comm="/usr/bin/python -Es /usr/bin/firewall-cmd --zone=p")
Nov 20 10:23:28 mail su: (to zimbra) root on none
Nov 20 10:23:34 mail zimbramon[1339]: 1339:info: Starting services initiated by zmcontrol
Nov 20 10:23:34 mail slapd[1403]: @(#) $OpenLDAP: slapd 2.4.44 (Sep 29 2016 14:52:27) $#012#011build@c787:/home/build/git/87/packages/thirdparty/openldap/build/RHEL7_64/zimbra-openldap/rpm/BUILD/openldap-2.4.44/servers/slapd
Nov 20 10:23:35 mail slapd[1404]: slapd starting
Nov 20 10:23:40 mail zimbramon[1339]: 1339:info: Starting zmconfigd via zmcontrol
Nov 20 10:23:43 mail zmconfigd[1431]: zmconfigd started on mail.abcdefg.com with loglevel=3 pid=1431
Nov 20 10:23:43 mail zmconfigd[1431]: Fetching All configs
Nov 20 10:23:43 mail zmconfigd[1431]: All configs fetched in 0.21 seconds
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/freshclam.conf with mode 600 (0.02 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/opendkim.conf with mode 440 (0.00 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/webapps/service/WEB-INF/web.xml with mode 440 (0.03 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbraAdmin/WEB-INF/jetty-env.xml with mode 440 (0.00 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/dspam.conf with mode 440 (0.01 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbra/WEB-INF/jetty-env.xml with mode 440 (0.00 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/clamd.conf with mode 440 (0.01 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbraAdmin/WEB-INF/web.xml with mode 440 (0.02 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/etc/spnego.conf with mode 440 (0.00 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/common/conf/tag_as_originating.re with mode 440 (0.00 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/unbound.conf with mode 440 (0.00 sec)
Nov 20 10:23:43 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/webapps/zimbra/WEB-INF/web.xml with mode 440 (0.01 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/etc/jetty.xml with mode 440 (0.04 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/spnego_java_options with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/sasl2/smtpd.conf with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/etc/spnego.properties with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/postfix_header_checks with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/opendkim-localnets.conf with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/etc/krb5.ini with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/stats.conf with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/common/conf/tag_as_foreign.re with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/saslauthd.conf with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/log4j.properties with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/amavisd.conf with mode 440 (0.02 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/common/conf/master.cf with mode 440 (0.02 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/webapps/zimlet/WEB-INF/web.xml with mode 440 (0.01 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/modules/setuid.mod with mode 440 (0.01 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/data/spamassassin/localrules/salocal.cf with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/conf/mta_milter_options with mode 440 (0.00 sec)
Nov 20 10:23:44 mail zmconfigd[1431]: Rewrote: /opt/zimbra/mailboxd/start.d/setuid.ini with mode 440 (0.01 sec)
Nov 20 10:23:54 mail zmconfigd[1431]: All rewrite threads completed in 10.94 sec
Nov 20 10:23:54 mail zmconfigd[1431]: All restarts completed in 0.00 sec
Nov 20 10:23:55 mail zimbramon[1339]: 1339:info: Starting dnscache via zmcontrol
Nov 20 10:23:55 mail unbound: [2543:0] warning: did not exit gracefully last time (2547)
Nov 20 10:23:55 mail unbound: [2544:0] notice: init module 0: validator
Nov 20 10:23:55 mail unbound: [2544:0] notice: init module 1: iterator
Nov 20 10:23:55 mail unbound: [2544:0] info: start of service (unbound 1.5.9).
Nov 20 10:23:57 mail zimbramon[1339]: 1339:info: Starting logger via zmcontrol
Nov 20 10:23:58 mail zimbramon[1339]: 1339:info: Starting mailbox via zmcontrol
Nov 20 10:24:03 mail zmmailboxdmgr[3275]: stale pid 3060 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Nov 20 10:24:03 mail zmmailboxdmgr[3275]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3275]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:24:03 mail zmmailboxdmgr[3275]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3275]: no manager process is running
Nov 20 10:24:03 mail zmmailboxdmgr[3322]: stale pid 3060 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Nov 20 10:24:03 mail zmmailboxdmgr[3322]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3322]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:24:03 mail zmmailboxdmgr[3322]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3322]: no manager process is running
Nov 20 10:24:03 mail zmmailboxdmgr[3401]: stale pid 3060 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Nov 20 10:24:03 mail zmmailboxdmgr[3401]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3401]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:24:03 mail zmmailboxdmgr[3401]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3401]: no manager process is running
Nov 20 10:24:03 mail zmmailboxdmgr[3419]: stale pid 3060 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Nov 20 10:24:03 mail zmmailboxdmgr[3419]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3419]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:24:03 mail zmmailboxdmgr[3419]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3419]: no manager process is running
Nov 20 10:24:03 mail zmmailboxdmgr[3437]: stale pid 3060 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Nov 20 10:24:03 mail zmmailboxdmgr[3437]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3437]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:24:03 mail zmmailboxdmgr[3437]: assuming no other instance is running
Nov 20 10:24:03 mail zmmailboxdmgr[3437]: no manager process is running
Nov 20 10:24:17 mail zmmailboxdmgr[3523]: stale pid 3060 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Nov 20 10:24:17 mail zmmailboxdmgr[3523]: assuming no other instance is running
Nov 20 10:24:17 mail zmmailboxdmgr[3523]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:24:17 mail zmmailboxdmgr[3523]: assuming no other instance is running
Nov 20 10:24:17 mail zmmailboxdmgr[3523]: no manager process is running
Nov 20 10:24:17 mail zmmailboxdmgr[3534]: start requested
Nov 20 10:24:17 mail zmmailboxdmgr[3534]: checking if another instance of manager is already running
Nov 20 10:24:17 mail zmmailboxdmgr[3534]: stale pid 3060 found in /opt/zimbra/log/zmmailboxd_manager.pid: No such process
Nov 20 10:24:17 mail zmmailboxdmgr[3534]: assuming no other instance is running
Nov 20 10:24:17 mail zmmailboxdmgr[3534]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:24:17 mail zmmailboxdmgr[3534]: assuming no other instance is running
Nov 20 10:24:17 mail zmmailboxdmgr[3535]: wrote manager pid 3535 to /opt/zimbra/log/zmmailboxd_manager.pid
Nov 20 10:24:17 mail zmmailboxdmgr[3535]: manager started mailboxd/JVM with pid 3536
Nov 20 10:24:17 mail zmmailboxdmgr[3536]: wrote java pid 3536 to /opt/zimbra/log/zmmailboxd_java.pid
Nov 20 10:24:18 mail zimbramon[1339]: 1339:info: Starting memcached via zmcontrol
Nov 20 10:24:22 mail zimbramon[1339]: 1339:info: Starting proxy via zmcontrol
Nov 20 10:24:22 mail systemd-logind: New session 2 of user root.
Nov 20 10:24:23 mail zimbramon[1339]: 1339:info: Starting amavis via zmcontrol
Nov 20 10:24:23 mail amavis-mc[3920]: amavis master process starting. daemonized as PID [3920], perl 5.016003
Nov 20 10:24:23 mail amavis-mc[3920]: Process [3924] started: /opt/zimbra/common/sbin/amavis-services msg-forwarder
Nov 20 10:24:23 mail amavis-mc[3920]: Process [3925] started: /opt/zimbra/common/sbin/amavis-services childproc-minder
Nov 20 10:24:23 mail amavis-mc[3920]: Process [3926] started: /opt/zimbra/common/sbin/amavis-services snmp-responder
Nov 20 10:24:23 mail amavis-services[3925]: amavis-services-2.9.0 (20140506) task 'childproc-minder' [3925] started. ZMQ::LibZMQ3 1.19, lib 4.1.4
Nov 20 10:24:23 mail amavis-services[3926]: amavis-services-2.9.0 (20140506) task 'snmp-responder' [3926] started. ZMQ::LibZMQ3 1.19, lib 4.1.4
Nov 20 10:24:23 mail amavis-services[3924]: amavis-services-2.9.0 (20140506) task 'msg-forwarder' [3924] started. ZMQ::LibZMQ3 1.19, lib 4.1.4
Nov 20 10:24:24 mail amavis-services[3925]: childproc_minder: FLUSH process states
Nov 20 10:24:25 mail amavis-services[3926]: snmp_responder: FLUSH snmp data
Nov 20 10:24:25 mail amavis-services[3925]: childproc_minder: FLUSH process states
Nov 20 10:24:25 mail amavis[3960]: Ignoring stale PID file /opt/zimbra/log/amavisd.pid, older than system uptime 0 0:01:00
Nov 20 10:24:25 mail amavis[3960]: starting. /opt/zimbra/common/sbin/amavisd at mail.abcdefg.com amavisd-new-2.10.1 (20141025), Unicode aware, LC_ALL="C", LANG="C"
Nov 20 10:24:25 mail amavis[3960]: perl=5.016003, user=997, EUID: 997 (997);  group=, EGID: 995 4 5 89 995 (995 4 5 89 995)
Nov 20 10:24:25 mail amavis[3960]: SpamControl: init_pre_chroot on SpamAssassin done
Nov 20 10:24:25 mail amavis[3960]: (!)Net::Server: 2017/11/20-10:24:25 Pid_file already exists for running process (3481)... aborting\n\n  at line 144 in file /opt/zimbra/common/lib/perl5/Net/Server.pm
Nov 20 10:24:25 mail amavis[3960]: Net::Server: 2017/11/20-10:24:25 Server closing!
Nov 20 10:24:54 mail zimbramon[1339]: 1339:info: Starting antispam via zmcontrol
Nov 20 10:24:54 mail zmconfigd[1431]: Fetching All configs
Nov 20 10:24:54 mail zmconfigd[1431]: All configs fetched in 0.04 seconds
Nov 20 10:24:54 mail zmconfigd[1431]: Tracking service amavis
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service antispam
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service antivirus
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service dnscache
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service dnscache now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service ldap
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service ldap now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service logger
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service logger now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service mailbox
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service mailbox now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service mailboxd
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service mailboxd now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service memcached
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service memcached now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service mta
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service mta now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service opendkim
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service proxy
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service proxy now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service sasl
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service sasl now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service service
Nov 20 10:24:56 mail zmconfigd[1431]: Watchdog: service service now available for watchdog.
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service snmp
Nov 20 10:24:56 mail zmconfigd[1431]: Tracking service spell
Nov 20 10:24:57 mail zmconfigd[1431]: Tracking service stats
Nov 20 10:24:57 mail zmconfigd[1431]: Tracking service zimbra
Nov 20 10:24:57 mail zmconfigd[1431]: Watchdog: service zimbra now available for watchdog.
Nov 20 10:24:57 mail zmconfigd[1431]: Tracking service zimbraAdmin
Nov 20 10:24:57 mail zmconfigd[1431]: Watchdog: service zimbraAdmin now available for watchdog.
Nov 20 10:24:57 mail zmconfigd[1431]: Tracking service zimlet
Nov 20 10:24:57 mail zmconfigd[1431]: Watchdog: service zimlet now available for watchdog.
Nov 20 10:24:57 mail zmconfigd[1431]: Watchdog: skipping service antivirus. Service not yet available for restarts.
Nov 20 10:24:57 mail zmconfigd[1431]: All rewrite threads completed in 0.00 sec
Nov 20 10:24:57 mail zmconfigd[1431]: All restarts completed in 0.00 sec
Nov 20 10:24:57 mail amavis-services[3926]: snmp_responder: FLUSH snmp data
Nov 20 10:24:57 mail amavis[4436]: Ignoring stale PID file /opt/zimbra/log/amavisd.pid, older than system uptime 0 0:02:00
Nov 20 10:24:57 mail amavis-services[3925]: childproc_minder: FLUSH process states
Nov 20 10:24:57 mail amavis[4436]: starting. /opt/zimbra/common/sbin/amavisd at mail.abcdefg.com amavisd-new-2.10.1 (20141025), Unicode aware, LC_ALL="C", LANG="C"
Nov 20 10:24:57 mail amavis[4436]: perl=5.016003, user=997, EUID: 997 (997);  group=, EGID: 995 4 5 89 995 (995 4 5 89 995)
Nov 20 10:24:57 mail amavis[4436]: SpamControl: init_pre_chroot on SpamAssassin done
Nov 20 10:24:57 mail amavis[4436]: (!)Net::Server: 2017/11/20-10:24:57 Pid_file already exists for running process (3481)... aborting\n\n  at line 144 in file /opt/zimbra/common/lib/perl5/Net/Server.pm
Nov 20 10:24:57 mail amavis[4436]: Net::Server: 2017/11/20-10:24:57 Server closing!
Nov 20 10:24:57 mail su: (to zimbra) root on pts/0
Nov 20 10:25:12 mail zimbramon[5255]: 5255:info: Stopping services initiated by zmcontrol
Nov 20 10:25:12 mail zimbramon[5255]: 5255:info: Stopping vmware-ha via zmcontrol
Nov 20 10:25:12 mail zimbramon[5255]: 5255:info: Stopping zmconfigd via zmcontrol
Nov 20 10:25:12 mail zmconfigd[1431]: Shutting down. Received signal 15
Nov 20 10:25:13 mail zimbramon[5255]: 5255:info: Stopping zimlet via zmcontrol
Nov 20 10:25:13 mail zmmailboxdmgr[5366]: stop requested
Nov 20 10:25:13 mail zmmailboxdmgr[5366]: waiting for manager process 3535 to die
Nov 20 10:25:13 mail zmmailboxdmgr[3535]: shutdown requested, sending TERM signal to 3536
Nov 20 10:25:17 mail zmmailboxdmgr[3535]: mailboxd/JVM process exited (waitpid expected 3536 got 3536)
Nov 20 10:25:17 mail zmmailboxdmgr[3535]: manager woke up from wait on mailboxd/JVM with pid 3536
Nov 20 10:25:18 mail zmmailboxdmgr[5366]: manager process 3535 died, shutdown completed
Nov 20 10:25:22 mail zimbramon[5255]: 5255:info: Stopping zimbraAdmin via zmcontrol
Nov 20 10:25:23 mail zmmailboxdmgr[5504]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Nov 20 10:25:23 mail zmmailboxdmgr[5504]: assuming no other instance is running
Nov 20 10:25:23 mail zmmailboxdmgr[5504]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:25:23 mail zmmailboxdmgr[5504]: assuming no other instance is running
Nov 20 10:25:23 mail zmmailboxdmgr[5504]: no manager process is running
Nov 20 10:25:23 mail zimbramon[5255]: 5255:info: Stopping zimbra via zmcontrol
Nov 20 10:25:23 mail zmmailboxdmgr[5529]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Nov 20 10:25:23 mail zmmailboxdmgr[5529]: assuming no other instance is running
Nov 20 10:25:23 mail zmmailboxdmgr[5529]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:25:23 mail zmmailboxdmgr[5529]: assuming no other instance is running
Nov 20 10:25:23 mail zmmailboxdmgr[5529]: no manager process is running
Nov 20 10:25:23 mail zimbramon[5255]: 5255:info: Stopping service via zmcontrol
Nov 20 10:25:23 mail zmmailboxdmgr[5554]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Nov 20 10:25:23 mail zmmailboxdmgr[5554]: assuming no other instance is running
Nov 20 10:25:23 mail zmmailboxdmgr[5554]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:25:23 mail zmmailboxdmgr[5554]: assuming no other instance is running
Nov 20 10:25:23 mail zmmailboxdmgr[5554]: no manager process is running
Nov 20 10:25:23 mail zimbramon[5255]: 5255:info: Stopping stats via zmcontrol
Nov 20 10:25:23 mail zimbramon[5255]: 5255:info: Stopping mta via zmcontrol
Nov 20 10:25:23 mail /postfix-script[5631]: fatal: the Postfix mail system is not running
Nov 20 10:25:24 mail zimbramon[5255]: 5255:info: Stopping spell via zmcontrol
Nov 20 10:25:24 mail zimbramon[5255]: 5255:info: Stopping snmp via zmcontrol
Nov 20 10:25:24 mail zimbramon[5255]: 5255:info: Stopping cbpolicyd via zmcontrol
Nov 20 10:25:24 mail zimbramon[5255]: 5255:info: Stopping archiving via zmcontrol
Nov 20 10:25:24 mail amavis-mc[3920]: Master process shutting down
Nov 20 10:25:24 mail amavis-mc[3920]: Terminating process [3924] (/opt/zimbra/common/sbin/amavis-services msg-forwarder)
Nov 20 10:25:24 mail amavis-mc[3920]: Terminating process [3925] (/opt/zimbra/common/sbin/amavis-services childproc-minder)
Nov 20 10:25:24 mail amavis-mc[3920]: Terminating process [3926] (/opt/zimbra/common/sbin/amavis-services snmp-responder)
Nov 20 10:25:24 mail amavis-services[3926]: Task 'snmp-responder' [3926] shutting down
Nov 20 10:25:24 mail amavis-services[3925]: Task 'childproc-minder' [3925] shutting down
Nov 20 10:25:24 mail amavis-services[3924]: Task 'msg-forwarder' [3924] shutting down
Nov 20 10:25:24 mail amavis-services[3926]: snmp-responder closing outer socket
Nov 20 10:25:24 mail amavis-services[3925]: childproc-minder closing inner socket
Nov 20 10:25:24 mail amavis-services[3924]: msg-forwarder closing inner socket
Nov 20 10:25:24 mail amavis-services[3926]: snmp-responder closing SNMP socket
Nov 20 10:25:24 mail amavis-services[3925]: childproc-minder closing outer socket
Nov 20 10:25:24 mail amavis-services[3924]: msg-forwarder closing outer socket
Nov 20 10:25:24 mail amavis-services[3926]: snmp-responder closing context
Nov 20 10:25:24 mail amavis-services[3925]: childproc-minder closing context
Nov 20 10:25:24 mail amavis-services[3924]: msg-forwarder closing context
Nov 20 10:25:24 mail amavis-services[3926]: Task 'snmp-responder' [3926] exiting: TERM
Nov 20 10:25:24 mail amavis-services[3925]: Task 'childproc-minder' [3925] exiting: TERM
Nov 20 10:25:24 mail amavis-services[3924]: Task 'msg-forwarder' [3924] exiting: TERM
Nov 20 10:25:24 mail amavis-mc[3920]: Process [3926] exited (/opt/zimbra/common/sbin/amavis-services snmp-responder) after 60.9 s: exit 0
Nov 20 10:25:24 mail amavis-mc[3920]: Process [3924] exited (/opt/zimbra/common/sbin/amavis-services msg-forwarder) after 60.9 s: exit 0
Nov 20 10:25:24 mail amavis-mc[3920]: Process [3925] exited (/opt/zimbra/common/sbin/amavis-services childproc-minder) after 60.9 s: exit 0
Nov 20 10:25:25 mail amavis-mc[3920]: Master process exiting: TERM
Nov 20 10:25:26 mail zimbramon[1339]: 1339:info: Starting antivirus via zmcontrol
Nov 20 10:25:26 mail amavis-mc[5718]: amavis master process starting. daemonized as PID [5718], perl 5.016003
Nov 20 10:25:26 mail amavis-mc[5718]: Process [5722] started: /opt/zimbra/common/sbin/amavis-services msg-forwarder
Nov 20 10:25:26 mail amavis-mc[5718]: Process [5723] started: /opt/zimbra/common/sbin/amavis-services childproc-minder
Nov 20 10:25:26 mail amavis-mc[5718]: Process [5724] started: /opt/zimbra/common/sbin/amavis-services snmp-responder
Nov 20 10:25:26 mail amavis-services[5723]: amavis-services-2.9.0 (20140506) task 'childproc-minder' [5723] started. ZMQ::LibZMQ3 1.19, lib 4.1.4
Nov 20 10:25:26 mail amavis-services[5724]: amavis-services-2.9.0 (20140506) task 'snmp-responder' [5724] started. ZMQ::LibZMQ3 1.19, lib 4.1.4
Nov 20 10:25:26 mail amavis-services[5722]: amavis-services-2.9.0 (20140506) task 'msg-forwarder' [5722] started. ZMQ::LibZMQ3 1.19, lib 4.1.4
Nov 20 10:25:27 mail amavis-services[5723]: childproc_minder: FLUSH process states
Nov 20 10:25:27 mail amavis-services[5724]: snmp_responder: FLUSH snmp data
Nov 20 10:25:27 mail amavis-services[5723]: childproc_minder: FLUSH process states
Nov 20 10:25:27 mail amavis[5729]: Ignoring stale PID file /opt/zimbra/log/amavisd.pid, older than system uptime 0 0:02:00
Nov 20 10:25:27 mail amavis[5729]: starting. /opt/zimbra/common/sbin/amavisd at mail.abcdefg.com amavisd-new-2.10.1 (20141025), Unicode aware, LC_ALL="C", LANG="C"
Nov 20 10:25:27 mail amavis[5729]: perl=5.016003, user=997, EUID: 997 (997);  group=, EGID: 995 4 5 89 995 (995 4 5 89 995)
Nov 20 10:25:27 mail amavis[5729]: SpamControl: init_pre_chroot on SpamAssassin done
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Process Backgrounded
Nov 20 10:25:27 mail amavis[5747]: Net::Server: 2017/11/20-10:25:27 Amavis (type Net::Server::PreForkSimple) starting! pid(5747)
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Binding to UNIX socket file "/opt/zimbra/data/amavisd/amavisd.sock"
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Binding to TCP port 10024 on host ::1 with IPv6
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Binding to TCP port 10026 on host 127.0.0.1 with IPv4
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Binding to TCP port 10026 on host ::1 with IPv6
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Binding to TCP port 10032 on host 127.0.0.1 with IPv4
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Binding to TCP port 10032 on host ::1 with IPv6
Nov 20 10:25:27 mail amavis[5747]: Net::Server: Group Not Defined.  Defaulting to EGID '995 4 5 89 995'
Nov 20 10:25:27 mail amavis[5747]: Net::Server: User Not Defined.  Defaulting to EUID '997'
Nov 20 10:25:27 mail amavis[5747]: Module Amavis::Conf        2.404
Nov 20 10:25:27 mail amavis[5747]: Module Archive::Zip        1.53
Nov 20 10:25:27 mail amavis[5747]: Module Compress::Raw::Zlib 2.069
Nov 20 10:25:27 mail amavis[5747]: Module Compress::Zlib      2.069
Nov 20 10:25:27 mail amavis[5747]: Module Crypt::OpenSSL::RSA 0.28
Nov 20 10:25:27 mail amavis[5747]: Module DB_File             1.835
Nov 20 10:25:27 mail amavis[5747]: Module Digest::MD5         2.52
Nov 20 10:25:27 mail amavis[5747]: Module Digest::SHA         5.85
Nov 20 10:25:27 mail amavis[5747]: Module Encode              2.51
Nov 20 10:25:27 mail amavis[5747]: Module File::LibMagic      1.15
Nov 20 10:25:27 mail amavis[5747]: Module File::Temp          0.2301
Nov 20 10:25:27 mail amavis[5747]: Module IO::Socket::INET6   2.72
Nov 20 10:25:27 mail amavis[5747]: Module IO::Socket::IP      0.37
Nov 20 10:25:27 mail amavis[5747]: Module MIME::Entity        5.507
Nov 20 10:25:27 mail amavis[5747]: Module MIME::Parser        5.507
Nov 20 10:25:27 mail amavis[5747]: Module MIME::Tools         5.507
Nov 20 10:25:27 mail amavis[5747]: Module Mail::DKIM::Signer  0.4
Nov 20 10:25:27 mail amavis[5747]: Module Mail::DKIM::Verifier 0.4
Nov 20 10:25:27 mail amavis[5747]: Module Mail::Header        2.14
Nov 20 10:25:27 mail amavis[5747]: Module Mail::Internet      2.14
Nov 20 10:25:27 mail amavis[5747]: Module Mail::SPF           v2.009
Nov 20 10:25:27 mail amavis[5747]: Module Mail::SpamAssassin  3.004001
Nov 20 10:25:27 mail amavis[5747]: Module Net::DNS            1.04
Nov 20 10:25:27 mail amavis[5747]: Module Net::LDAP           0.65
Nov 20 10:25:27 mail amavis[5747]: Module Net::LibIDN         0.12
Nov 20 10:25:27 mail amavis[5747]: Module Net::Server         2.008
Nov 20 10:25:27 mail amavis[5747]: Module NetAddr::IP         4.078
Nov 20 10:25:27 mail amavis[5747]: Module Scalar::Util        1.27
Nov 20 10:25:27 mail amavis[5747]: Module Socket              2.020
Nov 20 10:25:27 mail amavis[5747]: Module Socket6             0.23
Nov 20 10:25:27 mail amavis[5747]: Module Time::HiRes         1.9725
Nov 20 10:25:27 mail amavis[5747]: Module URI                 1.69
Nov 20 10:25:27 mail amavis[5747]: Module Unix::Getrusage     0.03
Nov 20 10:25:27 mail amavis[5747]: Module Unix::Syslog        1.1
Nov 20 10:25:27 mail amavis[5747]: Module ZMQ::LibZMQ3        1.19
Nov 20 10:25:27 mail amavis[5747]: Amavis::ZMQ code     loaded
Nov 20 10:25:27 mail amavis[5747]: Amavis::DB code      NOT loaded
Nov 20 10:25:27 mail amavis[5747]: SQL base code        NOT loaded
Nov 20 10:25:27 mail amavis[5747]: SQL::Log code        NOT loaded
Nov 20 10:25:27 mail amavis[5747]: SQL::Quarantine      NOT loaded
Nov 20 10:25:27 mail amavis[5747]: Lookup::SQL code     NOT loaded
Nov 20 10:25:27 mail amavis[5747]: Lookup::LDAP code    loaded
Nov 20 10:25:27 mail amavis[5747]: AM.PDP-in proto code loaded
Nov 20 10:25:27 mail amavis[5747]: SMTP-in proto code   loaded
Nov 20 10:25:27 mail amavis[5747]: Courier proto code   NOT loaded
Nov 20 10:25:27 mail amavis[5747]: SMTP-out proto code  loaded
Nov 20 10:25:27 mail amavis[5747]: Pipe-out proto code  NOT loaded
Nov 20 10:25:27 mail amavis[5747]: BSMTP-out proto code NOT loaded
Nov 20 10:25:27 mail amavis[5747]: Local-out proto code loaded
Nov 20 10:25:27 mail amavis[5747]: OS_Fingerprint code  NOT loaded
Nov 20 10:25:27 mail amavis[5747]: ANTI-VIRUS code      loaded
Nov 20 10:25:27 mail amavis[5747]: ANTI-SPAM code       loaded
Nov 20 10:25:27 mail amavis[5747]: ANTI-SPAM-EXT code   NOT loaded
Nov 20 10:25:27 mail amavis[5747]: ANTI-SPAM-C code     NOT loaded
Nov 20 10:25:27 mail amavis[5747]: ANTI-SPAM-SA code    loaded
Nov 20 10:25:27 mail amavis[5747]: Unpackers code       loaded
Nov 20 10:25:27 mail amavis[5747]: DKIM code            loaded
Nov 20 10:25:27 mail amavis[5747]: Tools code           NOT loaded
Nov 20 10:25:27 mail amavis[5747]: Found $file            at /usr/bin/file
Nov 20 10:25:27 mail amavis[5747]: No $altermime,         not using it
Nov 20 10:25:27 mail amavis[5747]: Internal decoder for .mail
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .F, tried: unfreeze, freeze -d, melt, fcat
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .Z    at /usr/bin/gzip -d
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .gz   at /usr/bin/gzip -d
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .bz2, tried: bzip2 -d
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .xz   at /usr/bin/xzdec
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .lzma at /usr/bin/xz -dc --format=lzma
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .lrz, tried: lrzip -q -k -d -o -, lrzcat -q -k
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .lzo, tried: lzop -d
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .rpm  at /usr/bin/rpm2cpio
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .cpio at /usr/bin/cpio
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .tar  at /usr/bin/cpio
Nov 20 10:25:27 mail amavis[5747]: Found decoder for    .deb  at /usr/bin/ar
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .rar, tried: unrar, rar
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .arj, tried: unarj, arj
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .arc, tried: nomarch, arc
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .zoo, tried: zoo, unzoo
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .doc, tried: ripole
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .cab, tried: cabextract
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .tnef, tried: tnef
Nov 20 10:25:27 mail amavis[5747]: Internal decoder for .tnef
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .zip, tried: 7za, 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .kmz, tried: 7za, 7z
Nov 20 10:25:27 mail amavis[5747]: Internal decoder for .zip
Nov 20 10:25:27 mail amavis[5747]: Internal decoder for .kmz
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .7z, tried: 7zr, 7za, 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .7z, tried: 7za, 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .bz2, tried: 7za, 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .jar, tried: 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .arj, tried: 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .rar, tried: 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .swf, tried: 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .lha, tried: 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .iso, tried: 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .cab, tried: 7z
Nov 20 10:25:27 mail amavis[5747]: No ext program for   .exe, tried: unrar, rar; lha; unarj, arj
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .7z
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .F
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .arc
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .arj
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .bz2
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .cab
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .doc
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .exe
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .iso
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .jar
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .lha
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .lrz
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .lzo
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .rar
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .swf
Nov 20 10:25:27 mail amavis[5747]: No decoder for       .zoo
Nov 20 10:25:27 mail amavis[5747]: Using primary internal av scanner code for ClamAV-clamd
Nov 20 10:25:27 mail amavis[5747]: initializing Mail::SpamAssassin (0)
Nov 20 10:25:28 mail amavis[5747]: SpamControl: init_pre_fork on SpamAssassin done
Nov 20 10:25:28 mail amavis[5747]: extra modules loaded after daemonizing/chrooting: /usr/share/perl5/Net/libnet.cfg, Mail/SpamAssassin/Plugin/FreeMail.pm, Mail/SpamAssassin/Plugin/SpamCop.pm, Net/Cmd.pm, Net/Config.pm, Net/SMTP.pm
Nov 20 10:25:28 mail clamd[5787]: Received 0 file descriptor(s) from systemd.
Nov 20 10:25:28 mail clamd[5787]: clamd daemon 0.99.2 (OS: linux-gnu, ARCH: x86_64, CPU: x86_64)
Nov 20 10:25:28 mail clamd[5787]: Log file size limited to 20971520 bytes.
Nov 20 10:25:28 mail clamd[5787]: Reading databases from /opt/zimbra/data/clamav/db
Nov 20 10:25:28 mail clamd[5787]: Not loading PUA signatures.
Nov 20 10:25:28 mail clamd[5787]: Bytecode: Security mode set to "TrustSigned".
Nov 20 10:25:29 mail zimbramon[5255]: 5255:info: Stopping opendkim via zmcontrol
Nov 20 10:25:29 mail zimbramon[5255]: 5255:info: Stopping amavis via zmcontrol
Nov 20 10:25:29 mail amavis[5747]: Net::Server: 2017/11/20-10:25:29 Server closing!
Nov 20 10:25:31 mail clamd[5787]: Loaded 4566324 signatures.
Nov 20 10:25:32 mail clamd[5787]: TCP: Bound to [127.0.0.1]:3310
Nov 20 10:25:32 mail clamd[5787]: TCP: Setting connection queue length to 200
Nov 20 10:25:32 mail clamd[5787]: LOCAL: Removing stale socket file /opt/zimbra/data/clamav/clamav.sock
Nov 20 10:25:32 mail clamd[5787]: LOCAL: Unix socket file /opt/zimbra/data/clamav/clamav.sock
Nov 20 10:25:32 mail clamd[5787]: LOCAL: Setting connection queue length to 200
Nov 20 10:25:32 mail clamd[5810]: Limits: Global size limit set to 102891520 bytes.
Nov 20 10:25:32 mail clamd[5810]: Limits: File size limit set to 102891520 bytes.
Nov 20 10:25:32 mail clamd[5810]: Limits: Recursion level limit set to 16.
Nov 20 10:25:32 mail clamd[5810]: Limits: Files limit set to 10000.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxEmbeddedPE limit set to 10485760 bytes.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxHTMLNormalize limit set to 10485760 bytes.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxHTMLNoTags limit set to 2097152 bytes.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxScriptNormalize limit set to 5242880 bytes.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxZipTypeRcg limit set to 1048576 bytes.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxPartitions limit set to 50.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxIconsPE limit set to 100.
Nov 20 10:25:32 mail clamd[5810]: Limits: MaxRecHWP3 limit set to 16.
Nov 20 10:25:32 mail clamd[5810]: Limits: PCREMatchLimit limit set to 10000.
Nov 20 10:25:32 mail clamd[5810]: Limits: PCRERecMatchLimit limit set to 5000.
Nov 20 10:25:32 mail clamd[5810]: Limits: PCREMaxFileSize limit set to 26214400.
Nov 20 10:25:32 mail clamd[5810]: Archive support enabled.
Nov 20 10:25:32 mail clamd[5810]: Archive: Blocking encrypted archives.
Nov 20 10:25:32 mail clamd[5810]: Algorithmic detection enabled.
Nov 20 10:25:32 mail clamd[5810]: Portable Executable support enabled.
Nov 20 10:25:32 mail clamd[5810]: ELF support enabled.
Nov 20 10:25:32 mail clamd[5810]: Mail files support enabled.
Nov 20 10:25:32 mail clamd[5810]: OLE2 support enabled.
Nov 20 10:25:32 mail clamd[5810]: PDF support enabled.
Nov 20 10:25:32 mail clamd[5810]: SWF support enabled.
Nov 20 10:25:32 mail clamd[5810]: HTML support enabled.
Nov 20 10:25:32 mail clamd[5810]: XMLDOCS support enabled.
Nov 20 10:25:32 mail clamd[5810]: HWP3 support enabled.
Nov 20 10:25:32 mail clamd[5810]: Self checking every 600 seconds.
Nov 20 10:25:33 mail zimbramon[1339]: 1339:info: Starting opendkim via zmcontrol
Nov 20 10:25:33 mail opendkim[5831]: OpenDKIM Filter v2.10.3 starting (args: -x /opt/zimbra/conf/opendkim.conf -u zimbra)
Nov 20 10:25:34 mail amavis-mc[5718]: Master process shutting down
Nov 20 10:25:34 mail amavis-mc[5718]: Terminating process [5722] (/opt/zimbra/common/sbin/amavis-services msg-forwarder)
Nov 20 10:25:34 mail amavis-mc[5718]: Terminating process [5723] (/opt/zimbra/common/sbin/amavis-services childproc-minder)
Nov 20 10:25:34 mail amavis-mc[5718]: Terminating process [5724] (/opt/zimbra/common/sbin/amavis-services snmp-responder)
Nov 20 10:25:34 mail amavis-services[5722]: Task 'msg-forwarder' [5722] shutting down
Nov 20 10:25:34 mail amavis-services[5722]: msg-forwarder closing inner socket
Nov 20 10:25:34 mail amavis-services[5723]: Task 'childproc-minder' [5723] shutting down
Nov 20 10:25:34 mail amavis-services[5722]: msg-forwarder closing outer socket
Nov 20 10:25:34 mail amavis-services[5724]: Task 'snmp-responder' [5724] shutting down
Nov 20 10:25:34 mail amavis-services[5723]: childproc-minder closing inner socket
Nov 20 10:25:34 mail amavis-services[5722]: msg-forwarder closing context
Nov 20 10:25:34 mail amavis-services[5724]: snmp-responder closing outer socket
Nov 20 10:25:34 mail amavis-services[5723]: childproc-minder closing outer socket
Nov 20 10:25:34 mail amavis-services[5723]: childproc-minder closing context
Nov 20 10:25:34 mail amavis-services[5724]: snmp-responder closing SNMP socket
Nov 20 10:25:34 mail amavis-services[5724]: snmp-responder closing context
Nov 20 10:25:34 mail amavis-services[5724]: Task 'snmp-responder' [5724] exiting: TERM
Nov 20 10:25:34 mail amavis-services[5722]: Task 'msg-forwarder' [5722] exiting: TERM
Nov 20 10:25:34 mail amavis-services[5723]: Task 'childproc-minder' [5723] exiting: TERM
Nov 20 10:25:34 mail amavis-mc[5718]: Process [5722] exited (/opt/zimbra/common/sbin/amavis-services msg-forwarder) after 8.1 s: exit 0
Nov 20 10:25:34 mail amavis-mc[5718]: Process [5723] exited (/opt/zimbra/common/sbin/amavis-services childproc-minder) after 8.1 s: exit 0
Nov 20 10:25:34 mail amavis-mc[5718]: Process [5724] exited (/opt/zimbra/common/sbin/amavis-services snmp-responder) after 8.1 s: exit 0
Nov 20 10:25:35 mail amavis-mc[5718]: Master process exiting: TERM
Nov 20 10:25:35 mail zimbramon[1339]: 1339:info: Starting snmp via zmcontrol
Nov 20 10:25:35 mail zimbramon[1339]: 1339:info: Starting spell via zmcontrol
Nov 20 10:25:35 mail zimbramon[1339]: 1339:info: Starting mta via zmcontrol
Nov 20 10:25:35 mail saslauthd[5962]: detach_tty      : master pid is: 5962
Nov 20 10:25:35 mail saslauthd[5962]: ipc_init        : listening on socket: /opt/zimbra/data/sasl2/state/mux
Nov 20 10:25:36 mail /postfix-script[6062]: starting the Postfix mail system
Nov 20 10:25:36 mail postfix/master[6064]: daemon started -- version 3.1.1, configuration /opt/zimbra/common/conf
Nov 20 10:25:36 mail zimbramon[1339]: 1339:info: Starting stats via zmcontrol
Nov 20 10:25:36 mail postfix/qmgr[6066]: 085741F21817: from=<cloud@abcdefg.de>, size=5994, nrcpt=1 (queue active)
Nov 20 10:25:36 mail zimbramon[1339]: 1339:info: Starting service via zmcontrol
Nov 20 10:25:38 mail clamd[5810]: Reading databases from /opt/zimbra/data/clamav/db
Nov 20 10:25:39 mail zimbramon[5255]: 5255:info: Stopping antivirus via zmcontrol
Nov 20 10:25:40 mail zmmailboxdmgr[7362]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Nov 20 10:25:40 mail zmmailboxdmgr[7362]: assuming no other instance is running
Nov 20 10:25:40 mail zmmailboxdmgr[7362]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:25:40 mail zmmailboxdmgr[7362]: assuming no other instance is running
Nov 20 10:25:40 mail zmmailboxdmgr[7362]: no manager process is running
Nov 20 10:25:40 mail zmmailboxdmgr[7373]: start requested
Nov 20 10:25:40 mail zmmailboxdmgr[7373]: checking if another instance of manager is already running
Nov 20 10:25:40 mail zmmailboxdmgr[7373]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Nov 20 10:25:40 mail zmmailboxdmgr[7373]: assuming no other instance is running
Nov 20 10:25:40 mail zmmailboxdmgr[7373]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Nov 20 10:25:40 mail zmmailboxdmgr[7373]: assuming no other instance is running
Nov 20 10:25:40 mail zmmailboxdmgr[7374]: wrote manager pid 7374 to /opt/zimbra/log/zmmailboxd_manager.pid
Nov 20 10:25:40 mail zmmailboxdmgr[7374]: manager started mailboxd/JVM with pid 7375
Nov 20 10:25:40 mail zmmailboxdmgr[7375]: wrote java pid 7375 to /opt/zimbra/log/zmmailboxd_java.pid
Nov 20 10:25:42 mail zimbramon[1339]: 1339:info: Starting zimbra via zmcontrol
Nov 20 10:25:42 mail zimbramon[1339]: 1339:info: Starting zimbraAdmin via zmcontrol
Nov 20 10:25:42 mail zimbramon[1339]: 1339:info: Starting zimlet via zmcontrol
Nov 20 10:25:44 mail postfix/postscreen[7454]: CONNECT from [203.166.201.3]:2572 to [88.99.136.142]:25
Nov 20 10:25:45 mail clamd[5810]: Database correctly reloaded (6345531 signatures)
Nov 20 10:25:45 mail clamd[5810]: Pid file removed.
Nov 20 10:25:45 mail clamd[5810]: --- Stopped at Mon Nov 20 10:25:45 2017
Nov 20 10:25:45 mail clamd[5810]: Socket file removed.
Nov 20 10:25:47 mail zimbramon[5255]: 5255:info: Stopping antispam via zmcontrol
Nov 20 10:25:49 mail postfix/submission/smtpd[6147]: connect from static.208.20.251.148.clients.your-server.de[148.251.20.208]
Nov 20 10:25:49 mail saslauthd[5964]: zmauth: authenticating against elected url 'https://mail.abcdefg.com:7073/service/admin/soap/' ...
Nov 20 10:25:50 mail zimbramon[5255]: 5255:info: Stopping proxy via zmcontrol
Nov 20 10:25:50 mail postfix/postscreen[7454]: PASS NEW [203.166.201.3]:2572
Nov 20 10:25:50 mail postfix/smtpd[7455]: connect from unknown[203.166.201.3]
Nov 20 10:25:51 mail zimbramon[5255]: 5255:info: Stopping memcached via zmcontrol
Nov 20 10:25:51 mail postfix/smtpd[7455]: disconnect from unknown[203.166.201.3] ehlo=1 mail=1 rcpt=0/1 data=0/1 quit=1 commands=3/5
Nov 20 10:25:52 mail zimbramon[5255]: 5255:info: Stopping mailbox via zmcontrol
Nov 20 10:25:52 mail zmmailboxdmgr[7972]: stop requested
Nov 20 10:25:52 mail zmmailboxdmgr[7972]: waiting for manager process 7374 to die
Nov 20 10:25:52 mail zmmailboxdmgr[7374]: shutdown requested, sending TERM signal to 7375
Nov 20 10:25:52 mail saslauthd[5964]: authentication against url 'https://mail.abcdefg.com:7073/service/admin/soap/' caused error 'curl_easy_perform: error(35): Unknown SSL protocol error in connection to mail.abcdefg.com:7073 '
Nov 20 10:25:52 mail saslauthd[5964]: url 'https://mail.abcdefg.com:7073/service/admin/soap/' will not be used for (at least) 600 seconds
Nov 20 10:25:52 mail saslauthd[5964]: Authentication cycle re-elected url https://mail.abcdefg.com:7073/service/admin/soap/, giving up ...
Nov 20 10:25:52 mail saslauthd[5964]: auth_zimbra: cloud@abcdefg.de auth failed: curl_easy_perform: error(35): Unknown SSL protocol error in connection to mail.abcdefg.com:7073
Nov 20 10:25:52 mail saslauthd[5964]: do_auth         : auth failure: [user=cloud@abcdefg.de] [service=smtp] [realm=abcdefg.de] [mech=zimbra] [reason=Unknown]
Nov 20 10:25:52 mail postfix/submission/smtpd[6147]: warning: static.208.20.251.148.clients.your-server.de[148.251.20.208]: SASL LOGIN authentication failed: authentication failure
Nov 20 10:25:52 mail postfix/submission/smtpd[6147]: disconnect from static.208.20.251.148.clients.your-server.de[148.251.20.208] ehlo=1 auth=0/1 quit=1 commands=2/3
Nov 20 10:25:53 mail zmmailboxdmgr[7374]: mailboxd/JVM process exited (waitpid expected 7375 got 7375)
Nov 20 10:25:53 mail zmmailboxdmgr[7374]: manager woke up from wait on mailboxd/JVM with pid 7375
Nov 20 10:25:54 mail zmmailboxdmgr[7972]: manager process 7374 died, shutdown completed
Nov 20 10:25:58 mail zimbramon[5255]: 5255:info: Stopping convertd via zmcontrol
Nov 20 10:25:58 mail zimbramon[5255]: 5255:info: Stopping logger via zmcontrol
Nov 20 10:25:59 mail postfix/submission/smtpd[6147]: connect from static.208.20.251.148.clients.your-server.de[148.251.20.208]
Nov 20 10:25:59 mail saslauthd[5967]: zmauth: authenticating against elected url 'https://mail.abcdefg.com:7073/service/admin/soap/' ...
Nov 20 10:25:59 mail saslauthd[5967]: authentication against url 'https://mail.abcdefg.com:7073/service/admin/soap/' caused error 'curl_easy_perform: error(7): Failed to connect to mail.abcdefg.com port 7073: Connection refused'
Nov 20 10:25:59 mail saslauthd[5967]: url 'https://mail.abcdefg.com:7073/service/admin/soap/' will not be used for (at least) 600 seconds
Nov 20 10:25:59 mail saslauthd[5967]: Authentication cycle re-elected url https://mail.abcdefg.com:7073/service/admin/soap/, giving up ...
Nov 20 10:25:59 mail saslauthd[5967]: auth_zimbra: cloud@abcdefg.de auth failed: curl_easy_perform: error(7): Failed to connect to mail.abcdefg.com port 7073: Connection refused
Nov 20 10:25:59 mail saslauthd[5967]: do_auth         : auth failure: [user=cloud@abcdefg.de] [service=smtp] [realm=abcdefg.de] [mech=zimbra] [reason=Unknown]
Nov 20 10:25:59 mail postfix/submission/smtpd[6147]: warning: static.208.20.251.148.clients.your-server.de[148.251.20.208]: SASL LOGIN authentication failed: authentication failure
Nov 20 10:25:59 mail postfix/submission/smtpd[6147]: disconnect from static.208.20.251.148.clients.your-server.de[148.251.20.208] ehlo=1 auth=0/1 quit=1 commands=2/3
Nov 20 10:29:20 mail postfix/scache[7209]: statistics: start interval Nov 20 10:25:38
Post Reply