My system seems to be running perfectly. I can send and receive mail. zmcontrol status shows everything as up. However in my logs I get:
Aug 20 09:58:30 claven2 postfix/postqueue[111]: fatal: Queue report unavailable - mail system is down
Aug 20 09:59:00 claven2 postfix/postqueue[605]: fatal: Queue report unavailable - mail system is down
every 30 seconds. No other postfix is running that I can see (launchd postfix disabled).
Any ideas?
Thanks,
Gregor
zimbra 5.0.9
OS x 10.5.4
2.5 GB RAM
Bumping to see if anyone can figure this out. The system is running perfectly but my log has:
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: ldap: Running
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: logger: Running
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: mailbox: Stopped
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: mta: Stopped
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: saslauthd: is running with pid 45409
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: snmp: Running
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: spell: Running
Aug 25 21:52:05 xxx zimbramon[66088]: 66088:info: 2008-08-25 21:52:01, STATUS: xxx.marionette.ca: stats: Running
Aug 25 21:52:30 xxx postfix/postqueue[66320]: fatal: Queue report unavailable - mail system is down
Aug 25 21:53:00 xxx postfix/postqueue[66367]: fatal: Queue report unavailable - mail system is down
Aug 25 21:53:30 xxx postfix/postqueue[66399]: fatal: Queue report unavailable - mail system is down
zmcontrol status shows:
antispam Stopped
zmmtaconfigctl is not running
amavisd running pid: 45009
antivirus Stopped
zmmtaconfigctl is not running
amavisd running pid: 45009
ldap Running
logger Running
mailbox Stopped
zmmtaconfigctl is not running
mta Stopped
zmmtaconfigctl is not running
saslauthd is running with pid 45409
snmp Running
spell Running
stats Running
status page on zimbra admin pages shows same thing.
I can send and receive mails internally and externally with no problems. zmcontrol stop and zmcontrol start seems to 'fix' everything. Is the reporting correct on OS X?
Thanks,
Gregor
Look at /opt/zimbra/log/zmmtaconfig.log for errors on why zmmtaconfig is not running.
yesterdays zmmtaconfig.log has:
Tue Aug 26 22:55:33 2008 Watchdog: service antivirus status is OK.
Tue Aug 26 22:56:45 2008 Watchdog: service antivirus status is OK.
Tue Aug 26 22:57:57 2008 Watchdog: adding antivirus to restart list
Tue Aug 26 22:57:57 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Tue Aug 26 22:57:57 2008 Failed to restart antivirus rc=256
Tue Aug 26 22:59:08 2008 Watchdog: skipping service antivirus. Service not yet available for restarts.
Tue Aug 26 22:59:08 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Tue Aug 26 22:59:08 2008 Failed to restart antivirus rc=256
Tue Aug 26 23:00:20 2008 Watchdog: skipping service antivirus. Service not yet available for restarts.
Tue Aug 26 23:00:20 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Tue Aug 26 23:00:20 2008 Failed to restart antivirus rc=256
Tue Aug 26 23:01:31 2008 Watchdog: skipping service antivirus. Service not yet available for restarts.
Tue Aug 26 23:01:31 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Tue Aug 26 23:01:31 2008 Failed to restart antivirus rc=256
.
.
.
Wed Aug 27 03:09:17 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Wed Aug 27 03:09:17 2008 Failed to restart antivirus rc=256
Wed Aug 27 03:10:28 2008 Watchdog: skipping service antivirus. Service not yet available for restarts.
Wed Aug 27 03:10:28 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Wed Aug 27 03:10:28 2008 Failed to restart antivirus rc=256
Wed Aug 27 03:11:40 2008 Watchdog: skipping service antivirus. Service not yet available for restarts.
Wed Aug 27 03:11:40 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Wed Aug 27 03:11:40 2008 Failed to restart antivirus rc=256
Wed Aug 27 03:12:51 2008 Watchdog: skipping service antivirus. Service not yet available for restarts.
Wed Aug 27 03:12:51 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Wed Aug 27 03:12:51 2008 Failed to restart antivirus rc=256
Wed Aug 27 03:14:03 2008 Watchdog: skipping service antivirus. Service not yet available for restarts.
Wed Aug 27 03:14:03 2008 CONTROL ANTIVIRUS: /opt/zimbra/bin/zmclamdctl restart
Wed Aug 27 03:14:03 2008 Failed to restart antivirus rc=256
todays zmmtaconfig.log has:
Wed Aug 27 04:37:56 2008 zmmtaconfig started on claven2.marionette.ca with loglevel=3 pid=668
Wed Aug 27 04:38:30 2008 zmmtaconfig already running at 668
Wed Aug 27 04:38:41 2008 zmmtaconfig already running at 668
Wed Aug 27 04:38:54 2008 zmmtaconfig already running at 668
Wed Aug 27 04:39:23 2008 Watchdog: service sasl now available for watchdog.
Wed Aug 27 04:39:23 2008 Watchdog: service spell now available for watchdog.
Wed Aug 27 04:39:24 2008 Watchdog: service stats now available for watchdog.
Wed Aug 27 04:39:24 2008 Watchdog: service ldap now available for watchdog.
Wed Aug 27 04:39:24 2008 Watchdog: service antispam now available for watchdog.
Wed Aug 27 04:39:24 2008 Watchdog: service snmp now available for watchdog.
Wed Aug 27 04:39:24 2008 Watchdog: service mailboxd now available for watchdog.
Wed Aug 27 04:39:25 2008 Watchdog: service mta now available for watchdog.
Wed Aug 27 04:39:25 2008 Watchdog: service mailbox now available for watchdog.
Wed Aug 27 04:39:25 2008 Watchdog: service logger now available for watchdog.
Wed Aug 27 04:39:25 2008 Watchdog: service antivirus now available for watchdog.
Wed Aug 27 04:39:25 2008 Watchdog: service antivirus status is OK.
The log appears to have a gap in it from 3:14AM to 4:37AM. My backup script starts at 4:30AM and typically ends at 4:36/4:37. My scripts looks like:
su - zimbra -c "/opt/zimbra/bin/zmcontrol stop"
#perform backup
su - zimbra -c "/opt/zimbra/bin/zmcontrol start"
this morning a zmcontrol status give me:
antispam Stopped
zmmtaconfigctl is not running
amavisd running pid: 1366
antivirus Stopped
zmmtaconfigctl is not running
amavisd running pid: 1366
ldap Running
logger Running
mailbox Stopped
zmmtaconfigctl is not running
mta Stopped
zmmtaconfigctl is not running
saslauthd is running with pid 1769
snmp Running
spell Running
stats Running
and zimbra.log had:
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: antispam: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: antivirus: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: ldap: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: logger: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: mailbox: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: mta: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: snmp: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: spell: Running
Aug 26 22:56:05 claven2 zimbramon[69280]: 69280:info: 2008-08-26 22:56:00, STATUS: claven2.marionette.ca: stats: Running
Aug 26 22:56:44 claven2 zmmailboxdmgr[69666]: status requested
Aug 26 22:56:44 claven2 zmmailboxdmgr[69666]: status OK
Aug 26 22:56:45 claven2 zmmailboxdmgr[69717]: status requested
Aug 26 22:56:45 claven2 zmmailboxdmgr[69717]: status OK
Aug 26 22:57:56 claven2 zimbramon[48427]: 48427:err: Service status change: claven2.marionette.ca sasl changed from running to stopped
Aug 26 22:57:56 claven2 zimbramon[48427]: 48427:err: Service status change: claven2.marionette.ca stats changed from running to stopped
Aug 26 22:57:56 claven2 zimbramon[48427]: 48427:err: Service status change: claven2.marionette.ca antispam changed from running to stopped
Aug 26 22:57:56 claven2 zimbramon[48427]: 48427:err: Service status change: claven2.marionette.ca mailboxd changed from running to stopped
Aug 26 22:57:57 claven2 postfix/sendmail[69967]: fatal: no login name found for user ID 505
Aug 26 22:57:57 claven2 zimbramon[48427]: 48427:err: Service status change: claven2.marionette.ca mta changed from running to stopped
Aug 26 22:57:57 claven2 zimbramon[48427]: 48427:err: Service status change: claven2.marionette.ca mailbox changed from running to stopped
Aug 26 22:57:57 claven2 zimbramon[48427]: 48427:err: Service status change: claven2.marionette.ca antivirus changed from running to stopped
Aug 26 22:57:57 claven2 zimbramon[48427]: 48427:info: zmmtaconfig: Watchdog: adding antivirus to restart list
Aug 26 22:57:57 claven2 zimbramon[48427]: 48427:info: ANTIVIRUS restart initiated from zmmtaconfig
Aug 26 22:57:57 claven2 zimbramon[48427]: 48427:info: zmmtaconfig: Failed to restart antivirus rc=256
Aug 26 22:57:57 claven2 postfix/sendmail[70008]: fatal: no login name found for user ID 505
Aug 26 22:57:57 claven2 postfix/sendmail[70010]: fatal: no login name found for user ID 505
Aug 26 22:57:57 claven2 postfix/sendmail[70012]: fatal: no login name found for user ID 505
Aug 26 22:57:57 claven2 postfix/sendmail[70014]: fatal: no login name found for user ID 505
Aug 26 22:57:57 claven2 postfix/sendmail[70016]: fatal: no login name found for user ID 505
Aug 26 22:57:58 claven2 postfix/sendmail[70018]: fatal: no login name found for user ID 505
Aug 26 22:58:02 claven2 zmmailboxdmgr[70158]: status requested
Aug 26 22:58:02 claven2 zmmailboxdmgr[70158]: status OK
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: antispam: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: antivirus: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: ldap: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: logger: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: mailbox: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: mta: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: snmp: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: spell: Running
Aug 26 22:58:04 claven2 zimbramon[70021]: 70021:info: 2008-08-26 22:58:00, STATUS: claven2.marionette.ca: stats: Running
Aug 26 22:59:08 claven2 zimbramon[48427]: 48427:info: ANTIVIRUS restart initiated from zmmtaconfig
Aug 26 22:59:08 claven2 zimbramon[48427]: 48427:info: zmmtaconfig: Failed to restart antivirus rc=256
Aug 26 23:00:00 claven2 zimbramon[70534]: 70534:info: 2008-08-26 23:00:00, QUEUE: 0 0
Aug 26 23:00:01 claven2 zimbramon[70537]: 70537:info: 2008-08-26 23:00:00, DISK: claven2.marionette.ca: dev: /dev/disk0s2, mp: /, tot: 238147, avail: 80410
Aug 26 23:00:01 claven2 zimbramon[70537]: 70537:info: 2008-08-26 23:00:00, DISK: claven2.marionette.ca: dev: /dev/disk1s3, mp: /Volumes/Daily, tot: 286060, avail: 128593
Aug 26 23:00:05 claven2 zmmailboxdmgr[70795]: status requested
Aug 26 23:00:05 claven2 zmmailboxdmgr[70795]: status OK
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: antispam: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: antivirus: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: ldap: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: logger: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: mailbox: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: mta: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: snmp: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: spell: Running
Aug 26 23:00:07 claven2 zimbramon[70536]: 70536:info: 2008-08-26 23:00:00, STATUS: claven2.marionette.ca: stats: Running
Aug 26 23:00:20 claven2 zimbramon[48427]: 48427:info: ANTIVIRUS restart initiated from zmmtaconfig
Aug 26 23:00:20 claven2 zimbramon[48427]: 48427:info: zmmtaconfig: Failed to restart antivirus rc=256
Aug 26 23:01:31 claven2 zimbramon[48427]: 48427:info: ANTIVIRUS restart initiated from zmmtaconfig
Aug 26 23:01:31 claven2 zimbramon[48427]: 48427:info: zmmtaconfig: Failed to restart antivirus rc=256
Aug 26 23:01:44 claven2 postfix/smtpd[71339]: connect from unknown[58.10.36.205]
Aug 26 23:01:45 claven2 postfix/proxymap[71340]: error: dict_ldap_connect: Unable to set STARTTLS: -1: Can't contact LDAP server
Aug 26 23:01:45: --- last message repeated 2 times ---
Aug 26 23:01:45 claven2 postfix/trivial-rewrite[71346]: fatal: proxy:ldap:/opt/zimbra/conf/ldap-vad.cf(0,lock|fold_fix): table lookup problem
Aug 26 23:01:46 claven2 postfix/master[49462]: warning: process /opt/zimbra/postfix/libexec/trivial-rewrite pid 71346 exit status 1
Aug 26 23:01:47 claven2 postfix/proxymap[71340]: error: dict_ldap_connect: Unable to set STARTTLS: -1: Can't contact LDAP server
Aug 26 23:01:47: --- last message repeated 2 times ---
Aug 26 23:01:47 claven2 postfix/trivial-rewrite[71347]: fatal: proxy:ldap:/opt/zimbra/conf/ldap-vad.cf(0,lock|fold_fix): table lookup problem
Aug 26 23:01:48 claven2 postfix/smtpd[71339]: warning: problem talking to service rewrite: Unknown error: 0
Aug 26 23:01:48 claven2 postfix/master[49462]: warning: process /opt/zimbra/postfix/libexec/trivial-rewrite pid 71347 exit status 1
Aug 26 23:01:48 claven2 postfix/master[49462]: warning: /opt/zimbra/postfix/libexec/trivial-rewrite: bad command startup -- throttling
Aug 26 23:02:03 claven2 zmmailboxdmgr[71494]: status requested
Aug 26 23:02:03 claven2 zmmailboxdmgr[71494]: status OK
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: antispam: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: antivirus: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: ldap: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: logger: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: mailbox: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: mta: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: snmp: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: spell: Running
Aug 26 23:02:04 claven2 zimbramon[71357]: 71357:info: 2008-08-26 23:02:00, STATUS: claven2.marionette.ca: stats: Running
Aug 26 23:02:43 claven2 zimbramon[48427]: 48427:info: ANTIVIRUS restart initiated from zmmtaconfig
Aug 26 23:02:43 claven2 zimbramon[48427]: 48427:info: zmmtaconfig: Failed to restart antivirus rc=256
Aug 26 23:02:48 claven2 postfix/proxymap[71340]: error: dict_ldap_connect: Unable to set STARTTLS: -1: Can't contact LDAP server
Aug 26 23:02:48: --- last message repeated 2 times ---
It appears it broke well before my backup started so something else is breaking it....
Thanks
Gregor
i am seeing this too. what is your solution?
I can see atal: proxy:ldap:/opt/zimbra/conf/ldap-vad.cf(0,lock|fold_fix): table lookup problem is logs you pasted.
does the password in opt/zimbra/conf/ldap-vad.cf is correct and matches that in zmlocalconfig ?
zmlocalconfig -s | grep -i pass
you are interested in ldap_postfix_password = <password>
cat ldap-vad.cf
bind_pw = <password>
These should match