Zimbra offers Open Source email server software and shared calendar for Linux and the Mac
Go Back   Zimbra :: Forums > Zimbra Collaboration Suite > Administrators

Welcome to the Zimbra :: Forums!
Welcome, if you would like to post a comment please register. We also encourage you to explore all things Zimbra with our team and members of the community.

Reply
 
LinkBack Thread Tools Search this Thread Display Modes
  #1 (permalink)  
Old 07-20-2007, 10:25 AM
Member
 
Posts: 13
Default Zimbra servers shut down every morning at 3am

Since upgrading from 4.5.4 to 4.5.6, the zimbra services (all of them) shut down every morning at 3:01.

Could be the same issue as this forum post

The server stays up and is accessible via SSH. Uptime shows that it didn't reboot. I issue a simple zmcontrol start and everything comes back online like normal and functions without error all day long.

I saw in the zimbra user crontab that zmpurgemessages was running at 3am so I changed it to run later to determine if it was the problem - the services still shut down at 3am.

It's a pretty new machine - Dual Xeon quad cores, 8GB RAM, 925GB RAID.

This server was running 4.5.4 for several months without any issues. Issue appeared a couple days after the upgrade to 4.5.6.

The catalina.out log is small.
Code:
[root@mailhost log]# ls -lah /opt/zimbra/tomcat/logs/catalina.out
-rw-rw-rw-  1 zimbra zimbra 259K Jul 20 09:12 /opt/zimbra/tomcat/logs/catalina.out
/opt/zimbra/tomcat/logs/catalina.out
Code:
[tomcat launcher] got signal SIGTERM invoking stop
Jul 20, 2007 3:01:58 AM org.apache.coyote.http11.Http11BaseProtocol pause
INFO: Pausing Coyote HTTP/1.1 on http-80
Jul 20, 2007 3:01:58 AM org.apache.coyote.http11.Http11BaseProtocol pause
INFO: Pausing Coyote HTTP/1.1 on http-443
Jul 20, 2007 3:01:58 AM org.apache.coyote.http11.Http11BaseProtocol pause
INFO: Pausing Coyote HTTP/1.1 on http-7071
Jul 20, 2007 3:01:59 AM org.apache.catalina.core.StandardService stop
INFO: Stopping service Catalina
Jul 20, 2007 3:02:10 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 39 instance(s) to be deallocated
Jul 20, 2007 3:02:11 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 39 instance(s) to be deallocated
Jul 20, 2007 3:02:12 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 39 instance(s) to be deallocated
Jul 20, 2007 3:02:12 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 8 instance(s) to be deallocated
Jul 20, 2007 3:02:13 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 8 instance(s) to be deallocated
Jul 20, 2007 3:02:14 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 8 instance(s) to be deallocated
Jul 20, 2007 3:02:14 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 2 instance(s) to be deallocated
Jul 20, 2007 3:02:15 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 2 instance(s) to be deallocated
Jul 20, 2007 3:02:16 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 2 instance(s) to be deallocated
Jul 20, 2007 3:02:17 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 8 instance(s) to be deallocated
log4j:ERROR Error occured while converting date.
java.lang.NullPointerException
        at java.lang.System.arraycopy(Native Method)
        at java.lang.AbstractStringBuilder.getChars(AbstractStringBuilder.java:331)
        at java.lang.StringBuffer.getChars(StringBuffer.java:202)
        at org.apache.log4j.helpers.ISO8601DateFormat.format(ISO8601DateFormat.java:120)
        at java.text.DateFormat.format(DateFormat.java:314)
        at org.apache.log4j.helpers.PatternParser$DatePatternConverter.convert(PatternParser.java:436)
        at org.apache.log4j.helpers.PatternConverter.format(PatternConverter.java:56)
        at org.apache.log4j.PatternLayout.format(PatternLayout.java:495)
        at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:292)
        at org.apache.log4j.DailyRollingFileAppender.subAppend(DailyRollingFileAppender.java:349)
        at org.apache.log4j.WriterAppender.append(WriterAppender.java:150)
        at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221)
        at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57)
        at org.apache.log4j.Category.callAppenders(Category.java:187)
        at org.apache.log4j.Category.forcedLog(Category.java:372)
        at org.apache.log4j.Category.log(Category.java:864)
        at org.apache.commons.logging.impl.Log4JLogger.error(Log4JLogger.java:192)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:260)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
        at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
        at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
        at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
        at java.lang.Thread.run(Thread.java:595)
Jul 20, 2007 3:02:18 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 8 instance(s) to be deallocated
Jul 20, 2007 3:02:19 AM org.apache.catalina.core.StandardWrapper unload
INFO: Waiting for 8 instance(s) to be deallocated
/var/log/zimbra.log
Code:
Jul 20 03:01:02 mailhost slapd[4555]: is_entry_objectclass("", "2.5.6.1") no objectClass attribute
Jul 20 03:01:48 mailhost saslauthd[6786]: server_exit     : master exited: 6786
Jul 20 03:01:48 mailhost slapd[4555]: daemon: shutdown requested and initiated.
Jul 20 03:01:48 mailhost slapd[4555]: slapd shutdown: waiting for 0 threads to terminate
Jul 20 03:01:48 mailhost slapd[4555]: slapd stopped.
Jul 20 03:01:53 mailhost amavis[7338]: Net::Server: 2007/07/20-03:01:53 Server closing!
Jul 20 03:01:56 mailhost zmtomcatmgr[10209]: threaddump requested
Jul 20 03:01:56 mailhost zmtomcatmgr[6263]: sending SIQUIT to tomcat/JVM process 6264
Jul 20 03:01:58 mailhost zmtomcatmgr[10216]: stop requested
Jul 20 03:01:58 mailhost zmtomcatmgr[10216]: waiting for manager process 6263 to die
Jul 20 03:01:58 mailhost zmtomcatmgr[6263]: shutdown requested, sending TERM signal to 6264
Jul 20 03:02:22 mailhost zmtomcatmgr[6263]: tomcat/JVM process exited (waitpid expected 6264 got 6264)
Jul 20 03:02:22 mailhost zmtomcatmgr[6263]: manager woke up from wait on tomcat/JVM with pid 6264
Jul 20 03:02:23 mailhost zmtomcatmgr[10216]: manager process 6263 died, shutdown completed
Jul 20 03:02:28 mailhost zmtomcatmgr[10277]: status requested
Jul 20 03:02:28 mailhost zmtomcatmgr[10277]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 20 03:02:28 mailhost zmtomcatmgr[10277]: assuming no other instance is running
Jul 20 03:02:28 mailhost zmtomcatmgr[10277]: no manager process is running
Jul 20 03:02:28 mailhost zmtomcatmgr[10278]: status requested
Jul 20 03:02:28 mailhost zmtomcatmgr[10278]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 20 03:02:28 mailhost zmtomcatmgr[10278]: assuming no other instance is running
Jul 20 03:02:28 mailhost zmtomcatmgr[10278]: no manager process is running
Jul 20 03:02:28 mailhost postfix/postfix-script: stopping the Postfix mail system
Jul 20 03:02:28 mailhost postfix/master[6740]: terminating on signal 15
Jul 20 03:02:33 mailhost zmtomcatmgr[10432]: threaddump requested
Jul 20 03:02:33 mailhost zmtomcatmgr[10432]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 20 03:02:33 mailhost zmtomcatmgr[10432]: assuming no other instance is running
Jul 20 03:02:33 mailhost zmtomcatmgr[10432]: no manager process is running
Jul 20 03:02:35 mailhost zmtomcatmgr[10440]: stop requested
Jul 20 03:02:35 mailhost zmtomcatmgr[10440]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 20 03:02:35 mailhost zmtomcatmgr[10440]: assuming no other instance is running
Jul 20 03:02:35 mailhost zmtomcatmgr[10440]: no manager process is running
Jul 20 03:02:40 mailhost zmtomcatmgr[10442]: status requested
Jul 20 03:02:40 mailhost zmtomcatmgr[10442]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 20 03:02:40 mailhost zmtomcatmgr[10442]: assuming no other instance is running
Jul 20 03:02:40 mailhost zmtomcatmgr[10442]: no manager process is running
Jul 20 03:02:40 mailhost zmtomcatmgr[10443]: status requested
Jul 20 03:02:40 mailhost zmtomcatmgr[10443]: file /opt/zimbra/log/zmtomcatmgr.pid does not exist
Jul 20 03:02:40 mailhost zmtomcatmgr[10443]: assuming no other instance is running
Jul 20 03:02:40 mailhost zmtomcatmgr[10443]: no manager process is running
Jul 20 03:02:43 mailhost zimbramon[10219]: 10219:info: 2007-07-20 03:02:01, STATUS: : Cannot: determine
Jul 20 03:02:43 mailhost sendmail[10248]: l6KA2bdR010248: from=zimbra, size=869, class=0, nrcpts=1, msgid=<200707201002.l6KA2bdR010248@mailhost.fhi.net>, rel
ay=zimbra@localhost
Jul 20 03:02:43 mailhost sendmail[10248]: l6KA2bdR010248: to=zimbra, ctladdr=zimbra (502/502), delay=00:00:06, xdelay=00:00:00, mailer=relay, pri=30869, rela
y=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
/var/log/secure
Code:
Jul 20 02:50:03 mailhost sudo:   zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 02:52:03 mailhost sudo:   zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 02:54:04 mailhost sudo:   zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 02:56:03 mailhost sudo:   zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 02:58:04 mailhost sudo:   zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 03:00:03 mailhost sudo:   zimbra : TTY=unknown ; PWD=/opt/zimbra ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 03:01:56 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr threaddump
Jul 20 03:01:58 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr stop
Jul 20 03:02:28 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 03:02:28 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 03:02:28 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/postfix-2.2.9/sbin/postalias /etc/aliases
Jul 20 03:02:28 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/postfix-2.2.9/sbin/postfix stop norewrite
Jul 20 03:02:33 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr threaddump
Jul 20 03:02:35 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr stop
Jul 20 03:02:40 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
Jul 20 03:02:40 mailhost sudo:   zimbra : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/opt/zimbra/libexec/zmtomcatmgr status
/var/log/messages
Code:
Jul 20 03:01:48 mailhost saslauthd[6786]: server_exit     : master exited: 6786
Jul 20 03:01:53 mailhost amavis[7338]: Net::Server: 2007/07/20-03:01:53 Server closing!
Jul 20 03:02:43 mailhost zimbramon[10219]: 10219:info: 2007-07-20 03:02:01, STATUS: : Cannot: determine
Jul 20 03:04:02 mailhost zimbramon[10445]: 10445:info: 2007-07-20 03:04:01, STATUS: : Cannot: determine
Jul 20 03:06:03 mailhost zimbramon[10498]: 10498:info: 2007-07-20 03:06:01, STATUS: : Cannot: determine
Jul 20 03:08:02 mailhost zimbramon[10551]: 10551:info: 2007-07-20 03:08:01, STATUS: : Cannot: determine
I'm getting tired of jumping out of bed at 3am to restart the services. Any help is warmly welcome.
Reply With Quote
  #2 (permalink)  
Old 07-23-2007, 08:50 AM
Member
 
Posts: 13
Default Stopgap measure

Until a resolution is found - I've added another cron job for 3:05am to start the Zimbra service and adjusted my network monitoring software to wait 10 minutes until it alerts me that the Zimbra services are down.

So I'm getting all my beauty sleep again but am still going to need a resolution to this.
Reply With Quote
  #3 (permalink)  
Old 08-06-2007, 02:00 PM
Member
 
Posts: 13
Default zmfixperms does the trick

Perhaps it was just our installation but I've found two things when upgrading from 4.5.4 to 4.5.6 on RedHat4-64bit...

1. You have to undeploy and redeploy all zimlets to get them to show up and work. (This should be in the documentation)
2. You have to run zmfixperms as root after the upgrade to keep the zimbra services from dying at 3am every morning.

Took many hours to find these gems. Hopefully this post will help someone else.
Reply With Quote
Reply


Thread Tools Search this Thread
Search this Thread:

Advanced Search
Display Modes


Similar Threads

Why Join?

Registering let's you ask questions, makes it easier to search, displays any files attached to posts, and notifies you about replies.

blog.zimbra.com




 

SEO by vBSEO ©2011, Crawlability, Inc.