Integration with the Python standard library logging module

Comments on 12012-r11603.diff:

Re. the change in conf/__init__.py:

I know there's an open issue about where to place setup code in Django to run once only, so I assume this placement of the logging configuration code is just temporary because no better mechanism exists? As a user, I would prefer to control exactly when and how logging gets set up, and not to have it done automagically for me. If you feel that automagic configuration is wanted by the majority of users, you can still have an additional setting called e.g. AUTOLOG, set by default to True if you want, which does the logging setup automatically when true but can be overridden when more precise control is wanted. In fact if more granularity over logging settings is wanted, you could have a settings dict LOGGING_CONFIG { "enabled": True, "automatic": True } etc.

Re. the change in db/backends/__init__.py:

You might want to control via settings.py whether a CursorLoggingWrapper is returned rather than a plain cursor. There might be some petrol-heads for whom speed is paramount ;-)

Re. the change in "/dev/null", presumably this is your new django.utils.log:

I've proposed on python-dev a change to Python logging to add a dictConfig() function to the logging.config module. The start of the thread is here (though some of the posts don't appear in this thread because of broken email clients) and the draft of the schema I'm proposing is here. It would be good if we could align the schemata for the LOGGING dict.

I might be going about the initialisation the wrong way then. Here's what I want to achieve: without the user needing to do anything at all (including modifying a settings.py created before logging was added to Django) I want ALL messages to any logger beneath "django" to be silently swallowed, no matter what the severity. My understanding is that the correct way to do this is to hook up a NullHandler? and set "propogate = False" on the "django" logger as early as possible. Is there a better way of achieving that?

No, you're right about the best way to achieve what you want - i.e. by adding the NullHandler and setting propagate to False on the "django" logger, you will indeed ensure that any thing logged to "django.*" will disappear into the ether. That'll be fine from a backward compatibility point of view - users who have old settings files shouldn't see any unexpected logging messages.

The other question is what different modes of initialisation of logging might be wanted by different users. If a user wants Django to automatically configure logging for them, they can define a dict bound to LOGGING in settings.py. This covers the simplest use case - users don't need to do anything else. About the schema for the dict, it would be nice if we could align the schema with what I'm proposing on python-dev, linked-to above (the schema is different to what Ivan Sagalaev suggested on the django-developers thread, but then it has to cover functionality of the logging module such as shared handlers, filters, formatters etc. which wasn't covered by Ivan's overview, but will be needed in certain cases).

In a more complex use case, say the user wants to set up logging using their own code, but this needs to be done as early as possible and be called just once. For this, I suggested a callback mechanism here on your thread about "Best place for code that processes stuff from settings.py once". There, the user could define callbacks for logging or anything else which needs to be done just once. Their logging setup callback can use any mechanism to configure logging, e.g. programmatically using the logging getLogger/addHandler APIs or via loading a dict from YAML or JSON or just invoking the dict config mechanism using a dict obtained from some other source - including a literal dict in settings.py not called LOGGING ;-)

One more point about handlers. Because propagate is set to False for the "django" logger, in order for users to see django events, they will explicitly have to add appropriate handlers to the "django" logger. These can be the same handlers as they e.g. attach to the root logger, or completely different handlers.

A fairly common usage pattern is to attach console, file handlers to the root logger and nowhere else (but that wouldn't work for Django events, as I've explained above). Another common pattern is to attach console and file handlers to the root, and additional handlers (e.g. SMTP or file handlers pointing to files which just store errors) for particular severities (e.g. ERROR or CRITICAL) and/or particular areas of the application.

Of course, knowledgeable users can, if they wish, set the "django" logger's propagate flag to True in their logging setup code, which means that they then don't need to attach handlers specifically to the "django" logger, as events will propagate up to the root logger.

Patch to show how both logging and class_prepared listening can be done via setting.py

As per this thread on django-developers

Improved patch to show hooks at settings read, pre app/model load and post app/model load

Improved settings.py for use with patch in 12012-r11624.diff

Result of running ./manage.py validate with patch in 12012-r11624.diff and attached settings.py:

2009-10-15 14:58:31,772 INFO     logtest       Adding listener for class_prepared...
2009-10-15 14:58:31,803 INFO     logtest       class_prepared listener called: ContentType
2009-10-15 14:58:31,805 INFO     logtest       class_prepared listener called: Permission
2009-10-15 14:58:31,807 INFO     logtest       class_prepared listener called: Group
2009-10-15 14:58:31,810 INFO     logtest       class_prepared listener called: User
2009-10-15 14:58:31,813 INFO     logtest       class_prepared listener called: Message
2009-10-15 14:58:31,843 INFO     logtest       class_prepared listener called: Session
2009-10-15 14:58:31,864 INFO     logtest       class_prepared listener called: Site
2009-10-15 14:58:31,916 INFO     logtest       ORM works: all users: vinay (Vinay Sajip)

I've proposed the detail of a dictionary schema for Python logging configuration on python-dev in this post. An example configuration in YAML format would be:

formatters:
  brief:
	format: '%(levelname)-8s: %(name)-15s: %(message)s'
  precise:
	format: '%(asctime)s %(name)-15s %(levelname)-8s %(message)s'
        datefmt: '%Y-%m-%d %H:%M:%S'
filters:
  allow_foo:
	name: foo
handlers:
  console:
	class : logging.StreamHandler
	formatter: brief
	level   : INFO
	stream  : ext://sys.stdout
	filters: [allow_foo]
  file:
	class : logging.handlers.RotatingFileHandler
	formatter: precise
	filename: logconfig.log
	maxBytes: 1024
	backupCount: 3
  debugfile:
	class : logging.FileHandler
	formatter: precise
	filename: logconfig-detail.log
	mode: a
  email:
	class: logging.handlers.SMTPHandler
	mailhost: localhost
	fromaddr: my_app at domain.tld
	toaddrs:
	  - support_team at domain.tld
	  - dev_team at domain.tld
	subject: Houston, we have a problem.
loggers:
  foo:
	level : ERROR
	handlers: [debugfile]
  spam:
	level : CRITICAL
	handlers: [debugfile]
	propagate: no
  bar.baz:
	level: WARNING
root:
  level     : DEBUG
  handlers  : [console, file]

See Simon's experimental branch on this feature on github and this djd thread