深度學習框架火焰圖pprof和CUDA Nsys配置指南

注：如下是在做深度學習框架開發時，用到的火焰圖pprof和 CUDA Nsys 配置指南，可能對大家有一些幫助，就此分享。一些是基於飛槳的Docker映象配置的。

一、環境 & 工具配置

0. 開發機配置

# 1.構建映象, 記得對映埠，可以多對映幾個；記得掛載ssd目錄，因為資料都在ssd盤上
nvidia-docker run -it --name=profile_dev --shm-size 128G --ulimit core=-1 --cap-add ALL -v $PWD:/workspace -v /ssd1:/ssd1 -v /ssd2:/ssd2 -v /ssd3:/ssd3 --net=host -p 9422:22 -p 9423:9423 -p 9424:9424 registry.baidubce.com/paddlepaddle/paddle:latest-dev-cuda11.2-cudnn8-gcc82 /bin/bash

# 2.更新設定，安裝vim
apt update
apt install vim

# 3. 將代理儲存到 ~/.my_profile
# 4.安裝zsh 和 oh_my_zsh
apt install zsh
sh -c "$(curl -fsSL https://raw.github.com/ohmyzsh/ohmyzsh/master/tools/install.sh)"
# 5. 自動初始化個性化設定
vim ~/.zshrc
# 最後一行新增 source ~/.my_profile

# 6. 配置效能最佳化工具
apt install libgoogle-perftools-dev

# 7. 建立全域性python3.7 沙盒
virtualenv env3.7 --python=python3.7
source env3.7/bin/activate

# 8. 配置pprof
rm -rf /usr/local/go
tar -xzf go1.16.4.linux-amd64.tar.gz -C /usr/local
export GOROOT=/usr/local/go
export PATH=/root/gopath/bin:$GOROOT/bin:$PATH
go version
go get github.com/google/pprof

1. NsightSyetem 工具

1.1 前序準備

NsightSystem 是一個集終端 CUDA Profile 日誌生成和 前端視覺化 timeline 分析的強大工具。安裝 nsys 需要分別下載適合Unix 的 Installer 和 Mac/Windows 的視覺化終端。

• Step 1： 註冊 Nvidia 賬號（略）
• Step 2：下載 Linux Installer
  • 下載頁面在 此處
• Step 3：下載桌面客戶端
  • MAC：Nvidia NSight Systems

1.2 安裝過程

首先，在建立 docker 映象時，需要加上 --privileged=true，否則可能無許可權讀取Performance Counter。比如：

• 現在不允許加 --privileged=true 了，只需要加 --cap-add ALL 即可
• doacker 容器命令前文件最前面

然後，在 docker 容器中的命令列下，安裝 nsys：

# step 1: 此處是舊的，推薦大家下載最新的按照包
bash NsightSystems-linux-public-2020.4.1.144-20fdc64.run  

# step 2: 然後 Enter 鍵，並翻頁到最後，鍵入 ACCEPT 接受協議

# step 3: 輸入安裝路徑，或者回車使用預設路徑，完成安裝。
Enter install path: [ default is /opt/nvidia/nsight-systems/2020.4.1 ]:
...
========================================
To uninstall the Nsight Systems 2020.4.1, please delete "/opt/nvidia/nsight-systems/2020.4.1"
Installation Complete

# step 4: 將安裝路徑加入PATH
$ export PATH=/opt/nvidia/nsight-systems/2020.4.1/bin:$PATH
$ which nsys
/opt/nvidia/nsight-systems/2020.4.1/bin/nsys

注：桌面視覺化的客戶端安裝非常簡單，和安裝其他軟體無差別。

1.3 基礎用法

常用命令如下：

nsys profile -w true -t cuda,nvtx,osrt,cudnn,cublas -s cpu --cud -x true python abs.py

"""
–stats=true，表示在收集完資訊後，會在終端輸出本次profiling的統計概要。
-t cuda，用於指定待profiling的 API.可以設定為cublas, cuda, cudnn, nvtx, opengl, openacc, openmp, osrt, mpi, vulkan, none
"""

注：更多用法，可以參考：nsys文件。

命令執行完，會在當前路徑下生成一個 *.qdrep檔案，將其拖入 NSight GUI 工具即可。

2. 火焰圖

2.1 yep 庫

C++的效能分析工具非常多。常見的包括gprof, valgrind, google-perftools。但是除錯Python中使用的動態連結庫與直接除錯原始二進位制相比增加了很多複雜度。幸而Python的一個第三方庫yep提供了方便的和google-perftools互動的方法。於是這裡使用yep進行Python與C++混合程式碼的效能分析。

使用yep前需要安裝google-perftools與yep包。ubuntu下安裝命令為：

apt update
apt install libgoogle-perftools-dev
pip install yep

因為C++與Python不同，編譯時可能會去掉除錯資訊，執行時也可能因為多執行緒產生混亂不可讀的效能分析結果。為了生成更可讀的效能分析結果，可以採取下面幾點措施:

• 編譯時指定-g生成除錯資訊。使用cmake的話，可以將CMAKE_BUILD_TYPE指定為RelWithDebInfo
• 編譯時一定要開啟最佳化。單純的Debug編譯效能會和-O2或者-O3有非常大的差別。Debug模式下的效能測試是沒有意義的
• 執行效能分析的時候，先從單執行緒開始，再開啟多執行緒，進而多機。畢竟單執行緒除錯更容易。可以設定OMP_NUM_THREADS=1這個環境變數關閉openmp最佳化

2.2 pprof 命令

在執行完效能分析後，會生成效能分析結果檔案。我們可以使用pprof來顯示效能分析結果。注意，這裡使用了用Go語言重構後的pprof，因為這個工具具有web服務介面，且展示效果更好。

首先，安裝 GO 環境，以Linux為例：

# step 1: 下載較新的的 GO 安裝檔案
wget https://golang.org/dl/go1.16.4.linux-amd64.tar.gz

# step 2: 刪除系統舊版的 go
rm -rf /usr/local/go

# step 3: 解壓到 /usr/local 目錄
tar -xzf go1.16.4.linux-amd64.tar.gz -C /usr/local

# step 4: 設定環境變數
export GOROOT=/usr/local/go
export PATH=/root/gopath/bin:$GOROOT/bin:$PATH

# step 5: 驗證安裝
go version

然後，安裝 pprof 命令：

go get github.com/google/pprof

2.3 基礎用法

生成日誌檔案：

python -m yep -- model.py --device=GPU ....

可以啟動一個服務，檢視火焰圖：

pprof -http=0.0.0.0:8878 `which python`  ./main.py.prof

二、模型效能分析

1. 日誌生成

1.1 Profiler timeline

對於模型程式碼，需要在訓練的 for 迴圈中，新增如下程式碼：

if iter == 100:
    profiler.start_profiler("All", "OpDetail")
if iter == 110:
    profiler.stop_profiler("total", "./profile")
    return

其中 start_profiler 的 trace_option 建議設定為 “Default“ 或 “OpDetail“ ，取10次迭代資料。

執行完之後，會在終端輸出日誌彙總結果，同時也會生成一個檔案。該檔案的路徑為./profile

執行如下命令，可以生成 timeline 檔案，方便在 chrom 瀏覽器中檢視：

python Paddle/tools/timeline.py --profile_path=./profile --timeline_path=timeline

• 訪問 chrome://tracing/
• 點選 load 按鈕，載入 timeline檔案

1.2 NSight timeline

在模型訓練相關的 for 迴圈中，新增如下程式碼：

• 使用nvprof_start()和core.nvprof_stop()控制profile的開始和結束
• 使用core.nvprof_nvtx_push(）和core.nvprof_nvtx_pop() 新增要統計的特定event。在event開始前push event 的名稱，在event結束後，進行 pop。
• 例如下面程式碼，使用迭代次數作為事件的名稱。

for iter_id, data in enumerate(train_loader):
    if iter_id == 100:
        core.nvprof_start()
        core.nvprof_enable_record_event()
        core.nvprof_nvtx_push(str(iter_id))
    if iter_id == 110:
        core.nvprof_nvtx_pop()
        core.nvprof_stop()
        
    if iter_id > 100 and iter_id < 110:
        core.nvprof_nvtx_pop()
        core.nvprof_nvtx_push(str(iter_id))

執行如下命令生成 timeline 檔案（參考：Paddle 30567）：

nsys profile -o my_report -w true -t cuda,nvtx,osrt,cudnn,cublas -s cpu --capture-range=cudaProfilerApi --stop-on-range-end=true --cudabacktrace=true -x true -o my_profile python train.py

在視覺化客戶端中載入此檔案，效果如下：

2. 效能分析

2.1 如何看profile report

Profile Report中可以重點關注OP的呼叫次數，CPU時間和GPU時間。

• 呼叫次數多的OP，很難從report中確定是否有最佳化空間，需要進一步結合timeline去發現是否有耗時異常的kernel。
  
• 呼叫次數少，但是時間上佔比不低的OP，可能是需要最佳化的
  
• OP的CPU時間遠遠大於GPU時間，可能的原因一般有：
  • 框架執行排程問題，比較難排查，需要透過新增更細緻的event，以及結合timeline去排查
  • OP執行過程中，引入了裝置間的資料複製，在report中會直接列印出來。案例PR25810
    
  • OP的Compute中某部分CPU耗時較多，可以透過在c++端新增event去確認

2.2 如何看timeline

2.2.1 認識模型的timeline構成

timeline展示了模型訓練過程中各個事件在時間軸上情況，模型訓練時每一個step經歷的階段都是具有規律的，比如下圖中的動態圖模型timeline大致具有以下階段：

資料讀取 →前向計算→反向計算→optimizer引數更新→ClearGradient

我們可以根據需要，透過nvprof_nvtx_push為一個step的不同階段打上標記。

模型分析時，我們要關注timeline的哪些資訊呢？

圖中藍色的矩形塊顯示了CUDA Kernel的執行，下面是CPU執行，左側展示出了Kernel的GPU時間佔比，可以結合這3部分確定模型的效能瓶頸。

2.2.2 timeline常見的問題表現

timeline的表現可能有以下4種：下圖中上面一行表示CPU執行，下面一行表示GPU執行

• 理想場景：CPU和GPU資源都被充分利用
• 問題場景1：CPU計算較快，GPU事件較高，透過最佳化CUDA Kernel縮短GPU時間，就縮短了一次迭代的耗時
• 問題場景2：CPU計算較慢，GPU出現等待，timeline上會發現GPU Kernel之間有大段空白
• 問題場景3：存在wait，比如上文中提到的裝置間的資料複製等，需要等待GPU執行完，CPU才能開始執行

模型中可能是多種問題的混合。

2.3 如何發現效能瓶頸

前面提到的Profile Report可以給我們相對宏觀的統計資訊，要定位具體的效能瓶頸，常常還需要結合timeline的表現。通常可以按照以下技巧：

• 確認reader耗時的佔比：兩個step之間的間隔如果較大， 可能是reader的耗時比較大。Paddle使用DataLoader載入資料，該API的num_workers>0時，使用多程序方式非同步載入資料。如果發現兩個step間隔較大，可嘗試調大這個引數。
• 檢視佔比高的Kernel，如果耗時異常，這類kernel需要最佳化：
  • 佔比高，耗時異常：下圖中drad2d_grouped_direct_kernel佔比高達62.6%，實際上這是conv_grad中呼叫的cuDNN的kernel。conv在CV模型中呼叫次數非常高，我們透過對比會發現這個kernel的執行時間遠遠高於其他conv_grad。
    
  • 佔比高，耗時無明顯異常，：batch_norm佔比排第3，但是如果放大timeline去看，其實kernel的耗時並沒有特別異常的。
    
• 有些Kernel在特定的API配置下計算很慢，需要最佳化：例如下圖中，佔比7.6%的kernel，1個step呼叫了3次，但是其中最後一次耗時16 ms，而另外2個大概是幾百us。這意味著，如果找出這個耗時異常的配置，對Kernel進行最佳化，模型的效能就會有比較明顯的提升。
  
• 不要忽略單個佔比並不高的kernel：下圖中有兩個佔比分別為1.4%的kernel。結合右側timeline，會發現這2個kernel在1個step中都分別呼叫了1次，是在softmax_with_cross_entropy op裡呼叫的，這個OP的GPU時間需要將這些kernel統計進去。
  
• timeline上的空白：如果空白佔比非常高，最佳化後會有比較明顯的收益。
  • 靜態圖模型：如果kernel之間有較大空白，一般可以認為是框架開銷。在一個GPU Kernel執行之前，框架會完成記憶體分配、組建ExecutionContext，InferShape，prepare data（可能存在裝置間的資料複製），launch kernel。這些都是CPU時間，如果這段時間較長，那當前的這個kernel和上一個GPU Kernel之間可能就存在空白。
  • 動態圖模型：還會受python端code的影響，當發現timeline上存在空白，需要結合python code去排查。
  • 一個例子：下圖是一個動態圖的timeline，最下面是CPU事件，可以看到記錄的OP和OP之間都有空白，比如空白標記2。由於我們的profile是從c++端op run開始標記，在2個OP run之間，python端的開銷，或者框架上其他的開銷，都未被記錄在timeline上。框架開銷通常也比較難最佳化，但可以透過簡單的方法排查是否有相對異常的？如果瀏覽timeline，發現CPU執行的部分，某個空白遠大於其他的空白，可以優先排查下是不是python API的code造成了較大開銷。對於空白1，它發生在conv2d這個OP中的2個GPU Kernel之間，如果要確認，可以優先在OP的compute中，新增一些event去看看哪段程式碼造成了這段空白。
    

2.4 其他問題

• 如何評估一個最佳化點的效能收益

  • 確定一個step的平均時間，通常可以看模型的log中的batch_cost
  • 確定這項最佳化工作預期能將開銷降低到多少，比如最佳化OP時我們可以透過對比競品，大概知道這個OP的耗時能降低多少，估計出最佳化後的batch_cost，算出效能收益

• 當timeline上發現某個kernel耗時嚴重，如何確認它的配置是什麼？

  • 收集模型中該OP的所有配置，用op-benchmark跑一遍，找出耗時異常的OP。但收集過程會相對麻煩，目前動態圖只能透過列印log。
  • 透過timeline分析OP在模型中的大概位置，然後結合模型的結構圖，或者python程式碼，定位到這個配置。【舉個例子 pool2d】

• 有一些OP佔比高，就只能透過最佳化CUDA Kernel嗎？

  • 不一定，例如混合精度訓練中，常常出現，某個OP不支援float16型別，導致頻繁的cast。假設OP2支援float32型別計算，其他OP都是float16算，那麼混合精度訓練中，將會像下面第2行類似，插入了較多的cast。
  • 明確原因後，我們可以對OP2支援float16型別，那麼就能去除掉這些cast。

  OP1 -> OP2 -> OP3 -> OP4 -> OP2 -> OP5OP1 -> cast_to_float32 -> OP2 -> cast_to_float16 -> OP3 -> OP4 -> cast_to_float32 -> OP2 ->  cast_to_float16 -> OP5
  

• 競品Torch的profile教程
  • 執行命令：nsys profile -w true -t cuda,nvtx,osrt,cudnn,cublas -s cpu --capture-range=cudaProfilerApi --**stop**-**on**-range-**end**=true --cudabacktrace=true -x true -o my_profile python main.py