游戏服务端死循环检测方案
传统死循环问题检测排查的困境
游戏服务端开发维护过程中,经常会碰到死循环或者游服性能问题,此类问题一般存在本机或者QA内部环境极难重现,难以定位和排查的问题。一般能采用的方式,只有:
-
静态代码审查
-
在可能出问题或者可能耗时较多的代码部分添加LOG,然后经过测试后上线观察,再加LOG,再观察。
以上这些传统方案不仅定位效率低,准确度低,而且问题的解决周期长,碰到影响恶劣的问题,还可能引起重大项目事故。
本方案解决的问题
1.实现精确到功能点级的故障定位,极大缩短了定位问题的时间。一般故障报出以后,当下查看LOG即可定位到问题所在。 2.实现精确到功能点级的耗时检测,和函数级的LUA脚本函数调用检测,并从时间段累计调用次数,累计调用耗时,单次调用平均耗时等方面综合监测性能问题,检测时间精确到tick。 方案应用后极大的提高外服死循环和性能问题的排查效率,目前已通过该方案查出数个死循环和性能问题。
实现方案
游服的业务驱动,一般来自这么几个部分:
-
游服的定时器OnTimer
-
客户端上发的消息
-
游服内部产生的消息
-
LUA脚本调用
因此,我们针对以上4个部分分别进行监测,就能准确定位具体是哪个消息触发了哪个功能导致的死循环或者性能问题。 首先,对于死循环检测,必须独立于业务线程之外,所以我们单独使用一个线程MonitorKernel来进行死循环和性能问题的检测。基本的思路都是在业务开始前向MonitorKernel发送业务开始消息,结束后再发送业务结束消息,分别附带上时间戳和耗时信息,这样在MonitorKernel就可以通过时间检测和开始/结束配对进行检测是否有死循环发生,以及各个业务的耗时情况。 其次,耗时检测方面,我们需要非常精确地计时,因此我们对常用的几种计时方式做了porfile,下面是各种方式调用的耗时信息(10W次调用):
-
timegettime:检测时间精度1-16ms,耗时0.61ms
-
QPC,检测时间精度tick,耗时0.59ms
-
std::chrono,检测时间精度最高1ns,耗时19ms
基于以上的精度和耗时结果,我们选了QPC进行耗时检测。 针对上述四种业务驱动因素的特点,我们分别采用了如下不同处理:
-
OnTimer:由于调用非常频繁,在OnTimer中每个步骤发送一个开始/结束消息是不现实的,因此我们的方式是,在OnTimer开始和结束时,发送消息到MonitorKernel,中间过程通过全局数组,为每个线程分配了一个全局的定时器监测数据结构,然后每个步骤修改全局变量的步骤ID和时间戳。这样MonitorKernel检测到OnTimer开始后2秒未收到配对的结束消息,则可以知道哪个线程可能发生了死循环,然后通过全局数组取对应的线程OnTimer检测结构体,则可以知道哪个步骤,哪个时间点发生了死循环。
-
客户端消息检测和游服内部消息:这个没什么特别的,收到消息后,开始处理前将消息ID和ACTION_ID发送到MonitorKernel,结束时再发送一次即可。
-
LUA脚本:LUA脚本调用必须通过程序触发,因此我们在触发点callLuaFunction进行检测,开始执行前发送一次,包含调用的函数名和参数,结束后发送一次,即可进行检测。
一些注意事项
-
在OnTimer中按业务增加定位处理。因为游服业务OnTimer调用非常频繁,而OnTimer中涉及的业务又非常多,要精确到功能点定位又不影响游服性能,需要特殊方案处理(上面已经详细阐述过,这里不再赘述)。
-
windows下高精度计时QPC,在部分较老的CPU和操作系统版本可能有性能问题(有些云服务器也有问题),因此我们在程序启动时做了一个动态检测是否启用高精度计时器(未启用QPC则使用timegettime计时,会有16ms左右的误差,这种情况下耗时累计检测是不准确的,但是平均耗时检测可以降低这部分误差)。也可以根据是否启用了QPC,来区分使用不同的性能超时判定策略。
-
容错机制。因为异步检测,依赖于开始和结束消息的配对,但是游服运行过程中,可能由于触发异常导致没有正确发送结束消息,这样MonitorKernel可能一直缓存着开始信息,如果量很大可能导致频繁输出LOG和内存占用导致游服性能下降或者内存耗尽,因此对于缓存超过10分钟的未配对信息,将会进行清除。