https://lrita.github.io/2017/09/16/get-function-elapse/
https://lrita.github.io/2017/09/16/get-function-elapse/
https://blog.csdn.net/Z_Stand/article/details/107881875
如下stap脚本抓取运行时进程内部指定函数的耗时情况，并将耗时结果打印出来
#!/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
}
https://blog.csdn.net/Z_Stand/article/details/103152344?ops_request_misc=%257B%2522request%255Fid%2522%253A%2522159687672919725247641717%2522%252C%2522scm%2522%253A%252220140713.130102334.pc%255Fblog.%2522%257D&request_id=159687672919725247641717&biz_id=0&utm_medium=distribute.pc_search_result.none-task-blog-2~blog~first_rank_v1~rank_blog_v1-1-103152344.pc_v1_rank_blog_v1&utm_term=systemtap&spm=1018.2118.3001.4187
Systemtap 工作原理是通过将脚本语句翻译成C语句，编译成内核模块。
模块加载之后，将所有探测的事件以钩子的方式挂到内核上，当任何处理器上的某个事件发生时，相应钩子上句柄就会被执行。
最后，当systemtap会话结束之后，钩子从内核上取下，移除模块。整个过程用一个命令 stap 就可以完成。
systemtap 测试示例
安装完systemtap之后，我们需要测试一下systemtap是否能正确运行：
示例一：打印hello systemtap
以root用户或者具有sudo权限的用户运行以下命令：
$stap -ve 'probe begin { log("hello systemtap!") exit() }'
如果安装正确，会得到如下类似的输出结果：
Pass 1: parsed user script and 96 library script(s) using 55100virt/26224res/2076shr/25172data kb, in 120usr/0sys/119real ms.
Pass 2: analyzed script: 1 probe(s), 2 function(s), 0 embed(s), 0 global(s) using 55496virt/27016res/2172shr/25568data kb, in 0usr/0sys/4real ms.
Pass 3: translated to C into "/tmp/stapYqNuF9/stap_e2d1c1c9962c809ee9477018c642b661_939_src.c" using 55624virt/27380res/2488shr/25696data kb, in 0usr/0sys/0real ms.
Pass 4: compiled C into "stap_e2d1c1c9962c809ee9477018c642b661_939.ko" in 1230usr/160sys/1600real ms.
Pass 5: starting run.
hello systemtap!
Pass 5: run completed in 0usr/10sys/332real ms.
示例二：打印4s内所有open系统调用的信息
创建systemtap脚本文件test2.stp:
#!/usr/bin/stap
probe begin
{
log("begin to probe")
}
probe syscall.open
{
printf ("%s(%d) open (%s)\n", execname(), pid(), argstr)
}
probe timer.ms(4000) # after 4 seconds
{
exit ()
}
probe end
{
log("end to probe")
}
将该脚本添加可执行的权限 chmod +x test2.stp ，使用./test2.stp 运行该脚本，即可打印4s内所有open系统调用的信息，打印格式为：进程名（进程号）打开什么文件。 大家可以自行去测试，如果两个示例都能正确运行，基本上算是安装成功了！
当我们需要对应用程序进行系能分析时，我们通常可以使用perf或者火焰图。 但是这些工具通常只能定性问题，发现那些函数占用cpu较多，需要优化。但是给不出定量的数据， 比如这个函数的耗时情况，它耗时1ms还是5ms。
SystemTap
因此在不在代码中加入统计耗时的代码的情况，我们可以使用SystemTap来统计应用程序的耗时情况。
SystemTap可以跟踪内核函数和用户态进程，当我们跟踪用户态进程时，需要使用其process模块。
查找函数符号
很多情况下，代码在执行时，其函数符号并不一定是代码中写的名称，因此我们可以使用以下脚本打印 出应用程序中在调用的函数符号。
probe process("/data0/app").function("*") {
println(probefunc())
}
然后执行
stap echo.stp
其会打印出/data0/app这个程序运行时调用到的各个函数名，此处最好填绝对路径。我们可以从中找到 我们需要统计的函数名称。
统计函数耗时
我们可以使用SystemTap内置的直方图来展示耗时的分布。我们有两种直方图函数可以使用:
@hist_linear(v, start, stop, interval) # 打印start-stop区间interval间隔的直方图
@hist_log(v) # 打印以2为底指数分布的直方图
统计脚本：
global sends # 声明全局的统计存储容器
probe process("/data0/app").function("git.intra.xx.send").return { # function中为函数名，同时支持通配符*等，在该函数return时计算耗时
sends <<< gettimeofday_us() - @entry(gettimeofday_us()) # 以微秒精度来统计，entry方法将一个表达式放置于函数入口处
}
probe timer.s(10) { # 每10s打印一次直方图
print(@hist_log(sends))
}
然后执行stap elaspe.stp即可获得每10秒统计的结果，如果希望每10秒清空重新统计的话， 可以将打印函数修改为：
probe timer.s(10) { # 每10s打印一次直方图
print(@hist_log(sends))
delete sends # 清空数据
}
注意
目前SystemTap并不能很好的分析go/golang程序，会极大概率的引起go/golang程序的崩溃，因此推荐使用bcc来 分析go/golang程序。
BCC
如果我们要分析go/golang程序时，我们就需要bcc，该工具也是一众大神最近 几年搞出来的新工具，利用linux的eBPF功能，因此需要使用linux 3.15+/4.1+。
因此我们需要先升级内核再安装bcc。
安装
使用
安装bcc后，各个工具默认安装路径为/usr/share/bcc/tools/
分析函数耗时我们可以使用/usr/share/bcc/tools/funclatency，执行命令:
./funclatency '/data1/vintage_rd/vintage_new:git*storage.\(*store\).Get' -F -p 29878 -i 20
-F如果规则匹配到多个函数符号，则为每一个函数生成一个独立的直方图-p进程号-i 20每20秒输出一次结果-u时间单位为微秒'/data1/vintage_rd/vintage_new:github*storage.\(*store\).Get'为'程序路径:需要分析的函数符号'。
注意:此处有一个坑，”:”后的函数符号其实为一个正则表达式，但是作者为了方便linux系下熟悉glob表达式 的人使用，做了一个转换pattern = pattern.replace('*', '.*')。通常情况下写vfs_fstat*会被转为vfs_fstat.* 然后进行正则匹配。但是go/golang程序里，函数符号通常包含.*()这些在正则里的特殊字符，会出现一些问题。 因此有两种解决方案：
- 编辑使用的命令脚本(/usr/share/bcc/tools/funclatency)，删除其中的
pattern = pattern.replace('*', '.*')这句， 然后函数符号使用正常的正则表达式，例如用.*\(\*store\)\.Get来匹配”(*store).Get”结尾的这个函数符号。 - 根据原脚本中的转换规则来针对性的修改匹配规则，例如
.这个通常不需要转义，因为在正则里.可以匹配到’.’，*也不需要转义，因为*被转为.*也能匹配到’*‘，()必须要转义，否则会出错。因此可以使用*\(*store\).Get匹配 “.(*store).Get”结尾的函数符号，因为其会被转换为.*\(.*store\).Get。
其运行结果：
Function = git.xxx/storage.(*store).Get [29878]
usecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 0 | |
4 -> 7 : 0 | |
8 -> 15 : 1 |****************************************|
16 -> 31 : 1 |****************************************|
Function = git.xxx/storage.(*store).Get [29878]
usecs : count distribution
0 -> 1 : 0 | |
2 -> 3 : 0 | |
4 -> 7 : 0 | |
8 -> 15 : 1 |****************************************|
16 -> 31 : 1 |****************************************|
参考
浙公网安备 33010602011771号