mail.log rotation

[AlArenal]

I'm sorry for crossposting (http://www.howtoforge.com/forums/showpost.php?p=77524&postcount=26), but I need a solution to a problem induced by ISPConfig.

I'm using Debian Etch with ISPC and Postfix on which by default the mail logs are rotated by syslog's cronjob around 06:30 every morning. Problem is, that at 23:00 an ISPC cronjob starts mail_logs.php which does something to mail.log (gather statistics and stuff), copying it from here to there, starting a new one, ... pretty weird and not really documented stuff.

Question:
Can't you use something more spohisticated, leaving the original log files as they are, so ISPC's cron job does not interfer with other cron jobs?

In the meantime:
Is mail_logs.php something so cool I wouldn't want to live without it running every night or may I just throw it out of my crontab?

Thx :)

[falko]

In the meantime:
Is mail_logs.php something so cool I wouldn't want to live without it running every night or may I just throw it out of my crontab?

You can remove it from your crontab if you don't care about email traffic statistics in ISPConfig. :)

[AlArenal]

That's cool, thank you!

BTW, do you plan to redesign this part in ISPConfig 3?

[till]

I never seen your problem on any other installation, so I guess it must have something to do that cronjobs on your server collide. Please try to run the conjobs at another time so they dont collide.

BTW, do you plan to redesign this part in ISPConfig 3?

ISPconfig 3 has a new virtual mail system.

[Morons]

You can remove it from your crontab if you don't care about email traffic statistics in ISPConfig. :)
What traffic statistics, how do I get that statistics you speak about?:confused:

[till]

What traffic statistics, how do I get that statistics you speak about?:confused:

The mail traffic statistics are on the statistics tab of the website in ISPConfig like all other traffic stats :)

[Morons]

The mail traffic statistics are on the statistics tab of the website in ISPConfig like all other traffic stats :)
That statistics for mail is in any case totally not functioning and soe time show zero value, the reason is that ISP rotate the logfiles at mindnite, causing syslog sometime NOT to work at all till the next day 06:23! when syslog can restart it. I saw these gaps in logfiles as I analyse them with some scripts but found them unreliable and full of gaps! Thus far I could not detect the villan! Gotcha!:D

[Anwe]

We are also experiencing this problem. Each day the mail.log gets rotated at 23:59 by ISPConfig and then again by logrotate at 06:25. We're using Debian Etch, Postfix (from etch) and ISPConfig 2.2.13.

Is there a simple way to modify the script to work on a temporary copy? I would rather not deactivate the traffic statistics, customers would probably complain.

Also the mail_logs.php script won't compress old logs, this seems a bit wasteful. I noticed my maillogs for this machine are above 5 GB since about may :) I do monitor so i would've caught this before it became a problem, but i tend to assume logs are rotated correctly.

Kind regards
Andreas Wettergren

[falko]

I've added this to our bugtracker.

[till]

Is there a simple way to modify the script to work on a temporary copy? I would rather not deactivate the traffic statistics, customers would probably complain.

I checked the mail logs script. ISPConfig works already on a temporary copy and not on the original mail logfile.

Also the mail_logs.php script won't compress old logs, this seems a bit wasteful. I noticed my maillogs for this machine are above 5 GB since about may I do monitor so i would've caught this before it became a problem, but i tend to assume logs are rotated correctly.

ISPConfig does not rotate logs, its just analyzes a temporary copy. You should check your log rotate settings to ensure that the mail log is compressed.

[lewis_saint]

I too am having problems. All of my rotated mail.log files start at 23:59 and end at 06:25. It is as if ISPC deletes all prior content in the log file when it analyses it at 23:59. Till, falko, any suggestions?
Regards,
Lewis

[xrat]

Eventually, I took the time to investigate this a bit more. My Debian box with ISPconfig is running Debian 4.0 "Etch" (pretty much a default installation) with a current ISPconfig v2.2.19.

The problem persists: /var/log/mail.log.0 shows only lines from midnight until approximately 6:30. The reason is, vaguely put, a conflict between default Debian log file rotation and ISPconfig, more specifically its cronjob
59 23 * * * /root/ispconfig/php/php /root/ispconfig/scripts/shell/mail_logs.php

BTW, if you miss your data have a look at the other mail.* log files, especially /var/log/mail.info

Whether your Debian log file rotation kicks in or not you can check with
syslogd-listfiles --weekly
It returns all files which get rotated weekly by means of /etc/cron.weekly/sysklogd which again, on my system, is run every Sunday morning at 6:47 (see /etc/crontab).

But the main problem I see -- sorry to say this -- in ISPconfig's /root/ispconfig/scripts/shell/mail_logs.php -- though the whole issue is definitely not trivial. Anyway, from my point of view, mail_logs.php needs some rethinking.

As till wrote, mail_logs.php is working on a temporary copy. I guess he referred to line 53
$mod->log->caselog("cp -f $dist_mail_log $dist_mail_log.$datum", $FILE, __LINE__);
So this is true. But a few lines further below the original data is overwritten with
$fp = fopen($dist_mail_log, "w");
fwrite($fp, "");
fclose($fp);

There our data is lost. mail_logs.php deletes everything until midnight.

I do not know enough about ISPconfig but I am afraid this here is bound to break on systems with log rotation that occurs during the day. I guess it also means that ISPconfig's mail stats are not accurate. Certainly, just disabling the lines which erase $dist_mail_log does not help.

Nevertheless, maybe there is a simpler fix since till reported that he has never seen this problem, probably for a reason.

HTH,
-- xrat

P.S.: In mail_logs.php there are references to $datum2 which I assume does not exist/is empty. It does not break the script but I recommend to fix it anyway should the code ever be used somewhere else.

[xrat]

Whether your Debian log file rotation kicks in or not you can check with syslogd-listfiles --weekly. It returns all files which get rotated weekly by means of /etc/cron.weekly/sysklogd which again, on my system, is run every Sunday morning at 6:47 (see /etc/crontab).
When I wrote this I missed the fact that mail.log is also rotated on a daily basis at 6:25 by means of /etc/crontab -> /etc/cron.daily/sysklogd

A quick fix to the issues pointed out above is the following:

Make syslog to log all mail.* data to another log file which is then used only by ISPconfig. E.g. add to /etc/syslog.conf the line
mail.* -/var/log/mail.log4ispc
Create a copy of the already existing log file with the new name and reload syslog's configuration with
cd /var/log
cp -a mail.log mail.log4ispc && /etc/init.d/sysklogd reload

Then change the log file name in ISPconfig. Login as admin and go to Management > Server > Settings. On tab "EMail" change field "Log File" from (I suppose, at least for Debian) /var/log/mail.log to /var/log/mail.log4ispc

Note that with these settings also /var/log/mail.log4ispc will get automagically rotated by Debian's sysklogd but only weekly. Thus, every Sunday the mail stats of ISPconfig will miss 6 hours.

Please check yourself if the here suggested changes are suitable for your system.

HTH,
-- xrat

[Morons]

Best practice would be to include the cronjobs into the /etc/cron.daily, /etc/cron.weekly etc.
If we can get all the ispc cron scripts under /etc/cron.daily that process all the daily ispc activity then the system will take care of the timing and rotations will be synchronized.

[lewis_saint]

Is there a simple fix possible for /root/ispconfig/scripts/shell/mail_logs.php?

Lewis

[wpwood3]

I am having this same problem.
My mail logs do not include a full 24 hour day.

Is there a fix in the works?

[xrat]

Dude, it's up there!

[lewis_saint]

Note that with these settings also /var/log/mail.log4ispc will get automagically rotated by Debian's sysklogd but only weekly. Thus, every Sunday the mail stats of ISPconfig will miss 6 hours.


By your own words xrat, the fix improves the situation, but does not fully rectify the problem.

Regards,

Lewis

[wpwood3]

Dude, it's up there!Dude...that's a hack. Not a fix.

A fix means that the bug in ISPConfig is addressed so the problem does not occur.

[till]

We will have a look at this. Falko already added it to the bugtracker.

[wpwood3]

We will have a look at this. Falko already added it to the bugtracker.This issue shows "not a bug" in the bugtracker (http://bugtracker.ispconfig.org/).

How can this be? All of my maillog files only show entries from 23:59 to 04:06. There is most certainly a problem!

[falko]

I've reopened it again.

[jbravo]

One question related:
Is it safe to logrotate /var/log/mail.ispconfigsave file and still have all mail statistics?

[falko]

Yes, that's no problem.

[jbravo]

Yes, that's no problem.

Should i insert some postrotate job? It seems to me that this log file is used only by cronscript so it is not needed.

[xrat]

Should i insert some postrotate job? It seems to me that this log file is used only by cronscript so it is not needed.

This is right. No postrotate job is needed. Of course, the rotation should not be done while the ISPconfig cron job is running, which should be at midnight. HTH.

[make-fun]

Hi folks,

unfortunatly I did not find this thread earlier and so far I can only confirm that this is also a problem with Ubuntu 6.06 (perfect setup) and ISPConfigVersion: 2.2.21
http://www.howtoforge.com/forums/showthread.php?p=114698#post114698

Cheers

[Morons]

Hi people, I have implemented a quick and very effective workaround for the broken logrotation on all my Ubuntu boxes, I have the last 2 Ubuntu versions all upgraded to latest via apt-get. It also make sure the postgrey does not die on me. Perhaps this posting may help Postgrey users to solve the constant dying issues on Ubuntu.

In crontab
22 06 * * * /bin/kill -9 `/usr/bin/pgrep postgrey-check.rc`
37 06 * * * echo "Daily logrotation." >/root/boot-reason
38 06 * * * /sbin/shutdown -r now
Note: The idea is to "fix" the broken parts of the logrotation, therefore killing my own checking scripts before the logrotation at 23 06 and restarting the stuff after logrotation, yes in this case via re-boot witch helps a lot. I have an mail sent to me each time the server statrup with the reason given the content of an file called "/root/boot-reason". this way all my scripts etc can send me notes if they re-started the server and for what reason.

First the Postgrey Fix
in the file postgrey-check.rc i have
#!/bin/bash
LOGFILE=/var/log/syslog
(
while read ans
do
DUMMY=
done
#echo "Going to main loop"
while :
do
read ans
if [ "$ans" = "" ]
then
sleep 1
else
problem=`echo $ans | grep 'Server configuration problem'`
if [ "$problem" != "" ] && grep "$problem" $LOGFILE > /dev/null
then
/usr/sbin/invoke-rc.d postgrey restart
/usr/sbin/invoke-rc.d postfix restart
echo 'Postgrey broken!' 2>&1 |/usr/bin/mailx -s "`uname -n` Postgrey And Postfix re-started" root@domain.tld
fi
fi
done
) < $LOGFILE
Note: I loop through the logfile constantly grep for the error, then imediatly act! As this does not reboot the server I have to mail myself some message of this error occuring. The funny thing is since I actually re-boot the server just after each log-rotation Postgrey never have issues. Apearently Postgrey run into file access rights on Ubuntu after logrotation, I cannot confirm this but it does seem so. After re-booting Postgrey re-start properly.

Now the Startup
In the file /etc/rc.local
cat /root/boot-reason 2>&1 |/usr/bin/mailx -s "`uname -n` Server restarted" root@domain.tld
echo "No reason given" >/root/boot-reason
/usr/bin/postgrey-check.rc >/dev/null &

to get mailx use apt-get install mailx:cool:

[falko]

I think I've finally fixed the log rotation problem in ISPConfig. :)
The fix will be available with the next ISPConfig version.

[xrat]

This is good news :) Can you say a word or two about how you approached it?

[falko]

We don't delete the lines from the original logs anymore, but instead do a grep on the date and work on the copy.

[zalo]

Thanks falko

Is there info about when the new version will be released? Have been waiting for this fix a while.

Zalo :D

[falko]

It has been released today (version 2.2.22). :)