openresty的ngx_http_lua_ngx_now()导致worker cpu 100%

hugolee6963 · 2018-09-28T20:06:27+00:00

2018/09/27 00:01:21 [error] 4164#4164: *2971907157 lua entry thread aborted: runtime error: /usr/local/openresty/lualib/resty/mysql.lua:131:...

openresty的ngx_http_lua_ngx_now()导致worker cpu 100%

hugolee6963

环境：openresty 1.11.2.1 ，os环境：centos 6.3

问题描述：业务使用openresty+lua开发。qps高的时候会导致个别nginx worker cpu 100%。使用ngx-lua-bt，显示最后执行的函数是：ngx_http_lua_ngx_now()

其中业务代码调用ngx.now()如下：

local new_method = function(...)

local st = ngx.now()

local _type = "normal"

local method_name = method_name

local args = {...}

local ret1,ret2,ret3, ret4 = origin_method(unpack(args))

local et = ngx.now()

local server_id = global.get_serverid()

local red = args[1]

local resource_name = red.sock[3]

local use_us = (et-st)*1000000

local key = ""

if type(args[2]) ~= "table" then

key = tostring(args[2])

else

for k, v in pairs(args[2]) do

key= key .." "..tostring(k).." "..tostring(v)

end

ngx-lua-bt显示函数调用最后是在local et=ngx.now()，即ngx_http_lua_ngx_now()这个函数

ngx_http_lua_ngx_now代码如下：

static int
ngx_http_lua_ngx_now(lua_State *L)
{
    ngx_time_t              *tp;

    tp = ngx_timeofday();

    lua_pushnumber(L, (lua_Number) (tp->sec + tp->msec / 1000.0L));

    return 1;
}

想不明白为啥这个函数会导致cpu 100%，请各位给点思路，谢谢！

hugolee6963

在 2018年9月28日星期五 UTC+8下午8:06:27，hugol...@gmail.com写道：

环境：openresty 1.11.2.1 ，os环境：centos 6.3

问题描述：业务使用openresty+lua开发。qps高的时候会导致个别nginx worker cpu 100%。使用ngx-lua-bt，显示最后执行的函数是：ngx_http_lua_ngx_now()

其中业务代码调用ngx.now()如下：
local new_method = function(...)
local st = ngx.now()
local _type = "normal"
local method_name = method_name
local args = {...}
local ret1,ret2,ret3, ret4 = origin_method(unpack(args))
local et = ngx.now()
local server_id = global.get_serverid()
local red = args[1]
local resource_name = red.sock[3]
local use_us = (et-st)*1000000
local key = ""
if type(args[2]) ~= "table" then
key = tostring(args[2])
else
for k, v in pairs(args[2]) do
key= key .." "..tostring(k).." "..tostring(v)
end
end

ngx-lua-bt显示函数调用最后是在local et=ngx.now()，即ngx_http_lua_ngx_now()这个函数

ngx_http_lua_ngx_now代码如下：
static int
ngx_http_lua_ngx_now(lua_State *L)
{
ngx_time_t *tp;

tp = ngx_timeofday();

lua_pushnumber(L, (lua_Number) (tp->sec + tp->msec / 1000.0L));

return 1;
}

想不明白为啥这个函数会导致cpu 100%，请各位给点思路，谢谢！

ngx-lua-bt的运行结果在附件

Attachment: 2.png
Description: PNG image

moonbingbing

建议用 https://github.com/openresty/openresty-systemtap-toolkit/blob/master/README-CN.markdown#sample-bt 和 https://github.com/openresty/stapxx#lj-lua-stacks 给出 C 和 Lua 级别的火焰图看看。

<hugol...@gmail.com> 于2018年9月28日周五下午8:06写道：

环境：openresty 1.11.2.1 ，os环境：centos 6.3

问题描述：业务使用openresty+lua开发。qps高的时候会导致个别nginx worker cpu 100%。使用ngx-lua-bt，显示最后执行的函数是：ngx_http_lua_ngx_now()

其中业务代码调用ngx.now()如下：
local new_method = function(...)
local st = ngx.now()
local _type = "normal"
local method_name = method_name
local args = {...}
local ret1,ret2,ret3, ret4 = origin_method(unpack(args))
local et = ngx.now()
local server_id = global.get_serverid()
local red = args[1]
local resource_name = red.sock[3]
local use_us = (et-st)*1000000
local key = ""
if type(args[2]) ~= "table" then
key = tostring(args[2])
else
for k, v in pairs(args[2]) do
key= key .." "..tostring(k).." "..tostring(v)
end
end

ngx-lua-bt显示函数调用最后是在local et=ngx.now()，即ngx_http_lua_ngx_now()这个函数

ngx_http_lua_ngx_now代码如下：
static int
ngx_http_lua_ngx_now(lua_State *L)
{
ngx_time_t *tp;

tp = ngx_timeofday();

lua_pushnumber(L, (lua_Number) (tp->sec + tp->msec / 1000.0L));

return 1;
}

想不明白为啥这个函数会导致cpu 100%，请各位给点思路，谢谢！

--