LuaJIT assertion failures

rgomes · 2013-05-28T23:53:41+00:00

I think existing modules are the best current documentation. It's been on my list for ages to do a quick tutorial, but I haven't had the time. ...

LuaJIT assertion failures

rgomes

I'm seeing worrisome LuaJIT assertion failures being thrown by my openresty instance:

lj_ctype.h:395: ctype_check: Assertion `id > 0 && id < cts->top' failed.

and sometimes this:

lj_state.c:169: close_state: Assertion `g->gc.total == sizeof(GG_State)' failed.

It's not triggered by anything helpfully obvious, like accesses to a particular page or something like that.

The abrupt failure of nginx is of course visible to clients downloading at that moment.

I haven't yet tried running without LuaJIT but it seems that I'll have to try doing that (i.e. running with the interpreter) if I can't prevent these assertion failures from happening, though I'm not sure what the effect of that will be on performance. Fortunately none of this is actually in production yet but banishing this problem is certainly a prerequisite to production use.

The version of LuaJIT bundled with openresty is 2.0.1, which seems to be the latest. Is there any newer release planned in the near future?

agentzh

Hello!

On Tue, May 28, 2013 at 8:53 AM, Ron Gomes wrote:
> I'm seeing worrisome LuaJIT assertion failures being thrown by my openresty
> instance:
>
> lj_ctype.h:395: ctype_check: Assertion `id > 0 && id < cts->top' failed.
>
> and sometimes this:
>
> lj_state.c:169: close_state: Assertion `g->gc.total == sizeof(GG_State)'
> failed.
>
> It's not triggered by anything helpfully obvious, like accesses to a
> particular page or something like that.
>

Thank you for the report!

Could you please try to obtain a minimized example that can reproduce
this issue? Or at least obtain backtraces at the assertion failures
with tools like gdb? (You're recommended to pass CCDEBUG=-g to the
"make" command while building LuaJIT.)

> The abrupt failure of nginx is of course visible to clients downloading at
> that moment.
>

Yes, the Nginx worker should crash at such failures.

> I haven't yet tried running without LuaJIT but it seems that I'll have to
> try doing that (i.e. running with the interpreter) if I can't prevent these
> assertion failures from happening, though I'm not sure what the effect of
> that will be on performance.  Fortunately none of this is actually in
> production yet but banishing this problem is certainly a prerequisite to
> production use.
>

As long as we can reproduce this or at least get enough information,
we can fix it (either in ngx_lua or LuaJIT or both). I'm very
interested in fixing such assertion failures.

> The version of LuaJIT bundled with openresty is 2.0.1, which seems to be the
> latest.  Is there any newer release planned in the near future?
>

Which version of ngx_openresty are you using? I'm wondering

Because LuaJIT 2.0.2 is around the corner, you can just try out the
git master HEAD of LuaJIT 2.0:

    http://luajit.org/download.html

Best regards,
-agentzh

rgomes

Thanks. I'll try rebuilding LuaJIT with CCDEBUG=-g, and I'll also try the newer LuaJIT. (And I'll also try the interpreter but I hope it doesn't come to that.)

In the meantime here's the stack trace (without -g) displayed by gdb on a recent failure:

#0 0x0000003e5ba329a5 in raise () from /lib64/libc.so.6

#1 0x0000003e5ba34185 in abort () from /lib64/libc.so.6

#2 0x0000003e5ba2b935 in __assert_fail () from /lib64/libc.so.6

#3 0x00007ffff7daadab in ctype_check (g=<value optimized out>,

cd=<value optimized out>) at lj_ctype.h:395

#4 ctype_get (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:402

#5 ctype_child (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:413

#6 ctype_raw (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:420

#7 lj_cdata_free (g=<value optimized out>, cd=<value optimized out>)

at lj_cdata.c:69

#8 0x00007ffff7d6739d in gc_sweep (g=0x400003b8, p=0x40048200, lim=23)

at lj_gc.c:405

#9 0x00007ffff7d685ac in gc_onestep (L=0x40011580) at lj_gc.c:632

#10 0x00007ffff7d68d28 in lj_gc_step (L=0x40011580) at lj_gc.c:676

#11 0x00007ffff7d7a851 in lj_parse_keepstr (ls=0x7fffffffbfc0,

str=<value optimized out>, len=<value optimized out>) at lj_parse.c:238

#12 0x00007ffff7d77bf2 in read_string (ls=0x7fffffffbfc0, tv=0x7fffffffbfd0)

at lj_lex.c:255

#13 llex (ls=0x7fffffffbfc0, tv=0x7fffffffbfd0) at lj_lex.c:338

#14 0x00007ffff7d77dad in lj_lex_next (ls=0x7fffffffbfc0) at lj_lex.c:430

#15 0x00007ffff7d7bf88 in lex_opt (ls=0x7fffffffbfc0, e=0x7fffffffba30)

at lj_parse.c:985

#16 expr_table (ls=0x7fffffffbfc0, e=0x7fffffffba30) at lj_parse.c:1787

#17 0x00007ffff7d7aba3 in expr_simple (ls=0x7fffffffbfc0, v=0x7fffffffba30,

limit=0) at lj_parse.c:2028

#18 expr_unop (ls=0x7fffffffbfc0, v=0x7fffffffba30, limit=0) at lj_parse.c:2101

#19 expr_binop (ls=0x7fffffffbfc0, v=0x7fffffffba30, limit=0)

at lj_parse.c:2114

#20 0x00007ffff7d7c255 in expr (ls=<value optimized out>,

v=<value optimized out>) at lj_parse.c:2133

#21 expr_list (ls=<value optimized out>, v=<value optimized out>)

at lj_parse.c:1901

#22 0x00007ffff7d7c7b8 in parse_assignment (ls=0x7fffffffbfc0,

lh=0x7fffffffbaf0, nvars=1) at lj_parse.c:2224

#23 0x00007ffff7d7cab3 in parse_call_assign (ls=0x7fffffffbfc0)

at lj_parse.c:2257

#24 parse_stmt (ls=0x7fffffffbfc0) at lj_parse.c:2695

#25 parse_chunk (ls=0x7fffffffbfc0) at lj_parse.c:2707

#26 0x00007ffff7d7d98e in lj_parse (ls=0x7fffffffbfc0) at lj_parse.c:2740

#27 0x00007ffff7d8015b in cpparser (L=0x40011580, dummy=<value optimized out>,

ud=0x7fffffffbfc0) at lj_load.c:41

#28 0x00007ffff7d651d0 in lj_vm_cpcall ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#29 0x00007ffff7d7fe1d in lua_loadx (L=0x40011580,

reader=<value optimized out>, data="" optimized out>,

chunkname=<value optimized out>, mode=<value optimized out>)

at lj_load.c:58

#30 0x00007ffff7d7ff68 in luaL_loadfilex (L=0x40011580,

filename=0x40008dc0 "/usr/local/openresty/nginx/lua/doorman_global_config.lua", mode=0x0) at lj_load.c:101

#31 0x00007ffff7dc05fa in lj_cf_package_loader_lua (L=0x40011580)

at lib_package.c:345

#32 0x00007ffff7d64e8f in lj_BC_FUNCC ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#33 0x00007ffff7dbfadd in lj_cf_package_require (L=0x40011580)

at lib_package.c:423

#34 0x00007ffff7d64e8f in lj_BC_FUNCC ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#35 0x000000000049ef3b in ngx_http_lua_run_thread (L=0x40000378, r=0x77e650,

ctx=0x77f878, nrets=0) at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

#36 0x00000000004a25fd in ngx_http_lua_rewrite_by_chunk (L=0x40000378,

r=0x77e650) at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:306

#37 0x00000000004a2763 in ngx_http_lua_rewrite_handler_file (r=0x77e650)

at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:224

#38 0x00000000004a2a23 in ngx_http_lua_rewrite_handler (r=0x77e650)

at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:140

---Type <return> to continue, or q <return> to quit---

#39 0x000000000043fa73 in ngx_http_core_rewrite_phase (r=0x77e650, ph=0x77bba0)

at src/http/ngx_http_core_module.c:942

#40 0x000000000043b2c3 in ngx_http_core_run_phases (r=0x77e650)

at src/http/ngx_http_core_module.c:888

#41 0x000000000043b3bd in ngx_http_handler (r=<value optimized out>)

at src/http/ngx_http_core_module.c:871

#42 0x0000000000445f94 in ngx_http_process_request (r=0x77e650)

at src/http/ngx_http_request.c:1692

#43 0x00000000004465fc in ngx_http_process_request_headers (

rev=<value optimized out>) at src/http/ngx_http_request.c:1140

#44 0x0000000000446c09 in ngx_http_process_request_line (rev=0x7b2738)

at src/http/ngx_http_request.c:936

#45 0x000000000044359d in ngx_http_init_request (rev=0x7b2738)

at src/http/ngx_http_request.c:520

#46 0x0000000000434879 in ngx_epoll_process_events (cycle=0x73d990,

timer=<value optimized out>, flags=<value optimized out>)

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

#47 0x000000000042c2d3 in ngx_process_events_and_timers (cycle=0x73d990)

at src/event/ngx_event.c:247

#48 0x00000000004330d8 in ngx_worker_process_cycle (cycle=0x73d990,

data="" optimized out>) at src/os/unix/ngx_process_cycle.c:813

#49 0x00000000004318c5 in ngx_spawn_process (cycle=0x73d990,

proc=0x432fe2 <ngx_worker_process_cycle>, data="">

name=0x4cb69b "worker process", respawn=-3)

at src/os/unix/ngx_process.c:198

#50 0x0000000000432563 in ngx_start_worker_processes (cycle=0x73d990, n=1,

type=-3) at src/os/unix/ngx_process_cycle.c:364

#51 0x000000000043374e in ngx_master_process_cycle (cycle=0x73d990)

at src/os/unix/ngx_process_cycle.c:136

#52 0x0000000000416bea in main (argc=<value optimized out>,

argv=<value optimized out>) at src/core/nginx.c:412

On Tuesday, May 28, 2013 3:40:28 PM UTC-4, agentzh wrote:

Hello!

On Tue, May 28, 2013 at 8:53 AM, Ron Gomes wrote:
> I'm seeing worrisome LuaJIT assertion failures being thrown by my openresty
> instance:
>
> lj_ctype.h:395: ctype_check: Assertion `id > 0 && id < cts->top' failed.
>
> and sometimes this:
>
> lj_state.c:169: close_state: Assertion `g->gc.total == sizeof(GG_State)'
> failed.
>
> It's not triggered by anything helpfully obvious, like accesses to a
> particular page or something like that.
>

Thank you for the report!

Could you please try to obtain a minimized example that can reproduce
this issue? Or at least obtain backtraces at the assertion failures
with tools like gdb? (You're recommended to pass CCDEBUG=-g to the
"make" command while building LuaJIT.)

> The abrupt failure of nginx is of course visible to clients downloading at
> that moment.
>

Yes, the Nginx worker should crash at such failures.

> I haven't yet tried running without LuaJIT but it seems that I'll have to
> try doing that (i.e. running with the interpreter) if I can't prevent these
> assertion failures from happening, though I'm not sure what the effect of
> that will be on performance. Fortunately none of this is actually in
> production yet but banishing this problem is certainly a prerequisite to
> production use.
>

As long as we can reproduce this or at least get enough information,
we can fix it (either in ngx_lua or LuaJIT or both). I'm very
interested in fixing such assertion failures.

> The version of LuaJIT bundled with openresty is 2.0.1, which seems to be the
> latest. Is there any newer release planned in the near future?
>

Which version of ngx_openresty are you using? I'm wondering

Because LuaJIT 2.0.2 is around the corner, you can just try out the
git master HEAD of LuaJIT 2.0:

http://luajit.org/download.html

Best regards,
-agentzh

rgomes

Here's another stack trace after rebuilding LuaJIT with -g, though it doesn't look very different.

I neglected to mention that there is one additional module (ngx_cache_purge) that I'm including in the build. I'm using the latest openresty bundle (1.2.8.5) and it's configured this way:

./configure \

--with-luajit \

--with-luajit-xcflags=-g \

--add-module=/usr/local/src/nginx-modules/ngx_cache_purge \

--with-debug

Program received signal SIGABRT, Aborted.

0x0000003e5ba329a5 in raise () from /lib64/libc.so.6

(gdb) where

#0 0x0000003e5ba329a5 in raise () from /lib64/libc.so.6

#1 0x0000003e5ba34185 in abort () from /lib64/libc.so.6

#2 0x0000003e5ba2b935 in __assert_fail () from /lib64/libc.so.6

#3 0x00007f278a15adab in ctype_check (g=<value optimized out>,

cd=<value optimized out>) at lj_ctype.h:395

#4 ctype_get (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:402

#5 ctype_child (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:413

#6 ctype_raw (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:420

#7 lj_cdata_free (g=<value optimized out>, cd=<value optimized out>)

at lj_cdata.c:69

#8 0x00007f278a11739d in gc_sweep (g=0x41a813b8, p=0x405a23e8, lim=36)

at lj_gc.c:405

#9 0x00007f278a1185ac in gc_onestep (L=0x40d24ba8) at lj_gc.c:632

#10 0x00007f278a118d28 in lj_gc_step (L=0x40d24ba8) at lj_gc.c:676

#11 0x00007f278a12a851 in lj_parse_keepstr (ls=0x7fff4b842c30,

str=<value optimized out>, len=<value optimized out>) at lj_parse.c:238

#12 0x00007f278a127a9f in llex (ls=0x7fff4b842c30, tv=0x7fff4b842c40)

at lj_lex.c:274

#13 0x00007f278a127dad in lj_lex_next (ls=0x7fff4b842c30) at lj_lex.c:430

#14 0x00007f278a12aa6e in parse_body (ls=0x7fff4b842c30, e=0x7fff4b842160,

needself=<value optimized out>, line=446) at lj_parse.c:1894

#15 0x00007f278a12b805 in expr_simple (ls=0x7fff4b842c30, v=0x7fff4b842160,

limit=1) at lj_parse.c:2032

#16 expr_unop (ls=0x7fff4b842c30, v=0x7fff4b842160, limit=1) at lj_parse.c:2101

#17 expr_binop (ls=0x7fff4b842c30, v=0x7fff4b842160, limit=1)

at lj_parse.c:2114

#18 0x00007f278a12b1af in expr_binop (ls=0x7fff4b842c30, v=0x7fff4b842290,

limit=0) at lj_parse.c:2122

#19 0x00007f278a12c255 in expr (ls=<value optimized out>,

v=<value optimized out>) at lj_parse.c:2133

#20 expr_list (ls=<value optimized out>, v=<value optimized out>)

at lj_parse.c:1901

#21 0x00007f278a12d54c in parse_local (ls=0x7fff4b842c30) at lj_parse.c:2285

#22 parse_stmt (ls=0x7fff4b842c30) at lj_parse.c:2671

#23 parse_chunk (ls=0x7fff4b842c30) at lj_parse.c:2707

#24 0x00007f278a12a9ac in parse_body (ls=0x7fff4b842c30, e=0x7fff4b8427c0,

needself=<value optimized out>, line=389) at lj_parse.c:1878

#25 0x00007f278a12d41a in parse_local (ls=0x7fff4b842c30) at lj_parse.c:2272

#26 parse_stmt (ls=0x7fff4b842c30) at lj_parse.c:2671

#27 parse_chunk (ls=0x7fff4b842c30) at lj_parse.c:2707

#28 0x00007f278a12d98e in lj_parse (ls=0x7fff4b842c30) at lj_parse.c:2740

#29 0x00007f278a13015b in cpparser (L=0x40d24ba8, dummy=<value optimized out>,

ud=0x7fff4b842c30) at lj_load.c:41

#30 0x00007f278a1151d0 in lj_vm_cpcall ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#31 0x00007f278a12fe1d in lua_loadx (L=0x40d24ba8,

reader=<value optimized out>, data="" optimized out>,

chunkname=<value optimized out>, mode=<value optimized out>)

at lj_load.c:58

#32 0x00007f278a12ff68 in luaL_loadfilex (L=0x40d24ba8,

filename=0x40d23268 "/usr/local/openresty/nginx/lua/compress/deflatelua.lua", mode=0x0) at lj_load.c:101

#33 0x00007f278a1705fa in lj_cf_package_loader_lua (L=0x40d24ba8)

at lib_package.c:345

#34 0x00007f278a114e8f in lj_BC_FUNCC ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#35 0x00007f278a16fadd in lj_cf_package_require (L=0x40d24ba8)

at lib_package.c:423

#36 0x00007f278a114e8f in lj_BC_FUNCC ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#37 0x00007f278a16fb7c in lj_cf_package_require (L=0x40d24ba8)

at lib_package.c:434

#38 0x00007f278a114e8f in lj_BC_FUNCC ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#39 0x000000000049ef3b in ngx_http_lua_run_thread (L=0x41a81378, r=0xad8420,

ctx=0xad7378, nrets=0) at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

#40 0x00000000004a25fd in ngx_http_lua_rewrite_by_chunk (L=0x41a81378,

r=0xad8420) at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:306

#41 0x00000000004a2763 in ngx_http_lua_rewrite_handler_file (r=0xad8420)

at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:224

#42 0x00000000004a2a23 in ngx_http_lua_rewrite_handler (r=0xad8420)

at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:140

#43 0x000000000043fa73 in ngx_http_core_rewrite_phase (r=0xad8420, ph=0xad3ba0)

at src/http/ngx_http_core_module.c:942

#44 0x000000000043b2c3 in ngx_http_core_run_phases (r=0xad8420)

at src/http/ngx_http_core_module.c:888

#45 0x000000000043b3bd in ngx_http_handler (r=<value optimized out>)

at src/http/ngx_http_core_module.c:871

#46 0x0000000000445f94 in ngx_http_process_request (r=0xad8420)

at src/http/ngx_http_request.c:1692

#47 0x00000000004465fc in ngx_http_process_request_headers (

rev=<value optimized out>) at src/http/ngx_http_request.c:1140

#48 0x0000000000446c09 in ngx_http_process_request_line (rev=0xb0a668)

at src/http/ngx_http_request.c:936

#49 0x000000000044359d in ngx_http_init_request (rev=0xb0a668)

at src/http/ngx_http_request.c:520

#50 0x0000000000434879 in ngx_epoll_process_events (cycle=0xa95990,

timer=<value optimized out>, flags=<value optimized out>)

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

#51 0x000000000042c2d3 in ngx_process_events_and_timers (cycle=0xa95990)

at src/event/ngx_event.c:247

#52 0x00000000004330d8 in ngx_worker_process_cycle (cycle=0xa95990,

data="" optimized out>) at src/os/unix/ngx_process_cycle.c:813

#53 0x00000000004318c5 in ngx_spawn_process (cycle=0xa95990,

proc=0x432fe2 <ngx_worker_process_cycle>, data="">

name=0x4cb69b "worker process", respawn=-3)

at src/os/unix/ngx_process.c:198

#54 0x0000000000432563 in ngx_start_worker_processes (cycle=0xa95990, n=1,

type=-3) at src/os/unix/ngx_process_cycle.c:364

#55 0x000000000043374e in ngx_master_process_cycle (cycle=0xa95990)

at src/os/unix/ngx_process_cycle.c:136

#56 0x0000000000416bea in main (argc=<value optimized out>,

argv=<value optimized out>) at src/core/nginx.c:412

rgomes

I replaced the LuaJIT-2.0.1 source in the openresty-1.2.8.5 bundle with the latest version from the LuaJIT git repository and rebuilt openresty. Assertion failure still occurs.

Program received signal SIGABRT, Aborted.

0x0000003e5ba329a5 in raise () from /lib64/libc.so.6

(gdb) where

#0 0x0000003e5ba329a5 in raise () from /lib64/libc.so.6

#1 0x0000003e5ba34185 in abort () from /lib64/libc.so.6

#2 0x0000003e5ba2b935 in __assert_fail () from /lib64/libc.so.6

#3 0x00007f920105853b in ctype_check (g=<value optimized out>,

cd=<value optimized out>) at lj_ctype.h:395

#4 ctype_get (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:402

#5 ctype_child (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:413

#6 ctype_raw (g=<value optimized out>, cd=<value optimized out>)

at lj_ctype.h:420

#7 lj_cdata_free (g=<value optimized out>, cd=<value optimized out>)

at lj_cdata.c:69

#8 0x00007f920101439d in gc_sweep (g=0x414e63b8, p=0x40647c70, lim=23)

at lj_gc.c:405

#9 0x00007f92010155ac in gc_onestep (L=0x41bc5220) at lj_gc.c:632

#10 0x00007f9201015d28 in lj_gc_step (L=0x41bc5220) at lj_gc.c:676

#11 0x00007f9201027851 in lj_parse_keepstr (ls=0x7fffead480d0,

str=<value optimized out>, len=<value optimized out>) at lj_parse.c:238

#12 0x00007f9201024bf2 in read_string (ls=0x7fffead480d0, tv=0x7fffead480e0)

at lj_lex.c:255

#13 llex (ls=0x7fffead480d0, tv=0x7fffead480e0) at lj_lex.c:338

#14 0x00007f9201024dad in lj_lex_next (ls=0x7fffead480d0) at lj_lex.c:430

#15 0x00007f9201028f88 in lex_opt (ls=0x7fffead480d0, e=0x7fffead47b40)

at lj_parse.c:985

#16 expr_table (ls=0x7fffead480d0, e=0x7fffead47b40) at lj_parse.c:1787

#17 0x00007f9201027ba3 in expr_simple (ls=0x7fffead480d0, v=0x7fffead47b40,

limit=0) at lj_parse.c:2028

#18 expr_unop (ls=0x7fffead480d0, v=0x7fffead47b40, limit=0) at lj_parse.c:2101

#19 expr_binop (ls=0x7fffead480d0, v=0x7fffead47b40, limit=0)

at lj_parse.c:2114

#20 0x00007f9201029255 in expr (ls=<value optimized out>,

v=<value optimized out>) at lj_parse.c:2133

#21 expr_list (ls=<value optimized out>, v=<value optimized out>)

at lj_parse.c:1901

#22 0x00007f92010297b8 in parse_assignment (ls=0x7fffead480d0,

lh=0x7fffead47c00, nvars=1) at lj_parse.c:2224

#23 0x00007f9201029ab3 in parse_call_assign (ls=0x7fffead480d0)

at lj_parse.c:2257

#24 parse_stmt (ls=0x7fffead480d0) at lj_parse.c:2695

#25 parse_chunk (ls=0x7fffead480d0) at lj_parse.c:2707

#26 0x00007f920102a98e in lj_parse (ls=0x7fffead480d0) at lj_parse.c:2740

#27 0x00007f920102d15b in cpparser (L=0x41bc5220, dummy=<value optimized out>,

ud=0x7fffead480d0) at lj_load.c:41

#28 0x00007f92010121d0 in lj_vm_cpcall ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

---Type <return> to continue, or q <return> to quit---

#29 0x00007f920102ce1d in lua_loadx (L=0x41bc5220,

reader=<value optimized out>, data="" optimized out>,

chunkname=<value optimized out>, mode=<value optimized out>)

at lj_load.c:58

#30 0x00007f920102cf68 in luaL_loadfilex (L=0x41bc5220,

filename=0x414f3ad8 "/usr/local/openresty/nginx/lua/doorman_global_config.lua", mode=0x0) at lj_load.c:101

#31 0x00007f920106ddca in lj_cf_package_loader_lua (L=0x41bc5220)

at lib_package.c:345

#32 0x00007f9201011e8f in lj_BC_FUNCC ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#33 0x00007f920106d2ad in lj_cf_package_require (L=0x41bc5220)

at lib_package.c:423

#34 0x00007f9201011e8f in lj_BC_FUNCC ()

from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2

#35 0x000000000049ef3b in ngx_http_lua_run_thread (L=0x414e6378, r=0x1f236c0,

ctx=0x1fc1288, nrets=0) at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

#36 0x00000000004a25fd in ngx_http_lua_rewrite_by_chunk (L=0x414e6378,

r=0x1f236c0) at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:306

#37 0x00000000004a2763 in ngx_http_lua_rewrite_handler_file (r=0x1f236c0)

at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:224

#38 0x00000000004a2a23 in ngx_http_lua_rewrite_handler (r=0x1f236c0)

at ../ngx_lua-0.8.2/src/ngx_http_lua_rewriteby.c:140

#39 0x000000000043fa73 in ngx_http_core_rewrite_phase (r=0x1f236c0,

ph=0x1f55ba0) at src/http/ngx_http_core_module.c:942

#40 0x000000000043b2c3 in ngx_http_core_run_phases (r=0x1f236c0)

at src/http/ngx_http_core_module.c:888

#41 0x000000000043b3bd in ngx_http_handler (r=<value optimized out>)

at src/http/ngx_http_core_module.c:871

#42 0x0000000000445f94 in ngx_http_process_request (r=0x1f236c0)

at src/http/ngx_http_request.c:1692

#43 0x00000000004465fc in ngx_http_process_request_headers (

rev=<value optimized out>) at src/http/ngx_http_request.c:1140

#44 0x0000000000446c09 in ngx_http_process_request_line (rev=0x1f8c738)

at src/http/ngx_http_request.c:936

#45 0x000000000044359d in ngx_http_init_request (rev=0x1f8c738)

at src/http/ngx_http_request.c:520

#46 0x0000000000434879 in ngx_epoll_process_events (cycle=0x1f17990,

timer=<value optimized out>, flags=<value optimized out>)

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

#47 0x000000000042c2d3 in ngx_process_events_and_timers (cycle=0x1f17990)

at src/event/ngx_event.c:247

#48 0x00000000004330d8 in ngx_worker_process_cycle (cycle=0x1f17990,

data="" optimized out>) at src/os/unix/ngx_process_cycle.c:813

#49 0x00000000004318c5 in ngx_spawn_process (cycle=0x1f17990,

proc=0x432fe2 <ngx_worker_process_cycle>, data="">

name=0x4cb69b "worker process", respawn=-3)

at src/os/unix/ngx_process.c:198

#50 0x0000000000432563 in ngx_start_worker_processes (cycle=0x1f17990, n=1,

type=-3) at src/os/unix/ngx_process_cycle.c:364

#51 0x000000000043374e in ngx_master_process_cycle (cycle=0x1f17990)

at src/os/unix/ngx_process_cycle.c:136

#52 0x0000000000416bea in main (argc=<value optimized out>,

argv=<value optimized out>) at src/core/nginx.c:412

agentzh

Hello!

On Wed, May 29, 2013 at 6:59 AM, Ron Gomes wrote:
> I replaced the LuaJIT-2.0.1 source in the openresty-1.2.8.5 bundle with the
> latest version from the LuaJIT git repository and rebuilt openresty.
> Assertion failure still occurs.
>

Thank you for providing the backtraces! It seems that LuaJIT was
having problems when collecting some FFI cdata objects created by some
Lua libraries in its GC.

What Lua libraries are you currently using in your Lua code?
Especially those using LuaJIT FFI?

Is it possible for you to create a minimized standalone example (with
nginx.conf and embedded Lua code) that can be reliably reproduced by
simple steps?

Thanks!
-agentzh

rgomes

On Wednesday, May 29, 2013 1:38:16 PM UTC-4, agentzh wrote:

Thank you for providing the backtraces! It seems that LuaJIT was
having problems when collecting some FFI cdata objects created by some
Lua libraries in its GC.

What Lua libraries are you currently using in your Lua code?
Especially those using LuaJIT FFI?

The only targets of "require" in our Lua code that aren't pure Lua are "ngx", "cjson", "resty.string", and "resty.sha1". I know for sure that resty.string (at least) uses FFI because when I build openresty without LuaJIT the Lua scripts fail since they can't find ffi:

2013/05/29 11:54:04 [error] 17887#0: *2 lua entry thread aborted: runtime error: /usr/local/openresty/lualib/resty/string.lua:4: module 'ffi' not found:

I guess this is not surprising since (evidently) FFI is only available as part of LuaJIT, but it's a problem for us since it means that we can't use resty.string (and maybe some others) if we try to use the interpreter instead of LuaJIT, so we'll have to provide that functionality in some other way. So the workaround isn't as straightforward as I'd hoped.

Is it possible for you to create a minimized standalone example (with
nginx.conf and embedded Lua code) that can be reliably reproduced by
simple steps?

I'll try. I'll see if I can whittle down the configuration and the Lua code to something smaller that still shows the problem. But so far I haven't found anything as simple as a single request via curl that provokes the problem.

agentzh

Hello!

On Wed, May 29, 2013 at 11:12 AM, Ron Gomes wrote:
>
> The only targets of "require" in our Lua code that aren't pure Lua are
> "ngx", "cjson", "resty.string", and "resty.sha1".

Interesting :)

> I'll try.  I'll see if I can whittle down the configuration and the Lua code
> to something smaller that still shows the problem.  But so far I haven't
> found anything as simple as a single request via curl that provokes the
> problem.
>

Please do :) Because it's GC related, you'll have to run tools like ab
or weighttp to keep your Nginx loaded so as to reproduce such issues.

Thanks!
-agentzh

rgomes

I've made progress on this. The short version is that there seems to be some interaction between resty.string and the Lua code cache that causes the corruption. I can make the assertion failures disappear if I leave the Lua code cache "on" (the default) instead of including "lua_code_cache off" in the nginx conf (as I've been doing during development).

I have a small configuration that reliably provokes a GC assertion failure on server shutdown on my RHEL 6 system using openresty 1.2.8.5.

Use this nginx.conf:

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

worker_processes 1;

error_log logs/error.log info;

events {

worker_connections 1024;

}

http {

lua_code_cache off;

server {

listen 15080 default_server;

location / {

rewrite_by_lua 'require "resty.string"';

content_by_lua 'ngx.say("Hello")';

}

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

Then send the server two requests in succession, e.g.:

$ curl -s -D - http://localhost:15080/x

Then shut down the server, e.g.

$ /usr/local/openresty/nginx/sbin/nginx -s stop

This provokes a GC assertion failure in error.log:

lj_state.c:169: close_state: Assertion `g->gc.total == sizeof(GG_State)' failed.

If the "lua_code_cache off" line is commented out in nginx.conf, the assertion failure doesn't happen.

I hope this is helpful.

agentzh

Hello Ron!

On Thu, May 30, 2013 at 12:49 PM, Ron Gomes wrote:
> I've made progress on this.  The short version is that there seems to be
> some interaction between resty.string and the Lua code cache that causes the
> corruption.  I can make the assertion failures disappear if I leave the Lua
> code cache "on" (the default) instead of including "lua_code_cache off" in
> the nginx conf (as I've been doing during development).
>
> I have a small configuration that reliably provokes a GC assertion failure
> on server shutdown on my RHEL 6 system using openresty 1.2.8.5.
>

Thank you for the test case! I've reproduced this assertion failure on
my side and it is because ngx_lua unload the standard "ffi" package
when lua_code_cache is turned off.

I've committed a patch that fixes this:

    https://github.com/chaoslawful/lua-nginx-module/commit/b3218be

Please just try out ngx_openresty prerelease 1.2.8.6rc1 which includes
this patch:

    http://openresty.org/download/ngx_openresty-1.2.8.6rc1.tar.gz

Thanks!
-agentzh

rgomes

Thanks for the patch. The assertion failures are gone but there's a new problem. Our code has this line in it:

local resty_sha1 = require "resty.sha1"

The first time this is executed it's fine, but on subsequent executions we see this in the log:

lua entry thread aborted: runtime error: /usr/local/openresty/lualib/resty/sha.lua:19: attempt to redefine 'SHA_LBLOCK' at line 5

resulting in a 500 return to the client.

As before, the problem goes away if the Lua code cache is left on.

justin

On 31 May 2013 14:08, "Ron Gomes" <rg...@consumer.org> wrote:
>
> Thanks for the patch. The assertion failures are gone but there's a new problem. Our code has this line in it:
>
> local resty_sha1 = require "resty.sha1"
>
> The first time this is executed it's fine, but on subsequent executions we see this in the log:
>
> lua entry thread aborted: runtime error: /usr/local/openresty/lualib/resty/sha.lua:19: attempt to redefine 'SHA_LBLOCK' at line 5
>
> resulting in a 500 return to the client.
>
> As before, the problem goes away if the Lua code cache is left on.

Unfortunately LuaJIT has some global state related to ffi about type and function definitions that cannot be turned off or unloaded without shutting down and restarting Lua. So the current way that code cache is turned off is not sufficient and it will need to create a new Lua state for each request to work.

Justin

.
>
>

agentzh

Hello!

On Fri, May 31, 2013 at 6:08 AM, Ron Gomes wrote:
> Thanks for the patch.  The assertion failures are gone but there's a new
> problem.  Our code has this line in it:
[...]
> lua entry thread aborted: runtime error:
> /usr/local/openresty/lualib/resty/sha.lua:19: attempt to redefine
> 'SHA_LBLOCK' at line 5
>

Okay, it seems that we indeed need to unload the "ffi" package when
lua_code_cache is turned off. The assertion failures you saw should be
a bug in LuaJIT and I'm asking Mike Pall if he can resolve it:

    http://www.freelists.org/post/luajit/Assertion-failures-when-unloading-and-reloading-the-ffi-package

Thank you for the report!

Best regards,
-agentzh

agentzh

Hello!

On Fri, May 31, 2013 at 10:14 AM, Justin Cormack wrote:
>
> Unfortunately LuaJIT has some global state related to ffi about type and
> function definitions that cannot be turned off or unloaded without shutting
> down and restarting Lua. So the current way that code cache is turned off is
> not sufficient and it will need to create a new Lua state for each request
> to work.
>

I've been trying hard not to destroy and recreate the "world" here :)
One downside of creating a separate Lua VM on every request is that
global initializing in init_by_lua will no longer work when lua code
cache is off. Also, it requires significant code refactoring in the
current ngx_lua code base.

Furthermore, even when the code cache is on, Lua code's "hot
replacement" in production is also a very good use case for this.

Best regards,
-agentzh

rgomes

For the moment I've given up using "lua_code_cache off"; I think that the only alternative is to stop using resty.string (or any other FFI-using module) for now and recreate any necessary functionality in some other way.

Does it seem like this issue is likely to be corrected in a future release? Or is hairy enough that it's not likely to be changed anytime soon?

On Friday, May 31, 2013 3:13:13 PM UTC-4, agentzh wrote:

Hello!

On Fri, May 31, 2013 at 10:14 AM, Justin Cormack wrote:
>
> Unfortunately LuaJIT has some global state related to ffi about type and
> function definitions that cannot be turned off or unloaded without shutting
> down and restarting Lua. So the current way that code cache is turned off is
> not sufficient and it will need to create a new Lua state for each request
> to work.
>

I've been trying hard not to destroy and recreate the "world" here :)
One downside of creating a separate Lua VM on every request is that
global initializing in init_by_lua will no longer work when lua code
cache is off. Also, it requires significant code refactoring in the
current ngx_lua code base.

Furthermore, even when the code cache is on, Lua code's "hot
replacement" in production is also a very good use case for this.

Best regards,
-agentzh

agentzh

Hello!

On Tue, Jun 11, 2013 at 11:30 AM, Ron Gomes wrote:
> For the moment I've given up using "lua_code_cache off"; I think that the
> only alternative is to stop using resty.string (or any other FFI-using
> module) for now and recreate any necessary functionality in some other way.
>

For production use, you should never never disable the Lua code cache
because the performance is very bad. Disabling the Lua code cache is
for development only. So this is not a critical issue at all.

Giving up FFI is not an option because eventually the whole ngx_lua
will be rewritten atop FFI (see the ongoing work in ngx_lua's "ffi"
git branch).

Because it seems not possible to make unloading "ffi" work in LuaJIT,
I think I'll just take Justin's advice and creating a new Lua VM for
each Nginx request, which should solve the issue. But it also means
that disabling the Lua code cache will lead to even worse performance
so NEVER NEVER do that for production.

Best regards,
-agentzh

rgomes

I can't tell from the release notes to 1.4.1.1: has this issue been addressed yet? Or is it still unsafe to use "lua_code_cache off" if I'm also using any module that uses FFI?

On Tuesday, June 11, 2013 2:39:15 PM UTC-4, agentzh wrote:

Hello!

On Tue, Jun 11, 2013 at 11:30 AM, Ron Gomes wrote:
> For the moment I've given up using "lua_code_cache off"; I think that the
> only alternative is to stop using resty.string (or any other FFI-using
> module) for now and recreate any necessary functionality in some other way.
>

For production use, you should never never disable the Lua code cache
because the performance is very bad. Disabling the Lua code cache is
for development only. So this is not a critical issue at all.

Giving up FFI is not an option because eventually the whole ngx_lua
will be rewritten atop FFI (see the ongoing work in ngx_lua's "ffi"
git branch).

Because it seems not possible to make unloading "ffi" work in LuaJIT,
I think I'll just take Justin's advice and creating a new Lua VM for
each Nginx request, which should solve the issue. But it also means
that disabling the Lua code cache will lead to even worse performance
so NEVER NEVER do that for production.

Best regards,
-agentzh

agentzh

Hello!

On Thu, Jul 25, 2013 at 8:17 AM, Ron Gomes wrote:
> I can't tell from the release notes to 1.4.1.1: has this issue been
> addressed yet?

This issue has not yet been addressed in the latest ngx_lua (included
in openresty 1.4.1.1) due to its relatively low priority (because it
only affects development environments disabling the Lua code cache).
Anyway, I'll look into this soon :)

Regards,
-agentzh

agentzh

Hello!

Sorry for the delay on my side! Finally fixed it. See my reply below :)

On Thu, Jul 25, 2013 at 11:57 AM, Yichun Zhang (agentzh) wrote:
> On Thu, Jul 25, 2013 at 8:17 AM, Ron Gomes wrote:
>> I can't tell from the release notes to 1.4.1.1: has this issue been
>> addressed yet?
>
> This issue has not yet been addressed in the latest ngx_lua (included
> in openresty 1.4.1.1) due to its relatively low priority (because it
> only affects development environments disabling the Lua code cache).
> Anyway, I'll look into this soon :)
>

I've just committed a series of (big) patches to ngx_lua's git master
branch and reimplemented the "lua_code_cache off" thing from scratch.
And this issue should be resolved now.

Basically the new model always creates a clean separate Lua VM
instance for every request served by ngx_lua when lua_code_cache is
turned off. And timers created by the ngx.timer.at() API on the Lua
land will share the same Lua VM instance as the request handler
creating them.

Will you try out ngx_lua's latest git master on your side? This fix
will be included in the next formal release of ngx_lua and
ngx_openresty :)

Disabling lua_code_cache is still (strongly) discouraged for
production use, however, due to its high overhead involved in
per-request Lua VM instances. On my laptop powered by Intel Core i7,
for example, a "hello world" example using ngx_lua drops performance
by almost an order of magnitude when turning off lua_code_cache, from
50k req/sec per nginx worker to 5.5k req/sec. So only use it for the
ease of Lua development ;)

Thank you again for your original bug report!

Best regards,
-agentzh