关于 Rocksdb 性能分析 需要知道的一些“小技巧“ -- perf_context的“内功” ,systemtap、perf、 ftrace的颜值
文章目錄
- 內(nèi)部工具
- 包含頭文件
- 接口使用
- 核心指標
- Perf Context
- IOStats Context
- 外部工具
- Systemtap 工具
- Perf工具
- Ftrace 工具
2020.8.20 23:23 ,又到了夜深人靜學習時,不斷得思考總結(jié)總會讓繁忙一天的大腦得到舒緩。
作為單機存儲引擎,Rocksdb總會被嵌入到各個存儲系統(tǒng)之中作為核心數(shù)據(jù)的存儲,那么有理有據(jù)得“甩鍋”便需要一些手段。在業(yè)務(wù)場景未達到rocksdb自身性能情況下,如何將rocksdb性能在業(yè)務(wù)中的體現(xiàn)合理展現(xiàn)給使用者,讓他們心服口服得"背鍋"。
本篇通過內(nèi)部工具 + 外部工具 的介紹 來全面展示rocksdb 整個IO鏈(這個IO的范圍是從rocksdb入,到文件系統(tǒng)write系統(tǒng)調(diào)用完成)上的性能獲取,從而更好得決定自己是否可以瀟灑"甩鍋"。
內(nèi)部工具
facebook頂尖工程師的不斷投入,精心雕琢得社區(qū)已經(jīng)讓rocksdb的各個核心特性及其實現(xiàn)都完整展現(xiàn)給使用者,那么一些profling的狀態(tài)也必然存在。
基本的profiling使用方式如下:
包含頭文件
當然這兩種頭文件是不同的profling狀態(tài)
iostats_context.h主要是io層面的耗時統(tǒng)計,比如write,read等系統(tǒng)調(diào)用的耗時,計數(shù)
perf_context.h 主要是內(nèi)部各個子流程的耗時統(tǒng)計,比如寫wal的耗時/請求計數(shù),寫memtable的耗時/請求計數(shù)
#include “rocksdb/iostats_context.h”
#include “rocksdb/perf_context.h”
接口使用
rocksdb::SetPerfLevel(rocksdb::PerfLevel::kEnableTimeExceptForMutex); //開啟profilingrocksdb::get_perf_context()->Reset(); // 初始化perf_context對象
rocksdb::get_iostats_context()->Reset() // 初始化 iostats_context對象// ...... 調(diào)用Get/Put ,或者一些其他的IO流程rocksdb::SetPerfLevel(rocksdb::PerfLevel::kDisable); // 關(guān)閉profling//獲取具體的profling結(jié)果
std::cout << rocksdb::get_perf_context()->ToString() << std::endl; //獲取所有的perf 狀態(tài)
std::cout << rocksdb::get_iostats_context()->ToString() << std::endl; //獲取所有的iostats狀態(tài)
std::cout << "get_from_memtable_time: " << rocksdb::get_perf_context()->get_from_memtable_time << "write_nanos: "<< rocksdb::get_iostats_context()->write_nanos<< std::endl; // 獲取某一個具體狀態(tài)的數(shù)值
簡單說一下rocksdb提供的perf級別,在文件perf_level.h中
enum PerfLevel : unsigned char {kUninitialized = 0, // 什么也不監(jiān)控,一般不實用這個選項kDisable = 1, // 關(guān)閉profling功能kEnableCount = 2, // 僅開啟count計數(shù)的profling 功能kEnableTimeExceptForMutex = 3, // 僅開啟time profiling功能,我們耗時方面分析就直接開啟這個級別。// 不過使用者需要注意這里統(tǒng)計的耗時在不同的系統(tǒng)上是有差異的。kEnableTimeAndCPUTimeExceptForMutex = 4, // 僅開啟cpu 耗時的統(tǒng)計kEnableTime = 5, // 開啟所有stats的統(tǒng)計,包括耗時和計數(shù) kOutOfBounds = 6 // 這個不太理解。。。。。。。反正也用不到
};
一般耗時的分析直接用kEnableTimeExceptForMutex 這個級別,如果想要抓取所有的stats信息,包括耗時和計數(shù),就可以使用kEnableTime功能。
詳細的實現(xiàn)主要是在perf_context_imp.h 通過宏定義來 實現(xiàn)一些計數(shù)和統(tǒng)計的接口,也是為了減少本身統(tǒng)計過程中函數(shù)調(diào)用的開銷。
核心指標
Perf Context
Ps: 以下的耗時統(tǒng)計都是取決于自己什么時候調(diào)用SetPerfLevel(rocksdb::PerfLevel::kDisable);的接口,來終止prifling。
二分查找的耗時
user_key_comparison_count統(tǒng)計二分查找的次數(shù),如果次數(shù)過多,可能是我們配置的comparator不是很合理。當然這個也與系統(tǒng)中數(shù)據(jù)量的大小,是否是冷熱數(shù)據(jù)有關(guān)。
block cache或者 page cache的效率
block_cache_hit_count我們從block cache中讀取數(shù)據(jù)的次數(shù)block_read_count從page cache中讀取數(shù)據(jù)的次數(shù),通過和上一個指標的對比來評估block cache的miss rate,從而確定當前配置下的block cache性能。(實現(xiàn)上,block cache是在page cache之上的一層緩存,默認是LRU)
Get 鏈路的耗時統(tǒng)計
一般以get 開頭的指標,如下是比較重要那的幾個
get_from_memtable_time從memtable中讀取數(shù)據(jù)的耗時get_from_output_files_time從sst文件中讀取數(shù)據(jù)的耗時seek_on_memtable_time查找memtable的耗時
Put 鏈路耗時統(tǒng)計
一般以 write 開頭的指標,如下是幾個比較重要的
write_wal_time寫wal的耗時write_memtable_time寫memtable的耗時write_pre_and_post_process_time主要是寫入數(shù)據(jù)之前的一些準備耗時,不包括wal以及memtale的寫入耗時
比如在組提交過程中,非leader的寫入需要等待leader完成wal的寫入之后才能開始寫memtble,這一些耗時也會被計算在內(nèi)
如下代碼,在開始寫memtale的時候才會停止計時,如果writer是非leader,則writer的狀態(tài)并不是能夠?qū)憁emtable的,不會進入到這個邏輯,那么非leader就會等待一段時間。
之后還會進入ProcessWrite函數(shù)來統(tǒng)計即將寫入前的write delay 部分的耗時
IOStats Context
如下幾個重要的耗時指標,統(tǒng)計的總時間取決于什么時候關(guān)閉profiling接口,也可以每一個請求都統(tǒng)計一次。
write_nanos調(diào)用write 和 pwrite系統(tǒng)調(diào)用的耗時read_nanos調(diào)用read和 pread系統(tǒng)調(diào)用的耗時統(tǒng)計fsync_nanos調(diào)用fsync系統(tǒng)調(diào)用的耗時cpu_write_nanos官方給的描述是 : cpu在write 和 pwrite的耗時
這里應(yīng)該是統(tǒng)計cpu的寫入key-value到文件的計算耗時,因為看代碼是在compaction的最終由cpu處理ProcessKeyValueCompaction函數(shù)的起始和末尾計算了一下耗時cpu_read_nanoscpu在read 和 pread的耗時
同樣read也是在上文中的函數(shù)中進行統(tǒng)計的,因為ProcessKeyValueCompaction的處理過程中會涉及key-value 從底層sst文件中的讀取
一個簡單的demo之前的統(tǒng)計信息:
.......rocksdb::get_perf_context()->Reset();rocksdb::get_iostats_context()->Reset();std::vector<string> keys, values;rocksdb::WriteOptions write_option;rocksdb::Status s;/*執(zhí)行具體IO操作,stats的統(tǒng)計是兩次put,一個get的總和*/s = binlog_vec[n_db]->Put(write_option, k, rand_value);assert(s.ok());s = db_vec[n_db]->Get(rocksdb::ReadOptions(), k, &value); assert(s.ok());s = db_vec[n_db]->Put(write_option, k, rand_value);assert(s.ok());req_num ++; buff_num ++; if (!s.ok()){ cerr << "Put failed: " << s.ToString() << endl;exit(1);} //if ( thread_id==21 && (now() - ts) >= 1.00 )if ( (now() - ts) >= 1.00 ) //每隔一秒打印一次{ time_t temp;temp = time(NULL); printf("time is :%s thread_id %ld db%d : count=%ld, speed=%ld\n", \ctime(&temp),thread_id, n_db, req_num, buff_num);ts = now();buff_num = 0;g_time += 10; // 關(guān)閉profilingrocksdb::SetPerfLevel(rocksdb::PerfLevel::kDisable);std::cout << "get_perf_context: \n get_from_memtable_time: " << rocksdb::get_perf_context()->get_from_memtable_time<< "\nget_from_output_files_time: " << rocksdb::get_perf_context()->get_from_output_files_time << "\nblock_read_time: " << rocksdb::get_perf_context()->block_read_time << "\nseek_on_memtable_time "<< rocksdb::get_perf_context()->seek_on_memtable_time << "\nseek_min_heap_time "<< rocksdb::get_perf_context()->seek_min_heap_time << "\neek_max_heap_time "<< rocksdb::get_perf_context()->seek_max_heap_time << "\nseek_internal_seek_time "<< rocksdb::get_perf_context()->seek_internal_seek_time << "\nwrite_wal_time "<< rocksdb::get_perf_context()->write_wal_time << "\nwrite_memtable_time "<< rocksdb::get_perf_context()->write_memtable_time << "\nwrite_delay_time "<< rocksdb::get_perf_context()->write_delay_time << "\nwrite_scheduling_flushes_compactions_time "<< rocksdb::get_perf_context()->write_scheduling_flushes_compactions_time << "\n write_pre_and_post_process_time "<< rocksdb::get_perf_context()->write_pre_and_post_process_time << "\nwrite_nanos "<< rocksdb::get_iostats_context()-> write_nanos<< "\nread_nanos "<< rocksdb::get_iostats_context()-> read_nanos<< std::endl;std::string out;db_vec[n_db]->GetProperty("rocksdb.estimate-pending-compaction-bytes", &out);fprintf(stdout, "rocksdb.estimate-pending-compaction-bytes : %s\n", out.c_str());if(g_time == 60) {std::cout << "begin write" << std::endl;judge_read = false;} } ......
輸出如下,以下的耗時統(tǒng)計單位都是微妙:
get_perf_context: get_from_memtable_time: 838
get_from_output_files_time: 0
block_read_time: 0
seek_on_memtable_time 0
seek_min_heap_time 0
eek_max_heap_time 0
seek_internal_seek_time 0
write_wal_time 5947
write_memtable_time 2050
write_delay_time 0
write_scheduling_flushes_compactions_time 261write_pre_and_post_process_time 899
write_nanos 4513
read_nanos 0
這樣,我們就可以通過簡單的rocksdb內(nèi)部已有的工具來進行引擎層的profiling過程排查分析,比如上層存儲系統(tǒng)調(diào)用rocksdb接口,我們可以將我們rocksdb內(nèi)部耗時完整展示出來,那么是不是我們的問題就一目了然了。
當然這樣的調(diào)試過程還會有一些麻煩,我們需要侵入業(yè)務(wù)的代碼,增加一些狀態(tài)統(tǒng)計,不過結(jié)果是精確的,即使因為統(tǒng)計本事的耗時所產(chǎn)生的誤差也基本都是us級的,并不影響宏觀上的性能比對。
外部工具
結(jié)合內(nèi)部調(diào)試工具,我們再通過外部工具進行一些rocksdb流程上耗時的抓取,這里需要對rocksdb內(nèi)部實現(xiàn)有一定的了解, 我們需要知道抓取一些rocksdb的IO鏈上的函數(shù)。
抓取之前需要應(yīng)用的二進制文件中包含rocksdb的符號表,即編譯rocksdb需要加入-g或者-gd b參數(shù)來編譯。
大體思路上,還是說先集中在rocksdb內(nèi)部的耗時之上,因為我們需要明確rocksdb自己的性能上限,處理一個key的過程中,內(nèi)部各個字階段的耗時大概是什么樣子的量級,相關(guān)的測試都是基于Centos7.4 3.10內(nèi)核。
Systemtap 工具
Systemtap 工具是一種可以通過腳本進行自由擴展的動態(tài)追蹤技術(shù),但是因為長時間游離于內(nèi)核之外,所以在RHEL系統(tǒng)中是比較穩(wěn)定,而其他系統(tǒng)則容易出現(xiàn)異常。
反過來說,在3.x 等舊版本內(nèi)核中,systemtap 相比于eBPF 是一個巨大的優(yōu)勢。
首先通過systemtap 來獲取我們rocksdb內(nèi)部子流程上的關(guān)鍵函數(shù)調(diào)用棧,從而幫助大家更好的分析。
如果沒有stap命令,則可以通過sudo yum install system tap -y來安裝systemtap工具。
比如我們抓取寫WAL 函數(shù)的調(diào)用棧,編寫call_trace.stp 如下
#!/bin/stapprobe process("/home/test_binary").function("rocksdb::DBImpl::WriteToWAL") print("------------------------------------\n")print_ubacktrace()print("------------------------------------\n")}
通過sudo stap call_trace.stp | c++filt 將每次調(diào)用WriteToWAL函數(shù)的調(diào)用棧打印出來。這里如果編譯rocksdb的時候采用demangle的方式,那么就不需要c++filt了, 否則會出現(xiàn)一些亂碼,這里使用c++filt進行過濾。
最終可以看到很多wal相關(guān)的調(diào)用棧信息如下
通過調(diào)用棧,我們就大概知道了從rocksdb的IO鏈路到上層應(yīng)用鏈路的調(diào)用關(guān)系, 取到了這條路徑上的函數(shù),再逐層從下向上結(jié)合后面的stap腳本進行耗時統(tǒng)計。
以下是一個案例,可以在binary中增加多個探針,來打印對應(yīng)函數(shù)的耗時情況。
!#/bin/stapglobal timesprobe process("/home/test_binary").function("rocksdb::DBImpl::WriteImpl").return,process("/home/test_binary").function("rocksdb::DBImpl::WriteToWAL").return,process("/home/test_binary").function("rocksdb::WriteBatchInternal::InsertInto").return,process("/home/test_binary").function("rocksdb::WriteBatchInternal::Iterate").return,process("/home/test_binary").function("rocksdb::MemTable::Add").return {times[pid(), ppfunc()] += gettimeofday_us() - @entry(gettimeofday_us()) #耗時及耗時信息放在times 數(shù)組之中
}probe timer.s(10) { #每隔十秒打印一次println("========%s", execname())foreach([pid, pp] in times - limit 10) {printf("pid:%5d %50s %10ld(us)\n", pid, pp, times[pid, pp])}delete times
}
最終結(jié)果如下(這個結(jié)果顯然偏高了):
========%sswapper/42
pid:98097 rocksdb::DBImpl::WriteImpl 1510686(us)
pid:98097 rocksdb::DBImpl::WriteToWAL 1153604(us)
pid:98097 rocksdb::WriteBatchInternal::InsertInto 574674(us)
pid:98097 rocksdb::WriteBatchInternal::Iterate 437807(us)
pid:98097 rocksdb::MemTable::Add 257805(us)
一般不建議使用這種多個探針方式進行探測,這樣會對應(yīng)用程序性能有比較大的影響,systemtap的執(zhí)行方式是 先轉(zhuǎn)換成C代碼,編譯成內(nèi)核模塊,加載到內(nèi)核中,對指定的用戶程序添加探針,根據(jù)指定的行為做對應(yīng)的返回。如果同時有過多的探針,那肯定會對性能有比較大的影響。
所以這里抓取 的 耗時能夠和rocksdb內(nèi)部統(tǒng)計的耗時數(shù)據(jù)核對上之后(比如writeToWAL函數(shù)的消耗),再進行逐層向上抓取,當然也可以向下抓取。
比如writeToWAL之下會調(diào)用AddRecord函數(shù)進行l(wèi)og文件的寫入,再之下會通過Flush函數(shù)進行數(shù)據(jù)的寫入,通過PosixWritableFile::Append函數(shù) 調(diào)用 PosixWrite函數(shù),最終執(zhí)行到文件系統(tǒng)的write系統(tǒng)調(diào)用之上。詳細的寫WAL的實現(xiàn)可以參考Rocksdb Wal機制 底層探索。
System tap 這個工具本身還是有很多可以研究的地方,能夠極大得節(jié)省內(nèi)核的調(diào)試效率(本身的執(zhí)行方式就是編譯成對應(yīng)的內(nèi)核模塊,加載到系統(tǒng)中執(zhí)行的),但是在調(diào)試用戶態(tài)應(yīng)用過程中除了會對應(yīng)用本身性能有影響之外,其他功能方面的影響還好。
Perf工具
Perf 同樣是google開發(fā)出來的可以調(diào)試用戶態(tài)以及內(nèi)核態(tài)應(yīng)用的工具,這里還是挑一些簡單的子工具來用作我們rocksdb層面的性能分析。
首先Perf 能夠抓取On CPU的進程消耗調(diào)用棧,且提供一個火焰圖來展示調(diào)用棧的信息。
下載FlameGraph到服務(wù)器之上,進入FlameGraph目錄之后通過root用戶執(zhí)行如下腳本抓取對應(yīng)進程的On CPU消耗,并且是調(diào)用棧的形式。
#!/bin/bashpid=$1if [ -z "$pid" ];thenperf record -F 99 -g -- sleep 180
elseperf record -F 99 -p $pid -g -- sleep 180
fiperf script > out.perf./stackcollapse-perf.pl out.perf > out.folded
./flamegraph.pl out.folded > kernel-"$pid".svg
傳入進程PID,即可生成一個可視化的.svg文件,包含on cpu的進程內(nèi)部各個函數(shù)的消耗情況。
當然這個只能看到一個大體的百分比,我們想要看到具體的耗時情況需要切換一下子工具。
使用perf probe來增加類似于systemtap的探針功能,不過perf的采樣更加輕量級,關(guān)于內(nèi)核態(tài)的調(diào)試這里也是類似的,可以提前perf list來查看 可調(diào)試的探針。
-
perf probe增加探針
這里需要提前說明一下,因為perf probe向用戶態(tài)應(yīng)用增加探針時可能因為編譯選項的一些問題(C++工程沒有demangle),則無法找到對應(yīng)探測的函數(shù)地址。建議先手動找一下函數(shù)地址,直接使用函數(shù)地址進行探測。
通過objdump工具查看函數(shù)所處二進制文件中的偏移地址,位于打印出來的第一列objdump /home/test_binary --syms | c++filt | grep -i "rocksdb::rocksdb::log::Writer::AddRecord"增加perf 探針
sudo perf probe -x /home/test_binary '0x0000000000f7d59c'增加成功之后會給一個類似于這樣的地址
probe_test_binary:abs_f7d59c,直接復(fù)制進行接下來的采樣即可。
如果是探測內(nèi)核函數(shù),更換一下命令選項即可。$ perf probe --add do_sys_open Added new event:probe:do_sys_open (on do_sys_open) You can now use it in all perf tools, such as: perf record -e probe:do_sys_open -aR sleep 1 -
perf record進行采樣sudo perf record -e probe_test_binary:abs_f7d59c -aR sleep 60 -
perf script生成可讀性報告,查看采樣結(jié)果sudo perf script
當然這里調(diào)試內(nèi)核的時候可以增加一些參數(shù)選項:$ perf probe -V do_sys_openAvailable variables at do_sys_open@<do_sys_open+0>char* filenameint dfdint flagsstruct open_flags opumode_t mode從而能夠使用帶參數(shù)的探測選項來完成更加詳細的探測信息展示:
perf probe --add 'do_sys_open filename:string' -
perf brobe --del探針用完之后需要刪除掉sudo perf probe --del probe_test_binary:abs_f7d59c這里的perf probe還是追蹤一些調(diào)用關(guān)系的邏輯,在火焰圖的分析中可以再關(guān)注rocksdb層面在當前進程中的消耗占比,大體是能夠看出我們rocksdb在當前CPU下的一個壓力情況。
不過很多情況,我們還是想要更加精確得了解到系統(tǒng)硬件以及一些系統(tǒng)調(diào)用執(zhí)行到情況,這個時候就需要探測一些硬件相關(guān)到事件,比如
cpu cache-misses,context-switches,cpu-migrations等CPU相關(guān)的事件,這一些數(shù)據(jù)的升高,可能系統(tǒng)存在大量的無效線程切換,從而導(dǎo)致整個CPU消耗在非IO鏈路之上。或者說我們想追蹤某一個內(nèi)核函數(shù)的執(zhí)行情況,也可以通過perf 的
tracepoints進行追蹤。
接下來簡單演示一下這個perf 組合命令的使用詳情: -
perf list查看可追蹤的事件
或者通過perf list的子命令來查看具體的可采樣的事件-
perf list hw查看可以采樣的具體硬件事件,像cpu 的cache-misses,branch-misses,ref-cycle等重要指標簡單說一下CPU cache, 它是操作系統(tǒng)設(shè)計的局部性原理的體現(xiàn),利用CPU L1-cache(訪問速度遠高于內(nèi)存,但是容量小)來保存近期CPU處理過的數(shù)據(jù),CPU再次進行計算時,需要重新加載參與計算的數(shù)據(jù),此時會先從L1-cache中查找,如果找到了就不去內(nèi)存中找了。這樣的一個優(yōu)化在有大量局部性特性的數(shù)據(jù)處理過程中會極大得提升處理效率。
如下簡單的代碼
#include <stdio.h> #include <unistd.h>int a[10000][10000];int main(int argc, char **argv) {int i,j;printf("%d \n",argc);if(argc == 1){for(i = 0; i < 10000; ++i){for(j = 0; j < 10000; ++j){a[i][j] = 0;}}}else{for(i = 0; i < 10000; ++i){for(j = 0; j < 10000; ++j){a[j][i] = 0;}}}return 0; }這里兩種相同功能,但不同賦值順序的循環(huán),CPU處理性能差異還是比較大的。
第二個循環(huán)性能會比較差,因為第二個循環(huán)的j 數(shù)據(jù)每次都會變化,j控制的是行的訪問,每次賦值都需要重新加載一整行的數(shù)據(jù)到CPU cache之中,所以這樣的循環(huán)下CPU cache的局部性優(yōu)化就不怎么明顯了,而且存在大量的cache-misses性能差異:
可以看到在相同環(huán)境下見到操作一億條數(shù)據(jù)時的執(zhí)行效率有兩倍的差異
通過perf 驗證如下:
對應(yīng)的cpu cache-misses也有接近七倍的差異,在CPU cache這里的空間局部性非常差,性能自然就會差。相當于CPU 每次加載不到cpu-cache的時候就需要訪存,自然帶來更大的開銷。
那就會有人問,為什么不把cpu cache再增大一點呢,這樣不就有更多的空間存放更多的數(shù)據(jù)來靠近CPU執(zhí)行了。CPU的設(shè)計工藝上 就是核心芯片,無數(shù)的功能集中在數(shù)平方厘米的地盤(計算,存儲,肯定是以計算為主),為了一增大一部分的存儲的性能,而讓計算變得更加擁擠,自然是得不償失。
-
-
perf stat實時進行events的采樣
以上案例展示了通過perf stat來 抓取具體的事件執(zhí)行情況,我們也可以抓取具體進程的某個事件指標
perf stat -e $events -p $pid sleep $time抓取一段時時間內(nèi)指定進程的指定events情況。
這里的time單位是s
詳細的events還包括具體內(nèi)核模塊的函數(shù),可以通過perf list tracepoint查看
-
perf record對給定的evets采樣一段時間,做一個數(shù)據(jù)記錄
perf record -e $events -p $pid -o $output_filename sleep $time
如果沒有指定-o 參數(shù),采樣完成后會生成一個perf.data文件,否則會將針對events的采樣數(shù)據(jù)存放在當前目錄下自己指定的文件之中
-
perf report將record記錄的數(shù)據(jù)生成可讀性的報告
perf report -i $input_file通過 -i 參數(shù)指定自己record生成的數(shù)據(jù)文件,如果不用-i參數(shù),則默認會加載perf.data數(shù)據(jù)
接下來看到的report中的數(shù)據(jù)就類似perf top中的每個函數(shù)的消耗占用情況
Ftrace 工具
ftrace 工具通過擴展支持了各種事件的跟蹤功能,來以普通文件的形式,向用戶提供抓取內(nèi)核系統(tǒng)調(diào)用的接口。
主要是通過類似于procfs的debugfs進行文件訪問 。
這樣 不需要額外的工具,只需要掛載/sys/kernel/debug/tracing目錄,對內(nèi)部的文件進行讀寫,來跟ftrace進行交互。
- 一般交互是需要進入
/sys/kernel/debug/tracing目錄,所以第一步 root用戶 執(zhí)行cd /sys/kernel/debug/tracing - 如果該目錄不存在,則用進行掛載
mount -t debugfs nodev /sys/kernel/debug - 設(shè)置追蹤函數(shù)
echo SyS_write > set_graph_function
通過cat available_filter_functions能夠看到當前可以追蹤的內(nèi)核函數(shù),有大量的不同模塊的內(nèi)核函數(shù)以及系統(tǒng)調(diào)用
通過cat available_events可以看到支持追蹤的事件,這個事件是內(nèi)核源碼中事先定義好的追蹤點 - 配置追蹤選項,
echo function_graph > current_tracer
其中查看支持的追蹤器可以通過cat available_tracers
這其中,function 表示跟蹤函數(shù)的執(zhí)行,function_graph 則是跟蹤函數(shù)的調(diào)用關(guān)系,也就是生 成直觀的調(diào)用關(guān)系圖,這便是最常用的兩種跟蹤器。# cat available_tracers hwlat blk function_graph wakeup_dl wakeup_rt wakeup function nop - 配置追蹤進程選項,
echo funcgraph-proc > trace_options - 開啟追蹤
echo 1 > tracing_on - 關(guān)閉追蹤
echo 0 > tracing_on - 查看追蹤結(jié)果
cat trace
可以看到SyS_write整體執(zhí)行到底層的調(diào)用鏈,甚至將每一個函數(shù)的耗時都展示出來了
以上的輸出含義如下:- 第一列表示運行的 CPU
- 第二列是任務(wù)名稱和進程 PID或者主線程ID
- 第三列是函數(shù)執(zhí)行延遲,單位是 us
- 最后一列,則是函數(shù)調(diào)用關(guān)系圖。
可以看到以上執(zhí)行的整個過程還是比較復(fù)雜的,需要操作很多的文件,所以這里ftrace開發(fā)者提供了trace-cmd工具進行追蹤步驟的簡化。
通過yum install trace-cmd -y即可安裝。
使用方式:
#追蹤系統(tǒng)所有執(zhí)行`SyS_write` 系統(tǒng)調(diào)用的進程
trace-cmd record -p function_graph -g SyS_write -O funcgraph-proc
trace-cmd start # 開啟追蹤
trace-cmd stop # 結(jié)束追蹤
trace-cmd reset # 重置所有配置信息
其他詳細的使用可以參考trace-cmd -h
這里有一個性能文件需要提前說明一下,因為ftrace 追蹤的是內(nèi)核的函數(shù),采樣的頻率很高,實際的內(nèi)核函數(shù)的執(zhí)行耗時大概只有ftrace抓取的十分之一,不過并不影響我們來確認具體的執(zhí)行邏輯和耗時比對(相同環(huán)境下)。
通過如上的內(nèi)部工具 + 外部工具基本能夠觀察到整個rocksdb 引擎層的耗時情況,這個時候即使不能甩鍋,也能輕松定位到具體耗時的函數(shù),來讓我們的問題分析排查過程更加精確簡單。
總結(jié)
以上是生活随笔為你收集整理的关于 Rocksdb 性能分析 需要知道的一些“小技巧“ -- perf_context的“内功” ,systemtap、perf、 ftrace的颜值的全部內(nèi)容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 使用 sched_setaffinity
- 下一篇: 200斤啤酒酿酒设备多少钱一套