最近在使用lua-resty-redis库连接redis时,出现“lua tcp socket read timed out” 异常。
测试的场景:
1 连接redis数据库;
2 从redis中获取指定key的值,输出日志;
3 等待10秒(模拟进行其他操作花费的时间,例如:查询mysql数据库,读取本地文件等消耗时间较长的操作);
4 再次从redis中获取同一个key的值,输出日志;
redis请求连接的超时时间设置为1s;(client:set_timeout(1000))
测试结果:
1 单次请求时,没有问题,一次请求中,两次从redis中获取key的值,都能正常打印日志;
2 并发请求时,有些请求的第二次从redis中获取key值,提示“lua tcp socket read timed out”异常,导致无法正常输出;
并发请求使用的是Apach 的ab测试工具,并发10个,共发起10次请求,“ab -c 10 -n 10 http://172.18.1.234/test”
问题:
1、10个并发应该远远没有达到redis数据库并发连接的瓶颈(单独测试过,redis的并发连接数能上1000),出现这种错误是什么原因导致?
2、如果延长redis请求连接的超时时间为10s,这种错误出现的几率会减少,但偶尔也会有。
请指教!
谢谢
附代码和测试结果:
——————————————————————————————test.lua——————————————
local function sleep(n)
os.execute("sleep " .. n)
end
local redis = require("resty.redis")
local client, errmsg = redis:new()
if not client then
print("redis.socket_failed: " .. (errmsg or "nil"))
end
client:set_timeout(1000) --1秒
local result, errmsg = client:connect("172.18.1.230", 6379)
if not result then
print("redis.connect_failed: " .. (errmsg or "nil"))
end
client:select(0)
print("result = "..client:get("hello"))
sleep(10)
print("again result = "..client:get("hello"))
client:close()
ngx.print(200)
————————————————————日志————————————————————————
2015/02/27 12:20:53 [notice] 23809#0: *1001019 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:20:53 [notice] 23811#0: *1001021 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:03 [notice] 23809#0: *1001019 [lua] test.lua:23: again result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:03 [notice] 23811#0: *1001022 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:13 [notice] 23811#0: *1001026 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:23 [notice] 23811#0: *1001024 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:33 [notice] 23811#0: *1001028 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [notice] 23811#0: *1001021 [lua] test.lua:23: again result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [error] 23811#0: *1001022 lua tcp socket read timed out, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [error] 23811#0: *1001022 lua entry thread aborted: runtime error: /usr/local/openresty/nginx/51fafa/test.lua:23: attempt to concatenate a nil value
stack traceback:
coroutine 0:
/usr/local/openresty/nginx/51fafa/test.lua: in function </usr/local/openresty/nginx/51fafa/test.lua:1>, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [error] 23811#0: *1001032 lua tcp socket read timed out, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [error] 23811#0: *1001032 lua entry thread aborted: runtime error: /usr/local/openresty/nginx/51fafa/test.lua:21: attempt to concatenate a nil value
stack traceback:
coroutine 0:
/usr/local/openresty/nginx/51fafa/test.lua: in function </usr/local/openresty/nginx/51fafa/test.lua:1>, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [error] 23811#0: *1001030 lua tcp socket read timed out, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [error] 23811#0: *1001030 lua entry thread aborted: runtime error: /usr/local/openresty/nginx/51fafa/test.lua:21: attempt to concatenate a nil value
stack traceback:
coroutine 0:
/usr/local/openresty/nginx/51fafa/test.lua: in function </usr/local/openresty/nginx/51fafa/test.lua:1>, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:43 [notice] 23811#0: *1001034 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:53 [notice] 23811#0: *1001026 [lua] test.lua:23: again result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:53 [notice] 23811#0: *1001024 [lua] test.lua:23: again result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:21:53 [notice] 23811#0: *1001036 [lua] test.lua:21: result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:22:03 [notice] 23811#0: *1001028 [lua] test.lua:23: again result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:22:03 [notice] 23811#0: *1001034 [lua] test.lua:23: again result = world1, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:22:03 [error] 23811#0: *1001036 lua tcp socket read timed out, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"
2015/02/27 12:22:03 [error] 23811#0: *1001036 lua entry thread aborted: runtime error: /usr/local/openresty/nginx/51fafa/test.lua:23: attempt to concatenate a nil value
stack traceback:
coroutine 0:
/usr/local/openresty/nginx/51fafa/test.lua: in function </usr/local/openresty/nginx/51fafa/test.lua:1>, client: 172.18.1.44, server: localhost, request: "GET /test HTTP/1.0", host: "172.18.1.234"