Results 1 to 6 of 6

Thread: MTA Going Down After Full Backup

  1. #1
    jpsinacola is offline Intermediate Member
    Join Date
    Nov 2010
    Location
    Michigan
    Posts
    19
    Rep Power
    4

    Default MTA Going Down After Full Backup

    I am trying to troubleshoot a problem with my installation, specifically the MTA service going down on Saturday morning, during which I presume my full backup. It does it every Friday night / Saturday morning and I need to start services and it comes backup up without any problems. I have looked through the logs and I found that the full backup completes. I guess my first question is, does the MTA shut down during full backup? In the log, after it gives the backup detail, says ExceptionID:btpool10-54701:myserver/soap/sendmsgrequest: messageID
    Code:mail.TRY_AGAIN.

    I can post more of log if needed, but was wondering if anyone else had experienced that problem?

    Thanks!

  2. #2
    phoenix is online now Zimbra Consultant & Moderator
    Join Date
    Sep 2005
    Location
    Vannes, France
    Posts
    23,582
    Rep Power
    57

    Default

    Quote Originally Posted by jpsinacola View Post
    I guess my first question is, does the MTA shut down during full backup?
    No, the MTA doesn't shutdown after any sort of backup.

    Quote Originally Posted by jpsinacola View Post
    In the log, after it gives the backup detail, says ExceptionID:btpool10-54701:myserver/soap/sendmsgrequest: messageID
    Code:mail.TRY_AGAIN.

    I can post more of log if needed, but was wondering if anyone else had experienced that problem?
    You need to post more details from the log files after the moment the backup finishes to to the time after the MTA shuts down (I assume you're seeing a shutdown in the log files?).
    Regards


    Bill


    Acompli: A new adventure for Co-Founder KevinH.

  3. #3
    jpsinacola is offline Intermediate Member
    Join Date
    Nov 2010
    Location
    Michigan
    Posts
    19
    Rep Power
    4

    Default

    Thanks for that info Bill, that helps a lot. So something is knocking that service offline then. I am not seeing a specific instance where it shuts down, I just see that mail.TRY_AGAIN. I am looking for more information from the MTA service itself. Here is more from the log:

    Code:
    2011-10-29 02:19:42,882 INFO  [FullBackupThread] [] backup - full backup took 4778054 millisec
    2011-10-29 00:00:04,153 INFO  [btpool0-54574://localhost:7071/service/admin/soap/AuthRequest] [ip=127.
    0.0.1;ua=zmprov/7.1.1_GA_3196;] soap - AuthRequest
    2011-10-29 00:00:04,178 INFO  [btpool0-54575://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    e=dkcornett@mymail.com;mid=100;ip=10.99.0.60;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - WaitS
    etRequest
    2011-10-29 00:00:04,215 INFO  [btpool0-54574://localhost:7071/service/admin/soap/GetAllServersRequest]
     [name=zimbra;ip=127.0.0.1;ua=zmprov/7.1.1_GA_3196;] soap - GetAllServersRequest
    2011-10-29 00:00:04,444 INFO  [btpool0-54574://localhost:7071/service/admin/soap/AuthRequest] [ip=127.
    0.0.1;ua=zmbackup/7.1.1_GA_3196;] soap - AuthRequest
    2011-10-29 00:00:04,535 INFO  [btpool0-54574://localhost:7071/service/admin/soap/BackupRequest] [name=
    zimbra;ip=127.0.0.1;ua=zmbackup/7.1.1_GA_3196;] soap - BackupRequest
    2011-10-29 00:00:04,538 INFO  [btpool0-54574://localhost:7071/service/admin/soap/BackupRequest] [name=
    zimbra;ip=127.0.0.1;ua=zmbackup/7.1.1_GA_3196;] backup - Backup request started
    2011-10-29 00:00:04,541 INFO  [btpool0-54574://localhost:7071/service/admin/soap/BackupRequest] [name=
    zimbra;ip=127.0.0.1;ua=zmbackup/7.1.1_GA_3196;] backup - deleting backups on or older than Thu Sep 29
    00:00:04 EDT 2011
    2011-10-29 00:00:04,665 INFO  [btpool0-54574://localhost:7071/service/admin/soap/BackupRequest] [name=
    zimbra;ip=127.0.0.1;ua=zmbackup/7.1.1_GA_3196;] backup - deleting backup incr-20110928.050005.088
    2011-10-29 00:00:04,667 INFO  [btpool0-54574://localhost:7071/service/admin/soap/BackupRequest] [name=
    zimbra;ip=127.0.0.1;ua=zmbackup/7.1.1_GA_3196;] backup - Backup request finished
    2011-10-29 00:00:04,667 INFO  [BackupDeletion] [] backup - Starting deletion of 1 old backups
    2011-10-29 00:00:04,667 INFO  [BackupDeletion] [] backup - Deleting old backup directory /opt/zimbra/b
    ackup/sessions/TO_DELETE-incr-20110928.050005.088
    2011-10-29 00:00:05,423 INFO  [Timer-Zimbra] [] session - WaitSet sweeper: 2 active WaitSets (2 accoun
    ts) - 0 sets with blocked callbacks
    2011-10-29 00:00:05,859 INFO  [BackupDeletion] [] backup - Finished deletion of 1 old backups
    2011-10-29 00:00:05,923 INFO  [btpool0-54574://mail1.mymail.com/service/soap/NoOpRequest] [name=m
    herron@mymail.com;mid=112;ip=69.246.24.154;ua=ZimbraWebClient - IE7 (Win)/7.1.1_GA_3196;] soap -
    NoOpRequest
    2011-10-29 00:00:06,455 INFO  [Timer-Zimbra] [] SessionCache - Removed 1 idle sessions (ADMIN). 15 act
    ive sessions remain.
    2011-10-29 00:00:14,766 INFO  [btpool0-54574://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    e=blang@mymail.com;mid=69;ip=10.3.0.15;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - WaitSetRequ
    est
    2011-10-29 00:00:16,622 INFO  [btpool0-54576://mail1.mymail.com/service/soap/NoOpRequest] [name=s
    kimble@mymail.com;mid=65;ip=10.8.0.28;ua=ZimbraWebClient - IE8 (Win)/7.1.1_GA_3196;] soap - NoOpR
    equest
    2011-10-29 00:00:23,233 INFO  [btpool0-54574://mail1.mymail.com/service/soap/NoOpRequest] [name=b
    scally@mymail.com;mid=70;ip=10.99.0.39;ua=ZimbraWebClient - IE7 (Win)/7.1.1_GA_3196;] soap - NoOp
    Request
    2011-10-29 00:00:34,971 WARN  [btpool0-54574] [] log - SSL renegotiate denied: java.nio.channels.Socke
    tChannel[connected local=/10.99.0.73:443 remote=/174.255.68.118:37616]
    2011-10-29 00:00:39,089 INFO  [MailboxPurge] [name=dhood@mymail.com;mid=99;] purge - Purging mess
    ages.
    2011-10-29 00:01:01,475 INFO  [btpool0-54574://mail1.mymail.com/service/soap/NoOpRequest] [name=g
    kilby@mymail.com;mid=104;ip=75.39.8.226;ua=ZimbraWebClient - IE8 (Win)/7.1.1_GA_3196;] soap - NoO
    pRequest
    2011-10-29 00:01:05,423 INFO  [Timer-Zimbra] [] session - WaitSet sweeper: 2 active WaitSets (2 accoun
    ts) - 1 sets with blocked callbacks
    2011-10-29 00:01:09,181 INFO  [btpool0-54574://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    e=dkcornett@mymail.com;mid=100;ip=10.99.0.60;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - WaitS
    etRequest
    2011-10-29 00:01:19,754 INFO  [btpool0-54574://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    e=blang@mymail.com;mid=69;ip=10.3.0.15;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - WaitSetRequ
    est
    2011-10-29 00:01:39,156 INFO  [MailboxPurge] [name=dkcornett@mymail.com;mid=100;] purge - Purging
    /4778054
    ...skipping
    2011-10-29 02:19:42,882 INFO  [FullBackupThread] [] backup - full backup took 4778054 millisec
    2011-10-29 02:19:53,157 INFO  [btpool0-54701://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    e=dkcornett@mymail.com;mid=100;ip=10.99.0.60;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - WaitS
    etRequest
    2011-10-29 02:20:03,934 INFO  [btpool0-54701://localhost:7071/service/admin/soap/AuthRequest] [ip=127.
    0.0.1;ua=zmprov/7.1.1_GA_3196;] soap - AuthRequest
    2011-10-29 02:20:03,992 INFO  [btpool0-54701://localhost:7071/service/admin/soap/GetAllServersRequest]
     [name=zimbra;ip=127.0.0.1;ua=zmprov/7.1.1_GA_3196;] soap - GetAllServersRequest
    2011-10-29 02:20:05,438 INFO  [Timer-Zimbra] [] session - WaitSet sweeper: 2 active WaitSets (2 accoun
    ts) - 1 sets with blocked callbacks
    2011-10-29 02:20:06,827 INFO  [btpool0-54701://mail1.mymail.com/service/upload?fmt=raw] [name=cru
    ssell@mymail.com;mid=39;ip=24.231.147.200;ua=Jakarta Commons-HttpClient/3.1;] FileUploadServlet -
     Received plain: Upload: { accountId=a9287dba-93d2-4244-89a6-ef1fff84f4ff, time=Sat Oct 29 02:20:06 ED
    T 2011, size=2484, uploadId=cee5f9fe-787c-4987-b717-fa9418375e8f:76d60598-8ae0-4ad4-99b6-32fccc7dd88a,
     name=msg-1073746026, path=null }
    2011-10-29 02:20:06,869 INFO  [btpool0-54701://mail1.mymail.com/service/soap/SendMsgRequest] [nam
    e=crussell@mymail.com;mid=39;ip=24.231.147.200;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - Sen
    dMsgRequest
    2011-10-29 02:20:06,918 INFO  [MailboxPurge] [name=tcunningham@mymail.com;mid=88;] purge - Purgin
    g messages.
    2011-10-29 02:20:07,608 INFO  [Timer-Zimbra] [] FileUploadServlet - 2 pending file uploads
    2011-10-29 02:20:11,371 INFO  [btpool0-54701://mail1.mymail.com/service/soap/SendMsgRequest] [nam
    e=crussell@mymail.com;mid=39;ip=24.231.147.200;ua=Zimbra Desktop/7.1.2_10978_Windows;] SoapEngine
     - handler exception
    com.zimbra.cs.mailbox.MailServiceException: try again: message send already in progress: c19870d8-75f5
    -4a34-9c47-088d9077e1ea
    ExceptionId:btpool0-54701://mail1.mymail.com/service/soap/SendMsgRequest:1319869211370:dcffa0a146
    d4baba
    Code:mail.TRY_AGAIN
     at com.zimbra.cs.mailbox.MailServiceException.TRY_AGAIN(MailServiceException.java:475)
     at com.zimbra.cs.service.mail.SendMsg.handle(SendMsg.java:142)
     at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:412)
     at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:287)
     at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:158)
     at com.zimbra.soap.SoapServlet.doWork(SoapServlet.java:294)
     at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:215)
     at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
     at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:208)
     at javax.servlet.http.HttpServlet.service(HttpServlet.java:814)
     at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
     at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
     at com.zimbra.cs.servlet.SetHeaderFilter.doFilter(SetHeaderFilter.java:79)
     at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
     at org.mortbay.servlet.UserAgentFilter.doFilter(UserAgentFilter.java:81)
     at org.mortbay.servlet.GzipFilter.doFilter(GzipFilter.java:155)
     at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
     at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
     at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:218)
     at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
     at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
     at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:422)
     at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230
    )
     at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
     at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
     at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:230)
     at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
     at org.mortbay.jetty.handler.DebugHandler.handle(DebugHandler.java:77)
     at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
     at org.mortbay.jetty.Server.handle(Server.java:326)
     at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:543)
     at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:946)
     at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:756)
     at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
     at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:405)
     at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:410)
     at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:451)
    2011-10-29 02:20:28,362 INFO  [btpool0-54703://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    e=me@mymail.com;mid=69;ip=10.3.0.15;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - WaitSetRequ
    est
    2011-10-29 02:20:46,400 WARN  [btpool0-54703] [] log - SSL renegotiate denied: java.nio.channels.Socke
    tChannel[connected local=/10.99.0.73:443 remote=/174.252.242.84:60408]
    2011-10-29 02:20:58,149 INFO  [btpool0-54703://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    e=me@mymail.com;mid=100;ip=10.99.0.60;ua=Zimbra Desktop/7.1.2_10978_Windows;] soap - WaitS
    etRequest
    2011-10-29 02:21:05,438 INFO  [Timer-Zimbra] [] session - WaitSet sweeper: 2 active WaitSets (2 accoun
    ts) - 1 sets with blocked callbacks
    2011-10-29 02:21:07,050 INFO  [MailboxPurge] [name=tmayles@mymail.com;mid=89;] purge - Purging me
    ssages.
    2011-10-29 02:21:07,608 INFO  [Timer-Zimbra] [] FileUploadServlet - 2 pending file uploads
    2011-10-29 02:21:24,888 INFO  [btpool0-54703://mail1.mymail.com/service/soap/NoOpRequest] [name=s
    me@mymail.com;mid=65;ip=10.8.0.28;ua=ZimbraWebClient - IE8 (Win)/7.1.1_GA_3196;] soap - NoOpR
    equest
    2011-10-29 02:21:33,350 INFO  [btpool0-54703://mail1.mymail.com/service/soap/WaitSetRequest] [nam
    --More--
    Release 7.1.1_GA_3196.SLES11_64_20110527115356 SLES11_64 NETWORK edition.

  4. #4
    phoenix is online now Zimbra Consultant & Moderator
    Join Date
    Sep 2005
    Location
    Vannes, France
    Posts
    23,582
    Rep Power
    57

    Default

    IS the service actually down at this point, what's the status of the services after the backup is done? Post the output of the following command:

    Code:
    zmcontrol status
    Does this happen with all users? Has this problem just started? Any upgrades to the server recently? If all the services are still up and running are the accounts in maintenance mode?
    Regards


    Bill


    Acompli: A new adventure for Co-Founder KevinH.

  5. #5
    jpsinacola is offline Intermediate Member
    Join Date
    Nov 2010
    Location
    Michigan
    Posts
    19
    Rep Power
    4

    Default

    At that point, yes, the MTA service is down. All other services are running. I cannot provide the output now because all of the services are currently up. Every Saturday morning I have to VPN in to my network, I check it with zmcontrol status, I see that MTA is not running (everything else is), and I do a zmcontrol start and it starts running again and all appears normal.

    This has been going on for about a couple of months, I do not have the date exactly, sorry. I have not done any software updates, neither Zimbra nor SUSE during that time frame.

    I wish I had more to go on, which is why I turned to the forums hoping maybe someone had something similar, or let me know where to even start looking.

    **
    Upon more thought, I understand your question. Am I SURE that the backup is causing it? No, not exactly. There is nothing in the logs to show where is went down, so you could call it a "deduction" since the full backup is the only thing that is different. Other than this issue, I have ZERO problems with Zimbra and it runs wonderfully. So, I need to figure out how best to monitor it, so that I know exactly WHEN it goes down. Thoughts?
    **

    Thanks again for the help!
    Last edited by jpsinacola; 11-01-2011 at 06:22 AM. Reason: More thoughts
    Release 7.1.1_GA_3196.SLES11_64_20110527115356 SLES11_64 NETWORK edition.

  6. #6
    phoenix is online now Zimbra Consultant & Moderator
    Join Date
    Sep 2005
    Location
    Vannes, France
    Posts
    23,582
    Rep Power
    57

    Default

    Quote Originally Posted by jpsinacola View Post
    **
    Upon more thought, I understand your question. Am I SURE that the backup is causing it? No, not exactly. There is nothing in the logs to show where is went down, so you could call it a "deduction" since the full backup is the only thing that is different. Other than this issue, I have ZERO problems with Zimbra and it runs wonderfully. So, I need to figure out how best to monitor it, so that I know exactly WHEN it goes down. Thoughts?
    **!
    Do you have any monitoring software (such as Nagios) on your LAN or something just to check port 25 to see when exactly the MTA is stopping? Is this a VM or a bare metal server?
    Regards


    Bill


    Acompli: A new adventure for Co-Founder KevinH.

Thread Information

Users Browsing this Thread

There are currently 1 users browsing this thread. (0 members and 1 guests)

Similar Threads

  1. Replies: 658
    Last Post: 04-04-2014, 09:01 AM
  2. Migrate Zimbra 6.0.8 NE to a new Server Failed
    By danisam in forum Administrators
    Replies: 6
    Last Post: 09-08-2011, 07:19 AM
  3. Daily mail report always reports "No messages found"
    By McPringle in forum Installation
    Replies: 42
    Last Post: 06-13-2011, 08:57 AM
  4. Global statistics not working
    By etiennepouliot in forum Administrators
    Replies: 1
    Last Post: 02-28-2011, 07:41 PM
  5. [SOLVED] Backups failing, "unable to read metadata for account"
    By smcgrath1111 in forum Administrators
    Replies: 10
    Last Post: 04-10-2008, 03:15 PM

Tags for this Thread

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •