by Tykling
27. apr 2020 19:49 UTC
This post is about the way newsyslog(8) names rotated logfiles on FreeBSD. It explains how to reconfigure newsyslog(8) to timestamp rotated logs rather than numbering them sequentially. It also explains how I renamed the existing logfiles.
newsyslog(8) takes care of rotating logs based on time or size restrictions defined in /etc/newsyslog.conf or its included files. The default /etc/newsyslog.conf looks like this:
# logfilename [owner:group] mode count size when flags [/pid_file] [sig_num] /var/log/all.log 600 7 * @T00 J /var/log/auth.log 600 7 1000 @0101T JC /var/log/console.log 600 5 1000 * J /var/log/cron 600 3 1000 * JC /var/log/daily.log 640 7 * @T00 JN /var/log/debug.log 600 7 1000 * JC /var/log/init.log 644 3 1000 * J /var/log/kerberos.log 600 7 1000 * J /var/log/maillog 640 7 * @T00 JC /var/log/messages 644 5 1000 @0101T JC /var/log/monthly.log 640 12 * $M1D0 JN /var/log/devd.log 644 3 1000 * JC /var/log/security 600 10 1000 * JC /var/log/utx.log 644 3 * @01T05 B /var/log/weekly.log 640 5 * $W6D0 JN <include> /etc/newsyslog.conf.d/* <include> /usr/local/etc/newsyslog.conf.d/*
Most of these are set to be rotated at 1000 kilobytes of size, the rest @ a certain time, and a few has both. Most of these have the J flag which means newsyslog(8) will compress the file with bzip2. A similar flag X is used for xz compression in newer installs, but the principle is the same. In modern times the compression is a bit pointless because the ZFS filesystem they live in is compressed anyway, so I should just have Ansible remove the compression flags. But that is an exercise for another day.
newsyslog(8) does a good job, and mostly keeps to itself. But I've never really understood why the default for newsyslog(8) is to name rotated logs sequentially. This is an example from my IRC shell, which doesn't have a lot of stuff happening in the logs since it runs no services
[tykling@irc ~]$ ls -l /var/log/messages* -rw-r--r-- 1 root wheel 8668 3 apr. 09:26 /var/log/messages -rw-r--r-- 1 root wheel 1404 1 jan. 00:00 /var/log/messages.0.bz2 -rw-r--r-- 1 root wheel 2566 1 jan. 2019 /var/log/messages.1.bz2 -rw-r--r-- 1 root wheel 9384 1 jan. 2018 /var/log/messages.2.bz2 -rw-r--r-- 1 root wheel 10552 13 apr. 2017 /var/log/messages.3.bz2 -rw-r--r-- 1 root wheel 1871 1 jan. 2017 /var/log/messages.4.bz2 [tykling@irc ~]$
A better example might be from my mailserver which runs Postfix which logs to syslog facility mail meaning the logs go to /var/log/maillog and gets rotated daily with the default syslogd and newsyslog configuration:
[tykling@smtp2 ~]$ ls -tl /var/log/maillog* -rw-r----- 1 root wheel 9280943 Apr 27 19:09 /var/log/maillog -rw-r----- 1 root wheel 161802 Apr 27 00:00 /var/log/maillog.0.bz2 -rw-r----- 1 root wheel 208722 Apr 26 00:00 /var/log/maillog.1.bz2 -rw-r----- 1 root wheel 182361 Apr 25 00:00 /var/log/maillog.2.bz2 -rw-r----- 1 root wheel 201262 Apr 24 00:00 /var/log/maillog.3.bz2 -rw-r----- 1 root wheel 152031 Apr 23 00:00 /var/log/maillog.4.bz2 -rw-r----- 1 root wheel 155537 Apr 22 00:00 /var/log/maillog.5.bz2 -rw-r----- 1 root wheel 173292 Apr 21 00:00 /var/log/maillog.6.bz2 -rw-r----- 1 root wheel 163493 Apr 20 00:00 /var/log/maillog.7.bz2 -rw-r----- 1 root wheel 188224 Apr 19 00:00 /var/log/maillog.8.bz2 -rw-r----- 1 root wheel 159963 Apr 18 00:00 /var/log/maillog.9.bz2 -rw-r----- 1 root wheel 149439 Apr 17 00:00 /var/log/maillog.10.bz2 -rw-r----- 1 root wheel 155947 Apr 16 00:00 /var/log/maillog.11.bz2 -rw-r----- 1 root wheel 158183 Apr 15 00:00 /var/log/maillog.12.bz2 ....snip....
The point is that when newsyslog rotates /var/log/maillog it first appends .0 to the logfile name and then compresses it, so the final name is /var/log/maillog.0.bz2. If this file already exists it is renamed to .1.bz2. If that file already exists it is renamed to .2.bz2, and so on, until the retention limit is reached, and the remaining files are deleted.
This means that if you keep, say, 100 days worth of maillog around, it means each logrotate operation performed by newsyslog starts with 100 seperate file renames. This is ridiculous in itself, but it gets worse:
Renaming files like this effectively means that the filesystem has completely different data for the same filename, for all logfiles, every single day. This means that differential backup systems need to backup every single byte of all 100 logfiles every day, because they all changed content. This is clearly not ideal - it makes zfs snapshots and backups take much more space than they need to, because you end up with many copies of the same logfiles.
Finally it means that if I have to go back to a certain date to see the logs for that day my best option is to either check the timestamp of the file, or count the number of days and calculate whether I want maillog.62.bz2 or maillog.63.bz2.
A more sane default would be to name the file after when it was rotated. For daily rotated files it would mean that the file would always be named for the day after the logs it contains, nice and predictable. It would also mean that newsyslog would never need to rename old logfiles when rotating, solving the incremental backup issue. Fortunately newsyslog has just such an option waiting to be utilized:
-t timefmt
If specified newsyslog will create the “rotated” logfiles using
the specified time format instead of the default sequential
filenames. The filename used will be kept until it is deleted.
The time format is described in the strftime(3) manual page. If
the timefmt argument is set to an empty string or the string
“DEFAULT”, the default built in time format is used. If the
timefmt string is changed the old files created using the
previous time format will not be automatically removed (unless
the new format is very similar to the old format). This is also
the case when changing from sequential filenames to time based
file names, and the other way around. The time format should
contain at least year, month, day, and hour to make sure rotating
of old logfiles can select the correct logfiles.
They don't mention what the default built in time format is, but I can reveal that it looks like this:
-rw-r----- 1 root wheel 1178944 Apr 27 17:12 maillog -rw-r----- 1 root wheel 6746 Apr 21 00:00 maillog.20200421T000013.bz2 -rw-r----- 1 root wheel 6708 Apr 22 00:00 maillog.20200422T000012.bz2 -rw-r----- 1 root wheel 6738 Apr 23 00:00 maillog.20200423T000011.bz2 -rw-r----- 1 root wheel 9951 Apr 24 00:00 maillog.20200424T000004.bz2 -rw-r----- 1 root wheel 10772 Apr 25 00:00 maillog.20200425T000008.bz2 -rw-r----- 1 root wheel 12599 Apr 26 00:00 maillog.20200426T000013.bz2 -rw-r----- 1 root wheel 25340 Apr 27 00:00 maillog.20200427T000010.bz2
So YYYYMMDDTHHMMSS or if you prefer strftime(3) the format it is %Y%m%dT%H%M%S:
$ date +"%Y%m%dT%H%M%S" 20200427T213224
OK so changing the newsyslog entry in /etc/crontab is easy enough, just add -t DEFAULT to the existing line like to:
[tykling@webproxy2 ~]$ grep newsyslog /etc/crontab 0 * * * * root newsyslog -t DEFAULT [tykling@webproxy2 ~]$
But what about all the existing logs that are named sequentially? For two very good reasons they need to be renamed to follow the new naming convention. First reason is simply to have a consistent naming of old logfiles. Log analysis tools and such will be easier to implement, stuff will be easier to find and so on. Second reason is a bit more concrete: If newsyslog is to have any chance of finding the old logfiles so it can delete them when the retention limit has been reached they need to be named like newsyslog would have named them. This means I need a script to rename old logfiles.
I do all my system administration in Ansible, so I added a task to change the crontab line, with a notify: to call a handler which runs a shell: task which looks like this:
INCLUDEPATHS=$(cat /etc/newsyslog.conf | grep "^<include>" | cut -d " " -f 2)
for LOGPATH in $(cat /etc/newsyslog.conf $INCLUDEPATHS | grep -Ev "^(#|$|)" | awk "{print \$1}" | sed -e 's,/[^/]*$,,' | sort -u); do
for EXT in bz2 xz; do
for FILE in $(ls -1 ${LOGPATH}/*.${EXT}); do
MTIME=$(stat -f %Sm -t "%Y%m%dT%H%M%S" ${FILE})
NEWNAME=$(echo $(basename ${FILE}) | sed -E "s/(.+)\.[0-9]+\.${EXT}/\1.${MTIME}.${EXT}/")
mv ${FILE} $(dirname ${FILE})/${NEWNAME}
done
done
done
It could just as well be a Bourne Posix .sh file with a #!/bin/sh shebang line to be run by hand. The way I've configured it in Ansible means the change will happen automatically and gradually the next time I run Ansible on my servers and jails.
The script understands the newsyslog.conf <include> syntax and looks for paths with files that need renaming in included files too. It simply looks for compressed files in /var/log and other places as configured in /etc/newsyslog.conf and renames each with the files modification time in the filename. Unless the compressed logfile for some reason has been changed since it was rotated this will give the same result as if newsyslog had been configured this way from the beginning.
I should have done this years ago. The advantages easily outweigh the time I've spent on it, and I will be enjoying sensibly named logfiles for years to come. Next time I write about newsyslog will probably be about removing the compression and letting ZFS handle it.