Logging is an often over-looked necessity when developing your hot new web site or application. Fortunately, Python provides us with the logging module. This powerful and easy-to-use module makes logging a trivial process that would be far more beneficial to your development process than scattered print statements throughout your source.
This isn’t just a basic introduction — the Python documentation of the logging module already provide us with that. Instead we’re going to go straight into a fairly flexible and scalable logging solution. One that is simple enough to start using right away and robust enough to carry with you as your application grows.
Getting Started
First, we’ll use the ConfigParser functionality present in the logging module. This functionality is unfortunately not very well documented. However, as we’ll see — it’s very useful.
First we’ll need to create a configuration file to get things set up in a central location. Read the documentation to get a feel for the power and flexibility available. Here’s a simple example configuration file:
[loggers]
keys=model,root
[formatters]
keys=simple,complex
[handlers]
keys=syslog,default
[formatter_simple]
class=logging.Formatter
format=%(name)s:%(levelname)s= %(message)s
[formatter_complex]
class=logging.Formatter
format=%(name)s:%(levelname)s[%(module)s]:%(lineno)s -- %(message)s
[handler_syslog]
class=handlers.SysLogHandler
args=[('localhost', 514), handlers.SysLogHandler.LOG_DAEMON]
level=DEBUG
formatter=simple
[handler_default]
class=FileHandler
level=DEBUG
formatter=complex
args=('debug.log', 'w')
[logger_model]
level=INFO
handlers=syslog
qualname=model
[logger_root]
level=DEBUG
handlers=defaultCreate that file and save it somewhere in your project directory. Then in your settings file, create a new global variable to refer to that file.
LOGGING_CONFIG = '/path/to/my/project/logging.config'This is a good time to note that logging should be very granular. You can create loggers for each model, for views, exceptions, and so forth. Logging doesn’t cost much in terms of server resources and will save you so many headaches both in development and in production. Instead of managing print statements all over the place, you can leave your logging messages in, change the logging level in your configuration file when you go to production and not change any source.
So go nuts with those loggers. You’ll appreciate it later.
Next, you can start creating logger instances in your code with few lines of code.
import logging
from django.db import models
from myproject import settings
logging.config.fileConfig(settings.LOGGING_CONFIG)
log = logging.getLogger('model')
class MyModel(models.Model):
# ...The trick to note is that we can get any logger we define in our config file with the value we define by the ‘qualname’ property. The value of this property allows us to select our logger via the getLogger() method in our application code. Starting to make sense?
System Configuration
The astute observer will note that I used the SysLogHandler() logging handler provided in the logging.handlers module. This handler essentially passes on our logging messages to the syslogd daemon process that is common to GNU/Linux, Unix, and BSD systems. It’s configurable enough to allow the developer to use other syslog-like daemons. Check the documentation for more information (although sparse documentation may require you to delve into the source).
Syslogd does one really important thing for our application. It can receive log messages from a UDP socket. In terms of scaling, this allows us to create dedicated logging machines. At first you’ll probably use syslogd on a localhost. However, more complex setups may hide several logging machines behind a proxy load-balancer (recombining fragmented logs is a task left to the reader… ).
Little Tricks
So where should I put log messages, and how detailed should those messages be?
The answer is to slip them in everywhere it makes sense where you’d like to know what outcome was determined by your application. Be aware of message levels: use more detailed reports for debug messages where something went wrong in a critical method or low-level process. More precise messages should be used for more general messages.
Also make sure your messages are going to the right place. You can and should specify the proper context. LOG_DAEMON is not an appropriate file to log to when logging system messages. You would be better off using LOG_MESSAGE or LOG_DEBUG for debugging. Again, check out the documentation and source code for the logging module.
Hint:
Use signals to send log messages!
Want to keep a running log of new user registrations? Why not — by-pass running the query on your busy production database. Log the message from the pre- or post-save signals in your models.
Also, if you’re still in the dark about syslogd… check /var/log. It’s the most common place the syslogd is configured to maintain log files. If it’s not, check /etc/syslog.conf — it will tell you where to look. If you’re up to it, you can also configure your own custom syslogd and tweak to your heart’s content (I often copy emergency messages to a passive administrative console). Documentation is pretty hefty however, so it’s not for the feint of heart!
Wrapping Up
The Python logging module is a very powerful and useful tool. Syslogd is a very powerful tool. Combined, these tools will provide you with a logging solution that will scale with your application. The cost of adding abundant log messages is negligible. So log everything and log it often. The more granular, the better!