openresty的luajit库进入死循环导致CPU100%的问题

blueswind830630 · 2016-09-26T14:48:52+00:00

Hello! 2016-11-07 21:13 GMT-08:00 yunthanatos: > 现在还有一个小问题是关于lua-rest...

openresty的luajit库进入死循环导致CPU100%的问题

blueswind830630

最近发现线上服务会有CPU100%的问题出现，并且一旦出现后即使没有请求了也还会保持CPU100%。应该是跑到死循环里面去了，各位大神帮忙看看：

(gdb) bt

#0 ctype_get (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:402

#1 ctype_child (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:413

#2 ctype_raw (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:420

#3 lj_ccall_func (L=0x406c6b78, cd=0x411794b8) at lj_ccall.c:972

#4 0x00007f2a1720bbe6 in lj_cf_ffi_meta___call (L=<value optimized out>) at lib_ffi.c:230

#5 0x00007f2a171b5907 in lj_BC_FUNCC () from /opt/data-qkpack-ngproxy/luajit/lib/libluajit-5.1.so.2

#6 0x00000000004baf30 in ngx_http_lua_run_thread (L=0x41c5f378, r=0x7f2a09bb47c0, ctx=0x7f2a09b98400, nrets=0)

at ../ngx_lua-0.10.6/src/ngx_http_lua_util.c:1005

#7 0x00000000004bc94c in ngx_http_lua_content_by_chunk (L=0x41c5f378, r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:120

#8 0x00000000004bccf4 in ngx_http_lua_content_handler_file (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:284

#9 0x00000000004bcdfe in ngx_http_lua_content_handler (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:222

#10 0x000000000044f300 in ngx_http_core_content_phase (r=0x7f2a09bb47c0, ph=<value optimized out>) at src/http/ngx_http_core_module.c:1379

#11 0x00000000004495ed in ngx_http_core_run_phases (r=0x7f2a09bb47c0) at src/http/ngx_http_core_module.c:856

#12 0x0000000000454221 in ngx_http_process_request (r=0x7f2a09bb47c0) at src/http/ngx_http_request.c:1916

#13 0x0000000000454edc in ngx_http_process_request_line (rev=0x7f2a0ae7a1f0) at src/http/ngx_http_request.c:1027

#14 0x000000000043fea5 in ngx_epoll_process_events (cycle=<value optimized out>, timer=<value optimized out>, flags=<value optimized out>)

at src/event/modules/ngx_epoll_module.c:900

#15 0x0000000000437c25 in ngx_process_events_and_timers (cycle=0x7f2a16e8c680) at src/event/ngx_event.c:242

#16 0x000000000043e208 in ngx_worker_process_cycle (cycle=0x7f2a16e8c680, data="" optimized out>) at src/os/unix/ngx_process_cycle.c:753

#17 0x000000000043c847 in ngx_spawn_process (cycle=0x7f2a16e8c680, proc=0x43e1d0 <ngx_worker_process_cycle>, data="" name=0x4f22f5 "worker process",

respawn=-3) at src/os/unix/ngx_process.c:198

#18 0x000000000043d70c in ngx_start_worker_processes (cycle=0x7f2a16e8c680, n=24, type=-3) at src/os/unix/ngx_process_cycle.c:358

#19 0x000000000043e884 in ngx_master_process_cycle (cycle=0x7f2a16e8c680) at src/os/unix/ngx_process_cycle.c:130

#20 0x000000000041c08f in main (argc=<value optimized out>, argv=<value optimized out>) at src/core/nginx.c:367

看代码lj_ctype.h的420行附近：

416 /* Get raw type for a C type ID. */

417 static LJ_AINLINE CType *ctype_raw(CTState *cts, CTypeID id)

418 {

419 CType *ct = ctype_get(cts, id);

420 while (ctype_isattrib(ct->info)) ct = ctype_child(cts, ct);

421 return ct;

422 }

怀疑是这个while循环死循环了。现在的问题是，什么情况下会导致这种死循环存在？是luajit的bug吗？多谢各位帮忙！

blueswind830630

补充一下，luajit版本：LuaJIT-2.1.0-beta2

On Monday, September 26, 2016 at 2:48:52 PM UTC+8, 高嵩 wrote:

最近发现线上服务会有CPU100%的问题出现，并且一旦出现后即使没有请求了也还会保持CPU100%。应该是跑到死循环里面去了，各位大神帮忙看看：

(gdb) bt
#0 ctype_get (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:402
#1 ctype_child (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:413
#2 ctype_raw (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:420
#3 lj_ccall_func (L=0x406c6b78, cd=0x411794b8) at lj_ccall.c:972
#4 0x00007f2a1720bbe6 in lj_cf_ffi_meta___call (L=<value optimized out>) at lib_ffi.c:230
#5 0x00007f2a171b5907 in lj_BC_FUNCC () from /opt/data-qkpack-ngproxy/luajit/lib/libluajit-5.1.so.2
#6 0x00000000004baf30 in ngx_http_lua_run_thread (L=0x41c5f378, r=0x7f2a09bb47c0, ctx=0x7f2a09b98400, nrets=0)
at ../ngx_lua-0.10.6/src/ngx_http_lua_util.c:1005
#7 0x00000000004bc94c in ngx_http_lua_content_by_chunk (L=0x41c5f378, r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:120
#8 0x00000000004bccf4 in ngx_http_lua_content_handler_file (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:284
#9 0x00000000004bcdfe in ngx_http_lua_content_handler (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:222
#10 0x000000000044f300 in ngx_http_core_content_phase (r=0x7f2a09bb47c0, ph=<value optimized out>) at src/http/ngx_http_core_module.c:1379
#11 0x00000000004495ed in ngx_http_core_run_phases (r=0x7f2a09bb47c0) at src/http/ngx_http_core_module.c:856
#12 0x0000000000454221 in ngx_http_process_request (r=0x7f2a09bb47c0) at src/http/ngx_http_request.c:1916
#13 0x0000000000454edc in ngx_http_process_request_line (rev=0x7f2a0ae7a1f0) at src/http/ngx_http_request.c:1027
#14 0x000000000043fea5 in ngx_epoll_process_events (cycle=<value optimized out>, timer=<value optimized out>, flags=<value optimized out>)
at src/event/modules/ngx_epoll_module.c:900
#15 0x0000000000437c25 in ngx_process_events_and_timers (cycle=0x7f2a16e8c680) at src/event/ngx_event.c:242
#16 0x000000000043e208 in ngx_worker_process_cycle (cycle=0x7f2a16e8c680, data="" optimized out>) at src/os/unix/ngx_process_cycle.c:753
#17 0x000000000043c847 in ngx_spawn_process (cycle=0x7f2a16e8c680, proc=0x43e1d0 <ngx_worker_process_cycle>, data="" name=0x4f22f5 "worker process",
respawn=-3) at src/os/unix/ngx_process.c:198
#18 0x000000000043d70c in ngx_start_worker_processes (cycle=0x7f2a16e8c680, n=24, type=-3) at src/os/unix/ngx_process_cycle.c:358
#19 0x000000000043e884 in ngx_master_process_cycle (cycle=0x7f2a16e8c680) at src/os/unix/ngx_process_cycle.c:130
#20 0x000000000041c08f in main (argc=<value optimized out>, argv=<value optimized out>) at src/core/nginx.c:367

看代码lj_ctype.h的420行附近：
416 /* Get raw type for a C type ID. */
417 static LJ_AINLINE CType *ctype_raw(CTState *cts, CTypeID id)
418 {
419 CType *ct = ctype_get(cts, id);
420 while (ctype_isattrib(ct->info)) ct = ctype_child(cts, ct);
421 return ct;
422 }

怀疑是这个while循环死循环了。现在的问题是，什么情况下会导致这种死循环存在？是luajit的bug吗？多谢各位帮忙！

moonbingbing

你用 on-CPU 火焰图分析看看，会更直观：

https://github.com/openresty/nginx-systemtap-toolkit#sample-bt （C 级别）

https://github.com/openresty/stapxx#lj-lua-stacks （Lua 级别）

2016-09-26 14:50 GMT+08:00 高嵩 <blueswi...@gmail.com>:

补充一下，luajit版本：LuaJIT-2.1.0-beta2

On Monday, September 26, 2016 at 2:48:52 PM UTC+8, 高嵩 wrote:
最近发现线上服务会有CPU100%的问题出现，并且一旦出现后即使没有请求了也还会保持CPU100%。应该是跑到死循环里面去了，各位大神帮忙看看：

(gdb) bt
#0 ctype_get (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:402
#1 ctype_child (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:413
#2 ctype_raw (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:420
#3 lj_ccall_func (L=0x406c6b78, cd=0x411794b8) at lj_ccall.c:972
#4 0x00007f2a1720bbe6 in lj_cf_ffi_meta___call (L=<value optimized out>) at lib_ffi.c:230
#5 0x00007f2a171b5907 in lj_BC_FUNCC () from /opt/data-qkpack-ngproxy/luajit/lib/libluajit-5.1.so.2
#6 0x00000000004baf30 in ngx_http_lua_run_thread (L=0x41c5f378, r=0x7f2a09bb47c0, ctx=0x7f2a09b98400, nrets=0)
at ../ngx_lua-0.10.6/src/ngx_http_lua_util.c:1005
#7 0x00000000004bc94c in ngx_http_lua_content_by_chunk (L=0x41c5f378, r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:120
#8 0x00000000004bccf4 in ngx_http_lua_content_handler_file (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:284
#9 0x00000000004bcdfe in ngx_http_lua_content_handler (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:222
#10 0x000000000044f300 in ngx_http_core_content_phase (r=0x7f2a09bb47c0, ph=<value optimized out>) at src/http/ngx_http_core_module.c:1379
#11 0x00000000004495ed in ngx_http_core_run_phases (r=0x7f2a09bb47c0) at src/http/ngx_http_core_module.c:856
#12 0x0000000000454221 in ngx_http_process_request (r=0x7f2a09bb47c0) at src/http/ngx_http_request.c:1916
#13 0x0000000000454edc in ngx_http_process_request_line (rev=0x7f2a0ae7a1f0) at src/http/ngx_http_request.c:1027
#14 0x000000000043fea5 in ngx_epoll_process_events (cycle=<value optimized out>, timer=<value optimized out>, flags=<value optimized out>)
at src/event/modules/ngx_epoll_module.c:900
#15 0x0000000000437c25 in ngx_process_events_and_timers (cycle=0x7f2a16e8c680) at src/event/ngx_event.c:242
#16 0x000000000043e208 in ngx_worker_process_cycle (cycle=0x7f2a16e8c680, data="" optimized out>) at src/os/unix/ngx_process_cycle.c:753
#17 0x000000000043c847 in ngx_spawn_process (cycle=0x7f2a16e8c680, proc=0x43e1d0 <ngx_worker_process_cycle>, data="" name=0x4f22f5 "worker process",
respawn=-3) at src/os/unix/ngx_process.c:198
#18 0x000000000043d70c in ngx_start_worker_processes (cycle=0x7f2a16e8c680, n=24, type=-3) at src/os/unix/ngx_process_cycle.c:358
#19 0x000000000043e884 in ngx_master_process_cycle (cycle=0x7f2a16e8c680) at src/os/unix/ngx_process_cycle.c:130
#20 0x000000000041c08f in main (argc=<value optimized out>, argv=<value optimized out>) at src/core/nginx.c:367

看代码lj_ctype.h的420行附近：
416 /* Get raw type for a C type ID. */
417 static LJ_AINLINE CType *ctype_raw(CTState *cts, CTypeID id)
418 {
419 CType *ct = ctype_get(cts, id);
420 while (ctype_isattrib(ct->info)) ct = ctype_child(cts, ct);
421 return ct;
422 }

怀疑是这个while循环死循环了。现在的问题是，什么情况下会导致这种死循环存在？是luajit的bug吗？多谢各位帮忙！

--

blueswind830630

谢谢WenMing，我用sample-bt生成了火焰图，确认是进入死循环了，火焰图如下，请各位帮忙看看：

On Monday, September 26, 2016 at 5:12:52 PM UTC+8, WenMing wrote:

你用 on-CPU 火焰图分析看看，会更直观：

https://github.com/openresty/nginx-systemtap-toolkit#sample-bt （C 级别）

https://github.com/openresty/stapxx#lj-lua-stacks （Lua 级别）

2016-09-26 14:50 GMT+08:00 高嵩 <blueswi...@gmail.com>:
补充一下，luajit版本：LuaJIT-2.1.0-beta2

On Monday, September 26, 2016 at 2:48:52 PM UTC+8, 高嵩 wrote:
最近发现线上服务会有CPU100%的问题出现，并且一旦出现后即使没有请求了也还会保持CPU100%。应该是跑到死循环里面去了，各位大神帮忙看看：

(gdb) bt
#0 ctype_get (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:402
#1 ctype_child (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:413
#2 ctype_raw (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:420
#3 lj_ccall_func (L=0x406c6b78, cd=0x411794b8) at lj_ccall.c:972
#4 0x00007f2a1720bbe6 in lj_cf_ffi_meta___call (L=<value optimized out>) at lib_ffi.c:230
#5 0x00007f2a171b5907 in lj_BC_FUNCC () from /opt/data-qkpack-ngproxy/luajit/lib/libluajit-5.1.so.2
#6 0x00000000004baf30 in ngx_http_lua_run_thread (L=0x41c5f378, r=0x7f2a09bb47c0, ctx=0x7f2a09b98400, nrets=0)
at ../ngx_lua-0.10.6/src/ngx_http_lua_util.c:1005
#7 0x00000000004bc94c in ngx_http_lua_content_by_chunk (L=0x41c5f378, r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:120
#8 0x00000000004bccf4 in ngx_http_lua_content_handler_file (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:284
#9 0x00000000004bcdfe in ngx_http_lua_content_handler (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:222
#10 0x000000000044f300 in ngx_http_core_content_phase (r=0x7f2a09bb47c0, ph=<value optimized out>) at src/http/ngx_http_core_module.c:1379
#11 0x00000000004495ed in ngx_http_core_run_phases (r=0x7f2a09bb47c0) at src/http/ngx_http_core_module.c:856
#12 0x0000000000454221 in ngx_http_process_request (r=0x7f2a09bb47c0) at src/http/ngx_http_request.c:1916
#13 0x0000000000454edc in ngx_http_process_request_line (rev=0x7f2a0ae7a1f0) at src/http/ngx_http_request.c:1027
#14 0x000000000043fea5 in ngx_epoll_process_events (cycle=<value optimized out>, timer=<value optimized out>, flags=<value optimized out>)
at src/event/modules/ngx_epoll_module.c:900
#15 0x0000000000437c25 in ngx_process_events_and_timers (cycle=0x7f2a16e8c680) at src/event/ngx_event.c:242
#16 0x000000000043e208 in ngx_worker_process_cycle (cycle=0x7f2a16e8c680, data="" optimized out>) at src/os/unix/ngx_process_cycle.c:753
#17 0x000000000043c847 in ngx_spawn_process (cycle=0x7f2a16e8c680, proc=0x43e1d0 <ngx_worker_process_cycle>, data="" name=0x4f22f5 "worker process",
respawn=-3) at src/os/unix/ngx_process.c:198
#18 0x000000000043d70c in ngx_start_worker_processes (cycle=0x7f2a16e8c680, n=24, type=-3) at src/os/unix/ngx_process_cycle.c:358
#19 0x000000000043e884 in ngx_master_process_cycle (cycle=0x7f2a16e8c680) at src/os/unix/ngx_process_cycle.c:130
#20 0x000000000041c08f in main (argc=<value optimized out>, argv=<value optimized out>) at src/core/nginx.c:367

看代码lj_ctype.h的420行附近：
416 /* Get raw type for a C type ID. */
417 static LJ_AINLINE CType *ctype_raw(CTState *cts, CTypeID id)
418 {
419 CType *ct = ctype_get(cts, id);
420 while (ctype_isattrib(ct->info)) ct = ctype_child(cts, ct);
421 return ct;
422 }

怀疑是这个while循环死循环了。现在的问题是，什么情况下会导致这种死循环存在？是luajit的bug吗？多谢各位帮忙！

--

yuansheng

On Mon, Sep 26, 2016 at 7:24 PM, 高嵩 <blueswi...@gmail.com> wrote:

谢谢WenMing，我用sample-bt生成了火焰图，确认是进入死循环了，火焰图如下，请各位帮忙看看：

On Monday, September 26, 2016 at 5:12:52 PM UTC+8, WenMing wrote:
你用 on-CPU 火焰图分析看看，会更直观：

https://github.com/openresty/nginx-systemtap-toolkit#sample-bt （C 级别）

https://github.com/openresty/stapxx#lj-lua-stacks （Lua 级别）

用这个获取一下lua火焰图

下次直接上传火焰图原始 svg 文件，更清晰。

2016-09-26 14:50 GMT+08:00 高嵩 <blueswi...@gmail.com>:
补充一下，luajit版本：LuaJIT-2.1.0-beta2

On Monday, September 26, 2016 at 2:48:52 PM UTC+8, 高嵩 wrote:
最近发现线上服务会有CPU100%的问题出现，并且一旦出现后即使没有请求了也还会保持CPU100%。应该是跑到死循环里面去了，各位大神帮忙看看：

(gdb) bt
#0 ctype_get (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:402
#1 ctype_child (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:413
#2 ctype_raw (L=0x406c6b78, cd=0x411794b8) at lj_ctype.h:420
#3 lj_ccall_func (L=0x406c6b78, cd=0x411794b8) at lj_ccall.c:972
#4 0x00007f2a1720bbe6 in lj_cf_ffi_meta___call (L=<value optimized out>) at lib_ffi.c:230
#5 0x00007f2a171b5907 in lj_BC_FUNCC () from /opt/data-qkpack-ngproxy/luajit/lib/libluajit-5.1.so.2
#6 0x00000000004baf30 in ngx_http_lua_run_thread (L=0x41c5f378, r=0x7f2a09bb47c0, ctx=0x7f2a09b98400, nrets=0)
at ../ngx_lua-0.10.6/src/ngx_http_lua_util.c:1005
#7 0x00000000004bc94c in ngx_http_lua_content_by_chunk (L=0x41c5f378, r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:120
#8 0x00000000004bccf4 in ngx_http_lua_content_handler_file (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:284
#9 0x00000000004bcdfe in ngx_http_lua_content_handler (r=0x7f2a09bb47c0) at ../ngx_lua-0.10.6/src/ngx_http_lua_contentby.c:222
#10 0x000000000044f300 in ngx_http_core_content_phase (r=0x7f2a09bb47c0, ph=<value optimized out>) at src/http/ngx_http_core_module.c:1379
#11 0x00000000004495ed in ngx_http_core_run_phases (r=0x7f2a09bb47c0) at src/http/ngx_http_core_module.c:856
#12 0x0000000000454221 in ngx_http_process_request (r=0x7f2a09bb47c0) at src/http/ngx_http_request.c:1916
#13 0x0000000000454edc in ngx_http_process_request_line (rev=0x7f2a0ae7a1f0) at src/http/ngx_http_request.c:1027
#14 0x000000000043fea5 in ngx_epoll_process_events (cycle=<value optimized out>, timer=<value optimized out>, flags=<value optimized out>)
at src/event/modules/ngx_epoll_module.c:900
#15 0x0000000000437c25 in ngx_process_events_and_timers (cycle=0x7f2a16e8c680) at src/event/ngx_event.c:242
#16 0x000000000043e208 in ngx_worker_process_cycle (cycle=0x7f2a16e8c680, data="" optimized out>) at src/os/unix/ngx_process_cycle.c:753
#17 0x000000000043c847 in ngx_spawn_process (cycle=0x7f2a16e8c680, proc=0x43e1d0 <ngx_worker_process_cycle>, data="" name=0x4f22f5 "worker process",
respawn=-3) at src/os/unix/ngx_process.c:198
#18 0x000000000043d70c in ngx_start_worker_processes (cycle=0x7f2a16e8c680, n=24, type=-3) at src/os/unix/ngx_process_cycle.c:358
#19 0x000000000043e884 in ngx_master_process_cycle (cycle=0x7f2a16e8c680) at src/os/unix/ngx_process_cycle.c:130
#20 0x000000000041c08f in main (argc=<value optimized out>, argv=<value optimized out>) at src/core/nginx.c:367

看代码lj_ctype.h的420行附近：
416 /* Get raw type for a C type ID. */
417 static LJ_AINLINE CType *ctype_raw(CTState *cts, CTypeID id)
418 {
419 CType *ct = ctype_get(cts, id);
420 while (ctype_isattrib(ct->info)) ct = ctype_child(cts, ct);
421 return ct;
422 }

怀疑是这个while循环死循环了。现在的问题是，什么情况下会导致这种死循环存在？是luajit的bug吗？多谢各位帮忙！

--

--

YuanSheng Wang

---------------------------------------

My Github: https://github.com/membphis

OpenResty lover ^_^