关于openresty 热循环问题的排查

xfan1015 · 2013-08-01T07:55:11+00:00

-j8 和luajit肯定无关，找找别的原因吧Sent from my iPadOn Aug 1, 2013, at 18:31,...

关于openresty 热循环问题的排查

xfan1015

getipinfo.conf 内容

lua_package_path "/usr/local/nginx/lualib/?.lua;/usr/local/nginx/lualib/?/init.lua;;";

lua_socket_connect_timeout 2s;

lua_socket_send_timeout 2s;

lua_socket_read_timeout 2s;

lua_socket_buffer_size 4k;

lua_socket_pool_size 256;

lua_socket_keepalive_timeout 60s;

lua_socket_log_errors off;

lua_max_pending_timers 256；

lua_max_running_timers 64；

server {

listen 80;

chunked_transfer_encoding off;

gzip off;

access_log /usr/local/nginx/logs/access.log;

error_log /usr/local/nginx/logs/error.log;

resolver 8.8.8.8;

location /getipinfo {

lua_code_cache on;

content_by_lua_file /usr/local/nginx/conf/vhost/getipinfo.lua;

}

location / {

return 444;

}

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

getipinfo.lua内容

local checkproxy=function (ip,port)

local http = require "resty.http"

local cjson = require "cjson"

local hc = http:new()

if ip and port then

ngx.say('</br>checkproxy: '..ip..":"..port)

proxystr=table.concat( {"http://",ip,":",port})

else

return "request error: ip or port error"

end

local ok, code, headers, status, body = hc:request {

url = "",

-- proxy = "http://36.47.205.205:27416",

proxy=proxystr,

timeout = 2000,

method = "GET",

headers = { Agent = "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Trident/6.0;)" },

}

if not ok then

return "request error: "..code

end

-- body='{"code":0,"data":{"country":"\u4e2d\u56fd","country_id":"CN","area":"\u534e\u4e1c","area_id":"300000","region":"\u6c5f\u82cf\u7701","region_id":"320000","city":"\u5357\u4eac\u5e02","city_id":"320100","county":"","county_id":"-1","isp":"\u7535\u4fe1","isp_id":"100017","ip":"114.221.112.167"}}'

local bodyt=cjson.decode(body)

if type(bodyt)~='table' then

return "response error: can not jsondecode body"

end

if bodyt.code ~=0 then

return "response error: can not get ip info ,code: "..bodyt.code

end

return nil,bodyt.data.country,bodyt.data.country_id,bodyt.data.area,bodyt.data.area_id+0,bodyt.data.region,bodyt.data.region_id+0,bodyt.data.city,bodyt.data.city_id+0,bodyt.data.county,bodyt.data.county_id+0,bodyt.data.isp,bodyt.data.isp_id+0

end

ngx.header.content_type = "text/html;charset=utf-8"

local ip=ngx.var.remote_addr or ngx.header.x_forward_for or ngx.header.x_real_ip or "115.151.20.36"

local port=ngx.var.arg_port or "20300"

local ok,err,country,country_id,area,area_id,region,region_id,city,city_id,county,county_id,isp,isp_id = pcall(checkproxy,ip,port)

if not ok then

-- ngx.say("</br>**exit pcall checkproxy error")

ngx.exit(444)

end

local ok,local_id=pcall(function()

if county_id and county_id+0>0 then

return county_id

elseif city_id and city_id+0>0 then

return city_id

elseif region_id and region_id+0>0 then

return region_id

end

end)

if not ok then local_id=nil end

if not err then --验证代理成功

-- ngx.say("</br>",ip,port,country,country_id,area,area_id,region,region_id,city,city_id,county,county_id,isp,isp_id,local_id)

else --验证代理失败

ngx.exit(444)

-- ngx.say("</br>check proxy error :"..err)

end

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

项目上线后跑一段时间就会处于热循环状态 cpu占用100%

gdb 调试进程会有以下信息

#0 0x00254b99 in lj_vmeta_tgetv () from /usr/local/luajit/lib/libluajit-5.1.so.2

#1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134

#2 0x080e5933 in ngx_http_lua_run_thread (L=0xaff311c0, r=0x8b7d8f0, ctx=0x8b9c9bc, nrets=3)

at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

#3 0x080ee9e8 in ngx_http_lua_socket_tcp_resume (r=0x8b7d8f0) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:4000

#4 0x080e8c9d in ngx_http_lua_content_wev_handler (r=0xaff3c240) at ../ngx_lua-0.8.2/src/ngx_http_lua_contentby.c:131

#5 0x080edb10 in ngx_http_lua_socket_handle_error (r=0x8b7d8f0, u=0xaf51bef0, ft_type=2)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2216

#6 0x080f1796 in ngx_http_lua_socket_read_handler (r=0x8b7d8f0, u=0xaf51bef0)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2003

#7 0x080eeb3c in ngx_http_lua_socket_tcp_handler (ev=0xaf7c46fc) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:1968

#8 0x080703fc in ngx_event_expire_timers () at src/event/ngx_event_timer.c:151

#9 0x080702b6 in ngx_process_events_and_timers (cycle=0x8b671a8) at src/event/ngx_event.c:263

#10 0x080778a0 in ngx_worker_process_cycle (cycle=0x8b671a8, data="" at src/os/unix/ngx_process_cycle.c:813

#11 0x08075f51 in ngx_spawn_process (cycle=0x8b671a8, proc=0x80777c2 <ngx_worker_process_cycle>, data="">

name=0x8111e7a "worker process", respawn=-4) at src/os/unix/ngx_process.c:198

#12 0x08076d9b in ngx_start_worker_processes (cycle=0x8b671a8, n=4, type=-4) at src/os/unix/ngx_process_cycle.c:364

#13 0x0807886d in ngx_master_process_cycle (cycle=0x8b671a8) at src/os/unix/ngx_process_cycle.c:249

#14 0x0805a7e1 in main (argc=1, argv=0xbfaa52d4) at src/core/nginx.c:412

#0 0x0025ae72 in lj_tab_newkey (L=0xaf46d958, t=0xaf527eb0, key=0xbfaa4c40) at lj_tab.c:420

#1 0x0025d496 in lj_meta_tset (L=0xaf46d958, o=0xaf4aa600, k=0xbfaa4c40) at lj_meta.c:173

#2 0x00266a65 in lua_setfield (L=0xaf46d958, idx=-2, k=0x811fb39 "__gc") at lj_api.c:914

#3 0x080eeebe in ngx_http_lua_socket_tcp_receiveuntil (L=0xaf46d958) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2514

#4 0x002547b7 in lj_BC_FUNCC () from /usr/local/luajit/lib/libluajit-5.1.so.2

#5 0x00262e9e in lua_resume (L=0xaf46d958, nargs=3) at lj_api.c:1134

#6 0x080e5933 in ngx_http_lua_run_thread (L=0xaff311c0, r=0x8bd7900, ctx=0x8bdd05c, nrets=3)

at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

#7 0x080ee9e8 in ngx_http_lua_socket_tcp_resume (r=0x8bd7900) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:4000

#8 0x080e8c9d in ngx_http_lua_content_wev_handler (r=0xbfaa4c40) at ../ngx_lua-0.8.2/src/ngx_http_lua_contentby.c:131

#9 0x080edb10 in ngx_http_lua_socket_handle_error (r=0x8bd7900, u=0xaf51aea8, ft_type=2)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2216

#10 0x080f1796 in ngx_http_lua_socket_read_handler (r=0x8bd7900, u=0xaf51aea8)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2003

#11 0x080eeb3c in ngx_http_lua_socket_tcp_handler (ev=0xaf7c3550) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:1968

#12 0x080703fc in ngx_event_expire_timers () at src/event/ngx_event_timer.c:151

#13 0x080702b6 in ngx_process_events_and_timers (cycle=0x8b671a8) at src/event/ngx_event.c:263

#14 0x080778a0 in ngx_worker_process_cycle (cycle=0x8b671a8, data="" at src/os/unix/ngx_process_cycle.c:813

#15 0x08075f51 in ngx_spawn_process (cycle=0x8b671a8, proc=0x80777c2 <ngx_worker_process_cycle>, data="">

name=0x8111e7a "worker process", respawn=-4) at src/os/unix/ngx_process.c:198

#16 0x08076d9b in ngx_start_worker_processes (cycle=0x8b671a8, n=4, type=-4) at src/os/unix/ngx_process_cycle.c:364

#17 0x0807886d in ngx_master_process_cycle (cycle=0x8b671a8) at src/os/unix/ngx_process_cycle.c:249

#18 0x0805a7e1 in main (argc=1, argv=0xbfaa52d4) at src/core/nginx.c:412

#0 0x001699d9 in gc_traverse_thread (th=<optimized out>, g=<optimized out>) at lj_gc.c:287

#1 propagatemark (g=0xaff4a1f0) at lj_gc.c:325

#2 0x00169b97 in gc_propagate_gray (g=0xaff4a1f0) at lj_gc.c:345

#3 0x0016a35d in atomic (L=<optimized out>, g=<optimized out>) at lj_gc.c:585

#4 gc_onestep (L=0xaf51a3a8) at lj_gc.c:617

#5 0x0016a777 in lj_gc_step (L=0xaf51a3a8) at lj_gc.c:676

#6 0x00177ea6 in lua_pushcclosure (L=0xaf51a3a8, f=0x80f131a <ngx_http_lua_socket_receiveuntil_iterator>, n=3) at lj_api.c:626

#7 0x080ef0be in ngx_http_lua_socket_tcp_receiveuntil (L=0xaf51a3a8) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2530

#8 0x001667b7 in lj_BC_FUNCC () from /usr/local/luajit/lib/libluajit-5.1.so.2

#9 0x00174e9e in lua_resume (L=0xaf51a3a8, nargs=3) at lj_api.c:1134

#10 0x080e5933 in ngx_http_lua_run_thread (L=0xaff4a1c0, r=0x83ae518, ctx=0x83a720c, nrets=3)

at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

#11 0x080ee9e8 in ngx_http_lua_socket_tcp_resume (r=0x83ae518) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:4000

#12 0x080e8c9d in ngx_http_lua_content_wev_handler (r=0x8) at ../ngx_lua-0.8.2/src/ngx_http_lua_contentby.c:131

#13 0x080edb10 in ngx_http_lua_socket_handle_error (r=0x83ae518, u=0xaf5275d8, ft_type=2)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2216

#14 0x080f1796 in ngx_http_lua_socket_read_handler (r=0x83ae518, u=0xaf5275d8)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2003

#15 0x080eeb3c in ngx_http_lua_socket_tcp_handler (ev=0xaf7dd55c) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:1968

#16 0x080703fc in ngx_event_expire_timers () at src/event/ngx_event_timer.c:151

#17 0x080702b6 in ngx_process_events_and_timers (cycle=0x83ba388) at src/event/ngx_event.c:263

#18 0x080778a0 in ngx_worker_process_cycle (cycle=0x83ba388, data="" at src/os/unix/ngx_process_cycle.c:813

#19 0x08075f51 in ngx_spawn_process (cycle=0x83ba388, proc=0x80777c2 <ngx_worker_process_cycle>, data="">

#0 0x00169d80 in gc_finalize (L=0xaf414118) at lj_gc.c:491

#1 0x0016a0cb in gc_onestep (L=0xaf414118) at lj_gc.c:650

#2 0x0016a777 in lj_gc_step (L=0xaf414118) at lj_gc.c:676

#3 0x00177889 in lua_createtable (L=0xaf414118, narray=0, nrec=1) at lj_api.c:653

#4 0x080eee88 in ngx_http_lua_socket_tcp_receiveuntil (L=0xaf414118) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2512

#5 0x001667b7 in lj_BC_FUNCC () from /usr/local/luajit/lib/libluajit-5.1.so.2

#6 0x00174e9e in lua_resume (L=0xaf414118, nargs=3) at lj_api.c:1134

#7 0x080e5933 in ngx_http_lua_run_thread (L=0xaff4a1c0, r=0x846b728, ctx=0x83bf95c, nrets=3)

at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

#8 0x080ee9e8 in ngx_http_lua_socket_tcp_resume (r=0x846b728) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:4000

#9 0x080e8c9d in ngx_http_lua_content_wev_handler (r=0xaff4a1f0) at ../ngx_lua-0.8.2/src/ngx_http_lua_contentby.c:131

#10 0x080edb10 in ngx_http_lua_socket_handle_error (r=0x846b728, u=0xaf496ca8, ft_type=2)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2216

#11 0x080f1796 in ngx_http_lua_socket_read_handler (r=0x846b728, u=0xaf496ca8)

at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:2003

#12 0x080eeb3c in ngx_http_lua_socket_tcp_handler (ev=0xaf7dd9a0) at ../ngx_lua-0.8.2/src/ngx_http_lua_socket_tcp.c:1968

#13 0x080703fc in ngx_event_expire_timers () at src/event/ngx_event_timer.c:151

#14 0x080702b6 in ngx_process_events_and_timers (cycle=0x83ba388) at src/event/ngx_event.c:263

#15 0x080778a0 in ngx_worker_process_cycle (cycle=0x83ba388, data="" at src/os/unix/ngx_process_cycle.c:813

#16 0x08075f51 in ngx_spawn_process (cycle=0x83ba388, proc=0x80777c2 <ngx_worker_process_cycle>, data="">

name=0x8111e7a "worker process", respawn=-4) at src/os/unix/ngx_process.c:198

#17 0x08076d9b in ngx_start_worker_processes (cycle=0x83ba388, n=4, type=-4) at src/os/unix/ngx_process_cycle.c:364

#18 0x0807886d in ngx_master_process_cycle (cycle=0x83ba388) at src/os/unix/ngx_process_cycle.c:249

#19 0x0805a7e1 in main (argc=1, argv=0xbfe5abf4) at src/core/nginx.c:412

pstack 调试进程会有以下信息

#0 0x001bd8e4 in lj_alloc_f () from /usr/local/luajit/lib/libluajit-5.1.so.2

#1 0x001687f3 in lj_mem_newgco () from /usr/local/luajit/lib/libluajit-5.1.so.2

#2 0x0016de11 in lj_func_newC () from /usr/local/luajit/lib/libluajit-5.1.so.2

#3 0x00177d3b in lua_pushcclosure () from /usr/local/luajit/lib/libluajit-5.1.so.2

#4 0x080ef0be in ngx_http_lua_socket_tcp_receiveuntil ()

#5 0x001667b7 in lj_BC_FUNCC () from /usr/local/luajit/lib/libluajit-5.1.so.2

#6 0x00174e9e in lua_resume () from /usr/local/luajit/lib/libluajit-5.1.so.2

#7 0x080e5933 in ngx_http_lua_run_thread ()

#8 0x080ee9e8 in ngx_http_lua_socket_tcp_resume ()

#9 0x080e8c9d in ngx_http_lua_content_wev_handler ()

#10 0x080edb10 in ngx_http_lua_socket_handle_error ()

#11 0x080f1796 in ngx_http_lua_socket_read_handler ()

#12 0x080eeb3c in ngx_http_lua_socket_tcp_handler ()

#13 0x080703fc in ngx_event_expire_timers ()

#14 0x080702b6 in ngx_process_events_and_timers ()

#15 0x080778a0 in ngx_worker_process_cycle ()

#16 0x08075f51 in ngx_spawn_process ()

#17 0x08076d9b in ngx_start_worker_processes ()

#18 0x0807886d in ngx_master_process_cycle ()

#19 0x0805a7e1 in main ()

#0 0x0016888f in lj_mem_realloc () from /usr/local/luajit/lib/libluajit-5.1.so.2

#1 0x0016e39c in lj_udata_new () from /usr/local/luajit/lib/libluajit-5.1.so.2

#2 0x00175be4 in lua_newuserdata () from /usr/local/luajit/lib/libluajit-5.1.so.2

#3 0x080eee4e in ngx_http_lua_socket_tcp_receiveuntil ()

#4 0x001667b7 in lj_BC_FUNCC () from /usr/local/luajit/lib/libluajit-5.1.so.2

#5 0x00174e9e in lua_resume () from /usr/local/luajit/lib/libluajit-5.1.so.2

#6 0x080e5933 in ngx_http_lua_run_thread ()

#7 0x080ee9e8 in ngx_http_lua_socket_tcp_resume ()

#8 0x080e8c9d in ngx_http_lua_content_wev_handler ()

#9 0x080edb10 in ngx_http_lua_socket_handle_error ()

#10 0x080f1796 in ngx_http_lua_socket_read_handler ()

#11 0x080eeb3c in ngx_http_lua_socket_tcp_handler ()

#12 0x080703fc in ngx_event_expire_timers ()

#13 0x080702b6 in ngx_process_events_and_timers ()

#14 0x080778a0 in ngx_worker_process_cycle ()

#15 0x08075f51 in ngx_spawn_process ()

#16 0x08076d9b in ngx_start_worker_processes ()

#17 0x0807886d in ngx_master_process_cycle ()

#18 0x0805a7e1 in main ()

#0 0x0016c81e in lj_tab_getstr () from /usr/local/luajit/lib/libluajit-5.1.so.2

#1 0x0016ed2a in lj_meta_cache () from /usr/local/luajit/lib/libluajit-5.1.so.2

#2 0x00169332 in lj_gc_separateudata () from /usr/local/luajit/lib/libluajit-5.1.so.2

#3 0x0016a371 in gc_onestep () from /usr/local/luajit/lib/libluajit-5.1.so.2

#4 0x0016a777 in lj_gc_step () from /usr/local/luajit/lib/libluajit-5.1.so.2

#5 0x001784d1 in lua_pushlstring () from /usr/local/luajit/lib/libluajit-5.1.so.2

#6 0x080f13ea in ngx_http_lua_socket_receiveuntil_iterator ()

#7 0x001667b7 in lj_BC_FUNCC () from /usr/local/luajit/lib/libluajit-5.1.so.2

#8 0x00174e9e in lua_resume () from /usr/local/luajit/lib/libluajit-5.1.so.2

#9 0x080e5933 in ngx_http_lua_run_thread ()

#10 0x080ee9e8 in ngx_http_lua_socket_tcp_resume ()

#11 0x080e8c9d in ngx_http_lua_content_wev_handler ()

#12 0x080edb10 in ngx_http_lua_socket_handle_error ()

#13 0x080f1796 in ngx_http_lua_socket_read_handler ()

#14 0x080eeb3c in ngx_http_lua_socket_tcp_handler ()

#15 0x080703fc in ngx_event_expire_timers ()

#16 0x080702b6 in ngx_process_events_and_timers ()

#17 0x080778a0 in ngx_worker_process_cycle ()

#18 0x08075f51 in ngx_spawn_process ()

#19 0x08076d9b in ngx_start_worker_processes ()

#20 0x0807886d in ngx_master_process_cycle ()

#21 0x0805a7e1 in main ()

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

nginx version: ngx_openresty/1.2.8.6

built by gcc 4.1.2 20080704 (Red Hat 4.1.2-54)

TLS SNI support disabled

configure arguments: --prefix=/usr/local/nginx --with-debug --add-module=../ngx_devel_kit-0.2.18 --add-module=../echo-nginx-module-0.45 --add-module=../xss-nginx-module-0.03rc9 --add-module=../ngx_coolkit-0.2rc1 --add-module=../set-misc-nginx-module-0.22rc8 --add-module=../form-input-nginx-module-0.07 --add-module=../encrypted-session-nginx-module-0.03 --add-module=../srcache-nginx-module-0.21 --add-module=../ngx_lua-0.8.2 --add-module=../headers-more-nginx-module-0.20 --add-module=../array-var-nginx-module-0.03rc1 --add-module=../memc-nginx-module-0.13rc3 --add-module=../redis2-nginx-module-0.10 --add-module=../redis-nginx-module-0.3.6 --add-module=../auth-request-nginx-module-0.2 --add-module=../rds-json-nginx-module-0.12rc10 --add-module=../rds-csv-nginx-module-0.05rc2 --with-ld-opt=-Wl,-rpath,/usr/local/luajit/lib --with-http_stub_status_module --with-google_perftools_module --with-http_ssl_module

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

error.log中会有以下错误应该是验证代理失败的记录

[error] 30086#0: *821262 connect() failed (111: Connection refused),

[error] 30086#0: *824643 connect() failed (113: No route to host),

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

各位能否帮忙看看问题出在哪里，排查很久也没能找出来

agentzh

Hello!

On Wed, Jul 31, 2013 at 4:55 PM, 东方凡 wrote:
> 项目上线后 跑一段时间就会处于热循环状态 cpu占用100%
>
> gdb 调试进程 会有以下信息
>
> #0  0x00254b99 in lj_vmeta_tgetv () from
> /usr/local/luajit/lib/libluajit-5.1.so.2
> #1  0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134
> #2  0x080e5933 in ngx_http_lua_run_thread (L=0xaff311c0, r=0x8b7d8f0,
> ctx=0x8b9c9bc, nrets=3)
>     at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

看起来应当是在 Lua 代码里面热循环了。有多种方法可以取得 Lua 热循环的位置。

第一种做法：你可以使用 Nginx GDB Utils 中的 gdb 命令从 L 取得当前的 Lua 代码调用轨迹。例如：

    (gdb) source lbt.py
    (gdb) set $myL = 0xaf5194c0
    (gdb) lbt $myL

这里的地址值 0xaf5194c0 是从你给出的 gdb bt 输出中的这一行得到的：

    #1  0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134

这里用到的 lbt 命令是在 lbt.py 文件中定义的，而 lbt.py 文件可以从 Nginx GDB Utils 项目中取得：

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

注意你需要最新的启用了 python 扩展支持的 gdb 7.6 （默认就会开启 python 支持）:

    http://ftp.gnu.org/gnu/gdb/

第二种做法：你也可以不使用 gdb，而改用  Nginx Systemtap Toolkit 中的基于 systemtap
的工具，ngx-lua-bt，来取得 Lua 调用栈：

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

Best regards,
-agentzh

wang.fl1429

什么叫 "热循环啊" ? 死循环的意思吗.

2013/8/1 Yichun Zhang (agentzh) <age...@gmail.com>

Hello!

On Wed, Jul 31, 2013 at 4:55 PM, 东方凡 wrote:
> 项目上线后跑一段时间就会处于热循环状态 cpu占用100%
>
> gdb 调试进程会有以下信息
>
> #0 0x00254b99 in lj_vmeta_tgetv () from
> /usr/local/luajit/lib/libluajit-5.1.so.2
> #1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134
> #2 0x080e5933 in ngx_http_lua_run_thread (L=0xaff311c0, r=0x8b7d8f0,
> ctx=0x8b9c9bc, nrets=3)
> at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

看起来应当是在 Lua 代码里面热循环了。有多种方法可以取得 Lua 热循环的位置。

第一种做法：你可以使用 Nginx GDB Utils 中的 gdb 命令从 L 取得当前的 Lua 代码调用轨迹。例如：

(gdb) source lbt.py
(gdb) set $myL = 0xaf5194c0
(gdb) lbt $myL

这里的地址值 0xaf5194c0 是从你给出的 gdb bt 输出中的这一行得到的：

#1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134

这里用到的 lbt 命令是在 lbt.py 文件中定义的，而 lbt.py 文件可以从 Nginx GDB Utils 项目中取得：

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

注意你需要最新的启用了 python 扩展支持的 gdb 7.6 （默认就会开启 python 支持）:

http://ftp.gnu.org/gnu/gdb/

第二种做法：你也可以不使用 gdb，而改用 Nginx Systemtap Toolkit 中的基于 systemtap
的工具，ngx-lua-bt，来取得 Lua 调用栈：

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

Best regards,
-agentzh

--

xfan1015

我在论坛里看到的这个词应该是死循环的意思

在 2013年8月1日星期四UTC+8上午10时06分07秒，wxianfeng写道：

什么叫 "热循环啊" ? 死循环的意思吗.

2013/8/1 Yichun Zhang (agentzh) <age...@gmail.com>

Hello!

On Wed, Jul 31, 2013 at 4:55 PM, 东方凡 wrote:
> 项目上线后跑一段时间就会处于热循环状态 cpu占用100%
>
> gdb 调试进程会有以下信息
>
> #0 0x00254b99 in lj_vmeta_tgetv () from
> /usr/local/luajit/lib/libluajit-5.1.so.2
> #1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134
> #2 0x080e5933 in ngx_http_lua_run_thread (L=0xaff311c0, r=0x8b7d8f0,
> ctx=0x8b9c9bc, nrets=3)
> at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

看起来应当是在 Lua 代码里面热循环了。有多种方法可以取得 Lua 热循环的位置。

第一种做法：你可以使用 Nginx GDB Utils 中的 gdb 命令从 L 取得当前的 Lua 代码调用轨迹。例如：

(gdb) source lbt.py
(gdb) set $myL = 0xaf5194c0
(gdb) lbt $myL

这里的地址值 0xaf5194c0 是从你给出的 gdb bt 输出中的这一行得到的：

#1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134

这里用到的 lbt 命令是在 lbt.py 文件中定义的，而 lbt.py 文件可以从 Nginx GDB Utils 项目中取得：

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

注意你需要最新的启用了 python 扩展支持的 gdb 7.6 （默认就会开启 python 支持）:

http://ftp.gnu.org/gnu/gdb/

第二种做法：你也可以不使用 gdb，而改用 Nginx Systemtap Toolkit 中的基于 systemtap
的工具，ngx-lua-bt，来取得 Lua 调用栈：

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

Best regards,
-agentzh

--

xfan1015

tks 用ngx-lua-bt定位热循环的代码段成功

在 2013年8月1日星期四UTC+8上午8时09分08秒，agentzh写道：

Hello!

On Wed, Jul 31, 2013 at 4:55 PM, 东方凡 wrote:
> 项目上线后跑一段时间就会处于热循环状态 cpu占用100%
>
> gdb 调试进程会有以下信息
>
> #0 0x00254b99 in lj_vmeta_tgetv () from
> /usr/local/luajit/lib/libluajit-5.1.so.2
> #1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134
> #2 0x080e5933 in ngx_http_lua_run_thread (L=0xaff311c0, r=0x8b7d8f0,
> ctx=0x8b9c9bc, nrets=3)
> at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

看起来应当是在 Lua 代码里面热循环了。有多种方法可以取得 Lua 热循环的位置。

第一种做法：你可以使用 Nginx GDB Utils 中的 gdb 命令从 L 取得当前的 Lua 代码调用轨迹。例如：

(gdb) source lbt.py
(gdb) set $myL = 0xaf5194c0
(gdb) lbt $myL

这里的地址值 0xaf5194c0 是从你给出的 gdb bt 输出中的这一行得到的：

#1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134

这里用到的 lbt 命令是在 lbt.py 文件中定义的，而 lbt.py 文件可以从 Nginx GDB Utils 项目中取得：

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

注意你需要最新的启用了 python 扩展支持的 gdb 7.6 （默认就会开启 python 支持）:

http://ftp.gnu.org/gnu/gdb/

第二种做法：你也可以不使用 gdb，而改用 Nginx Systemtap Toolkit 中的基于 systemtap
的工具，ngx-lua-bt，来取得 Lua 调用栈：

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

Best regards,
-agentzh

agentzh

Hello!

2013/7/31 wxianfeng:
> 什么叫 "热循环啊" ? 死循环的意思吗.
>

热循环不一定是死循环，比如耗时很长的循环（比如秒级）也可以称为“热循环”。

Regards,
-agentzh

wang.fl1429

赞，春哥. 了解了.

fatfatson

看了ngx-lua-bt，大开眼界，顺带学习了systemtap知识

不过有点疑问，为啥要探测str_find(string.find)函数？

据我初次接触systemtap粗读文档的理解，这个脚本的意思是生成一个tsp脚本供stap用，而该tsp的内容是指定当lua模块里的str_find函数被调用时，执行下面的逻辑，也就是打印lua栈，从而知道当前正运行在哪里

只是不明白为什么选择str_find作为采样点，难道是它的调用很频繁足以代表覆盖？

求春歌指点

在 2013年8月1日星期四UTC+8上午8时09分08秒，agentzh写道：

Hello!

On Wed, Jul 31, 2013 at 4:55 PM, 东方凡 wrote:
> 项目上线后跑一段时间就会处于热循环状态 cpu占用100%
>
> gdb 调试进程会有以下信息
>
> #0 0x00254b99 in lj_vmeta_tgetv () from
> /usr/local/luajit/lib/libluajit-5.1.so.2
> #1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134
> #2 0x080e5933 in ngx_http_lua_run_thread (L=0xaff311c0, r=0x8b7d8f0,
> ctx=0x8b9c9bc, nrets=3)
> at ../ngx_lua-0.8.2/src/ngx_http_lua_util.c:1032

看起来应当是在 Lua 代码里面热循环了。有多种方法可以取得 Lua 热循环的位置。

第一种做法：你可以使用 Nginx GDB Utils 中的 gdb 命令从 L 取得当前的 Lua 代码调用轨迹。例如：

(gdb) source lbt.py
(gdb) set $myL = 0xaf5194c0
(gdb) lbt $myL

这里的地址值 0xaf5194c0 是从你给出的 gdb bt 输出中的这一行得到的：

#1 0x00262e9e in lua_resume (L=0xaf5194c0, nargs=3) at lj_api.c:1134

这里用到的 lbt 命令是在 lbt.py 文件中定义的，而 lbt.py 文件可以从 Nginx GDB Utils 项目中取得：

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

注意你需要最新的启用了 python 扩展支持的 gdb 7.6 （默认就会开启 python 支持）:

http://ftp.gnu.org/gnu/gdb/

第二种做法：你也可以不使用 gdb，而改用 Nginx Systemtap Toolkit 中的基于 systemtap
的工具，ngx-lua-bt，来取得 Lua 调用栈：

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

Best regards,
-agentzh

agentzh

Hello!

2013/8/20 小冶:
> 看了ngx-lua-bt，大开眼界，顺带学习了systemtap知识
> 不过有点疑问，为啥要探测str_find(string.find)函数？

目前 ngx-lua-bt 的实现是一种折衷，即尽可能多地在 LuaJIT VM 内的 C
函数上设置探针，以便通够命中其中的任何一个从而取得当前正在运行的 Lua thread 的 lua_State 指针。

目前 ngx-lua-bt 选择了 luaL_*, lua_*, ngx_http_lua_ngx_*, 和 str_find 这些 C
函数来放置探针。或许这里的 str_find 相比其他函数会显得有些特别，添加它带有较大的随意性。

其实更正确更高效的实现方法是在 probe timer.profile 这样的定时器上下文中直接从堆（通过
@var）或者从栈取得当前正在运行的 Lua thread 的 lua_State. 我一直有这般重写 ngx-lua-bt 的计划。

当然，由于 LuaJIT VM 本身并不会在堆上维护指向当前运行的 lua thread 的 state
入口指针，所以如果要从堆上拿的话，需要宿主 C 程序（比如 ngx_lua 模块）自己在每次 resume 调用前把当前的
lua_State 保存到某个全局变量里去。而另一种方式，即从栈上取得 lua_State 可能需要修改 systemtap 的 stack
unwinder，因为缺少现成的自定义的栈分析功能（这一点上，gdb 的 python API 倒是做得更好一些）。

> 据我初次接触systemtap粗读文档的理解
> ，这个脚本的意思是生成一个tsp脚本供stap用，而该tsp的内容是指定当lua模块里的str_find函数被调用时，执行下面的逻辑，也就是打印lua栈，从而知道当前正运行在哪里
> 只是不明白为什么选择str_find作为采样点，难道是它的调用很频繁足以代表覆盖？

str_find 并不是唯一的探测点，注意 ngx-lua-bt 脚本中下面这段代码：

    my $probes = <<_EOC_;
         process("$lua_path").function("luaL_*"),
         process("$lua_path").function("lua_*"),
         process("$nginx_path").function("ngx_http_lua_ngx_*")
    _EOC_

Regards,
-agentzh

fatfatson

多谢春哥解答！

确实看漏了lua*,luaL*系列函数

不过如你所说，

这种“被动”的打桩采样方式，只是折衷的方案

更准确的方法应该是就在探测那一下（敲下命令时，或是在定时检测点触发时），“主动”出击执行，直接拿到Ｌ，然后就可遍历其栈了

至于拿到Ｌ的方法，可以直接修改lua虚拟机代码呀，让它在resume时把所有用到的Ｌ统一存到某个地方去（完成时再清除），以供探测程序来拿。（以前我做集成lua的程序时，为了在crash时保存所有L的栈信息，也是用这个办法），只是看把这个逻辑直接塞到修改的lua里，还是只在lua里插一句简单的回调，然后在自己这边的代码里实现并注册回调。

在 2013年8月21日星期三UTC+8上午2时34分20秒，agentzh写道：

Hello!

2013/8/20 小冶:
> 看了ngx-lua-bt，大开眼界，顺带学习了systemtap知识
> 不过有点疑问，为啥要探测str_find(string.find)函数？

目前 ngx-lua-bt 的实现是一种折衷，即尽可能多地在 LuaJIT VM 内的 C
函数上设置探针，以便通够命中其中的任何一个从而取得当前正在运行的 Lua thread 的 lua_State 指针。

目前 ngx-lua-bt 选择了 luaL_*, lua_*, ngx_http_lua_ngx_*, 和 str_find 这些 C
函数来放置探针。或许这里的 str_find 相比其他函数会显得有些特别，添加它带有较大的随意性。

其实更正确更高效的实现方法是在 probe timer.profile 这样的定时器上下文中直接从堆（通过
@var）或者从栈取得当前正在运行的 Lua thread 的 lua_State. 我一直有这般重写 ngx-lua-bt 的计划。

当然，由于 LuaJIT VM 本身并不会在堆上维护指向当前运行的 lua thread 的 state
入口指针，所以如果要从堆上拿的话，需要宿主 C 程序（比如 ngx_lua 模块）自己在每次 resume 调用前把当前的
lua_State 保存到某个全局变量里去。而另一种方式，即从栈上取得 lua_State 可能需要修改 systemtap 的 stack
unwinder，因为缺少现成的自定义的栈分析功能（这一点上，gdb 的 python API 倒是做得更好一些）。

> 据我初次接触systemtap粗读文档的理解
> ，这个脚本的意思是生成一个tsp脚本供stap用，而该tsp的内容是指定当lua模块里的str_find函数被调用时，执行下面的逻辑，也就是打印lua栈，从而知道当前正运行在哪里
> 只是不明白为什么选择str_find作为采样点，难道是它的调用很频繁足以代表覆盖？

str_find 并不是唯一的探测点，注意 ngx-lua-bt 脚本中下面这段代码：

my $probes = <<_EOC_;
process("$lua_path").function("luaL_*"),
process("$lua_path").function("lua_*"),
process("$nginx_path").function("ngx_http_lua_ngx_*")
_EOC_

Regards,
-agentzh

agentzh

Hello!

2013/8/20 小冶:
> 至于拿到Ｌ的方法，可以直接修改lua虚拟机代码呀，让它在resume时把所有用到的Ｌ统一存到某个地方去（完成时再清除），以供探测程序来拿。（以前我做集成lua的程序时，为了在crash时保存所有L的栈信息，也是用这个办法），只是看把这个逻辑直接塞到修改的lua里，还是只在lua里插一句简单的回调，然后在自己这边的代码里实现并注册回调。
>

显然，为此修改 LuaJIT 的源码对我来说是下下策 ;)

Regards,
-agentzh