How to implement an implicit logger in Python?-CodePudding

I want to add some helpful logging to a Python codebase.

I'm looking to add logging roughly of the form:

[2022-01-06 10:00:01] function foo called with args x=1, y=22, z=3
[2022-01-06 10:00:05] function foo returned 1416
[2022-01-06 10:00:13] function bar called with args w=1416
[2022-01-06 10:00:16] function bar returned None

I could do this by wrapping all functions in the codebase with a decorator, but is there a better way? At least to indicate the timestamp and order in which functions are being called.

I could implement the decorator:

def logthis(func):
    def inner(*args, **kwargs):
        logger.info(f'Calling {func.__name__} with args={args} and kwargs={kwargs}')
        ans = func(*args, **kwargs)
        logger.info(f'Function {func.__name__} returned {ans}')
        return ans
    return inner

@logthis
def foo(x, y, z):
   return x y z

@logthis
def bar(w):
   return None

This works reasonably well; provided I'm happy to add it across my whole codebase.

CodePudding user response：

You can use the inspect module. I typically use it to implement a "Get the filepath of the function that called this function" Method I use for various reasons. Inspect.stack() (See this) may be what you are looking for as you can go up the list of callers and create info about it. From there i think the only problem youd have is how to log the time. Another idea is two create a wrapper for entire classes or a function that you pass locals to that gets all functions and applies a decorator to them. That method is going somewhat into meta programming since youd have to reconstruct the class objects /update/wrap all of their functions like you have and whatnot, but it could save you a fair amount of tedious work.

Also see the traceback module

CodePudding user response：

The dumb way, writing to the console. Parameters can be added to log to a file.

import logging
import sys

logging.basicConfig(
    level=logging.INFO,
    format='%(asctime)s.%(msecs)03d %(levelname)s %(module)s - %(funcName)s: %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S',
    stream=sys.stdout
)

def my_func():
  logging.info('message from inside function') # should display a timestamp, the level of the log message, the name of the function it was executed in, and the message.

my_func()
logging.info('message from outside function')

Returns:

2022-01-06 23:39:04.829 INFO randoms - my_func: message from inside function
2022-01-06 23:39:04.829 INFO randoms - <module>: message from outside function