stapxx的ngx-lua-exec-time的结果疑问

ruoshan.huang · 2014-03-18T14:43:29+00:00

好的，我下一步试试看，thanks to 春哥~------------------ 原始&#...

stapxx的ngx-lua-exec-time的结果疑问

ruoshan.huang

hi,

stapxx的ngx-lua-exec-time是主要统计含有lua_resume调用的函数的耗时吗? 这个的时间和probe process.function("ngx_http_lua_access_handler")的timedelta差距很大是正常的不? 对比结果(gist): https://gist.github.com/ruoshan/e2e55e2d3d04631cd85c

ngx_http_access_handler 平均耗时在310us

ngx-lua-exec-time 才64us.

BTW. stapxx中的`$r' 这个变量我可以在哪找定义(或者宏?). 看不懂perl. T.T

agentzh

Hello!

2014-03-17 23:43 GMT-07:00 Ruoshan Huang:
>    stapxx的ngx-lua-exec-time是主要统计含有lua_resume调用的函数的耗时吗? 这个的时间和probe
> process.function("ngx_http_lua_access_handler")的timedelta差距很大是正常的不?

你直接查看 ngx-lua-exec-time 工具的文档和源码：

    https://github.com/agentzh/stapxx#ngx-lua-exec-time

这个工具统计的时间一般会小于整个 access handler 的用时。

> 对比结果(gist): https://gist.github.com/ruoshan/e2e55e2d3d04631cd85c
>

在进行计时时，你应当避免一次触发过多的探针，因为那样的话，你的计时工具引入的误差会占统治地位，从而让你的结果失真。

建议在这种模式下尽量一次统计一个函数的用时。比如我的 func-latency-distr.sxx 工具可以用于此目的。考虑下面这个例子：

    location = /t {
        access_by_lua '
            return
        ';
        content_by_lua '
            ngx.say("ok")
        ';
    }

用 ab -c1 -n1000000 -k 对 /t 保持压力，然后用 func-latency-distr 单独统计
ngx_http_lua_access_handler 的用时：

    $ func-latency-distr.sxx --arg
func='@pfunc(ngx_http_lua_access_handler)' -x 21978
    Start tracing 21978...
    Please wait for 5 seconds.

    Distribution of ngx_http_lua_access_handler latencies (in microseconds)
    max/avg/min: 68/5/3
    value |-------------------------------------------------- count
       0 |                                                        0
       1 |                                                        0
       2 |@@                                                   8047
       4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  144014
       8 |@@@@@                                               14811
      16 |                                                     1300
      32 |                                                      135
      64 |                                                        1
     128 |                                                        0
     256 |                                                        0

我们看到平均延时是 5us.

> ngx_http_access_handler 平均耗时在310us
> ngx-lua-exec-time 才64us.
>

当你需要对整体的延时分布作出解释时，你应当使用火焰图工具，比如 on-CPU 火焰图和 off-CPU 火焰图：

    https://github.com/agentzh/nginx-systemtap-toolkit#sample-bt

    https://github.com/agentzh/nginx-systemtap-toolkit#sample-bt-off-cpu

> BTW. stapxx中的`$r' 这个变量我可以在哪找定义(或者宏?). 看不懂perl. T.T
>

在这里，$r 不是 Perl 变量，而是 systemtap 语言里的变量。见
https://www.sourceware.org/systemtap/SystemTap_Beginners_Guide/targetvariables.html

Regards,
-agentzh