乐趣区

关于开源:MegEngine-使用小技巧Profiler使用手册

jiezi

0. 写在后面

“xx，R 那边反馈多机训练速度慢，你看一下什么状况”

“xxx，为什么 MGE 更新之后，xxx 网络训练变慢了，你看一下”

这是组内日常对话

而后有人日常背锅

组员的状态是：提性能，提性能，还是 TMD 提性能

据不齐全统计，有 80% 的性能问题其实是因为训练代码写的不够好，让 MGE 无力使不进去

包含但不限于以下状况

1）没开 fast_run

2）频繁应用 numpy 进行同步

3）没有用 make_allreduce_cb，让计算通信串行

4）。。。

次数多了，就发现这玩意太花工夫了，而且每次的步骤都千篇一律，为啥肯定要我来做，所以写这篇文章进行总结，不便大家也不便本人

1.Profiler 介绍

首先咱们要意识 Profiler 这个货色

简略来说，Profiler 以时间轴的模式记录了所有算子的运行工夫

通过 Profile 后果，咱们能够很快的发现这段代码为什么跑的慢

是做了多余的工作？还是计算资源的节约？或者是算子自身的性能很差，须要替换成别的算子

这是一个简略的 profile 后果展现

大部分状况下咱们只关注 gpu thread，每一个 gpu thread 对应一个 cuda stream，下面都是运行在这个 cuda stream 上的算子

2. 应用形式

PS：动态图的统计信息还不够欠缺（受到图优化影响），profile 后果绝对动态图的不够敌对 

from megengine.utils.profiler import profile, Profiler
 
# 装璜器写法
@profile()
def train_step(data, label, *, optimizer, gm, model)
    with gm:
        logits = model(data)
        loss = F.loss.cross_entropy(logits, label)
        gm.backward(loss)
        optimizer.step().clear_grad()
    return loss
 
# with 写法
# 训练过程中最好只有一个 profiler 实例，因为 profiler 会在析构时主动 dump 出后果，如果有多个实例的话每个 iter 都会 dump，十分慢
profiler = Profiler()
 
def train_step(data, label, *, optimizer, gm, model)
    with profiler:
       with gm:
           logits = model(data)
           loss = F.loss.cross_entropy(logits, label)
           gm.backward(loss)
           optimizer.step().clear_grad()
    return loss

⚠️留神，profiler 默认会在析构的时候导出 profile 后果，也能够手动调用 profiler.dump 办法手动 dump

参数阐明：

Profiler 的构造函数反对如下参数：

  • path:  profile 数据的存储门路，默认为以后门路下的 profile 文件夹.
  • format: 输入数据的格局，默认为 chrome_timeline.json，是 Chrome 反对的一种规范格局，以工夫线的模式展示 profiling 后果. 可选项还有 有 memory_flow.svg，以工夫 x 地址空间的模式展现内存应用状况.
  • formats:  若须要的输入格局不止一种，能够在 formats 参数里列出.
  • sample_rate:  若该项不为零，则每隔 n 个 op 会统计一次显存信息，剖析数据时能够绘制显存占用曲线，默认为 0.
  • profile_device:  是否记录 gpu 耗时，默认为 True.
  • with_scopes:  是否额定记录 functional/ tensor method 等 python API 对应的 scope，默认为 False. 

  • with_backtrace: 是否记录 op/event 对应的 python 调用栈，默认为 False，开启会使记录数据文件体积变大.

    scope 应用介绍

咱们会主动在 module 的 forward 还有 backward 以及 step 步骤中退出 scope，scope 会在 host thread 上显示，能看出 op 属于哪一个 module 的什么阶段

也能够本人加上 scope

from megengine.utils.profiler import Profiler, scope
 
def main()
    with Profiler():
        x = Tensor(1)
        with scope("Add"):
            y = x+1
        with scope("Mul"):
            z = x*3

默认状况下 profiler 只会记录 module forward，backward，step 三类 scope，用户能够在结构 Profiler 对象时传入参数 with_scopes = True 额定记录 functional，tensor method 等 api 调用对应的 scope。

开启 with_scopes 选项后额定记录了 BatchNorm2d Module 外部调用的 functional / tensor method API 调用 scope

开启 with_scopes 选项后额定记录了 backward scope，该 scope 用于记录反向计算序列对应的前向算子，可用于查找反向计算中有性能问题的算子是由哪种算子前向计算产生。下图 scope 示意 Broadcast，SetSubtensor 等算子是由 Subtensor 反向计算产生的。

3. 可视化显示

举荐应用 perfetto 查看 profile 后果，也能够用 Chrome 开发者模式（F12）的 Performance 模块查看 timeline 格式文件，也能够用 [chrome://tracing/]() 进行查看

以下介绍的都是基于 perfetto 的操作形式

1）统计

能够选中一段间断的时间段，查看这一个时间段的统计后果

下方会显示事件统计后果，能够看到事件理论占用工夫（Wall duration）（能够联合总工夫算出闲暇工夫），能够依照总占用工夫排序，也能够依照均匀工夫排序

2）依赖关系

在 host thread 上，op 会记录对应的 input 和 output 以及相应的依赖关系，能够根据箭头找到 input 依赖的上一个 op，也能够通过下方 flow event 点击挪动到上一个或者下一个

咱们还能找到 op 对应的 host 工夫和 gpu 工夫，点击 op 能够看到在不同 thread（cpu，gpu）占用的工夫

3）查看显存应用，gpu 利用率等指标

profiler 除了记录时间算子执行工夫外，还会记录一些与显存和性能相干的指标。gpu_usage_ratio 记录程序执行均匀的 gpu 利用率（gpu 执行 kernel 工夫占总工夫的比例），gpu_usage_ratio 低阐明程序 host 侧是瓶颈。gpux:x alloc_mem_value 记录了 gpux 显存使用量随工夫的变动的曲线，须要把 sample_rate 设置为大于 0 的整数（sampe rate 代表每隔 n 个 op 记录一次显存使用量）

4）放大放大

能够拖动上方时间轴的起始和完结点来批改起始点和完结点，也能够通过放大放大手势进行放大放大

两头竖线下面的灰色小方块就是能够拖动的点

4. 常见调试技巧（附应用例子

1）多余计算

yolox 例子，forward，backward，step 运行实现了，然而前面多出了很多的 reshape 操作（个别认为 reshape 无理论计算，所以根本看作是节约

找到起因后后果如下（5s->1.3s）

2）计算通信串行（请认准 make_allreduce_cb)

allreduce 通信在 gpu0:1，如果发现通信在 gpu0:0 那就是用错了

3）host 性能慢，gpu 利用率不高

cpu 工夫和 gpu 工夫基本上统一，很可疑

放大认真看，gpu 运行工夫中有很多空隙，而且点击对应 op 查看依赖关系，能够看出两头的空隙工夫是在期待 host 进行 launch cuda kernel

4）应用  backtrace 记录性能查找性能瓶颈局部对应源码

上述示例介绍了如何从 profile 后果中发现性能异样的局部，profiler 提供了 backtrace 调用栈记录性能，不便用户找到异样局部对应的训练代码源码。backtrace 记录会记录算子的 dispatch/kernel 执行，TensorWaitProperty 等事件对应的 python 调用栈。

能够在结构 Profiler 对象时通过传入 with_backtrace = True 开启调用栈记录性能。开启该选项后 profiler 保留数据文件体积会增大。

用户能够在 perfetto UI 界面上点击 op 查看其对应的源码。

下图 profiler 后果中 CompiledOp[IOU] 算子执行工夫较长，通过记录的 backtrace 能够发现该算子是检测模型计算 loss 局部调用的。

下图中 interpreter 线程中某个 TensorWaitProp 占用工夫很长，可能会拖慢 host 执行速度，导致 gpu 闲暇。

（TensorWaitProp 可能是由 tensor.shape, tensor.numpy() 等办法调用产生的，会让 host 侧期待 device 执行，以获取 Tensor 的 value 或 shape 属性）

通过调用栈能够发现该事件是由 basedet 检测模型 get_ground_truth 办法中的某个 getitem 产生的（__getitem__中应用了 tensor shape 属性触发了 host 侧的 sync）。

附

更多 MegEngine 信息获取，您能够：查看文档和 GitHub 我的项目，或退出 MegEngine 用户交换 QQ 群：1029741705。欢送参加 MegEngine 社区奉献，成为 Awesome MegEngineer，荣誉证书、定制礼品享不停。

退出移动版