Re: 请教nginx-systemtap-toolkit问题

96 views
Skip to first unread message

Yichun Zhang (agentzh)

unread,
Nov 21, 2013, 2:40:15 PM11/21/13
to jsdoitao, openresty
Hello!

On Thu, Nov 21, 2013 at 6:09 AM, jsdoitao wrote:
> 您好,最近在研究nginx,用的是openresty,看到你放出了很多有价值的工具,比如ngx_systemtap-toolkit,从描述上来看非常好,

嗯,我们在生产环境中非常依赖这些工具来诊断各种在线问题。

> 不过我执行的过程中,却没有打印任何的结果出来,我觉得挺奇怪的。

Nginx Systemtap Toolkit 中有几十个工具。你具体使用的是哪个工具呀?另外,你使用的具体的命令行是怎样的?你没有看到任何输出吗?

> 问问你是如何检查和确认这些工具是否能够work的?
>

一般地,我会先检查 hello world 是否能工具,即运行命令

stap -e 'probe begin { println("hello world") exit() }'

期望的输出是一行

hello world

如果这可以工作,我会进一步地让工具调用 stap 时传入 -vv 或者 -vvv 选项,这样 stap 会给出更具体的细节信息。以
ngx-active-reqs 工具为例,即把下面这一行源码

open my $in, "|stap --skip-badvars @opts $stap_args -"

替换为

open my $in, "|stap -vvv --skip-badvars @opts $stap_args -"

> 下面是我的kernel,perl和stap信息。stap明确是可以用的,也尝试过火焰图。多谢!
>
>
> $ uname -r
> 3.5.0-43-generic
>

3.5 的内核是有 uprobes 支持的(虽然没有 uretprobes 支持,但不影响大部分工具的使用)。你可以进一步检查
uprobes 支持在内核编译时是否被禁用:

grep UPROBES /boot/config-`uname -r`

如果输出类似

CONFIG_ARCH_SUPPORTS_UPROBES=y
CONFIG_UPROBES=y

说明 uprobes 支持没有被禁用。

> $sudo stap --help
> Systemtap translator/driver (version 2.3/0.152, non-git sources)

systemtap 的版本足够新。

> $perl -v
>
> This is perl 5, version 14, subversion 2 (v5.14.2) built for

perl 的版本也足够新 :)

同时抄送给 openresty 中文邮件列表:https://groups.google.com/group/openresty

Best regards,
-agentzh

jsdoitao

unread,
Nov 22, 2013, 4:42:51 AM11/22/13
to Yichun Zhang (agentzh), openresty
well done! 非常棒。header_filter,body_filter能够很好的工作了。

加上-vvv能看到很多trace,但是对于ngx-phase-handlers这个非常好用的工具,依然未能得到期望的结果。。能帮忙看看不? 多谢!

sudo ./ngx-phase-handlers -p 28006
Systemtap translator/driver (version 2.3/0.152, non-git sources)
Copyright (C) 2005-2013 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: TR1_UNORDERED_MAP NLS
Created temporary directory "/tmp/stapd452kM"
Session arch: x86_64 release: 3.5.0-43-generic
Parsed kernel "/lib/modules/3.5.0-43-generic/build/.config", containing 5071 tuples
Parsed kernel /lib/modules/3.5.0-43-generic/build/Module.symvers, which contained 6630 vmlinux exports
Kernel symbol table /lib/modules/3.5.0-43-generic/build/System.map unavailable, (没有那个文件或目录)
Processing tapset "/usr/local/share/systemtap/tapset/linux/context.stpm"
Processing tapset "/usr/local/share/systemtap/tapset/linux/nfs_proc.stpm"
Searched for library macro files: "/usr/local/share/systemtap/tapset/linux/*.stpm", found: 2, processed: 2
Processing tapset "/usr/local/share/systemtap/tapset/choose_defined.stpm"
Searched for library macro files: "/usr/local/share/systemtap/tapset/*.stpm", found: 1, processed: 1
Processing tapset "/usr/local/share/systemtap/tapset/linux/x86_64/aux_syscalls.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/x86_64/nd_syscalls.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/x86_64/syscalls.stp"
Searched: "/usr/local/share/systemtap/tapset/linux/x86_64/*.stp", found: 3, processed: 3
Processing tapset "/usr/local/share/systemtap/tapset/linux/atomic.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/aux_syscalls.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/context-caller.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/context-envvar.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/context.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/context-symbols.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/context-unwind.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/conversions-guru.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/conversions.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ctime.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/dentry.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/dev.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/endian.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/guru-delay.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/guru-signal.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/inet_sock.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/inet.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ioblock.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ioscheduler.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ipmib-filter-default.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ipmib.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ip.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/irq.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/kprocess.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/kretprobe.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/linuxmib-filter-default.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/linuxmib.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/logging.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/memory.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/nd_syscalls2.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/nd_syscalls.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/netfilter.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/networking.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/nfsderrno.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/nfsd.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/nfs_proc.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/nfs.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/panic.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/perf.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/proc_mem.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/pstrace.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/rcu.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/rpc.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/scheduler.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/scsi.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/signal.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/socket.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/syscalls2.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/syscalls_cfg_trunc.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/syscalls.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/target_set.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/task.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/task_time.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/tcpmib-filter-default.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/tcpmib.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/tcp.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/timestamp_gtod.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/timestamp_monotonic.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/timestamp.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/tty.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/tzinfo.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ucontext.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ucontext-symbols.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/ucontext-unwind.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/udp.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/utrace.stp"
Processing tapset "/usr/local/share/systemtap/tapset/linux/vfs.stp"
Searched: "/usr/local/share/systemtap/tapset/linux/*.stp", found: 67, processed: 67
Processing tapset "/usr/local/share/systemtap/tapset/x86_64/registers.stp"
Searched: "/usr/local/share/systemtap/tapset/x86_64/*.stp", found: 1, processed: 1
Processing tapset "/usr/local/share/systemtap/tapset/ansi.stp"
Processing tapset "/usr/local/share/systemtap/tapset/argv.stp"
Processing tapset "/usr/local/share/systemtap/tapset/context.stp"
Processing tapset "/usr/local/share/systemtap/tapset/errno.stp"
Processing tapset "/usr/local/share/systemtap/tapset/indent-default.stp"
Processing tapset "/usr/local/share/systemtap/tapset/indent.stp"
Processing tapset "/usr/local/share/systemtap/tapset/logging.stp"
Processing tapset "/usr/local/share/systemtap/tapset/null.stp"
Processing tapset "/usr/local/share/systemtap/tapset/pn.stp"
Processing tapset "/usr/local/share/systemtap/tapset/queue_stats.stp"
Processing tapset "/usr/local/share/systemtap/tapset/random.stp"
Processing tapset "/usr/local/share/systemtap/tapset/registers.stp"
Processing tapset "/usr/local/share/systemtap/tapset/speculative.stp"
Processing tapset "/usr/local/share/systemtap/tapset/stap_staticmarkers.stp"
Processing tapset "/usr/local/share/systemtap/tapset/stopwatch.stp"
Processing tapset "/usr/local/share/systemtap/tapset/string.stp"
Processing tapset "/usr/local/share/systemtap/tapset/system.stp"
Processing tapset "/usr/local/share/systemtap/tapset/timers.stp"
Processing tapset "/usr/local/share/systemtap/tapset/tokenize.stp"
Processing tapset "/usr/local/share/systemtap/tapset/tzinfo.stp"
Processing tapset "/usr/local/share/systemtap/tapset/uconversions.stp"
Searched: "/usr/local/share/systemtap/tapset/*.stp", found: 21, processed: 21
Pass 1: parsed user script and 95 library script(s) using 58932virt/26456res/2160shr/25072data kb, in 90usr/0sys/94real ms.
Extracting build ID.
parse 'ngx_http_log_request', func 'ngx_http_log_request'
focused on module '/home/WWW/code/u-nginx/pkg-src/objs/nginx' = [0x400000-0x76ce40, bias 0 file /home/WWW/code/u-nginx/pkg-src/objs/nginx ELF machine |x86_64 (code 62)
focused on module '/home/WWW/code/u-nginx/pkg-src/objs/nginx'
selected function ngx_http_log_request
selected function ngx_http_log_request
searching for prologue of function 'ngx_http_log_request' 0x46477e-0x4647f8@src/http/ngx_http_request.c:3073
checking line record 0x46477e@src/http/ngx_http_request.c:3074
prologue found function 'ngx_http_log_request' (naked) = 0x46477e
probe ngx_http_log_request@src/http/ngx_http_request.c:3073 process=/home/WWW/code/u-nginx/pkg-src/objs/nginx reloc=.absolute pc=0x46477e
finding location for local 'ngx_http_core_module' near address 0x46477e, module bias 0
finding symtable address for ngx_http_core_module
found ngx_http_core_module @0x74f220
emit dwarf addr 0x74f220 => module /home/WWW/code/u-nginx/pkg-src/objs/nginx section  relocaddr 0x74f220
finding location for local 'r' near address 0x46477e, module bias 0
get_cfa_ops @0x46477e, module_start @0x400000
found cfa, info: -1 [start: 0, end: 0x7fff2892cb68, nops: 1
get_cfa_ops @0x46477e, module_start @0x400000
found cfa, info: -1 [start: 0x6f00000067, end: 0, nops: 1
finding location for local 'r' near address 0x46477e, module bias 0
get_cfa_ops @0x46477e, module_start @0x400000
found cfa, info: -1 [start: 0x44, end: 0x7f491d35a720, nops: 1
get_cfa_ops @0x46477e, module_start @0x400000
found cfa, info: -1 [start: 0x1, end: 0x7fff2892c870, nops: 1
finding location for local 'r' near address 0x46477e, module bias 0
get_cfa_ops @0x46477e, module_start @0x400000
found cfa, info: -1 [start: 0x44, end: 0x7f491d35a720, nops: 1
get_cfa_ops @0x46477e, module_start @0x400000
found cfa, info: -1 [start: 0x1, end: 0x7fff2892c600, nops: 1
focused on module '/home/WWW/code/u-nginx/pkg-src/objs/nginx' = [0x400000-0x76ce40, bias 0 file /home/WWW/code/u-nginx/pkg-src/objs/nginx ELF machine |x86_64 (code 62)
focused on module '/home/WWW/code/u-nginx/pkg-src/objs/nginx'
WWW@WWW:~/soft/performance/nginx-systemtap-toolkit-master$ 

Yichun Zhang (agentzh)

unread,
Nov 22, 2013, 3:03:58 PM11/22/13
to jsdoitao, openresty
Hello!

On Fri, Nov 22, 2013 at 1:42 AM, jsdoitao wrote:
> well done! 非常棒。header_filter,body_filter能够很好的工作了。
>

Cool :)

> 加上-vvv能看到很多trace,但是对于ngx-phase-handlers这个非常好用的工具,依然未能得到期望的结果。。能帮忙看看不? 多谢!
>

貌似 stap 在中途崩溃了。你能用 gdb 获取一下 stap 进程崩溃位置的调试栈轨迹吗?

另外,你的 nginx 是用什么版本的 gcc 编译的?建议使用较新版本的 gcc 编译,例如 4.7.3. 因为老版本的 gcc
倾向于生成更多不正确的 DWARF 调试信息。

Regards,
-agentzh
Reply all
Reply to author
Forward
0 new messages