Elegant setup of Python logging in Django

I know this is a solved answer already, but as per django >= 1.3 there's a new logging setting.

Moving from old to new is not automatic, so I thought i'll write it down here.

And of course checkout the django doc for some more.

This is the basic conf, created by default with django-admin createproject v1.3 - mileage might change with latest django versions:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'mail_admins': {
            'level': 'ERROR',
            'class': 'django.utils.log.AdminEmailHandler',
        }
    },
    'loggers': {
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': True,
        }
    }
}

This structure is based upon the standard Python logging dictConfig, that dictates the following blocks:

formatters - the corresponding value will be a dict in which each key is a formatter id and each value is a dict describing how to configure the corresponding Formatter instance.
filters - the corresponding value will be a dict in which each key is a filter id and each value is a dict describing how to configure the corresponding Filter instance.
handlers - the corresponding value will be a dict in which each key is a handler id and each value is a dict describing how to configure the corresponding Handler instance. Each handler has the following keys:
- class (mandatory). This is the fully qualified name of the handler class.
- level (optional). The level of the handler.
- formatter (optional). The id of the formatter for this handler.
- filters (optional). A list of ids of the filters for this handler.

I usually do at least this:

add a .log file
configure my apps to write to this log

Which translates into:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'verbose': {
            'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'
        },
        'simple': {
            'format': '%(levelname)s %(message)s'
        },
    },
    'filters': {
        'require_debug_false': {
            '()': 'django.utils.log.RequireDebugFalse'
        }
    },
    'handlers': {
        'null': {
            'level':'DEBUG',
            'class':'django.utils.log.NullHandler',
        },
        'console':{
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        # I always add this handler to facilitate separating loggings
        'log_file':{
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': os.path.join(VAR_ROOT, 'logs/django.log'),
            'maxBytes': '16777216', # 16megabytes
            'formatter': 'verbose'
        },
        'mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false'],
            'class': 'django.utils.log.AdminEmailHandler',
            'include_html': True,
        }
    },
    'loggers': {
        'django.request': {
            'handlers': ['mail_admins'],
            'level': 'ERROR',
            'propagate': True,
        },
        'apps': { # I keep all my of apps under 'apps' folder, but you can also add them one by one, and this depends on how your virtualenv/paths are set
            'handlers': ['log_file'],
            'level': 'INFO',
            'propagate': True,
        },
    },
    # you can also shortcut 'loggers' and just configure logging for EVERYTHING at once
    'root': {
        'handlers': ['console', 'mail_admins'],
        'level': 'INFO'
    },
}

edit

See request exceptions are now always logged and Ticket #16288:

I updated the above sample conf to explicitly include the correct filter for mail_admins so that, by default, emails are not sent when debug is True.

You should add a filter:

'filters': {
    'require_debug_false': {
        '()': 'django.utils.log.RequireDebugFalse'
    }
},

and apply it to the mail_admins handler:

    'mail_admins': {
        'level': 'ERROR',
        'filters': ['require_debug_false'],
        'class': 'django.utils.log.AdminEmailHandler',
        'include_html': True,
    }

Otherwise the django.core.handers.base.handle_uncaught_exception doesn't pass errors to the 'django.request' logger if settings.DEBUG is True.

If you don't do this in Django 1.5 you'll get a

DeprecationWarning: You have no filters defined on the 'mail_admins' logging handler: adding implicit debug-false-only filter

but things will still work correctly BOTH in django 1.4 and django 1.5.

** end edit **

That conf is strongly inspired by the sample conf in the django doc, but adding the log file part.

I often also do the following:

LOG_LEVEL = 'DEBUG' if DEBUG else 'INFO'

...
    'level': LOG_LEVEL
...

Then in my python code I always add a NullHandler in case no logging conf is defined whatsoever. This avoid warnings for no Handler specified. Especially useful for libs that are not necessarily called only in Django (ref)

import logging
# Get an instance of a logger
logger = logging.getLogger(__name__)
class NullHandler(logging.Handler): #exists in python 3.1
    def emit(self, record):
        pass
nullhandler = logger.addHandler(NullHandler())

# here you can also add some local logger should you want: to stdout with streamhandler, or to a local file...

[...]

logger.warning('etc.etc.')

Hope this helps!

The best way I've found so far is to initialize logging setup in settings.py - nowhere else. You can either use a configuration file or do it programmatically step-by-step - it just depends on your requirements. The key thing is that I usually add the handlers I want to the root logger, using levels and sometimes logging.Filters to get the events I want to the appropriate files, console, syslogs etc. You can of course add handlers to any other loggers too, but there isn't commonly a need for this in my experience.

In each module, I define a logger using

logger = logging.getLogger(__name__)

and use that for logging events in the module (and, if I want to differentiate further) use a logger which is a child of the logger created above.

If my app is going to be potentially used in a site which doesn't configure logging in settings.py, I define a NullHandler somewhere as follows:

#someutils.py

class NullHandler(logging.Handler):
    def emit(self, record):
        pass

null_handler = NullHandler()

and ensure that an instance of it is added to all loggers created in the modules in my apps which use logging. (Note: NullHandler is already in the logging package for Python 3.1, and will be in Python 2.7.) So:

logger = logging.getLogger(__name__)
logger.addHandler(someutils.null_handler)

This is done to ensure that your modules play nicely in a site which doesn't configure logging in settings.py, and that you don't get any annoying "No handlers could be found for logger X.Y.Z" messages (which are warnings about potentially misconfigured logging).

Doing it this way meets your stated requirements:

You can set up different log handlers for different events, as you currently do.
Easy access to loggers in your modules - use getLogger(__name__).
Easily applicable to command-line modules - they also import settings.py.

Update: Note that as of version 1.3, Django now incorporates support for logging.

We initialize logging in the top-level urls.py by using a logging.ini file.

The location of the logging.ini is provided in settings.py, but that's all.

Each module then does

logger = logging.getLogger(__name__)

To distinguish testing, development and production instances, we have different logging.ini files. For the most part, we have a "console log" that goes to stderr with Errors only. We have an "application log" that uses a regular rolling log file that goes to a logs directory.

Elegant setup of Python logging in Django

Related

Recent Posts