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，榮譽證書、定制禮品享不停。

關鍵詞：