分享一下自己的做的 Python profiling/debugging/logging 工具 VizTracer

[laike9m]

首先声明这个不是我写的，而是替刚注册 V2 还不能发帖的朋友发的。当然我觉得 VizTracer 确实不错，比其它的火焰图库更符合直觉。 他的账号：@gaogaotiantian

下面是正文。

---

小伙伴们大家好~今天来分享一下我这几个月做的开源项目 VizTracer 。先把地址给了。

https://github.com/gaogaotiantian/viztracer

VizTracer 的核心功能是帮助你理解你的代码到底在干什么。它会 trace 你的 python code，记录每一次函数运行和返回的时间点，最后生成一个 html 文件把整个运行结果可视化，大概长这个样子：

可能有些同学用过一些代码运行可视化的库，比如 gprof2dot 或者 snakeviz 之类，也可能大家觉得这个图和 flamegraph 也就是火焰图很像，但是 VizTracer 带来的信息和一切 profiler 是不太一样的。

如果仔细观察的话能看出来，VizTracer 的横轴是时间，它记录了所有事件（函数）发生的顺序，谁调用的谁，每一次运行的时间，而不是单纯地某个函数一共占了多少时间，或者是总结性的函数关系图。VizTracer 展示的数据是一切以 cProfile 为基础的库都没法展示的，因为 cProfile 压根就没记录这些数据。相比起这些"profiler"，VizTracer 更像一个 logging tool 。

先简单说一下 VizTracer 怎么用吧。在设计之初，我的理念就是要让工具尽可能地好上手，所以 VizTracer 的使用其实特别容易：

pip install viztracer

viztracer your_script.py

是不是超级简单。基本上你只需要把原来的

python your_script.py arg1 arg2

变成

viztracer your_script.py arg1 arg2

就行了。

在运行之后，VizTracer 会在当前目录下生成一个result.html文件，用 chrome 打开它即可。我自己生成了一些demo，感兴趣的同学可以看一下。

除了最基础的记录函数 entry/exit 的功能之外，VizTracer 还有很多其他 loggin 功能，比较有趣的事，这里面有大量的功能是可以不改源代码就完成的。

举个例子，你可以让 VizTracer 记录每个函数的 arguments 和 return value，只需要

viztracer --log_return_value --log_function_args your_script.py

或者你可以让 VizTracer 记录任何符合某些 RegEx 的变量

viztracer --log_var <regex1> <regex2> --run your_script.py

这个的效果是，如果有一个变量的名称符合<regex1>或者<regex2>，VizTracer 就会在这个变量每次被 assign 之后记录一个 custom event，让你可以在 report 里看到它被改成什么值了。（这里增加了--run是为了去歧义，--log_var可以 take 任意多的值）

另外 VizTracer 还提供了一些 filter 功能，让你可以不记录你不感兴趣的内容。比如你可以只记录某些文件里的函数

viztracer --include_files ./src --run your_script.py

其实还有很多很多 feature，欢迎大家去试用一下，这里只介绍了开箱即用的不改代码的一少部分 feature，还有一些 custom event 可以修改源代码来更精确地记录数据的变化。

最后其实我想提一句的是，VizTracer 是我很认真对待的一个项目，不是当作玩具做的，我写了比较详细的文档（所有的 feature 都介绍了），test coverage 做到了 99.5%+，支持 Linux/MacOS/Windows 。另外为了追求 performance，VizTracer 的核心代码是纯 C 写的（所以只支持 CPython ），产生的 Overhead 和 cProfile 是差不多的，在 worst case 大概是 2x-3x 这个数量级（当然前提是没有 log 太多 custom 的东西）。

就先介绍到这里吧！欢迎大家试用以及提出宝贵意见哈！有任何问题可以下面留言，也可以直接去 github 给我提 issue~

顺便一提，作者 @gaogaotiantian 下一期就将作客捕蛇者说和大家聊聊 VizTracer 。在此先预告一下
https://www.pythonhunter.org/

[ruanimal]

lz 毅力强，github 基本每天都有 commit

[siluni]

我是小白用户，刚才试用了一下，几百行代码的 project 跑出来了一个 156MB 的 html...是我用法有问题还是本来就这么大呢

[zouzou0208]

看了下，做的好棒。

[gaogaotiantian]

@siluni 这是正常的，VizTracer 本身记录的数据非常多，所以 log 会很大。代码的行数几百行可能有很多的 function call，十行代码就可以有几十万个 call 对吧~和 cProfile 不同，VizTracer 对于每个 call 都要单独记录一个 entry，所以文件会比较大~

[siluni]

@gaogaotiantian 明白了！非常感谢您的作品和回复~已 star

[Ehco1996]

在运行之后，VizTracer 会在当前目录下生成一个 result.html 文件 -> 换成程序结束之后

[gaogaotiantian]

@Ehco1996 确实应该是结束之后~不过文章似乎已经改不了了~大家应该差不多能理解吧~哈哈~

[no1xsyzy]

看起来挺不错的，但其实我一直没搞懂火焰图怎么看（

[gaogaotiantian]

@no1xsyzy 哈~这个不是火焰图，算是 call stack 图吧~核心展示内容是函数之间的调用次序和时间

[THP301]

这个作品从实用性和易用性都做到了极致，生成的图还非常直观，少有的作品

[gaogaotiantian]

@THP301 谢谢如此高的评价啊~实用性和易用性确实是我做这个项目时候很期望达成的目标~

[frostming]

在 POSIX getopt 标准里面"--" 可以用来分隔 option 和 positinal args，-- 后面的参数通通当做 positional args 塞给 Python 就好了，这个是有惯例的，个人认为会比--run 好，减少一个记忆点

[frostming]

我看了一下你用的 argparse，这些主流框架都是支持这么弄的，不需要额外的处理代码，如果有需要我可以 pr

[no1xsyzy]

@gaogaotiantian 拿主题这张图仔细看了看，结合你这句回复……
我一直以为火焰图就是 call stack 图，原来不是吗？难怪看不懂……
好吧，什么时候再去看看火焰图怎么看

[laike9m]

@no1xsyzy 我也以为是。。

[gaogaotiantian]

@frostming 这是个挺好的建议……我这两天就弄一下，把--run 作为 undocumented feature （为了 backward compatibility ），然后用--为主。

[gaogaotiantian]

@no1xsyzy VizTracer 提供的图确实有和火焰图很相似的地方。简单来说，火焰图是一个“总结”性的图，它展示的是某一个函数在这个位置占据的总时间。而 VizTracer 的图是每一次调用都会有一个展示。

比如说，A 调用了 B 100 次，每次 1ms 。在火焰图上，就是最下面是 A，A 的宽度是 100ms 的 B 加上 A 自己的耗时，A 上面有一个 B，B 的宽度是 100ms 。而 VizTracer 的图上，最下面是 A，A 上面有 100 个 1ms 的 B，每个 B 之间的间隔就是他们被调用之间 A 的耗时。