临潼网站建设,wordpress主题xueui,网站开发网页权限如何控制,wordpress小工具打不开一、现象
2023.10.17下午收到业务反馈#xff0c;说是接口调用超时#xff0c;进件系统和核心系统调用外数系统接口时等待过久#xff0c;引起系统异常。然后我们看了下接口调用的日志#xff0c;确实接口的响应时间在五十秒左右。我们自己测试了下#xff0c;发现也是这…一、现象
2023.10.17下午收到业务反馈说是接口调用超时进件系统和核心系统调用外数系统接口时等待过久引起系统异常。然后我们看了下接口调用的日志确实接口的响应时间在五十秒左右。我们自己测试了下发现也是这么长这是必现的大概率就是系统自身的问题。很容易就联想到Java虚拟机内在频繁gc导致Java进程运行受阻处理时间过长然后我们就看到报元空间内存溢出的异常了java.lang.OutOfMemoryError: Metaspace当时我们调大元空间的内存就立即重启了。 二、排查过程
1.相关概念
Java虚拟机的元空间是保存类的元数据(Class)的不同于堆元空间是到服务器上申请内存的所以如果一台服务器部署了多个应用最好设置个上限可以通过这两个参数设置大小
-XX:MetaspaceSize256m //初始大小-XX:MaxMetaspaceSize512m //最大值
我们生产设置的值为512M正常情况下也是够用的测试环境压测的时候发现元空间内存稳定在220M左右说明加载了很多类。
Jdk内置了很多工具jcmd、jconsole、jvisualvm配合下面这些参数可以查看Java虚拟机内存占用情况
-XX:NativeMemoryTrackingsummary //NMT内存分析-XX:UnlockDiagnosticVMOptions //启用内置工具-XX:TraceClassLoading //查看类加载信息-XX:TraceClassUnloading //查看类卸载信息
反射调用时会加载很多中间类用于构造Java对象或方法调用。使用反射应该慎重并且只在没有其他代替方案时使用。
2.定位问题
从日志看首先com.netflix.discovery.DiscoveryClient是eureka客户端发现注册中心的类eureka客户端启动时会开启定时任务周期性轮询微服务的状态本质就是发送get请求拉取微服务信息并与本地已经保存的微服务进行对比发现有变化就更新这里面会执行一段代码 可见每次轮询都会创建RequestExecutor接口的匿名实现类如果元空间满了就会报内存溢出的异常这是在DiscoveryClient类的fetchRegistry方法中报的日志中的Timeout则是因为无法创建匿名类导致Future无法返回这样就能明确的定位是由于元空间内存满了导致频繁gc而引起的线上问题。
复现问题
刚开始我们觉得是线上的并发量很大处理的请求过多导致我们的反射代码大量执行从而加载了很多中间类于是我们进行了压测结果发现元空间大概稳定在220M左右然后每次波动很小上涨很慢。之后去生产看了接口调用信息发现qps在39左右因此不是高并发引起。之后我们仔细看了日志发现在之前就一直报主键冲突的异常。我们用的是Oracle数据库主键是通过雪花算法生成的。 这里我想到两个问题一是不断地报主键冲突的异常对元空间内存占用造成的影响是什么二是为什么会报主键冲突的异常。
a.反射对元空间的影响
Java虚拟机底层是c实现的代码看不懂的。网上的说法也是众说纷纭每个统一的标准而且Java内存溢出也是很少出现。我就打算自己来验证了。首先我到生产环境把出现主键冲突到内存溢出这段时间的接口都查出来了然后使用postman为接口设置调用次数延时为25ms模拟qps为40的调用环境。在本地的代码中手动设置实体类主键为数据库中已有的主键结果就复现了生产环境内存溢出的问题了。
我通过 jcmd 220096 GC.class_stats class10.txt 指令将虚拟机的类加载信息保存了下来可以看到加载了大量的sun.reflect包下的类这些正是跟反射相关的类用于反射的方式构造实例对象和方法调用。从日志也可以看到如果jdbc抛出了异常就会有大量的发射调用。
所以我得出的结论就是我们元空间内存溢出(OOM)就是由不断地产生主键冲突的异常引起的。
b.雪花算法
我们的主键不是数据库生产而是我们通过雪花算法生成的。我先看了实体类中id所有set方法调用的地方发现这个值只来自于雪花算法的实现方法。
我们的id是由generate()方法生成的雪花算法是由nextId()实现的timeStr是yyMMddHHmmss格式表示的时间字符串这个方法的逻辑就是如果同一秒的线程拿到锁执行nextId()方法序列号就会加加到新的一秒就会置0而我们的id就是由yyMMddHHmmss格式表示的时间字符串和nextId()方法返回的值合并的所以一般情况应该是不会重复的。 但也有特殊情况第一是服务器的时间变化了就会生成重复的id虽然这个概率很低。第二个就是多线程同步执行的情况了看图说话吧整个过程分以下几步
线程1在12:00:00.990获取到锁执行nextId()方法的时候线程2在12:00:00.995进来了线程3在12:00:01.005进来了假设方法的执行时长为20ms。到12:00:01.010方法执行完毕线程1生成的id为”20231015120000””0000”此时释放锁由于synchronized是公平锁所以要么线程2获取到锁要么线程3获取到锁如果线程2获取到生成的id就是”20231015120000””0001”再然后线程3拿到锁生成的id是”20231015120001””0000”id是各不相同的但是如果是线程3先拿到锁呢那么线程3拿到锁后生成id是”20231015120001””0000”线程2再拿到锁生成的id就是”20231015120000””0001”就跟线程1产生的id重复了也就会在插入到数据库时引起主键冲突了进而抛出异常进而持续大量占用元空间导致元空间内存溢出。
为什么会产生这个问题因为线程抢占锁是随机且公平不是按照时间顺序的就是说可能后一秒的线程执行完了锁可能会让给前一秒在等待的线程。 解决问题
刚开始打算使用Atomic原子变量解决就写个下面这个版本意思是只要有请求进来 就加加只要一秒内的请求数不超过MAX_SEQUENCE(8191)就不会重复结果压测发现还是生成的重复的id上面的nextIdAtomic()效率是很高但是问题是sequence是单例bean的属性即便计算出sequence的值在return之前如果有其他线程进来了拿到的就是跟当前线程一样的值。
最终我们的雪花算法实现如下: 逻辑是每次获取当前毫秒时间戳如果是同一毫秒的线程序列号就加加加到512为止(如果加到512以上还是会重复但是概率几乎为0因为1s内得有500*6030000个请求进来)如果不同毫秒的线程就置为0压测了20万个线程分别设置qps为100、200、1000均正常。
三、总结
通过这次生产问题的解决自己也积累了一点排查问题的经验。首先解决问题的时候一定要学会分析问题是什么怎么产生的怎么导致的要一层一层的排查。然后就是大胆猜想小心证明一定要自己动手操作容易产生灵感。现有的数据一定要好好利用。最后就是平时的积累很重要因为不怎么熟悉jvm所以很多工具还是现学现卖的就比较耽误时间所以平时不可以忽视学习积累的机会。
