Richard Jones' Log

The next meeting of the Melbourne Python Users Group will be on Tuesday the 11th of August starting at 6:30pm. We'll be meeting at Horse Bazaar again but this time we'll have use of their projector. We'll have time for several short presentations and lightning talks.

Meeting details, location and talks list are at the MelbournePUG wiki page.

If you've seen something cool or are doing something cool then we'd like you to tell everyone about it! Presentations could be 5 minutes or up to 15 minutes if you'd like to ramble for a bit longer. I'll be getting up to talk a bit about my experiences playing with IronPython - what's cool and what's downright odd :)

If you've got an idea for a talk just add it to the wiki page.

Thanks to Kent Johnson for reminding me about contexts (I don't get to play with them much so I sometimes forget :) usage is a lot simpler:

    for i in range(5):
        with DebugCapture(log):
            task(i) 

This is produced by modifying the code from yesterday a little:

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

Simple use (requires "with" statement in Python 2.5 or later):

    with DebugCapture(logger):
        do_stuff()

If an exception occurs the DEBUG output will be emitted to the log followed
by an exception ERROR message.

Alternatively for Python < 2.5 you may use it more manually:

    handler = DebugCapture(logger)

And at the end of a transaction:

    handler.clear()

If an error occurs:

    handler.emit_debug()

And to uninstall (stop trapping DEBUG messages):

    handler.uninstall()

Copyright 2009 Richard Jones (richard@mechanicalcat.net) and you're free
to use / modify / ignore it as you like.
'''

import logging
import weakref

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.logger = weakref.proxy(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 uninstall(self):
        self.logger.handlers = self.slaves
        self.slaves = self.logger = None
    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)
    def __enter__(self):
        pass
    def __exit__(self, exc_type, exc_value, traceback):
        if exc_type is not None:
            self.emit_debug()
            self.logger.error('unhandled exception', exc_info=(exc_type,
                exc_value, traceback))
        self.uninstall()
        return True

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

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):
        with DebugCapture(log):
            task(i)

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)