Re: 请教nginx-systemtap-toolkit问题

101 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)

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

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