[性能優化] perf 高級用法：完整記錄程序性能指標，並按照時間段對程序進行有針對性的性能分析

 

如題：

假設你已經熟悉了基本用法，知道perf是干嘛的，以及會用 perf top

[性能優化] perf

 

背景：目標程序在運行的某時間段內會出現性能下降，需要了解這個時間內，程序發生了什么。

方法：

1. 按時間軸記錄下性能變化數據。

2. 同時記錄下當時的perf數據，使用perf record

3. 按照時間軸進行對比，對特定時間段內的perf數據進行分析。使用perf report。

 

1.  因為perf data內目前不能記錄wall clock time。所以需要保證同時啟動（關閉）性能變化的記錄程序和perf record。之后才能對應時間軸。

 

編譯的時候最好加編譯選項“” -O0 -ggdb“”

 

記錄性能變化的腳本：(這個腳本是用來抽樣檢測性能數據的)

[root@vm perf-4]# ../forward/forward.sh |tee perf.log

#! /bin/bash

date
old_value=`/root/cli-client getPortStatus 0 |awk -F '[=,]' '{if($12=="'\''all'\''") print $22}'`
old_date_value=`date +%s`

while true :
do
    sleep 5
    value=`/root/cli-client getPortStatus 0 |awk -F '[=,]' '{if($12=="'\''all'\''") print $22}'`
    date_value=`date +%s`
    conn_count=`/root/cli-client nlb_conn_count`

    x_value=`expr $value - $old_value`
    x_date_value=`expr $date_value - $old_date_value`

    old_value=$value
    old_date_value=$date_value

    output=`echo "scale=2; $x_value / $x_date_value" | bc -l`
    echo -e "$date_value\t$output\t$conn_count"
done

 

 

 

 

perf record的用法：

對於多線程程序，找到要調試的線程id

[root@vm perf-4]# top -n 1 -H -p 24981

運行perf：

T：保留時間戳。g：記錄調用樹。

[root@vmnlb perf-4]# perf record -Tgs -t 25006,25007,25008,25009

perf record會在當前目錄生成文件perf.data

 

查看時間軸： 可見： 時間為：79627到80301

[root@vm perf-4]# perf script -i perf.data |head
lcore-slave-1 25006 79627.186181:          1 cycles: 
        7fff8105ad5a native_write_msr_safe ([kernel.kallsyms])
        7fff81032bfc intel_pmu_enable_all ([kernel.kallsyms])
        7fff8102d284 x86_pmu_enable ([kernel.kallsyms])
        7fff8115d4b7 perf_pmu_enable ([kernel.kallsyms])
        7fff8102b459 x86_pmu_commit_txn ([kernel.kallsyms])
        7fff8115e620 group_sched_in ([kernel.kallsyms])
        7fff8115eabf __perf_event_enable ([kernel.kallsyms])
        7fff81159be0 remote_function ([kernel.kallsyms])
        7fff810e8a1d flush_smp_call_function_queue ([kernel.kallsyms])
[root@vmnlb perf-4]# perf script -i perf.data |tail -n 100
lcore-slave-4 25009 80301.104199:     622239 cycles: 
        7fff8163ec99 _raw_spin_lock_irq ([kernel.kallsyms])
        7fff810f236c acct_collect ([kernel.kallsyms])
        7fff8108345f do_exit ([kernel.kallsyms])

 

分析對應了時間軸之后的，性能日志：（根據前文中的forward.sh作出的抽樣數據，可以生成如下的頻率圖。）

 

使用 perf report：

--sort參數很重要，用來指定不同的統計維度，維度不同的時候，累計值也不同，所以如果選擇了錯誤的維度，很可能忽略問題。

--no-children與--children是一對互逆的配置，可以影響統計排序，也很重要。參考：https://stackoverflow.com/questions/31567272/sorting-by-self-column-in-perf-report?utm_medium=organic&utm_source=google_rich_qa&utm_campaign=google_rich_qa

[root@vm perf-4]# perf report --time 79830,79940

[root@vm perf-4]# perf report --time 79830,79940 -s sym
[root@vm perf-4]# perf report --time 79830,79940 -s sym --no-children