记两次Erlang服务器线上事故

这次的上线不太太平。虽然早就使用机器人进行了测试,也夸下海口理论上承载上万人不成问题,然而在上线前两天就发生了严重事故。尽管最终测试数据出乎意料的好,但整个项目为我们的傲慢和松懈付出了沉重的代价。被打脸之后,赶紧记一下以示警醒。

部分用户操作超时,大量用户进程启动失败

现象

游戏开放登陆之后,很快同时在线达到了1000左右。此时有玩家报告,部分交互操作出现了超时,并且在超时之后玩家登陆时服务器回报timeout错误。同时有玩家无法登陆,服务器根本就没有返回。我们立即查看了服务器机器的状态,此时内存和CPU的占用都绰绰有余,状态良好。使用etop查看Erlang中进程的状态,情况也没有异常,Reduction比较高的都是预料中的系统,消息队列中也没有太多积压。
查看日志之后,发现大量操作在对玩家进程进行gen_server:call()时就发生了超时,显然玩家进程在忙于做其他事情,而且也并未产生太高的Reduction。对阻塞的玩家进程调用process_info()后,能获得的信息非常有限。而无法登陆的错误,根本就没有明显的报错。

排查

我们意识到,用户操作超时就是由于有的用户进程启动失败造成的。我们的玩家有一些操作需要唤醒其他未登录玩家的进程,显然是需要被唤醒的玩家进程也出现了启动失败的情况。而发生一次超时之后,该进程一直在等待目标进程的返回,所以一直未处理新来的消息。然而,对其他玩家进程进行操作的时,我们使用的gen_server:call()在默认情况下会在5秒后超时,照理说不可能会长时间阻塞。
我们迅速review代码,发现没有在调用gen_server:call()时使用infinite超时的地方。同时,我们认为DB会是一个可能的瓶颈,但是在查看慢查询日志之后一无所获。然后我们尝试让客户端在登陆时一直等待服务器的返回,发现过了接近10-15分钟之后,登陆请求居然成功返回了。这种现象在我们的认识(gen_server:call()五秒超时)下看来时极其诡异的。
获得这个线索之后,我们在登陆的流程上添加了大量记录时间的日志,并且仔细阅读了代码和源码。最终,我们注意到跨节点的rpc:call()和启动进程的supervisor:new_process()是不会超时的。看来罪魁祸首就是玩家进程上面的supervisor了。我们立即查看了该supervisor的消息队列,发现已经积压上千条。

结论

我们的玩家进程在初始化时是同步等待的。单个玩家进程的启动时间并不慢,不足以引起我们的注意。然而,在玩家数量增多之后,supervisor需要等待大量玩家进程的初始化完成,极大地降低处理请求的速度。
最终我们增加了supervisor的速度,并且将玩家进程的初始化修改为异步,解决了问题。
需要记住的教训有以下几点:
1. 在关注worker性能的同时,也需要关注supervisor。尤其是会大量产生新进程的supervisor,其下的进程绝不可以使用同步初始化。
2. 对可能唤醒一个甚至多个其他进程的操作应当重点注意,在测试时应当专门关照。
3. 不能轻视复杂的线上环境,性能测试时需要覆盖尽可能多的复杂操作。能同时处理大量来自机器人的指令并不能说明系统能应对线上的压力。

ERTS内存迅速增长造成服务器崩溃

现象

在解决前一个问题之后,服务器一直状态良好,内存也未见异常增长。
晚上下班后邀朋友吃烤串庆祝一下,谁知道拍黄瓜刚端上来,同事就告诉我出大事儿了:逻辑服务器实例消失了,所有玩家自然也登陆不上去了。丢下风中独自凌乱的朋友回到公司,姑且先重启了逻辑服务器。
检查日志之后,没有任何报错和异常。然后开始分析服务器留下的crashdump。

显然,服务器是在试图扩张堆尺寸时发现操作系统的内存已经耗尽,才发生崩溃的。此时,ETS和Atom的情况也没有异常,不是它们造成的内存暴涨。我们查看了所有线程的快照,发现只有一个玩家进程的新生代和老生代堆非常巨大,达到了GB级别。不幸的是,该进程在崩溃时出于GC状态,其stack traceback都已经丢失,只能看见其PC正指向string:tokens()。
我们认为,可能是我们的某些代码逻辑存在问题,使得内存在一段不短的时间后逐渐增长到如此之大。而且当时时间已经很晚,所以大家先行回家休息,计划第二天再进行排查。
回家之后屁股还没有坐热,同事那边又传来噩耗,服务器再一次崩溃了。看来内存暴涨是在短时间之内发生的。这样的崩溃在当天晚上一共来了3次,发生异常的玩家全是同一个,而且crashdump几乎如出一辙。而该玩家的数据和行为未见明显异常。

排查

同事的第一反应是逻辑错误造成的无限递归调用,不过在尝试之后,我们的代码和协议应该不会允许这样的错误。
string:tokens()这个方法代价不小,一次调用new的字符串对象连同栈帧本身的结构,即便是最保守的估计都将需要数十字节堆、栈空间。显然内存的暴涨多半是某处代码反复调用该方法造成的。即便不是无限,也足以使得服务器崩溃。由于信息非常有限,我们不得不排查代码中可能会反复调用string:tokens()的地方。花费不少时间后,我们定位到了某商店的购买功能。该功能中商品一次可以购买复数个,且每次价格都是动态的,需要解析表来获得。而且,商品在需求中没有限制购买次数!
该请求的数量参数是uint32,于是我们立即尝试在请求时传入0xFFFFFFFF,果不其然ERTS在十分钟之内崩溃,crashdump也和事故时基本一致。的确,42亿次函数调用,耗尽服务器的内存绰绰有余。这处代码也写的相当有问题,它选择在递归中每次解析字符串而非解析为列表后再进行递归,比较随意和浪费。

结论

显然,这是一位不怀好意的玩家,修改了客户端的代码,向服务器发出了极端数据类型的请求。
我们迅速在该处功能和其他系统中的类似功能中都对传入的参数添加了限制,堵住了漏洞。日后应该会在code review和开发中加倍注意类似情况。
需要记住的教训有以下几点:
1. 需求不需要限制不代表程序不进行限制。
2. 哪怕是不那么核心的功能,在开发时也不能过于随意。应避免对CPU时间和内存的无谓浪费。
3. 不要盲目信任Erlang的软实时和抢占式调度。在测试中我们发现,该异常的玩家进程凭借一己之力便大大降低整个服务器的响应。所以对于个别热点功能对其他功能的影响,我们应提高警惕并重点关注。


谨以此文为我在这家公司的工作画上句号。虽然将要离开这个团队,但也算是陪着她扛住了最后一波考验。祝愿同事们码力日进,项目一切顺利。


评论 3 您还未登录,请先 登录 后发表或查看评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
©️2022 CSDN 皮肤主题:大白 设计师:CSDN官方博客 返回首页

打赏作者

苦恼的山城号

你的鼓励将是我创作的最大动力

¥2 ¥4 ¥6 ¥10 ¥20
输入1-500的整数
余额支付 (余额:-- )
扫码支付
扫码支付:¥2
获取中
扫码支付

您的余额不足,请更换扫码支付或充值

打赏作者

实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、C币套餐、付费专栏及课程。

余额充值