Django Logging Rotating files not working

Question

So i am having some issues with Django logging when it gets to the maxBytes size. Basically when that happens the file does not seem to rotate and create a new file.

Someone told me this could have something to do with the writing permissions of the server but i am not sure how to set that properly so that django is able to create a new log file when the old one is full.

my settings:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'filters': {
        'require_debug_false': {
            '()': 'django.utils.log.RequireDebugFalse'
        }
    },
    'formatters': {
        'verbose': {
            'format': "[%(asctime)s] %(levelname)s [%(name)s:%(lineno)s] %(message)s",
            'datefmt': "%d/%b/%Y %H:%M:%S"
        },
        'simple': {
            'format': '[%(levelname)-7s] %(asctime)s - %(message)s'
        },
    },
    'handlers': {
        'mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false'],
            'class': 'django.utils.log.AdminEmailHandler'
        },
        'console': {
            'level': 'INFO',
            'class': 'logging.StreamHandler'
        },
        'boom_file': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'maxBytes': 1024*1024*10,  # 10 MB
            'backupCount': 10,
            'filename': '/var/log/boom.log',
            'formatter': 'simple'
        },
        'binglaw_crawler_file': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'maxBytes': 1024*1024*10,  # 10 MB
            'backupCount': 10,
            'filename': '/var/log/boom-binglaw-crawler.log',
            'formatter': 'simple'
        },
    },
    'loggers': {
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': True,
        },
        'boom': {
            'handlers': ['console', 'boom_file'],
            'propagate': True,
            'level': 'DEBUG',
        },
        'boom.binglaw_crawler': {
            'handlers': ['binglaw_crawler_file', ],
            'propagate': False,
            'level': 'DEBUG',
        },
    }
}

i noticed my other log celeryd seems o be rotaing just fine.. isnt that strange?

-rw-r--rw- 1 root          root          10485721 Aug 18 12:12 boom-binglaw-crawler.log
-rw-r--r-- 1 root          root            403506 Nov  8 23:42 boom-celeryd.log
-rw-r--r-- 1 root          root             20201 Oct  2 12:47 boom-celeryd.log.1
-rw-r--rw- 1 root          root           1049478 Oct  1 18:49 boom-celeryd.log.2

UPDATE:

i am getting this error when i try to run the manage command that creates the log file

Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/handlers.py", line 77, in emit
    self.doRollover()
  File "/usr/lib/python2.7/logging/handlers.py", line 142, in doRollover
    os.rename(self.baseFilename, dfn)
OSError: [Errno 13] Permission denied

Answer 1

When using the 'logging.handlers.RotatingFileHandler' in Django logging, I had this error:

Traceback (most recent call last):
  File "C:\Python33\lib\logging\handlers.py", line 73, in emit
    self.doRollover()
  File "C:\Python33\lib\logging\handlers.py", line 176, in doRollover
    self.rotate(self.baseFilename, dfn)
  File "C:\Python33\lib\logging\handlers.py", line 116, in rotate
    os.rename(source, dest)
PermissionError: [WinError 32] The process cannot access the file because it is being used by another process: 'log.txt.1'

This error was happening to me because when I start Django, it seems to start 2 different processes. Both processes setup logging, which means both get a handle to the same LOGGING files defined in 'settings.py' config file.

I added this line to my settings.py file, right before I set my LOGGING variable.

print("Initializing LOGGING in settings.py - if you see this more than once use 'runserver --noreload'")

If you start the app with 'manage.py runserver --noreload' parameter, it may cure your file contention issue.

Answer 2

One solution, which currently works for for me, was to use 'delay': True for the handler ids that write to files (the RotatingFileHandler in my case). This creates the files only when the first emit() is called from the loggers, and my understanding is that the thread contention between the main thread and the autoreload thread (which is the cause of the error) seems not to exist at that point.