[SOLVED] zmconfigd WARNING in 7.0.0 GA

[Perlpigeon]

Originally Posted by phoenix

Instead of a 'me too' post, let's see some evidence that you have the 'bug'.

Really? Here you go:

root@dreadnought:~# uname -a
Linux dreadnought 2.6.32-32-server #62-Ubuntu SMP Wed Apr 20 22:07:43 UTC 2011 x86_64 GNU/Linux
root@dreadnought:~# date
Tue Jul 12 13:21:25 CEST 2011
root@dreadnought:~# sudo -u zimbra /opt/zimbra/bin/zmcontrol -v
Release 7.1.1_GA_3196.UBUNTU10_64 UBUNTU10_64 FOSS edition.
root@dreadnought:~# tail -10 /opt/zimbra/log/zmconfigd.log
2011-07-12 13:20:04,571 zmconfigd WARNING [22776-MainThread] Watchdog: service antivirus status is OK.
2011-07-12 13:20:04,648 zmconfigd WARNING [22776-MainThread] All rewrite threads completed in 0.00 sec
2011-07-12 13:20:04,648 zmconfigd WARNING [22776-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-07-12 13:21:04,657 zmconfigd WARNING [22776-MainThread] Fetching All configs
2011-07-12 13:21:05,005 zmconfigd WARNING [22776-MainThread] All configs fetched in 0.35 seconds
2011-07-12 13:21:06,387 zmconfigd WARNING [22776-MainThread] Watchdog: service antivirus status is OK.
2011-07-12 13:21:06,467 zmconfigd WARNING [22776-MainThread] All rewrite threads completed in 0.00 sec
2011-07-12 13:21:06,469 zmconfigd WARNING [22776-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
root@dreadnought:~#

Every minute...

Originally Posted by phoenix

It's been fixed in the current (as of this date) release.

The latest version I can find is this 7.1.1 version with Patch 2, link: Open Source Edition Downloads: Enterprise Messaging and Collaboration Software by Zimbra
, which is installed and shows me the bug.

[quanah]

I don't see a bug in what you posted above? Everything seems correct. What issue are you trying to report here?

[Perlpigeon]

Originally Posted by quanah

I don't see a bug in what you posted above? Everything seems correct. What issue are you trying to report here?

Quanah, you're wright. I don't have the postfix bug/problem. My apologies for that.

My mistake was that I am unfamiliar with log files that report this many warnings and state an unnecessary restart every minute. I don't believe that any other zimbra daemon creates these messages (unless there is something to warn about). So, logging that zmconfigd starts every minute and states that it is already running and a 5 line warning list is expected. I was unaware. I personally prefer to see only INFO statements, not warnings in my log files if it is not a warning, and perhaps a ps -ef|grep zmconfigd or something similar before trying to start the daemon? Perhaps in future the zmconfigd logging and 'check-time' can be configured? I also don't understand the CRITITCAL statement when Tracking service xxxx during a start. I choose to ignore it because 2 minutes later everything seems to be started correctly.

I did notice something else which I guess I should report as a minor thing:
When I perform a 'service zimbra stop/zmcontrol stop//etc/init.d/zimbra stop', the zmconfigd daemon tries to start some daemons again which I just tried to stop (e.g. antivirus), look at the entries in the log file below. It makes sense when issuing the command that zmconfigd is the first one to stop and the last one to be started when starting zimbra to prevent the below kind of behaviour. The antivirus daemon was running while doing the backup. I've added to my backup script my own 'check & kill' to prevent issues with the backup.

So at 00:30:xx the zimbra stop is issued.

2011-07-13 00:30:42,265 zmconfigd WARNING [10400-MainThread] Fetching All configs
2011-07-13 00:30:45,013 zmconfigd WARNING [10400-MainThread] All configs fetched in 2.75 seconds
2011-07-13 00:30:45,125 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmamavisdctl status norewrite returned 1 (24 - 13) (0.03 sec)
2011-07-13 00:30:45,125 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl antispam changed from running to stopped
2011-07-13 00:30:45,819 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/postfix status norewrite returned 1 (14 - 13) (0.53 sec)
2011-07-13 00:30:45,819 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl mta changed from running to stopped
2011-07-13 00:30:45,838 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmsaslauthdctl status norewrite returned 1 (26 - 13) (0.01 sec)
2011-07-13 00:30:45,838 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl sasl changed from running to stopped
2011-07-13 00:30:45,855 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmswatchctl status norewrite returned 1 (25 - 13) (0.01 sec)
2011-07-13 00:30:45,857 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl snmp changed from running to stopped
2011-07-13 00:30:45,874 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmspellctl status norewrite returned 1 (27 - 13) (0.01 sec)
2011-07-13 00:30:45,875 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl spell changed from running to stopped
2011-07-13 00:30:46,394 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmstatctl status norewrite returned 1 (14 - 13) (0.52 sec)
2011-07-13 00:30:46,394 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl stats changed from running to stopped
2011-07-13 00:30:46,434 zmconfigd WARNING [10400-MainThread] Watchdog: service antivirus status is OK.
2011-07-13 00:30:46,506 zmconfigd WARNING [10400-MainThread] All rewrite threads completed in 0.00 sec
2011-07-13 00:30:46,506 zmconfigd WARNING [10400-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-07-13 00:31:46,516 zmconfigd WARNING [10400-MainThread] Fetching All configs
2011-07-13 00:31:46,961 zmconfigd WARNING [10400-MainThread] All configs fetched in 0.45 seconds
2011-07-13 00:31:47,073 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmamavisdctl status norewrite returned 1 (24 - 13) (0.03 sec)
2011-07-13 00:31:47,776 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/postfix status norewrite returned 1 (14 - 13) (0.55 sec)
2011-07-13 00:31:47,790 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmsaslauthdctl status norewrite returned 1 (26 - 13) (0.01 sec)
2011-07-13 00:31:47,806 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmswatchctl status norewrite returned 1 (25 - 13) (0.01 sec)
2011-07-13 00:31:47,821 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmspellctl status norewrite returned 1 (27 - 13) (0.01 sec)
2011-07-13 00:31:48,302 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmstatctl status norewrite returned 1 (14 - 13) (0.48 sec)
2011-07-13 00:31:48,338 zmconfigd WARNING [10400-MainThread] Watchdog: service antivirus status is OK.
2011-07-13 00:31:48,413 zmconfigd WARNING [10400-MainThread] All rewrite threads completed in 0.00 sec
2011-07-13 00:31:48,414 zmconfigd WARNING [10400-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-07-13 00:32:48,423 zmconfigd WARNING [10400-MainThread] Fetching All configs
2011-07-13 00:32:48,799 zmconfigd WARNING [10400-MainThread] All configs fetched in 0.38 seconds
2011-07-13 00:32:48,915 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmamavisdctl status norewrite returned 1 (24 - 13) (0.03 sec)
2011-07-13 00:32:48,948 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmclamdctl status norewrite returned 1 (23 - 13) (0.03 sec)
2011-07-13 00:32:48,950 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl antivirus changed from running to stopped
2011-07-13 00:32:49,048 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmstorectl status norewrite returned 1 (59 - 13) (0.05 sec)
2011-07-13 00:32:49,048 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl mailbox changed from running to stopped
2011-07-13 00:32:49,079 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmmailboxdctl status norewrite returned 1 (25 - 13) (0.03 sec)
2011-07-13 00:32:49,081 zmconfigd CRITICAL [10400-MainThread] Service status change: dreadnought.taube.nl mailboxd changed from running to stopped
2011-07-13 00:32:49,618 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/postfix status norewrite returned 1 (14 - 13) (0.53 sec)
2011-07-13 00:32:49,634 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmsaslauthdctl status norewrite returned 1 (26 - 13) (0.01 sec)
2011-07-13 00:32:49,651 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmswatchctl status norewrite returned 1 (25 - 13) (0.02 sec)
2011-07-13 00:32:49,667 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmspellctl status norewrite returned 1 (27 - 13) (0.01 sec)
2011-07-13 00:32:50,072 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmstatctl status norewrite returned 1 (14 - 13) (0.40 sec)
2011-07-13 00:32:50,105 zmconfigd ERROR [10400-MainThread] Executed: /opt/zimbra/bin/zmclamdctl status norewrite returned 1 (23 - 13) (0.03 sec)
2011-07-13 00:32:50,105 zmconfigd ERROR [10400-MainThread] Watchdog: adding antivirus to restart list
2011-07-13 00:32:50,181 zmconfigd WARNING [10400-MainThread] All rewrite threads completed in 0.00 sec
2011-07-13 00:32:50,181 zmconfigd WARNING [10400-MainThread] controlProcess antivirus restart (-1)
2011-07-13 00:32:50,183 zmconfigd WARNING [10400-MainThread] CONTROL antivirus: bin/zmclamdctl restart norewrite
2011-07-13 00:32:50,183 zmconfigd CRITICAL [10400-MainThread] antivirus restart initiated from zmconfigd
2011-07-13 00:33:00,282 zmconfigd WARNING [10400-MainThread] All restarts completed in 10.10 sec
2011-07-13 00:33:04,989 zmconfigd WARNING [10400-SIGTERM handler] Shutting down. Received signal 15

zimbra start

2011-07-13 00:41:20,523 zmconfigd CRITICAL [21768-MainThread] zmconfigd started on dreadnought.taube.nl with loglevel=3 pid=21768
2011-07-13 00:41:20,549 zmconfigd WARNING [21768-MainThread] Fetching All configs
log4j:WARN No appenders could be found for logger (zimbra.ldap).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See Apache log4j 1.2 - Frequently Asked Technical Questions for more info.
2011-07-13 00:41:22,530 zmconfigd WARNING [21768-MainThread] All configs fetched in 1.98 seconds
2011-07-13 00:41:24,359 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/jetty.xml with mode 440 (0.19 sec)
2011-07-13 00:41:24,453 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/clamd.conf with mode 440 (0.09 sec)
2011-07-13 00:41:24,605 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/log4j.properties with mode 440 (0.15 sec)
2011-07-13 00:41:24,674 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/mta_milter_options with mode 440 (0.07 sec)
2011-07-13 00:41:24,717 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/postfix/conf/master.cf with mode 440 (0.04 sec)
2011-07-13 00:41:24,844 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/cyrus-sasl-2.1.23.3z/etc/saslauthd.conf with mode 440 (0.12 sec)
2011-07-13 00:41:24,882 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/jetty.properties with mode 440 (0.04 sec)
2011-07-13 00:41:24,951 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/spnego_java_options with mode 440 (0.07 sec)
2011-07-13 00:41:25,145 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/zimbraAdmin/WEB-INF/web.xml with mode 440 (0.19 sec)
2011-07-13 00:41:25,266 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/krb5.ini with mode 440 (0.12 sec)
2011-07-13 00:41:25,285 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/freshclam.conf with mode 600 (0.02 sec)
2011-07-13 00:41:25,427 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/stats.conf with mode 440 (0.14 sec)
2011-07-13 00:41:25,529 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/service/WEB-INF/web.xml with mode 440 (0.10 sec)
2011-07-13 00:41:25,575 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/postfix_header_checks with mode 440 (0.04 sec)
2011-07-13 00:41:25,676 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/zimlet/WEB-INF/web.xml with mode 440 (0.10 sec)
2011-07-13 00:41:25,687 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/spnego.conf with mode 440 (0.01 sec)
2011-07-13 00:41:25,740 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/zimbra/WEB-INF/web.xml with mode 440 (0.05 sec)
2011-07-13 00:41:25,868 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/spnego.properties with mode 440 (0.13 sec)
2011-07-13 00:41:25,997 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/amavisd.conf with mode 440 (0.13 sec)
2011-07-13 00:41:26,069 zmconfigd WARNING [21768-rewrites] Rewrote: /opt/zimbra/conf/salocal.cf with mode 440 (0.07 sec)
2011-07-13 00:41:31,736 zmconfigd WARNING [21768-MainThread] All rewrite threads completed in 7.57 sec
2011-07-13 00:41:31,739 zmconfigd WARNING [21768-MainThread] All restarts completed in 0.00 sec
2011-07-13 00:42:31,762 zmconfigd WARNING [21768-MainThread] Fetching All configs
2011-07-13 00:42:33,242 zmconfigd WARNING [21768-MainThread] All configs fetched in 1.48 seconds
2011-07-13 00:42:34,098 zmconfigd CRITICAL [21768-MainThread] Tracking service antispam
2011-07-13 00:42:34,101 zmconfigd WARNING [21768-MainThread] Watchdog: service antispam now available for watchdog.
2011-07-13 00:42:34,147 zmconfigd CRITICAL [21768-MainThread] Tracking service antivirus
2011-07-13 00:42:34,154 zmconfigd WARNING [21768-MainThread] Watchdog: service antivirus now available for watchdog.
2011-07-13 00:42:34,213 zmconfigd CRITICAL [21768-MainThread] Tracking service ldap
2011-07-13 00:42:34,216 zmconfigd WARNING [21768-MainThread] Watchdog: service ldap now available for watchdog.
2011-07-13 00:42:34,266 zmconfigd CRITICAL [21768-MainThread] Tracking service logger
2011-07-13 00:42:34,267 zmconfigd WARNING [21768-MainThread] Watchdog: service logger now available for watchdog.
2011-07-13 00:42:34,433 zmconfigd CRITICAL [21768-MainThread] Tracking service mailbox
2011-07-13 00:42:34,436 zmconfigd WARNING [21768-MainThread] Watchdog: service mailbox now available for watchdog.
2011-07-13 00:42:34,493 zmconfigd CRITICAL [21768-MainThread] Tracking service mailboxd
2011-07-13 00:42:34,496 zmconfigd WARNING [21768-MainThread] Watchdog: service mailboxd now available for watchdog.
2011-07-13 00:42:35,257 zmconfigd CRITICAL [21768-MainThread] Tracking service mta
2011-07-13 00:42:35,260 zmconfigd WARNING [21768-MainThread] Watchdog: service mta now available for watchdog.
2011-07-13 00:42:35,282 zmconfigd CRITICAL [21768-MainThread] Tracking service sasl
2011-07-13 00:42:35,285 zmconfigd WARNING [21768-MainThread] Watchdog: service sasl now available for watchdog.
2011-07-13 00:42:35,312 zmconfigd CRITICAL [21768-MainThread] Tracking service snmp
2011-07-13 00:42:35,315 zmconfigd WARNING [21768-MainThread] Watchdog: service snmp now available for watchdog.
2011-07-13 00:42:35,335 zmconfigd CRITICAL [21768-MainThread] Tracking service spell
2011-07-13 00:42:35,338 zmconfigd WARNING [21768-MainThread] Watchdog: service spell now available for watchdog.
2011-07-13 00:42:35,752 zmconfigd CRITICAL [21768-MainThread] Tracking service stats
2011-07-13 00:42:35,755 zmconfigd WARNING [21768-MainThread] Watchdog: service stats now available for watchdog.
2011-07-13 00:42:35,792 zmconfigd WARNING [21768-MainThread] Watchdog: service antivirus status is OK.
2011-07-13 00:42:35,992 zmconfigd WARNING [21768-MainThread] All rewrite threads completed in 0.00 sec
2011-07-13 00:42:35,993 zmconfigd WARNING [21768-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.

btw. why does this appear?
log4j:WARN No appenders could be found for logger (zimbra.ldap).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See Apache log4j 1.2 - Frequently Asked Technical Questions for more info.


And to make one thing absolutely clear: Zimbra is simply the best Mail/Time management tool out there, there is no doubt in my mind. I report these only to help you (and in that help myself) finding all bugs/undocumented features/improvement points.

Ciao, PP.

[quanah]

The restart every minute was added because of the fact that prior to upgrading Jython, zmconfigd died constantly. So that bit is remaining in place until such a time as we've seen proved stability (which I'm getting more comfortable with so far).

I've filed a bug on the watchdog restart issue -- zmconfigd definitely needs to be stopped earlier when zmcontrol stop is issued.

[fedya]

Could be related: [SOLVED] zmconfigd is not running.

In short: dying zmconfigd, make sure that you have nc and which installed.

[frosticus]

So last week I decided to pilot Zimbra server. Today, I see the desktop crap out with SOAP errors trying to move emails between our existing server and the new Zimbra server so I start looking thru error logs to see if I can find the source of the issue. I notice that the zmconfigd.log has a bunch of WARNINGs every few minutes. This looks bad - it appears that a service is getting constantly restarted! This couldn't be by design, besides being a horrible design, they wouldn't have put WARNING in big bold letters! So I search this forum only to see this thread. I'm not sure whether to laugh or cry.

In short, you have a bug you can't fix so you restart the service just in case it dies. To compound the problem, you flood the logs with notifications of same just so you know that it's successfully restarting. When someone reports the issue, you hit them with the old "this is not a bug, it's by design" routine. Classic.

Sure you don't actually insist that this is acceptable software design and that this is a closed issue?

[quanah]

Originally Posted by frosticus

In short, you have a bug you can't fix so you restart the service just in case it dies. To compound the problem, you flood the logs with notifications of same just so you know that it's successfully restarting. When someone reports the issue, you hit them with the old "this is not a bug, it's by design" routine. Classic.

Sure you don't actually insist that this is acceptable software design and that this is a closed issue?

Your comment does not contain any useful information. The issue reported in this thread has long since been fixed, nor are there any known issues that cause services to repeatedly crash. If you have actual useful information to supply, then please do so in a new thread.

--Quanah

[frosticus]

Originally Posted by quanah

Your comment does not contain any useful information. The issue reported in this thread has long since been fixed, nor are there any known issues that cause services to repeatedly crash. If you have actual useful information to supply, then please do so in a new thread.

--Quanah

I am running the latest version (7.1.4 downloaded 4 days ago). My system behaves exactly as described by this thread (warning messages in the log repeated at 1 minute intervals). Just so I am clear, you are classifying this as intended/desired behavior?

[quanah]

Originally Posted by frosticus

I am running the latest version (7.1.4 downloaded 4 days ago). My system behaves exactly as described by this thread (warning messages in the log repeated at 1 minute intervals). Just so I am clear, you are classifying this as intended/desired behavior?

No, that's is not what I said at all. I said that sort of behavior is not known to exist at this point in time. If that is what you are seeing, then that is not expected, intended, nor desired behavior. Again, please follow up with useful information on what it is you're seeing in your logs in a new thread.

--Quanah

[rodolfoap]

Clean install, on yesterday installed/upgraded centos, with 3days-downloaded zimbra. If it's useful, I believe it's the same error.

2012-02-10 10:55:46,539 zmconfigd CRITICAL [13512-MainThread] zmconfigd started on mail.domainchangedforhelpclaiming.com with loglevel=3 pid=13512
2012-02-10 10:55:46,607 zmconfigd WARNING [13512-MainThread] Fetching All configs
log4j:WARN No appenders could be found for logger (zimbra.ldap).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See Apache log4j 1.2 - Frequently Asked Technical Questions for more info.
2012-02-10 10:55:51,592 zmconfigd WARNING [13512-MainThread] All configs fetched in 4.99 seconds