Log rotating of tomcat7 finds too old files.

Bug #1694923 reported by Thorsten Schöning
22
This bug affects 2 people
Affects Status Importance Assigned to Milestone
tomcat7 (Ubuntu)
Confirmed
Undecided
Unassigned

Bug Description

I've additionally described that problem on some other topic on SO:

https://superuser.com/questions/1214566/why-does-the-behaviour-of-find-differ-using-daystart-and-mtime-0-vs-0

My web apps hosted by Tomcat7 log into /var/log/tomcat7 as well, with the only difference that I name my log files per month instead of per day. The problem is that the default log rotating script with compression enabled finds those log files even though they didn't change at a particular day like "yesterday", but only some days before the last time. That leads to unnecessary error mails from cron because the files can't be zipped if they already have been zipped before in the same month. The reason for that is name clashes of course, because my names potentially exist pretty often already per month.

In general I can live with those messages coming once a while per month, because my log files only contain error messages, which simply don't occur that often. So the files shouldn't change very often and log rotating shouldn't try to zip the old files. But in fact it does try to zip those files every day even if they didn't change for some days.

Look at the following example, where in one of my own log dirs a log file is present which was last changed some days ago, at 29.05.2017, while we today have the 01.06.2017. That log file from the last month is found when executing the find used in the log rotating script, which is something I wouldn't expect.

> root@...:/var/log/tomcat7/.../RebootDevice# ls -lisa
> [...]
> 1089049 0 -rw-r--r-- 1 tomcat7 tomcat7 0 Mai 29 09:09 2017-05.log
> 1089047 4 -rw-r--r-- 1 tomcat7 adm 402 Mai 26 10:22 2017-05.log.gz
> root@...:/var/log/tomcat7/.../RebootDevice# find . -name \*.log -daystart -mtime +0
> ./2017-05.log

So what is the intended behaviuor of the log rotating script? Should it find all modified files AT LEAST changed 24 hours ago, but arbitrary old? If so, shouldn't that script have an upper limit to make it more compatible with names like mine?

How about something like the following:

> find . -name \*.log -daystart -mtime +0 -a ! -mtime +1

Using +2 and +3 seems to properly find my file changed some days ago, while +3 and +4 or +1 and +2 don't.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Hi Thorsten,
while I'm not the logrotate expert I tried to read into your case trying to understand it.
I see your issue being many files (since they change names often) being found and tried to be compressed.
For you question in the last paragraph:
"So what is the intended behavior of the log rotating script? Should it find all modified files AT LEAST changed 24 hours ago, but arbitrary old? If so, shouldn't that script have an upper limit to make it more compatible with names like mine?"

My unimportant opinion is - yes - it should find and try to compress all old files.
Because there is no guarantee the job ran on the former days. Things could have been broken/disabled/... for a random amount of days.
Therefore finding and trying to compress ALL old files is the right approach.

Now OTOH I understand your issue with the warning mail.
Also thinking about your case it will zip 2017-05.log on the second day of may, and then refuse to overwrite the zipped file right?
So you end up with a small log from day 1 zipped and a huge unzipped log of days 2-days-of-month. Plus day-of-month-1 warnings that there was a file in the way right?

I think since you customized from the default which is logs per day to become logs per month.
The right solution IMHO would then be to map (on just your system) this customization to the rest, which would mean also logrotate monthly - now since that rounds up how about:
  find . -name \*.log -daystart -mtime +31
That would work for all months (+1 day on short months, 3 days later in February - but not too critical I think).

The other way would be to overwrite. So since you log into the same file for a month after the first .gz is created the logfile actually on the next day is a superset right?
If so you could try to call logrotate in a way to overwrite the gz and not complain (or remove target before rotating the file).

Please take no offense in anything I wrote - all this is up for discussion - I was just trying to think through your case.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

On the very interesting +0 vs -0 discussion I read the manpage that due to rounding +0 actually means yesterday. So while +/-0*24 is surely 0 we know that in the special case +0*24 is actually a day.
So -0 might just be a day in the other direction?

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Setting incomplete since I'll wait on your feedback to my suggestions for now.
That should not stop others to chime in in case there are other ideas.

Changed in tomcat7 (Ubuntu):
status: New → Incomplete
Revision history for this message
Thorsten Schöning (tschoening) wrote :

> My unimportant opinion is - yes - it should find and try to compress all old files.
> Because there is no guarantee the job ran on the former days.

I get your point and therefore simply disabled compression for now, which was responsible the error mails from cron.

> Also thinking about your case it will zip 2017-05.log on the second day of may,
> and then refuse to overwrite the zipped file right?

Yes.

> So you end up with a small log from day 1 zipped and a huge unzipped log of days 2-days-of-month.

Partly correct, because it's about my own web apps, not Tomcat itself, and those log errors only. As errors don't occur very often, the file might be pretty small for a whole month, even of size 0. So the problem is not file size, but the approach trying to compress it each and every day even if it's size 0, just because all "old" files should be compressed. And because those files are of size 0 most of the time, it doesn't make sense to name them by day in opinion.

> Plus day-of-month-1 warnings that there was a file in the way right?

Correct and that's a bit annoying.

> I think since you customized from the default which is logs per day to become logs per month.

I didn't change Tomcat itself, only my own web apps are logging per month by default into subdirs of /var/log/tomcat7. So in fact I have both, Tomcat still logging per day, me logging per month. Simply because I prefer per month, but don't care enough for Tomcat itself to change it and customize working default configs.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

I'll set it to confirmed, although I'm not sure what to do in general to cover your case and the potential others as well. Because if we consider this a default case that the default config should handle well, there could be way more.

Changed in tomcat7 (Ubuntu):
status: Incomplete → Confirmed
Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

I found another report about the same - which increases the severity in a sense of being an issue for more people.

There as well no zipping seemed to be the solution.
"To silence the cron messages, an easy workaround is to disable log compression in /etc/default/tomcat7 by setting "LOGFILE_COMPRESS=0". This will bypass the problematic section of /etc/cron.daily/tomcat7."

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.