Tag: logging

Rotating logs with multiple workers in Django

The default Django logging settings make use of FileHandler which writes to a single file that grows indefinitely, or at least until your server vomits. You'll probably first reach for RotatingFileHandler or even better TimedRotatingFileHandler to solve your problem, but alas you're heading down a blind alley.

The problem, as myriad Stack Overflow questions will tell you, is if you are serving your app with something like gunicorn or uwsgi you're probably using multiple workers, which means multiple processes simultaneously trying to write and rotate logs. This leads to unexpected results such as; multiple log files changing at once, log files containing the wrong timestamped data, truncated logs and missing data. Ouch.

Since Django/Python can't be relied on to rotate logs in this scenario we turn to the trusty sysadmin's tonic: logrotate. However logrotate has a couple pitfalls of its own, such as using the copytruncate directive which can also lead to data loss! So to avoid using that directive we'll settle on Python's WatchedFileHandler, which detects file changes on disk and can continue logging appropriately, whereas FileHandler would either continue writing to the old log file or just stop writing logs entirely.

In the end your settings/base.py logging setup should look something like this:

LOGGING = {
  'version': 1,
  'disable_existing_loggers': False,
  'formatters': {
      'verbose': {
          'format': "[%(asctime)s] %(levelname)s [line:%(lineno)s] %(message)s",
          'datefmt': "%d/%b/%Y %H:%M:%S"
      },
      'simple': {
          'format': '%(levelname)s %(message)s'
      },
  },
  'handlers': {
      'file': {
          'level': 'DEBUG',
          'class': 'logging.handlers.WatchedFileHandler',
          'filename': '/var/log/myapp/myapp.log',
          'formatter': 'verbose'
      },
  },
  'loggers': {
      'django': {
          'handlers': ['file'],
          'propagate': True,
          'level': 'DEBUG',
      },
  }
}

Then I created a basic logrotate config but doing a dry-run test reported this error:

$ logrotate -d /etc/logrotate.d/myapp

error: skipping "/var/log/myapp/myapp.log" because parent directory has insecure permissions (It's world writable or writable by group which is not "root") Set "su" directive in config file to tell logrotate which user/group should be used for rotation.

Turns out that error is because /var/log/myapp is owned by the gunicorn user (which serves the django app, and thus writes the logs, and thus owns the directory). The su directive lets you set the owner and group logrotate should run as to solve that problem.

I also used the dateyesterday directive to backdate the rotated log files. Otherwise since anacron runs at 3am (the default on RHEL/CentOS) the filename wouldn't match the timestamps inside.

My final logrotate config looks like:

/var/log/myapp/myapp.log {
  daily
  rotate 30
  create
  dateext
  dateyesterday
  compress
  delaycompress
  notifempty
  missingok
  su gunicorn web
}

If you're really set on letting Python handle log rotation you can look into the ConcurrentLogHandler package; however it only rotates based on size, not date.

© Justin Montgomery. Built using Pelican. Theme is subtle by Carey Metcalfe. Based on svbhack by Giulio Fidente.