id	summary	reporter	owner	description	type	status	component	version	severity	resolution	keywords	cc	stage	has_patch	needs_docs	needs_tests	needs_better_patch	easy	ui_ux
25321	Make it clear that django.db.backends.schema messages (which can propogate to django.db.backends) don't include 'duration'	netpositive36	Markus Holtermann	"It fails on everything written in the logging message format (except asctime) so the extra parameters (duration, sql, etc.) mentioned in the documentation doesn't work. 

{{{
#!python

# LOGGING
LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'filters': {
         'require_debug_false': {
             '()': 'django.utils.log.RequireDebugFalse'
         },
         # Temporary SuspiciousOperation filter
         'skip_suspicious_operations': {
             '()': 'django.utils.log.CallbackFilter',
             'callback': skip_suspicious_operations,
         },
     },
    'formatters': {
        'standard': {
            'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s'
        },
        'simple': {
            'format': '> %(levelname)-8s %(message)s'
        },
        'verbose': {
            'format': '%(levelname)-8s %(message)s [%(asctime)s %(filename)s:%(funcName)s:%(lineno)d]'
        },
        'simple_sql': {
            'format': '%% %(asctime)s %(duration).3f %(sql)s' # 
        },
    },
    'handlers': {
        'null': {
            'level':'DEBUG',
            'class':'django.utils.log.NullHandler',
        },
        'console':{
            'level':'DEBUG',
            'class':'logging.StreamHandler',
            'formatter': 'simple'
        },
        'console_sql':{
            'level':'DEBUG',
            'class':'logging.StreamHandler',
            'formatter': 'simple_sql'
        },
        'sql_log_file': {
            'level':'DEBUG',
            'class':'logging.handlers.RotatingFileHandler',
            'filename': APP_LOG_HOME + 'django_sql_log.log',   
            'maxBytes': 1024*1024*10, # 10 MB
            'backupCount': 10,
            'formatter':'simple_sql',
        },
        'mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false', 'skip_suspicious_operations'],   # Temporary SuspiciousOperation filter
            'class': 'common.log.AdminMultilineEmailHandler'  #'django.utils.log.AdminEmailHandler',
        },
    },
    'loggers': {
        '': {
            'handlers': ['console', 'log_file'],
            'level': 'DEBUG',
            'propagate': False,
        },
        'z.caching': {
            'handlers': ['null'],
            'level': 'DEBUG',
            'propagate': False,
        },
        'django.db.backends': {
            'handlers': ['sql_log_file'],
            'level': 'DEBUG',
            'propagate': False,
        },
        'django': {
            'handlers': ['console'],
            'level': 'DEBUG',
            'propagate': True,
        },
        'django.request': { 
            'handlers': ['console', 'mail_admins'],
            'level': 'DEBUG',
            'propagate': False
        },
    }
}

}}}


{{{
#!python

Traceback (most recent call last):
  File ""/usr/local/Cellar/python/2.7.10_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/handlers.py"", line 76, in emit
    if self.shouldRollover(record):
  File ""/usr/local/Cellar/python/2.7.10_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/handlers.py"", line 156, in shouldRollover
    msg = ""%s\n"" % self.format(record)
  File ""/usr/local/Cellar/python/2.7.10_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/__init__.py"", line 732, in format
    return fmt.format(record)
  File ""/usr/local/Cellar/python/2.7.10_1/Frameworks/Python.framework/Versions/2.7/lib/python2.7/logging/__init__.py"", line 474, in format
    s = self._fmt % record.__dict__
KeyError: 'duration'
Logged from file schema.py, line 102

}}}"	Cleanup/optimization	closed	Documentation	1.8	Normal	fixed	logging, db		Ready for checkin	1	0	0	0	1	0