我们的网页游戏服务器上线2个月了,一直运行平稳,没出什么重大BUG。前两天刚更新了一个版本,结果今天早上GM报过来一个BUG,让我折腾了整整一天。
事情是这样的,早上GM报告说某台服务器上有玩家抱怨在线时间奖励无法领取,客户端上显示在线时间已经到了,点击领取服务器却报错说在线时间不足。一开始怀疑是否客户端计时和服务器是否不同步,但很快排除了这个可能性。反复实验后发现是服务器上的玩家在线时间一直没有更新。查阅了一下服务器代码,玩家的在线时间变量是每隔60秒加1,这里判断时间间隔是用的系统的tick count,tick count是一个32位的int,单位是毫秒,每隔40天会溢出,因此就怀疑是不是tick count溢出,造成了时间判断错误(但是实际上tick count循环相减也是能够得到正确值的)。
虽然一时难以确定是tick count溢出造成的问题,不过还是顺手把tick count改为了更加可靠的DateTime计时方式。但就在修改的过程中,GM又收到了更多的玩家抱怨,其他和时间相关的刷新功能都报出了问题,最要命的是我们的游戏有每日零点自动恢复资源的设计,服务器是美国太平洋时间也就是我们早上10点会自动刷新资源,结果在线的玩家都没有在这个时间点上刷新资源,于是玩家开始造反了,各种投诉和抱怨不断。
继续查阅代码来分析问题,零点刷新的代码是用的DateTime来计时的,这样就排除了Tick count的问题,根据所掌握的情况,跟时间相关的功能都多多少少出了问题,但也不应该是代码的问题,因为其他服务器都正常运行的。难道是系统本身的时间出了问题吗?貌似只能这样解释了...不过,当你开始怀疑编译器、系统或者硬件出问题的时候,往往是自己犯低级错误的时候。所以我决定在关闭、迁移服务器之前再好好检查一下服务器的log记录,以定位问题所在。
在生产环境中的服务器是没办法用调试器去检查问题的,要分析问题只能看log记录。但是正式运营的服务器是不开DEBUG级的log的,(开了的话每秒会输出几千条信息,那就把服务器彻底搞崩溃了),所以能够看到的log信息很少,也没有发现明显的异常出错log,要定位这个问题就比较困难了。不过我在服务器上集成了一个实时profile的功能,能够统计并打印每个重要函数(感兴趣的函数)的执行次数和执行时间,profile了几次,终于发现了一条重要线索:服务器的主定时器OnUpdate函数不执行了。因为大部分时间相关的刷新都是在OnUpdate里执行的,这个函数不执行可想而知服务器问题有多严重,难怪玩家抱怨不断了。
服务器的定时器代码是我自己实现的,之前跑了那么久一直都没出过问题,怎么这次突然会出问题呢?分析了一下代码终于找到了原因,Timer的调度函数在每次执行完Timer的事件代码之后会重新把Timer添加到Timer队列里以便下次执行(如果这个Timer是多次或者无限次运行的话),由于Timer函数可能因为BUG会抛异常,所以调度函数是会处理异常事件并记录出错log的。但是在接住异常后我的代码就不会再将这个Timer添加到Timer队列里了,从逻辑上说这个策略是为了保护服务的安全性考虑,一旦Timer函数出现了异常,那么下次就不应该再去调度这个Timer,否则可能会不断的出异常把服务器拖慢甚至拖死。但是我的服务器OnUpdate也是依赖的Timer来实现的,如果OnUpdate里抛出了异常,OnUpdate就再也不会被执行了,这样就出大问题了。以前没发生过这种问题是因为我的OnUpdate代码从来没有出过错,而其他的Timer事件虽然有出过异常,但都是临时的一次性Timer,下次不会再被调度,因此掩盖了这个问题。出了这次的事故之后,我决定把这个坑填上,即使Timer事件发生异常也保证Timer可以继续被调度,因为频繁的报错总好过不知不觉的把Timer关掉,这样有利与用户查错。
那么OnUpdate怎么会抛异常的呢?继续翻阅了之前的服务器log记录,发现前面确实有好几条异常报错的log,其中有一条就是在OnUpdate里抛出来的,就是这条致命的异常log引发的血案。一般服务器在处理Bug所引发的异常时通常是采取容错策略,也就是在靠近外层的函数上接住异常,做好记录以备排查,然后把相关的用户session关闭,继续正常运行。这样的策略可以让服务器存在一些BUG的情况下依然可以健壮的运行,但也容易让人产生一些错觉。因为之前服务器已经稳定运行了很久了,对自己的代码过分的自信,所以现在很少会去检查错误log,很多Bug其实也就失去了被及时发现和修正的机会了。而前两天服务器代码刚刚更新过,有新来的同事添加过新的功能代码,引入新的BUG也是很正常的事情。亡羊补牢,根据服务器上的错误记录,把代码好好检查了一下,修正了3处会导致异常的代码Bug。然后更新版本重启服务器,才把这次的运营事故圆满的解决了。
总结一下这次的运营事故,在实践中容错策略和速错策略的权衡需要更加的小心。这次的问题是由于在服务器上更偏重容错策略,使得问题难以在第一时间被发现,虽然容错没有让这些Bug搞垮服务器,但是问题会以另一种形式呈现,最终让服务难以为继。万不可认为有了容错就可以高枕无忧啊。