DB-유

Log Rotation with logrotate

· linux, logrotate, logging

A full disk is the most boring outage there is, and a log file that nobody rotated is the usual cause. The distribution packages for nginx, MySQL and rsyslog all ship their own logrotate snippets, so the system logs mostly take care of themselves. The trouble starts with the things you add: an application writing to /var/log/myapp/app.log, a backup script appending to its own log, a MariaDB slow query log you turned on for a week and forgot about.

I've been paged for that one enough times that I now write the logrotate snippet the same day I deploy anything that logs. Here's how it's wired up on CentOS 7 and Ubuntu 16.04, and how to test a snippet without waiting for the 3 a.m. run.

How logrotate runs

logrotate is not a daemon. It is run once a day by cron from /etc/cron.daily/logrotate, which calls:

/usr/sbin/logrotate /etc/logrotate.conf

On CentOS 7 the daily cron jobs are triggered by anacron, so the exact time varies; on Ubuntu 16.04 it is whatever /etc/crontab says for cron.daily (06:25 by default). The main file /etc/logrotate.conf sets defaults and then does include /etc/logrotate.d, so each package drops a file there. State about when each file was last rotated is kept in /var/lib/logrotate/logrotate.status (CentOS) or /var/lib/logrotate/status (Ubuntu).

Look at an existing snippet to see the shape:

cat /etc/logrotate.d/nginx

A snippet for an application log

Create /etc/logrotate.d/myapp:

sudo vi /etc/logrotate.d/myapp
/var/log/myapp/*.log {
    daily
    rotate 14
    missingok
    notifempty
    compress
    delaycompress
    dateext
    create 0640 myapp adm
    sharedscripts
    postrotate
        systemctl kill -s HUP myapp.service > /dev/null 2>&1 || true
    endscript
}

What each line does:

  • daily / rotate 14: keep two weeks of daily files. weekly and size 100M are the other common choices; size rotates whenever the file exceeds the threshold regardless of time.
  • missingok / notifempty: do not complain if the file is absent, and skip rotation when it is empty.
  • compress with delaycompress: gzip old files, but leave the most recent rotated one uncompressed for a cycle so a process still holding it open can finish writing.
  • dateext: name files app.log-20180208 instead of app.log.1, which is far easier to work with.
  • create 0640 myapp adm: after moving the old file aside, create a new empty one with these permissions so the application can keep writing.
  • postrotate: tell the application to reopen its log. Most daemons reopen on SIGHUP. sharedscripts runs it once for all matched files rather than once per file.

copytruncate, for programs that can't reopen

I avoid copytruncate when I can, but some applications hold a file descriptor open and have no signal to reopen it. After a normal rotation they keep writing into the renamed file and the new one stays empty. For these, use copytruncate instead of create:

/var/log/backup/backup.log {
    weekly
    rotate 8
    compress
    missingok
    copytruncate
}

logrotate copies the file and then truncates the original in place. There is a tiny window where lines written between the copy and the truncate are lost, which is acceptable for a backup log and not acceptable for an audit log.

The MySQL slow query log

The mysql-server package's snippet only covers the error log in some versions. If you enabled slow_query_log in my.cnf, add its own snippet using mysqladmin flush-logs so the server closes and reopens the file cleanly:

/var/lib/mysql/slow.log {
    daily
    rotate 7
    missingok
    compress
    delaycompress
    notifempty
    create 640 mysql mysql
    postrotate
        /usr/bin/mysqladmin --defaults-file=/root/.my.cnf flush-logs
    endscript
}

Put the credentials in /root/.my.cnf with mode 600 rather than on the command line.

Test it now, not next month

Run logrotate in debug mode against just your snippet. It prints what it would do without touching anything:

sudo logrotate -d /etc/logrotate.d/myapp

Then force a real rotation to confirm permissions and the postrotate script work:

sudo logrotate -f /etc/logrotate.d/myapp
ls -la /var/log/myapp/

You should see app.log (new, empty or nearly so, owned by myapp:adm) next to app.log-20180208. Write something through the application and confirm it lands in the new file, not the old one. Finally, check the state file to make sure logrotate recorded the rotation:

grep myapp /var/lib/logrotate/logrotate.status

Errors you'll probably see

  • error: skipping "/var/log/myapp/app.log" because parent directory has insecure permissions (It's world writable or writable by group which is not "root"): logrotate refuses to work in a directory it considers unsafe. Either fix the permissions (chmod 755) or add su myapp myapp to the snippet so it rotates as that user.
  • error: myapp:3 duplicate log entry for /var/log/myapp/app.log: the same file is matched by two snippets, often a wildcard in one and an explicit path in another. Remove one.
  • Rotated but the application keeps writing to the old file: missing or wrong postrotate, or the daemon does not respond to HUP. Check ls -l /proc/$(pidof myapp)/fd to see which file it has open; switch to copytruncate if there is no reopen mechanism.
  • Nothing rotates at all and the debug output says log does not need rotating: the state file says it was rotated today. Use -f to force, or check that the cron.daily job actually runs (grep logrotate /var/log/cron on CentOS).

Always run logrotate -d and then logrotate -f on a new snippet the day you write it. Trusting the syntax is how you find out a month later that the file grew to 40 GB.