postfix/postfix-script: fatal: the Postfix mail system is not running

Printable View

09-30-2012, 07:39 PM
jimmyk

postfix/postfix-script: fatal: the Postfix mail system is not running

Hello,

My centos 5.8 zimbra 7.1.4 ose 64bit server has a problem with postfix.

Postfix is not running and I cannot get it to start.

I rebooted the server and then used an rsync script to back zimbra up earlier to day and now nothing is listening for mail on port 25, and the MTA will not start!

Examples of a few commands and logs:

[zimbra@imap ~]$ zmmtactl restart
Rewriting configuration files...done.
postfix/postfix-script: fatal: the Postfix mail system is not running
Stopping saslauthd...done.
Starting saslauthd...done.
[zimbra@imap ~]$ zmmtactl restart
Rewriting configuration files...done.
postfix/postfix-script: fatal: the Postfix mail system is not running
Stopping saslauthd...done.
Starting saslauthd...done.
[zimbra@imap ~]$ zmcontrol restart
Host imap.xxxxxxxxxx.co.uk
Stopping zmconfigd...Done.
Stopping stats...Done.
Stopping mta...Done.
Stopping spell...Done.
Stopping snmp...Done.
Stopping cbpolicyd...Done.
Stopping archiving...Done.
Stopping antivirus...Done.
Stopping antispam...Done.
Stopping imapproxy...Done.
Stopping memcached...Done.
Stopping mailbox...Done.
Stopping logger...Done.
Stopping ldap...Done.
Host imap.xxxxxxxxxxxxx.co.uk
Starting ldap...Done.
Starting zmconfigd...Done.
Starting logger...Done.
Starting mailbox...Done.
Starting antispam...Done.
Starting antivirus...Done.
Starting snmp...Done.
Starting spell...Done.
Starting mta...Done.
Starting stats...Done.
[zimbra@imap ~]$ zmmtactl restart
Rewriting configuration files...done.
postfix/postfix-script: fatal: the Postfix mail system is not running
Stopping saslauthd...done.
Starting saslauthd...done.
[zimbra@imap ~]$ exit
[root@imap ~]# lsof -i :25
[root@imap ~]# lsof -i TCP:25
[root@imap ~]# cat /var/log/zimbra.log | grep fatal
Oct 1 02:24:01 imap postfix/postqueue[7857]: fatal: Queue report unavailable - mail system is down
Oct 1 02:24:31 imap postfix/postqueue[8584]: fatal: Queue report unavailable - mail system is down
Oct 1 02:25:01 imap postfix/postqueue[8601]: fatal: Queue report unavailable - mail system is down
Oct 1 02:25:31 imap postfix/postqueue[8963]: fatal: Queue report unavailable - mail system is down
Oct 1 03:25:48 imap postfix/postfix-script[9112]: fatal: the Postfix mail system is not running
Oct 1 02:29:00 imap postfix/postqueue[12838]: fatal: Queue report unavailable - mail system is down
Oct 1 02:29:30 imap postfix/postqueue[13020]: fatal: Queue report unavailable - mail system is down
Oct 1 03:29:58 imap postfix/postfix-script[14048]: fatal: the Postfix mail system is not running
Oct 1 02:30:00 imap postfix/postqueue[14072]: fatal: Queue report unavailable - mail system is down
Oct 1 02:30:01 imap postfix/postqueue[14138]: fatal: Queue report unavailable - mail system is down
Oct 1 02:30:30 imap postfix/postqueue[14990]: fatal: Queue report unavailable - mail system is down
Oct 1 02:31:00 imap postfix/postqueue[15006]: fatal: Queue report unavailable - mail system is down
Oct 1 02:31:30 imap postfix/postqueue[15263]: fatal: Queue report unavailable - mail system is down

It has been working fine for at least a year. Does anyone know how the get the MTA started again, or have any ideas?

jk
09-30-2012, 10:56 PM
phoenix

Quote:

Originally Posted by jimmyk

It has been working fine for at least a year.

Check if your certificates have expired and regenerate them if they have.
10-01-2012, 03:16 AM
jimmyk

I did check the certificates from the web administration interface. The info was as follows:

Server Name: imap.waasupwidis.dog
Certificate for Zimbra ldap Service:
Subject: /C=UK/ST=N/A/O=sup dog/OU=IT/CN=imap.waasupwidis.dog
Issuer: /C=US/ST=N/A/L=N/A/O=Zimbra Collaboration Suite/OU=Zimbra Collaboration Suite/CN=imap.waasupwidis.dog
Validation Days: Feb 1 00:25:12 2012 GMT - Jan 31 00:25:12 2013 GMT
Subject Alternative Name:
Certificate for Zimbra mailboxd Service:
Subject: /C=UK/ST=N/A/O=sup dog/OU=IT/CN=imap.waasupwidis.dog
Issuer: /C=US/ST=N/A/L=N/A/O=Zimbra Collaboration Suite/OU=Zimbra Collaboration Suite/CN=imap.waasupwidis.dog
Validation Days: Feb 1 00:25:12 2012 GMT - Jan 31 00:25:12 2013 GMT
Subject Alternative Name:
Certificate for Zimbra mta Service:
Subject: /C=UK/ST=N/A/O=sup dog/OU=IT/CN=imap.waasupwidis.dog
Issuer: /C=US/ST=N/A/L=N/A/O=Zimbra Collaboration Suite/OU=Zimbra Collaboration Suite/CN=imap.waasupwidis.dog
Validation Days: Feb 1 00:25:12 2012 GMT - Jan 31 00:25:12 2013 GMT
Subject Alternative Name:
Certificate for Zimbra proxy Service:
Subject: /C=UK/ST=N/A/O=sup dog/OU=IT/CN=imap.waasupwidis.dog
Issuer: /C=US/ST=N/A/L=N/A/O=Zimbra Collaboration Suite/OU=Zimbra Collaboration Suite/CN=imap.waasupwidis.dog
Validation Days: Feb 1 00:25:12 2012 GMT - Jan 31 00:25:12 2013 GMT
Subject Alternative Name:

Therefore, I thought the certificates dates were still ok.

I am almost out of ideas with this.

If I risked doing up upgrade would that be likely to fix this issue!!!

jk
10-01-2012, 03:30 AM
phoenix

Quote:

Originally Posted by jimmyk

If I risked doing up upgrade would that be likely to fix this issue!!!

No that's not likely to fix it and it's never the resolution to a problem unless some specific bug is addressed. What else is in the log files? Have you looked at some of the forum threads and wiki articles on the subject and tried some of the solutions and if you have, which ones and what was the outcome? Have you done any upgrades to your server recently?
10-01-2012, 03:41 AM
jimmyk

My yum log from June is as follows:

Jun 21 19:58:41 Updated: e2fsprogs-libs-1.39-34.el5_8.1.x86_64
Jun 21 19:58:44 Updated: openssl-0.9.8e-22.el5_8.4.x86_64
Jun 21 19:58:44 Updated: 30:bind-libs-9.3.6-20.P1.el5_8.1.x86_64
Jun 21 19:58:45 Updated: expat-1.95.8-11.el5_8.x86_64
Jun 21 19:58:45 Updated: 30:bind-utils-9.3.6-20.P1.el5_8.1.x86_64
Jun 21 19:58:48 Updated: e2fsprogs-1.39-34.el5_8.1.x86_64
Jun 21 19:59:00 Updated: tzdata-2012c-1.el5.x86_64
Jun 21 19:59:39 Installed: kernel-2.6.18-308.8.2.el5.x86_64
Jun 21 19:59:39 Updated: e2fsprogs-libs-1.39-34.el5_8.1.i386
Jun 21 19:59:41 Updated: openssl-0.9.8e-22.el5_8.4.i686
Jun 21 19:59:42 Updated: expat-1.95.8-11.el5_8.i386
Jun 21 19:59:54 Updated: python-libs-2.4.3-46.el5_8.2.x86_64
Jun 21 19:59:54 Updated: python-2.4.3-46.el5_8.2.x86_64
Jul 03 18:24:38 Updated: libtiff-3.8.2-15.el5_8.x86_64
Jul 03 18:24:39 Updated: libtiff-3.8.2-15.el5_8.i386
Jul 18 02:55:45 Updated: nspr-4.9.1-4.el5_8.x86_64
Jul 18 02:55:46 Updated: nss-3.13.5-4.el5_8.x86_64
Jul 18 02:55:47 Updated: openldap-2.3.43-25.el5_8.1.x86_64
Jul 18 02:55:48 Updated: sudo-1.7.2p1-14.el5_8.x86_64
Jul 18 02:55:49 Updated: nss-tools-3.13.5-4.el5_8.x86_64
Jul 18 02:56:32 Installed: kernel-2.6.18-308.11.1.el5.x86_64
Jul 18 02:56:32 Updated: nspr-4.9.1-4.el5_8.i386
Jul 18 02:56:33 Updated: nss-3.13.5-4.el5_8.i386
Jul 18 02:56:33 Updated: openldap-2.3.43-25.el5_8.1.i386
Sep 01 00:45:24 Updated: tzdata-2012c-3.el5.x86_64
Sep 01 00:46:18 Updated: glibc-common-2.5-81.el5_8.7.x86_64
Sep 01 00:46:33 Updated: glibc-2.5-81.el5_8.7.x86_64
Sep 01 00:46:34 Updated: 30:bind-libs-9.3.6-20.P1.el5_8.2.x86_64
Sep 01 00:46:38 Updated: initscripts-8.45.42-1.el5.centos.1.x86_64
Sep 01 00:46:39 Updated: sudo-1.7.2p1-14.el5_8.3.x86_64
Sep 01 00:47:18 Installed: kernel-2.6.18-308.13.1.el5.x86_64
Sep 01 00:47:18 Updated: 30:bind-utils-9.3.6-20.P1.el5_8.2.x86_64
Sep 01 00:47:19 Updated: 12:dhclient-3.0.5-31.el5_8.1.x86_64
Sep 01 00:47:19 Updated: nscd-2.5-81.el5_8.7.x86_64
Sep 01 00:47:22 Updated: glibc-2.5-81.el5_8.7.i686
Sep 04 12:56:12 Updated: cyrus-sasl-lib-2.1.22-7.el5_8.1.x86_64
Sep 04 12:56:13 Updated: cyrus-sasl-plain-2.1.22-7.el5_8.1.x86_64
Sep 04 12:56:14 Updated: cyrus-sasl-2.1.22-7.el5_8.1.x86_64
Sep 04 12:56:15 Updated: cyrus-sasl-plain-2.1.22-7.el5_8.1.i386
Sep 04 12:56:15 Updated: cyrus-sasl-lib-2.1.22-7.el5_8.1.i386
Sep 22 18:56:11 Updated: libxml2-2.6.26-2.1.15.el5_8.5.x86_64
Sep 22 18:56:11 Updated: 30:bind-libs-9.3.6-20.P1.el5_8.4.x86_64
Sep 22 18:56:13 Updated: sudo-1.7.2p1-14.el5_8.4.x86_64
Sep 22 18:56:14 Updated: ipsec-tools-0.6.5-14.el5_8.5.x86_64
Sep 22 18:56:16 Updated: libxml2-python-2.6.26-2.1.15.el5_8.5.x86_64
Sep 22 18:56:16 Updated: 30:bind-utils-9.3.6-20.P1.el5_8.4.x86_64
"/var/log/yum.log" 290L, 16424C

The server was working on the morning of the 30 Sept 2012 when I shut the system down to do some work on the rack and I believe it has not worked since it was rebooted.

To only error I may have made was to shut the server down in a rush with the halt command. Normally, I would shut zimbra down first and then issue the halt command.

jk
10-01-2012, 03:50 AM
jimmyk

Some more log info:

#vi + /var/log/zimbra.log

Oct 1 10:41:28 imap postfix/postqueue[6876]: fatal: Queue report unavailable - mail system is down
Oct 1 10:41:58 imap postfix/postqueue[6883]: fatal: Queue report unavailable - mail system is down
Oct 1 11:42:13 imap zmmailboxdmgr[7257]: status requested
Oct 1 11:42:13 imap zmmailboxdmgr[7257]: status OK
Oct 1 11:42:13 imap zmmailboxdmgr[7270]: status requested
Oct 1 11:42:13 imap zmmailboxdmgr[7270]: status OK
Oct 1 11:42:14 imap zmmailboxdmgr[7382]: status requested
Oct 1 11:42:14 imap zmmailboxdmgr[7382]: status OK
Oct 1 10:42:28 imap postfix/postqueue[7621]: fatal: Queue report unavailable - mail system is down
Oct 1 10:42:58 imap postfix/postqueue[7632]: fatal: Queue report unavailable - mail system is down
Oct 1 11:43:19 imap zmmailboxdmgr[7724]: status requested
Oct 1 11:43:19 imap zmmailboxdmgr[7724]: status OK
Oct 1 11:43:19 imap zmmailboxdmgr[7733]: status requested
Oct 1 11:43:19 imap zmmailboxdmgr[7733]: status OK
Oct 1 10:43:28 imap postfix/postqueue[7895]: fatal: Queue report unavailable - mail system is down
Oct 1 10:43:58 imap postfix/postqueue[7904]: fatal: Queue report unavailable - mail system is down
Oct 1 11:44:13 imap zmmailboxdmgr[8253]: status requested
Oct 1 11:44:13 imap zmmailboxdmgr[8253]: status OK
Oct 1 11:44:24 imap zmmailboxdmgr[8470]: status requested
Oct 1 11:44:24 imap zmmailboxdmgr[8470]: status OK
Oct 1 11:44:24 imap zmmailboxdmgr[8479]: status requested
Oct 1 11:44:24 imap zmmailboxdmgr[8479]: status OK
Oct 1 10:44:28 imap postfix/postqueue[8639]: fatal: Queue report unavailable - mail system is down
Oct 1 10:44:58 imap postfix/postqueue[8649]: fatal: Queue report unavailable - mail system is down
Oct 1 10:45:29 imap postfix/postqueue[8660]: fatal: Queue report unavailable - mail system is down
Oct 1 11:45:30 imap zmmailboxdmgr[8755]: status requested
Oct 1 11:45:30 imap zmmailboxdmgr[8755]: status OK
Oct 1 11:45:30 imap zmmailboxdmgr[8765]: status requested
Oct 1 11:45:30 imap zmmailboxdmgr[8765]: status OK
Type :quit<Enter> to exit Vim

The times are strange on these logs!

I have also searched the forums for few hours and this issue is normally exim or sendmail running on port 25, but there is nothing running on port 25 on this server.

jk
10-01-2012, 04:01 AM
jimmyk

Ok this is the best log info I can find on when the server stopped tranferring mail (from /var/log/maillog):

Sep 30 15:46:21 imap zmmailboxdmgr[29208]: status requested
Sep 30 15:46:21 imap zmmailboxdmgr[29208]: status OK
Sep 30 15:46:30 imap postfix/postfix-script[29499]: stopping the Postfix mail system
Sep 30 15:46:30 imap postfix/master[2823]: terminating on signal 15
Sep 30 15:46:43 imap zmmailboxdmgr[29774]: status requested
Sep 30 15:46:43 imap zmmailboxdmgr[29774]: status OK
Sep 30 15:46:45 imap zmmailboxdmgr[29780]: stop requested
Sep 30 15:46:45 imap zmmailboxdmgr[29780]: waiting for manager process 1360 to die
Sep 30 15:46:45 imap zmmailboxdmgr[1360]: shutdown requested, sending TERM signal to 1361
Sep 30 15:46:48 imap zmmailboxdmgr[1360]: mailboxd/JVM process exited (waitpid expected 1361 got 1361)
Sep 30 15:46:48 imap zmmailboxdmgr[1360]: manager woke up from wait on mailboxd/JVM with pid 1361
Sep 30 15:46:49 imap zmmailboxdmgr[29780]: manager process 1360 died, shutdown completed
Sep 30 17:18:14 imap zmmailboxdmgr[4366]: status requested
Sep 30 17:18:14 imap zmmailboxdmgr[4366]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Sep 30 17:18:14 imap zmmailboxdmgr[4366]: assuming no other instance is running
Sep 30 17:18:14 imap zmmailboxdmgr[4366]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Sep 30 17:18:14 imap zmmailboxdmgr[4366]: assuming no other instance is running
Sep 30 17:18:14 imap zmmailboxdmgr[4366]: no manager process is running
Sep 30 17:18:14 imap zmmailboxdmgr[4377]: start requested
Sep 30 17:18:14 imap zmmailboxdmgr[4377]: checking if another instance of manager is already running
Sep 30 17:18:14 imap zmmailboxdmgr[4377]: file /opt/zimbra/log/zmmailboxd_manager.pid does not exist
Sep 30 17:18:14 imap zmmailboxdmgr[4377]: assuming no other instance is running
Sep 30 17:18:14 imap zmmailboxdmgr[4377]: file /opt/zimbra/log/zmmailboxd.pid does not exist
Sep 30 17:18:14 imap zmmailboxdmgr[4377]: assuming no other instance is running
Sep 30 17:18:14 imap zmmailboxdmgr[4378]: wrote manager pid 4378 to /opt/zimbra/log/zmmailboxd_manager.pid
Sep 30 17:18:14 imap zmmailboxdmgr[4380]: wrote java pid 4380 to /opt/zimbra/log/zmmailboxd_java.pid
Sep 30 17:18:14 imap zmmailboxdmgr[4378]: manager started mailboxd/JVM with pid 4380
Sep 30 17:18:17 imap zmmailboxdmgr[4633]: status requested
Sep 30 17:18:17 imap zmmailboxdmgr[4633]: status OK
Sep 30 17:18:54 imap zmmailboxdmgr[5058]: status requested
Sep 30 17:18:54 imap zmmailboxdmgr[5058]: status OK
Sep 30 17:18:54 imap zmmailboxdmgr[5067]: status requested
Sep 30 17:18:54 imap zmmailboxdmgr[5067]: status OK
Sep 30 16:19:30 imap postfix/postqueue[5971]: fatal: Queue report unavailable - mail system is down
Sep 30 16:20:00 imap postfix/postqueue[6109]: fatal: Queue report unavailable - mail system is down
Sep 30 16:20:01 imap postfix/postqueue[6173]: fatal: Queue report unavailable - mail system is down
Sep 30 17:20:02 imap zmmailboxdmgr[6326]: status requested
Sep 30 17:20:02 imap zmmailboxdmgr[6326]: status OK

some warnings from /var/log/maillog:

Oct 1 02:02:53 imap zmmailboxdmgr[19586]: status OK
Oct 1 01:03:01 imap postfix/postqueue[19788]: fatal: Queue report unavailable - mail system is down
Oct 1 02:03:12 imap postfix/postfix-script[19901]: warning: not owned by root: /opt/zimbra/postfix-2.7.7.3z/conf/main.cf
Oct 1 02:03:12 imap postfix/postfix-script[19902]: warning: not owned by root: /opt/zimbra/postfix-2.7.7.3z/conf/master.cf
Oct 1 02:03:12 imap postfix/postfix-script[19903]: warning: not owned by root: /opt/zimbra/postfix-2.7.7.3z/conf/master.cf.in
Oct 1 01:03:31 imap postfix/postqueue[19930]: fatal: Queue report unavailable - mail system is down
Oct 1 02:03:58 imap zmmailboxdmgr[20019]: status requested
10-01-2012, 04:18 AM
jimmyk

I found this in /var/log/messages:

Sep 30 17:19:06 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Sep 30 17:19:06 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Sep 30 17:19:30 imap ntpd[2855]: synchronized to LOCAL(0), stratum 10
Sep 30 17:19:30 imap ntpd[2855]: kernel time sync enabled 0001
Sep 30 17:20:35 imap ntpd[2855]: synchronized to 176.34.228.173, stratum 2
Sep 30 17:37:30 imap ntpd[2855]: time reset -0.334582 s
Sep 30 17:40:55 imap ntpd[2855]: synchronized to LOCAL(0), stratum 10
Sep 30 17:41:16 imap ntpd[2855]: synchronized to 176.34.228.173, stratum 2
Oct 1 01:01:53 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 01:01:53 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 01:43:24 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 01:43:24 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 02:21:07 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 02:21:07 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 02:49:21 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 02:49:21 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 02:52:25 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 02:52:25 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 02:53:19 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 02:53:19 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 02:56:35 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 02:56:35 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 03:18:07 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 03:18:07 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 03:18:52 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 03:18:52 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 03:28:36 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 03:28:36 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
Oct 1 03:30:13 imap saslauthd: auth_zimbra_init: zimbra_cert_check is off!
Oct 1 03:30:13 imap saslauthd: auth_zimbra_init: 1 auth urls initialized for round-robin
10-01-2012, 05:40 AM
jimmyk

I think it is the time problem is stopping postfix from starting, but I do not know how to resolve this issue.

My fstab is as follows:

/dev/VolGroup00/LogVolRoot / ext3 defaults 1 1
/dev/md0 /boot ext3 defaults 1 2
/dev/VolGroup00/LogVolVar /var ext3 defaults 1 2
/dev/VolGroup00/LogVolVarLog /var/log ext3 defaults 1 2
/dev/VolGroup00/LogVolDevShm /dev/shm ext3 defaults 1 2
/dev/VolGroup00/LogVolHome /home ext3 defaults 1 2
/dev/VolGroup00/LogVolOpt /opt ext3 defaults 1 2
/dev/VolGroup00/LogVolTmp /tmp ext3 defaults 1 2
tmpfs /dev/shm tmpfs defaults 0 0
devpts /dev/pts devpts gid=5,mode=620 0 0
sysfs /sys sysfs defaults 0 0
proc /proc proc defaults 0 0
/dev/VolGroup00/LogVolSwap swap swap defaults 0 0

I have removed/moved /opt/zimbra/data/postfix/spool/pid/master.pid as was mentioned in another thread, but postfix still refuses to start.

EDIT: I spoke too soon Postfix has restarted. Not the type of crisis you want on a Monday!