作者：王璐璐 | 旷视 MegEngine 架构师
一、背景
在 MegEngine imperative runtime 的晚期开发中，咱们面临着一些的性能优化问题。除了一些已知须要重构的中央（晚期设计时为了开发效率而就义性能的斗争），还存在一些未知的性能问题须要用 profiler 进行观测和剖析能力发现。MegEngine 的 imperative runtime 是一个由 Python 和 C /C++ 编写的模块，对于这类程序，各种 profiler 多到令人目迷五色。在调研各种 profiler 的过程中，咱们也踩了不少的坑，比方发现两个 profiler 对同一个程序的 profiling 后果差别微小，咱们起初狐疑其中一个 profiler 的准确性有问题，最初发现是两者的观测对象不同，其中一个只 profiling 程序的 CPU time，而另一个 profiling wall clock time。尽管一些这样的信息在文档的某些角落里可能找到，但很多使用者可能在踩了坑之后才会留神到。如果一开始能找到一篇介绍各种 profiler 的特点、劣势、有余和应用场景的文章，咱们可能会节俭不少工夫。
因而本文尝试对这些教训进行总结，心愿可能给首次应用这些工具的读者一些参考。性能优化是一个非常宽泛的话题，它波及 CPU、内存、磁盘、网络等方面，本文次要关注 Python 及 C /C++ 拓展程序在 CPU 上的性能优化，文章次要围绕着上面三个问题开展:
- Python 及 C /C++ 拓展程序的常见的优化指标有哪些
- 常见工具的能力范畴和局限是什么，给定一个优化指标咱们应该如何抉择工具
- 各种工具的应用办法和后果的可视化办法
除此之外，本文还会介绍一些性能优化中须要理解的基本概念，并在文章开端以 MegEngine 开发过程中的一个性能优化的理论案例来展现一个优化的流程。
二、基本概念
本节介绍性能优化中的一些根底概念:
2.1 wall clock time, CPU time 和 off-CPU time
掂量程序性能最间接的规范就是程序的运行工夫，但仅仅晓得程序的运行工夫很难领导咱们如何把程序优化地更快，咱们想要更进一步地理解这段时间之内到底产生了什么。
Linux 零碎上的 time 命令可能通知咱们一些毛糙的信息，咱们在命令行里输入上面的命令来测量查看某个文件的 CRC 校验码的运行工夫:
time cksum \<some_file\>
以我的电脑 (MacBook Pro 2018) 为例，失去了以下输入:
8.22s user 1.06s system 96% cpu 9.618 total
这段文字通知了咱们工夫都花在了哪里:
- 总工夫 9.618s
- user 工夫 8.22s
- system 工夫 1.06s
其中 user 和 system 的含意是 user CPU time 和 system CPU time, 之所以会把 CPU 的执行工夫分为两个局部，是因为程序在运行时除了执行程序自身代码和一些库的代码，还会调用操作系统提供的函数(即零碎调用，程序运行零碎调用时有更高的权限)，因而程序运行时通常会处于两种状态: 用户态和内核态: 内核态指的是 CPU 在运行零碎调用时的状态，而用户态就是 CPU 运行非零碎调用（即用户本人的代码或一些库）时的状态。
因而下面提到的 user CPU time 指的是用户态所破费的工夫，而 system CPU time 指的是内核态破费的工夫。
咱们发现 user CPU time + system CPU time = 8.22s + 1.06s = 9.28s 并不等于总工夫 9.618s，这是因为这条命令执行的工夫内，程序并不是总是在 CPU 上执行，还有可能处于睡眠、期待等状态，比方期待文件从磁盘加载到内存等。这段时间既不算在 user CPU time 也不算在 system CPU time 内。咱们把程序在 CPU 上执行的工夫 (即 user CPU time + system CPU time) 称为 CPU time (或 on-CPU time), 程序处于睡眠等状态的工夫称为 off-CPU time (or blocked time)，程序理论运行的工夫称为 wall clock time（字面意思是墙上时钟的工夫，也就是真实世界中流逝的工夫），对于一个给定的线程: wall clock time = CPU time + off-CPU time。
通常在计算密集型（CPU intensive）的工作中 CPU time 会占据较大的比重，而在 I / O 密集型（I/O intensive）工作中 off-CPU time 会占据较大的比重。搞清楚 CPU time 和 off-CPU time 的区别对性能优化非常重要，比方某个程序的性能瓶颈在 off-CPU time 上，而咱们抉择了一个只观测 CPU time 的工具，那么很难找到真正的性能瓶颈，反之亦然。
2.2 性能观测工具
咱们晓得了一个线程执行过程中的 CPU time 和 off-CPU time，如果要对程序的性能进行优化，这些还远远不够，咱们须要进一步晓得 CPU time 的时间段内，CPU 上到底产生了哪些事件、这些事件别离耗费了多少工夫、在哪里导致了线程被 block 住了、别离 block 了多久等。咱们须要性能观测工具来取得这些具体的信息。通常状况下咱们也将称这种观测工具称为 profiler。
不同的观测对象对应着不同的 profiler，仅就 CPU 而言，profiler 也不可胜数。
依照观测范畴来分类，CPU 上的 profiler 大抵能够分为两大类: 过程级 (per-process, 某些中央也叫做利用级) 和零碎级(system wide)，其中:
- 过程级只观测一个过程或线程上产生的事件
- 零碎级不局限在某一个过程上，观测对象为整个零碎上运行的所有程序
须要留神的是，某些工具既能观测整个零碎也反对观测单个过程，比方 perf，因而这样的工具同时属于两个类别。
依照观测办法来分类，大抵能够分为 event based 和 sampling based 两大类。其中:
- event based: 在一个指定的 event 汇合上进行，比方进入或来到某个 / 某些特定的函数、分配内存、异样的抛出等事件。event based profiler 在一些文章中也被称为 tracing profiler 或 tracer
- sampling based: 以某一个指定的频率对运行的程序的某些信息进行采样，通常状况下采样的对象是程序的调用栈
即便确定了咱们优化的对象属于上述的某一个类别，依然有更细粒度的分类。在抉择工具之前要搞清楚具体的优化对象是什么，单个 profiler 个别无奈满足咱们所有的需要，针对不同的优化对象 (比方 Python 线程、C/C++ 线程等) 咱们须要应用不同的 profiler。并且，对于同一个优化对象，如果咱们关注的信息不同，也可能须要应用不同的 profiler。
2.3 Python 过程模型
本文次要关注 Python（包含 C /C++ 拓展) 程序的优化，一个典型的 Python 和 C /C++ 拓展程序的过程如下图所示:
一个 Python 过程必须蕴含一个 Python 主线程，可能蕴含若干个 Python 子线程和若干个 C /C++ 子线程。因而咱们进一步把优化对象细分为三类:
- Python 线程中的 Python 代码
- Python 线程中的 C /C++ 拓展代码
- C/C++ 线程
这里的 Python 线程具体指 CPython 解释器线程，而 C /C++ 线程指不蕴含 Python 调用栈的 C /C++ 线程。
三、profiler 的分类和抉择
咱们从以下两个角度对 profiler 进行刻画:
- 是否反对 profiling time、off-CPU time 和 wall clock time (CPU time + off-CPU time)
- 是否反对 profiling C/C++ stack
- 是否可能从 CPython 解释器的调用栈中解析出 Python 调用栈
咱们介绍将介绍 6 个 profiler，别离为 py-spy、cProfile、pyinstrument、perf、systemtap 和 eu-stack。为了不便大家进行抉择，咱们依照下面介绍的特色，把这些 profiler 分成了 4 类并总结在了上面的表格中 (其中✔、⚠、×别离示意反对、不齐全反对和不反对):
表格中第一种是纯 Python profiler，只能观测 Python 线程中 Python 函数的调用栈，适宜优化纯 Python 代码时应用，本文将介绍 CProfile（Python 的 built-in profiler）和 pyinstrument（第三方 Python profiler），这类 profiler 还有很多，比方 scalene、line-profiler、pprofile 等，因为这些 profiler 在能力上差别不大，因而这里就不一一介绍了。
第二类是 Python 线程 profiler，与第一类的次要区别是除了可能观测 Python 线程里的 Python 调用栈，还能观测 c /c++ 拓展的调用栈，这一类只介绍 py-spy。
第三类是零碎级 profiler，咱们次要用来观测 Python 线程中的 C /C++ 拓展的调用栈和纯 C /C++ 线程，这类 profiler 尽管可能观测 CPython 解释器的调用栈，但因为不是专为 Python 设计的 profiler，不会去解析 Python 函数的调用栈，因而不太适宜观测 Python stack。这一类工具咱们将介绍 perf 和 systemtap。
最初一类是对第三类的补充，因为第三类介绍的两个工具都无奈在 wall clock time (CPU time + off-CPU time) 上观测程序，eu-stack 能够在 wall clock time 上采样程序的 C /C++ 调用栈，因而能够作为这种场景下的 profiler。
表格中的 overhead 指 profiler 运行时对被 profiling 程序的影响，overhead 越大 profiling 的后果准确度越低。须要留神的是，任何 profiler 都无奈做到相对的精确，profiler 自身对程序带来的影响、采样的随机性等都会对后果造成影响，咱们不应该将 profiling 后果作为程序运行时的理论状况，而应该将其视为一种对理论状况的预计（这种预计甚至是有偏的）。
除了 profiler，咱们还须要一些工具来对 profiling 的后果进行可视化来剖析性能瓶颈。与 profiler 不同的是，可视化工具个别具备较强通用性，一种宽泛应用的工具是火焰图(flamegraph)，本文将介绍 flamegraph 的应用办法，除此之外还会介绍一个火焰图的改进版工具: speedscope。
因为 profiler 的介绍里须要援用可视化工具，因而接下来咱们先介绍可视化工具，再介绍 profiler。
四、可视化工具
4.1 flamegraph
火焰图（flamegraph）是一个功能强大的可视化 profiling 后果的工具。它即能够对多种 profiler 的输入进行解决，也能够对解决后的后果进行可视化。它可能解决不同平台上的十多种 profiler 的原始输入，除了可能可视化 cpu 上的 profiling 后果，它也能够对一些内存 profiler 的输入后果进行可视化。
flamegraph 的应用流程个别是对 profiler 的原始输入后果进行解决，之后再生成一个 SVG 文件，能够在浏览器里关上，成果如下:
flamegraph 的次要性能就是显示 profiler 采样的调用栈的频率散布，图中纵向堆起来的代表调用栈，调用栈中的矩形块的宽度代表该函数运行时被采到的频率（某个执行门路的工夫占比与它被采样到的概率成正比，因而采样频率近似等于该执行门路的工夫占比）。通过观察火焰图，咱们能够看到程序都有哪些执行门路，以及每个执行门路的工夫占比，而后对工夫占比拟大的性能瓶颈（或 \” 热点 \”）进行优化，来达到优化性能的目标。
如果想深刻理解 flamegraph，能够参考作者的主页或 github repo:
- homepage: http://www.brendangregg.com/f…
- github repo: https://github.com/brendangre…
4.2 speedscope
另外一个值得介绍的工具是 speedscope。speedscope 的应用办法和 flamegraph 相似，且兼容 flamegraph 的输入格局。与 flamegraph 相比，speedscope 在两个方面具备劣势: 1) speedscope 在可视化成果、交互性等方面体现非常优良，2) speedscope 运行时的开销比 SVG 低很多，同时开很多窗口也不会造成显著卡顿。因而，咱们举荐把 speedscope 与 flamegraph 联合在一起应用: 用 flamegraph 来解决不同工具的输入数据，用 speedscope 进行可视化。speedscope 是一个 web app，作者提供了一个能够间接应用的地址: https://www.speedscope.app/, 咱们也能够在本地部署，但更前者更不便。本文次要以 speedscope 来可视化 profiling 后果，上面简略介绍一下它的应用办法:
进入 https://www.speedscope.app/ 中，关上 json 格局的 profiling 后果 (咱们会在上面各种 profiler 的应用办法中介绍如何将后果转为这种 json)。能够看到以下界面 (与 flamegraph 的一个不同之处是 speedscope 的调用栈是倒过去的):
左上角能够抉择三种模式:
- Time Order: 即时间轴模式，从左到右代表工夫的方向，两头每一列代表改时刻采样的调用栈
-
Left Heavy: 依照调用栈函数的工夫占比 (采样次数占比来预计工夫占比) 进行展现，即调用栈的每一层都依照左侧工夫多右侧工夫短的程序来排序。点击任何一个调用栈中的函数:
- 能够在图中左下角看到该函数在以后调用栈 (This Instance) 的总开销 (Total) 和本身开销(Self)，以及该函数在所有呈现过的调用栈(All Instances) 中的总开销 (Total) 和本身开销(Self), 图中的整数代表被采样的次数，百分比为被采样的占比(近似等于工夫占比)。
- 图下方的红色框内是该函数的调用栈。
- Sandwich: 用函数的总开销和本身开销来排序，点击函数能够看到该函数的调用者和被调用者
更具体的介绍能够参考 speedscope 的官网 repo: https://github.com/jlfwong/sp…
五、性能观测工具
接下来咱们介绍几个在 Python 和 C /C++ 拓展程序的优化过程中罕用的 profiler。咱们将介绍每种 profiler 的长处和局限，大家应该依据本人的理论需要来抉择适合的工具。
5.1 py-spy
py-spy 是一个 sampling based profiler, 它的 profiling 的对象是 Python 及 C /C++ 拓展的调用栈。py-spy 的 overhead 中等，对运行的程序速度影响不算太大。且自身反对间接输入 speedscope 和 flamegraph 格局的后果。
repo: https://github.com/benfred/py…
能够间接应用 pip 进行装置:
pip install py-spy
应用办法:
# 根本应用办法:
py-spy record --format speedscope -o output.json --native -- python3 xxx.py
# =====
# 主要参数:
# --format: 输入格局，默认是 flamegraph，举荐应用 speedscope 格局
# --output: 输入文件名
# --native: 是否采样 C /C++ 调用栈，不加 --native 只会对 Python 调用栈进行采样
# =====
# 其余参数
# --rate: 采样频率，默认值为 100，关上 --native 会增大 overhead，倡议关上 --native 时调低 --rate
# --subprocesses: 是否对子过程进行采样，默认为否
# --gil: 是否只对拿到 Python GIL 的线程进行采样
# --threads: 在输入中显示 thread id
# --idle: 是否对 idle(即 off-CPU time)的 thread 进行采样，默认为否，依据具体场景抉择是否关上
# =====
# 例子:
py-spy record -sti --rate 10 --format speedscope --native -o output.json -- python3 xxx.py
# 除了在启动时运行 py-spy，还能够对一个曾经运行的 python 过程进行采样，如:
py-spy record --format speedscope -o output.json --native --pid 12345
其余性能:
除了 record 子命令外，py-spy 还提供了 top 子命令: 能够在命令行中动态显示工夫开销最大函数排序; 以及 dump 子命令: 能够打印一个正在运行的 python 过程的调用栈。具体应用办法能够参考文档: https://github.com/benfred/py…
py-spy 反对在 CPU time 或 wall clock time (CPU time + off-CPU time) 上对程序的调用栈进行采样，采样的对象是 Python 线程的 python 调用栈或 c /c++ 拓展的调用栈。
py-spy 尽管也能对 C /C++ 线程的调用栈进行采样，但目前（v0.3.4）会把 Python 调用栈与 C /C++ 调用栈拼在一起 (详见 GitHub 相干 issue：https://github.com/benfred/py…，无论两者是否真正存在调用关系，这样会使 C /C++ 线程的 profiling 后果在可视化时依照 Python 调用栈进行聚合，导致很难进行剖析，因而 py-spy 目前只适宜对纯 Python 代码以及 Python 线程上的 C /C++ 拓展 (存在 Python 到 C /C++ 的调用关系) 进行观测，不适宜观测独立的 C /C++ 线程，这是 py-spy 的一个不足之处。
5.2 cProfile
cProfile 是一个 event based profiler，它的工作原理是追踪 Python 解释器上的每一个 Python 函数调用和工夫开销。cProfile 是 Python 的 built-in profiler，实践上对 Python 的反对度绝对较高。cProfile 的局限有很多：
- 只能观测纯 Python 的函数调用，无奈看到 C /C++ 拓展的调用栈
- 只反对 wall clock time
- overhead 绝对较大
应用办法:
python3 -m cProfile xxx.py
cProfile 的输入格局是一个 table, 如下:
2173 function calls (2145 primitive calls) in 10.230 seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:103(release)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:143(__init__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:147(__enter__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:151(__exit__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:157(_get_module_lock)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:176(cb)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:211(_call_with_frames_removed)
32 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:222(_verbose_message)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:307(__init__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:311(__enter__)
....也能够指定输入文件:
python3 -m cProfile -o xxx.cprof xxx.py
原始输入不不便剖析，咱们须要一些第三方工具来解决输入数据和可视化，上面介绍两种办法:
- 转成一个 call graph 的图片
# dependency: gprof2dot, graphviz
# sudo apt install graphviz
# pip3 install gprof2dot
gprof2dot -f pstats xxx.cprof | dot -Tpng -o xxx.png && feh可视化成果如下:
- 转成 flamegraph
# dependency: flameprof
# pip3 install flameprof
flameprof xxx.cprof > flamegraph.svg更多信息请参考 cProfile 文档: https://docs.python.org/3/lib…
5.3 pyinstrument
pyinstrument 是一个 sampling based profiler，性能上与 cProfile 相似，只反对 Sampling 纯 Python 调用栈，相似地只反对 wall clock time，但 overhead 绝对 cProfile 低一些，且自带多种可视化办法。
官网 repo 地址: https://github.com/joerick/py…
装置:
pip3 install pyinstrument
应用办法:
python3 -m pyinstrument xxx.py
默认输入后果在命令行中，如下:
_ ._ __/__ _ _ _ _ _/_ Recorded: 15:50:07 Samples: 8794
/_//_/// /_\ / //_// / //_'/ // Duration: 23.332 CPU time: 31.381
/ _/ v3.4.1
Program: train.py
23.331 <module> train.py:9
├─ 22.641 main train.py:29
│ └─ 22.631 worker train.py:114
│ ├─ 10.077 item megengine/core/tensor/array_method.py:391
│ │ └─ 10.067 numpy megengine/tensor.py:113
│ │ └─ 10.067 Tensor.numpy <built-in>:0
│ ├─ 8.056 train_step train_random.py:159
│ │ ├─ 5.396 __call__ megengine/module/module.py:120
│ │ │ └─ 5.392 forward model.py:170
│ │ │ └─ 5.348 __call__ megengine/module/module.py:120
│ │ │ └─ 5.239 forward megengine/module/sequential.py:94
│ │ │ └─ 5.198 __call__ megengine/module/module.py:120
│ │ │ └─ 4.838 forward model.py:87
...
也能够输入 html 文件在浏览器里查看下面的后果：
python3 -m pyinstrument \--html xxx.py
成果如下:
5.4 perf
perf 是 Linux 官网的 profiler，能够在 Linux kernel 中找到它的源代码。perf 的性能非常弱小，它同时反对对整个操作系统进行观测，也反对对单个给定的过程进行观测，除此之外 perf 即能够 trace 指定的 event 也反对对过程的调用栈进行 sampling。perf 运行在内核态，其本身的 overhead 非常低。
装置 perf:
sudo apt-get install linux-tools-common linux-tools-generic linux-tools-\uname -r\
perf 的版本须要与 Linux kernel 的版本保持一致，装置命令中的 uname -r 确保了这一点
应用办法:
# 间接运行程序并进行采样，如 python3 xxx.py
perf record -F 99 --call-graph dwarf python3 xxx.py
# 或对给定线程 id(TID)进行采样
perf record -F 99 --call-graph dwarf --tid <TID>
# 其中 -F 99 是采样频率，这里指每秒采样 99 次; 也能够用 --pid 指定采样的过程 id，此时 perf 会对该过程的所有线程进行采样
运行完结后会在以后的目录下产生一个名为 perf.data 的文件
对后果进行可视化:
能够应用 perf 自带的子命令剖析 profiling 后果:
perf report \--stdio -i perf.data
咱们更举荐将其转为火焰图:
# 将 perf.data 转成调用栈
perf script -i perf.data > perf.unfold
# clone FlameGraph
git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
# 假如 perf.unfold 放在了 <result_dir> 里
stackcollapse-perf.pl <result_dir>/perf.unfold > perf.fold
# 能够间接在 speedscope 里关上 perf.fold，或者将其转化为 svg:
# 将 perf.fold 转为 svg 文件
flamegraph.pl perf.fold > perf.svg对 Linux kernel 版本大于等于 5.8 的用户，perf 反对间接将后果转为火焰图:
perf script report flamegraph -i perf.data
对于 Python 程序的优化，perf 也有一些局限性，因为 perf 不是为 python 定制的 profiler，对 python 的函数调用，perf 采样的是 CPython 解释器的调用栈，所以无奈间接看到具体的 Python 函数，如下图所示:
因而 perf 不太适宜优化纯 Python 代码，更适宜观测 C /C++ 线程。此外，下面应用的 perf record 命令只会对程序 CPU time 的调用栈进行采样，如果要对 off-CPU time 进行观测，须要应用 perf 的 trace 命令，这里就不具体开展了，具体做法能够参考这篇文章: http://www.brendangregg.com/b…。目前为止 perf 还不反对同时对 CPU time 和 off-CPU time 进行观测，对这两种状况只能独立进行剖析。
5.5 systemtap
systemtap 是一个操作系统的动静追踪 (dynamic tracing) 工具。它的性能更为弱小，咱们能够简略地将 systemtap 视为一个可编程的零碎级 tracer。systemtap 提供了一个脚本语言，用户能够编写脚本来追踪和监控各种零碎调用、用户态的函数调用等各种自定义事件。因而用户能够依据本人的需要，编写脚本来取得程序运行中的各种须要观测的信息，systemtap 将会用户编写的脚本编译成 c 代码，再编译成内核模块，而后加载到正在运行的操作系统内核中。
本文不打算对 systemtap 进行具体介绍，咱们只关注它在 profiling 方面的利用（对 systemtap 感兴趣的读者能够参考 SystemTap Beginners Guide）此外，本文也不会展现如何编写脚本来实现一个 profiler，openresty 团队提供了一个 systemtap 的工具集 (openresty-systemtap-toolkit) 能够间接拿来应用。
接下来咱们介绍 systemtap 的装置和上述工具集的应用办法:
装置 systemtap:
sudo apt install systemtap systemtap-runtime
除此之外，咱们还须要装置 systemtap 运行时的各种 kernel 依赖：咱们能够间接运行 sudo stap-prep来装置依赖，如果这个命令执行失败，则须要手动装置:
sudo apt install kernel-debuginfo-`uname -r`
sudo apt install kernel-debuginfo-common-`uname -r`
sudo apt install kernel-devel-`uname -r`systemtap 的运行须要 sudo 权限，咱们能够运行上面的命令来检测装置是否胜利:
sudo stap -e \'probe begin {printf(\"Hello, World!\\n\"); exit()}\'
如果能失常输入 Hello World 示意装置胜利。
应用 systemtap:
咱们须要用到 openresty-systemtap-toolkit 提供的两个工具：sample_gt 和 sample_bt_off_cpu，这两个工具别离对程序 cpu time 和 off-cpu time 的调用栈进行采样:
git clone https://github.com/openresty/openresty-systemtap-toolkit.git
cd openresty-systemtap-toolkit
# 对程序 cpu time 的调用栈进行采样, 采样工夫为 10s, 采样对象为 user space 调用栈, 并将后果保留为 cpu.bt
sudo ./sample_bt -u -t 10 -p PID > cpu.bt
# 对程序 off cpu time 的调用栈进行采样，采样工夫为 10s, 采样对象为 user space 调用栈，并将后果保留为 off_cpu.bt
sudo ./sample_bt_off_cpu -u -t 10 -p PID > off_cpu.bt
# 命令中的 - u 选项指采样 user space 调用栈，还能够抉择 - k 来采样 kernel space 的调用栈；- t 指采样工夫，这里都设置为 10s；- p 是待采样程序的 pid
与 perf 相似，systemtap 运行在内核态，overhead 非常低。且对于 python 线程，systemtap 采样的也是 CPython 解释器的调用栈，因而更适宜观测 C /C++ 线程。
对后果进行可视化:
可视化办法与 perf 相似，flamegraph 反对解决 systemtap 的输入后果:
# 解决 cpu.bt 或 off_cpu.bt
stackcollapse-stap.pl <result_dir>/cpu.bt > cpu.fold
# 能够间接在 speedscope 里关上 cpu.fold，或者将其转化为 svg:
# 将 perf.fold 转为 svg 文件
flamegraph.pl cpu.fold > cpu.svg5.6 eu-stack
eu-stack 是 elfutils(https://sourceware.org/elfutils)工具集中的一员，它的根底性能是对一个程序的调用栈进行采样:
eu-stack -p <pid>
#===== 能够失去相似上面的输出:
#0 0x00007f5f96bbadd7 __select
#1 0x00007f5f95868278 call_readline
#2 0x0000000000425182 PyOS_Readline
#3 0x00000000004a84aa tok_nextc.cold.140
#4 0x00000000005a7774 tok_get
#5 0x00000000005a8892 parsetok
#6 0x00000000006351bd PyParser_ASTFromFileObject
#7 0x00000000004ad729 PyRun_InteractiveOneObjectEx
#8 0x00000000004afbfe PyRun_InteractiveLoopFlags
#9 0x0000000000638cb3 PyRun_AnyFileExFlags
#10 0x0000000000639671 Py_Main
#11 0x00000000004b0e40 main
#12 0x00007f5f96ac5bf7 __libc_start_main
#13 0x00000000005b2f0a _start与 perf 和 systemtap 不同的中央是，即便程序处于 off-CPU 的状态，eu-stack 仍然能够取得它的 C /C++ 调用栈。因而咱们能够写一个简略的脚本对一个线程的调用栈一直采样来实现一个 wall clock time 上的 sampling based profiler。
一个简略的 profiler 实现:
#!/bin/bash -xe
pid=$1
for x in $(seq 0 1000)
do
eu-stack -p $pid > d_$x.txt || true
sleep 0.2
doneeu-stack 执行时不须要 root 权限，运行一次的工夫大概几十毫秒，对程序的影响不算太大。
应用办法:
# 1. 装置 elfutils
sudo` `apt ``install` `elfutils# 2. 运行下面的脚本
.``/profiler``.sh <pid>可视化办法:
flamegraph 里也自带了一个解决 eu-stack 输入后果的工具，能够把采集的样本转为 flamegraph，同样也能够在 speedscope 中进行查看：
# 假如采样后果放在了 <result_path> 里
stackcollapse-elfutils.pl <result_path>/d*txt > eu_perf.txt
# 可视化：# 办法 1: use speedscope.app
# 间接在 speedscope.app 里关上 eu_perf.txt 即可
# 办法 2: use flamegraph
flamegraph.pl eu_perf.txt output.svg
# 在浏览器里关上 output.svg六、例子
最初，介绍 MegEngine 开发过程中一个性能优化的实在例子，来展现一个从 profiling 到寻找 bottleneck 再到性能优化的流程。
在 MegEngine 的晚期开发中咱们发现某个检测模型在单机 8 卡数据并行上的训练速度十分慢，一个 step 的运行工夫是单卡的 2 倍多。咱们首先狐疑的是多卡间同步梯度时 All Reduce 的开销带来的影响，为了对此进行确认，咱们将卡间的梯度同步敞开，使每张卡的训练互相独立，发现速度只晋升了一点，8 卡速度仍是单卡的 2 倍左右。
因为 8 卡训练会启动 8 个过程，为了彻底排除 8 个过程之间可能存在的分割带来的烦扰，咱们将 8 卡训练改成启 8 个独立的单卡训练，发现速度简直没有变动。此外咱们还察看到一个 step 的运行工夫与启动的单卡训练的数量成正相干，启 2 个单卡训练时速度只慢了一点，4 个单卡训练慢了 50% 左右。
于是咱们狐疑可能是 8 个过程之间竞争 CPU 资源导致了速度变慢，为了进行确认，咱们对每个过程绑定雷同数量的 cpu 核，即单过程训练和 8 过程训练中每个过程应用的 CPU 数量保持一致，再一次发现速度简直没有变动，因而 8 卡速度慢与 CPU 资源竞争应该没有关系。
简略的猜想没有定位到问题，咱们打算应用 profiler 来查找。MegEngine 的过程能够简化为两个线程: python 主线程和 worker 线程，其中:
- Python 主线程: 执行 python 训练脚本，并且向队列里发送工作
- worker 线程: 是一个纯 C ++ 线程，负责从队列里取工作并且执行
咱们首先对 Python 主线程进行了 profiling，因为心愿能同时观测到 C /C++ extension，纯 Python profiler 无奈满足咱们的需要，因而咱们应用了 py-spy，咱们关上了 –idle 选项来使后果蕴含 off cpu time 上的样本，最终失去了上面的后果:
咱们发现，主线程大概有 80% 的工夫花在了期待上，如上图中的红色框所示。有两个中央是获取一个 tensor 的 numpy ndarray，单个中央是获取一个 tensor 的 shape，这两种状况的期待全部都是 sync worker 线程引发的。MegEngine 中主线程发命令和 worker 执行命令之间是异步进行的，当咱们须要取得一个 tensor 的 numpy ndarray 时，则须要等 worker 在 CUDA 上实现计算并将后果 copy 到 memory 中，因而会触发 sync。另一种状况是取得一个 tensor 的 shape，如果某个算子的输入的 shape 无奈提前揣测进去，也须要等 worker 完称计算能力晓得，因而也会触发 sync。
由此可见主线程的工夫简直都花在了期待 worker 上，阐明 worker 的执行比较慢，真正的问题应该在 worker 线程上。
于是咱们打算对 worker 线程进行 profiling，因为 worker 线程是纯 C /C++ 线程，因而咱们可选的工具有 perf、systemtap 和 eu-stack，咱们不确定问题出在 CPU time 上还是 off-CPU time 上，为了可能将两种状态下的后果放在一起观测，咱们抉择应用 eu-stack，于是取得了以下后果:
咱们发现 worker 线程竟然有 85% 以上的工夫花在了 topk 算子调用 cudaGetDeviceProperties 的中央（图中的红色框），查阅文档后发现这个 api 的 overhead 比拟大，且多过程同时调用时会产生 io traffic 竞争，因而 ioctl 在 8 过程的工夫耗费过大。咱们随后批改了 topk 的实现 (commit)，防止调用 cudaGetDeviceProperties，之后再次测试，发现该模型的速度回复失常：单过程速度晋升了约 13%，8 过程速度晋升了 1 倍以上。
七、参考资料
- 《Systems Performance: Enterprise and the Cloud》
- http://www.brendangregg.com/o…
- http://www.brendangregg.com/f…
- https://iobservable.net/blog/…
- https://blog.openresty.com.cn…
- http://qqibrow.github.io/perf…
- https://www.percona.com/blog/…
欢送小伙伴退出咱们 MegEngine 旷视天元开发者交换 QQ 群：1029741705
框架应用相干交换或反馈，欢送拜访论坛：http://discuss.megengine.org.cn；
GitHub 我的项目地址：http://github.com/MegEngine/M…