項(xiàng)目鏈接，fork一下即可使用 https://aistudio.baidu.com/aistudio/projectdetail/4482932?contributionType=1

Paddle模型性能分析Profiler：定位性能瓶頸點(diǎn)優(yōu)化程序提升性能

Paddle Profiler是飛槳框架自帶的低開(kāi)銷性能分析器，可以對(duì)模型運(yùn)行過(guò)程的性能數(shù)據(jù)進(jìn)行收集、統(tǒng)計(jì)和展示。性能分析器提供的數(shù)據(jù)可以幫助定位模型的瓶頸，識(shí)別造成程序運(yùn)行時(shí)間過(guò)長(zhǎng)或者GPU利用率低的原因，從而尋求優(yōu)化方案來(lái)獲得性能的提升。

1.使用Profiler工具調(diào)試程序性能

在模型性能分析中，通常采用如下四個(gè)步驟：

• 獲取模型正常運(yùn)行時(shí)的ips(iterations per second， 每秒的迭代次數(shù))，給出baseline數(shù)據(jù)。
• 開(kāi)啟性能分析器，定位性能瓶頸點(diǎn)。
• 優(yōu)化程序，檢查優(yōu)化效果。
• 獲取優(yōu)化后模型正常運(yùn)行時(shí)的ips，和baseline比較，計(jì)算真實(shí)的提升幅度。

下面是使用神經(jīng)網(wǎng)絡(luò)對(duì)cifar10進(jìn)行分類的示例代碼，里面加上了啟動(dòng)性能分析的代碼。通過(guò)這個(gè)比較簡(jiǎn)單的示例，來(lái)看性能分析工具是如何通過(guò)上述四個(gè)步驟在調(diào)試程序性能中發(fā)揮作用。

1.1 使用cifar10數(shù)據(jù)集卷積神經(jīng)網(wǎng)絡(luò)進(jìn)行圖像分類

import paddleimport paddle.nn.functional as Ffrom paddle.vision.transforms import ToTensorimport numpy as npimport matplotlib.pyplot as pltprint(paddle.__version__)

加載數(shù)據(jù)集

cifar10數(shù)據(jù)集由60000張大小為32 * 32的彩色圖片組成，其中有50000張圖片組成了訓(xùn)練集，另外10000張圖片組成了測(cè)試集。這些圖片分為10個(gè)類別，將訓(xùn)練一個(gè)模型能夠把圖片進(jìn)行正確的分類。

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

組建網(wǎng)絡(luò)

接下來(lái)使用飛槳定義一個(gè)使用了三個(gè)二維卷積（ Conv2D ) 且每次卷積之后使用 relu 激活函數(shù)，兩個(gè)二維池化層（ MaxPool2D ），和兩個(gè)線性變換層組成的分類網(wǎng)絡(luò)，來(lái)把一個(gè)(32, 32, 3)形狀的圖片通過(guò)卷積神經(jīng)網(wǎng)絡(luò)映射為10個(gè)輸出，這對(duì)應(yīng)著10個(gè)分類的類別

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

模型訓(xùn)練&預(yù)測(cè)

接下來(lái)，用一個(gè)循環(huán)來(lái)進(jìn)行模型的訓(xùn)練，將會(huì):

使用 paddle.optimizer.Adam 優(yōu)化器來(lái)進(jìn)行優(yōu)化。

使用 F.cross_entropy 來(lái)計(jì)算損失值。

使用 paddle.io.DataLoader 來(lái)加載數(shù)據(jù)并組建batch。

import paddle.profiler as profiler#參數(shù)設(shè)置epoch_num = 10batch_size = 32learning_rate = 0.001val_acc_history = []val_loss_history = []def train(model):print(‘start training … ‘)# turn into training modemodel.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)# 創(chuàng)建性能分析器相關(guān)的代碼def my_on_trace_ready(prof):# 定義回調(diào)函數(shù)，性能分析器結(jié)束采集數(shù)據(jù)時(shí)會(huì)被調(diào)用callback = profiler.export_chrome_tracing(‘./profiler_demo’) # 創(chuàng)建導(dǎo)出性能數(shù)據(jù)到profiler_demo文件夾的回調(diào)函數(shù)callback(prof)# 執(zhí)行該導(dǎo)出函數(shù)prof.summary(sorted_by=profiler.SortedKeys.GPUTotal) # 打印表單，按GPUTotal排序表單項(xiàng)p = profiler.Profiler(scheduler = [3,14], on_trace_ready=my_on_trace_ready, timer_only=True) # 初始化Profiler對(duì)象p.start() # 性能分析器進(jìn)入第0個(gè)stepfor 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() # 指示性能分析器進(jìn)入下一個(gè)stepif batch_id == 19:p.stop() # 關(guān)閉性能分析器exit() # 做性能分析時(shí)，可以將程序提前退出# evaluate model after one epochmodel.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)**部分結(jié)果展示：**epoch: 6, batch_id: 0, loss is: [0.91811454]epoch: 6, batch_id: 1000, loss is: [0.89851004][validation] accuracy/loss: 0.7232428193092346/0.8434960246086121epoch: 7, batch_id: 0, loss is: [0.60690844]epoch: 7, batch_id: 1000, loss is: [0.6912922][validation] accuracy/loss: 0.7049720287322998/0.887704074382782epoch: 8, batch_id: 0, loss is: [0.6330824]epoch: 8, batch_id: 1000, loss is: [0.5715592][validation] accuracy/loss: 0.7176517844200134/0.8511289954185486epoch: 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 獲取性能調(diào)試前模型正常運(yùn)行的ips

上述程序在創(chuàng)建Profiler時(shí)候，timer_only設(shè)置的值為True，此時(shí)將只開(kāi)啟benchmark功能，不開(kāi)啟性能分析器，程序輸出模型正常運(yùn)行時(shí)的benchmark信息如下

• Reader Ratio：表示數(shù)據(jù)讀取部分占訓(xùn)練batch迭代過(guò)程的時(shí)間占比，
• reader_cost：代表數(shù)據(jù)讀取時(shí)間，
• batch_cost：代表batch迭代的時(shí)間，
• ips：表示每秒能迭代多少次，即跑多少個(gè)batch。

可以看到，此時(shí)的ips為70.99，可將這個(gè)值作為優(yōu)化對(duì)比的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. 開(kāi)啟性能分析器，定位性能瓶頸點(diǎn)

修改程序，將Profiler的timer_only參數(shù)設(shè)置為False， 此時(shí)代表不只開(kāi)啟benchmark功能，還將開(kāi)啟性能分析器，進(jìn)行詳細(xì)的性能分析。

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

性能分析器會(huì)收集程序在第3到14次（不包括14）訓(xùn)練迭代過(guò)程中的性能數(shù)據(jù)，并在profiler_demo文件夾中輸出一個(gè)json格式的文件，用于展示程序執(zhí)行過(guò)程的timeline，可通過(guò)chrome瀏覽器的chrome://tracing 插件打開(kāi)這個(gè)文件進(jìn)行查看。

如圖所示，把json文件load即可：

性能分析器還會(huì)直接在終端打印統(tǒng)計(jì)表單（建議重定向到文件中查看），查看程序輸出的Model Summary表單

———————————————–Model Summary———————————————–Time unit: ms—————————————————————————————————–Name Calls CPU Total / Avg / Max / Min / Ratio(%)GPU Total / Avg / Max / Min / Ratio(%)—————————————————————————————————–ProfileStep11138.99 / 12.64 / 17.91 / 10.65 / 100.00 8.81 / 0.80 / 0.80 / 0.80 / 100.00Dataloader 1116.88 / 1.53 / 6.91 / 0.09 / 12.140.00 / 0.00 / 0.00 / 0.00 / 0.00Forward1145.18 / 4.11 / 4.41 / 3.61 / 32.502.73 / 0.25 / 0.25 / 0.25 / 31.01 Backward 1127.63 / 2.51 / 2.85 / 2.37 / 19.884.04 / 0.37 / 0.37 / 0.36 / 45.81 Optimization 1119.75 / 1.80 / 1.89 / 1.61 / 14.211.05 / 0.10 / 0.10 / 0.09 / 11.56 Others – 29.55 / – / – / – / 21.26 1.05 / – / – / – / 11.63—————————————————————————————————–Note:在此表中，GPU 時(shí)間是該階段調(diào)用的所有設(shè)備（GPU）事件的總和。與概述摘要不同，如果兩個(gè)設(shè)備（GPU）事件在不同的流上執(zhí)行重疊時(shí)間，我們直接在這里求和。

• 其中ProfileStep表示訓(xùn)練batch的迭代step過(guò)程，對(duì)應(yīng)代碼中每?jī)纱握{(diào)用p.step()的間隔時(shí)間；
• Dataloader表示數(shù)據(jù)讀取的時(shí)間，即for batchid, data in enumerate(trainloader())的執(zhí)行時(shí)間；
• Forward表示模型前向的時(shí)間，即logits = model(x_data)的執(zhí)行時(shí)間，
• Backward表示反向傳播的時(shí)間，即loss.backward()的執(zhí)行時(shí)間；
• Optimization表示優(yōu)化器的時(shí)間，即opt.step()的執(zhí)行時(shí)間。

通過(guò)timeline可以看到，Dataloader占了執(zhí)行過(guò)程的很大比重，Model Summary顯示其接近了12%。分析程序發(fā)現(xiàn)，這是由于模型本身比較簡(jiǎn)單，需要的計(jì)算量小，再加上Dataloader 準(zhǔn)備數(shù)據(jù)時(shí)只用了單進(jìn)程來(lái)讀取，使得程序讀取數(shù)據(jù)時(shí)和執(zhí)行計(jì)算時(shí)沒(méi)有并行操作，導(dǎo)致Dataloader占比過(guò)大。

1.1.3. 優(yōu)化程序，檢查優(yōu)化效果

識(shí)別到了問(wèn)題產(chǎn)生的原因，對(duì)程序繼續(xù)做如下修改，將Dataloader的num_workers設(shè)置為4，使得能有多個(gè)進(jìn)程并行讀取數(shù)據(jù)。

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

重新對(duì)程序進(jìn)行性能分析，新的timeline和Model Summary如下所示

———————————————–Model Summary———————————————–Time unit: ms—————————————————————————————————–Name Calls CPU Total / Avg / Max / Min / Ratio(%)GPU Total / Avg / Max / Min / Ratio(%)—————————————————————————————————–ProfileStep1189.44 / 8.13 / 8.76 / 7.82 / 100.00 8.82 / 0.80 / 0.80 / 0.80 / 100.00Dataloader 111.51 / 0.14 / 0.16 / 0.12 / 1.690.00 / 0.00 / 0.00 / 0.00 / 0.00Forward1131.67 / 2.88 / 3.17 / 2.82 / 35.412.72 / 0.25 / 0.25 / 0.24 / 36.11 Backward 1125.35 / 2.30 / 2.49 / 2.20 / 28.344.07 / 0.37 / 0.37 / 0.37 / 42.52 Optimization 1111.67 / 1.06 / 1.16 / 1.01 / 13.041.04 / 0.09 / 0.10 / 0.09 / 10.59 Others – 19.25 / – / – / – / 21.52 1.06 / – / – / – / 10.78—————————————————————————————————–

可以看到，從Dataloader中取數(shù)據(jù)的時(shí)間大大減少，從12%變成了平均只占一個(gè)step的1.69%，并且平均一個(gè)step所需要的時(shí)間也相應(yīng)減少了從1.53到0.14。

### 1.1.4 獲取優(yōu)化后模型正常運(yùn)行的ips，確定真實(shí)提升幅度重新將timer_only設(shè)置的值為True，獲取優(yōu)化后模型正常運(yùn)行時(shí)的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|

此時(shí)從原來(lái)的Reader Ratio: 35.240%—->Reader Ratio: 1.718%

ips的值變成了137.3，相比優(yōu)化前的baseline70.99，模型真實(shí)性能提升了193%。

注意點(diǎn)：

由于Profiler開(kāi)啟的時(shí)候，收集性能數(shù)據(jù)本身也會(huì)造成程序性能的開(kāi)銷，因此正常跑程序時(shí)請(qǐng)不要開(kāi)啟性能分析器，性能分析器只作為調(diào)試程序性能時(shí)使用。

• 1.如果想獲得程序正常運(yùn)行時(shí)候的 benchmark信息（如ips），可以像示例一樣將Profiler的timer_only參數(shù)設(shè)置為True，此時(shí)不會(huì)進(jìn)行詳盡的性能數(shù)據(jù)收集，幾乎不影響程序正常運(yùn)行的性能，所獲得的benchmark信息也趨于真實(shí)。
• 2.benchmark信息計(jì)算的數(shù)據(jù)范圍是從調(diào)用Profiler的start方法開(kāi)始，到調(diào)用stop方法結(jié)束這個(gè)過(guò)程的數(shù)據(jù)。而Timeline和性能數(shù)據(jù)的統(tǒng)計(jì)表單的數(shù)據(jù)范圍是所指定的采集區(qū)間，如這個(gè)例子中的第3到14次迭代，這會(huì)導(dǎo)致開(kāi)啟性能分析器時(shí)統(tǒng)計(jì)表單和benchmark信息輸出的值不同（如統(tǒng)計(jì)到的Dataloader的時(shí)間占比）。
• 3.當(dāng)benchmark統(tǒng)計(jì)的范圍和性能分析器統(tǒng)計(jì)的范圍不同時(shí)， 由于benchmark統(tǒng)計(jì)的是平均時(shí)間，如果benchmark統(tǒng)計(jì)的范圍覆蓋了性能分析器開(kāi)啟的范圍，也覆蓋了關(guān)閉性能調(diào)試時(shí)的正常執(zhí)行的范圍，此時(shí)benchmark的值沒(méi)有意義，因此開(kāi)啟性能分析器時(shí)請(qǐng)以性能分析器輸出的統(tǒng)計(jì)表單為參考，這也是為何上面示例里在開(kāi)啟性能分析器時(shí)沒(méi)貼benchmark信息的原因。

1.1.5 結(jié)果展示

#結(jié)果展示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.2 統(tǒng)計(jì)表單展示

統(tǒng)計(jì)表單負(fù)責(zé)對(duì)采集到的數(shù)據(jù)(Event)從多個(gè)不同的角度進(jìn)行解讀，也可以理解為對(duì)timeline進(jìn)行一些量化的指標(biāo)計(jì)算。 目前提供Device Summary、Overview Summary、Model Summary、Distributed Summary、Operator Summary、Kernel Summary、Memory Manipulation Summary和UserDefined Summary的統(tǒng)計(jì)表單，每個(gè)表單從不同的角度進(jìn)行統(tǒng)計(jì)計(jì)算。每個(gè)表單的統(tǒng)計(jì)內(nèi)容簡(jiǎn)要敘述如下：

Device Summary

——————-Device Summary———————————————————————DeviceUtilization (%)————————————————–CPU(Process)77.13CPU(System) 25.99GPU255.50————————————————–Note:CPU(進(jìn)程) 利用率 = 當(dāng)前進(jìn)程在所有 cpu 內(nèi)核上的 CPU 時(shí)間/經(jīng)過(guò)的時(shí)間，因此最大利用率可以達(dá)到 100% * cpu 內(nèi)核數(shù)。CPU（系統(tǒng)）利用率=所有進(jìn)程在所有cpu內(nèi)核上的CPU時(shí)間（忙碌時(shí)間）/（忙碌時(shí)間+空閑時(shí)間）。GPU 利用率 = 當(dāng)前進(jìn)程 GPU 時(shí)間 / 已用時(shí)間。—————————————————-

DeviceSummary提供CPU和GPU的平均利用率信息。其中

CPU(Process): 指的是進(jìn)程的cpu平均利用率，算的是從Profiler開(kāi)始記錄數(shù)據(jù)到結(jié)束這一段過(guò)程，進(jìn)程所利用到的 cpu core的總時(shí)間與該段時(shí)間的占比。因此如果是多核的情況，對(duì)于進(jìn)程來(lái)說(shuō)cpu平均利用率是有可能超過(guò)100%的，因?yàn)橥瑫r(shí)用到的多個(gè)core的時(shí)間進(jìn)行了累加。

CPU(System): 指的是整個(gè)系統(tǒng)的cpu平均利用率，算的是從Profiler開(kāi)始記錄數(shù)據(jù)到結(jié)束這一段過(guò)程，整個(gè)系統(tǒng)所有進(jìn)程利用到的cpu core總時(shí)間與該段時(shí)間乘以cpu core的數(shù)量的占比?？梢援?dāng)成是從cpu的視角來(lái)算的利用率。

GPU: 指的是進(jìn)程的gpu平均利用率，算的是從Profiler開(kāi)始記錄數(shù)據(jù)到結(jié)束這一段過(guò)程，進(jìn)程在gpu上所調(diào)用的kernel的執(zhí)行時(shí)間 與 該段時(shí)間 的占比。

Overview Summary

Overview Summary用于展示每種類型的Event一共分別消耗了多少時(shí)間，對(duì)于多線程或多stream下，如果同一類型的Event有重疊的時(shí)間段，采取取并集操作，不對(duì)重疊的時(shí)間進(jìn)行重復(fù)計(jì)算。

———————————————Overview Summary———————————————Time unit: ms—————————————————————————————————-Event Type CallsCPU Time Ratio (%)—————————————————————————————————-ProfileStep84945.15100.00CudaRuntime283362435.6349.25UserDefined4862280.5446.12Dataloader 81819.1536.79Forward81282.6425.94Operator 8056 1244.4125.16OperatorInner21880374.18 7.57Backward 8160.43 3.24Optimization 8102.34 2.07—————————————————————————————————-CallsGPU Time Ratio (%)—————————————————————————————————-Kernel 136882744.6155.50Memcpy 49629.820.60Memset 1040.12 0.00Communication784257.23 5.20—————————————————————————————————-Note:在此表中，我們根據(jù)事件類型匯總了所有收集到的事件。在主機(jī)上收集的事件時(shí)間顯示為 CPU 時(shí)間，如果在設(shè)備上則顯示為 GPU 時(shí)間。不同類型的事件可能會(huì)重疊或包含，例如 Operator 包括 OperatorInner，因此比率之和不是 100%。有重疊的同類型事件的時(shí)間不會(huì)計(jì)算兩次，合并后所有時(shí)間相加。Example:Thread 1:Operator: |___________| |__________|Thread 2:Operator: |____________| |___|After merged:Result: |______________||__________|———————————————————————————————————-

不在繼續(xù)詳細(xì)說(shuō)明，參考項(xiàng)目即可：

項(xiàng)目鏈接，fork一下即可使用 https://aistudio.baidu.com/aistudio/projectdetail/4482932?contributionType=1