由一个疑难Bug想到的... ...

      今天游戏服务器在测试时碰到了一个疑难Bug，具体现象如下：server进程在间隔很短的时间（几十ms），同时收到client发过来的两个做技能的消息包，而正常情况下这两个消息包是要隔一个技能CD时间的。在排除client是按正常发送消息的情况后，自然就是对server的处理逻辑进行检查了。

      几经排查，发现了另外一个问题，即在打印的server日志中，发现存在两条日志的时间有超过2s以上的，而且这样的日志还不少。正常情况下，因为server存在一个tick机制，tick的时间间隔目前是200ms，即最多每隔200ms左右就应该有日志输出的（tick处理函数里有日志输出）。把这个情况与之前的那个Bug联系起来，就可以有一种合理的解释了。具体如下：

      首先，我们的server程序的主函数(main)本质上是一个在大循环下的单进程程序，如果在主函数中某个调用的业务逻辑处理模块，由于某种原因被阻塞了一段时间，比如：几秒钟，那么，当处理完这步回到接收消息处理步骤时，就有可能同时收到两个本该间隔时间收到的消息，换句话说，就是这两个间隔消息的业务模块被之前的模块“挂起了”，并且这个挂起的时间超过了这两个消息的间隔时间。

      那么，究竟是什么原因导致server的某个模块被“挂起了”呢？我们去查看那些间隔超过2s以上的日志，看程序逻辑中是否存在不合理的循环、随机函数调用等处理，但查来查去还是没发现什么异常。我们查看有些日志都是凌晨3、4点打印的，而server是凌晨根本就没有人登录，这样看来，server的负载引发的异常情况，是可以排除的。既然不是CPU的问题，那还有谁会出问题，答案是I/O，没错，I/O的写操作太频繁了，同样可能会阻塞住进程一小段时间，更何况我们现在都是实时写日志的。OK接着看I/O的操作，经过大家一起努力，并且咨询其它同事，问题可以定性为I/O引起的，由于我们的server是放在公司内网服务器上，这些服务器目前是被公司统一用虚拟机平台管理的，而虚拟机之间读写磁盘是有可能影响server日志输出的，即有可能使写日志操作被挂起。这是我们现在解释这个Bug最合理的理由，当然，我们还不能百分之百确定就是这个原因，所以，与Bug的争斗仍将继续... ...

      只是，写到这里，我不禁想起另外一个问题来，即如果我们游戏在实际的运营中，有可能由于server的CPU负载较高而引发刚才说的那个Bug。这里涉及到另外一个问题，即游戏server的消息处理能力问题。目前，我们server在一次大循环处理中，是串行最多接收处理10条上行消息的。那如果我们server的处理能力小于这个数目还又该怎么办呢？当然，最简单的办法是调整消息处理的数目，但这样的话，消息就会在BUS中超积超多，达到一定的数量后，就会出现消息丢失的情况。所以，从根本上解决的办法，恐怕还是得提高我们server消息处理的能力，即提高业务逻辑的处理性能才是上策啊！这也是咱们写游戏server的伙计们重点关注的问题了。