Richard Jones' Log: Debug logging only when it's needed

This is an idea mentioned in passing at the MXUG last night. It seemed neat to me.

This is a little snippet that'll let you sprinkle DEBUG level logging throughout your code and only have it appear in your log file when it's needed (for example when there's an exception.)

'''Capture a logger's DEBUG output for potential later dumping.

To use:
    handler = DebugCapture(log)

And at the end of a transaction:
    handler.clear()

If an error occurs:
    handler.emit_debug()
'''

import logging

class DebugCapture(logging.Handler):
    def __init__(self, logger):
        logging.Handler.__init__(self, logging.DEBUG)
        self.records = []
        # insert myself as the handler for the logger
        self.slaves = logger.handlers
        logger.handlers = [self]
    def emit_debug(self):
        # emit stored records to the original logger handler(s)
        for record in self.records:
            for slave in self.slaves:
                slave.handle(record)
    def clear(self):
        self.records = []
    def emit(self, record):
        self.records.append(record)
    def handle(self, record):
        # if its a DEBUG level record then intercept otherwise
        # pass through to the original logger handler(s)
        if record.levelno == logging.DEBUG:
            return logging.Handler.handle(self, record)
        return sum(slave.handle(record) for slave in self.slaves)


#
# SAMPLE PROGRAM
#
logging.basicConfig()
log = logging.getLogger()
log.setLevel(logging.DEBUG)
handler = DebugCapture(log)

def task(argument):
    log.info('run task (argument=%s)'%argument)
    log.debug('debug info should only appear next to error')
    if argument%2: BROKEN
    log.debug('all done!')

if __name__ == '__main__':
    for i in range(5):
        try:
            task(i)
        except:
            handler.emit_debug()
            log.exception('task is broken')
        handler.clear()

When run, this will generate the following console output:

$ python sample_program.py 
INFO:root:run task (argument=0)
INFO:root:run task (argument=1)
DEBUG:root:debug info should only appear next to error
ERROR:root:task is broken
Traceback (most recent call last):
  File "sample_program.py", line 59, in 
    task(i)
  File "sample_program.py", line 53, in task
    if argument%2: BROKEN
NameError: global name 'BROKEN' is not defined
INFO:root:run task (argument=2)
INFO:root:run task (argument=3)
DEBUG:root:debug info should only appear next to error
ERROR:root:task is broken
Traceback (most recent call last):
  File "sample_program.py", line 59, in 
    task(i)
  File "sample_program.py", line 53, in task
    if argument%2: BROKEN
NameError: global name 'BROKEN' is not defined
INFO:root:run task (argument=4)