websocket的lua tcp socket read timed out问题

pq16344 · 2017-04-11T23:05:38+00:00

初始化放在 init_worker 也未尝不可，只不过此时不可...

websocket的lua tcp socket read timed out问题

pq16344

local wb, err = server:new{

timeout = 10000,

max_payload_len = 65535

}

while true do

local data, typ, err = wb:recv_frame()

end

将websocket的demo最简化，会隔10秒报一次timeout错误，请教了QQ群的朋友，说加心跳

后来改成

local wb, err = server:new{

timeout = 10000,

max_payload_len = 65535

}

while true do

local data, typ, err = wb:recv_frame()

if typ == "text" then

ngx.log(ngx.ERR,data);

elseif not data then

local bytes, err = wb:send_ping()

if not bytes then

---ngx.log(ngx.ERR, "failed to send ping: ", err)

return ngx.exit(444)

end

elseif typ == "pong" then

ngx.log(ngx.ERR,"ponged");

elseif typ == "close" then

break

end

还是隔10秒报一次time out错误，我的理解是否在wb:recv_frame()此处会有个timeout时间的等待，在10秒后无数据上报则返回timeout 错误。

2017/04/11 22:25:50 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

2017/04/11 22:25:50 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

2017/04/11 22:26:00 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

2017/04/11 22:26:00 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

2017/04/11 22:26:10 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

2017/04/11 22:26:10 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

2017/04/11 22:26:20 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

2017/04/11 22:26:20 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

pq16344

测试了好多次，并且翻了github上的issue，最后也没找到答案，英文不是很好。请大神指教。

On Tuesday, April 11, 2017 at 11:05:38 PM UTC+8, pan qing wrote:

local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
end

将websocket的demo最简化，会隔10秒报一次timeout错误，请教了QQ群的朋友，说加心跳

后来改成
local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
if typ == "text" then
ngx.log(ngx.ERR,data);
elseif not data then
local bytes, err = wb:send_ping()
if not bytes then
---ngx.log(ngx.ERR, "failed to send ping: ", err)
return ngx.exit(444)
end
elseif typ == "pong" then
ngx.log(ngx.ERR,"ponged");
elseif typ == "close" then
break
end
end
还是隔10秒报一次time out错误，我的理解是否在wb:recv_frame()此处会有个timeout时间的等待，在10秒后无数据上报则返回timeout 错误。
2017/04/11 22:25:50 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:25:50 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

pq16344

看了源码

ngx_http_lua_socket_tcp_read(ngx_http_request_t *r,

ngx_http_lua_socket_tcp_upstream_t *u)

b = &u->buffer;

read = 0;

for ( ;; ) {

size = b->last - b->pos;

ngx_http_lua_socket_read_handler(ngx_http_request_t *r,

ngx_http_lua_socket_tcp_upstream_t *u)

{

ngx_connection_t *c;

ngx_http_lua_loc_conf_t *llcf;

c = u->peer.connection;

ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,

"lua tcp socket read handler");

if (c->read->timedout) {

c->read->timedout = 0;

在接收环节有自旋锁不断接受数据流，并判断是否超时。不知道我判断的对不对，请大神指教。现象确实是，在无数据包提交来的10S后就报超时错误。

On Tuesday, April 11, 2017 at 11:05:38 PM UTC+8, pan qing wrote:

local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
end

将websocket的demo最简化，会隔10秒报一次timeout错误，请教了QQ群的朋友，说加心跳

后来改成
local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
if typ == "text" then
ngx.log(ngx.ERR,data);
elseif not data then
local bytes, err = wb:send_ping()
if not bytes then
---ngx.log(ngx.ERR, "failed to send ping: ", err)
return ngx.exit(444)
end
elseif typ == "pong" then
ngx.log(ngx.ERR,"ponged");
elseif typ == "close" then
break
end
end
还是隔10秒报一次time out错误，我的理解是否在wb:recv_frame()此处会有个timeout时间的等待，在10秒后无数据上报则返回timeout 错误。
2017/04/11 22:25:50 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:25:50 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

walker.ma.biz

所有的sock:receive都会在timeout的时候报出一个timeout error，但并不会断开连接，websocket是包装的ngx.req.socket，因此也是一样。
解决办法：
1、无视这种错误，比如发现在timeout err就不打印

2、跟客户端做一个ping的协议，用来保持连接，比如 ping的间隔 < timeout的设置

其他建议：可以在timeout的时候做一下计数，如超过10次即退出循环（服务端主动断开连接），这样可以保证在客户端网络不好的时候释放服务器资源，但需要客户端
做一些重连机制之类的

在 2017年4月11日星期二 UTC+8下午11:05:38，pan qing写道：

local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
end

将websocket的demo最简化，会隔10秒报一次timeout错误，请教了QQ群的朋友，说加心跳

后来改成
local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
if typ == "text" then
ngx.log(ngx.ERR,data);
elseif not data then
local bytes, err = wb:send_ping()
if not bytes then
---ngx.log(ngx.ERR, "failed to send ping: ", err)
return ngx.exit(444)
end
elseif typ == "pong" then
ngx.log(ngx.ERR,"ponged");
elseif typ == "close" then
break
end
end
还是隔10秒报一次time out错误，我的理解是否在wb:recv_frame()此处会有个timeout时间的等待，在10秒后无数据上报则返回timeout 错误。
2017/04/11 22:25:50 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:25:50 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

walker.ma.biz

不用看这个源码，只要看看一下openresty/lualib/resty/websocket/protocol.lua就知道了，同时建议看一下epoll或libevent之类的东西，
对于事件通知机制有一个更好的了解

在 2017年4月12日星期三 UTC+8下午12:04:29，pan qing写道：

看了源码
ngx_http_lua_socket_tcp_read(ngx_http_request_t *r,
ngx_http_lua_socket_tcp_upstream_t *u)
b = &u->buffer;
read = 0;

for ( ;; ) {

size = b->last - b->pos;

ngx_http_lua_socket_read_handler(ngx_http_request_t *r,
ngx_http_lua_socket_tcp_upstream_t *u)
{
ngx_connection_t *c;
ngx_http_lua_loc_conf_t *llcf;

c = u->peer.connection;

ngx_log_debug0(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
"lua tcp socket read handler");

if (c->read->timedout) {
c->read->timedout = 0;

在接收环节有自旋锁不断接受数据流，并判断是否超时。不知道我判断的对不对，请大神指教。现象确实是，在无数据包提交来的10S后就报超时错误。

On Tuesday, April 11, 2017 at 11:05:38 PM UTC+8, pan qing wrote:
local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
end

将websocket的demo最简化，会隔10秒报一次timeout错误，请教了QQ群的朋友，说加心跳

后来改成
local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
if typ == "text" then
ngx.log(ngx.ERR,data);
elseif not data then
local bytes, err = wb:send_ping()
if not bytes then
---ngx.log(ngx.ERR, "failed to send ping: ", err)
return ngx.exit(444)
end
elseif typ == "pong" then
ngx.log(ngx.ERR,"ponged");
elseif typ == "close" then
break
end
end
还是隔10秒报一次time out错误，我的理解是否在wb:recv_frame()此处会有个timeout时间的等待，在10秒后无数据上报则返回timeout 错误。
2017/04/11 22:25:50 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:25:50 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"

pq16344

多谢，明白了。

On Wednesday, April 12, 2017 at 1:33:38 PM UTC+8, Walker Ma wrote:

所有的sock:receive都会在timeout的时候报出一个timeout error，但并不会断开连接，websocket是包装的ngx.req.socket，因此也是一样。
解决办法：
1、无视这种错误，比如发现在timeout err就不打印

2、跟客户端做一个ping的协议，用来保持连接，比如 ping的间隔 < timeout的设置

其他建议：可以在timeout的时候做一下计数，如超过10次即退出循环（服务端主动断开连接），这样可以保证在客户端网络不好的时候释放服务器资源，但需要客户端
做一些重连机制之类的

在 2017年4月11日星期二 UTC+8下午11:05:38，pan qing写道：
local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
end

将websocket的demo最简化，会隔10秒报一次timeout错误，请教了QQ群的朋友，说加心跳

后来改成
local wb, err = server:new{
timeout = 10000,
max_payload_len = 65535
}
while true do
local data, typ, err = wb:recv_frame()
if typ == "text" then
ngx.log(ngx.ERR,data);
elseif not data then
local bytes, err = wb:send_ping()
if not bytes then
---ngx.log(ngx.ERR, "failed to send ping: ", err)
return ngx.exit(444)
end
elseif typ == "pong" then
ngx.log(ngx.ERR,"ponged");
elseif typ == "close" then
break
end
end
还是隔10秒报一次time out错误，我的理解是否在wb:recv_frame()此处会有个timeout时间的等待，在10秒后无数据上报则返回timeout 错误。
2017/04/11 22:25:50 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:25:50 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:00 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:10 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 lua tcp socket read timed out, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"
2017/04/11 22:26:20 [error] 1485#0: *10 [lua] ws_redis_test.lua:83: ponged, client: 192.168.1.17, server: localhost, request: "GET /sredis HTTP/1.1", host: "192.168.1.200"