Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

服务 task 积压,内存暴涨,signal 后 task 依然不会消耗 #1654

Closed
mrzhangjing opened this issue Sep 25, 2022 · 11 comments
Closed

Comments

@mrzhangjing
Copy link

mrzhangjing commented Sep 25, 2022

表现
  1. 服务器内存飙升

  2. DebugConsole > stat 发现 task 异常积压

  3. 查看日志没有 endless 输出

  4. signal 后,task 数没有被消耗

DebugConsole > stat 多次执行效果(执行间隔比较久)

:0000000e       cpu:72901.470634        message:543117495       mqlen:16        task:18736806
:0000000e       cpu:74400.674503        message:543154039       mqlen:19        task:18734242
:0000000e       cpu:79306.974164        message:543264801       mqlen:22        task:18731018

signal 堆栈:

[599237][0000000e] : ./lualib/skynet.lua:937: ./lualib/skynet.lua:340: ../../server/public/srv_dbmgr.lua:133: signal 0
stack traceback:
​        ./lualib/skynet/queue.lua:15: in function <./lualib/skynet/queue.lua:12>
​        (...tail calls...)
​        ../../server/public/srv_dbmgr.lua:133: in function 'cluster_command_base.userQueueDispatch'
​        ../../server/public/command_base.lua:75: in upvalue 'f'
​        ./lualib/skynet.lua:256: in function <./lualib/skynet.lua:255>
stack traceback:
[C]: in function 'assert'
​        ./lualib/skynet.lua:937: in function 'skynet.dispatch_message'

代码片段:

-- srv_dbmgr.lua
local queue = require("skynet.queue")

function command.userQueueDispatch(userId, method, ...)
    local UserQueue = UserQueueIndex[tostring(userId)]
    if not UserQueue then
        UserQueue = {
            userId = userId,
            add = queue()
        }
        UserQueueIndex[tostring(userId)] = UserQueue
    end

    local result = {}
    UserQueue.add(queueFunc, result, method, ...)-------------- srv_dbmgr.lua:133
    return result[1]
end
-- queue.lua
function skynet.queue()
	local current_thread
	local ref = 0
	local thread_queue = {}

	local function xpcall_ret(ok, ...)
		ref = ref - 1
		if ref == 0 then
			current_thread = table.remove(thread_queue,1)-------------- queue.lua:15
			if current_thread then
				skynet.wakeup(current_thread)
			end
		end
		assert(ok, (...))
		return ...
	end

	return function(f, ...)
		local thread = coroutine.running()
		if current_thread and current_thread ~= thread then
			table.insert(thread_queue, thread)
			skynet.wait()
			assert(ref == 0)	-- current_thread == thread
		end
		current_thread = thread

		ref = ref + 1
		return xpcall_ret(xpcall(f, traceback, ...))
	end
end

DebugConsole > stat 多次执行效果(执行间隔比较久)

:0000000e       cpu:87025.518779        message:543451556       mqlen:16        task:18717803
:0000000e       cpu:87026.191734        message:543452038       mqlen:10        task:18717803

task 过长导致 DebugConsole task、uniqtask 无法使用

由于时间匆忙,未来得及收集更多信息。

项目代码稳定运行半年多,突然异常,由于我们没有对服务状态进行监控导致雪崩。

@sniper00
Copy link
Contributor

应该是这个导致的 table.remove(thread_queue,1), 算法复杂度 n平方, 大量数据容易出现雪崩

@mrzhangjing
Copy link
Author

应该是这个导致的table.remove(thread_queue,1),算法复杂度 n 平方,大量数据容易出现雪崩

是的,消息积压到这个程度出现各种问题都是可能的。
可问题在于消息积压的起因。该类型的服务启动了17个,主要任务是转发消息,其余服务负载状态良好。

针对此类情况,我除了做服务状态监控,是否还有其他的应对方式。

@cloudwu
Copy link
Owner

cloudwu commented Sep 25, 2022

table.remove 是 O(N) 的,它在同一队列中太长时比较慢。这是果不是因。

把它变成 O(1) 并不麻烦,保留一个 head 和 tail 指针,然后用 O(1) 删除即可。

-- 出队列
if head == tail then
  current_thread = nil
else
  current_thread = thread_queue[head]
  thread_queue[head] = nil
  head = head + 1
end

-- 入队列
thread_queue[tail] = thread
tail = tail + 1

但这并不解决这里的问题。它可能引起的问题是:队列累积过快,而能够快速消化时,消化速度不够快。
但如果没有出现 endless 的 log ,说明情况并没有恶化到队列长到无法在短时间处理完。

另外应该查一下是否有 message queue 过长的 log ,这里看起来也没有,因为 stat 查询时的平均长度只有 10~20 ,没有累积的迹象。

至于为什么 signal 后为什么 task 数量不再下降,这是因为在 table.remove 处打断了正常执行流程,所以 wakeup 没有调用。所以之前挂起的 task 无法继续运行。

当没有出现 endless 时,不建议使用 signal 打断正常的执行流程。

此处可能做的补救手段是改进 queue 的实现,在 queue 累积到一定长度后,后续向 queue 添加任务直接抛错,而不再进入队列。

btw, 这里 userQueueDispatch 的实现不符合 lua 的惯用法,性能无谓的损失。这和这里的问题无关,但平时开发应该注意。惯用的方法是用 meta method 去触发新的 queue 。因为 meta method 触发是在 C 中完成的,而用 lua 代码判断会导致 happy path 上非常多的无效 lua code 运行。

-- tostring(userId) 似乎多余
local UserQueueIndex = setmetatable({}, {
  __index = function(t, userId)
    local r = {userId = userId,  add = queue() }
    t[userId] = r
    return r
  end })

@cloudwu
Copy link
Owner

cloudwu commented Sep 25, 2022

如果你是一个专用服务,看起来只是希望顺序执行同一个 userId 上的请求,每个请求结束之前,不执行下一个请求。

我认为这里并不需要 skynet.queue ,或者说是这是对 skynet.queue 的误用。因为 skynet.queue 是用 wait/wakup 实现的,每次添加任务都记录了当前的 coroutine ,也就是发起任务时的上下文。

而对于专用服务,就是你说的 “转发消息” 的任务,这个来源的上下文并不重要,要执行的函数已经描述了全部任务。这里只需要自己做一个队列,把要运行的函数放入队列。而接受请求的 coroutine 可以退出。这样并不会累积 task 。内存开销远小于对 coroutine 排队。

大致流程:

  1. 封装任务,除了运行任务函数之外,同时检查任务队列是否还有后续任务。
  2. 如果任务队列为空,执行这个任务。
  3. 否则,将任务加入队列。

只要每个任务都在执行完后检查队列的后续,就自然做到了一个任务接一个的执行。

但是,依然要对这个队列的长度进行管理。

@mrzhangjing
Copy link
Author

感谢, @cloudwu @sniper00 的解惑。

反思下,不知从何时开始对性能的要求慢慢变的不在意,也懒得造轮子,能直接使用的绝对不自己动手。可能是安逸太久了。

接下来我会做这些优化:

  1. zabbix 对服务状态进行监控
  2. 优化专用服务队列

模拟情况,对优化前后的效果做对比

再次感谢。

@cloudwu
Copy link
Owner

cloudwu commented Sep 26, 2022

skynet.queue 另外解决了一个问题:在执行任务的流程中又发起了新任务。这个新任务和旧任务是同属一个 coroutine 上的。这一点是用计数器增减完成的。

如果不存在这种用法,其实可以省下相关的处理逻辑。

@mrzhangjing
Copy link
Author

多谢指点,对于 skynet.queue 的设计用意已经有了新的认识和理解。

btw,大概描述一下背景和相关概念:
  • Game服务
    • 玩家业务逻辑
  • DBMgr服务
    • DB入口
    • 用户请求队列
    • 管理所有DBHandler,并负载均衡
  • DBHandler服务
    • 管理数据库连接
    • 数据库增删改查
流程

Game -(call/send)->DBMgr-(call)->DBHandler

本意是为了保证请求的有序,就直接使用了 skynet.queue

DBMgr 启动了17个,通过 UserId%17 的方式分配,正常情况下 task 数不超过100,且各服务消息数大致相同

以下是各服务的状态:

:0000000e       cpu:72023.175737        message:543095840       mqlen:17 task:18738306
:0000001e       cpu:10412.741359        message:519359420       mqlen:0 task:1
:0000002f       cpu:10257.216258        message:519285196       mqlen:0 task:1
:0000003e       cpu:10230.350268        message:523019975       mqlen:0 task:1
:0000007f       cpu:10266.272948        message:518792661       mqlen:0 task:1
……

异常发生后,单核心CPU未满载。

原本的问题是专用服务的优化方案,其实我这边还需要定位的是为什么任务数会积压。

@cloudwu
Copy link
Owner

cloudwu commented Sep 26, 2022

看结构,应该是 DBMgr 到 DBHandler 的 call 被挂起了,然后 Game 又接着提交了很多请求。这些接连的请求比较常见是在不停的重试。

@mrzhangjing
Copy link
Author

mrzhangjing commented Sep 26, 2022

看,应该是 DBMgr 到 DBHandler 的被挂了,然后这些游戏又接着提交了很多请求。接连的请求比较经常是在不停的调用的重试。

这确实是最值得怀疑的一个方向,而且这种方式是必定复现的。
但 DBMgr 管理的 DBHandler 最新状态是正常的,我没有服务的历史状态记录,所以还不能完全确定由他引起。
关于这种情况,我会完善一下监控信息,定时采样服务状态并记录。

@sniper00
Copy link
Contributor

看,应该是 DBMgr 到 DBHandler 的被挂了,然后这些游戏又接着提交了很多请求。接连的请求比较经常是在不停的调用的重试。

这确实是最值得怀疑的一个方向,而且这种方式是必定复现的。 但 DBMgr 管理的 DBHandler 最新状态是正常的,我没有服务的历史状态记录,所以还不能完全确定由他引起。 关于这种情况,我会完善一下监控信息,定时采样服务状态并记录。

如果客户端登陆会触发DB请求,看下是否有客户端不断重连断开的日志?一种猜测,有些客户端没处理好网络断开事件,造成旧的断开事件把新建的链接断开,出现循环创建链接触发DB请求。

@mrzhangjing
Copy link
Author

mrzhangjing commented Sep 26, 2022

看结构,应该是 DBMgr 到 DBHandler 的 call 被挂起了,然后 Game 又接着提交了很多请求。这些接连的请求比较常见是在不停的重试。

这确实是最值得怀疑的一个方向,而且这种方式是必定复现的。 但 DBMgr 管理的 DBHandler 最新状态是正常的,我没有服务的历史状态记录,所以还不能完全确定由他引起。 关于这种情况,我会完善一下监控信息,定时采样服务状态并记录。

如果客户端登陆会触发DB请求,看下是否有客户端不断重连断开的日志?一种猜测,有些客户端没处理好网络断开事件,造成旧的断开事件把新建的链接断开,出现循环创建链接触发DB请求。

客户端的请求也有自己的队列,登陆的加载使用的是call。

客户端断开会触发缓存中变更的数据入库,这里用的是send。

新客户端挤掉旧客户端的情况,一定是旧客户端的缓存数据推入DB队列后,才会对新的客户端鉴权。

因为只有变更的缓存才会入库,同时Game有缓存的情况下不会重复请求DB加载,所以频繁登陆登出理论上不会让DB过载。

我更多的是怀疑玩家正常在线状态下(会持续产生变更数据),DBHandler 某些原因阻塞了。而后续的变更累积到一定程度后雪崩。

在DBHandler处理尚未返回的情况下,我不敢贸然的尝试切换DBHandler。 -_-||

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants