簡單記錄一些 在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
  sudo perf trace -p $pid --duration 50 --call-graph dwarf -o $save_file_name
  統計運行耗時超過50ms的系統調用，并打印該系統調用的calltrace，并將打印的結果保存到save_file_name的文件之中，一般用于追蹤IO性能問題

  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    
  }
  

  需要sudo權限，直接sudo ./trace_function_time即可

  Fri Aug  7 03:24:18 2020 
  value |-------------------------------------------------- count0 |                                                       01 |                                                       02 |                                                     1824 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  212808 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@                 1466616 |@@@@@@@@@@@@@@@                                     651832 |@@@@@@@@@@                                          460864 |@@@@@@@@                                            3421128 |@@@@@                                               2148256 |@@                                                   923512 |                                                     3611024 |                                                     1942048 |                                                      754096 |                                                      308192 |                                                       0
  16384 |                                                       0
  

  打印的一秒內，統計處于各個微妙時間段內的請求個數

總結

以上是生活随笔為你收集整理的Linux 下 进程运行时内部函数耗时的统计 工具：pstack,strace,perf trace,systemtap的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。