请教ngx lua 调试方法

姚尉

unread,

May 7, 2014, 2:49:45 AM5/7/14

to open...@googlegroups.com

hi,agentzh

我的程序在运行一段时间后出现 'attempt to index a function value' 错误，并且有个别worker 收到signal 11 信号后退出，这个貌似是ngx_lua的bug。

想问下春哥，有什么方式能够调试ngx_lua的问题？

我用的是openresty-1.4.3.6 + ngx_lua-0.9.7 版本

--

ywsample :)

姚尉

unread,

May 7, 2014, 3:11:40 AM5/7/14

to open...@googlegroups.com

而且奇怪的是，错误总在我调用了tcp:receive 之后发生，看日志中打印的出错行竟然是第0行。
在 2014年5月7日星期三UTC+8下午2时49分45秒，姚尉写道：

Yichun Zhang (agentzh)

unread,

May 7, 2014, 5:18:33 PM5/7/14

to openresty

Hello!

2014-05-06 23:49 GMT-07:00 姚尉:
> 我的程序在运行一段时间后出现 'attempt to index a function value' 错误，并且有个别worker 收到signal
> 11 信号后退出，这个貌似是ngx_lua的bug。
>
> 想问下春哥，有什么方式能够调试ngx_lua的问题？
>

你目前提供的信息还不足以确认是 ngx_lua 的问题。关于追踪此问题，我有如下建议：

1.. 尝试最新的 OpenResty 1.5.12.1 正式版发布：http://openresty.org/#Download

2. 在构造 OpenResty 时，启用其 ./configure 脚本的 --with-debug 选项，此时会开启 LuaJIT
的断言检查和 API 检查。

3. 配置 nginx 生成 core dump 文件（见文档
http://wiki.nginx.org/Debugging#Core_dump ），这样你可以在 nginx worker 崩溃时得到
core dump 文件。然后你可以使用 gdb 对此 core dump 进行分析，比如使用 bt full 命令得到崩溃位置上完整的 C
调用栈轨迹。也可以使用我们的 nginx gdb utils 项目中的工具从 core dump
得到更多的信息：https://github.com/openresty/nginx-gdb-utils#readme 特别是其中的
lbt、lgc、lgcstat、lvmst 这些gdb 扩展命令。

4. 检查你使用的 OpenResty 以外的 Lua C 模块或者使用了使用了 LuaJIT FFI 的 Lua 模块（即 Lua
库），以及是否使用了 OpenResty 以外的 NGINX C 模块。这些我们未测试过的 Lua 库或者 NGINX
模块可能会引入我们无法控制的内存问题。

5. 尝试使用 Valgrind memcheck 工具运行你的 nginx
应用，检查是否有内存问题。在此运行模式下，建议使用下面的命令构造 OpenResty:

./configure --with-debug --with-no-pool-patch \
--with-luajit-xcflags='-DLUAJIT_USE_SYSMALLOC -DLUAJIT_USE_VALGRIND'

然后在 valgrind 运行模式下，在 nginx.conf 中作如下配置：

worker_processes 1;
daemon off;
master_process off;

在用 valgrind 启动 nginx 以后，再用你的测试请求不断访问 nginx，直到 valgrind 产生错误报告。

> 我用的是openresty-1.4.3.6 + ngx_lua-0.9.7 版本
>

OpenResty 1.4.3.6 中携带的 ngx_lua 版本是 0.9.2，难道你自己手工覆盖了里了
ngx_lua？一般不建议这么做，因为 OpenResty 的每一个版本里的所有组件一般都是作为整体来测试的。

Regards,
-agentzh

Jiale Zhi

unread,

May 7, 2014, 9:36:12 PM5/7/14

to open...@googlegroups.com

可以提供你的代码和详细的错误日志吗？还有复现问题的方式

Best regards,

- Jiale

姚尉

unread,

May 7, 2014, 11:55:39 PM5/7/14

to open...@googlegroups.com

谢谢春哥的建议
这个问题在昨天测试的时候复现过几次，但是今天测试的时候并没有复现，而我并没有经过什么改动
我再尝试重新复现这个问题

>1.. 尝试最新的 OpenResty 1.5.12.1 正式版发布：http://openresty.org/#Download

这个版本也出现过这种问题

>3. 配置 nginx 生成 core dump 文件（见文档
>http://wiki.nginx.org/Debugging#Core_dump ），这样你可以在 nginx worker 崩溃时得到
>core dump 文件。然后你可以使用 gdb 对此 core dump 进行分析，比如使用 bt full 命令得到崩溃位置上完整的 C
>调用栈轨迹。也可以使用我们的 nginx gdb utils 项目中的工具从 core dump
>得到更多的信息：https://github.com/openresty/nginx-gdb-utils#readme 特别是其中的
>lbt、lgc、lgcstat、lvmst 这些gdb 扩展命令。

生成过一次core文件，gdb core文件信息( core 文件是有openresty 1.5.12.1生成的)
#0 0x00002b6145f2f04c in debug_localname (L=0x41612438, ar=<value optimized out>,
name=0x41611738, slot1=5096856) at lj_debug.c:187
187 if (!nextframe) nextframe = L->top;

>4. 检查你使用的 OpenResty 以外的 Lua C 模块或者使用了使用了 LuaJIT FFI 的 Lua 模块（即 Lua
>库），以及是否使用了 OpenResty 以外的 NGINX C 模块。这些我们未测试过的 Lua 库或者 NGINX
>模块可能会引入我们无法控制的内存问题。

没有自己编写的Lua C模块使用LuaJIT FFI 的 Lua 模块

>OpenResty 1.4.3.6 中携带的 ngx_lua 版本是 0.9.2，难道你自己手工覆盖了里了
>ngx_lua？一般不建议这么做，因为 OpenResty 的每一个版本里的所有组件一般都是作为整体来测试的。

是的，因为ngx_lua 0.9.2 还没有init_worker_by_lua 指令

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 8, 2014, 3:54:54 PM5/8/14

to openresty

Hello!

2014-05-07 20:55 GMT-07:00 姚尉:
>> 比如使用 bt full 命令得到崩溃位置上完整的 C
>>调用栈轨迹。也可以使用我们的 nginx gdb utils 项目中的工具从 core dump
>>得到更多的信息：https://github.com/openresty/nginx-gdb-utils#readme 特别是其中的
>>lbt、lgc、lgcstat、lvmst 这些gdb 扩展命令。
>
> 生成过一次core文件，gdb core文件信息( core 文件是有openresty 1.5.12.1生成的)
> #0 0x00002b6145f2f04c in debug_localname (L=0x41612438, ar=<value optimized
> out>,
> name=0x41611738, slot1=5096856) at lj_debug.c:187
> 187 if (!nextframe) nextframe = L->top;
>

请按我的建议，把 bt full 完整的输出贴出来（建议贴到类似 gist.github.com
的网站上，以节约邮件列表的带宽），并且尝试针对你的 core 运行 nginx gdb utils 中的那些命令。

请尽可能多地尝试我前一封邮件里面的建议 :)

Regards,
-agentzh

姚尉

unread,

May 9, 2014, 4:32:17 AM5/9/14

to open...@googlegroups.com

hello

https://gist.github.com/horizen/c172030d53a4fa99201c 这个地址里有关于这个问题的一些日志和栈信息

--

ywsample :)

姚尉

unread,

May 9, 2014, 4:32:30 AM5/9/14

to open...@googlegroups.com

hello

https://gist.github.com/horizen/c172030d53a4fa99201c 这个地址里有关于这个问题的一些日志和栈信息

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 9, 2014, 6:38:56 PM5/9/14

to openresty

Hello!

2014-05-09 1:32 GMT-07:00 姚尉:
>
> https://gist.github.com/horizen/c172030d53a4fa99201c 这个地址里有关于这个问题的一些日志和栈信息
>

这些信息还不足以定位问题。

请继续按照我前面邮件的其他建议提供更多的细节。特别地：

"
2. 在构造 OpenResty 时，启用其 ./configure 脚本的 --with-debug 选项，此时会开启 LuaJIT
的断言检查和 API 检查。

3. ……使用我们的 nginx gdb utils 项目中的工具从 core dump

得到更多的信息：https://github.com/openresty/nginx-gdb-utils#readme 特别是其中的
lbt、lgc、lgcstat、lvmst 这些gdb 扩展命令。

5. 尝试使用 Valgrind memcheck 工具运行你的 nginx
应用，检查是否有内存问题。在此运行模式下，建议使用下面的命令构造 OpenResty:

./configure --with-debug --with-no-pool-patch \
--with-luajit-xcflags='-DLUAJIT_USE_SYSMALLOC -DLUAJIT_USE_VALGRIND'

然后在 valgrind 运行模式下，在 nginx.conf 中作如下配置：

worker_processes 1;
daemon off;
master_process off;

在用 valgrind 启动 nginx 以后，再用你的测试请求不断访问 nginx，直到 valgrind 产生错误报告。
"

另外，还可以在 nginx.conf 里尝试禁用 JIT 编译器：

init_by_lua '
jit.off()
';

看看是否还能复现问题。

另外，建议不要重复发贴。如果使用 web 界面很容易重复操作的话，建议直接通过电子邮件来访问此列表：

“订阅方法：发送空白邮件到地址 openresty...@googlegroups.com 即可完成订阅。
发贴：在完成订阅之后，直接发送你的讨论邮件到地址 open...@googlegroups.com
”

Regards,
-agentzh

姚尉

unread,

May 13, 2014, 8:57:37 AM5/13/14

to open...@googlegroups.com

hello

最近在尝试复现问题的时候又出现了下面的问题：
worker process: lj_gc.c:812: lj_mem_realloc: Assertion `((uintptr_t)(p) == (uint32_t)(uintptr_t)(p))' failed.
2014/05/13 20:09:48 [alert] 20914#0: worker process 20924 exited on signal 6 (core dumped)

(gdb) bt full
#0 0x0000003717a30265 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x0000003717a31d10 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x0000003717a296e6 in __assert_fail () from /lib64/libc.so.6
No symbol table info available.
#3 0x00002b46217fc73a in lj_mem_realloc (L=0x17ab6ec0, p=<optimized out>, osz=0, nsz=524288)
    at lj_gc.c:812
        g = 0x15dac6c0
        __PRETTY_FUNCTION__ = "lj_mem_realloc"
#4 0x00002b46217ffe5f in lj_str_resize (L=0x51bc, newmask=131071) at lj_str.c:113
        g = 0x15dac6c0
        newhash = <optimized out>
        i = <optimized out>
        __PRETTY_FUNCTION__ = "lj_str_resize"
#5 0x00002b46218001d9 in lj_str_new (L=0x17ab6ec0,
    str=0x7fffb78e64d0 "093ca318-b123-4096-8a1a-acf81791f88c", lenx=<optimized out>)
    at lj_str.c:202
        g = 0x15dac6c0
        s = 0x17afa900
        o = 0x6
        len = 36
        a = <optimized out>
        b = <optimized out>
        h = <optimized out>
        __PRETTY_FUNCTION__ = "lj_str_new"
#6 0x00002b462180c4e9 in lua_pushlstring (L=0x17ab6ec0,
    str=0x7fffb78e64d0 "093ca318-b123-4096-8a1a-acf81791f88c", len=36) at lj_api.c:578
        s = 0x0

(gdb) lgc
The current memory size (allocated by GC): 25547610 bytes
GC分配了很多的内存，我看了下正常的worker并没有分配这么多

问下春哥，这种情况什么时候会出现，在Lua这端会出现内存泄露吗

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 13, 2014, 2:44:39 PM5/13/14

to openresty

Hello!

2014-05-13 5:57 GMT-07:00 姚尉:
> 最近在尝试复现问题的时候又出现了下面的问题：
> worker process: lj_gc.c:812: lj_mem_realloc: Assertion `((uintptr_t)(p) ==
> (uint32_t)(uintptr_t)(p))' failed.
> 2014/05/13 20:09:48 [alert] 20914#0: worker process 20924 exited on signal 6
> (core dumped)
>

这个断言失败通常意味着你的堆已经损坏了。请按我之前的建议使用 valgrind 运行你的应用：

“

5. 尝试使用 Valgrind memcheck 工具运行你的 nginx
应用，检查是否有内存问题。在此运行模式下，建议使用下面的命令构造 OpenResty:

./configure --with-debug --with-no-pool-patch \
--with-luajit-xcflags='-DLUAJIT_USE_SYSMALLOC -DLUAJIT_USE_VALGRIND'

然后在 valgrind 运行模式下，在 nginx.conf 中作如下配置：

worker_processes 1;
daemon off;
master_process off;

在用 valgrind 启动 nginx 以后，再用你的测试请求不断访问 nginx，直到 valgrind 产生错误报告。

”

>
> (gdb) lgc
> The current memory size (allocated by GC): 25547610 bytes
> GC分配了很多的内存，我看了下正常的worker并没有分配这么多
>
> 问下春哥，这种情况什么时候会出现，在Lua这端会出现内存泄露吗
>

25MB 本身这个数字真心不算多。你可以进一步使用 nginx gdb utils 里的 lgcstat 工具检查 Lua GC
对象的统计分布：https://github.com/openresty/nginx-gdb-utils#lgcstat

请注意，LuaJIT 使用的是 incremental GC，所以当你的代码在某个很短的时间区间里分配新内存的速率很快时，GC
需要一些时间跟上脚步。一般应当避免在一个很热的循环里分配很多临时的 GC 对象。不过正如我上面说的，25MB 这个绝对值对于很多真实世界里的
Lua 应用来说，其实是很小的。

Regards,
-agentzh

Yichun Zhang (agentzh)

unread,

May 13, 2014, 2:48:47 PM5/13/14

to openresty

Hello!

2014-05-13 11:44 GMT-07:00 Yichun Zhang (agentzh):
> 2014-05-13 5:57 GMT-07:00 姚尉:
>> 最近在尝试复现问题的时候又出现了下面的问题：
>> worker process: lj_gc.c:812: lj_mem_realloc: Assertion `((uintptr_t)(p) ==
>> (uint32_t)(uintptr_t)(p))' failed.
>> 2014/05/13 20:09:48 [alert] 20914#0: worker process 20924 exited on signal 6
>> (core dumped)
>>
>
> 这个断言失败通常意味着你的堆已经损坏了。

我又仔细看了一下你这个失败断言，这个问题应当是你的配置错误所导致的。你应当是启用了 -DLUAJIT_USE_SYSMALLOC
但却并没有使用 valgrind 运行你的 nginx/luajit，但你不使用 valgrind 时，系统分配器并不能保证在低 2GB
的地址空间里分配内存，从而会导致 checkptr32(p)
这个断言失败。请严格按照我的建议里的步骤来做，不要自己创新，以避免不必要的麻烦。

Regards,
-agentzh

姚尉

unread,

May 14, 2014, 6:13:20 AM5/14/14

to open...@googlegroups.com

hello agentzh

今天又发现了一个断言失败的情况
编译选项只有 --with-debug
2014/05/14 17:44:27 [alert] 8112#0: worker process 8619 exited on signal 11 (core dumped)
worker process: lj_debug.c:103: debug_framepc: Assertion `bc_isret(((BCOp)((ins[-1])&0xff)))' failed.
2014/05/14 17:44:29 [alert] 8112#0: worker process 8620 exited on signal 6 (core dumped)
worker process: lj_debug.c:103: debug_framepc: Assertion `bc_isret(((BCOp)((ins[-1])&0xff)))' failed.

问下春哥应该哪里下手找这个问题的原因呢？

bt full

#2 0x0000003717a296e6 in __assert_fail () from /lib64/libc.so.6
No symbol table info available.

#3 0x00002ad5a1cfbceb in debug_framepc (L=0x40efec78, fn=0x40ca1d78, nextframe=0x0)
    at lj_debug.c:103
        T = 0x40ca5884
        ins = 0x40ca58c0
        pt = 0x40caa658
        pos = 4294962313
        __PRETTY_FUNCTION__ = "debug_framepc"
#4 0x00002ad5a1cfbe3b in debug_frameline (L=0x40efec78, fn=0x40ca1d78, nextframe=0x0)
    at lj_debug.c:133
        pc = 32767
        __PRETTY_FUNCTION__ = "debug_frameline"
#5 0x00002ad5a1cfccf6 in lj_debug_addloc (L=0x40efec78,
    msg=0x421a52e8 "attempt to index a function value", frame=0x42193508, nextframe=0x0)
    at lj_debug.c:356
        line = 0
        fn = 0x40ca1d78
        __PRETTY_FUNCTION__ = "lj_debug_addloc"
#6 0x00002ad5a1cf296e in err_msgv (L=0x40efec78, em=LJ_ERR_BADOPRV) at lj_err.c:579
        msg = 0x421a52e8 "attempt to index a function value"
        argp = {{gp_offset = 32, fp_offset = 48, overflow_arg_area = 0x7fffe406b850,
            reg_save_area = 0x7fffe406b790}}
        __PRETTY_FUNCTION__ = "err_msgv"
#7 0x00002ad5a1cf2c21 in lj_err_optype (L=0x40efec78, o=0x42193528, opm=LJ_ERR_OPINDEX)
    at lj_err.c:616
        tname = 0x2ad5a1db50ca "function"
        opname = 0x2ad5a1db3c9b "index"
        __PRETTY_FUNCTION__ = "lj_err_optype"
#8 0x00002ad5a1cf95f9 in lj_meta_tget (L=0x40efec78, o=0x42193528, k=0x7fffe406b900)
---Type <return> to continue, or q <return> to quit---
    at lj_meta.c:141
        mo = 0x40ee5458
        loop = 0
        __PRETTY_FUNCTION__ = "lj_meta_tget"
#9 0x00002ad5a1cebaf1 in lj_vmeta_tgetv ()
   from /usr/home/yaowei2/work/openresty/luajit/lib/libluajit-5.1.so.2

No symbol table info available.

#10 0x00002ad5a1d0e0d3 in lua_resume (L=0x40efec78, nargs=3) at lj_api.c:1123
No locals.
#11 0x0000000000508e18 in ngx_http_lua_run_thread (L=0x40ee5378, r=0xe8bd620, ctx=0xe845b18, nrets=3)
    at ../ngx_lua-0.9.7/src/ngx_http_lua_util.c:1105
        next_coctx = 0x7fffe406ba30
        parent_coctx = 0x7fffe406ba50
        orig_coctx = 0xe845cf8
        rv = 0
        success = 1
        next_co = 0x51adc5 <ngx_http_lua_socket_tcp_receive_retval_handler+563>
        old_co = 0x40efec78
        err = 0xe845b18 ""
        msg = 0x3717a8c43d <gettimeofday+13> "=\001\360\377\377s\005H\203\304\b\303H\213\rX[,"
        trace = 0x42193570 "\230\326\024B\377\377\377\377\070\002"
        rc = 1089465464
        old_pool = 0x0
#12 0x000000000051fce4 in ngx_http_lua_socket_tcp_resume (r=0xe8bd620)
    at ../ngx_lua-0.9.7/src/ngx_http_lua_socket_tcp.c:4316
        nret = 3
        vm = 0x40ee5378
        rc = 166008
        c = 0x2ad5a23f4370
        ctx = 0xe845b18
        coctx = 0xe845cf8
        u = 0x40efd708
#13 0x000000000050efa9 in ngx_http_lua_content_wev_handler (r=0xe8bd620)
    at ../ngx_lua-0.9.7/src/ngx_http_lua_contentby.c:128

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 14, 2014, 10:06:48 PM5/14/14

to openresty

Hello!

2014-05-14 3:13 GMT-07:00 姚尉:
> 今天又发现了一个断言失败的情况
> 编译选项只有 --with-debug
> 2014/05/14 17:44:27 [alert] 8112#0: worker process 8619 exited on signal 11
> (core dumped)
> worker process: lj_debug.c:103: debug_framepc: Assertion
> `bc_isret(((BCOp)((ins[-1])&0xff)))' failed.
> 2014/05/14 17:44:29 [alert] 8112#0: worker process 8620 exited on signal 6
> (core dumped)
> worker process: lj_debug.c:103: debug_framepc: Assertion
> `bc_isret(((BCOp)((ins[-1])&0xff)))' failed.
>
> 问下春哥应该哪里下手找这个问题的原因呢？
>

这个断言失败经常是因为 LuaJIT 的 PC 寄存器和 BASE 寄存器发生了不一致所致。这有可能是 LuaJIT 的 JIT
编译器生成的机器程序里的问题。不过在此之前，请先尝试能过下面的配置禁用 LuaJIT 的 JIT 编译器，看看你是否仍然可以复现问题：

init_by_lua '
jit.off()
';

把这一段配置放在你的 nginx.conf 文件的 http {} 配置块中。

如果你不再能复现问题，则说明很可能是 JIT 编译器里的 bug，那时候我们再通过检查该断言失败前进出过的那些
trace（即编译过的最小单位的 Lua 代码路径）里的 LuaJIT IR 码和机器码来进行进一步的排查。

Regards,
-agentzh

姚尉

unread,

May 15, 2014, 1:53:18 AM5/15/14

to open...@googlegroups.com

hello

我尝试用valgrind 运行nginx来复现问题，但始终复现不了，但是在多个worker、大并发的情况下，这些问题确实又会发生。但是当我用jit.off 关闭JIT时没有出现过这种问题。

--

ywsample :)

姚尉

unread,

May 16, 2014, 6:04:58 AM5/16/14

to open...@googlegroups.com

hello

而且这个问题大都出现在cosocket receive超时之后，当我把 nginx.conf 里的 init_worker_by_lua_file(cosocket 相关代码在里面) 注释掉之后重新运行也不会出现问题。难道是cosocket receive频繁超时resume light thread增加了这个问题出现的概率？

--

ywsample :)

姚尉

unread,

May 16, 2014, 8:11:43 AM5/16/14

to open...@googlegroups.com

hello

我在浏览之前帖子的时候发现了遇到同样问题的帖子：
https://groups.google.com/forum/#!topic/OpenResty/cLeiYZCpwHs
https://groups.google.com/forum/#!topic/OpenResty/ZhfBFTuIW-E

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 16, 2014, 3:41:39 PM5/16/14

to openresty

Hello!

2014-05-14 22:53 GMT-07:00 姚尉:
> 我尝试用valgrind
> 运行nginx来复现问题，但始终复现不了，但是在多个worker、大并发的情况下，这些问题确实又会发生。但是当我用jit.off
> 关闭JIT时没有出现过这种问题。
>

OK，那么我们就当作 LuaJIT 的 JIT 编译器的问题来调试。下面请你采集一下到断言失败之前运行过的 trace 的相关细节信息。

请下载下面这个 openresty:

http://openresty.org/download/ngx_openresty-1.7.0.1rc0.tar.gz

请使用下面的命令构造之：

./configure --with-debug --with-luajit-xcflags='-DLUA_USE_TRACE_LOGS' -j2
make -j2
sudo make install

然后使用它复现问题，生成 core dump 文件。

接下来更新你的 nginx-gdb-utils 仓库为 master 最新版本：

https://github.com/openresty/nginx-gdb-utils

然后使用里面的 ltracelogs 命令得到最近进出过的 trace 历史：

(gdb) ltracelogs

请把该命令的输出贴到 github gist 这样的地方，并在这里提供对应的链接。

请保留你对应的 core 文件，因为我还需要根据你提供的 ltracelogs 命令的输出检查 core 里更多的细节信息。

多谢！

Best regards,
-agentzh

姚尉

unread,

May 16, 2014, 11:30:53 PM5/16/14

to open...@googlegroups.com

hello

多谢春哥

相应的输出已经贴到gist上了
https://gist.github.com/horizen/48a1fbd6c6c457896e0a

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 16, 2014, 11:37:56 PM5/16/14

to openresty

Hello!

2014-05-16 20:30 GMT-07:00 姚尉:
> 多谢春哥
>
> 相应的输出已经贴到gist上了
> https://gist.github.com/horizen/48a1fbd6c6c457896e0a
>

好极！我看到你把最后进出过的两个 trace 的细节也用 ltrace, lir 和 disas 命令打印出来了。

你的 ltracelogs 输出的最后一行

<-111 L=0x419afe30 direct_exit=0 exitno=0 pc=0x40c62074 fn=0x419a68a0

我想知道其 pc 和 fn 这两个东西是否匹配。请把下面的 gdb 命令的输出也补充到你上面的 gist 上去:

(gdb) lpc 0x40c62074
(gdb) lval (GCfunc*)0x419a68a0

同时请使用类似的方法检查最后进入 trace #111 和最后进出 trace #143 的 pc 和 fn 对是否匹配，也请一并补充到你的 gist 里去。

请注意，你需要使用原先那个 core dump 文件哈！

多谢，多谢！

Best regards,
-agentzh

姚尉

unread,

May 16, 2014, 11:58:15 PM5/16/14

to open...@googlegroups.com

hello

已经更新了，lpc lval相关输出加在tracelog文件里

多谢

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 17, 2014, 12:18:41 AM5/17/14

to openresty

Hello!

2014-05-16 20:58 GMT-07:00 姚尉:
> 已经更新了，lpc lval相关输出加在tracelog文件里
>

果然是在离开最后一个 trace（#111）的时候，pc（即 PC 寄存器）和 fn（得自 BASE 寄存器）出现不一致了，pc 指向的
proto 的开始位置是 rtb.lua:635 而从 BASE 推导出来的 fn 对应的 proto 的开始位置却是
broker1.lua:754－－二者相差很多 :)

多谢你提供的细节！我会把你的 gist 转发给 Mike Pall 进行分析 :)

Thanks!
-agentzh

姚尉

unread,

May 17, 2014, 12:31:42 AM5/17/14

to open...@googlegroups.com

hello

非常感谢春哥的帮助。
还有一个疑问，为什么用了cosocket的api会增加这个问题发生概率，当我把cosocket相关api注释掉的时候基本没有出现过类似的问题

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 18, 2014, 2:28:47 AM5/18/14

to openresty

Hello!

2014-05-16 21:31 GMT-07:00 姚尉:
> 还有一个疑问，为什么用了cosocket的api会增加这个问题发生概率，当我把cosocket相关api注释掉的时候基本没有出现过类似的问题
>

你的 Lua 代码布局和运行细节都会对 JIT 编译器的行为产生蝴蝶效应。我不觉得这与 cosocket 有直接关系（毕竟你禁用 JIT
编译器后无法再复现问题）。

我已经把你提供的相关细节信息转给了 Mike Pall. 我还在等他的回复。

在此期间，你可以再尝试禁掉 JIT 编译器新实现的 trace stitching 特性，看看是否还能复现问题。即在 init_by_lua
里面添加下面这一行 Lua 代码：

require("jit.opt").start("minstitch=10000000")

毕竟 trace stitching 是前不久刚实现的新特性（由我们公司赞助），而且复杂性很高，涉及面很广，比 JIT
编译器的其他部分更有可能出问题（之前已经捕捉并修复了 trace stitching 相关的好几个 bug 了）。

再加上你提供的 trace 历史中，崩溃前执行的最后一个 trace，#111，正是结束于 stitch C function call 的位置上。

多谢！

Best regards,
-agentzh

Yichun Zhang (agentzh)

unread,

May 19, 2014, 1:14:16 AM5/19/14

to openresty

Hello!

2014-05-16 20:30 GMT-07:00 姚尉:

> 相应的输出已经贴到gist上了
> https://gist.github.com/horizen/48a1fbd6c6c457896e0a
>

Mike Pall 注意到问题起始于进入最后一个 trace（而不是离开最后一个 trace），即 ltracelogs 命令输出中的倒数第二行:

->111 L=0x419afe30 pc=0x419b0d0c fn=0x419a68a0

此时 pc 指向的是 broker1.lua:763，而根据“lir 111”命令的 trace #111 本身却是起始于
rtb.lua:646，二者相去甚远。

我们希望能看到 pc 之前的几条 LuaJIT 字节码的内容。所以请在那个 core dump 里面再执行下面两条命令：

(gdb) lbc 0x419b0d0c-4 0x419b0d0c
(gdb) lbc 0x419b0d0c-4*3 0x419b0d0c

并请把输出追加到原来那个 gist 里面去。多谢，多谢！

Best regards,
-agentzh

姚尉

unread,

May 19, 2014, 2:22:26 AM5/19/14

to open...@googlegroups.com

hello

已更新gist

多谢

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 19, 2014, 3:13:17 AM5/19/14

to openresty

Hi!

2014-05-18 23:22 GMT-07:00 姚尉:
> 已更新gist
>

多谢！看起来你的 broker1.lua:763 这一行是在调用 cosocket 对象的 receive() 方法？

Regards,
-agentzh

姚尉

unread,

May 19, 2014, 3:27:45 AM5/19/14

to open...@googlegroups.com

hello

是的

--

ywsample :)

姚尉

unread,

May 22, 2014, 7:51:17 AM5/22/14

to open...@googlegroups.com

hello

这个问题有进展了吗，如果需要我提供更多的信息，随时联系我

>在此期间，你可以再尝试禁掉 JIT 编译器新实现的 trace stitching 特性，看看是否还能复现问题。即在 init_by_lua
>里面添加下面这一行 Lua 代码：
> require("jit.opt").start("minstitch=10000000")
>

添加这行代码后，也几乎没有出现过这个问题

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 22, 2014, 3:59:10 PM5/22/14

to openresty

Hello!

2014-05-22 4:51 GMT-07:00 姚尉:
> 这个问题有进展了吗，如果需要我提供更多的信息，随时联系我
>

目前可以确定是下列两种可能之一（或者皆而有之）：

1. ngx_lua 的协程调度器可能没有严格地平衡 lua stack，尚有待确认。如果真是如此，则和 LuaJIT 的 trace
stitching 特性一起工作时会出现你看到的问题。

2. LuaJIT 的 trace stitching 特性本身有 bug.

我们需要更多的时间进行确认。

>>在此期间，你可以再尝试禁掉 JIT 编译器新实现的 trace stitching 特性，看看是否还能复现问题。即在 init_by_lua
>>里面添加下面这一行 Lua 代码：
>> require("jit.opt").start("minstitch=10000000")
>
> 添加这行代码后，也几乎没有出现过这个问题
>

“几乎”是什么意思？在禁用 trace stitching 之后你仍然看到过崩溃？你能提供相应的 gdb 分析细节吗？

Regards,
-agentzh

姚尉

unread,

May 22, 2014, 10:26:47 PM5/22/14

to open...@googlegroups.com

hello

"几乎"是指在目前测试的情况来看没有发生过。用词不当，不好意思。

--

ywsample :)

Yichun Zhang (agentzh)

unread,

May 23, 2014, 12:36:05 AM5/23/14

to openresty

Hello!

2014-05-22 19:26 GMT-07:00 姚尉:
>
> "几乎"是指在目前测试的情况来看没有发生过。用词不当，不好意思。
>

OK. 那么眼下就先禁用 trace stitching 特性吧。这毕竟 trace stitching 只是一种优化。

Regards,
-agentzh

Reply all

Reply to author

Forward