Zimbra offers Open Source email server software and shared calendar for Linux and the Mac
Go Back   Zimbra :: Forums > Zimbra Collaboration Suite > Administrators
Reload this Page MTA service stopping and 1m later starting again?

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 11-07-2008, 10:56 AM
Moderator
  
Posts: 1,147
Default MTA service stopping and 1m later starting again?
This morning I got 2 messages in the admin mailbox telling me that the MTA service had stopped and then a minute later started back up again.

This has so far happened 4 times since the server was installed almost 5 months ago. Every time it has been around xx:45:00. It doesn't appear to be causing any issues but I was wondering if anybody has seen anything similar on their servers and knows why it is doing this?

Log entries that look interesting or might be related:
/var/log/zimbra.log (and similar entries in /var/log/messages) this one is interesting as it is sending the status messages to the admin account after the mta is supposedly down...
Code:
Nov  6 23:46:41 email zmmailboxdmgr[14858]: status requested
Nov  6 23:46:41 email zmmailboxdmgr[14858]: status OK
Nov  6 23:46:41 email zimbramon[8171]: 8171:err: Service status change: email.companyname.com mta changed from running to stopped
Nov  6 23:46:41 email zmmailboxdmgr[14920]: status requested
Nov  6 23:46:41 email zmmailboxdmgr[14920]: status OK
Nov  6 23:46:42 email postfix/pickup[10381]: 4B6CF904001: uid=1001 from=<zimbra>
Nov  6 23:46:42 email postfix/cleanup[14519]: 4B6CF904001: message-id=<20081107074642.4B6CF904001@email.companyname.com>
Nov  6 23:46:42 email postfix/qmgr[24061]: 4B6CF904001: from=<zimbra@email.companyname.com>, size=456, nrcpt=1 (queue active)
Nov  6 23:46:42 email amavis[15022]: (15022-14) ESMTP::10024 /opt/zimbra/data/amavisd/tmp/amavis-20081106T055744-15022: <zimbra@email.companyname.com> -> <admin@companyname.com> SIZE=456 Received: from email.companyname.com ([127.0.0.1]) by localhost (email.companyname.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <admin@companyname.com>; Thu,  6 Nov 2008 23:46:42 -0800 (PST)
Nov  6 23:46:42 email amavis[15022]: (15022-14) Checking: EgWpViM0arHV <zimbra@email.companyname.com> -> <admin@companyname.com>
Nov  6 23:46:42 email postfix/smtpd[14523]: connect from localhost.localdomain[127.0.0.1]
Nov  6 23:46:42 email postfix/smtpd[14523]: B152A904002: client=localhost.localdomain[127.0.0.1]
Nov  6 23:46:42 email postfix/cleanup[14519]: B152A904002: message-id=<20081107074642.4B6CF904001@email.companyname.com>
Nov  6 23:46:42 email postfix/qmgr[24061]: B152A904002: from=<zimbra@email.companyname.com>, size=1068, nrcpt=1 (queue active)
Nov  6 23:46:42 email postfix/smtpd[14523]: disconnect from localhost.localdomain[127.0.0.1]
Nov  6 23:46:42 email amavis[15022]: (15022-14) FWD via SMTP: <zimbra@email.companyname.com> -> <admin@companyname.com>,BODY=7BIT 250 2.6.0 Ok, id=15022-14, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as B152A904002
Nov  6 23:46:42 email amavis[15022]: (15022-14) Passed CLEAN, <zimbra@email.companyname.com> -> <admin@companyname.com>, Message-ID: <20081107074642.4B6CF904001@email.companyname.com>, mail_id: EgWpViM0arHV, Hits: -3.35, size: 456, queued_as: B152A904002, 403 ms
Nov  6 23:46:42 email postfix/smtp[14520]: 4B6CF904001: to=<admin@companyname.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.44, delays=0.04/0/0/0.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B152A904002)
Nov  6 23:46:42 email postfix/qmgr[24061]: 4B6CF904001: removed
Nov  6 23:46:42 email postfix/lmtp[14524]: B152A904002: to=<admin@companyname.com>, relay=email.companyname.com[10.0.1.6]:7025, delay=0.07, delays=0.01/0/0.01/0.05, dsn=2.1.5, status=sent (250 2.1.5 OK)
Nov  6 23:46:42 email postfix/qmgr[24061]: B152A904002: removed
Nov  6 23:47:53 email zmmailboxdmgr[15301]: status requested
Nov  6 23:47:53 email zmmailboxdmgr[15301]: status OK
Nov  6 23:47:53 email zimbramon[8171]: 8171:err: Service status change: email.companyname.com mta changed from stopped to running
Nov  6 23:47:53 email zmmailboxdmgr[15365]: status requested
Nov  6 23:47:53 email zmmailboxdmgr[15365]: status OK
Nov  6 23:47:54 email postfix/pickup[10381]: 070F8904001: uid=1001 from=<zimbra>
Nov  6 23:47:54 email postfix/cleanup[14519]: 070F8904001: message-id=<20081107074754.070F8904001@email.companyname.com>
Nov  6 23:47:54 email postfix/qmgr[24061]: 070F8904001: from=<zimbra@email.companyname.com>, size=456, nrcpt=1 (queue active)
Nov  6 23:47:54 email amavis[25660]: (25660-09) ESMTP::10024 /opt/zimbra/data/amavisd/tmp/amavis-20081105T192740-25660: <zimbra@email.companyname.com> -> <admin@companyname.com> SIZE=456 Received: from email.companyname.com ([127.0.0.1]) by localhost (email.companyname.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <admin@companyname.com>; Thu,  6 Nov 2008 23:47:54 -0800 (PST)
Nov  6 23:47:54 email amavis[25660]: (25660-09) Checking: ffqb4NkzC7bo <zimbra@email.companyname.com> -> <admin@companyname.com>
Nov  6 23:47:54 email postfix/smtpd[14523]: connect from localhost.localdomain[127.0.0.1]
Nov  6 23:47:54 email postfix/smtpd[14523]: 3E1A6904002: client=localhost.localdomain[127.0.0.1]
Nov  6 23:47:54 email postfix/cleanup[14519]: 3E1A6904002: message-id=<20081107074754.070F8904001@email.companyname.com>
Nov  6 23:47:54 email postfix/qmgr[24061]: 3E1A6904002: from=<zimbra@email.companyname.com>, size=1070, nrcpt=1 (queue active)
Nov  6 23:47:54 email postfix/smtpd[14523]: disconnect from localhost.localdomain[127.0.0.1]
Nov  6 23:47:54 email amavis[25660]: (25660-09) FWD via SMTP: <zimbra@email.companyname.com> -> <admin@companyname.com>,BODY=7BIT 250 2.6.0 Ok, id=25660-09, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 3E1A6904002
Nov  6 23:47:54 email amavis[25660]: (25660-09) Passed CLEAN, <zimbra@email.companyname.com> -> <admin@companyname.com>, Message-ID: <20081107074754.070F8904001@email.companyname.com>, mail_id: ffqb4NkzC7bo, Hits: -3.344, size: 456, queued_as: 3E1A6904002, 204 ms
Nov  6 23:47:54 email postfix/smtp[14520]: 070F8904001: to=<admin@companyname.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.24, delays=0.03/0/0/0.2, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 3E1A6904002)
Nov  6 23:47:54 email postfix/qmgr[24061]: 070F8904001: removed
Nov  6 23:47:54 email postfix/lmtp[14524]: 3E1A6904002: to=<admin@companyname.com>, relay=email.companyname.com[10.0.1.6]:7025, delay=0.08, delays=0/0/0/0.08, dsn=2.1.5, status=sent (250 2.1.5 OK)
Nov  6 23:47:54 email postfix/qmgr[24061]: 3E1A6904002: removed
/opt/zimbra/log/audit.log
Code:
2008-11-06 23:45:04,208 INFO  [btpool0-136] [ip=10.0.1.6;] security - cmd=AdminAuth; account=zimbra;
2008-11-06 23:45:04,209 INFO  [btpool0-136] [ip=10.0.1.6;] security - cmd=Auth; account=zimbra; protocol=soap;
2008-11-06 23:45:04,232 INFO  [btpool0-136] [name=zimbra;ip=10.0.1.6;] security - cmd=DelegateAuth; accountId=d1b39404-f07b-4784-8726-33d75af72871; accountName=spam.kq9iyvza@companyname.com;
2008-11-06 23:45:06,614 INFO  [btpool0-141] [ip=10.0.1.6;] security - cmd=AdminAuth; account=zimbra;
2008-11-06 23:45:06,614 INFO  [btpool0-141] [ip=10.0.1.6;] security - cmd=Auth; account=zimbra; protocol=soap;
2008-11-06 23:45:06,633 INFO  [btpool0-141] [name=zimbra;ip=10.0.1.6;] security - cmd=DelegateAuth; accountId=3a294422-1f01-48d9-8e9d-d1f646af7ef5; accountName=ham.v7ieqbfuyt@companyname.com;
/opt/zimbra/log/clamd.log
Code:
Thu Nov  6 23:46:10 2008 -> SelfCheck: Database status OK.
/opt/zimbra/log/zmmailboxd.out has 6 of:
Code:
java.io.IOException: Connection reset by peer
        at sun.nio.ch.FileDispatcher.read0(Native Method)
        at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:21)
        at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:233)
        at sun.nio.ch.IOUtil.read(IOUtil.java:200)
        at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:207)
        at org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.java:232)
        at org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcessor.java:206)
        at org.apache.mina.transport.socket.nio.SocketIoProcessor.access$500(SocketIoProcessor.java:44)
        at org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProcessor.java:506)
        at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:43)
        at java.lang.Thread.run(Thread.java:595)
but there are no timestamps so I can't tell if they are related or not...

/opt/zimbra/log/zmmtaconfig.log:
Code:
Thu Nov  6 23:45:30 2008  Watchdog: service antivirus status is OK.
Thu Nov  6 23:46:41 2008  Watchdog: service antivirus status is OK.
Thu Nov  6 23:47:53 2008  Watchdog: service antivirus status is OK.
Thu Nov  6 23:49:05 2008  Watchdog: service antivirus status is OK.
/opt/zimbra/log/zmswatch.out is the last one of interest that I can see:
Code:
SMTP notification: Nov  6 23:46:41 email zimbramon[8171]: 8171:err: Service status change: email.companyname.com mta changed from running to stopped
SNMP notification: Nov  6 23:46:41 email zimbramon[8171]: 8171:err: Service status change: email.companyname.com mta changed from running to stopped
SMTP notification: Nov  6 23:47:53 email zimbramon[8171]: 8171:err: Service status change: email.companyname.com mta changed from stopped to running
SNMP notification: Nov  6 23:47:53 email zimbramon[8171]: 8171:err: Service status change: email.companyname.com mta changed from stopped to running
Reply With Quote
  #2 (permalink)  
Old 03-16-2009, 05:15 AM
Starter Member
  
Posts: 1
Default
Hi,

I up this thread because I had the same trouble.
Have you solved this problem ? Is there anybody to help solving this ?

Thanks in advanced,
Thomas
Reply With Quote
  #3 (permalink)  
Old 08-20-2009, 11:47 AM
Moderator
  
Posts: 1,147
Default
It was happening about once a month when it occurred, but hasn't happened in quite a while. As it was so rarely and happened when nobody was using the system I ignored it.

Would certainly help with any debugging if anyone has a suggestion...
Reply With Quote
  #4 (permalink)  
Old 02-23-2010, 02:30 AM
New Member
  
Posts: 3
Default mta changed from stopped to running
HI,

I have also been having this same issue after recently upgrading to Zimbra 5.0.21. The interval between the restarts varies from 3 to 4 days. Any feedback on this will be appreciated.

Brian
Reply With Quote
  #5 (permalink)  
Old 02-23-2010, 11:18 AM
Moderator
  
Posts: 1,147
Default
Is there anything in your logs that might suggest a cause?
Reply With Quote
  #6 (permalink)  
Old 03-23-2010, 09:43 AM
New Member
  
Posts: 3
Default MTA service stopping and 1m later starting again
Hi,

Actually it took a while for the error to appear again...Here is the output from zimbra.log:

Mar 23 14:41:38 zimbra zimbramon[25804]: 25804:err: Service status change: <our zimbra server> mta changed from running to stopped
Mar 23 14:42:04 zimbra zimbramon[19683]: 19683:info: 2010-03-23 14:42:01, STATUS: <our zimbra server>: antispam: Running
.
.
Mar 23 14:42:46 zimbra zimbramon[25804]: 25804:err: Service status change: <our zimbra server> mta changed from stopped to running

Thanks for your assistance!

Brian
Reply With Quote
Reply

« Previous Thread | Today's Posts or Week's Posts | Next Thread »

Thread Tools Search this Thread
Search this Thread:

Advanced Search
Display Modes
Linear Mode Linear Mode


Product Information

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


Home - Blog - Contact Us - Archive - Top


 

SEO by vBSEO ©2011, Crawlability, Inc.