分享两个debug案例
案例一
img
如图所述,
App 发送login到A,
A向B发起一个PullMessage 拉取消息,
B如果有消息,将消息下发到A
A和B之前udp 传输,网络库确认。
App到A是Tcp传输
在线上测试用例中,用例保证每次B都有消息下发,线上无间断的跑着用例,100ml超时等待,没收到消息则失败,bvt偶尔会有失败。
我排查过程如下,拿错误时间和uuid去日志里看,线上日志输出还是比较多的。
先查看各自服务当时运行日志有无ERROR和WARN,无异常。
因为有超时等待,失败两种可能,B直接没消息下发,或者处理太慢,下发是超过了最大等待时间。
确定A收到了B的消息,看日志是收到了,那现在又有两种可能,udp网络库,网络库应用层实现的确认,A给B发送太费时,或者B消息处理太慢。
让同事看B收到消息到回复消息的耗时,结果是十几毫秒,时间比较正常。然后看下回复给A的udp发送时间,有发送成功的日志输出。A也的确收到了消息,耗时几毫秒。
看A给B发送的耗时,我看着也正常,我打包票我的服务没问题,同事说他不知道,感觉也没问题。
然后暂时陷入了无解。。等下次出现再查,干其他的了,同事直接说看着没问题,他不知道为啥。
再次出现,还是没啥结果。我想了下,看日志级别是INFO的,我说不行,让B开启DEBUG级别,我的A也开启DEBUG级别。这样的话,引用的两边网络库的运行过程都能输出,继续观察。
周五下班前,用例再次失败,ok,查日志,先看我A的日志,接受消息,udp网络库发送时间都正常,A问题排除
分布式环境中,不能拿两台机器时间直接对比,那我直接自己去看B服务的日志,看处理耗时,(DEBUG日志更多,引用库的代码日志都输出了),打开网络库的实现代码,按处理流程,日志一个个对,在相关的几千行日志里,逐步追踪网络库的处理,发现从接收到udp到发送Ack确认,耗时100多ms,这也太长了吧。
最终发现B从收到udp包,到发送ack,中途有100ml的时间,日志里是没有任何输出的,如果缓冲区没有其他内容的话,应该很快就回复了Ack,正常应该级几ml就一个发送就确认了。没有任何输出,当时机器复杂也很低。那么我就怀疑那个时间段,B程序就根本没收分配到cpu时间片。最后也找了主管来确认这个事,也确认了我的判断,OK,那报修系统组,让做一下机器检测,
最终系统组检测出机器cpu有问题.
至此该问题解决了,周报里我得到表扬,以及后面很多疑难偶有BVT失败的问题都是我去排查。
案例二
FE是长链接接入层,通过域名以及lvs负载均衡,机器众多。
B消息中转服务器,有预发布环境
C业务逻辑服务器
业务组,使用我们的消息系统,C->B-A 往下推送消息,最新版本增加了严格的条件测试,发现我们下发的消息10个能有1个解密出来后,的二进制内容发序列化失败,
问题如下
线上机器众多,FE具体接入那个机器不可知
后面放一台固定的预发布机器,没法重现
B只做消息转发,不加解密。FE我不熟悉,帮不上啥忙,
复现概率很低,没法通过线上日志查看。
周五都打算回家,下周再看,业务组老大,做个大胆设想,既然正确的key没法解密,让组里尝试,用错误的key去解密,试了多个,最后用空字符串,解密成功了,发现消息体里为空,FE的同学得到反馈后,查看代码,确认有一定概率会触发这个bug。大家纷纷表示,牛逼,还有这种假设,神操作。。。
小心求证,大胆假设!
领取专属 10元无门槛券
私享最新 技术干货