测试环境服务异常重启定位过程

1、第一次发生

周五的时候,测试环境一个C++服务每隔一段时间就发生core,负责这个服务的同事那天请假了,我就先看了一下调用栈,看完以为是挂在某个线程的执行函数里面了,并且是测试环境必现的问题,所以也没太上心,合计等同事回来加点日志就知道服务挂在哪里了,我就先把服务回滚到旧版本了,旧版本果然不挂了,于是认定就是这个服务最近修改代码导致的问题。


调用栈

周一同事回来review下自己的代码,加了几条日志,服务就不挂了,不知道为什么突然就好了,经验告诉我问题肯定还存在,当时我怀疑是踩内存了,改了代码可能踩到其它地方没导致core。

2、第二次发生

接下来没过多久就换其它C++服务core了,调用栈还是这个,并且那个服务已经很久没有改动过了,这就比较奇怪了。继续观察,发现了java服务也有很多重启的,打印出的异常是OutOfMemoryError: Direct buffer memory,还有一些系统日志显示部分服务被oomkiller干掉了,说明是真的没有内存了。

java异常

3、定位过程

在测试环境部署的服务非常多,32G的虚拟机会部署二十多个服务,先在运维系统上看看哪个服务占用的内存一直在增加,找到几个java的服务,把它们迁到其它机器上,但问题依然存在。

通过top命令观察发现在重启的那段时间,free里面内存不多,有时候只有不到200M,但cached里面有几G内存,这时候定位问题走了一段弯路,我怀疑是不是cached里面的内存没有被系统及时回收,然后弄了个定期任务定期回收cached里面的内存,发现依然没有解决,期间去找sys的同事几次,也都没登录到机器上给看,哎...

这时候又发现一个规律,我们测试环境有四台虚拟机,每个上面都有服务重启,并且重启的时间差不多,有没有可能这四台虚拟机在同一个宿主机上,宿主机的内存有问题,或者内存隔离有啥问题,所以又联系了金山云的同学帮忙看,他们看了系统日志,也是看到了oom,还是没有其它进展。

还得从内存入手,考虑到之前的内存采集间隔都是5秒,所以这次用dstat命令每隔两秒采集一次,这一次发现在重启的那个时间点used内存确实一下增加了很多,再用top命令每隔两秒采集一下进程的内存,发现几个java服务内存突增,而这些突增的都会报OutOfMemoryError: Direct buffer memory异常。捋了下思路,问题应该就是这几个java服务短时间申请大量内存,超出配置,发生异常,同时系统也由于内存不足oomkiller掉一些服务,C++服务有可能就是被kill掉的,或者就是因为没有内存出现异常。

找到了异常的java服务,接下来就得看看为啥突然需要这么多内存,测试环境没有多少流量啊。看这个异常都是thrift报的错,应该是thrift收到消息后开始申请大内存,所以先想到了用tcpdump抓一下thrift端口的包,看看有没有收到大包,没想到歪打正着,等发现服务重启之后看了下抓包日志,发现了问题,有一些安全组的机器往我们thrift接口发送了消息,并且有问题的服务都收到了这个消息。赶紧去找了安全组的同事,原来thrift有bug,他们定期往测试环境的thrift端口发消息,触发bug,现象就是会使thrift申请大内存。

4、最后

最后终于找到了问题,在差点要放弃的时候,前后大概花了10来天的时间,一个原因是复现一次问题需要一个小时左右,并且问题复现后看到的有可能是假象或者是不明显的现象,再一个原因就是定位问题的时候什么都怀疑,走了很多弯路,浪费了时间。

工作了这么多年,不断印证马克思理论的因果必然联系啊。BUG都将被定位,哈哈。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
【社区内容提示】社区部分内容疑似由AI辅助生成,浏览时请结合常识与多方信息审慎甄别。
平台声明:文章内容(如有图片或视频亦包括在内)由作者上传并发布,文章内容仅代表作者本人观点,简书系信息发布平台,仅提供信息存储服务。

友情链接更多精彩内容