使用单个文件进行Python日志记录(函数名,文件名,行号)

问题:使用单个文件进行Python日志记录(函数名,文件名,行号)

我正在尝试学习应用程序的工作方式。为此,我将调试命令作为每个函数主体的第一行插入,目的是记录该函数的名称以及将消息发送至日志输出的行号(在代码内)。最后,由于此应用程序包含许多文件,因此我想创建一个日志文件,以便可以更好地了解应用程序的控制流程。

这是我所知道的:

  1. 为了获得函数名,我可以使用,function_name.__name__但我不想使用function_name(这样我就可以Log.info("Message")在所有函数的主体中快速复制并粘贴泛型)。我知道这可以使用__func__宏在C语言中完成,但我不确定python。

  2. 用于获取文件名和行号,我已经看到了(我相信)我的应用程序是使用Python的locals()功能,但在语法,我不完全知道的如:options = "LOG.debug('%(flag)s : %(flag_get)s' % locals())我尝试过使用像LOG.info("My message %s" % locals())产生类似{'self': <__main__.Class_name object at 0x22f8cd0>}。请问对此有何意见?

  3. 我知道如何使用日志记录并向其添加处理程序以将其记录到文件中,但是我不确定是否可以使用单个文件来按项目中函数调用的正确顺序记录所有日志消息。

我将不胜感激任何帮助。

谢谢!

I am trying to learn how an application works. And for this I am inserting debug commands as the first line of each function’s body with the goal of logging the function’s name as well as the line number (within the code) where I send a message to the log output. Finally, since this application comprises of many files, I want to create a single log file so that I can better understand the control flow of the application.

Here is what I know:

  1. for getting function name, I can use function_name.__name__ but I don’t want to use the function_name (so that I could rapidly copy and paste a generic Log.info("Message") in the body of all functions). I know this could be done in C using __func__ macro but I am not sure about python.

  2. for getting the filename and line number, I have seen that (and I believe that) my application is using Python locals() function but in a syntax that I am not completely aware of e.g.: options = "LOG.debug('%(flag)s : %(flag_get)s' % locals()) and I tried it using like LOG.info("My message %s" % locals()) which produces something like {'self': <__main__.Class_name object at 0x22f8cd0>}. Any input on this please?

  3. I know how to use logging and add handler to it to log to a file but I am not sure if a single file can be used to record all log messages in correct order of function calls in the project.

I would greatly appreciate any help.

Thanks!


回答 0

您在这里有一些边际相关的问题。

我将从最简单的开始:(3)。使用,logging您可以将所有调用聚集到一个日志文件或其他输出目标中:它们将按照在处理过程中发生的顺序进行。

接下来:(2)。locals()提供当前范围的指示。因此,在没有其他参数的方法中,您将具有self作用域,该作用域包含对当前实例的引用。困扰您的技巧是使用字典作为%操作员的RHS的字符串格式。"%(foo)s" % bar将被替换为bar["foo"]is的任何值。

最后,您可以使用一些自省技巧,类似于pdb可以记录更多信息的自省技巧:

def autolog(message):
    "Automatically log the current function details."
    import inspect, logging
    # Get the previous frame in the stack, otherwise it would
    # be this function!!!
    func = inspect.currentframe().f_back.f_code
    # Dump the message + the name of this function to the log.
    logging.debug("%s: %s in %s:%i" % (
        message, 
        func.co_name, 
        func.co_filename, 
        func.co_firstlineno
    ))

这将记录传入的消息,以及(原始)函数名称,出现定义的文件名以及该文件中的行。看一下检查-检查活动对象以了解更多详细信息。

正如我在前面的评论中提到的那样,您还可以pdb通过插入行import pdb; pdb.set_trace()并重新运行程序来随时进入交互式调试提示符。这使您可以逐步检查代码,并根据需要检查数据。

You have a few marginally related questions here.

I’ll start with the easiest: (3). Using logging you can aggregate all calls to a single log file or other output target: they will be in the order they occurred in the process.

Next up: (2). locals() provides a dict of the current scope. Thus, in a method that has no other arguments, you have self in scope, which contains a reference to the current instance. The trick being used that is stumping you is the string formatting using a dict as the RHS of the % operator. "%(foo)s" % bar will be replaced by whatever the value of bar["foo"] is.

Finally, you can use some introspection tricks, similar to those used by pdb that can log more info:

def autolog(message):
    "Automatically log the current function details."
    import inspect, logging
    # Get the previous frame in the stack, otherwise it would
    # be this function!!!
    func = inspect.currentframe().f_back.f_code
    # Dump the message + the name of this function to the log.
    logging.debug("%s: %s in %s:%i" % (
        message, 
        func.co_name, 
        func.co_filename, 
        func.co_firstlineno
    ))

This will log the message passed in, plus the (original) function name, the filename in which the definition appears, and the line in that file. Have a look at inspect – Inspect live objects for more details.

As I mentioned in my comment earlier, you can also drop into a pdb interactive debugging prompt at any time by inserting the line import pdb; pdb.set_trace() in, and re-running your program. This enables you to step through the code, inspecting data as you choose.


回答 1

正确的答案是使用已经提供的funcName变量

import logging
logger = logging.getLogger('root')
FORMAT = "[%(filename)s:%(lineno)s - %(funcName)20s() ] %(message)s"
logging.basicConfig(format=FORMAT)
logger.setLevel(logging.DEBUG)

然后,在任何需要的地方,只需添加:

logger.debug('your message') 

我现在正在处理的脚本的示例输出:

[invRegex.py:150 -          handleRange() ] ['[A-Z]']
[invRegex.py:155 -     handleRepetition() ] [[<__main__.CharacterRangeEmitter object at 0x10ba03050>, '{', '1', '}']]
[invRegex.py:197 -          handleMacro() ] ['\\d']
[invRegex.py:155 -     handleRepetition() ] [[<__main__.CharacterRangeEmitter object at 0x10ba03950>, '{', '1', '}']]
[invRegex.py:210 -       handleSequence() ] [[<__main__.GroupEmitter object at 0x10b9fedd0>, <__main__.GroupEmitter object at 0x10ba03ad0>]]

The correct answer for this is to use the already provided funcName variable

import logging
logger = logging.getLogger('root')
FORMAT = "[%(filename)s:%(lineno)s - %(funcName)20s() ] %(message)s"
logging.basicConfig(format=FORMAT)
logger.setLevel(logging.DEBUG)

Then anywhere you want, just add:

logger.debug('your message') 

Example output from a script I’m working on right now:

[invRegex.py:150 -          handleRange() ] ['[A-Z]']
[invRegex.py:155 -     handleRepetition() ] [[<__main__.CharacterRangeEmitter object at 0x10ba03050>, '{', '1', '}']]
[invRegex.py:197 -          handleMacro() ] ['\\d']
[invRegex.py:155 -     handleRepetition() ] [[<__main__.CharacterRangeEmitter object at 0x10ba03950>, '{', '1', '}']]
[invRegex.py:210 -       handleSequence() ] [[<__main__.GroupEmitter object at 0x10b9fedd0>, <__main__.GroupEmitter object at 0x10ba03ad0>]]

回答 2

funcnamelinenamelineno提供有关执行记录的最后一个功能的信息。

如果您有记录器的包装器(例如,单例记录器),则@synthesizerpatel的答案可能对您不起作用。

要找出呼叫堆栈中的其他调用方法,您可以执行以下操作:

import logging
import inspect

class Singleton(type):
    _instances = {}

    def __call__(cls, *args, **kwargs):
        if cls not in cls._instances:
            cls._instances[cls] = super(Singleton, cls).__call__(*args, **kwargs)
        return cls._instances[cls]

class MyLogger(metaclass=Singleton):
    logger = None

    def __init__(self):
        logging.basicConfig(
            level=logging.INFO,
            format="%(asctime)s - %(threadName)s - %(message)s",
            handlers=[
                logging.StreamHandler()
            ])

        self.logger = logging.getLogger(__name__ + '.logger')

    @staticmethod
    def __get_call_info():
        stack = inspect.stack()

        # stack[1] gives previous function ('info' in our case)
        # stack[2] gives before previous function and so on

        fn = stack[2][1]
        ln = stack[2][2]
        func = stack[2][3]

        return fn, func, ln

    def info(self, message, *args):
        message = "{} - {} at line {}: {}".format(*self.__get_call_info(), message)
        self.logger.info(message, *args)

funcname, linename and lineno provide information about the last function that did the logging.

If you have wrapper of logger (e.g singleton logger), then @synthesizerpatel’s answer might not work for you.

To find out the other callers in the call stack you can do:

import logging
import inspect

class Singleton(type):
    _instances = {}

    def __call__(cls, *args, **kwargs):
        if cls not in cls._instances:
            cls._instances[cls] = super(Singleton, cls).__call__(*args, **kwargs)
        return cls._instances[cls]

class MyLogger(metaclass=Singleton):
    logger = None

    def __init__(self):
        logging.basicConfig(
            level=logging.INFO,
            format="%(asctime)s - %(threadName)s - %(message)s",
            handlers=[
                logging.StreamHandler()
            ])

        self.logger = logging.getLogger(__name__ + '.logger')

    @staticmethod
    def __get_call_info():
        stack = inspect.stack()

        # stack[1] gives previous function ('info' in our case)
        # stack[2] gives before previous function and so on

        fn = stack[2][1]
        ln = stack[2][2]
        func = stack[2][3]

        return fn, func, ln

    def info(self, message, *args):
        message = "{} - {} at line {}: {}".format(*self.__get_call_info(), message)
        self.logger.info(message, *args)