Prints the current stack to a logger.

logging_helper.py

import inspect
import logging

HEADER_FMT = "Call stack at %s, line %d in function %s, frames %d to %d of %d:"
"""The log header message formatter."""

STACK_FMT = "%s, line %d in function %s."
"""The log stack message formatter."""

def log_stack(logger=None, limit=None, start=0):
    """
    Prints the call stack at the point of the caller to the given log.
    
    Example:
    
    >>> import logging
    >>> logger = logging.getLogger(__name__)
    >>> logger.setLevel(logging.DEBUG)
    >>> 
    >>> import logging_helper
    >>> 
    >>> def outer():
    ...     middle()
    >>> 
    >>> def middle():
    ...     inner()
    >>> 
    >>> def inner():
    ...     logging_helper.log_stack(logger, 2)
    >>> 
    >>> outer()
    130424-12:17:35,722 __main__ DEBUG:
         Call stack at /snippet/test_logging_helper.py, line 13 in function inner, frames 2 to 3 of 11:
    130424-12:17:35,722 __main__ DEBUG:
    	 /snippet/test_logging_helper.py, line 10 in function middle.
    130424-12:17:35,722 __main__ DEBUG:
    	 /snippet/test_logging_helper.py, line 7 in function outer.
    
    @param logger: the logger to use (default use the root logger)
    @param limit: the number of frames to print (default print all remaining frames)
    @param start: the offset of the first frame preceding the caller to print (default 0)
    """   
    
    # Use the default logger, if necessary.
    if not logger:
        logger = logging.getLogger()
    
    # The call stack.
    stack = inspect.stack()
    
    # The penultimate frame is the caller to this function.
    here = stack[1]
    
    # The index of the first frame to print.
    begin = start + 2
    
    # The index of the last frame to print.
    if limit:
        end = min(begin + limit, len(stack))
    else:
        end = len(stack)
    
    # Print the stack to the logger.
    file, line, func = here[1:4]
    logger.debug(HEADER_FMT % (file, line, func, start + 2, end - 1, len(stack) - 1))
    # Print the next frames up to the limit.
    for frame in stack[begin:end]:
        file, line, func = frame[1:4]
        logger.debug(STACK_FMT % (file, line, func))

test_logging_helper.py

from nose.tools import *
import os, sys
from StringIO import StringIO

import logging
logger = logging.getLogger(__name__)

import sys
sys.path.insert(0, os.path.dirname(__file__))
import logging_helper

HEADER_PAT = logging_helper.HEADER_FMT.replace('%d', '%s') % ('.+', '\d+', '.+', '\d+', '\d+', '\d+')
"""The header log message pattern."""

STACK_PAT = logging_helper.STACK_FMT.replace('%d', '%s') % ('.+', '\d+', '.+')
"""The stack content log message pattern."""

class TestLoggingHelper(object):
    """The logging helper unit tests."""
    
    def setUp(self):
        self.buffer = StringIO()
        log_handler = logging.StreamHandler(self.buffer)
        formatter = logging.Formatter("%(message)s")
        log_handler.setFormatter(formatter)
        logger.addHandler(log_handler)
    
    def test_full_stack(self):
        self.outer()
        log = self.buffer.getvalue().splitlines()
        hdr = log.pop(0)
        assert_regexp_matches(hdr, HEADER_PAT, "Log header message incorrect")
        for msg in log:
            assert_regexp_matches(msg, STACK_PAT, "Log stack message incorrect")
    
    def test_partial_stack(self):
        self.outer(2, 1)
        log = self.buffer.getvalue().splitlines()
        assert_equals(3, len(log), "Log size incorrect: %d" % len(log))
    
    def outer(self, limit=None, start=0):
        self.middle(limit, start)
    
    def middle(self, limit, start):
        self.inner(limit, start)
    
    def inner(self, limit, start):
        logging_helper.log_stack(logger, limit, start)


if __name__ == "__main__":
    import nose
    
    nose.main(defaultTest=__name__)