[SOLVED] Logger problems after upgrade 5.0.9 to 6.0.6

[tgx]

Following wiki, tried the following:

>zmloggerctl status
zmlogswatchctl is not running

>./zmrrdfetch -f zmmtastats
DBI connect('dbname=/opt/zimbra/logger/db/data/logger.sqlitedb','',...) failed: unable to open database file at ./zmrrdfetch line 229
Can't call method "prepare" on an undefined value at ./zmrrdfetch line 57.

The /var/log/zimbra-stats.log file is empty zero byte file.

zmsoap -z GetLoggerStatsRequest stats/@name=zmmtastats | head -20
ERROR: service.FAILURE (system failure: Unable to read logger stats)

Additional info from /opt/zimbra/log/startup.log

no connection to syslog available
- unix dgram connect: Connection refused at .opt.zimbra/zimbramon/lib/Zimbra/Mon/Logger.pm line 44

[halley]

i have same problem.... how to fix this ??? thanks!!!

[jfthibault]

As a Zimbra partner, we ran into the very same problem during a customer upgrade, under similar circumstances:

ZCS 5.0.16 running on SLES 10 SP2 x86_64 on Xen DomU, upgrade to ZCS 6.0.4. Note: we didn't want to go to ZCS 6.0.6 directly, because it would have required a host OS upgrade for which there was no downtime allowed.

During upgrade, we found no noticeable errors on standard output, nor in /tmp/zmsetup.log, nor in /var/log/messages. Note: as best practice, we always tail -f /var/log/messages on a separate terminal during installs and upgrades. We find it will eventually leak info that stdout would otherwise skip and give you a head start on finding the root cause for unusual problems.

The upgrade completed fine and all ZCS services were functional, except that the Admin web interface Serer Status showed red X's for every service. Meanwhile su - zimbra; zmcontrol status showed every service as "Running".

Furthermore, clicking on any of the Server Statistics in the Admin web interface resulted in an error, which could eventually be root caused to the fact the sqlite logger DB had not been created during the upgrade (the /opt/zimbra/logger/db directory was empty) and the /var/log/zimbra-stats.log remained at 0 bytes.


The fix:

1. Make sure zmlogger is stopped. As the zimbra user, run:
zmloggerctl stop
pas ax | grep zmlogger

There should be no zmlogger process running. If there are still some, run:
killall zmlogger

2. Re-create the sqlite DB manually. As root, run:
rm -rf /opt/zimbra/logger/db/*
/opt/zimbra/libexec/zmfixperms

Then, as the zimbra user, run:
/opt/zimbra/libexec/zmlogger&

Note: normally you would not start zmlogger manually like this. Instead, you would use the zmloggerctl command. But in this case, the zmloggerctl might fail because we haven't fixed the problem of syslog not being able to log to the /var/log/zimbra-stats.log file (we'll do that next). So, this is just a temporary fix to create the sqlite logger DB files we need.

Check that the sqlite logger files exist. As root, run:
ls -lR /opt/zimbra/logger/db

Should output something like:
/opt/zimbra/logger/db:
total 0
drwxr-xr-x 3 zimbra zimbra 39 Apr 26 15:32 data

/opt/zimbra/logger/db/data:
total 24
-rw-r----- 1 zimbra zimbra 19456 Apr 26 15:32 logger.sqlitedb
drwxr-x--- 2 zimbra zimbra 4096 Apr 26 15:08 rrds

/opt/zimbra/logger/db/data/rrds:
total 38356
-rw-r----- 1 zimbra zimbra 648768 Apr 27 10:40 1-0.rrd
-rw-r----- 1 zimbra zimbra 11342616 Apr 27 10:40 1-1.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 1-2.rrd
-rw-r----- 1 zimbra zimbra 13611008 Apr 27 10:40 1-3.rrd
-rw-r----- 1 zimbra zimbra 3241216 Apr 27 10:40 1-4.rrd
-rw-r----- 1 zimbra zimbra 972824 Apr 27 10:39 1-5.rrd
-rw-r----- 1 zimbra zimbra 972824 Apr 27 10:39 1-6.rrd
-rw-r----- 1 zimbra zimbra 972824 Apr 27 10:39 1-7.rrd
-rw-r----- 1 zimbra zimbra 972824 Apr 27 10:39 1-8.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-0.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-1.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-10.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-2.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-3.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-4.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-5.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-6.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-7.rrd
-rw-r----- 1 zimbra zimbra 324712 Apr 27 10:40 2-8.rrd
-rw-r----- 1 zimbra zimbra 2917160 Apr 27 10:40 2-9.rrd

Once again, stop zmlogger. As the zimbra user, run:
zmloggerctl stop
pas ax | grep zmlogger

There should be no zmlogger process running. If there are still some, run:
killall zmlogger

3. Fix the syslog problem that prevents logging to /var/log/zimbra-stats.log.

Here, there are two variants of the problem. The first is those systems that use rsyslog which often only require a restart of rsyslogd. This issue is amply documented in several threads of the Zimbra forums, so I won't repeat those conversations here.

Our case was the second variant, involving those systems that use syslog-ng as a logging daemon. It turned out that the following file:
/etc/syslog-ng/syslog-ng.conf.in

was modified by the Zimbra installer in such a way that prevented the final system file:
/etc/syslog-ng/syslog-ng.conf

from being re-built correctly. Specifically, the directives that involve logging to the /var/log/zimbra-stats.log file didn't make to the final system file.

This is verified by running, as root, the following:
grep "# zimbra" syslog-ng.conf.in

Should output:
source zimbra_src { unix-stream("/dev/log"; keep-alive(yes); max-connections(20); }; # zimbra
filter zimbra_local0 { facility(local0); }; # zimbra
filter zimbra_local1 { facility(local1); }; # zimbra
filter zimbra_auth { facility(auth); }; # zimbra
filter zimbra_mail { facility(mail); }; # zimbra
destination zimbra_mail { file("/var/log/zimbra.log" owner("zimbra")); }; # zimbra
destination zimbra_local1 { file("/var/log/zimbra-stats.log" owner("zimbra")); }; # zimbra
destination zimbra_local0 { file("/var/log/zimbra.log" owner("zimbra")); }; # zimbra
destination zimbra_auth { file("/var/log/zimbra.log" owner("zimbra")); }; # zimbra
log { source(zimbra_src); filter(zimbra_mail); destination(zimbra_mail); }; # zimbra
log { source(zimbra_src); filter(zimbra_local0); destination(zimbra_local0); }; # zimbra
log { source(zimbra_src); filter(zimbra_local1); destination(zimbra_local1); }; # zimbra
log { source(zimbra_src); filter(zimbra_auth); destination(zimbra_auth); }; # zimbra

Then run:
grep "# zimbra" syslog-ng.conf

Should output:
filter zimbra_local0 { facility(local0); }; # zimbra
destination zimbra_mail { file("/var/log/zimbra.log" owner("zimbra")); }; # zimbra
log { source(zimbra_src); filter(zimbra_mail); destination(zimbra_mail); }; # zimbra
destination zimbra_local0 { file("/var/log/zimbra.log" owner("zimbra")); }; # zimbra
log { source(zimbra_src); filter(zimbra_local0); destination(zimbra_local0); }; # zimbra
filter zimbra_auth { facility(auth); }; # zimbra
destination zimbra_auth { file("/var/log/zimbra.log" owner("zimbra")); }; # zimbra
log { source(zimbra_src); filter(zimbra_auth); destination(zimbra_auth); }; # zimbra


From the above, we see that several lines from the syslog-ng.conf.in didn't make it to the syslog-ng.conf file.

After a few unsuccessful attempts to fix syslog-ng.conf.in and re-run zmsyslogsetup, which repeatedly caused the system to complain about the following line in syslog-ng.conf.in:
filter zimbra_auth { facility(auth); }; # zimbra

we simply chose to fix syslog-ng.conf directly. To do so, we stopped the syslog daemon. As root, run:
/etc/init.d/syslog stop

Then we edited syslog-ng.conf and made the last section look like this:

#
# Enable this, if you want to keep all messages in one file:
# (don't forget to provide logrotation config)
#
#destination allmessages { file("/var/log/allmessages"); };
#log { source(src); destination(allmessages); };


#filter f_local0 { facility(local0); }; # zimbra
#destination zmail { file("/var/log/zimbra.log" owner("zimbra") ); }; # zimbra
#log { source(src); filter(f_mail); destination(zmail); }; # zimbra
#destination local0 { file("/var/log/zimbra.log" owner("zimbra") ); }; # zimbra
#log { source(src); filter(f_local0); destination(local0); }; # zimbra
#filter f_auth { facility(auth); }; # zimbra
#destination zmauth { file("/var/log/zimbra.log" owner("zimbra") ); }; # zimbra
#log { source(src); filter(f_auth); destination(zmauth); }; # zimbra

filter f_local0 { facility(local0); }; # zimbra
filter f_local1 { facility(local1); }; # zimbra
destination zmail { file("/var/log/zimbra.log" owner("zimbra") ); }; # zimbra
destination zmstats { file("/var/log/zimbra-stats.log" owner("zimbra") ); }; # zimbra
log { source(src); filter(f_mail); destination(zmail); }; # zimbra
destination local0 { file("/var/log/zimbra.log" owner("zimbra") ); }; # zimbra
log { source(src); filter(f_local0); destination(local0); }; # zimbra
log { source(src); filter(f_local1); destination(zmstats); }; # zimbra
filter f_auth { facility(auth); }; # zimbra
destination zmauth { file("/var/log/zimbra.log" owner("zimbra") ); }; # zimbra
log { source(src); filter(f_auth); destination(zmauth); }; # zimbra

Note that we intentionally chose to make filer and destination directive tokens unique, as to avoid any potential source of problems with syslog-ng.

The, restart syslog-ng. As root, run:
/etc/init.d/syslog start

At this point, it is required to at least bounce the zmlogger service. Better yet, if you can afford it, is to simply restart zimbra. As the zimbra user, run:
zmloggerctl reload

or
zmcontrol stop
zmcontrol start

At that point, the /var/log/zimbra-stats.log file starts to grow, and you can also expect acceptable output from the following command run as the zimbra user:

libexec/zmrrdfetch -f zmmtastats | head

Should output something like:
Host: myhost.mydomain.com

timestamp,filter_misc,clam_events,mta_delay,mta_vo lume,filter_virus,filter_count,mta_count,filter_sp am,sendmail_events
1272304470,0,0,,1191.67361392743,0,0.0485729951420 127,0.0987912529399062,0.0317953368484273,0
1272304500,0,0,,1191.67361392743,0,0.0485729951420 127,0.0987912529399062,0.0317953368484273,0
1272304530,0,0,,1191.67361392743,0,0.0485729951420 127,0.0987912529399062,0.0317953368484273,0
1272304560,0,0,,1191.67361392743,0,0.0485729951420 127,0.0987912529399062,0.0317953368484273,0
1272304590,0,0,,1191.67361392743,0,0.0485729951420 127,0.0987912529399062,0.0317953368484273,0
1272304620,0,0,,1191.67361392743,0,0.0485729951420 127,0.0987912529399062,0.0317953368484273,0

If you get this far, it should be a matter of less than an hour until there is enough statistical data accumulated for some of the graphs to show up in the Server Statistic web admin interface, and for those red X's to be replaced by nice blue checkmarks in the Server Status page.

I hope this helps anyone running into the same issue as we did.

[tgx]

You are the man.

I should mention that the issues and findings I had made were
verbatim as to what you indicated, however, I was at a loss as
to where to begin to fix it. Your solution was spot on. To others
if you have problems with zmstats after the above procedure, do
a zmstatctl stop, wait a minute and then run zmstatctl start and
wait a few minutes. Then do a zmcontrol status and see if
it is running. The stats process was a little slow on my server to
start after the repairs.

Thanks again!

[det]

Hi,

I noticed that the logger is not able to display correct server/service statistics because in zimbra-stats.log it is duplicating the server hostname.

logger server zimbra-stats.log
Apr 5 11:30:06 mtasvr1 mtasvr1 zimbramon[28134]: 28134:info: 2011-04-05 11:30:01, STATUS: mtasvr1.mydomain.com: mta: Running
Apr 5 11:30:06 mtasvr1 mtasvr1 zimbramon[28134]: 28134:info: 2011-04-05 11:30:01, STATUS: mtasvr1.mydomain.com: snmp: Running
Apr 5 11:30:06 mtasvr1 mtasvr1 zimbramon[28134]: 28134:info: 2011-04-05 11:30:01, STATUS: mtasvr1.mydomain.com: stats: Running


mtasrv1 zimbra-stats.log
Apr 5 06:38:07 mtasvr1 zimbramon[10359]: 10359:info: 2011-04-05 06:38:02, STATUS: mtasvr1.mydomain.com: snmp: Running
Apr 5 06:38:07 mtasvr1 zimbramon[10359]: 10359:info: 2011-04-05 06:38:02, STATUS: mtasvr1.mydomain.com: stats: Running
Apr 5 06:40:06 mtasvr1 zimbramon[10704]: 10704:info: 2011-04-05 06:40:01, STATUS: mtasvr1.mydomain.com: mta: Running

[ericortego]

bump ^^ What det said.

A good explanation and solution can be found here:
http://www.rsyslog.com/doc/rsyslog_conf_actions.html

Note to sysklogd users: sysklogd does not support RFC 3164 format, which is the default forwarding template in rsyslog. As such, you will experience duplicate hostnames if rsyslog is the sender and sysklogd is the receiver. The fix is simple: you need to use a different template. Use that one:

$template sysklogd,"<%PRI%>%TIMESTAMP% %syslogtag%%msg%\""
*.* @192.168.0.1;sysklogd

I added this

$template Zimbra,"<%PRI%>%TIMESTAMP% %syslogtag%%msg%"

to my /etc/rsyslog.conf file

then changed the lines that zmloggerinit set in it from

local0.* @zimbra.mydomain.com
local1.* @zimbra.mydomain.com
auth.* @zimbra.mydomain.com
mail.* @zimbra.mydomain.com

to

local0.* @zimbra.mydomain.com;Zimbra
local1.* @zimbra.mydomain.com;Zimbra
auth.* @zimbra.mydomain.com;Zimbra
mail.* @zimbra.mydomain.com;Zimbra