[SOLVED] zmconfigd WARNING in 7.0.0 GA

[Labsy]

Hi,

after upgrading on Ubuntu 8.04 64-bit from 6.0.7 to 7.0.0, I first bumped into INSTALL warning, saying sqlite3 is not installed, but I continued installation disregarding this warning.
The rest of install finished fine, no errors on screen...but first running ZCS 7.0.0 got "relay Access denied" for all incoming mail, and also outgoing did not work. This part of problem was solved by manually replaying the postfix config command, which had status ERROR in /opt/zimbra/log/zmconfigd.log
Manually issuing this command (longest line, with lots of config settings) did not produce error, and restarting postfix solved the problem.

But I still notice WARNING in /opt/zimbra/log/zmconfigd.log file issued every 1 minute:

Starting zmconfigd...zmconfigd is already running.
2011-02-14 09:24:28,861 zmconfigd WARNING [8394-MainThread] Fetching All configs
2011-02-14 09:24:29,107 zmconfigd WARNING [8394-MainThread] All configs fetched in 0.24 seconds
2011-02-14 09:24:29,342 zmconfigd WARNING [8394-MainThread] All rewrite threads completed in 0.01 sec
2011-02-14 09:24:29,342 zmconfigd WARNING [8394-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-02-14 09:25:29,354 zmconfigd WARNING [8394-MainThread] Fetching All configs
2011-02-14 09:25:29,585 zmconfigd WARNING [8394-MainThread] All configs fetched in 0.23 seconds
2011-02-14 09:25:29,786 zmconfigd WARNING [8394-MainThread] All rewrite threads completed in 0.00 sec
2011-02-14 09:25:29,786 zmconfigd WARNING [8394-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-02-14 09:26:29,798 zmconfigd WARNING [8394-MainThread] Fetching All configs
2011-02-14 09:26:30,132 zmconfigd WARNING [8394-MainThread] All configs fetched in 0.34 seconds
2011-02-14 09:26:30,338 zmconfigd WARNING [8394-MainThread] All rewrite threads completed in 0.00 sec
2011-02-14 09:26:30,339 zmconfigd WARNING [8394-MainThread] All restarts completed in 0.00 sec

Any idea?

[Labsy]

Actually, after I issue

zmcontrol restart

I find lots of warnings and Error in /opt/zimbra/log/zmconfigd.log

2011-02-14 10:32:59,828 zmconfigd WARNING [8394-SIGTERM handler] Shutting down. Received signal 15
2011-02-14 10:33:22,842 zmconfigd CRITICAL [13494-MainThread] zmconfigd started on zimbra.server.realname with loglevel=3 pid=13494
2011-02-14 10:33:23,002 zmconfigd WARNING [13494-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 http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
2011-02-14 10:33:24,951 zmconfigd WARNING [13494-MainThread] All configs fetched in 1.95 seconds
[] INFO: Loading server object: zimbra.server.realname
2011-02-14 10:33:27,803 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/jetty.xml with mode 440 (1.18 sec)
2011-02-14 10:33:27,868 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/spnego/WEB-INF/web.xml with mode 440 (0.03 sec)
[] INFO: Added server to HTTP upstream: zimbra.server.realname
2011-02-14 10:33:28,211 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/clamd.conf with mode 440 (0.34 sec)
2011-02-14 10:33:28,216 zmconfigd ERROR [13494-postconf] Executed: /opt/zimbra/postfix/sbin/postconf -e mail_owner='postfix' bounce_notice_recipient='postmaster' content_filter='smtp-amavis:[127.0.0.1]:10024' relayhost='' smtpd_sasl_authenticated_header='no' broken_sasl_auth_clients='yes' minimal_backoff_time='300s' sender_canonical_maps='proxy:ldap:/opt/zimbra/conf/ldap-scm.cf' always_add_missing_headers='yes' smtpd_tls_key_file='/opt/zimbra/conf/smtpd.key' smtpd_helo_required='yes' virtual_transport='error' sendmail_path='/opt/zimbra/postfix/sbin/sendmail' smtpd_recipient_restrictions='reject_non_fqdn_recipient, permit_sasl_authenticated, permit_mynetworks, reject_unauth_destination, reject_unlisted_recipient, reject_invalid_hostname, reject_non_fqdn_sender, reject_unknown_sender_domain, reject_rbl_client zen.spamhaus.org reject_rbl_client psbl.surriel.com reject_rbl_client dnsbl.dronebl.org reject_rbl_client bl.spameatingmonkey.net, permit' smtpd_reject_unlisted_recipient='no' bounce_queue_lifetime='5d' local_header_rewrite_clients='permit_mynetworks,permit_sasl_authenticated' smtpd_data_restrictions='reject_unauth_pipelining' smtpd_tls_security_level='may' smtpd_milters='' smtpd_sender_restrictions='' lmtp_host_lookup='dns' delay_warning_time='0h' virtual_mailbox_maps='proxy:ldap:/opt/zimbra/conf/ldap-vmm.cf' queue_run_delay='300s' header_checks='' notify_classes='resource,software' command_directory='/opt/zimbra/postfix/sbin' smtpd_client_restrictions='reject_unauth_pipelining' smtpd_tls_auth_only='yes' virtual_alias_maps='proxy:ldap:/opt/zimbra/conf/ldap-vam.cf' mailq_path='/opt/zimbra/postfix/sbin/mailq' mynetworks='127.0.0.0/8 195.246.15.0/24' lmtp_connection_cache_time_limit='4s' transport_maps='proxy:ldap:/opt/zimbra/conf/ldap-transport.cf' virtual_alias_domains='proxy:ldap:/opt/zimbra/conf/ldap-vad.cf' smtpd_sasl_auth_enable='yes' smtpd_tls_loglevel='1' maximal_backoff_time='4000s' virtual_mailbox_domains='proxy:ldap:/opt/zimbra/conf/ldap-vmd.cf' daemon_directory='/opt/zimbra/postfix/libexec' non_smtpd_milters='' setgid_group='postdrop' alias_maps='hash:/etc/aliases' mydestination='localhost' myhostname='zimbra.server.realname' message_size_limit='81920000' recipient_delimiter='' in_flow_delay='1s' queue_directory='/opt/zimbra/data/postfix/spool' propagate_unmatched_extensions='canonical' manpage_directory='/opt/zimbra/postfix/man' smtpd_tls_cert_file='/opt/zimbra/conf/smtpd.crt' lmtp_connection_cache_destinations='' newaliases_path='/opt/zimbra/postfix/sbin/newaliases' policy_time_limit='3600' mailbox_size_limit='0' disable_dns_lookups='no' returned 1 (0 - 79) (1.57 sec)
2011-02-14 10:33:28,578 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/log4j.properties with mode 440 (0.36 sec)
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.template to file:/opt/zimbra/conf/nginx.conf
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.main.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.main
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.memcache.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.memcache
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail
2011-02-14 10:33:28,661 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/mta_milter_options with mode 440 (0.08 sec)
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imap.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imap
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imap.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imap.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imaps.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imaps
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.imaps.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.imaps.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3s.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3s
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.mail.pop3s.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.mail.pop3s.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.default.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.default
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-http.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-http
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-https.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-https
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-both.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-both
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-redirect.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-redirect
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.http.mode-mixed.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.http.mode-mixed
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-http.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-http
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-https.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-https
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-both.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-both
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-redirect.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-redirect
[] INFO: Expanding template:/opt/zimbra/conf/nginx/templates/nginx.conf.web.https.mode-mixed.template to file:/opt/zimbra/conf/nginx/includes/nginx.conf.web.https.mode-mixed
[] INFO: Proxy configuration files are generated successfully
2011-02-14 10:33:28,930 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/postfix/conf/master.cf with mode 440 (0.26 sec)
2011-02-14 10:33:28,960 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/cyrus-sasl-2.1.23.3z/etc/saslauthd.conf with mode 440 (0.02 sec)
2011-02-14 10:33:29,201 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/jetty.properties with mode 440 (0.24 sec)
2011-02-14 10:33:29,220 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/spnego_java_options with mode 440 (0.02 sec)
2011-02-14 10:33:29,342 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/zimbraAdmin/WEB-INF/web.xml with mode 440 (0.12 sec)
2011-02-14 10:33:29,529 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/krb5.ini with mode 440 (0.14 sec)
2011-02-14 10:33:29,848 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/spnego/spnego_error.jsp with mode 440 (0.24 sec)
2011-02-14 10:33:30,009 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/freshclam.conf with mode 600 (0.16 sec)
2011-02-14 10:33:30,061 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/stats.conf with mode 440 (0.05 sec)
2011-02-14 10:33:30,404 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/service/WEB-INF/web.xml with mode 440 (0.34 sec)
2011-02-14 10:33:30,634 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/postfix_header_checks with mode 440 (0.22 sec)
2011-02-14 10:33:30,696 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/zimlet/WEB-INF/web.xml with mode 440 (0.06 sec)
2011-02-14 10:33:30,716 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/spnego.conf with mode 440 (0.02 sec)
2011-02-14 10:33:31,069 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/webapps/zimbra/WEB-INF/web.xml with mode 440 (0.35 sec)
2011-02-14 10:33:31,145 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/mailboxd/etc/spnego.properties with mode 440 (0.07 sec)
2011-02-14 10:33:31,974 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/amavisd.conf with mode 440 (0.82 sec)
2011-02-14 10:33:32,391 zmconfigd WARNING [13494-rewrites] Rewrote: /opt/zimbra/conf/salocal.cf with mode 440 (0.39 sec)
2011-02-14 10:33:33,635 zmconfigd WARNING [13494-MainThread] All rewrite threads completed in 7.03 sec
2011-02-14 10:33:33,642 zmconfigd WARNING [13494-MainThread] All restarts completed in 0.00 sec
2011-02-14 10:34:33,776 zmconfigd WARNING [13494-MainThread] Fetching All configs
2011-02-14 10:34:34,128 zmconfigd WARNING [13494-MainThread] All configs fetched in 0.35 seconds
2011-02-14 10:34:35,082 zmconfigd WARNING [13494-MainThread] All rewrite threads completed in 0.02 sec
2011-02-14 10:34:35,085 zmconfigd WARNING [13494-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-02-14 10:35:35,180 zmconfigd WARNING [13494-MainThread] Fetching All configs
2011-02-14 10:35:35,512 zmconfigd WARNING [13494-MainThread] All configs fetched in 0.33 seconds
2011-02-14 10:35:36,022 zmconfigd WARNING [13494-MainThread] All rewrite threads completed in 0.00 sec
2011-02-14 10:35:36,023 zmconfigd WARNING [13494-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-02-14 10:36:36,045 zmconfigd WARNING [13494-MainThread] Fetching All configs
2011-02-14 10:36:36,388 zmconfigd WARNING [13494-MainThread] All configs fetched in 0.34 seconds
2011-02-14 10:36:36,796 zmconfigd WARNING [13494-MainThread] All rewrite threads completed in 0.00 sec
2011-02-14 10:36:36,799 zmconfigd WARNING [13494-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.
2011-02-14 10:37:36,812 zmconfigd WARNING [13494-MainThread] Fetching All configs
2011-02-14 10:37:37,131 zmconfigd WARNING [13494-MainThread] All configs fetched in 0.32 seconds
2011-02-14 10:37:37,665 zmconfigd WARNING [13494-MainThread] All rewrite threads completed in 0.00 sec
2011-02-14 10:37:37,667 zmconfigd WARNING [13494-MainThread] All restarts completed in 0.00 sec
Starting zmconfigd...zmconfigd is already running.

Could it be because I did not install sqlite3?
Or because I did not manually upgrae MySQL database scheme (if it wasn't upgraded automatically)?

Also:

zimbra@zimbra:/home$ postfix stop
postfix/postfix-script: stopping the Postfix mail system
zimbra@zimbra:/home$ postfix start
postfix/postfix-script: warning: not owned by root: /opt/zimbra/data/postfix/spool
postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.7.2.2z/conf/main.cf
postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.7.2.2z/conf/master.cf
postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.7.2.2z/conf/master.cf.in
postfix/postfix-script: starting the Postfix mail system

[phoenix]

Could it be because I did not install sqlite3?

No, it couldn't. It's the cbpolicyd daemon that uses sqlite3 and that's optional but if you use it you'll need sqlite3 installed.

Or because I did not manually upgrae MySQL database scheme (if it wasn't upgraded automatically)?

No, it couldn't be because of that either, although you need to run an update script after the upgrade (see the Release Notes for details).

The messages you're seeing from configd are merely warnings and perfectly normal.

Also:

zimbra@zimbra:/home$ postfix stop
postfix/postfix-script: stopping the Postfix mail system
zimbra@zimbra:/home$ postfix start
postfix/postfix-script: warning: not owned by root: /opt/zimbra/data/postfix/spool
postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.7.2.2z/conf/main.cf
postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.7.2.2z/conf/master.cf
postfix/postfix-script: warning: not owned by root: /opt/zimbra/postfix-2.7.2.2z/conf/master.cf.in
postfix/postfix-script: starting the Postfix mail system

They are also just warnings and normal, they've always been produced in all versions when you start Zimbra.

[Labsy]

Hi Bill,
thank you for response and explanation!
Hope Zimbra installer gets rid of the main error, which seems to be fixed by manually running postfix config line from first post.

[cvidal]

The problem is generic with Z7 GA (at least on RHEL5), I tested it on 3 different servers. Steps to reproduce it:

su - zimbra
zmcontrol stop
mv postfix/conf/main.cf /tmp
ldap start
/opt/zimbra/bin/zmconfigdctl start

In the /opt/zimbra/log/zmconfigd.log file you will see the line:

 zmconfigd ERROR [2835-postconf] Executed: /opt/zimbra/postfix/sbin/postconf -e mail_owner='postfix' ... limit='0' disable_dns_lookups='no' returned 1 (0 - 79) (1.22 sec)

If the postconf command is executed by hand it works flawlessly and returns with exit status 0.

As long as the main.cf file exists the postconf is never executed, so the bug is not seen.

[cvidal]

I replaced /opt/zimbra/postfix/sbin/postconf with a script dumping the arguments, user, PATH and current working directory to a file. This is what I get:

/opt/zimbra/postfix/sbin/postconf
ARGS: mail_owner=postfix setgid_group=postdrop

User: root
Path: /usr/bin:/bin
 CWD: /opt/zimbra

************************************************
/opt/zimbra/postfix/sbin/postconf
ARGS: mail_owner=postfix bounce_notice_recipient=postmaster content_filter=smtp-amavis:[127.0.0.1]:10024 relayhost=smtp.wanadoo.fr smtpd_sasl_authenticated_header=no broken_sasl_auth_clients=yes minimal_backoff_time=300s 
...... (cut for length sake) ......
lmtp_connection_cache_destinations= newaliases_path=/opt/zimbra/postfix/sbin/newaliases policy_time_limit=3600 mailbox_size_limit=0 disable_dns_lookups=no

User: zimbra
Path: /opt/zimbra/bin:/opt/zimbra/postfix/sbin:/opt/zimbra/openldap/bin:/opt/zimbra/snmp/bin:/opt/zimbra/bdb/bin:/opt/zimbra/openssl/bin:/opt/zimbra/java/bin:/usr/sbin:/usr/kerberos/bin:/usr/lib64/ccache:/usr/local/bin:/bin:/usr/bin
 CWD: /home/whm

So, the first time the command is called as root from /opt/zimbra and generates main.cf with 2 lines:
mail_owner=postfix
setgid_group=postdrop

The next time is the proper configuration call, but this time the command is called as zimbra. When running from a shell prompt as root and zimbra, these commands run OK if I do:

touch /opt/zimbra/postfix-2.7.2.2z/conf/main.cf

before starting, but from zmconfigd it doesn't work.

Should I post this in bugzilla?

[quanah]

No do not post in BZ, this bug is already fixed.

[pbruna]

No do not post in BZ, this bug is already fixed.

In what version?

[Perlpigeon]

I still have this error in 7.1.1 + Patch 2 on Ubuntu 10.04.2 LTS x64_86...

If it is solved then I would also like to know the version...

[phoenix]

I still have this error in 7.1.1 + Patch 2 on Ubuntu 10.04.2 LTS x64_86...

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

If it is solved then I would also like to know the version...

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