簡單記錄一些 在linux下 統計程序内部函數運作耗時的統計工具,主要是用作性能瓶頸分析。當然以下工具除了pstack功能單一之外,其他的工具都非常強大,這裡僅僅整理特定場景的特定用法,用作協同分析。
以下工具需要追蹤具體的程序,如果想要列印資訊更全,建議編譯的時候将符号資訊都編譯到二進制檔案之中,
-g
選項
-
strace
追蹤指定程序内部所有線程調用到的系統調用運作耗時,機關是秒,将統計結果儲存到strace -tttT -f -p $pid -o $save_file_name
的檔案之中save_file_name
[pid 35467] 1596874136.770976 <... clock_gettime resumed> {1479879, 802163984}) = 0 <0.000293>
[pid 35466] 1596874136.770989 <... futex resumed> ) = 0 <0.000290>
[pid 35462] 1596874136.770998 <... futex resumed> ) = 1 <0.000289>
[pid 35460] 1596874136.771007 <... sched_yield resumed> ) = 0 <0.000286>
[pid 35457] 1596874136.771016 <... clock_gettime resumed> {1479879, 802216718}) = 0 <0.000280>
[pid 35454] 1596874136.771025 <... sched_yield resumed> ) = 0 <0.000275>
-
pstack
追蹤正在運作的程序的調用棧pstack $pid
Thread 445 (Thread 0x7f17e35fe700 (LWP 33120)):
#0 0x00007f18638be945 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00007f18640a0cbc in __gthread_cond_wait (__mutex=<optimized out>, __cond=__cond@entry=0x13af91c8) at gthr-default.h:864
#2 std::condition_variable::wait (this=this@entry=0x13af91c8, __lock=...) at condition_variable.cc:53
#3 0x000000000065c21f in rocksdb::ThreadPoolImpl::Impl::BGThread (this=this@entry=0x13af9130, thread_id=thread_id@entry=29) at util/threadpool_imp.cc:196
#4 0x000000000065c5c5 in rocksdb::ThreadPoolImpl::Impl::BGThreadWrapper (arg=0x13afbaf0) at util/threadpool_imp.cc:306
#5 0x00007f18640a6f20 in execute_native_thread_routine_compat () at thread.cc:94
#6 0x00007f18638bae25 in start_thread () from /lib64/libpthread.so.0
#7 0x00007f18635e834d in clone () from /lib64/libc.so.6
-
perf trace
統計運作耗時超過50ms的系統調用,并列印該系統調用的calltrace,并将列印的結果儲存到sudo perf trace -p $pid --duration 50 --call-graph dwarf -o $save_file_name
的檔案之中,一般用于追蹤IO性能問題save_file_name
563.060 (61.970 ms): rocksdb:high0/33123 fdatasync(fd: 8396 ) = 0
[0xffff80e79cbff9dd] (/usr/lib64/libc-2.17.so)
rocksdb::PosixWritableFile::Sync (test)
rocksdb::WritableFileWriter::SyncInternal (test)
rocksdb::WritableFileWriter::Sync (test)
rocksdb::BuildTable (test)
rocksdb::FlushJob::WriteLevel0Table (test)
rocksdb::FlushJob::Run (test)
-
systemtap
這本身是一個非常強大的黑科技工具,除了核心态的調試之外,擁有符号表的使用者程序也能夠進行調試
如下stap腳本
,抓取運作時程序内部指定函數的耗時情況,并将耗時結果列印出來trace_function_time
#!/bin/stap
global sends
#列印出來的機關是微妙
probe process("test").function("rocksdb::DBImpl::GetImpl").return {
sends <<< gettimeofday_us() - @entry(gettimeofday_us())
}
probe timer.s(1) { #每隔一秒列印一次
print(ctime(gettimeofday_s()))
print("\n")
print(@hist_log(sends))
delete sends
}
Fri Aug 7 03:24:18 2020
value |-------------------------------------------------- count
0 | 0
1 | 0
2 | 182
4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 21280
8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 14666
16 |@@@@@@@@@@@@@@@ 6518
32 |@@@@@@@@@@ 4608
64 |@@@@@@@@ 3421
128 |@@@@@ 2148
256 |@@ 923
512 | 361
1024 | 194
2048 | 75
4096 | 30
8192 | 0
16384 | 0