Paddle模型效能分析工具Profiler定位瓶頸點優化程式詳解

2023-03-11 06:01:11

Paddle模型效能分析Profiler

定位效能瓶頸點優化程式提升效能

Paddle Profiler是飛槳框架自帶的低開銷效能分析器，可以對模型執行過程的效能資料進行收集、統計和展示。效能分析器提供的資料可以幫助定位模型的瓶頸，識別造成程式執行時間過長或者GPU利用率低的原因，從而尋求優化方案來獲得效能的提升。

1.使用Profiler工具偵錯程式效能

在模型效能分析中，通常採用如下四個步驟：

獲取模型正常執行時的ips(iterations per second，每秒的迭代次數)，給出baseline資料。
開啟效能分析器，定位效能瓶頸點。
優化程式，檢查優化效果。
獲取優化後模型正常執行時的ips，和baseline比較，計算真實的提升幅度。

下面是使用神經網路對cifar10進行分類的範例程式碼，裡面加上了啟動效能分析的程式碼。通過這個比較簡單的範例，來看效能分析工具是如何通過上述四個步驟在偵錯程式效能中發揮作用。

1.1 使用cifar10資料集折積神經網路進行影象分類

import paddle
import paddle.nn.functional as F
from paddle.vision.transforms import ToTensor
import numpy as np
import matplotlib.pyplot as plt
print(paddle.__version__)

載入資料集

cifar10資料集由60000張大小為32 * 32的彩色圖片組成，其中有50000張圖片組成了訓練集，另外10000張圖片組成了測試集。這些圖片分為10個類別，將訓練一個模型能夠把圖片進行正確的分類。

transform = ToTensor()
cifar10_train = paddle.vision.datasets.Cifar10(mode='train',
                                               transform=transform)
cifar10_test = paddle.vision.datasets.Cifar10(mode='test',
                                              transform=transform)

組建網路

接下來使用飛槳定義一個使用了三個二維折積（ Conv2D ) 且每次折積之後使用 relu 啟用函數，兩個二維池化層（ MaxPool2D ），和兩個線性變換層組成的分類網路，來把一個(32, 32, 3)形狀的圖片通過折積神經網路對映為10個輸出，這對應著10個分類的類別

class MyNet(paddle.nn.Layer):
    def __init__(self, num_classes=1):
        super(MyNet, self).__init__()
        self.conv1 = paddle.nn.Conv2D(in_channels=3, out_channels=32, kernel_size=(3, 3))
        self.pool1 = paddle.nn.MaxPool2D(kernel_size=2, stride=2)
        self.conv2 = paddle.nn.Conv2D(in_channels=32, out_channels=64, kernel_size=(3,3))
        self.pool2 = paddle.nn.MaxPool2D(kernel_size=2, stride=2)
        self.conv3 = paddle.nn.Conv2D(in_channels=64, out_channels=64, kernel_size=(3,3))
        self.flatten = paddle.nn.Flatten()
        self.linear1 = paddle.nn.Linear(in_features=1024, out_features=64)
        self.linear2 = paddle.nn.Linear(in_features=64, out_features=num_classes)
    def forward(self, x):
        x = self.conv1(x)
        x = F.relu(x)
        x = self.pool1(x)
        x = self.conv2(x)
        x = F.relu(x)
        x = self.pool2(x)
        x = self.conv3(x)
        x = F.relu(x)
        x = self.flatten(x)
        x = self.linear1(x)
        x = F.relu(x)
        x = self.linear2(x)
        return x

模型訓練&預測

接下來，用一個迴圈來進行模型的訓練，將會:

使用 paddle.optimizer.Adam 優化器來進行優化。

使用 F.cross_entropy 來計算損失值。

使用 paddle.io.DataLoader 來載入資料並組建batch。

import paddle.profiler as profiler
#引數設定
epoch_num = 10
batch_size = 32
learning_rate = 0.001
val_acc_history = []
val_loss_history = []
def train(model):
    print('start training ... ')
    # turn into training mode
    model.train()
    opt = paddle.optimizer.Adam(learning_rate=learning_rate,
                                parameters=model.parameters())
    train_loader = paddle.io.DataLoader(cifar10_train,
                                        shuffle=True,
                                        batch_size=batch_size,
                                        num_workers=4)
    valid_loader = paddle.io.DataLoader(cifar10_test, batch_size=batch_size)
    # 建立效能分析器相關的程式碼
    def my_on_trace_ready(prof):# 定義回撥函數，效能分析器結束採集資料時會被呼叫
        callback = profiler.export_chrome_tracing('./profiler_demo') # 建立匯出效能資料到profiler_demo資料夾的回撥函數
        callback(prof)  # 執行該匯出函數
        prof.summary(sorted_by=profiler.SortedKeys.GPUTotal) # 列印表單，按GPUTotal排序表單項
    p = profiler.Profiler(scheduler = [3,14], on_trace_ready=my_on_trace_ready, timer_only=True) # 初始化Profiler物件
    p.start() # 效能分析器進入第0個step
    for epoch in range(epoch_num):
        for batch_id, data in enumerate(train_loader()):
            x_data = data[0]
            y_data = paddle.to_tensor(data[1])
            y_data = paddle.unsqueeze(y_data, 1)
            logits = model(x_data)
            loss = F.cross_entropy(logits, y_data)
            if batch_id % 1000 == 0:
                print("epoch: {}, batch_id: {}, loss is: {}".format(epoch, batch_id, loss.numpy()))
            loss.backward()
            opt.step()
            opt.clear_grad()
            p.step() # 指示效能分析器進入下一個step
            if batch_id == 19:
                p.stop() # 關閉效能分析器
                exit() # 做效能分析時，可以將程式提前退出
        # evaluate model after one epoch
        model.eval()
        accuracies = []
        losses = []
        for batch_id, data in enumerate(valid_loader()):
            x_data = data[0]
            y_data = paddle.to_tensor(data[1])
            y_data = paddle.unsqueeze(y_data, 1)
            logits = model(x_data)
            loss = F.cross_entropy(logits, y_data)
            acc = paddle.metric.accuracy(logits, y_data)
            accuracies.append(acc.numpy())
            losses.append(loss.numpy())
        avg_acc, avg_loss = np.mean(accuracies), np.mean(losses)
        print("[validation] accuracy/loss: {}/{}".format(avg_acc, avg_loss))
        val_acc_history.append(avg_acc)
        val_loss_history.append(avg_loss)
        model.train()
model = MyNet(num_classes=10)
train(model)

**部分結果展示：**
epoch: 6, batch_id: 0, loss is: [0.91811454]
epoch: 6, batch_id: 1000, loss is: [0.89851004]
[validation] accuracy/loss: 0.7232428193092346/0.8434960246086121
epoch: 7, batch_id: 0, loss is: [0.60690844]
epoch: 7, batch_id: 1000, loss is: [0.6912922]
[validation] accuracy/loss: 0.7049720287322998/0.887704074382782
epoch: 8, batch_id: 0, loss is: [0.6330824]
epoch: 8, batch_id: 1000, loss is: [0.5715592]
[validation] accuracy/loss: 0.7176517844200134/0.8511289954185486
epoch: 9, batch_id: 0, loss is: [0.29487646]
epoch: 9, batch_id: 1000, loss is: [0.9094696]
[validation] accuracy/loss: 0.7097643613815308/0.9166476130485535

1.1.1 獲取效能偵錯前模型正常執行的ips

上述程式在建立Profiler時候，timer_only設定的值為True，此時將只開啟benchmark功能，不開啟效能分析器，程式輸出模型正常執行時的benchmark資訊如下

Reader Ratio：表示資料讀取部分佔訓練batch迭代過程的時間佔比，
reader_cost：代表資料讀取時間，
batch_cost：代表batch迭代的時間，
ips：表示每秒能迭代多少次，即跑多少個batch。

可以看到，此時的ips為70.99，可將這個值作為優化對比的baseline。

 ============================================Perf Summary============================================
 Reader Ratio: 35.240%
 Time Unit: s, IPS Unit: steps/s
|                 |       avg       |       max       |       min       |
 |   reader_cost   |     0.00496     |     0.00542     |     0.00469     |
|    batch_cost   |     0.01408     |     0.01325     |     0.01246     |
 |       ips       |     70.99914    |     80.24470    |     75.46403    |

1.1.2. 開啟效能分析器，定位效能瓶頸點

修改程式，將Profiler的timer_only引數設定為False，此時代表不只開啟benchmark功能，還將開啟效能分析器，進行詳細的效能分析。

p = profiler.Profiler(scheduler = [3,14], on_trace_ready=my_on_trace_ready, timer_only=False)

效能分析器會收集程式在第3到14次（不包括14）訓練迭代過程中的效能資料，並在profiler_demo資料夾中輸出一個json格式的檔案，用於展示程式執行過程的timeline，可通過chrome瀏覽器的chrome://tracing 外掛開啟這個檔案進行檢視。

如圖所示，把json檔案load即可：

效能分析器還會直接在終端列印統計表單（建議重定向到檔案中檢視），檢視程式輸出的Model Summary表單

-----------------------------------------------Model Summary-----------------------------------------------
Time unit: ms
---------------  ------  ----------------------------------------  ----------------------------------------  
Name             Calls   CPU Total / Avg / Max / Min / Ratio(%)    GPU Total / Avg / Max / Min / Ratio(%)    
---------------  ------  ----------------------------------------  ----------------------------------------  
ProfileStep      11      138.99 / 12.64 / 17.91 / 10.65 / 100.00   8.81 / 0.80 / 0.80 / 0.80 / 100.00        
  Dataloader     11      16.88 / 1.53 / 6.91 / 0.09 / 12.14        0.00 / 0.00 / 0.00 / 0.00 / 0.00          
  Forward        11      45.18 / 4.11 / 4.41 / 3.61 / 32.50        2.73 / 0.25 / 0.25 / 0.25 / 31.01         
  Backward       11      27.63 / 2.51 / 2.85 / 2.37 / 19.88        4.04 / 0.37 / 0.37 / 0.36 / 45.81         
  Optimization   11      19.75 / 1.80 / 1.89 / 1.61 / 14.21        1.05 / 0.10 / 0.10 / 0.09 / 11.56         
  Others         -       29.55 / - / - / - / 21.26                 1.05 / - / - / - / 11.63                  
---------------  ------  ----------------------------------------  ----------------------------------------  
Note:
在此表中，GPU 時間是該階段呼叫的所有裝置（GPU）事件的總和。
與概述摘要不同，如果兩個裝置（GPU）事件在不同的流上執行重疊時間，我們直接在這裡求和。

其中ProfileStep表示訓練batch的迭代step過程，對應程式碼中每兩次呼叫p.step()的間隔時間；
Dataloader表示資料讀取的時間，即for batch_id, data in enumerate(train_loader())的執行時間；
Forward表示模型前向的時間，即logits = model(x_data)的執行時間，
Backward表示反向傳播的時間，即loss.backward()的執行時間；
Optimization表示優化器的時間，即opt.step()的執行時間。

通過timeline可以看到，Dataloader佔了執行過程的很大比重，Model Summary顯示其接近了12%。分析程式發現，這是由於模型本身比較簡單，需要的計算量小，再加上Dataloader 準備資料時只用了單程序來讀取，使得程式讀取資料時和執行計算時沒有並行操作，導致Dataloader佔比過大。

1.1.3. 優化程式，檢查優化效果

識別到了問題產生的原因，對程式繼續做如下修改，將Dataloader的num_workers設定為4，使得能有多個程序並行讀取資料。

train_loader = paddle.io.DataLoader(cifar10_train,
                                    shuffle=True,
                                    batch_size=batch_size,
                                    num_workers=4)

重新對程式進行效能分析，新的timeline和Model Summary如下所示

-----------------------------------------------Model Summary-----------------------------------------------
Time unit: ms
---------------  ------  ----------------------------------------  ----------------------------------------  
Name             Calls   CPU Total / Avg / Max / Min / Ratio(%)    GPU Total / Avg / Max / Min / Ratio(%)    
---------------  ------  ----------------------------------------  ----------------------------------------  
ProfileStep      11      89.44 / 8.13 / 8.76 / 7.82 / 100.00       8.82 / 0.80 / 0.80 / 0.80 / 100.00        
  Dataloader     11      1.51 / 0.14 / 0.16 / 0.12 / 1.69          0.00 / 0.00 / 0.00 / 0.00 / 0.00          
  Forward        11      31.67 / 2.88 / 3.17 / 2.82 / 35.41        2.72 / 0.25 / 0.25 / 0.24 / 36.11         
  Backward       11      25.35 / 2.30 / 2.49 / 2.20 / 28.34        4.07 / 0.37 / 0.37 / 0.37 / 42.52         
  Optimization   11      11.67 / 1.06 / 1.16 / 1.01 / 13.04        1.04 / 0.09 / 0.10 / 0.09 / 10.59         
  Others         -       19.25 / - / - / - / 21.52                 1.06 / - / - / - / 10.78                  
---------------  ------  ----------------------------------------  ----------------------------------------

可以看到，從Dataloader中取資料的時間大大減少，從12%變成了平均只佔一個step的1.69%，並且平均一個step所需要的時間也相應減少了從1.53到0.14。

### 1.1.4 獲取優化後模型正常執行的ips，確定真實提升幅度
重新將timer_only設定的值為True，獲取優化後模型正常執行時的benchmark資訊
============================================Perf Summary============================================
Reader Ratio: 1.718%
Time Unit: s, IPS Unit: steps/s
|                 |       avg       |       max       |       min       |
|   reader_cost   |     0.00013     |     0.00015     |     0.00012     |
|    batch_cost   |     0.00728     |     0.00690     |     0.00633     |
|       ips       |    137.30879    |    158.01126    |    144.91796    |

此時從原來的Reader Ratio: 35.240%---->Reader Ratio: 1.718%

ips的值變成了137.3，相比優化前的baseline70.99，模型真實效能提升了193%。

注意點：

由於Profiler開啟的時候，收集效能資料本身也會造成程式效能的開銷，因此正常跑程式時請不要開啟效能分析器，效能分析器只作為偵錯程式效能時使用。

1.如果想獲得程式正常執行時候的 benchmark資訊（如ips），可以像範例一樣將Profiler的timer_only引數設定為True，此時不會進行詳盡的效能資料收集，幾乎不影響程式正常執行的效能，所獲得的benchmark資訊也趨於真實。
2.benchmark資訊計算的資料範圍是從呼叫Profiler的start方法開始，到呼叫stop方法結束這個過程的資料。而Timeline和效能資料的統計表單的資料範圍是所指定的採集區間，如這個例子中的第3到14次迭代，這會導致開啟效能分析器時統計表單和benchmark資訊輸出的值不同（如統計到的Dataloader的時間佔比）。
3.當benchmark統計的範圍和效能分析器統計的範圍不同時，由於benchmark統計的是平均時間，如果benchmark統計的範圍覆蓋了效能分析器開啟的範圍，也覆蓋了關閉效能偵錯時的正常執行的範圍，此時benchmark的值沒有意義，因此開啟效能分析器時請以效能分析器輸出的統計表單為參考，這也是為何上面範例裡在開啟效能分析器時沒貼benchmark資訊的原因。

1.1.5 結果展示

#結果展示
plt.plot(val_acc_history, label = 'validation accuracy')
plt.xlabel('Epoch')
plt.ylabel('Accuracy')
plt.ylim([0.5, 0.8])
plt.legend(loc='lower right')

2 統計表單展示

統計表單負責對採集到的資料(Event)從多個不同的角度進行解讀，也可以理解為對timeline進行一些量化的指標計算。目前提供Device Summary、Overview Summary、Model Summary、Distributed Summary、Operator Summary、Kernel Summary、Memory Manipulation Summary和UserDefined Summary的統計表單，每個表單從不同的角度進行統計計算。每個表單的統計內容簡要敘述如下：

Device Summary

-------------------Device Summary-------------------
------------------------------  --------------------  
Device                          Utilization (%)  
------------------------------  --------------------  
CPU(Process)                    77.13  
CPU(System)                     25.99  
GPU2                            55.50  
------------------------------  --------------------  
Note:
CPU(程序) 利用率 = 當前程序在所有 cpu 核心上的 CPU 時間/經過的時間，因此最大利用率可以達到 100% * cpu 核心數。
CPU（系統）利用率=所有程序在所有cpu核心上的CPU時間（忙碌時間）/（忙碌時間+空閒時間）。
GPU 利用率 = 當前程序 GPU 時間 / 已用時間。
----------------------------------------------------

DeviceSummary提供CPU和GPU的平均利用率資訊。其中

CPU(Process): 指的是程序的cpu平均利用率，算的是從Profiler開始記錄資料到結束這一段過程，程序所利用到的 cpu core的總時間與該段時間的佔比。因此如果是多核的情況，對於程序來說cpu平均利用率是有可能超過100%的，因為同時用到的多個core的時間進行了累加。

CPU(System): 指的是整個系統的cpu平均利用率，算的是從Profiler開始記錄資料到結束這一段過程，整個系統所有程序利用到的cpu core總時間與該段時間乘以cpu core的數量的佔比。可以當成是從cpu的視角來算的利用率。

GPU: 指的是程序的gpu平均利用率，算的是從Profiler開始記錄資料到結束這一段過程，程序在gpu上所呼叫的kernel的執行時間與該段時間的佔比。

Overview Summary

Overview Summary用於展示每種型別的Event一共分別消耗了多少時間，對於多執行緒或多stream下，如果同一型別的Event有重疊的時間段，採取取並集操作，不對重疊的時間進行重複計算。

---------------------------------------------Overview Summary---------------------------------------------
Time unit: ms
-------------------------  -------------------------  -------------------------  -------------------------  
Event Type                 Calls                      CPU Time                   Ratio (%)  
-------------------------  -------------------------  -------------------------  -------------------------  
ProfileStep                8                          4945.15                    100.00  
  CudaRuntime              28336                      2435.63                    49.25  
  UserDefined              486                        2280.54                    46.12  
  Dataloader               8                          1819.15                    36.79  
  Forward                  8                          1282.64                    25.94  
  Operator                 8056                       1244.41                    25.16  
  OperatorInner            21880                      374.18                     7.57  
  Backward                 8                          160.43                     3.24  
  Optimization             8                          102.34                     2.07  
-------------------------  -------------------------  -------------------------  -------------------------  
                          Calls                      GPU Time                   Ratio (%)  
-------------------------  -------------------------  -------------------------  -------------------------  
  Kernel                   13688                      2744.61                    55.50  
  Memcpy                   496                        29.82                      0.60  
  Memset                   104                        0.12                       0.00  
  Communication            784                        257.23                     5.20  
-------------------------  -------------------------  -------------------------  -------------------------  
Note:
在此表中，我們根據事件型別彙總了所有收集到的事件。
在主機上收集的事件時間顯示為 CPU 時間，如果在裝置上則顯示為 GPU 時間。
不同型別的事件可能會重疊或包含，例如 Operator 包括 OperatorInner，因此比率之和不是 100%。
有重疊的同型別事件的時間不會計算兩次，合併後所有時間相加。
Example:
Thread 1:
  Operator: |___________|     |__________|
Thread 2:
  Operator:   |____________|     |___|
After merged:
  Result:   |______________|  |__________|
----------------------------------------------------------------------------------------------------------

不在繼續詳細說明，參考專案即可：

專案連結，fork一下即可使用
aistudio.baidu.com/aistudio/pr…

以上就是Paddle模型效能分析工具Profiler定位瓶頸點優化程式詳解的詳細內容，更多關於Paddle分析工具Profiler的資料請關注it145.com其它相關文章！