博客 / 詳情

返回

DatenLord｜Rust程序性能分析

首發｜RustMagazine

簡介

程序的性能分析是一個很廣很深的話題，有各種各樣的工具來對不同的指標進行測試分析。本文主要介紹如何用profiling工具對Rust程序進行On-CPU和Off-CPU的性能分析，以及如何繪製火焰圖對結果測試進行可視化處理。

On-CPU性能分析

On-CPU的性能分析為了找出佔用CPU時間多的任務或者函數，進而找出程序的性能瓶頸。這裏主要介紹perf工具，perf是Linux提供的命令，也叫perf_events，它屬於Linux kernel，在tools/perf目錄下。perf提供了強大的功能包括監測CPU performance counters, tracepoints, kprobes和 uprobes等。這裏我們使用perf的CPU profiling功能。由於perf會拿到系統的信息，所以運行需要root權限。perf做On-CPU性能分析的原理是以一個指定的頻率對CPU進行採樣，進而拿到正在CPU上運行的指令乃至整個函數調用棧的快照，最後對採樣的數據分析，比如説在100次採樣中有20次在運行A指令或者A函數，那麼perf就會認為A函數的CPU使用率為20%。

下面我們使用一個簡單的程序來展示如何用perf來進行On-CPU的性能分析，需要使用debug編譯，程序如下：

fn test2() {
    for _ in 0..200000 {
        ()
    }
}
fn test1() {
    for _ in 0..100000 {
        ()
    }
    test2();
}
fn main() {
    for _ in 0..10 {
        test1();
    }
}

我們在test1()函數和test2()函數中分別加入了一個段循環來消耗CPU資源，在test2()中我們循環了200000次是在test1()中的兩倍。我們使用如下perf命令來做CPU profiling:

$ sudo perf record --call-graph=dwarf ./target/debug/mytest

採樣的數據默認會存到perf.data文件中。參數--call-graph的目的是開啓函數調用棧的記錄，這樣在profiling的結果中可以打印出完整的函數調用棧。目前perf支持fp(frame pointer), dwarf(DWARF's CFI - Call Frame Information)和lbr(Hardware Last Branch Record facility)三種方式來獲取函數調用棧。稍後我們會簡單介紹fp和dwarf的原理。由於Rust編譯器默認生成了dwarf格式的調試信息，我們可以直接使用--call-graph=dwarf。我們可以使用如下命令來讀取profiling的結果：

$ sudo perf report --stdio

這個命令會默認讀取perf.data中的數據並格式化輸出。命令的輸出如下，因為輸出很長，部分無關信息被省略掉，

# Children      Self  Command  Shared Object      Symbol
# ........  ........  .......  .................  .........................................................................................................
#
    77.57%     0.00%  mytest   mytest             [.] _start
            |
            ---_start
               __libc_start_main
               main
               ......
               mytest::main
               mytest::test1
               |
               |--52.20%--mytest::test2
               |          |
               |           --46.83%--core::iter::range::<impl core::iter::traits::iterator::Iterator for core::ops::range::Range<A>>::next
               |                     |......
               |
                --23.87%--core::iter::range::<impl core::iter::traits::iterator::Iterator for core::ops::range::Range<A>>::next
                          |......
               |......

從輸出可以看出整個測試程序佔用了77.57%的CPU資源，在mytest::test1函數中有23.87%的時間在做for循環，有52.20%的時間被調用的mytest::test2函數佔用，然後在mytest::test2函數中，有45.32%時間在做for循環，剩下的時間是一些其他的開銷。profiling的結果基本體現了我們測試程序CPU佔用率的實際情況。我們在mytest::test2函數中for循環次數是mytest::test1函數中兩倍，相應的我們也看到了在CPU佔用率上也幾乎是兩倍的關係。

火焰圖

火焰圖是對profiling進行可視化處理的一種方式，從而更直觀地展示程序CPU的使用情況，通過如下命令可以生成火焰圖

$ git clone https://github.com/brendangregg/FlameGraph
$ cd FlameGraph
$ sudo perf record --call-graph=dwarf mytest
$ sudo perf script | ./stackcollapse-perf.pl > out.perf-folded
$ ./flamegraph.pl out.perf-folded > perf.svg

可以使用Chrome瀏覽器打開perf.svg，生成的火焰圖如下 
圖片

火焰圖的縱軸代表了函數調用棧，橫軸代表了佔用CPU資源的比例，跨度越大代表佔用的CPU資源越多，從火焰圖中我們可以更直觀的看到程序中CPU資源的佔用情況以及函數的調用關係。

Frame Pointer 和 DWARF

前文有提到Frame Pointer和DWARF兩種方式拿到函數的調用棧，這裏做一個簡單的介紹。

Frame Pointer是基於標記棧基址EBP的方式來獲取函數調用棧的信息，通過EBP我們就可以拿到函數棧幀的信息，包括局部變量地址，函數參數的地址等。在做CPU profiling的過程中，fp幫助函數調用棧的展開，具體原理是編譯器會在每個函數入口加入如下的指令以記錄調用函數的EBP的值

push ebp
mov    ebp, esp
sub    esp, N

並在函數結尾的時候加入如下指令以恢復調用函數的EBP

mov    esp, ebp
pop    ebp
ret

通過這種方式整個函數調用棧像一個被EBP串起來的鏈表，如下圖所示
圖片

這樣調試程序就可以拿到完整的調用棧信息，進而進行調用棧展開。
因為Frame Pointer的保存和恢復需要引入額外的指令從而帶來性能開銷，所以Rust編譯器，gcc編譯器默認都是不會加入Frame Pointer的信息，需要通過編譯選項來開啓。Rust編譯器加入Frame Pointer的選項如下

$ RUSTFLAGS="-C force-frame-pointers=yes" cargo build

加入Frame Pointer的信息後就可以通過--call-graph=fp來打印函數的調用棧。
DWARF是被廣泛使用的調試格式，Rust編譯器默認加入了DWARF調試信息，DWARF格式提供了各種調試信息，在幫助函數調用棧展開方面，編譯器會插入CFI(Call Frame Information)指令來標記CFA(Canonical Frame Address)，CFA指的是調用函數在call被調函數前ESP的地址。通過CFA再加上預先生成的調試信息，就可以解析出完整的函數調用棧信息。

Off-CPU性能分析

Off-CPU性能分析與On-CPU性能分析是互補的關係。Off-CPU性能分析是為了分析進程花在等待上的時間，等待包括被I/O請求阻塞，等待鎖，等待timer，等等。有很多可以做Off-CPU性能分析的工具，這裏我們使用eBPF的前端工具包bcc中的offcputime-bpfcc工具。這個工具的原理是在每一次內核調用finish_task_switch()函數完成任務切換的時候記錄上一個進程被調度離開CPU的時間戳和當前進程被調度到CPU的時間戳，那麼一個進程離開CPU到下一次進入CPU的時間差即為Off-CPU的時間。為了模擬Off-CPU的場景我們需要修改一下我們的測試程序，需要使用debug編譯，因為offcputime-bpfcc依賴於frame pointer來進行棧展開，所以我們需要開啓RUSTFLAGS="-C force-frame-pointers=yes"的編譯選項，程序如下：

use std::io::Read;
fn test1() {
    std::thread::sleep(std::time::Duration::from_nanos(200));
}
fn test2() {
    let mut f = std::fs::File::open("./1.txt").unwrap();
    let mut buffer = Vec::new();
    f.read_to_end(&mut buffer).unwrap();
}
fn main() {
    loop {
        test1();
        test2();
    }
}

程序中一共有兩種會導致進程被調度出CPU的任務，一個是test1()函數中的sleep()，一個是在test2()函數中的讀文件操作。這裏我們需要開啓Frame Pointer編譯選項以便打印出用户態的函數棧。我們使用如下的命令獲取Off-CPU的分析數據，

$ ./target/debug/mytest &
$ sudo offcputime-bpfcc -p `pgrep -nx mytest` 5
    .......
    b'finish_task_switch'
    b'preempt_schedule_common'
    b'_cond_resched'
    b'copy_page_to_iter'
    b'generic_file_buffered_read'
    b'generic_file_read_iter'
    b'ext4_file_read_iter'
    b'new_sync_read'
    b'vfs_read'
    b'ksys_read'
    b'__x64_sys_read'
    b'do_syscall_64'
    b'entry_SYSCALL_64_after_hwframe'
    b'__libc_read'
    b'std::io::read_to_end::hca106f474265a4d9'
    b'std::io::Read::read_to_end::h4105ec7c4491a6c4'
    b'mytest::test2::hc2f1d4e3e237302e'
    b'mytest::main::h9ce3eef790671359'
    b'core::ops::function::FnOnce::call_once::hac091ad4a6fe651c'
    b'std::sys_common::backtrace::__rust_begin_short_backtrace::h071a56f0a04107d5'
    b'std::rt::lang_start::_$u7b$$u7b$closure$u7d$$u7d$::hc491d6fbd79f86bd'
    b'std::rt::lang_start_internal::h73711f37ecfcb277'
    b'[unknown]'
    -                mytest (179236)
        52

    b'finish_task_switch'
    b'schedule'
    b'do_nanosleep'
    b'hrtimer_nanosleep'
    b'common_nsleep'
    b'__x64_sys_clock_nanosleep'
    b'do_syscall_64'
    b'entry_SYSCALL_64_after_hwframe'
    b'clock_nanosleep'
    -                mytest (179236)
        1093

這裏只截取了最後兩個函數棧，輸出顯示有52ms的Off-CPU時間在等待文件讀取的syscall，有1092ms的Off-CPU時間在等待sleep。

火焰圖

Off-CPU性能分析的結果同樣可以用火焰圖進行可視化處理，命令如下，

$ git clone https://github.com/brendangregg/FlameGraph
$ cd FlameGraph
$ sudo offcputime-bpfcc -df -p `pgrep -nx mytest` 3 > out.stacks
$ ./flamegraph.pl --color=io --title="Off-CPU Time Flame Graph" --countname=us < out.stacks > out.svg

生成的火焰圖如下： 
圖片

與On-CPU的火焰圖相同，縱軸代表了函數調用棧，橫軸代表了Off-CPU時間的比例，跨度越大代表Off-CPU的時間越長。

總結

本文介紹瞭如何對Rust程序進行On-CPU和Off-CPU的性能分析，兩者相結合就實現了對一個程序100%運行時間的分析。至此我們對程序的性能有了初步的理解，進而可以通過更加具體的工具和編寫profiling程序來對我們關心的點進行更深入的分析。

參考引用

https://www.brendangregg.com/...
https://www.brendangregg.com/...
https://en.wikipedia.org/wiki...

程序 , 性能分析 , rust , 性能
user avatar apachepulsar 頭像
1 位用戶收藏了這個故事！

發佈 評論

Some HTML is okay.