lua_code_cache off with luajit, nginx worker will exit while run ab benchmark

270 views
Skip to first unread message

Simon

unread,
Mar 28, 2012, 5:51:59 AM3/28/12
to openresty
# ab -n 200 -c 100 localhost/mongo
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 100 requests
apr_socket_recv: Connection reset by peer (104)
Total of 119 requests completed


# tail error.log

2012/03/28 17:37:29 [notice] 18540#0: signal process started
2012/03/28 17:37:32 [warn] 18541#0: lua_code_cache is off; this will
hurt performance in /usr/local/openresty/nginx/conf/nginx.conf:55
orker process: lj_ctype.h:395: ctype_check: Assertion `id > 0 && id <
cts->top' failed.
2012/03/28 17:37:43 [alert] 18542#0: worker process 18543 exited on
signal 6


# sbin/nginx -V
nginx version: ngx_openresty/1.0.11.19
built by gcc 4.5.2 (Ubuntu/Linaro 4.5.2-8ubuntu4)
TLS SNI support enabled
configure arguments: --prefix=/usr/local/openresty/nginx --with-debug
--with-cc-opt=-O0 --add-module=../ngx_devel_kit-0.2.17 --add-module=../
echo-nginx-module-0.38rc1 --add-module=../xss-nginx-module-0.03rc9 --
add-module=../ngx_coolkit-0.2rc1 --add-module=../set-misc-nginx-
module-0.22rc5 --add-module=../form-input-nginx-module-0.07rc5 --add-
module=../encrypted-session-nginx-module-0.02 --add-module=../
ngx_lua-0.5.0rc16 --add-module=../headers-more-nginx-module-0.17rc1 --
add-module=../srcache-nginx-module-0.13rc3 --add-module=../array-var-
nginx-module-0.03rc1 --add-module=../memc-nginx-module-0.13rc3 --add-
module=../redis2-nginx-module-0.08rc4 --add-module=../upstream-
keepalive-nginx-module-0.7 --add-module=../auth-request-nginx-
module-0.2 --add-module=../rds-json-nginx-module-0.12rc7 --add-
module=../rds-csv-nginx-module-0.05rc1 --with-ld-opt=-Wl,-rpath,/usr/
local/openresty/luajit/lib --with-http_ssl_module

# uname -a
Linux simon-1 2.6.38-8-generic #42-Ubuntu SMP Mon Apr 11 03:31:50 UTC
2011 i686 i686 i386 GNU/Linux

================

ab -n 200 -c 1 localhost/mongo 一个并发就不会有问题。

将lua_code_cache设为on,ab会挂住超时:

# ab -n 200 -c 100 localhost/mongo
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
Completed 100 requests
apr_poll: The timeout specified has expired (70007)
Total of 101 requests completed

================ 退出时的堆栈:
(gdb) c
Continuing.

Program received signal SIGABRT, Aborted.
0x0014e416 in __kernel_vsyscall ()
(gdb) bt
#0 0x0014e416 in __kernel_vsyscall ()
#1 0x005b6e71 in raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/
raise.c:64
#2 0x005ba34e in abort () at abort.c:92
#3 0x005af888 in __assert_fail (assertion=0x560667 "id > 0 && id <
cts->top",
file=0x56065c "lj_ctype.h", line=395, function=0x563ab2
"ctype_check")
at assert.c:81
#4 0x005376eb in ctype_check (g=<value optimized out>, cd=0xb66f56f8)
at lj_ctype.h:395
#5 ctype_get (g=<value optimized out>, cd=0xb66f56f8) at lj_ctype.h:
402
#6 ctype_child (g=<value optimized out>, cd=0xb66f56f8) at lj_ctype.h:
413
#7 ctype_raw (g=<value optimized out>, cd=0xb66f56f8) at lj_ctype.h:
420
#8 lj_cdata_free (g=<value optimized out>, cd=0xb66f56f8) at
lj_cdata.c:69
#9 0x004f6877 in gc_sweep (g=0xb78251f0, p=0xb68f0c68, lim=31) at
lj_gc.c:404
#10 0x004f7ec8 in gc_onestep (L=0xb6a8fdd0) at lj_gc.c:631
#11 0x004f860f in lj_gc_step (L=0xb6a8fdd0) at lj_gc.c:675
#12 0x0050339b in lua_createtable (L=0xb6a8fdd0, narray=0, nrec=3)
at lj_api.c:655
#13 0x00543598 in lib_create_table (L=0xb6a8fdd0, libname=0x0,
p=0x566361 "\004free\003set\374\001\307__index\372\377",
cf=0x56886c)
at lj_lib.c:40
#14 lj_lib_register (L=0xb6a8fdd0, libname=0x0,
p=0x566361 "\004free\003set\374\001\307__index\372\377",
cf=0x56886c)
at lj_lib.c:52
#15 0x0055518d in luaopen_ffi (L=0xb6a8fdd0) at lib_ffi.c:799
#16 0x004f469f in lj_BC_FUNCC ()
from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2
#17 0x0054e5da in lj_cf_package_require (L=0xb6a8fdd0) at
lib_package.c:423
#18 0x004f469f in lj_BC_FUNCC ()
from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2
#19 0x0054e5da in lj_cf_package_require (L=0xb6a8fdd0) at
lib_package.c:423
#20 0x004f469f in lj_BC_FUNCC ()
from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2
#21 0x0054e5da in lj_cf_package_require (L=0xb6a8fdd0) at
lib_package.c:423
#22 0x004f469f in lj_BC_FUNCC ()
from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2
#23 0x0054e5da in lj_cf_package_require (L=0xb6a8fdd0) at
lib_package.c:423
#24 0x004f469f in lj_BC_FUNCC ()
from /usr/local/openresty/luajit/lib/libluajit-5.1.so.2
#25 0x005059fe in lua_resume (L=0xb6a8fdd0, nargs=0) at lj_api.c:1113
#26 0x081002e1 in ngx_http_lua_run_thread (L=0xb78251c0, r=0x87cdf18,
ctx=0x87e4800, nret=0) at ../ngx_lua-0.5.0rc16/src/
ngx_http_lua_util.c:786
#27 0x08103a11 in ngx_http_lua_content_by_chunk (L=0xb78251c0,
r=0x87cdf18)
at ../ngx_lua-0.5.0rc16/src/ngx_http_lua_contentby.c:92
#28 0x08103da9 in ngx_http_lua_content_handler_file (r=0x87cdf18)
at ../ngx_lua-0.5.0rc16/src/ngx_http_lua_contentby.c:243
---Type <return> to continue, or q <return> to quit---
#29 0x08103bb5 in ngx_http_lua_content_handler (r=0x87cdf18)
at ../ngx_lua-0.5.0rc16/src/ngx_http_lua_contentby.c:172
#30 0x0808bd6a in ngx_http_core_content_phase (r=0x87cdf18,
ph=0x87e0034)
at src/http/ngx_http_core_module.c:1375
#31 0x0808ac38 in ngx_http_core_run_phases (r=0x87cdf18)
at src/http/ngx_http_core_module.c:871
#32 0x0808abcd in ngx_http_handler (r=0x87cdf18)
at src/http/ngx_http_core_module.c:854
#33 0x08096901 in ngx_http_process_request (r=0x87cdf18)
at src/http/ngx_http_request.c:1671
#34 0x0809556d in ngx_http_process_request_headers (rev=0xb6ea5874)
at src/http/ngx_http_request.c:1117
#35 0x08094e26 in ngx_http_process_request_line (rev=0xb6ea5874)
at src/http/ngx_http_request.c:917
#36 0x080941a2 in ngx_http_init_request (rev=0xb6ea5874)
at src/http/ngx_http_request.c:522
#37 0x08081dae in ngx_epoll_process_events (cycle=0x87c6dc8,
timer=4997,
flags=1) at src/event/modules/ngx_epoll_module.c:678
#38 0x08075047 in ngx_process_events_and_timers (cycle=0x87c6dc8)
at src/event/ngx_event.c:245
#39 0x080800bb in ngx_worker_process_cycle (cycle=0x87c6dc8, data=0x0)
at src/os/unix/ngx_process_cycle.c:801
#40 0x0807d39f in ngx_spawn_process (cycle=0x87c6dc8,
proc=0x807ff6e <ngx_worker_process_cycle>, data=0x0,
name=0x8132d7f "worker process", respawn=0)
at src/os/unix/ngx_process.c:196
#41 0x0807fc61 in ngx_reap_children (cycle=0x87c6dc8)
at src/os/unix/ngx_process_cycle.c:617
#42 0x0807ecb2 in ngx_master_process_cycle (cycle=0x87c6dc8)
at src/os/unix/ngx_process_cycle.c:180
#43 0x080589d7 in main (argc=1, argv=0xbf850a04) at src/core/nginx.c:
411
(gdb)


=============== mongo.lua

local mongol = require "resty.mongol"
local conn = mongol ("10.6.2.51" ) -- Connect to localhost:27017

local db = conn:new_db_handle("test")
col = db:get_col("test")

col:insert({{name="dog"}})

ngx.say("ok")


春老师有时间帮忙看看,lua虚拟机实在不懂

agentzh

unread,
Mar 28, 2012, 7:45:07 AM3/28/12
to open...@googlegroups.com
On Wed, Mar 28, 2012 at 5:51 PM, Simon <big...@gmail.com> wrote:
> # ab -n 200 -c 100 localhost/mongo
[...]

>
> # tail error.log
>
> 2012/03/28 17:37:29 [notice] 18540#0: signal process started
> 2012/03/28 17:37:32 [warn] 18541#0: lua_code_cache is off; this will
> hurt performance in /usr/local/openresty/nginx/conf/nginx.conf:55
> orker process: lj_ctype.h:395: ctype_check: Assertion `id > 0 && id <
> cts->top' failed.
> 2012/03/28 17:37:43 [alert] 18542#0: worker process 18543 exited on
> signal 6
>
[...]

>
> ================
>
> ab -n 200 -c 1 localhost/mongo 一个并发就不会有问题。
>

禁用 Lua 代码缓存(即配置 lua_code_cache off)只是为了开发便利,一般不应以高于 1 并发来访问,否则可能会有
race condition 等等问题。同时因为它会有带来严重的性能衰退,所以不应在生产上使用此种模式。生产上应当总是启用 Lua
代码缓存,即配置 lua_code_cache on :)

Best regards,
-agentzh

Simon

unread,
Mar 28, 2012, 10:20:52 PM3/28/12
to openresty
lua_code_cache on 用ab测,有时成功,有时提示

# ab -n 200 -c 100 localhost/mongo
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient)
apr_socket_recv: Connection reset by peer (104)
Total of 65 requests completed

debug日志最后一个请求发送完之后shutdown失败,难道是ab的bug?

====
2012/03/29 10:15:31 [debug] 19843#0: *22858 http output filter "/
mongo?"
2012/03/29 10:15:31 [debug] 19843#0: *22858 http copy filter: "/
mongo?"
2012/03/29 10:15:31 [debug] 19843#0: *22858 http postpone filter "/
mongo?" BFF2E7F4
2012/03/29 10:15:31 [debug] 19843#0: *22858 write old buf t:1 f:0
0952BE08, pos 0952BE08, size: 167 file: 0, size: 0
2012/03/29 10:15:31 [debug] 19843#0: *22858 write old buf t:1 f:0
0952BD98, pos 0952BD98, size: 3 file: 0, size: 0
2012/03/29 10:15:31 [debug] 19843#0: *22858 write new buf t:0 f:0
00000000, pos 00000000, size: 0 file: 0, size: 0
2012/03/29 10:15:31 [debug] 19843#0: *22858 http write filter: l:1 f:0
s:170
2012/03/29 10:15:31 [debug] 19843#0: *22858 http write filter limit 0
2012/03/29 10:15:31 [debug] 19843#0: *22858 writev: 170
2012/03/29 10:15:31 [debug] 19843#0: *22858 http write filter 00000000
2012/03/29 10:15:31 [debug] 19843#0: *22858 http copy filter: 0 "/
mongo?"
2012/03/29 10:15:31 [debug] 19843#0: *22858 lua run thread returned 0
2012/03/29 10:15:31 [debug] 19843#0: *22858 http finalize request: 0,
"/mongo?" a:1, c:1
2012/03/29 10:15:31 [debug] 19843#0: *22858 event timer add: 107:
5000:1547475102
2012/03/29 10:15:31 [info] 19843#0: *22858 shutdown() failed (107:
Transport endpoint is not connected), client: 127.0.0.1, server:
localhost, request: "GET /mongo HTTP/1.0", host: "localhost"
2012/03/29 10:15:31 [debug] 19843#0: *22858 http request count:1 blk:0
2012/03/29 10:15:31 [debug] 19843#0: *22858 http close request
2012/03/29 10:15:31 [debug] 19843#0: *22858 cleanup lua socket
upstream request: "/mongo"


On Mar 28, 7:45 pm, agentzh <agen...@gmail.com> wrote:

agentzh

unread,
Mar 28, 2012, 10:30:27 PM3/28/12
to open...@googlegroups.com
On Thu, Mar 29, 2012 at 10:20 AM, Simon <big...@gmail.com> wrote:
> lua_code_cache on 用ab测,有时成功,有时提示
>
> # ab -n 200 -c 100 localhost/mongo
> This is ApacheBench, Version 2.3 <$Revision: 655654 $>
> Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
> Licensed to The Apache Software Foundation, http://www.apache.org/
>
> Benchmarking localhost (be patient)
> apr_socket_recv: Connection reset by peer (104)
> Total of 65 requests completed
>
> debug日志最后一个请求发送完之后shutdown失败,难道是ab的bug?
>

你的 worker_connections 配置为了多少?Test::Nginx 生成的配置中默认是 64,或许和这个有关系 :)

Best regards,
-agentzh

Simon

unread,
Mar 30, 2012, 1:13:11 AM3/30/12
to openresty
不是用的test case生成的。

worker_connections 65536;

On 3月29日, 上午10时30分, agentzh <agen...@gmail.com> wrote:


> On Thu, Mar 29, 2012 at 10:20 AM, Simon <bigp...@gmail.com> wrote:
> > lua_code_cache on 用ab测,有时成功,有时提示
>
> > # ab -n 200 -c 100 localhost/mongo
> > This is ApacheBench, Version 2.3 <$Revision: 655654 $>

> > Copyright 1996 Adam Twiss, Zeus Technology Ltd,http://www.zeustech.net/
> > Licensed to The Apache Software Foundation,http://www.apache.org/

agentzh

unread,
Mar 30, 2012, 2:55:41 AM3/30/12
to open...@googlegroups.com
On Thu, Mar 29, 2012 at 10:20 AM, Simon <big...@gmail.com> wrote:
> lua_code_cache on 用ab测,有时成功,有时提示
>
> # ab -n 200 -c 100 localhost/mongo
> This is ApacheBench, Version 2.3 <$Revision: 655654 $>
> Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
> Licensed to The Apache Software Foundation, http://www.apache.org/
>
> Benchmarking localhost (be patient)
> apr_socket_recv: Connection reset by peer (104)
> Total of 65 requests completed
>

我见过在一些系统上的某些 ab 的版本有问题。你可以尝试换用 weighttp 工具:

http://redmine.lighttpd.net/projects/weighttp/wiki

另外,在测试时可以考虑启用 http keepalive,以免测试工具耗尽动态端口。

> debug日志最后一个请求发送完之后shutdown失败,难道是ab的bug?
[...]


> 2012/03/29 10:15:31 [info] 19843#0: *22858 shutdown() failed (107:
> Transport endpoint is not connected), client: 127.0.0.1, server:

这个出错消息是无害的,其 info 级别也指出了这一点。它是指当前的下游连接已经提前断开了,所以 nginx 一侧再 shutdown
时就会报这个 ENOTCONN 错误。

你的 nginx 错误日志中还有其他 warn
以上级别的出错消息么?另外,启用调试日志会对性能产生很大的负面影响,进行性能压测时尽量避免使用启用了 --with-debug 选项的
nginx.

Regards,
-agentzh

Reply all
Reply to author
Forward
0 new messages