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都将被定位，哈哈。
网友评论