请教一个sample-bt-leaks工具生成火焰图报错的问题

sunsetmask

各位大神好！

最近公司的openresty worker进程老是内存暴增，动则增加到3g多，感觉是lua内存泄露的问题，尝试生成内存占用最大的worker的内存火焰图：

遇到如下错误：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt

Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"

Pass 1: parsed user script and 471 library scripts using 83656virt/50424res/4944shr/46200data kb, in 190usr/0sys/221real ms.

semantic error: while resolving probe point: identifier 'process' at <input>:17:7

source: probe process("/usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25").function("malloc").return,

semantic error: no match (similar functions: memcpy, memset, _fini, _init, _plug_buf_alloc)

semantic error: while resolving probe point: identifier 'process' at :18:7

source: process("/usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25").function("calloc").return,

semantic error: no match (similar functions: _fini, _init, _plug_buf_alloc, strcat, memcpy)

semantic error: while resolving probe point: identifier 'process' at :19:7

source: process("/usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25").function("realloc").return

semantic error: no match (similar functions: _fini, _init, _plug_buf_alloc, gettime, memcpy)

semantic error: while resolving probe point: identifier 'process' at :74:7

source: probe process("/usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25").function("free")

semantic error: no match (similar functions: _fini, memset, _init, gettime, strcat)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85512virt/53836res/6616shr/48056data kb, in 40usr/70sys/722real ms.

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

之前在libcrypto.so 中遇到了这个问题，然后通过安装openssl-dbgsym解决了，现在这个sasl2的我装了cyrus-sasl2-dbg但是并没有效果，不知道各位大佬是否碰到过此类问题？

Ubuntu下需要安装哪些包？或者有可能跳过这个库么？还望不吝赐教

# Ubuntu用systemtap有点难受。。。

- 线上环境： ubuntu server 14.04.5

- openresty 版本:

$ nginx -V

nginx version: openresty/1.11.2.1

built by gcc 4.8.4 (Ubuntu 4.8.4-2ubuntu1~14.04.3)

built with OpenSSL 1.0.1f 6 Jan 2014

TLS SNI support enabled

configure arguments: --prefix=/usr/local/openresty/nginx --with-cc-opt=-O2 --add-module=../ngx_devel_kit-0.3.0 --add-module=../echo-nginx-module-0.60 --add-module=../xss-nginx-module-0.05 --add-module=../ngx_coolkit-0.2rc3 --add-module=../set-misc-nginx-module-0.31 --add-module=../form-input-nginx-module-0.12 --add-module=../encrypted-session-nginx-module-0.06 --add-module=../srcache-nginx-module-0.31 --add-module=../ngx_lua-0.10.6 --add-module=../ngx_lua_upstream-0.06 --add-module=../headers-more-nginx-module-0.31 --add-module=../array-var-nginx-module-0.05 --add-module=../memc-nginx-module-0.17 --add-module=../redis2-nginx-module-0.13 --add-module=../redis-nginx-module-0.3.7 --add-module=../rds-json-nginx-module-0.14 --add-module=../rds-csv-nginx-module-0.07 --with-http_stub_status_module --with-http_sub_module --with-http_ssl_module

- sasl2的包安装情况（我都不知道这个包是拿来干嘛的

$ sudo dpkg -l | grep sasl2

ii cyrus-sasl2-dbg 2.1.25.dfsg1-17build1 amd64 Cyrus SASL - debugging symbols

ii cyrus-sasl2-mit-dbg 2.1.25.dfsg1-17build1 amd64 Cyrus SASL - debugging symbols for MIT modules

ii libsasl2-2:amd64 2.1.25.dfsg1-17build1 amd64 Cyrus SASL - authentication abstraction library

ii libsasl2-dev 2.1.25.dfsg1-17build1 amd64 Cyrus SASL - development files for authentication abstraction library

ii libsasl2-modules:amd64 2.1.25.dfsg1-17build1 amd64 Cyrus SASL - pluggable authentication modules

ii libsasl2-modules-db:amd64 2.1.25.dfsg1-17build1 amd64 Cyrus SASL - pluggable authentication modules (DB)

ii libsasl2-modules-gssapi-mit:amd64 2.1.25.dfsg1-17build1 amd64 Cyrus SASL - pluggable authentication modules (GSSAPI)

sunsetmask

如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt

Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.

semantic error: while resolving probe point: identifier 'process' at <input>:17:7

source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7

source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7

source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7

source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.

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

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

spacewanderlzx

可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：

如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

sunsetmask

感谢回复，刚上班，跑了下结果如下（这就是源文件了）：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 --dump-src

Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"

Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"

#!/usr/bin/env stap

# Copyright (C) Yichun Zhang (agentzh)

global ptr2bt

global ptr2size

global bt_stats

global quit

global free_misses

probe begin

{

warn(sprintf("Start tracing %d (/usr/local/openresty/nginx/sbin/nginx)...", target()))

warn("Wait for 5 sec to complete.\n")

}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,

process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,

process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return

{

if (pid() == target()) {

//printf("Hit %s\n", probefunc())

if (quit) {

if (free_misses) {

warn(sprintf("free misses: %d", free_misses))

}

foreach (bt in bt_stats) {

print_ustack(bt)

printf("\t%d\n", @sum(bt_stats[bt]))

}

exit()

} else {

if (@defined($oldmem)) {

//printf("free %p in realloc\n", $oldmem)

ptr = $oldmem

bt = ptr2bt[ptr]

delete ptr2bt[ptr]

bytes = ptr2size[ptr]

delete ptr2size[ptr]

bt_stats[bt] <<< -bytes

if (@sum(bt_stats[bt]) == 0) {

delete bt_stats[bt]

}

ptr = returnval()

if (ptr) {

// here we use a hack specific to glibc's implementation

// to get the size of the memory block because we

// may not get the value of the $bytes parameter reliably.

p = ptr - &@cast(0, "size_t")[1]

size = @cast(p, "size_t")[0] & ~(&@cast(0, "size_t")[1] - 1)

//printf("alloc: %p (bytes %d)\n", ptr, size)

bt = ubacktrace()

ptr2bt[ptr] = bt

ptr2size[ptr] = size

bt_stats[bt] <<< size

} else {

warn("NULL returned")

}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")

{

ptr = pointer_arg(1)

if (pid() == target() && ptr) {

//printf("free: %p\n", ptr)

bt = ptr2bt[ptr]

delete ptr2bt[ptr]

bytes = ptr2size[ptr]

delete ptr2size[ptr]

if (bt == "" && bytes == 0) {

free_misses++

} else {

bt_stats[bt] <<< -bytes

if (@sum(bt_stats[bt]) == 0) {

delete bt_stats[bt]

}

probe timer.s(5)

{

quit = 1

delete ptr2bt

delete ptr2size

}

我又跑了一次，但是似乎结果不一样了。。。

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt

Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"

Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"

Pass 1: parsed user script and 471 library scripts using 83660virt/50276res/4792shr/46204data kb, in 150usr/0sys/147real ms.

semantic error: while resolving probe point: identifier 'process' at <input>:17:7

source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,

semantic error: no match (similar functions: malloc, fputc, fflush, fileno, free)

semantic error: while resolving probe point: identifier 'process' at :18:7

source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,

semantic error: no match (similar functions: malloc, fcntl, fputc, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :19:7

source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return

semantic error: no match (similar functions: malloc, fputc, strerror, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :74:7

source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")

semantic error: no match (similar functions: free, fopen, fwrite, _fini, strlen)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85384virt/53552res/6432shr/47928data kb, in 20usr/40sys/63real ms.

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

再次感谢！

Zexuan Luo <spacew...@gmail.com>于2017年8月19日周六下午8:50写道：

可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：
如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

--

spacewanderlzx

你把 dump 下来的脚本里面的 /lib/x86_64-linux-gnu/libcom_err.so.2.1 换成 libc 的路径（可以通过 ldd $(which nginx) 获取，大致是 /path/to/libc.so.6 这样子的），然后直接运行修改后的脚本试试？
sxx 是 systemtap 模板，会被 stap++ 这个 perl 脚本展开成一个 systemtap 脚本。看样子是展开的时候逻辑有问题，原本应该展开成 libc 的路径，却变成了以 libc 开头的其他链接库。

2017-08-21 9:44 GMT+08:00 Dispensable <suns...@gmail.com>:

感谢回复，刚上班，跑了下结果如下（这就是源文件了）：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 --dump-src
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
#!/usr/bin/env stap

# Copyright (C) Yichun Zhang (agentzh)

global ptr2bt
global ptr2size
global bt_stats
global quit
global free_misses

probe begin
{
warn(sprintf("Start tracing %d (/usr/local/openresty/nginx/sbin/nginx)...", target()))
warn("Wait for 5 sec to complete.\n")
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
{
if (pid() == target()) {
//printf("Hit %s\n", probefunc())
if (quit) {
if (free_misses) {
warn(sprintf("free misses: %d", free_misses))
}

foreach (bt in bt_stats) {
print_ustack(bt)
printf("\t%d\n", @sum(bt_stats[bt]))
}

exit()

} else {
if (@defined($oldmem)) {
//printf("free %p in realloc\n", $oldmem)
ptr = $oldmem

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}

ptr = returnval()
if (ptr) {
// here we use a hack specific to glibc's implementation
// to get the size of the memory block because we
// may not get the value of the $bytes parameter reliably.

p = ptr - &@cast(0, "size_t")[1]
size = @cast(p, "size_t")[0] & ~(&@cast(0, "size_t")[1] - 1)

//printf("alloc: %p (bytes %d)\n", ptr, size)
bt = ubacktrace()
ptr2bt[ptr] = bt
ptr2size[ptr] = size
bt_stats[bt] <<< size

} else {
warn("NULL returned")
}
}
}
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
{
ptr = pointer_arg(1)
if (pid() == target() && ptr) {
//printf("free: %p\n", ptr)

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

if (bt == "" && bytes == 0) {
free_misses++

} else {
bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}
}
}

probe timer.s(5)
{
quit = 1
delete ptr2bt
delete ptr2size
}

我又跑了一次，但是似乎结果不一样了。。。

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
Pass 1: parsed user script and 471 library scripts using 83660virt/50276res/4792shr/46204data kb, in 150usr/0sys/147real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
^

semantic error: no match (similar functions: malloc, fputc, fflush, fileno, free)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
^

semantic error: no match (similar functions: malloc, fcntl, fputc, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
^

semantic error: no match (similar functions: malloc, fputc, strerror, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
^

semantic error: no match (similar functions: free, fopen, fwrite, _fini, strlen)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85384virt/53552res/6432shr/47928data kb, in 20usr/40sys/63real ms.
Pass 2: analysis failed. [man error::pass2]

再次感谢！

Zexuan Luo <spacew...@gmail.com>于2017年8月19日周六下午8:50写道：
可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：
如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

--

--

sunsetmask

感谢回复！

按照您的方法尝试了下，可以运行，但是程序会卡在wait for 5 sec to complete这里。尝试添加vv参数，输出如下：

$ sudo rm -rf ~/.systemtap/

$ sudo ./test_leak_modify.stap -vv -x 8001 -D STP_NO_OVERLOAD -D MAXMAPENTRIES=10000 > a.bt

focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)

probe __libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x82a80

focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)

probe __libc_calloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:3162 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83550

focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)

probe __libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83220

focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)

probe __libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83120

probe 1 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877").return') locks __global_ptr2bt[w] __global_ptr2size[w] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r]

probe 3 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").call') locks __global_entry_tvar_oldmem_0[w] __global_entry_tvar_oldmem_0_ctr[rw]

probe 4 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").return') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r] __global_entry_tvar_oldmem_0[rw] __global_entry_tvar_oldmem_0_ctr[rw]

probe 5 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913")') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_free_misses[rw]

dump_unwindsyms /lib/x86_64-linux-gnu/libc-2.19.so index=3 base=0x10000

Found build-id in /lib/x86_64-linux-gnu/libc-2.19.so, length 20, start at 0x280

$ sudo strace -p 20882

Process 20882 attached

restart_syscall(<... resuming interrupted call ...>

子进程:

$ sudo strace -p 20883

Process 20883 attached

wait4(22242,

5s是运行5s就结束还是说有请求才可以算作这个时间段内？现在这个进程的内存还没有明显增加的状态，上周末已经定位到了代码问题（业务逻辑代码），但是也只是数据量的问题，应该可以正常释放才对啊。

再次感谢～

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午10:09写道：

你把 dump 下来的脚本里面的 /lib/x86_64-linux-gnu/libcom_err.so.2.1 换成 libc 的路径（可以通过 ldd $(which nginx) 获取，大致是 /path/to/libc.so.6 这样子的），然后直接运行修改后的脚本试试？
sxx 是 systemtap 模板，会被 stap++ 这个 perl 脚本展开成一个 systemtap 脚本。看样子是展开的时候逻辑有问题，原本应该展开成 libc 的路径，却变成了以 libc 开头的其他链接库。

2017-08-21 9:44 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复，刚上班，跑了下结果如下（这就是源文件了）：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 --dump-src
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
#!/usr/bin/env stap

# Copyright (C) Yichun Zhang (agentzh)

global ptr2bt
global ptr2size
global bt_stats
global quit
global free_misses

probe begin
{
warn(sprintf("Start tracing %d (/usr/local/openresty/nginx/sbin/nginx)...", target()))
warn("Wait for 5 sec to complete.\n")
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
{
if (pid() == target()) {
//printf("Hit %s\n", probefunc())
if (quit) {
if (free_misses) {
warn(sprintf("free misses: %d", free_misses))
}

foreach (bt in bt_stats) {
print_ustack(bt)
printf("\t%d\n", @sum(bt_stats[bt]))
}

exit()

} else {
if (@defined($oldmem)) {
//printf("free %p in realloc\n", $oldmem)
ptr = $oldmem

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}

ptr = returnval()
if (ptr) {
// here we use a hack specific to glibc's implementation
// to get the size of the memory block because we
// may not get the value of the $bytes parameter reliably.

p = ptr - &@cast(0, "size_t")[1]
size = @cast(p, "size_t")[0] & ~(&@cast(0, "size_t")[1] - 1)

//printf("alloc: %p (bytes %d)\n", ptr, size)
bt = ubacktrace()
ptr2bt[ptr] = bt
ptr2size[ptr] = size
bt_stats[bt] <<< size

} else {
warn("NULL returned")
}
}
}
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
{
ptr = pointer_arg(1)
if (pid() == target() && ptr) {
//printf("free: %p\n", ptr)

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

if (bt == "" && bytes == 0) {
free_misses++

} else {
bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}
}
}

probe timer.s(5)
{
quit = 1
delete ptr2bt
delete ptr2size
}

我又跑了一次，但是似乎结果不一样了。。。

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
Pass 1: parsed user script and 471 library scripts using 83660virt/50276res/4792shr/46204data kb, in 150usr/0sys/147real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
^

semantic error: no match (similar functions: malloc, fputc, fflush, fileno, free)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
^

semantic error: no match (similar functions: malloc, fcntl, fputc, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
^

semantic error: no match (similar functions: malloc, fputc, strerror, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
^

semantic error: no match (similar functions: free, fopen, fwrite, _fini, strlen)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85384virt/53552res/6432shr/47928data kb, in 20usr/40sys/63real ms.
Pass 2: analysis failed. [man error::pass2]

再次感谢！

Zexuan Luo <spacew...@gmail.com>于2017年8月19日周六下午8:50写道：
可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：
如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

--

--

--

spacewanderlzx

5s之后又有请求才会触发退出。

2017-08-21 10:51 GMT+08:00 Dispensable <suns...@gmail.com>:

感谢回复！

按照您的方法尝试了下，可以运行，但是程序会卡在wait for 5 sec to complete这里。尝试添加vv参数，输出如下：

$ sudo rm -rf ~/.systemtap/
$ sudo ./test_leak_modify.stap -vv -x 8001 -D STP_NO_OVERLOAD -D MAXMAPENTRIES=10000 > a.bt

Kernel symbol table /lib/modules/4.4.0-31-generic/build/System.map unavailable, (No such file or directory)
Searched for library macro files: "/usr/local/share/systemtap/tapset/linux", found: 5, processed: 5
Searched for library macro files: "/usr/local/share/systemtap/tapset", found: 9, processed: 9
Searched: "/usr/local/share/systemtap/tapset/linux/x86_64", found: 22, processed: 22
Searched: "/usr/local/share/systemtap/tapset/linux", found: 406, processed: 406
Searched: "/usr/local/share/systemtap/tapset/x86_64", found: 1, processed: 1
Searched: "/usr/local/share/systemtap/tapset", found: 28, processed: 28
Pass 1: parsed user script and 471 library scripts using 83656virt/50412res/4952shr/46200data kb, in 180usr/20sys/199real ms.
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x82a80
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_calloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:3162 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83550
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83220
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83120
Running env -uARCH -uKBUILD_EXTMOD -uCROSS_COMPILE -uKBUILD_IMAGE -uKCONFIG_CONFIG -uINSTALL_PATH -uLD_LIBRARY_PATH PATH=/usr/bin:/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin make -C /lib/modules/4.4.0-31-generic/build M=/tmp/stapK86i0K/typequery_kmod_1 modules CONFIG_DEBUG_INFO= CONFIG_STACK_VALIDATION= ARCH=x86_64 --no-print-directory -j9
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
focused on module '/tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko' = [0x10000-0x10440, bias 0 file /tmp/stapK86i0K/typequery_kmod_1/typequery_kmod_1.ko ELF machine |x86_64 (code 62)
Pass 2: analyzed script: 8 probes, 17 functions, 7 embeds, 9 globals using 98620virt/66796res/6380shr/61164data kb, in 650usr/110sys/1209real ms.
Searching for vdso candidates: /lib/modules/4.4.0-31-generic/vdso
vdso candidate: /lib/modules/4.4.0-31-generic/vdso/vdso32.so
vdso candidate: /lib/modules/4.4.0-31-generic/vdso/vdso64.so
vdso candidate: /lib/modules/4.4.0-31-generic/vdso/vdsox32.so
probe 1 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877").return') locks __global_ptr2bt[w] __global_ptr2size[w] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r]
probe 3 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").call') locks __global_entry_tvar_oldmem_0[w] __global_entry_tvar_oldmem_0_ctr[rw]
probe 4 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").return') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r] __global_entry_tvar_oldmem_0[rw] __global_entry_tvar_oldmem_0_ctr[rw]
probe 5 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913")') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_free_misses[rw]
dump_unwindsyms /lib/modules/4.4.0-31-generic/vdso/vdso32.so index=0 base=0x10000
Found build-id in /lib/modules/4.4.0-31-generic/vdso/vdso32.so, length 20, start at 0x568
dump_unwindsyms /lib/modules/4.4.0-31-generic/vdso/vdso64.so index=1 base=0x10000
Found build-id in /lib/modules/4.4.0-31-generic/vdso/vdso64.so, length 20, start at 0x838
dump_unwindsyms /lib/modules/4.4.0-31-generic/vdso/vdsox32.so index=2 base=0x10000
Found build-id in /lib/modules/4.4.0-31-generic/vdso/vdsox32.so, length 20, start at 0x548
dump_unwindsyms /lib/x86_64-linux-gnu/libc-2.19.so index=3 base=0x10000
Found build-id in /lib/x86_64-linux-gnu/libc-2.19.so, length 20, start at 0x280
Pass 3: translated to C into "/tmp/stapK86i0K/stap_03e1cb4856cba70035242e3fa7451a43_25031_src.c" using 98620virt/66924res/6508shr/61164data kb, in 60usr/80sys/149real ms.
Running env -uARCH -uKBUILD_EXTMOD -uCROSS_COMPILE -uKBUILD_IMAGE -uKCONFIG_CONFIG -uINSTALL_PATH -uLD_LIBRARY_PATH PATH=/usr/bin:/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin make -C /lib/modules/4.4.0-31-generic/build M=/tmp/stapK86i0K modules CONFIG_DEBUG_INFO= CONFIG_STACK_VALIDATION= ARCH=x86_64 --no-print-directory -j9
Pass 4: compiled C into "stap_03e1cb4856cba70035242e3fa7451a43_25031.ko" in 8160usr/430sys/9330real ms.
Cache limit file /home/rzrk/.systemtap/cache/cache_mb_limit missing, creating default.
Cache clean interval file /home/rzrk/.systemtap/cache/cache_clean_interval_s missing, creating default.
Copying /tmp/stapK86i0K/stap_03e1cb4856cba70035242e3fa7451a43_25031.ko to /home/rzrk/.systemtap/cache/03/stap_03e1cb4856cba70035242e3fa7451a43_25031.ko
Copying /tmp/stapK86i0K/stap_03e1cb4856cba70035242e3fa7451a43_25031_src.c to /home/rzrk/.systemtap/cache/03/stap_03e1cb4856cba70035242e3fa7451a43_25031.c
Copying /tmp/stapK86i0K/stapconf_cee9fe7cd3119fb704283499e1922672_736.h to /home/rzrk/.systemtap/cache/ce/stapconf_cee9fe7cd3119fb704283499e1922672_736.h
Running /usr/local/bin/staprun -v -t 8001 -R /tmp/stapK86i0K/stap_03e1cb4856cba70035242e3fa7451a43_25031.ko
staprun:insert_module:191 Module stap_03e1cb4856cba70035242e3fa7451a43_22242 inserted from file /tmp/stapK86i0K/stap_03e1cb4856cba70035242e3fa7451a43_25031.ko
WARNING: Start tracing 8001 (/usr/local/openresty/nginx/sbin/nginx)...

$ sudo strace -p 20882
Process 20882 attached
restart_syscall(<... resuming interrupted call ...>

子进程:
$ sudo strace -p 20883
Process 20883 attached
wait4(22242,

5s是运行5s就结束还是说有请求才可以算作这个时间段内？现在这个进程的内存还没有明显增加的状态，上周末已经定位到了代码问题（业务逻辑代码），但是也只是数据量的问题，应该可以正常释放才对啊。

再次感谢～

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午10:09写道：
你把 dump 下来的脚本里面的 /lib/x86_64-linux-gnu/libcom_err.so.2.1 换成 libc 的路径（可以通过 ldd $(which nginx) 获取，大致是 /path/to/libc.so.6 这样子的），然后直接运行修改后的脚本试试？
sxx 是 systemtap 模板，会被 stap++ 这个 perl 脚本展开成一个 systemtap 脚本。看样子是展开的时候逻辑有问题，原本应该展开成 libc 的路径，却变成了以 libc 开头的其他链接库。

2017-08-21 9:44 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复，刚上班，跑了下结果如下（这就是源文件了）：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 --dump-src
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
#!/usr/bin/env stap

# Copyright (C) Yichun Zhang (agentzh)

global ptr2bt
global ptr2size
global bt_stats
global quit
global free_misses

probe begin
{
warn(sprintf("Start tracing %d (/usr/local/openresty/nginx/sbin/nginx)...", target()))
warn("Wait for 5 sec to complete.\n")
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
{
if (pid() == target()) {
//printf("Hit %s\n", probefunc())
if (quit) {
if (free_misses) {
warn(sprintf("free misses: %d", free_misses))
}

foreach (bt in bt_stats) {
print_ustack(bt)
printf("\t%d\n", @sum(bt_stats[bt]))
}

exit()

} else {
if (@defined($oldmem)) {
//printf("free %p in realloc\n", $oldmem)
ptr = $oldmem

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}

ptr = returnval()
if (ptr) {
// here we use a hack specific to glibc's implementation
// to get the size of the memory block because we
// may not get the value of the $bytes parameter reliably.

p = ptr - &@cast(0, "size_t")[1]
size = @cast(p, "size_t")[0] & ~(&@cast(0, "size_t")[1] - 1)

//printf("alloc: %p (bytes %d)\n", ptr, size)
bt = ubacktrace()
ptr2bt[ptr] = bt
ptr2size[ptr] = size
bt_stats[bt] <<< size

} else {
warn("NULL returned")
}
}
}
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
{
ptr = pointer_arg(1)
if (pid() == target() && ptr) {
//printf("free: %p\n", ptr)

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

if (bt == "" && bytes == 0) {
free_misses++

} else {
bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}
}
}

probe timer.s(5)
{
quit = 1
delete ptr2bt
delete ptr2size
}

我又跑了一次，但是似乎结果不一样了。。。

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
Pass 1: parsed user script and 471 library scripts using 83660virt/50276res/4792shr/46204data kb, in 150usr/0sys/147real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
^

semantic error: no match (similar functions: malloc, fputc, fflush, fileno, free)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
^

semantic error: no match (similar functions: malloc, fcntl, fputc, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
^

semantic error: no match (similar functions: malloc, fputc, strerror, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
^

semantic error: no match (similar functions: free, fopen, fwrite, _fini, strlen)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85384virt/53552res/6432shr/47928data kb, in 20usr/40sys/63real ms.
Pass 2: analysis failed. [man error::pass2]

再次感谢！

Zexuan Luo <spacew...@gmail.com>于2017年8月19日周六下午8:50写道：
可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：
如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

--

--

--

--

sunsetmask

明白了，十分感谢您的回复，祝好

# 一个持续了三周的bug排查，感觉才刚刚开始……

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午11:04写道：

5s之后又有请求才会触发退出。

2017-08-21 10:51 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复！

按照您的方法尝试了下，可以运行，但是程序会卡在wait for 5 sec to complete这里。尝试添加vv参数，输出如下：

$ sudo rm -rf ~/.systemtap/
$ sudo ./test_leak_modify.stap -vv -x 8001 -D STP_NO_OVERLOAD -D MAXMAPENTRIES=10000 > a.bt

focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x82a80
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_calloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:3162 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83550
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83220
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83120
probe 1 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877").return') locks __global_ptr2bt[w] __global_ptr2size[w] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r]
probe 3 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").call') locks __global_entry_tvar_oldmem_0[w] __global_entry_tvar_oldmem_0_ctr[rw]
probe 4 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").return') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r] __global_entry_tvar_oldmem_0[rw] __global_entry_tvar_oldmem_0_ctr[rw]
probe 5 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913")') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_free_misses[rw]
dump_unwindsyms /lib/x86_64-linux-gnu/libc-2.19.so index=3 base=0x10000
Found build-id in /lib/x86_64-linux-gnu/libc-2.19.so, length 20, start at 0x280

$ sudo strace -p 20882
Process 20882 attached
restart_syscall(<... resuming interrupted call ...>

子进程:
$ sudo strace -p 20883
Process 20883 attached
wait4(22242,

5s是运行5s就结束还是说有请求才可以算作这个时间段内？现在这个进程的内存还没有明显增加的状态，上周末已经定位到了代码问题（业务逻辑代码），但是也只是数据量的问题，应该可以正常释放才对啊。

再次感谢～

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午10:09写道：
你把 dump 下来的脚本里面的 /lib/x86_64-linux-gnu/libcom_err.so.2.1 换成 libc 的路径（可以通过 ldd $(which nginx) 获取，大致是 /path/to/libc.so.6 这样子的），然后直接运行修改后的脚本试试？
sxx 是 systemtap 模板，会被 stap++ 这个 perl 脚本展开成一个 systemtap 脚本。看样子是展开的时候逻辑有问题，原本应该展开成 libc 的路径，却变成了以 libc 开头的其他链接库。

2017-08-21 9:44 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复，刚上班，跑了下结果如下（这就是源文件了）：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 --dump-src
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
#!/usr/bin/env stap

# Copyright (C) Yichun Zhang (agentzh)

global ptr2bt
global ptr2size
global bt_stats
global quit
global free_misses

probe begin
{
warn(sprintf("Start tracing %d (/usr/local/openresty/nginx/sbin/nginx)...", target()))
warn("Wait for 5 sec to complete.\n")
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
{
if (pid() == target()) {
//printf("Hit %s\n", probefunc())
if (quit) {
if (free_misses) {
warn(sprintf("free misses: %d", free_misses))
}

foreach (bt in bt_stats) {
print_ustack(bt)
printf("\t%d\n", @sum(bt_stats[bt]))
}

exit()

} else {
if (@defined($oldmem)) {
//printf("free %p in realloc\n", $oldmem)
ptr = $oldmem

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}

ptr = returnval()
if (ptr) {
// here we use a hack specific to glibc's implementation
// to get the size of the memory block because we
// may not get the value of the $bytes parameter reliably.

p = ptr - &@cast(0, "size_t")[1]
size = @cast(p, "size_t")[0] & ~(&@cast(0, "size_t")[1] - 1)

//printf("alloc: %p (bytes %d)\n", ptr, size)
bt = ubacktrace()
ptr2bt[ptr] = bt
ptr2size[ptr] = size
bt_stats[bt] <<< size

} else {
warn("NULL returned")
}
}
}
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
{
ptr = pointer_arg(1)
if (pid() == target() && ptr) {
//printf("free: %p\n", ptr)

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

if (bt == "" && bytes == 0) {
free_misses++

} else {
bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}
}
}

probe timer.s(5)
{
quit = 1
delete ptr2bt
delete ptr2size
}

我又跑了一次，但是似乎结果不一样了。。。

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
Pass 1: parsed user script and 471 library scripts using 83660virt/50276res/4792shr/46204data kb, in 150usr/0sys/147real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
^

semantic error: no match (similar functions: malloc, fputc, fflush, fileno, free)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
^

semantic error: no match (similar functions: malloc, fcntl, fputc, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
^

semantic error: no match (similar functions: malloc, fputc, strerror, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
^

semantic error: no match (similar functions: free, fopen, fwrite, _fini, strlen)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85384virt/53552res/6432shr/47928data kb, in 20usr/40sys/63real ms.
Pass 2: analysis failed. [man error::pass2]

再次感谢！

Zexuan Luo <spacew...@gmail.com>于2017年8月19日周六下午8:50写道：
可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：
如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

--

--

--

--

--

sunsetmask

尴尬，结合日志查看进程的请求处理，分析的进程在5s甚至更时间段被调用之后依然没有什么输出，也不会自动退出，感觉内核模块根本没被加载上去啊。。。

Dispensable <suns...@gmail.com>于2017年8月21日周一上午11:07写道：

明白了，十分感谢您的回复，祝好

# 一个持续了三周的bug排查，感觉才刚刚开始……

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午11:04写道：
5s之后又有请求才会触发退出。

2017-08-21 10:51 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复！

按照您的方法尝试了下，可以运行，但是程序会卡在wait for 5 sec to complete这里。尝试添加vv参数，输出如下：

$ sudo rm -rf ~/.systemtap/
$ sudo ./test_leak_modify.stap -vv -x 8001 -D STP_NO_OVERLOAD -D MAXMAPENTRIES=10000 > a.bt

focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x82a80
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_calloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:3162 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83550
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83220
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83120
probe 1 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877").return') locks __global_ptr2bt[w] __global_ptr2size[w] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r]
probe 3 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").call') locks __global_entry_tvar_oldmem_0[w] __global_entry_tvar_oldmem_0_ctr[rw]
probe 4 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").return') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r] __global_entry_tvar_oldmem_0[rw] __global_entry_tvar_oldmem_0_ctr[rw]
probe 5 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913")') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_free_misses[rw]
dump_unwindsyms /lib/x86_64-linux-gnu/libc-2.19.so index=3 base=0x10000
Found build-id in /lib/x86_64-linux-gnu/libc-2.19.so, length 20, start at 0x280

$ sudo strace -p 20882
Process 20882 attached
restart_syscall(<... resuming interrupted call ...>

子进程:
$ sudo strace -p 20883
Process 20883 attached
wait4(22242,

5s是运行5s就结束还是说有请求才可以算作这个时间段内？现在这个进程的内存还没有明显增加的状态，上周末已经定位到了代码问题（业务逻辑代码），但是也只是数据量的问题，应该可以正常释放才对啊。

再次感谢～

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午10:09写道：
你把 dump 下来的脚本里面的 /lib/x86_64-linux-gnu/libcom_err.so.2.1 换成 libc 的路径（可以通过 ldd $(which nginx) 获取，大致是 /path/to/libc.so.6 这样子的），然后直接运行修改后的脚本试试？
sxx 是 systemtap 模板，会被 stap++ 这个 perl 脚本展开成一个 systemtap 脚本。看样子是展开的时候逻辑有问题，原本应该展开成 libc 的路径，却变成了以 libc 开头的其他链接库。

2017-08-21 9:44 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复，刚上班，跑了下结果如下（这就是源文件了）：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 --dump-src
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
#!/usr/bin/env stap

# Copyright (C) Yichun Zhang (agentzh)

global ptr2bt
global ptr2size
global bt_stats
global quit
global free_misses

probe begin
{
warn(sprintf("Start tracing %d (/usr/local/openresty/nginx/sbin/nginx)...", target()))
warn("Wait for 5 sec to complete.\n")
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
{
if (pid() == target()) {
//printf("Hit %s\n", probefunc())
if (quit) {
if (free_misses) {
warn(sprintf("free misses: %d", free_misses))
}

foreach (bt in bt_stats) {
print_ustack(bt)
printf("\t%d\n", @sum(bt_stats[bt]))
}

exit()

} else {
if (@defined($oldmem)) {
//printf("free %p in realloc\n", $oldmem)
ptr = $oldmem

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}

ptr = returnval()
if (ptr) {
// here we use a hack specific to glibc's implementation
// to get the size of the memory block because we
// may not get the value of the $bytes parameter reliably.

p = ptr - &@cast(0, "size_t")[1]
size = @cast(p, "size_t")[0] & ~(&@cast(0, "size_t")[1] - 1)

//printf("alloc: %p (bytes %d)\n", ptr, size)
bt = ubacktrace()
ptr2bt[ptr] = bt
ptr2size[ptr] = size
bt_stats[bt] <<< size

} else {
warn("NULL returned")
}
}
}
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
{
ptr = pointer_arg(1)
if (pid() == target() && ptr) {
//printf("free: %p\n", ptr)

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

if (bt == "" && bytes == 0) {
free_misses++

} else {
bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}
}
}

probe timer.s(5)
{
quit = 1
delete ptr2bt
delete ptr2size
}

我又跑了一次，但是似乎结果不一样了。。。

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
Pass 1: parsed user script and 471 library scripts using 83660virt/50276res/4792shr/46204data kb, in 150usr/0sys/147real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
^

semantic error: no match (similar functions: malloc, fputc, fflush, fileno, free)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
^

semantic error: no match (similar functions: malloc, fcntl, fputc, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
^

semantic error: no match (similar functions: malloc, fputc, strerror, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
^

semantic error: no match (similar functions: free, fopen, fwrite, _fini, strlen)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85384virt/53552res/6432shr/47928data kb, in 20usr/40sys/63real ms.
Pass 2: analysis failed. [man error::pass2]

再次感谢！

Zexuan Luo <spacew...@gmail.com>于2017年8月19日周六下午8:50写道：
可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：
如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

--

--

--

--

--

sunsetmask

在另一台测试机编译了systemtap 3.1 然后直接运行即可，看来线上这个机器发生了什么不为人知的事情（有可能我编译了多个版本的systemtap的原因？

Dispensable <suns...@gmail.com>于2017年8月21日周一上午11:37写道：

尴尬，结合日志查看进程的请求处理，分析的进程在5s甚至更时间段被调用之后依然没有什么输出，也不会自动退出，感觉内核模块根本没被加载上去啊。。。

Dispensable <suns...@gmail.com>于2017年8月21日周一上午11:07写道：
明白了，十分感谢您的回复，祝好

# 一个持续了三周的bug排查，感觉才刚刚开始……

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午11:04写道：
5s之后又有请求才会触发退出。

2017-08-21 10:51 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复！

按照您的方法尝试了下，可以运行，但是程序会卡在wait for 5 sec to complete这里。尝试添加vv参数，输出如下：

$ sudo rm -rf ~/.systemtap/
$ sudo ./test_leak_modify.stap -vv -x 8001 -D STP_NO_OVERLOAD -D MAXMAPENTRIES=10000 > a.bt

focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x82a80
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_calloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:3162 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83550
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83220
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
focused on module '/lib/x86_64-linux-gnu/libc-2.19.so' = [0x10000-0x3d82c0, bias 0x10000 file /usr/lib/debug/lib/x86_64-linux-gnu/libc-2.19.so ELF machine |x86_64 (code 62)
probe __libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913 process=/lib/x86_64-linux-gnu/libc-2.19.so reloc=.dynamic pc=0x83120
probe 1 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_malloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2877").return') locks __global_ptr2bt[w] __global_ptr2size[w] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r]
probe 3 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").call') locks __global_entry_tvar_oldmem_0[w] __global_entry_tvar_oldmem_0_ctr[rw]
probe 4 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_realloc@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2953").return') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_quit[r] __global_free_misses[r] __global_entry_tvar_oldmem_0[rw] __global_entry_tvar_oldmem_0_ctr[rw]
probe 5 ('process("/lib/x86_64-linux-gnu/libc-2.19.so").function("__libc_free@/build/eglibc-SvCtMH/eglibc-2.19/malloc/malloc.c:2913")') locks __global_ptr2bt[rw] __global_ptr2size[rw] __global_bt_stats[rw] __global_free_misses[rw]
dump_unwindsyms /lib/x86_64-linux-gnu/libc-2.19.so index=3 base=0x10000
Found build-id in /lib/x86_64-linux-gnu/libc-2.19.so, length 20, start at 0x280

$ sudo strace -p 20882
Process 20882 attached
restart_syscall(<... resuming interrupted call ...>

子进程:
$ sudo strace -p 20883
Process 20883 attached
wait4(22242,

5s是运行5s就结束还是说有请求才可以算作这个时间段内？现在这个进程的内存还没有明显增加的状态，上周末已经定位到了代码问题（业务逻辑代码），但是也只是数据量的问题，应该可以正常释放才对啊。

再次感谢～

Zexuan Luo <spacew...@gmail.com>于2017年8月21日周一上午10:09写道：
你把 dump 下来的脚本里面的 /lib/x86_64-linux-gnu/libcom_err.so.2.1 换成 libc 的路径（可以通过 ldd $(which nginx) 获取，大致是 /path/to/libc.so.6 这样子的），然后直接运行修改后的脚本试试？
sxx 是 systemtap 模板，会被 stap++ 这个 perl 脚本展开成一个 systemtap 脚本。看样子是展开的时候逻辑有问题，原本应该展开成 libc 的路径，却变成了以 libc 开头的其他链接库。

2017-08-21 9:44 GMT+08:00 Dispensable <suns...@gmail.com>:
感谢回复，刚上班，跑了下结果如下（这就是源文件了）：

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 --dump-src
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
#!/usr/bin/env stap

# Copyright (C) Yichun Zhang (agentzh)

global ptr2bt
global ptr2size
global bt_stats
global quit
global free_misses

probe begin
{
warn(sprintf("Start tracing %d (/usr/local/openresty/nginx/sbin/nginx)...", target()))
warn("Wait for 5 sec to complete.\n")
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
{
if (pid() == target()) {
//printf("Hit %s\n", probefunc())
if (quit) {
if (free_misses) {
warn(sprintf("free misses: %d", free_misses))
}

foreach (bt in bt_stats) {
print_ustack(bt)
printf("\t%d\n", @sum(bt_stats[bt]))
}

exit()

} else {
if (@defined($oldmem)) {
//printf("free %p in realloc\n", $oldmem)
ptr = $oldmem

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}

ptr = returnval()
if (ptr) {
// here we use a hack specific to glibc's implementation
// to get the size of the memory block because we
// may not get the value of the $bytes parameter reliably.

p = ptr - &@cast(0, "size_t")[1]
size = @cast(p, "size_t")[0] & ~(&@cast(0, "size_t")[1] - 1)

//printf("alloc: %p (bytes %d)\n", ptr, size)
bt = ubacktrace()
ptr2bt[ptr] = bt
ptr2size[ptr] = size
bt_stats[bt] <<< size

} else {
warn("NULL returned")
}
}
}
}

probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
{
ptr = pointer_arg(1)
if (pid() == target() && ptr) {
//printf("free: %p\n", ptr)

bt = ptr2bt[ptr]
delete ptr2bt[ptr]

bytes = ptr2size[ptr]
delete ptr2size[ptr]

if (bt == "" && bytes == 0) {
free_misses++

} else {
bt_stats[bt] <<< -bytes
if (@sum(bt_stats[bt]) == 0) {
delete bt_stats[bt]
}
}
}
}

probe timer.s(5)
{
quit = 1
delete ptr2bt
delete ptr2size
}

我又跑了一次，但是似乎结果不一样了。。。

$ sudo ./samples/sample-bt-leaks.sxx -v -x 8001 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Ignored ambiguous library /usr/lib/x86_64-linux-gnu/sasl2/libcrammd5.so.2.0.25 for "libc"
Ignored ambiguous library /usr/local/openresty/lualib/cjson.so for "libc"
Pass 1: parsed user script and 471 library scripts using 83660virt/50276res/4792shr/46204data kb, in 150usr/0sys/147real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("malloc").return,
^

semantic error: no match (similar functions: malloc, fputc, fflush, fileno, free)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("calloc").return,
^

semantic error: no match (similar functions: malloc, fcntl, fputc, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("realloc").return
^

semantic error: no match (similar functions: malloc, fputc, strerror, fflush, fileno)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/lib/x86_64-linux-gnu/libcom_err.so.2.1").function("free")
^

semantic error: no match (similar functions: free, fopen, fwrite, _fini, strlen)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85384virt/53552res/6432shr/47928data kb, in 20usr/40sys/63real ms.
Pass 2: analysis failed. [man error::pass2]

再次感谢！

Zexuan Luo <spacew...@gmail.com>于2017年8月19日周六下午8:50写道：
可以把 ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -dump-src 的输出贴出来吗？
理论上 sample-bt-leaks 应该 hook libc，而不是这些奇怪的玩意儿……

在 2017年8月18日星期五 UTC+8下午2:47:42，木哈哈写道：
如履薄冰的在线上升级了libsasl2的库，加了dbgsym包之后好了，但是……

$ sudo ./samples/sample-bt-leaks.sxx -v -x 22298 --arg time=5 -D STP_NO_OVERLOAD -D MAXMAOENTRIES=10000 > a.bt
Pass 1: parsed user script and 471 library scripts using 83648virt/50232res/4748shr/46192data kb, in 200usr/10sys/198real ms.
semantic error: while resolving probe point: identifier 'process' at <input>:17:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("malloc").return,
^

semantic error: no match (similar functions: die, memcpy, _fini, _init, fprintf)

semantic error: while resolving probe point: identifier 'process' at :18:7
source: process("/usr/local/openresty/lualib/cjson.so").function("calloc").return,
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :19:7
source: process("/usr/local/openresty/lualib/cjson.so").function("realloc").return
^

semantic error: no match (similar functions: die, _fini, _init, memcpy, fprintf)

semantic error: while resolving probe point: identifier 'process' at :74:7
source: probe process("/usr/local/openresty/lualib/cjson.so").function("free")
^

semantic error: no match (similar functions: die, _fini, strbuf_free, _init, fprintf)

Pass 2: analyzed script: 2 probes, 185 functions, 3 embeds, 5 globals using 85376virt/53572res/6412shr/47920data kb, in 30usr/40sys/69real ms.
Pass 2: analysis failed. [man error::pass2]

听着窗外的打雷，有点惆怅。。。

#　特么的怎么就这么难啊

--

--

--

--

--