调试：如何获取函数调用的文件名和行号？

Question

我现在正在用Python构建一个比较复杂的系统，在调试的时候，我经常在几个脚本里放一些简单的打印语句。为了保持清晰，我还想打印出这些打印语句所在的文件名和行号。当然，我可以手动去做，或者用类似下面的代码：

from inspect import currentframe, getframeinfo

print getframeinfo(currentframe()).filename + ':' + str(getframeinfo(currentframe()).lineno) + ' - ', 'what I actually want to print out here'

这段代码会打印出类似这样的内容：

filenameX.py:273 - what I actually want to print out here

为了让事情更简单，我想能够做到类似这样的效果：

print debuginfo(), 'what I actually want to print out here'

于是我把它放进一个函数里，然后尝试这样做：

from debugutil import debuginfo
print debuginfo(), 'what I actually want to print out here'
print debuginfo(), 'and something else here'

不幸的是，我得到的结果是：

debugutil.py:3 - what I actually want to print out here
debugutil.py:3 - and something else here

它打印出来的是我定义这个函数的文件名和行号，而不是我调用 debuginfo() 的那一行。这很明显，因为代码是在 debugutil.py 文件里。

所以我真正想问的是：我怎么才能获取调用这个 debuginfo() 函数时的文件名和行号呢？

Answer 1

只需把你发的代码放进一个函数里：

from inspect import currentframe, getframeinfo

def my_custom_debuginfo(message):
    print getframeinfo(currentframe()).filename + ':' + str(getframeinfo(currentframe()).lineno) + ' - ', message

然后你可以根据需要使用它：

# ... some code here ...
my_custom_debuginfo('what I actually want to print out here')
# ... more code ...

我建议你把这个函数放在一个单独的模块里，这样每次需要的时候都可以重复使用。

Answer 2

这是对之前接受的答案的更新，使用了字符串插值，并显示了调用者的函数名称。

import inspect
def debuginfo(message):
    caller = inspect.getframeinfo(inspect.stack()[1][0])
    print(f"{caller.filename}:{caller.function}:{caller.lineno} - {message}")

Answer 3

traceprint这个工具包现在可以帮你做到这一点：

import traceprint


def func():
    print('Hello from func!')

func()

#   File "/traceprint/examples/example.py", line 6, in <module>
#   File "/traceprint/examples/example.py", line 4, in func
# Hello from func!

在PyCharm中，文件链接会自动变得可以点击和跟踪。

你可以通过输入 pip install traceprint 来安装它。

Answer 4

如果你把追踪代码放在另一个函数里，然后从主代码中调用它，你需要确保获取的是祖父级的堆栈信息，而不是父级或追踪函数本身的。

下面是一个三层嵌套的系统示例，进一步说明我的意思。我的主函数调用一个追踪函数，这个追踪函数又调用另一个函数来完成工作。

######################################

import sys, os, inspect, time
time_start = 0.0                    # initial start time

def trace_libary_init():
    global time_start

    time_start = time.time()      # when the program started

def trace_library_do(relative_frame, msg=""):
    global time_start

    time_now = time.time()

        # relative_frame is 0 for current function (this one), 
        # 1 for direct parent, or 2 for grand parent.. 

    total_stack         = inspect.stack()                   # total complete stack
    total_depth         = len(total_stack)                  # length of total stack
    frameinfo           = total_stack[relative_frame][0]    # info on rel frame
    relative_depth      = total_depth - relative_frame      # length of stack there

        # Information on function at the relative frame number

    func_name           = frameinfo.f_code.co_name
    filename            = os.path.basename(frameinfo.f_code.co_filename)
    line_number         = frameinfo.f_lineno                # of the call
    func_firstlineno    = frameinfo.f_code.co_firstlineno

    fileline            = "%s:%d" % (filename, line_number)
    time_diff           = time_now - time_start

    print("%13.6f %-20s %-24s %s" % (time_diff, fileline, func_name, msg))

################################

def trace_do(msg=""):
    trace_library_do(1, "trace within interface function")
    trace_library_do(2, msg)
    # any common tracing stuff you might want to do...

################################

def main(argc, argv):
    rc=0
    trace_libary_init()
    for i in range(3):
        trace_do("this is at step %i" %i)
        time.sleep((i+1) * 0.1)         # in 1/10's of a second
    return rc

rc=main(sys.argv.__len__(), sys.argv)
sys.exit(rc)

这将打印出类似这样的内容：

$ python test.py 
    0.000005 test.py:39           trace_do         trace within interface func
    0.001231 test.py:49           main             this is at step 0
    0.101541 test.py:39           trace_do         trace within interface func
    0.101900 test.py:49           main             this is at step 1
    0.302469 test.py:39           trace_do         trace within interface func
    0.302828 test.py:49           main             this is at step 2

最上面的 trace_library_do() 函数是一个可以放到库里的示例，然后可以从其他追踪函数中调用它。相对深度值控制打印出 Python 堆栈中的哪个条目。

我在这个函数中展示了一些其他有趣的值，比如函数开始的行号、总堆栈深度和文件的完整路径。我没有展示，但函数中的全局和局部变量也可以在 inspect 中找到，还有你下面所有其他函数的完整堆栈跟踪。以上展示的信息足够用来制作层次化的调用/返回时间追踪。其实，从这里开始，创建自己源代码级调试器的主要部分也并不远——而且这些信息大部分都在那儿等着你去使用。

我相信会有人反对我使用 inspect 结构返回的内部字段，因为可能有访问函数可以为你做同样的事情。但我是在 Python 调试器中逐步调试这类代码时发现它们的，而且在这里它们确实有效。我使用的是 Python 2.7.12，如果你使用不同的版本，结果可能会有所不同。

无论如何，我强烈建议你把 inspect 代码导入到你自己的 Python 代码中，看看它能为你提供什么——尤其是如果你能在一个好的 Python 调试器中逐步执行你的代码。你会学到很多关于 Python 工作原理的知识，看到这个语言的好处，以及在幕后发生了什么使得这一切成为可能。

带时间戳的完整源代码级追踪是增强你对代码运行情况理解的好方法，特别是在动态实时环境中。这种追踪代码的好处在于，一旦写好，你就不需要调试器的支持就能看到它。

Answer 5

这个函数 inspect.stack() 会返回一个列表，里面包含了一些关于程序运行时的“帧记录”。这个列表是从调用这个函数的地方开始的，然后逐步向外扩展。你可以利用这些信息来获取你想要的内容：

from inspect import getframeinfo, stack

def debuginfo(message):
    caller = getframeinfo(stack()[1][0])
    print("%s:%d - %s" % (caller.filename, caller.lineno, message)) # python3 syntax print

def grr(arg):
    debuginfo(arg)      # <-- stack()[1][0] for this line

grr("aargh")            # <-- stack()[2][0] for this line

输出结果:

example.py:8 - aargh