Logging Formatter record current function executing

Question

In my python logging I want to record the function currently executing/running. For example;

class Foo:
    def bar(self):
       logging.info("I'm alive") # Writes to log: '[INFO]: Foo::bar(), I'm alive'

Is it possible to configure my logger to do this? Ie, create a formatter to find this out?

logging.config.dictConfig({
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'standard': {
            'format': '[%(levelname)s] %(FUNCTION_NAME)s: %(message)s'
        },
    },
    ...
})

score 0 · Answer 1 · edited May 23 '17 at 12:06

You can do that by adding the information context to the record of the logger. To do this, you need to define your own ContextFilter class and add an instance of it to your logger. Notice that in order to get the class name, we depend on the convention of calling self the instance of a class, and not using it as arguments of other functions (It is based on this SO question how-to-retrieve-class-information-from-a-frame-object). Notice also that this work-around is not able to determine the class of internalFunc because it does not have the self argument. See the code below.

import inspect
import logging


def get_class_from_frame(fr):
    args, _, _, value_dict = inspect.getargvalues(fr)
    if len(args) and args[0] == 'self':
        instance = value_dict.get('self', None)
        if instance:
            return getattr(instance, '__class__', None)
    return 'NOCLASS'

class ContextFilter(logging.Filter):
    """
    This is a filter which injects contextual information into the log.
    """
    def filter(self, record):
        #we are adding the function field to the logger record     
        mystack = inspect.stack()[5]
        record.function = '%s::%s'%(get_class_from_frame(mystack[0]), mystack[3])
        return True

def buildLogger():
    logger = logging.getLogger("root")
    #now we use the function field in the format
    myFormat = '[%(levelname)s] %(function)s: "%(message)s"' 
    formatter = logging.Formatter(myFormat)
    # add an instance of ContextFilter to the logger    
    myFilter = ContextFilter()
    logger.addFilter(myFilter)
    ch = logging.StreamHandler()
    ch.setFormatter(formatter)
    logger.addHandler(ch)
    logger.propagate = False
    return logger

# Some testing

def myStandaloneFunction():
    logger.warning('this is logged from myStandaloneFunction')

class A():
    def afunc(self):
        def internalFunc():
            logger.warning('this is logged from inside internalFunc call')
        logger.warning('this is logged from inside a afunc call')
        internalFunc()


logger = buildLogger()

logger.warning('this is logged from module level')
myStandaloneFunction()
a = A()
a.afunc()

Logging Formatter record current function executing

1 Answers1