systemtap调试技巧

1、安装

Centos

1.1 必要库

1
yum -y install elfutils、gcc、kernel-devel、kernel-debuginfo、yum-utils

1.2 yum安装

1
yum -y systemtap

Ubuntu

1.1 必要库

1
2
3
4
$ apt-get install build-essential
$ apt-get install gettext
$ apt-get install elfutils
$ apt-get install libdw-dev

1.2 源码安装

1
2
3
4
5
$ git clone git://sourceware.org/git/systemtap.git
$ cd systemtap
$ git checkout release-4.9
$ ./configure
$ make -j (getconf _NPROCESSORS_ONLN)

目前需要使用release4.9分支,安装完成后,在/usr/local/systemtap

2、入门

2.1、简介

SystemTap是一个Linux非常有用的调试(跟踪/探测)工具,常用于Linux内核或者应用程序的信息采集,需要编译时,指定-g选项,比如:获取一个函数里面运行时的变量、调用堆栈,甚至可以直接修改变量的值,对诊断性能或功能问题非常有帮助。SystemTap提供非常简单的命令行接口和很简洁的脚本语言,以及非常丰富的tapset和例子。

2.2、何时使用

定位(内核)函数位置
查看函数被调用时的调用堆栈、局部变量、参数
查看函数指针变量实际指的是哪个函数
查看代码的执行轨迹(哪些行被执行了)
查看内核或者进程的执行流程
调试内存泄露或者内存重复释放
统计函数调用次数
……

2.3、stap命令

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
stap [OPTIONS] FILENAME [ARGUMENTS]
stap [OPTIONS] - [ARGUMENTS]
stap [OPTIONS] –e SCRIPT [ARGUMENTS]

比较常用和有用的参数:
-e SCRIPT Run given script.
-l PROBE List matching probes.
-L PROBE List matching probes and local variables.
-g guru mode
-D NM=VAL emit macro definition into generated C code
-o FILE send script output to file, instead of stdout.
-x PID sets target() to PID
-T time set execute time
-G var=val set variable
-d object add trace object

2.4、staprun命令

1
staprun [OPTIONS] MODULE [MODULE-OPTIONS]

stap命令与staprun命令的区别在于:
stap命令的操作对象是stp文件或script命令等,而staprun命令的操作对象是编译生成的内核模块。

3、脚本语言

3.1、probe

“probe” <=> “探测”, 是SystemTap进行具体地收集数据的关键字。“probe point” 是probe动作的时机,也称探测点。也就是probe程序监视的某事件点,一旦侦测的事件触发了,则probe将从此处插入内核或者用户进程中。“probe handle” 是当probe插入内核或者用户进程后所做的具体动作。
probe用法:

1
probe probe-point { statement }

在Hello World例子中begin和end就是probe-point, statement就是该探测点的处理逻辑,在Hello World例子中statement只有一行print,statement可以是复杂的代码块。
探测点语法:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
kernel.function(PATTERN)
kernel.function(PATTERN).call
kernel.function(PATTERN).return
kernel.function(PATTERN).return.maxactive(VALUE)
kernel.function(PATTERN).inline
kernel.function(PATTERN).label(LPATTERN)
module(MPATTERN).function(PATTERN)
module(MPATTERN).function(PATTERN).call
module(MPATTERN).function(PATTERN).return.maxactive(VALUE)
module(MPATTERN).function(PATTERN).inline
kernel.statement(PATTERN)
kernel.statement(ADDRESS).absolute
module(MPATTERN).statement(PATTERN)
process(PROCESSPATH).function(PATTERN)
process(PROCESSPATH).function(PATTERN).call
process(PROCESSPATH).function(PATTERN).return
process(PROCESSPATH).function(PATTERN).inline
process(PROCESSPATH).statement(PATTERN)

PATTERN语法为:

1
2
func[@file]
func@file:linenumber

例如:
1
2
3
4
kernel.function("*init*")
module("ext3").function("*")
kernel.statement("*@kernel/time.c:296")
process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request")

在return探测点可以用$return获取该函数的返回值。
inline函数无法安装.return探测点,也无法用$return获取其返回值。

3.2 基本语法

SystemTap脚本语法比较简单,与C语言类似,只是每一行结尾”;”是可选的。主要语句如下:
if/else、while、for/foreach、break/continue、return、next、delete、try/catch
其中:
next:主要在probe探测点逻辑处理中使用,调用此语句时,立刻从调用函数中退出。不同于exit()的是,next只是退出当前的调用函数,而此SystemTap并没有终了,但exit()则会终止SystemTap。

3.3 变量

不需要明确声明变量类型,脚本语言会根据函数参数等自动判断变量是什么类型的。
局部变量:在声明的probe和block(”{ }“范围内的部分)内有效。
全局变量:用”global“声明的变量,在此SystemTap的整个动作过程中都有效。全局变量的声明位置没有具体要求。需要注意的是,全局变量默认有锁保护,使用过多会有性能损失,如果用全局变量保存指针,可能出现指针所指的内容被进程修改,在探测点中拿不到真正的数据。
获取进程中的变量(全局变量、局部变量、参数)直接在变量名前面加$即可。

3.4 注释

1
2
3
# ...... : Shell语言风格    
//...... : C++语言风格
/*......*/ : C语言风格

3.5 运算符

比较运算符、算数运算符基本上与C语言一样,需要特别指出的是:
(1)、.操作符:连接两个字符串,类似于php;
(2)、=~和!~:正则匹配和正则不匹配;

3.6 函数

函数的例子

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
function indent:string (delta:long){
return _generic_indent(-1, "", delta)
}

function _generic_indent (idx, desc, delta)
{
ts = __indent_timestamp ()
if (! _indent_counters[idx]) _indent_timestamps[idx] = ts
depth = _generic_indent_depth(idx, delta)
return sprintf("%6d (%d:%d) %s:%-*s", (ts - _indent_timestamps[idx]), depth, delta, desc, depth, "")
}

function strlen:long(s:string) %{
STAP_RETURN(strlen(STAP_ARG_s));
%}

官方有很多很有用的函数,详情请参考:https://sourceware.org/systemtap/tapsets/
以及在本机安装了SystemTap之后在目录/usr/local/share/systemtap/tapset/下也可以看具体函数的实现以及一些奇特的用法。

3.7、技巧

3.7.1、定位函数位置

在一个大型项目中找出函数在哪里定义有时很有用,特别是一些比较难找出在哪里定义的函数,比如内核或者glibc中的某个函数想要看其实现时,首先得找出其在哪个文件的哪一行定义,用SystemTap一行命令就可以搞定。
比如要看printf在glibc中哪里定义的:

1
2
root@j9 ~# stap -l 'kernel.function("sys_recv")'
kernel.function("sys_recv@/build/buildd/linux-lts-trusty-3.13.0/net/socket.c:1868")

可以看出recv是在socket.c第1868行定义的。
甚至可以*号来模糊查找:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
root@j9 ~# stap -l 'kernel.function("*recv")'   
kernel.function("__audit_mq_sendrecv@/build/buildd/linux-lts-trusty-3.13.0/kernel/auditsc.c:2062")
kernel.function("audit_mq_sendrecv@/build/buildd/linux-lts-trusty-3.13.0/include/linux/audit.h:263")
kernel.function("compat_sys_recv@/build/buildd/linux-lts-trusty-3.13.0/net/compat.c:762")
kernel.function("i2c_master_recv@/build/buildd/linux-lts-trusty-3.13.0/drivers/i2c/i2c-core.c:1827")
kernel.function("ip_cmsg_recv@/build/buildd/linux-lts-trusty-3.13.0/net/ipv4/ip_sockglue.c:147")
kernel.function("kgdb_tty_recv@/build/buildd/linux-lts-trusty-3.13.0/drivers/tty/serial/kgdb_nmi.c:109")
kernel.function("ppp_do_recv@/build/buildd/linux-lts-trusty-3.13.0/drivers/net/ppp/ppp_generic.c:1617")
kernel.function("scm_recv@/build/buildd/linux-lts-trusty-3.13.0/include/net/scm.h:109")
kernel.function("sys_recv@/build/buildd/linux-lts-trusty-3.13.0/net/socket.c:1868")
kernel.function("tcp_event_data_recv@/build/buildd/linux-lts-trusty-3.13.0/net/ipv4/tcp_input.c:615")
kernel.function("tcp_splice_data_recv@/build/buildd/linux-lts-trusty-3.13.0/net/ipv4/tcp.c:637")
kernel.function("tpm_tis_recv@/build/buildd/linux-lts-trusty-3.13.0/drivers/char/tpm/tpm_tis.c:231")
kernel.function("try_fill_recv@/build/buildd/linux-lts-trusty-3.13.0/drivers/net/virtio_net.c:615")

同理,也可以用来定位用户进程的函数位置:
比如tengine的文件ngx_shmem.c里面为了兼容各个操作系统而实现了三个版本的ngx_shm_alloc,用#if (NGX_HAVE_MAP_ANON)、#elif (NGX_HAVE_MAP_DEVZERO)、#elif (NGX_HAVE_SYSVSHM)、#endif来做条件编译,那怎么知道编译出来的是哪个版本呢,用SystemTap的话就很简单了,否则要去grep一下这几宏有没有定义才知道了。

1
2
[root@cache4 tengine]# stap -l 'process("/home/admin/tengine/bin/nginx").function("ngx_shm_alloc")'
process("/home/admin/tengine/bin/nginx").function("ngx_shm_alloc@src/os/unix/ngx_shmem.c:15")

3.7.2 查看可用探测点以及该探测点上可用的变量

在一些探测点上能获取的变量比较有限,这是因为这些变量可能已经被编译器优化掉了,优化掉的变量就获取不到了。一般先用-L参数来看看有哪些变量可以直接使用:

1
2
[root@cache4 tengine]# stap -L 'process("/home/admin/tengine/bin/nginx").function("ngx_shm_alloc")' 
process("/home/admin/tengine/bin/nginx").function("ngx_shm_alloc@src/os/unix/ngx_shmem.c:15") $shm:ngx_shm_t*

可见在该探测点上可以直接使用$shm这个变量,其类型是ngx_shm_t*。
statement探测点也类似:
1
2
3
4
5
[root@cache4 tengine]# stap -L 'process("/home/admin/tengine/bin/nginx").statement("ngx_pcalloc@src/core/ngx_palloc.c:*")'                   
process("/home/admin/tengine/bin/nginx").statement("ngx_pcalloc@src/core/ngx_palloc.c:395") $pool:ngx_pool_t* $size:size_t
process("/home/admin/tengine/bin/nginx").statement("ngx_pcalloc@src/core/ngx_palloc.c:398") $pool:ngx_pool_t* $size:size_t
process("/home/admin/tengine/bin/nginx").statement("ngx_pcalloc@src/core/ngx_palloc.c:399") $size:size_t
process("/home/admin/tengine/bin/nginx").statement("ngx_pcalloc@src/core/ngx_palloc.c:404") $size:size_t $p:void*

可以直接使用这些探测点

3.7.3 输出调用堆栈

用户态探测点堆栈:print_ubacktrace()、sprint_ubacktrace()
内核态探测点堆栈:print_backtrace()、sprint_backtrace()
不带s和带s的区别是前者直接输出,后者是返回堆栈字符串。
这几个函数非常有用,在排查问题时可以根据一些特定条件来过滤函数被执行时是怎么调用进来的,比如排查tengine返回5xx时的调用堆栈是怎样的:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
#cat debug_tengine_5xx.stp 
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_finalize_request").call {
if ($rc >= 500) {
printf("rc: %d\n", $rc)
print_ubacktrace()
}
}

#stap debug_tengine_5xx.stp
rc: 502
0x49af2e : ngx_http_finalize_request+0xe/0x480 [/home/admin/tengine/bin/nginx]
0x543305 : ngx_http_video_flv_send_rest+0xf5/0x380 [/home/admin/tengine/bin/nginx]
0x543187 : ngx_http_video_finalize_request+0x57/0xe0 [/home/admin/tengine/bin/nginx]
0x49828f : ngx_http_terminate_request+0x4f/0xc0 [/home/admin/tengine/bin/nginx]
0x49b760 : ngx_http_test_reading+0x50/0x130 [/home/admin/tengine/bin/nginx]
0x49779f : ngx_http_request_handler+0x1f/0x40 [/home/admin/tengine/bin/nginx]
0x47ea8f : ngx_epoll_process_events+0x2df/0x330 [/home/admin/tengine/bin/nginx]
0x4753f9 : ngx_process_events_and_timers+0x69/0x1c0 [/home/admin/tengine/bin/nginx]
0x47d4d8 : ngx_worker_process_cycle+0x138/0x260 [/home/admin/tengine/bin/nginx]
0x47a38a : ngx_spawn_process+0x1ca/0x5e0 [/home/admin/tengine/bin/nginx]
0x47c73c : ngx_start_worker_processes+0x7c/0x100 [/home/admin/tengine/bin/nginx]
0x47db5f : ngx_master_process_cycle+0x3af/0x9b0 [/home/admin/tengine/bin/nginx]
0x45a740 : main+0xa90/0xb50 [/home/admin/tengine/bin/nginx]
0x3623e1ecdd [/lib64/libc-2.12.so+0x1ecdd/0x38d000]

比如看看内核是怎么收包的:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
root@jusse ~# cat netif_receive_skb.stp 
probe kernel.function("netif_receive_skb")
{
printf("--------------------------------------------------------\n");
print_backtrace();
printf("--------------------------------------------------------\n");
}
root@jusse ~# stap netif_receive_skb.stp
--------------------------------------------------------
0xffffffff8164dc00 : netif_receive_skb+0x0/0x90 [kernel]
0xffffffff8164e280 : napi_gro_receive+0xb0/0x130 [kernel]
0xffffffff81554537 : handle_incoming_queue+0xe7/0x100 [kernel]
0xffffffff815555d9 : xennet_poll+0x279/0x430 [kernel]
0xffffffff8164ee09 : net_rx_action+0x139/0x250 [kernel]
0xffffffff810702cd : __do_softirq+0xdd/0x300 [kernel]
0xffffffff8107088e : irq_exit+0x11e/0x140 [kernel]
0xffffffff8144e785 : xen_evtchn_do_upcall+0x35/0x50 [kernel]
0xffffffff8176c9ed : xen_hvm_callback_vector+0x6d/0x80 [kernel]
--------------------------------------------------------

3.7.4 获取函数参数

一些被编译器优化掉的函数参数用-L去看的时候没有找到,这样的话在探测点里面也不能直接用$方式获取该参数变量,这时可以使用SystemTap提供的_arg函数接口,是根据类型指定的,比如pointer_arg是获取指针类型参数,int_arg是获取整型参数,类似的还有long_arg、longlong_arg、uint_arg、ulong_arg、ulonglong_arg、s32_arg、s64_arg、u32_arg、u64_arg:

1
2
3
4
5
6
7
8
9
10
11
12
13
root@j9 ~# stap -L 'kernel.function("sys_open")' 
kernel.function("SyS_open@/build/buildd/linux-lts-trusty-3.13.0/fs/open.c:1011") $ret:long int
root@j9 ~# cat sys_open.stp
probe kernel.function("sys_open").call
{
printf("filename: %p(%s), flags: %d, mode: %x\n", pointer_arg(1), kernel_string(pointer_arg(1)), int_arg(2), int_arg(3));
}
root@j9 ~# stap sys_open.stp
filename: 0xc2081d2120(/proc/stat), flags: 524288, mode: 0
filename: 0x7facec00e838(/root/opt/libexec/systemtap/stapio), flags: 0, mode: 1b6
filename: 0x2219488(/var/log/auth.log), flags: 0, mode: 1b6
filename: 0x7facec00e838(/root/opt/libexec/systemtap/stapio), flags: 0, mode: 1b6
filename: 0x7fad10172c29(/etc/passwd), flags: 524288, mode: 1b6

这两个函数的参数完全兼容,只是第二个参数命名不一样而已,可以像下面这么用:
1
2
3
4
5
6
7
8
#cat debug_tengine_5xx.stp 
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_finalize_request").call, process("/home/admin/tengine/bin/nginx").function("ngx_http_special_response_handler").call {
rc = int_arg(2)
if (rc >= 500) {
printf("rc: %d\n", rc)
print_ubacktrace()
}
}

3.7.5 获取全局变量

有时候用$可以直接获取到全局变量,但有时候又获取不到,那可以试试@var:
比如获取nginx的全局变量ngx_cycyle:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
root@j9 ~# cat get_ngx_cycle.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_process_events_and_timers").call {
printf("ngx_cycle->connections: %d\n", $ngx_cycle->connections)
exit()
}

root@j9 ~# stap get_ngx_cycle.stp
semantic error: while processing probe process("/home/admin/tengine/bin/nginx").function("ngx_process_events_and_timers@src/event/ngx_event.c:225").call from: process("/home/admin/tengine/bin/nginx").function("ngx_process_events_and_timers").call

semantic error: unable to find local 'ngx_cycle', [man error::dwarf] dieoffset 0x73ca8 in /home/admin/tengine/bin/nginx, near pc 0x434152 in ngx_process_events_and_timers src/event/ngx_event.c (alternatives: $cycle, $delta, $timer, $flags)): identifier '$ngx_cycle' at get_ngx_cycle.stp:3:44
source: printf("ngx_cycle->connections: %d\n", $ngx_cycle->connections)
^

Pass 2: analysis failed. [man error::pass2]

root@j9 ~# cat get_ngx_cycle.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_process_events_and_timers").call {
ngx_cycle = @var("ngx_cycle@src/core/ngx_cycle.c")
printf("ngx_cycle->connections: %d\n", ngx_cycle->connections)
exit()
}

root@j9 ~# stap get_ngx_cycle.stp
ngx_cycle->connections: 19507312

3.7.6 获取数据结构成员用法

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
#cat get_http_uri.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request").call {
printf("r->uri.len: %d, r->uri.data: %p\n", $r->uri.len, $r->uri.data)
}
#stap get_http_uri.stp
WARNING: never-assigned local variable 'len' (similar: data): identifier 'len' at get_http_uri.stp:2:57
source: printf("r->uri.len: %d, r->uri.data: %p\n", $r->uri.len, $r->uri.data)
^
WARNING: never-assigned local variable 'data' (similar: len): identifier 'data' at :2:70
source: printf("r->uri.len: %d, r->uri.data: %p\n", $r->uri.len, $r->uri.data)
^
semantic error: invalid operator: operator '.' at :2:56
source: printf("r->uri.len: %d, r->uri.data: %p\n", $r->uri.len, $r->uri.data)
^

semantic error: type mismatch: expected long but found string: operator '.' at :2:56
source: printf("r->uri.len: %d, r->uri.data: %p\n", $r->uri.len, $r->uri.data)
^

Pass 2: analysis failed. [man error::pass2]

#cat get_http_uri.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request").call {
printf("r->uri.len: %d, r->uri.data: %p\n", $r->uri->len, $r->uri->data)
}

#stap get_http_uri.stp
r->uri.len: 1, r->uri.data: 0x1276f94
r->uri.len: 1, r->uri.data: 0x11d5fc4
r->uri.len: 1, r->uri.data: 0x124fd24
^C

3.7.7 输出整个数据结构

SystemTap有两个语法可以输出整个数据结构:在变量的后面加一个或者两个$即可,例子如下:

1
2
3
4
5
6
7
#cat get_r_pool.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request").call {
printf("$r->pool$: %s\n$r->pool$$: %s\n", $r->pool$, $r->pool$$)
}
#stap get_r_pool.stp
$r->pool$: {.d={...}, .max=4016, .current=0x161acd0, .chain=0x0, .large=0x0, .cleanup=0x0, .log=0x161c690}
$r->pool$$: {.d={.last="a", .end="", .next=0x1617650, .failed=0}, .max=4016, .current=0x161acd0, .chain=0x0, .large=0x0, .cleanup=0x0, .log=0x161c690}

其中r->pool的结构如下:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
typedef struct {
u_char *last;
u_char *end;
ngx_pool_t *next;
ngx_uint_t failed;
} ngx_pool_data_t;

struct ngx_pool_s {
ngx_pool_data_t d;
size_t max;
ngx_pool_t *current;
ngx_chain_t *chain;
ngx_pool_large_t *large;
ngx_pool_cleanup_t *cleanup;
ngx_log_t *log;
#if (NGX_DEBUG_POOL)
size_t size;
ngx_pool_stat_t *stat;
#endif
};

ngx_pool_s包含了结构ngx_pool_data_t。变量后面加和$的区别是后者展开了里面的结构而前者不展开,此用法只输出基本数据类型的值。

3.7.8 输出字符串指针

用户态使用:user_string、user_string_n
内核态使用:kernel_string、kernel_string_n、user_string_quoted

1
2
3
4
5
6
7
8
9
#cat get_http_uri.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request").call {
printf("r->uri: %s\nr->uri(n): %s\n", user_string($r->uri->data), user_string_n($r->uri->data, $r->uri->len))
}

#stap get_http_uri.stp
r->uri: /?id=1 HTTP/1.1
User-Agent
r->uri(n): /

user_string_quoted是获取用户态传给内核的字符串,代码中一般有__user宏标记:
1
2
3
4
5
6
7
8
9
#cat sys_open.stp
probe kernel.function("sys_open")
{
printf("filename: %s\n", user_string_quoted(pointer_arg(1)));
}
#stap sys_open.stp
filename: "/var/log/auth.log"
filename: "/proc/stat"
filename: "/proc/uptime"

3.7.9 指针类型转换

SystemTap提供@cast来实现指针类型转换,比如可以将void *转成自己需要的类型

1
2
3
4
5
6
7
8
9
10
11
12
#cat get_c_fd.stp 
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request_line").call {
printf("c->fd: %d\n", @cast($rev->data, "ngx_connection_t")->fd)
}

#stap get_c_fd.stp
c->fd: 3
c->fd: 28
c->fd: 30
c->fd: 32
c->fd: 34
^C

3.7.10 定义某个类型的变量

同样是用@cast,定义一个变量用来保存其转换后的地址即可,用法如下:

1
2
3
4
5
6
7
8
9
10
11
#cat get_c.stp 
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request_line").call {
c = &@cast($rev->data, "ngx_connection_t")
printf("c->fd: %d, c->requests: %d\n", c->fd, c->requests)
}

#stap get_c.stp
c->fd: 3, c->requests: 1
c->fd: 28, c->requests: 1
c->fd: 30, c->requests: 1
^C

3.7.11 多级指针用法

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
root@j9 ~# cat cc_multi_pointer.c
#include <stdio.h>

struct test {
int count;
};

int main(int argc, char *argv[])
{
struct test t = {.count = 5566};
struct test *pt = &t;
struct test **ppt = &pt;

printf("t.count: %d, pt->count: %d, ppt->count: %d\n", t.count, pt->count, (*ppt)->count);

return 0;
}

root@j9 ~# gcc -Wall -g -o cc_multi_pointer ./cc_multi_pointer.c

root@j9 ~# cat cc_multi_pointer.stp
probe process("./cc_multi_pointer").statement("main@./cc_multi_pointer.c:13")
{
printf("$t->count: %d, $pt->count: %d, $ppt->count: %d", $t->count, $pt->count, $ppt[0]->count);
}

root@j9 ~# ./cc_multi_pointer
t.count: 5566, pt->count: 5566, ppt->count: 5566

root@j9 ~# stap ./cc_multi_pointer.stp -c './cc_multi_pointer'
t.count: 5566, pt->count: 5566, ppt->count: 5566
$t->count: 5566, $pt->count: 5566, $ppt->count: 5566

简言之:通过[0]去解引用即可

3.7.12 遍历C语言数组

下面是在nginx处理请求关闭时遍历请求头的例子:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
#cat debug_http_header.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_finalize_request").call {
i = 0
headers_in_part = &$r->headers_in->headers->part
headers = &@cast(headers_in_part->elts, "ngx_table_elt_t")[0]
while (headers) {
if (i >= headers_in_part->nelts) {
if (!headers_in_part->next) {
break
}
headers_in_part = headers_in_part->next;
headers = &@cast(headers_in_part->elts, "ngx_table_elt_t")[0]
i = 0
}
h = &@cast(headers, "ngx_table_elt_t")[i]
printf("%s: %s\n", user_string_n(h->key->data, h->key->len), user_string_n(h->value->data, h->value->len))
i += 1
}
}

#stap debug_http_header.stp
User-Agent: curl/7.29.0
Host: 127.0.0.1:20090
Accept: */*

3.7.13 查看函数指针所指的函数名

获取一个地址所对应的符号:
用户态:usymname
内核态:symname

1
2
3
4
5
6
7
8
9
#cat get_c_handler.stp
probe process("/home/admin/tengine/bin/nginx").function("ngx_http_process_request_line").call {
c = &@cast($rev->data, "ngx_connection_t")
printf("c->read->handlers: %s, c->write->handler: %s\n", usymname(c->read->handler), usymname(c->write->handler))
}

#stap get_c_handler.stp
c->read->handlers: ngx_http_process_request_line, c->write->handler: ngx_http_empty_handler
^C

3.7.14 修改进程中的变量

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
root@j9 ~# cat stap_set_var.c -n     
1 #include <stdio.h>
2
3 typedef struct policy {
4 int id;
5 } policy_t;
6
7 int main(int argc, char *argv[])
8 {
9 policy_t policy;
10 policy_t *p = &policy;
11 policy_t **pp;
12
13 p->id = 111;
14
15 printf("before stap set, p->id: %d\n", p->id);
16
17 pp = &p;
18
19 printf("after stap set, p->id: %d, (*pp)->id: %d\n", p->id, (*pp)->id);
20
21 return 0;
22 }

root@j9 ~# gcc -Wall -g -o ./stap_set_var ./stap_set_var.c

root@j9 ~# cat stap_set_var.stp
probe process("./stap_set_var").statement("main@./stap_set_var.c:17")
{
$p->id = 222;
printf("$p$: %s\n", $p$)
}

root@j9 ~# stap -g stap_set_var.stp -c ./stap_set_var
before stap set, p->id: 111
after stap set, p->id: 222, (*pp)->id: 222
$p$: {.id=222}

可以看出在第17行用SystemTap修改后的值在第19行就生效了。
需要注意的是stap要加-g参数在guru模式下才能修改变量的值。

3.7.15 跟踪进程执行流程

thread_indent(n): 补充空格
ppfunc(): 当前探测点所在的函数
在call探测点调用thread_indent(4)补充4个空格,在return探测点调用thread_indent(-4)回退4个空格,效果如下:

1
2
3
4
5
6
7
8
9
10
#cat trace_nginx.stp
probe process("/home/admin/tengine/bin/nginx").function("*@src/http/ngx_http_*").call
{
printf("%s -> %s\n", thread_indent(4), ppfunc());
}

probe process("/home/admin/tengine/bin/nginx").function("*@src/http/ngx_http_*").return
{
printf("%s <- %s\n", thread_indent(-4), ppfunc());
}

3.7.16 查看代码执行路径

pp(): 输出当前被激活的探测点

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
 
#cat ngx_http_process_request.stp
probe process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:*") {
printf("%s\n", pp())
}

#stap ngx_http_process_request.stp
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2762")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2768")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2771")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2773")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2774")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2783")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2835")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2840")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2841")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2842")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2843")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2846")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2847")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2848")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2850")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2852")
process("/home/admin/tengine/bin/nginx").statement("ngx_http_process_request@src/http/ngx_http_request.c:2853")
^C

可以看出该函数哪些行被执行了

3.7.17 巧用正则匹配过滤

在排查问题时,可以利用一些正则匹配来获取自己想要的信息,比如下面是只收集*.j9.com的堆栈:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
#
cat debug_tengine_5xx.stp
probe process("/home/admin/tengine/bin/t-coresystem-tengine-cdn").function("ngx_http_finalize_request").call {
rc = $rc
if (rc < 0) {
host = "(null)"
if ($r->headers_in->server->len != 0) {
host = user_string_n($r->headers_in->server->data, $r->headers_in->server->len)
} else {
cscf = &@cast($r->srv_conf, "ngx_http_core_srv_conf_t")[@var("ngx_http_core_module@src/http/ngx_http_core_module.c")->ctx_index]
if (cscf->server_name->len != 0) {
host = user_string_n(cscf->server_name->data, cscf->server_name->len)
}
}

if (host =~ ".*\.j9\.com") {
printf("rc: %d, host: %s\n", rc, host)
print_ubacktrace()
}
}

ss#stap debug_tengine_5xx.stp
WARNING: Missing unwind data for module, rerun with 'stap -d /lib64/libc-2.12.so'
rc: -4, host: www.j9.com
0x49af2e : ngx_http_finalize_request+0xe/0x480 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x492eab : ngx_http_core_content_phase+0x2b/0x130 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x48e74d : ngx_http_core_run_phases+0x3d/0x50 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x514c3c : ngx_http_lua_socket_tcp_read+0x44c/0x590 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x513150 : ngx_http_lua_socket_tcp_handler+0x30/0x50 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x475b96 : ngx_event_process_posted+0x36/0x40 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47d4d8 : ngx_worker_process_cycle+0x138/0x260 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47a38a : ngx_spawn_process+0x1ca/0x5e0 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47c73c : ngx_start_worker_processes+0x7c/0x100 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47db5f : ngx_master_process_cycle+0x3af/0x9b0 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x45a740 : main+0xa90/0xb50 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x3623e1ecdd [/lib64/libc-2.12.so+0x1ecdd/0x38d000]
rc: -4, host: cdn.j9.com
0x49af2e : ngx_http_finalize_request+0xe/0x480 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x492eab : ngx_http_core_content_phase+0x2b/0x130 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x48e74d : ngx_http_core_run_phases+0x3d/0x50 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x514c3c : ngx_http_lua_socket_tcp_read+0x44c/0x590 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x513150 : ngx_http_lua_socket_tcp_handler+0x30/0x50 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x475b96 : ngx_event_process_posted+0x36/0x40 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47d4d8 : ngx_worker_process_cycle+0x138/0x260 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47a38a : ngx_spawn_process+0x1ca/0x5e0 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47c73c : ngx_start_worker_processes+0x7c/0x100 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x47db5f : ngx_master_process_cycle+0x3af/0x9b0 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x45a740 : main+0xa90/0xb50 [/home/admin/tengine/bin/t-coresystem-tengine-cdn]
0x3623e1ecdd [/lib64/libc-2.12.so+0x1ecdd/0x38d000]
}




3.7.18 关联数组用法

SystemTap的关联数组必须是全局变量,需要用global进行声明,其索引可以支持多达9项索引域,各域间以逗号隔开。支持 =, ++ 与 +=操作,其默认的初始值为0。
例如:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
root@j9 ~# cat stap_array.stp 
global reads
probe vfs.read {
reads[execname(), pid()] ++
}
probe timer.s(3) {
foreach ([execname, pid] in reads) {
printf("%s(%d) : %d \n", execname, pid, reads[execname, pid])
}
print("============================\n")
delete reads
}

root@j9 ~# stap stap_array.stp
stapio(18716) : 16
rsyslogd(770) : 1
docker(743) : 3
IFSWatch(5594) : 30
QThread(5594) : 6
AliYunDunUpdate(1057) : 4
sshd(15118) : 1
sshd(15191) : 1
============================
stapio(18716) : 16
sshd(15191) : 3
docker(743) : 3
IFSWatch(5594) : 30
sshd(15118) : 2
QThread(5594) : 12
AliYunDunUpdate(1057) : 8
============================
^C
root@j9 ~/systemtap#

也可以用+、-进行排序:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
root@j9 ~# cat stap_array.stp
global reads
probe vfs.read {
reads[execname(), pid()] ++
}
probe timer.s(3) {
foreach ([execname, pid+] in reads) {
printf("%s(%d) : %d \n", execname, pid, reads[execname, pid])
}
print("============================\n")
delete reads
}

root@j9 ~# stap stap_array.stp
docker(743) : 3
rsyslogd(770) : 1
AliYunDunUpdate(1057) : 12
IFSWatch(5594) : 30
QThread(5594) : 12
sshd(15118) : 2
sshd(15191) : 2
stapio(19021) : 16
============================
docker(743) : 3
AliYunDunUpdate(1057) : 12
IFSWatch(5594) : 30
QThread(5594) : 6
sshd(15118) : 1
sshd(15191) : 19
stapio(19021) : 16
============================
^C
root@j9 ~#

3.7.19 调试内存泄漏以及内存重复释放

在return探测点,使用函数入参需要@entry

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
probe begin {
printf("=============begin============\n")
}

//记录内存分配和释放的计数关联数组
global g_mem_ref_tbl
//记录内存分配和释放的调用堆栈关联数组,以内存地址作为key
global g_mem_bt_tbl

probe process("/lib/x86_64-linux-gnu/libc.so.6").function("__libc_malloc").return, process("/lib/x86_64-linux-gnu/libc.so.6").function("__libc_calloc").return {
if (target() == pid()) {
if (g_mem_ref_tbl[$return] == 0) {
g_mem_ref_tbl[$return]++
g_mem_bt_tbl[$return] = sprint_ubacktrace()
}
}
}
//$mem是__libc_free的参数
probe process("/lib/x86_64-linux-gnu/libc.so.6").function("__libc_free").call {
if (target() == pid()) {
g_mem_ref_tbl[$mem]--

if (g_mem_ref_tbl[$mem] == 0) {
if ($mem != 0) {
//记录上次释放的调用堆栈
g_mem_bt_tbl[$mem] = sprint_ubacktrace()
}
} else if (g_mem_ref_tbl[$mem] < 0 && $mem != 0) {
//如果调用free已经失衡,那就出现了重复释放内存的问题,这里输出当前调用堆栈,以及这个地址上次释放的调用堆栈
printf("MMMMMMMMMMMMMMMMMMMMMMMMMMMM\n")
printf("g_mem_ref_tbl[%p]: %d\n", $mem, g_mem_ref_tbl[$mem])
print_ubacktrace()
printf("last free backtrace:\n%s\n", g_mem_bt_tbl[$mem])
printf("WWWWWWWWWWWWWWWWWWWWWWWWWWWW\n")
}
}
}

probe end {
//最后输出产生泄漏的内存是在哪里分配的
printf("=============end============\n")
foreach(mem in g_mem_ref_tbl) {
if (g_mem_ref_tbl[mem] > 0) {
printf("%s\n", g_mem_bt_tbl[mem])
printf("--------------------------------\n")
}
}
}

3.7.20 嵌入C代码

在进程fork出子进程时打印出进程id和进程名:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
root@jusse ~/systemtap# cat copy_process.stp
function getprocname:string(task:long)
%{
struct task_struct *task = (struct task_struct *)STAP_ARG_task;
snprintf(STAP_RETVALUE, MAXSTRINGLEN, "pid: %d, comm: %s", task->pid, task->comm);
%}

function getprocid:long(task:long)
%{
struct task_struct *task = (struct task_struct *)STAP_ARG_task;
STAP_RETURN(task->pid);
%}

probe kernel.function("copy_process").return
{
printf("copy_process return: %p, pid: %d, getprocname: %s, getprocid: %d\n", $return, $return->pid, getprocname($return), getprocid($return));
}

root@jusse ~/systemtap# stap -g copy_process.stp
copy_process return: 0xffff880039f61800, pid: 12212, getprocname: pid: 12212, comm: bash, getprocid: 12212
copy_process return: 0xffff880039f61800, pid: 12212, getprocname: pid: 12212, comm: bash, getprocid: 12212
copy_process return: 0xffff880039f63000, pid: 12213, getprocname: pid: 12213, comm: cc_epoll, getprocid: 12213
copy_process return: 0xffff880039f63000, pid: 12213, getprocname: pid: 12213, comm: cc_epoll, getprocid: 12213
copy_process return: 0xffff8800081a9800, pid: 12214, getprocname: pid: 12214, comm: cc_epoll, getprocid: 12214
copy_process return: 0xffff8800081a9800, pid: 12214, getprocname: pid: 12214, comm: cc_epoll, getprocid: 12214
copy_process return: 0xffff8800004d8000, pid: 12215, getprocname: pid: 12215, comm: cc_epoll, getprocid: 12215
copy_process return: 0xffff8800004d8000, pid: 12215, getprocname: pid: 12215, comm: cc_epoll, getprocid: 12215
copy_process return: 0xffff880000564800, pid: 12216, getprocname: pid: 12216, comm: cc_epoll, getprocid: 12216
copy_process return: 0xffff880000564800, pid: 12216, getprocname: pid: 12216, comm: cc_epoll, getprocid: 12216
copy_process return: 0xffff880000566000, pid: 12217, getprocname: pid: 12217, comm: cc_epoll, getprocid: 12217
copy_process return: 0xffff880000566000, pid: 12217, getprocname: pid: 12217, comm: cc_epoll, getprocid: 12217

有三个需要注意的地方:
1)、SystemTap脚本里面嵌入C语言代码要在每个大括号前加%前缀,是%{…… %} 而不是%{ …… }%;
2)、获取脚本函数参数要用STAP_ARG_前缀;
3)、一般long等返回值用STAP_RETURN,而string类型返回值要用snprintf、strncat等方式把字符串复制到STAP_RETVALUE里面。

3.7.21 调试内核模块

这小节就不细讲了,这篇博客 (http://blog.chinaunix.net/uid-14528823-id-4726046.html) 写得很详细,这里只copy两个关键点过来记录一下:
要调试自己的内核模块,需要注意的有两个关键点:
1)、使用SystemTap调试内核模块,探测点的编写格式示例为:
module(“ext3”).function(“ext3_*”)
2)、需要将自己的模块cp到/lib/modules/uname -r/extra目录中,否则找不到符号,如果/lib/modules/uname -r/目录下没有extra这个目录,自己mkdir一下就可以。

3.7.22 一些错误提示及解决办法

错误提示1:

1
2
ERROR: MAXACTION exceeded near keyword at debug_connection.stp:86:9
ERROR: MAXACTION exceeded near operator '->' at debug_connection.stp:84:30

解决办法:
加上stap参数:-DMAXACTION=102400,如果还报这种类型的错误,只需把102400调成更大的值即可。
错误提示2:
1
WARNING: Number of errors: 0, skipped probes: 82

解决办法:
加上-DMAXSKIPPED=102400和-DSTP_NO_OVERLOAD参数
还有一些可以去掉限制的宏:

MAXSTRINGLEN:这个宏会影响sprintf的buffer大小,默认为512字节。
MAXTRYLOCK:对全局变量进行try lock操作的次数,超过则次数还拿不到锁则放弃和跳过该探测点,默认值为1000.全局变量多的时候可以把这个宏开大一点。

3.7.23 传递参数

3.7.24 常用函数

本节来介绍systemtap中常用的一些函数
tid():当前线程ID。
uid():当前用户ID。
cpu():当前CPU编号。
ctime():当前UNIX epoch秒数。
pp():当前探测点的描述字符串
exit(): 执行一次后退出。
execname():当前运行的进程名称。
probefunc():探测点函数名称。
target():在stap使用-c command或者-x process命令时,target()能拿到进程的pid。
name():返回系统调用的名称字符串,仅能在syscall类型的探针处理函数中使用。
thread_indent(delta):它可以输出当前probe所处的可执行程序名称、线程id、函数执行的相对时间和执行的次数(通过空格的数量)信息,它的返回值就是一个字符串。参数delta是在每次调用时增加或移除的空白数量。
@defined和@choose_defined
由于版本变化,有一些变量可能在新版本中不存在了,此时可以使用@define来检查变量是否存在:

1
2
3
4
5
probe vm.pagefault = kernel.function("__handle_mm_fault@mm/memory.c") ?,
kernel.function("handle_mm_fault@mm/memory.c") ?
{
write_access = (@defined($flags) ? $flags & FAULT_FLAG_WRITE : $write_access)
}

@entry
在.return探针中,有一个特殊的操作符@entry,用于存储该探针的入口处的表达式的值,可以使用这个操作符,完成比如计算探针函数执行时间计算等工作,比如:
1
2
3
4
5
6
7
global sloth = 50

probe vfs.open.return {
time = gettimeofday_us()-@entry(gettimeofday_us())
if (time >= sloth)
printf("%s[%d] %d %s\n", execname(), tid(), time, pathname)
}

这个脚本在vfs.open.return探针处理函数中,通过@entry操作符,计算完成vfs.open操作的时间差,如果超过设置的阈值50就打印相关信息。
-G命令行参数,可以设置全局变量VAR的值为VAL,相应地就可以作为开关来控制脚本的行为,比如:
1
2
3
4
5
6
7
8
9
10
11
// sudo stap G-params.stp -G flag=1
// flag has set
global flag=0

probe begin {
if (flag == 0) {
printf("flag not set\n")
} else {
printf("flag has set\n")
}
}

3.7.25 异步事件

常见的异步事件是begin、end、never、timers。
timers用于定义定时器探测点,常见的格式timer.s(1)来定义每秒触发的探测点。
never定义的探测点不会被调用到,很多时候加这个探测点只是为了检查一些语法错误。