17.5. trace — 跟踪代码执行流

本节目标:监控执行了哪些声明和函数,生成覆盖和调用图信息。

trace 模块可以帮助理解程序的执行路径。它会查看执行过的声明,生成覆盖报告帮助梳理函数间的调用关系。

例子程序

本程序会作为例子在以后的章节出现。它导入了另一个叫 recurse 的模块,然后运行了里面的一个函数。

trace_example/main.py

from recurse import recurse

def main():
    print('This is the main program.')
    recurse(2)

if __name__ == '__main__':
    main()

recurse() 会不断调用自己直到参数为 0

trace_example/recurse.py


def recurse(level):
    print('recurse({})'.format(level))
    if level:
        recurse(level - 1)

def not_called():
    print('This function is never called.')

追踪执行

trace 可直接从命令行中使用。使用 -trace 选项时,程序运行所执行的声明都会打印出来。下例还忽略了 Python 标准库里的内容以免追踪进 importlib ,在其他例子中这些模块可能更有用,不过在此例中只能扰乱输出。

$ python3 -m trace --ignore-dir=.../lib/python3.6\
--trace trace_example/main.py

 --- modulename: main, funcname: <module>
main.py(7): """
main.py(10): from recurse import recurse
 --- modulename: recurse, funcname: <module>
recurse.py(7): """
recurse.py(11): def recurse(level):
recurse.py(17): def not_called():
main.py(13): def main():
main.py(18): if __name__ == '__main__':
main.py(19):     main()
 --- modulename: main, funcname: main
main.py(14):     print('This is the main program.')
This is the main program.
main.py(15):     recurse(2)
 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(2)
recurse.py(13):     if level:
recurse.py(14):         recurse(level - 1)
 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(1)
recurse.py(13):     if level:
recurse.py(14):         recurse(level - 1)
 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(0)
recurse.py(13):     if level:
 --- modulename: trace, funcname: _unsettrace
trace.py(77):         sys.settrace(None)

输出的第一部分是 trace 执行的设置步骤。其余部分展示的是进入每个函数的步骤,包括函数在模块中的位置,源代码中是哪一行执行了。我们可以看到 recurse() 进入了三次,正如我们调用 main() 所预期的一样。

代码覆盖

使用 --count 选项的 trace 会生成代码覆盖率报告信息,它会告诉我们哪些代码调用了哪些没有。由于一个复杂的程序通常都会分成多个文件,所以会每个文件都会生成一份报告。默认情况下,覆盖报告文件会在模块的相同目录下生成,后缀是 .cover

$ python3 -m trace --count trace_example/main.py

This is the main program.
recurse(2)
recurse(1)
recurse(0)

运行后会生成两个文件,一个是 trace_example/main.cover

trace_example/main.cover


    1: from recurse import recurse

    1: def main():
    1:     print 'This is the main program.'
    1:     recurse(2)
    1:     return

    1: if __name__ == '__main__':
    1:     main()

另一个是 trace_example/recurse.cover:

trace_example/recurse.cover


    1: def recurse(level):
    3:     print 'recurse(%s)' % level
    3:     if level:
    2:         recurse(level-1)
    3:     return

    1: def not_called():
           print 'This function is never called.'

注意

尽管 def recurse(level) 只记了一次,但这并不意味着该函数只运行了一次。记录了一次表示只 定义 了一次。def not_called() 也是同样,即使函数本身并没被调用过,也定义了一次。

我们还可以调用多次,每次也可以是不同的选项,覆盖率数据会生成一个综合报告。首次运行 trace 写了一个输出文件,不过爆了一个错误,因为在创建文件前它尝试将已存在的数据和新结果合并,但是没成功。

$ python3 -m trace --coverdir coverdir1 --count\
--file coverdir1/coverage_report.dat trace_example/main.py

This is the main program.
recurse(2)
recurse(1)
recurse(0)
Skipping counts file 'coverdir1/coverage_report.dat': [Errno 2]
No such file or directory: 'coverdir1/coverage_report.dat'

$ python3 -m trace --coverdir coverdir1 --count\
--file coverdir1/coverage_report.dat trace_example/main.py

This is the main program.
recurse(2)
recurse(1)
recurse(0)

$ python3 -m trace --coverdir coverdir1 --count\
--file coverdir1/coverage_report.dat trace_example/main.py

This is the main program.
recurse(2)
recurse(1)
recurse(0)

$ ls coverdir1

coverage_report.dat

只要覆盖信息已经在 .cover 文件中记录了,我们就能用 --report 选项来生成报告。

$ python3 -m trace --coverdir coverdir1 --report --summary\
--missing --file coverdir1/coverage_report.dat\
trace_example/main.py

lines   cov%   module   (path)
  461     0%   trace   (.../lib/python3.6/trace.py)
    7   100%   trace_example.main   (trace_example/main.py)
    7    85%   trace_example.recurse
(trace_example/recurse.py)

由于我们运行了三次,这次的数据比第一次的要高。--summary 选项会添加一个百分比覆盖率信息在输出中。 recurse 模块只有 87% 的覆盖率。查看 recurse 的覆盖率文件会发现 not_called 没有被调用,用 >>>>>> 前缀标出来的就是。

coverdir1/trace_example.recurse.cover


    3: def recurse(level):
    9:     print('recurse({})'.format(level))
    9:     if level:
    6:         recurse(level - 1)

    3: def not_called():
>>>>>>     print('This function is never called.')

调用关系

除了覆盖率信息,trace 模块还会收集并报告函数间的调用关系。
使用 --listfuncs 可以列出简短的函数间调用关系:

$ python3 -m trace --listfuncs trace_example/main.py |\
grep -v importlib

This is the main program.
recurse(2)
recurse(1)
recurse(0)

functions called:
filename: .../lib/python3.6/trace.py, modulename: trace,
funcname: _unsettrace
filename: trace_example/main.py, modulename: main, funcname:
<module>
filename: trace_example/main.py, modulename: main, funcname:
main
filename: trace_example/recurse.py, modulename: recurse,
funcname: <module>
filename: trace_example/recurse.py, modulename: recurse,
funcname: recurse

要想知道详细的是谁调用了它,要用 --trackcalls

$ python3 -m trace --listfuncs --trackcalls\
trace_example/main.py | grep -v importlib

This is the main program.
recurse(2)
recurse(1)
recurse(0)

calling relationships:

*** .../lib/python3.6/trace.py ***
    trace.Trace.runctx -> trace._unsettrace
  --> trace_example/main.py
    trace.Trace.runctx -> main.<module>

  --> trace_example/recurse.py

*** trace_example/main.py ***
    main.<module> -> main.main
  --> trace_example/recurse.py
    main.main -> recurse.recurse

*** trace_example/recurse.py ***
    recurse.recurse -> recurse.recurse

注意

--listfuncs--trackcalls 都不支持 --ignore-dirs--ignore-mods 参数,所以我们用 grep 来代替它。

编程接口

为了控制更多 trace 的接口,我们可以在程序内使用 Trace 对象来调用。在运行单个函数或运行某个需要追踪的 Python 命令前,Trace可以设置 fixture 和其他依赖。
trace_run.py

import trace
from trace_example.recurse import recurse

tracer = trace.Trace(count=False, trace=True)
tracer.run('recurse(2)')

我们只追踪了 recurse(),所以 main.py 的信息不包含在输出中。

$ python3 trace_run.py

 --- modulename: trace_run, funcname: <module>
<string>(1):  --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(2)
recurse.py(13):     if level:
recurse.py(14):         recurse(level - 1)
 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(1)
recurse.py(13):     if level:
recurse.py(14):         recurse(level - 1)
 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(0)
recurse.py(13):     if level:
 --- modulename: trace, funcname: _unsettrace
trace.py(77):         sys.settrace(None)

使用 runfunc() 可以达到同样的效果。

trace_runfunc.py

import trace
from trace_example.recurse import recurse

tracer = trace.Trace(count=False, trace=True)
tracer.runfunc(recurse, 2)

runfunc() 方法接受任意的位置和关键字参数,在 tracer 调用时会将他们传递给函数。

$ python3 trace_runfunc.py

 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(2)
recurse.py(13):     if level:
recurse.py(14):         recurse(level - 1)
 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(1)
recurse.py(13):     if level:
recurse.py(14):         recurse(level - 1)
 --- modulename: recurse, funcname: recurse
recurse.py(12):     print('recurse({})'.format(level))
recurse(0)
recurse.py(13):     if level:

保存结果数据

计数和覆盖率信息可以被保存下来,像命令行里的一样。数据必须以显式状态保存,要使用Trace 里的 CoverageResults 实例对象完成。

trace_CoverageResults.py

import trace
from trace_example.recurse import recurse

tracer = trace.Trace(count=True, trace=False)
tracer.runfunc(recurse, 2)

results = tracer.results()
results.write_results(coverdir='coverdir2')

例子会将覆盖率结果存到 coverdir2 目录下。

$ python3 trace_CoverageResults.py

recurse(2)
recurse(1)
recurse(0)

$ find coverdir2

coverdir2
coverdir2/trace_example.recurse.cover

输出:

       #!/usr/bin/env python
       # encoding: utf-8
       #
       # Copyright (c) 2008 Doug Hellmann All rights reserved.
       #
       """
>>>>>> """

       #end_pymotw_header

>>>>>> def recurse(level):
    3:     print('recurse({})'.format(level))
    3:     if level:
    2:         recurse(level - 1)

>>>>>> def not_called():
>>>>>>     print('This function is never called.')

保存计数报告需要用 Traceinfileoutfile 参数。

trace_report.py

import trace
from trace_example.recurse import recurse

tracer = trace.Trace(count=True,
                     trace=False,
                     outfile='trace_report.dat')
tracer.runfunc(recurse, 2)

report_tracer = trace.Trace(count=False,
                            trace=False,
                            infile='trace_report.dat')
results = tracer.results()
results.write_results(summary=True, coverdir='/tmp')

infile 需要传递一个文件名指向之前保存的数据,outfile 要传递另一个文件名来写入新的结果。如果 infileoutfile 相同,则视为累积数据。

$ python3 trace_report.py

recurse(2)
recurse(1)
recurse(0)
lines   cov%   module   (path)
    7    42%   trace_example.recurse
(.../trace_example/recurse.py)

选项

Trace 有几个可选的参数来控制运行的行为。

count

布尔类型。是否打开行计数。默认为 True

countfuncs

布尔类型。是否统计函数的调用列表。默认 False

countcallers

布尔类型。是否追踪调用者和被调用者。默认 False

ignoremods

序列。追踪覆盖时忽略的模块或包。默认是空元组。

ignoredirs

序列。要忽略的模块和包的目录。默认是空元组。

infile
包含已经抓取的计数值的文件的名称。默认是 None.

outfile

用于存储计数值的文件名。默认是 None,也就是不存储。

参阅