Re: nginx systemtap使用

agentzh · 2012-10-14T13:21:35+00:00

Hello! 2012/10/13 Wenhua Zhang: > Hi 章老师， > 您好， > 之前在微博上...

Re: nginx systemtap使用

agentzh

Hello!

2012/10/13 Wenhua Zhang:
> 您好，我在使用您的systemtap脚本时，出现了如下错误：
> Pass 4: compiled C into
> "stap_9bd58f613f10f902accc4171ced91dd4_5524.ko" in
> 7950usr/570sys/10924real ms.
> ERROR: global variable 's' allocation failed
> 是不是跟systemtap的版本有关系？
>

这是因为你的机器内存比较小，而我给出的 stap 命令中把  MAXMAPENTRIES 设得非常大，即 20240. 这个宏直接控制
systemtap 语言中的关联数组类型的变量所分配的空间大小。

20240 这个数值在我的 20GB
内存的笔记本上没有问题，但在你的机器上就可能内存溢出了。你可以按照你的机器配置，将这个配置项设得小一些，比如像 Brendan Gregg
的示范命令中那样置为 10240，或者更小一些。

> ]# stap --version
> Systemtap translator/driver (version 1.6/0.152 non-git sources)

我在上一封邮件中指出了，建议使用 SystemTap 2.0 以上版本。较老版本的 bug 比较多。

>
> 在使用源码编译时，出现如下错误：
> configure: error: elfutils, libdw too old, need 0.148+
>
[...]
>
> 从网上查了一下，elfutils在centos5上的最高版本是0.137.
>

你可以考虑从源码编译一个最新版本的 elfutils，CentOS 5 上的包版本都很古老 :)

Best regards,
-agentzh

P.S. 再次抄送 openresty 中文邮件列表：https://groups.google.com/group/openresty
也建议你直接在那里讨论这样的问题，这样可以有更多人参与 ;)

shiziwen

Hi ,
我重新编译了sytemtap 2.0,然后运行以下命令：
/opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
MAXMAPENTRIES=5120  -D MAXACTION=20000  -D MAXTRACE=100 -D
MAXSTRINGLEN=4096 -D MAXBACKTRACE=100 -x 16333 a.stp > a.out
WARNING: missing unwind/symbol data for module 'uprobes'
ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1 (0x2d vs 0x33)
address 0xffffffff81508170 rc 0
WARNING: /opt/systemtap/bin/staprun exited with status: 1
Pass 5: run failed.  Try again with another '--vp 00001' option.

针对“ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1 (0x2d vs
0x33) address 0xffffffff81508170 rc
0”的错误，参考“http://gekben.gitcd.com/blog/2012/08/16/install-systemtap-on-suse/”，把文件systemtap/runtime/sym.c中的if
(rc || (theory != practice))写成: if (0 && (rc || (theory !=
practice)))，然后重新编译：
# /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
MAXMAPENTRIES=5120  -D MAXACTION=2000  -D MAXTRACE=50 -D
MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 16333 a.stp
WARNING: missing unwind/symbol data for module 'uprobes'

但是很长时间没有结果。
请问这是什么原因？




在 2012年10月14日 下午1:21，agentzh <age...@gmail.com> 写道：
> Hello!
>
> 2012/10/13 Wenhua Zhang:
>> 您好，我在使用您的systemtap脚本时，出现了如下错误：
>> Pass 4: compiled C into
>> "stap_9bd58f613f10f902accc4171ced91dd4_5524.ko" in
>> 7950usr/570sys/10924real ms.
>> ERROR: global variable 's' allocation failed
>> 是不是跟systemtap的版本有关系？
>>
>
> 这是因为你的机器内存比较小，而我给出的 stap 命令中把  MAXMAPENTRIES 设得非常大，即 20240. 这个宏直接控制
> systemtap 语言中的关联数组类型的变量所分配的空间大小。
>
> 20240 这个数值在我的 20GB
> 内存的笔记本上没有问题，但在你的机器上就可能内存溢出了。你可以按照你的机器配置，将这个配置项设得小一些，比如像 Brendan Gregg
> 的示范命令中那样置为 10240，或者更小一些。
>
>> ]# stap --version
>> Systemtap translator/driver (version 1.6/0.152 non-git sources)
>
> 我在上一封邮件中指出了，建议使用 SystemTap 2.0 以上版本。较老版本的 bug 比较多。
>
>>
>> 在使用源码编译时，出现如下错误：
>> configure: error: elfutils, libdw too old, need 0.148+
>>
> [...]
>>
>> 从网上查了一下，elfutils在centos5上的最高版本是0.137.
>>
>
> 你可以考虑从源码编译一个最新版本的 elfutils，CentOS 5 上的包版本都很古老 :)
>
> Best regards,
> -agentzh
>
> P.S. 再次抄送 openresty 中文邮件列表：https://groups.google.com/group/openresty
> 也建议你直接在那里讨论这样的问题，这样可以有更多人参与 ;)

agentzh

Hello!

2012/10/14 Wenhua Zhang:
> # /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
> MAXMAPENTRIES=5120  -D MAXACTION=2000  -D MAXTRACE=50 -D
> MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 16333 a.stp
> WARNING: missing unwind/symbol data for module 'uprobes'
>
> 但是很长时间没有结果。
> 请问这是什么原因？
>

你确认你指定的那个 nginx worker 是足够繁忙的么？如果你的 nginx worker 足够繁忙，当会在 20
秒之后自动退出。我在测试时都是只启用一个 nginx worker 进程，然后用 ab 持续施加压力，直至 stap 命令退出。

Best regards,
-agentzh

agentzh

Hello!

2012/10/14 agentzh <age...@gmail.com>:
>
> 你确认你指定的那个 nginx worker 是足够繁忙的么？如果你的 nginx worker 足够繁忙，当会在 20
> 秒之后自动退出。我在测试时都是只启用一个 nginx worker 进程，然后用 ab 持续施加压力，直至 stap 命令退出。
>

当然，SystemTap 的启动时间也需要考虑进去，特别是首次启动的时间。启动时间是不算在我说的 20 秒之内的。即使在我的
ThinkPad W530 系统上，首次启动也需要 10 多秒的时间（随后再启动就是 1 秒以内了）。

其实我一直想好好优化一下 SystemTap 的启动时间，这是比 JVM 的启动还要夸张啊。。。

Best regards,
-agentzh

shiziwen

Hi 章老师，
运行stap时，使用另外３台机器运行ab加压，nginx启动了３个worker进程，“21954”为其中一个worker的PID。

# /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
MAXMAPENTRIES=5120  -D MAXACTION=2000  -D MAXTRACE=50 -D
MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 >
a.out
Pass 5: starting run.
WARNING: Missing unwind data for module, rerun with 'stap -d
stap_32956d49a7514625e7674714a68170c7_4108'
WARNING: _stp_read_address failed to access memory location
ERROR: MAXACTION exceeded near operator '{' at
/opt/systemtap/share/systemtap/tapset/linux/ucontext-symbols.stp:113:28
WARNING: Number of errors: 1, skipped probes: 24
WARNING: /opt/systemtap/bin/staprun exited with status: 1
Pass 5: run completed in 10usr/90sys/20437real ms.
Pass 5: run failed.  Try again with another '--vp 00001' option.

生成的SVG文件有很多“_init”,见附件。
请问这种情况是否正常？

另外，之前遇到的错误“ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1
(0x2d vs 0x33)
address 0xffffffff81508170 rc 0”，把文件systemtap/runtime/sym.c中的if(rc ||
(theory != practice))写成: if (0 && (rc || (theory
!=practice)))，然后重新编译，请问这种解决方法是否会影响systemtap的运行？

运行的机器的环境如下：
# uname -r
2.6.32-279.1.1.el6.x86_64

编译安装了systemtap 2.0:
./configure --prefix=/opt/systemtap --disable-docs --disable-publican
--disable-refdocs
make
make install

谢谢。

生成附件２的命令为(修改了MAXACTION，由2000调整为20000)：
# /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
MAXMAPENTRIES=5120  -D MAXACTION=20000  -D MAXTRACE=50 -D
MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 >
a.out
WARNING: missing unwind/symbol data for module 'uprobes'
Pass 5: starting run.
WARNING: Missing unwind data for module, rerun with 'stap -d
stap_3f263a8ae4e7ab56f20fd2d7a1b0adae_4371'
WARNING: _stp_read_address failed to access memory location
WARNING: Number of errors: 0, skipped probes: 99
Pass 5: run completed in 0usr/90sys/20488real ms.




在 2012年10月15日 下午2:03，agentzh <age...@gmail.com> 写道：
> Hello!
>
> 2012/10/14 agentzh <age...@gmail.com>:
>>
>> 你确认你指定的那个 nginx worker 是足够繁忙的么？如果你的 nginx worker 足够繁忙，当会在 20
>> 秒之后自动退出。我在测试时都是只启用一个 nginx worker 进程，然后用 ab 持续施加压力，直至 stap 命令退出。
>>
>
> 当然，SystemTap 的启动时间也需要考虑进去，特别是首次启动的时间。启动时间是不算在我说的 20 秒之内的。即使在我的
> ThinkPad W530 系统上，首次启动也需要 10 多秒的时间（随后再启动就是 1 秒以内了）。
>
> 其实我一直想好好优化一下 SystemTap 的启动时间，这是比 JVM 的启动还要夸张啊。。。
>
> Best regards,
> -agentzh

Attachment: nginx-agentzh-stap.svg
Description: image/svg

Attachment: nginx-agentzh-stap-2.svg
Description: image/svg

agentzh

Hello!

2012/10/15 Wenhua Zhang:
> Pass 5: starting run.
> WARNING: Missing unwind data for module, rerun with 'stap -d
> stap_32956d49a7514625e7674714a68170c7_4108'
> WARNING: _stp_read_address failed to access memory location
> ERROR: MAXACTION exceeded near operator '{' at
> /opt/systemtap/share/systemtap/tapset/linux/ucontext-symbols.stp:113:28
> WARNING: Number of errors: 1, skipped probes: 24
> WARNING: /opt/systemtap/bin/staprun exited with status: 1
> Pass 5: run completed in 10usr/90sys/20437real ms.
> Pass 5: run failed.  Try again with another '--vp 00001' option.
>
> 生成的SVG文件有很多“_init”,见附件。
> 请问这种情况是否正常？

你的 SVG 看起来完全不正确。你的 systemtap 貌似未能成功获得用户态调用栈。

>
> 另外，之前遇到的错误“ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1
> (0x2d vs 0x33)
> address 0xffffffff81508170 rc 0”，把文件systemtap/runtime/sym.c中的if(rc ||
> (theory != practice))写成: if (0 && (rc || (theory
> !=practice)))，然后重新编译，请问这种解决方法是否会影响systemtap的运行？
>

你这里把兼容性检查代码彻底移除，貌似并不是一个好主意 :) 你可以尝试移除 $HOME/.systemtap ?

我建议你先直接尝试系统自带的 systemtap 包？版本老点就老点吧，呵呵。基本能工作就好了。

另外，MAXACTION 确实应当设置得大一些 ;)

Best regards,
-agentzh

shiziwen

Hi 章老师，
谢谢您的回复。
我之前尝试了用系统自带的systemtap，但仍然出现问题：
＃stap --ldd -d /usr/sbin/nginx --all-modules -D MAXMAPENTRIES=5120  -D
MAXACTION=20000  -D MAXTRACE=50 -D MAXSTRINGLEN=1024 -D
MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 > a.out
Pass 5: starting run.
ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1 (0x2d vs 0x33)
address 0xffffffff81508170 rc 0
WARNING: /usr/bin/staprun exited with status: 1
Pass 5: run completed in 0usr/50sys/84real ms.
Pass 5: run failed.  Try again with another '--vp 00001' option.

# which stap
/usr/bin/stap

# stap --version
Systemtap translator/driver (version 1.7/0.152 non-git sources)
Copyright (C) 2005-2012 Red Hat, Inc. and others
This is free software; see the source for copying conditions.
enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR
TR1_UNORDERED_MAP NLS

是否和我装的debug包有关系？
# rpm -qa | grep `uname -r`
kernel-2.6.32-279.1.1.el6.x86_64
kernel-debuginfo-common-x86_64-2.6.32-279.1.1.el6.x86_64
kernel-headers-2.6.32-279.1.1.el6.x86_64
kernel-debuginfo-2.6.32-279.1.1.el6.x86_64
kernel-devel-2.6.32-279.1.1.el6.x86_64
perf-2.6.32-279.1.1.el6.x86_64

”Build-id mismatch“这个问题在网上也有人提出，但没有找到好的解决办法。
谢谢。

Best Wishes,
Wenhua


在 2012年10月16日 上午1:56，agentzh <age...@gmail.com> 写道：
> Hello!
>
> 2012/10/15 Wenhua Zhang:
>> Pass 5: starting run.
>> WARNING: Missing unwind data for module, rerun with 'stap -d
>> stap_32956d49a7514625e7674714a68170c7_4108'
>> WARNING: _stp_read_address failed to access memory location
>> ERROR: MAXACTION exceeded near operator '{' at
>> /opt/systemtap/share/systemtap/tapset/linux/ucontext-symbols.stp:113:28
>> WARNING: Number of errors: 1, skipped probes: 24
>> WARNING: /opt/systemtap/bin/staprun exited with status: 1
>> Pass 5: run completed in 10usr/90sys/20437real ms.
>> Pass 5: run failed.  Try again with another '--vp 00001' option.
>>
>> 生成的SVG文件有很多“_init”,见附件。
>> 请问这种情况是否正常？
>
> 你的 SVG 看起来完全不正确。你的 systemtap 貌似未能成功获得用户态调用栈。
>
>>
>> 另外，之前遇到的错误“ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1
>> (0x2d vs 0x33)
>> address 0xffffffff81508170 rc 0”，把文件systemtap/runtime/sym.c中的if(rc ||
>> (theory != practice))写成: if (0 && (rc || (theory
>> !=practice)))，然后重新编译，请问这种解决方法是否会影响systemtap的运行？
>>
>
> 你这里把兼容性检查代码彻底移除，貌似并不是一个好主意 :) 你可以尝试移除 $HOME/.systemtap ?
>
> 我建议你先直接尝试系统自带的 systemtap 包？版本老点就老点吧，呵呵。基本能工作就好了。
>
> 另外，MAXACTION 确实应当设置得大一些 ;)
>
> Best regards,
> -agentzh

shiziwen

Hi 章老师，
之前的"build-id mismatch"的问题解决了，是因为内核和安装的debuginfo包的build-id不同引起的。
重新安装debuginfo包之后问题不再出现。
＃eu-readelf -n /boot/vmlinuz-2.6.32-279.1.1.el6.x86_64  | grep "Build ID"
    Build ID: 8c33eab01b34cdde6dbb46ebcb2ae3c9929c836d
＃eu-readelf -n /usr/lib/debug/lib/modules/2.6.32-279.1.1.el6.x86_64/vmlinux
| grep "Build ID"
    Build ID: 8c33eab01b34cdde6dbb46ebcb2ae3c9929c836d

之后重新运行stap，第一次总是出错:
# /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
MAXMAPENTRIES=5120  -D MAXACTION=20000  -D MAXTRACE=50 -D
MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 >
a.out
Pass 5: starting run.
ERROR: error allocating hash
ERROR: global variable 's' allocation failed
WARNING: /opt/systemtap/bin/staprun exited with status: 1
Pass 5: run completed in 0usr/70sys/683real ms.
Pass 5: run failed.  Try again with another '--vp 00001' option.

# /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
MAXMAPENTRIES=5120  -D MAXACTION=20000  -D MAXTRACE=50 -D
MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 >
a.out
Pass 5: starting run.
WARNING: Missing unwind data for module, rerun with 'stap -d
stap_b4701e846c78c93e13b217f69be297e_18846'
WARNING: _stp_read_address failed to access memory location
WARNING: Number of errors: 0, skipped probes: 99
Pass 5: run completed in 0usr/90sys/20481real ms.

请问上面的一些警告信息是否会影响stap的运行？
谢谢。


2012/10/16 Wenhua Zhang <shi...@gmail.com>:
> Hi 章老师，
> 谢谢您的回复。
> 我之前尝试了用系统自带的systemtap，但仍然出现问题：
> ＃stap --ldd -d /usr/sbin/nginx --all-modules -D MAXMAPENTRIES=5120  -D
> MAXACTION=20000  -D MAXTRACE=50 -D MAXSTRINGLEN=1024 -D
> MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 > a.out
> Pass 5: starting run.
> ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1 (0x2d vs 0x33)
> address 0xffffffff81508170 rc 0
> WARNING: /usr/bin/staprun exited with status: 1
> Pass 5: run completed in 0usr/50sys/84real ms.
> Pass 5: run failed.  Try again with another '--vp 00001' option.
>
> # which stap
> /usr/bin/stap
>
> # stap --version
> Systemtap translator/driver (version 1.7/0.152 non-git sources)
> Copyright (C) 2005-2012 Red Hat, Inc. and others
> This is free software; see the source for copying conditions.
> enabled features: AVAHI LIBRPM LIBSQLITE3 NSS BOOST_SHARED_PTR
> TR1_UNORDERED_MAP NLS
>
> 是否和我装的debug包有关系？
> # rpm -qa | grep `uname -r`
> kernel-2.6.32-279.1.1.el6.x86_64
> kernel-debuginfo-common-x86_64-2.6.32-279.1.1.el6.x86_64
> kernel-headers-2.6.32-279.1.1.el6.x86_64
> kernel-debuginfo-2.6.32-279.1.1.el6.x86_64
> kernel-devel-2.6.32-279.1.1.el6.x86_64
> perf-2.6.32-279.1.1.el6.x86_64
>
> ”Build-id mismatch“这个问题在网上也有人提出，但没有找到好的解决办法。
> 谢谢。
>
> Best Wishes,
> Wenhua
>
>
> 在 2012年10月16日 上午1:56，agentzh <age...@gmail.com> 写道：
>> Hello!
>>
>> 2012/10/15 Wenhua Zhang:
>>> Pass 5: starting run.
>>> WARNING: Missing unwind data for module, rerun with 'stap -d
>>> stap_32956d49a7514625e7674714a68170c7_4108'
>>> WARNING: _stp_read_address failed to access memory location
>>> ERROR: MAXACTION exceeded near operator '{' at
>>> /opt/systemtap/share/systemtap/tapset/linux/ucontext-symbols.stp:113:28
>>> WARNING: Number of errors: 1, skipped probes: 24
>>> WARNING: /opt/systemtap/bin/staprun exited with status: 1
>>> Pass 5: run completed in 10usr/90sys/20437real ms.
>>> Pass 5: run failed.  Try again with another '--vp 00001' option.
>>>
>>> 生成的SVG文件有很多“_init”,见附件。
>>> 请问这种情况是否正常？
>>
>> 你的 SVG 看起来完全不正确。你的 systemtap 貌似未能成功获得用户态调用栈。
>>
>>>
>>> 另外，之前遇到的错误“ERROR: Build-id mismatch: "kernel" vs. "vmlinux" byte 1
>>> (0x2d vs 0x33)
>>> address 0xffffffff81508170 rc 0”，把文件systemtap/runtime/sym.c中的if(rc ||
>>> (theory != practice))写成: if (0 && (rc || (theory
>>> !=practice)))，然后重新编译，请问这种解决方法是否会影响systemtap的运行？
>>>
>>
>> 你这里把兼容性检查代码彻底移除，貌似并不是一个好主意 :) 你可以尝试移除 $HOME/.systemtap ?
>>
>> 我建议你先直接尝试系统自带的 systemtap 包？版本老点就老点吧，呵呵。基本能工作就好了。
>>
>> 另外，MAXACTION 确实应当设置得大一些 ;)
>>
>> Best regards,
>> -agentzh

Attachment: nginx-agentzh-stap-4.svg
Description: image/svg

agentzh

Hello!

On Mon, Oct 15, 2012 at 10:07 PM, Wenhua Zhang wrote:
> 之前的"build-id mismatch"的问题解决了，是因为内核和安装的debuginfo包的build-id不同引起的。
> 重新安装debuginfo包之后问题不再出现。
> ＃eu-readelf -n /boot/vmlinuz-2.6.32-279.1.1.el6.x86_64  | grep "Build ID"
>     Build ID: 8c33eab01b34cdde6dbb46ebcb2ae3c9929c836d
> ＃eu-readelf -n /usr/lib/debug/lib/modules/2.6.32-279.1.1.el6.x86_64/vmlinux
> | grep "Build ID"
>     Build ID: 8c33eab01b34cdde6dbb46ebcb2ae3c9929c836d
>

赞啊，解决了就好 :)

> 之后重新运行stap，第一次总是出错:
> # /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
> MAXMAPENTRIES=5120  -D MAXACTION=20000  -D MAXTRACE=50 -D
> MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 >
> a.out
> Pass 5: starting run.
> ERROR: error allocating hash
> ERROR: global variable 's' allocation failed
> WARNING: /opt/systemtap/bin/staprun exited with status: 1
> Pass 5: run completed in 0usr/70sys/683real ms.
> Pass 5: run failed.  Try again with another '--vp 00001' option.
>

这个错误还是说你设置的 MAXMAPENTRIES 相对于你的系统内存设置过大了。

> # /opt/systemtap/bin/stap --ldd -d /usr/sbin/nginx --all-modules -D
> MAXMAPENTRIES=5120  -D MAXACTION=20000  -D MAXTRACE=50 -D
> MAXSTRINGLEN=1024 -D MAXBACKTRACE=100 -x 21954 a.stp --vp 00001 >
> a.out
> Pass 5: starting run.
> WARNING: Missing unwind data for module, rerun with 'stap -d
> stap_b4701e846c78c93e13b217f69be297e_18846'
> WARNING: _stp_read_address failed to access memory location
> WARNING: Number of errors: 0, skipped probes: 99
> Pass 5: run completed in 0usr/90sys/20481real ms.
>
> 请问上面的一些警告信息是否会影响stap的运行？

这些错误无所谓了，只要你能生成靠谱的火焰图就好 :)

看来 SystemTap 还是在 Fedora 上最少折腾，呵呵。

Best regards,
-agentzh