大数据和大并发调用问题分析(11.04)

注:图片来自网络
对于OSB环境的服务运行,在前面自己也将过很多篇的文章来分析服务运行性能问题,包括服务运行中出现问题时候的排查方法和流程。对于服务运行而言,实际上大并发调用本身并不会引起太大的性能问题或整个集群的内存溢出,真正影响最大的还是大数据量的调用和中大数据量的长耗时服务并发调用,因为以上几种情况最终导致的都是OSB集群中的服务器JVM内存持续增长而无法回收。
而现在当出现集群中某一台服务器内存溢出的时候,一般我们可以初步分析为由于大数据量大报文调用导致的内存溢出,但是当前面临的问题还是无法快速的诊断分析和定位到具体的哪个服务引起上面。
举例来说,当前我们发现节点内存溢出,但是我们实际上看服务运行监控日志,并没有出现大数据量的服务运行调用,而这个时候我们更加难以快速的定位到具体哪个服务引起的。
从服务器和OSB运行日志可以看到的一些关键信息如下:
11:01:01
11:02:01
也就是两条日志数据相隔不到1分钟,从25%剩余到只剩余不到1%的内存,内存完全被耗尽,同时无法进行回收导致内存溢出。接着是Oracle Coherence监控进程反馈出如下日志,Service guardian is 11369ms late, indicating that this JVM may be running slowly or experienced a long GC。在差不多2分钟的时间内报出多次该日志信息。
接着是报出最大线程约束达到的一个提示日志信息:The maximum thread constraint ClusterMessaging has been reached 22 times for the last 182 seconds。
在.out的日志里面,我们发现如下日志信息,即accepting connection migration with, 正在接受连接迁移。是出现问题的节点在接受其他节点的连接迁移?还是说将出现问题节点的连接迁移到其它正常的服务器节点去?暂时没有搞明白。
个人初步分析出现问题的时候应该只是集群中的一个节点,
同时可以在out日志里面看到Oracle Coherence的一个警告信息,看信息应该是两个节点之间出现沟通延迟。具体的信息如下:Experienced a 4140 ms communication delay (probable remote GC) with Member,而这个沟通延迟刚好出现在两个出现问题的节点上面。
参考文档:
https://confluence.atlassian.com/confkb/confluence-cluster-issues-180847200.html
里面也谈到如下内容:
Nodes communicate via UDP using unicast (they first use multicast to discover a new node, once discovered they communicate via unicast). If there are network problems, then the nodes may experience communication delays:
即不排除是由于集群节点之间的网络通讯延迟导致了上面的问题。
上面这篇文章初步分析了在整个Cluster集群中进行心跳检测的时候出现沟通延迟导致的超时或其他问题和具体的处理方式。实际上集群整个机制是在发现沟通延迟或超时的时候会快速的将问题节点从集群中去除掉。
从这个信息,初步分析还是很有可能是某一个节点在出现问题后,该节点的连接迁移到集群中的另外一个节点进行后续处理,结果导致集群中的另外一个节点也跟着出现内存溢出的问题。
由于内存一直无法回收,在持续了3分钟左右报出如下信息:Free memory in the server is 4,955,048 bytes. There is danger of receiving an OutOfMemoryError。即最终出现内存溢出。
从服务器监控日志也可以看到在这段时间里面会频繁的出现JVM Full Gc操作,但是仍然无法进行内存回收。内存被耗尽,最终导出内存溢出。在内存溢出后节点自动或手工进行重启,重启后才能够恢复正常。
如果整个内存快速耗尽和服务本身的大报文量调用没有太大关系的话,那么很可能就是和我们的APM监控工具或者和我们的OSB模板的拦截插件程序有关系,但是暂时无法分析和定位到具体是哪个影响。
该问题还没有最终解决掉,因此本文先做下在问题解决中的临时记录。