线上故障之-内存问题
内存概述
内存泄漏(Memory Leak)
是指程序中已动态分配的堆内存由于某种原因程序未释放或无法释放,造成系统内存的浪费,导致程序运行速度减慢甚至系统崩溃等严重后果。
一般内存泄露的方式:
- 常发性内存泄漏:发生内存泄漏的代码会被多次执行到,每次被执行时都会导致一块内存泄漏。
- 偶发性内存泄漏:发生内存泄漏的代码只有在某些特定环境或操作过程下才会发生。常发性和偶发性是相对的。对于特定的环境,偶发性的也许就变成了常发性的。所以测试环境和测试方法对检测内存泄漏至关重要。
- 一次性内存泄漏:发生内存泄漏的代码只会被执行一次,或者由于算法上的缺陷,导致总会有一块且仅有一块内存发生泄漏。
- 隐式内存泄漏:程序在运行过程中不停的分配内存,但是直到结束的时候才释放内存。严格的说这里并没有发生内存泄漏,因为最终程序释放了所有申请的内存。但是对于一个服务器程序,需要运行几天,几周甚至几个月,不及时释放内存也可能导致最终耗尽系统的所有内存。所以,我们称这类内存泄漏为隐式内存泄漏。从用户使用程序的角度来看,内存泄漏本身不会产生什么危害,作为一般的用户,根本感觉不到内存泄漏的存在。真正有危害的是内存泄漏的堆积,这会最终耗尽系统所有的内存。从这个角度来说,一次性内存泄漏并没有什么危害,因为它不会堆积,而隐式内存泄漏危害性则非常大,因为较之于常发性和偶发性内存泄漏它更难被检测到。
以上是出现时机和频率不同
JAVA中的内存泄露:
上面所描述的是通常的内存泄露方式,当然也适用于java,但是对于java而言,问题似乎变得简单了,JAVA的一个重要特性就是通过垃圾收集器(GC)自动管理内存的回收,而不需要程序员自己来释放内存。理论上Java中所有不会再被利用的对象所占用的内存,都可以被GC回收,但是Java也存在内存泄露,但它的表现与C或者C++不同而已。这通常都是设计不合理造成的,也因此通过设计是可以避免的。根本问题在于,是否我们需要掌控的对象,在应该销毁的时候没有销毁,或者没有预料到对象的增量超出我们的预想。
1-对象增长超出预想
2-设计应该销毁的对象,而常驻内存
对于问题一,举一个常见的设计规约:线程池的创建应该显示指定阻塞队列得到小,避免默认值失去控制,极坏的情况下创建了大量的线程,导致OOM。
问题二,经常出现在设计缓存,存储的map,list中,无限增长,失去控制。
常见的容易导致内存泄露的点
1-线程池创建未显示指定阻塞队列大小
2-ThreadLocal 的管理中忘记回收对象
objectThreadLocal.set(userInfo);
try {
// ...
} finally {
objectThreadLocal.remove();
}
3-所有涉及资源链接的地方,都不要忘记关闭资源
4-类的成员变量为集合,或者单例的模式中有集合,引用了大量的其他对象
5-java方法,是传值还是传引用,造成的小时间段内,内存没按照预想回收掉
内存溢出(Out Of Memory)
内存溢出就是内存越界。内存越界有一种很常见的情况是调用栈溢出(即stackoverflow),虽然这种情况可以看成是栈内存不足的一种体现
内存溢出跟内存泄露区别
内存溢出:申请内存时,JVM没有足够的内存空间。
内存泄露:申请了内存,但是没有释放,导致内存空间浪费。
JVM内存布局
类的生命周期
JVM参数
1-JVM的参数类型
1.1 标配参数:-version,-help
1.2 X参数(了解):-Xint,-Xmixed
1.3 XX参数:
1.3.1 boolean类型:-XX:+PrintGCDetails
1.3.2 KV设值类型:-XX:MetaspaceSize=128m
2-查看内存参数
2.1 -XX:+PrintFlagsInitial 主要查看初始默认(不依赖java进程)
case:java -XX:+PrintFlagsInitial
2.2 -XX:+PrintFlagsFinal 主要查看修改更新(不依赖java进程)
case:java -XX:+PrintFlagsFinal
2.3 -XX:+PrintCommandLineFlags 打印命令行参数
2.4 jinfo 查看进程相关数据
case: jinfo -flag MetaspaceSize pid
问题:
-Xms:初始大小内存,默认物理内存1/64,等价于-XX:InitialHeapSize
-Xmx:最大分配内存,默认为物理内存1/4,等价于-XX:MaxHeapSize
-Xss:设置单个线程栈的大小,一般默认为512k~1024k,等价于-XX:ThreadStackSize
参考:https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html
常用配置
-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heapdump.txt
-XX:+PrintGCDetails
-Xloggc:gc.log
模拟内存溢出
/**
* 堆栈溢出错误模拟
*
*/
public class _1_StackOverflowErrorMock {
public static void main(String[] args) throws InterruptedException {
new Thread(() -> {
try {
stackOverflowError();
} catch (Exception e) {
e.printStackTrace();
}
}).start();
new Thread(() -> {
int num = 0;
while (true) {
try {
TimeUnit.SECONDS.sleep(1);
} catch (InterruptedException e) {
e.printStackTrace();
}
System.out.println(num);
num++;
}
}).start();
new CountDownLatch(1).await();
}
private static void stackOverflowError() {
try {
TimeUnit.NANOSECONDS.sleep(100);
} catch (InterruptedException e) {
e.printStackTrace();
}
stackOverflowError();
}
}
/**
* 堆空间溢出模拟
* JVM参数:-Xms20m -Xmx20m
*
*/
public class _2_JavaHeapSpaceDemo {
public static void main(String[] args) {
new Thread(() -> {
String str = "asdasd";
while (true) {
str += str + new Random().toString();
}
}).start();
new Thread(() -> {
int num = 0;
while (true) {
try {
TimeUnit.SECONDS.sleep(1);
} catch (InterruptedException e) {
e.printStackTrace();
}
System.out.println(num);
num++;
}
}).start();
}
}
/**
* JVM参数
* -XX:MetaspaceSize=12m -XX:MaxMetaspaceSize=12m
* <p>
* java 8及之后的版本使用Metaspace来替代永久代,存放了以下信息:
* <p>
* 虚拟机加载的类信息
* 即时编译后的代码
* <p>
* 模拟Metaspace空间溢出
**/
public class _3_MataspaceOOMTest {
public static void main(String[] args) {
new Thread(() -> {
try {
while (true) {
Enhancer enhancer = new Enhancer();
enhancer.setSuperclass(OOMTest.class);
enhancer.setUseCache(false);
enhancer.setCallback((MethodInterceptor) (o, method, objects, methodProxy) -> methodProxy.invoke(o, args));
enhancer.create();
}
} catch (Throwable throwable) {
throwable.printStackTrace();
}
}).start();
new Thread(() -> {
int num = 0;
while (true) {
try {
TimeUnit.SECONDS.sleep(1);
} catch (InterruptedException e) {
e.printStackTrace();
}
System.out.println(num);
num++;
}
}).start();
}
static class OOMTest {
}
}
/**
* 高并发请求服务器时,经常出现如下异常:java.lang.OutOfMemoryError:unable to create new native thread
* native thread异常与对应的平台有关
* <p>
* 导致原因:
* 1 应用创建了太多线程了,一个应用进程创建多个线程,超过系统承载极限
* 2 服务器并不允许应用程序创建这么多线程,linux系统默认允许单个进程可以创建的线程数是1024个,
* 应用创建超过这个数量,就会报java.lang.OutOfmemoryError:unable to create new native thread
* <p>
* 解决办法:
* 1.想办法降低你应用程序创建线程的数量,分析应用是否真的需要创建这么多线程,如果不是,改代码将线程数量降到最低
* 2.对于有的应用,确实需要创建很多线程,远超过linux系统的默认1024个线程的限制,可以通过修改linux服务器配置,扩大linux默认限制
**/
public class _4_UnableCreateNewThreadDemo {
public static void main(String[] args) {
for (int i = 0; ; i++) {
System.out.println("********i=" + i);
new Thread(() -> {
try {
TimeUnit.SECONDS.sleep(Integer.MAX_VALUE);
} catch (InterruptedException e) {
e.printStackTrace();
}
}, "" + i).start();
}
}
}
/**
* 〈一句话功能简述〉<br>
* 配置参数:
* -Xms10m -Xmx10m -XX:+PrintGCDetails -XX:MaxDirectMemorySize=5m
* <p>
* 故障现象
* Exception in thread "main" java.lang.OutOfMemoryError:Direct buffer memory
* <p>
* 导致原因:
* 写NIO程序经典使用ByteBuffer来读取或者写入数据,这是一种基于通道(Channel)与缓冲区(Buffer)的 I/O方式,
* 可以使用native函数库直接分配堆外内存,然后通过一个存储在Java堆里面的DirectByteBuffer对象作为这块内存的引用进行操作。
* 这样能在一些场景种显著提高性能,因为避免了在Java堆和Native堆种来回复制数据。
* <p>
* ByteBuffer.allocate(capability) 第一种方式是分配JVM堆内存,
* ByteBuffer.allocateDirect(capability)第一种方式时分配OS本地内存,由于不需要内存拷贝所以速度相对较快。
* <p>
* 但如果不断分配本地内存,对内存很少使用,那么JVM就不需要执行GC,DirectByteBuffer对象们就不会被回收。
* 这时候对内存重组,但本地内存可能已经使用光了,再次尝试分配本地内存就会出OutOfMemoryError,那程序就直接崩溃了。
**/
public class _5_DirectBufferMemoryDemo {
public static void main(String[] args) {
System.out.println("配置的maxDirectMemory:" + (sun.misc.VM.maxDirectMemory() / (double) 1024 / 1024) + "MB");
ByteBuffer bb = ByteBuffer.allocateDirect(6 * 1024 * 1024);
}
}
/**
* 〈一句话功能简述〉<br>
* <p>
* JVM参数配置演示
* -Xms20m -Xmx20m -XX:+PrintGCDetails
* <p>
* GC 回收实践过程时会抛出OutOfMemoryError。过长的定义是,超过98%的时间用来做GC并且回收了不到2%的堆内存
* 连续多次GC都只会收到了不到2%的极端情况下才会抛出。假如不抛出GC overhead limit错误会发生什么情况呢?
* <p>
* 那就是GC清理的这么点内存很快会再次填满,迫使GC再次执行,这样就形成了恶性循环,
* CPU使用率一直100%,而GC却没有任何成果
**/
public class _6_GCOverheadDemo {
public static void main(String[] args) {
int i = 0;
List<String> list = new ArrayList<>();
try {
while (true) {
list.add(String.valueOf(++i).intern());
}
} catch (Throwable e) {
System.out.println("*******i:" + i);
e.printStackTrace();
throw e;
}
}
}
什么条件触发GC-CMS为例
1-eden区满了?会不会触发?
2-老年代满了会不会触发?
3-直接缓冲区满了会不会触发?
4-元空间满了,会不会触发?
工具
1-jvm gc日志分析工具:https://javagc.cn/
https://gceasy.io/ft-index.jsp
2-内存快照分析工具:mat,jprofile,VisualVM
3-java自带:
-jps 进程查看
-jstat:用于监视虚拟机各种运行状态信息的命令行工具。可以显示本地或者远程虚拟机进程中的类记载、内存、垃圾收集、JIT编译等运行数据.
jstat -gc pid #垃圾回收统计
jstat -gccapacity pid #堆内存统计
jstat -gcnew pid #新生代垃圾回收统计
jstat -gcnewcapacity pid #新生代内存统计
jstat -gcold pid #老年代垃圾回收统计
jstat -gcoldcapacity pid #老年代内存统计
jstat -gcutil pid #总结垃圾回收统计
jstat -printcompilation pid #JVM编译方法统计
jstat -class pid #类加载统计
-jinfo 参数配置查看
-jmap 内存监控
jmap -clstats pid #打印进程的类加载器和类加载器加载的持久代对象信息
jmap -heap pid #查看进程堆内存使用情况,包括使用的GC算法、堆配置参数和各代中堆内存使用情况。
jmap -histo[:live] pid #查看堆内存中的对象数目、大小统计直方图,如果带上live则只统计活对象
jmap -dump:format=b,file=dumpFileName pid #jmap把进程内存使用情况dump到文件中
-jstatck线程监控
思考
1-eden space+ from space > to space可能么? 会发生什么GC
2-Integer为什么用equals判断相等
非堆内存泄露
背景:
三方路由系统对外提供的查询三方全程跟踪接口调用方TP99较高,提供方TP99很低,差距较大,为寻找原因,进行了极限压测
1、 服务单提供方TP99 30多ms,而调用方TP99 250ms左右,主要是因为极限压测过程中服务
提供方机器数量过少,而调用方机器是我们的几十倍,从统计方式上(按机器维度),我们的
TP999或者是Max值才是调用方的TP99,单从TP999与Max值来看,这个接口还存在可以优化的
空间,后来通过Jtrace查看几个执行慢的方法也看不出特别的东西,有些是SQL执行数据库慢,有些是跟Jimdb交互慢,表象是这样。实际上这个sql都是走的索引,这个分表大小也才250w数据,所以正常不会出现这种。
2、 后来看了下GC,发现存在大量FullGC,且堆占用很小的时候就执行FullGC了,看了下非堆,非堆大小从0-2G频繁变化,由此判断堆外泄露了,第一次遇到这种堆外泄露问题,jvm内存分布-方法区,这个地方出问题了,堆内存有MAT,dump之后有很多分析方式,非堆咋分析?(截图FullGC平均时长应该是700ms),后面的过程也是寻找可以分析非堆内存的工具,找了一圈找了俩,一个是google的greftools,但是这个工具需要安装一些库,根据实际观察,随着调用量增加非堆内存增加的越快,判断是某个方法出现的内存泄露,不知道哪个方法的情况下没法本地做复现,这个工具在生产环境安装又需要运维帮忙,可能会比较麻烦。那有没有其他方式轻松的查看非堆内存分布呢?答案是肯定的,有个命令jmap –permstat,但是很可惜,这个命令在生产环境使用的时候竟然卡主了,最后直接导致jvm假死,JSF没能及时移除这个节点,导致调用方超时。
3、 后来咨询胡老师(感谢胡老师,给出关键性的一步),给出的建议是在启动的时候增加参数-
verbose:class参数,看到这个参数,我想到了jstat –class查看class加载数量,果然加载了96w的class对象,而此时重启也生效了,控制台频繁打出加载class的输出。接下来代码就容易定位了,原因是JAXBContext的使用方式不对(搜索结果),本来应该单例,却每次都创建对象使用。修改代码-测试-发布-再次极限压测。最终验证正确,再也没出现非堆飙升,也没出现FullGC,我们自己的TP999 跟MAX值很稳定,调用方TP99也维持在10ms以下,至此问题解决。
4、 但是why?,经过漫长跟踪JAXBContext.newInstance代码过程中发现JAXB内部使用了反射
获取对象属性和方法(JAXBxml转对象的工具)生成代理类,代理类需要通过classLoader加载,走
类加载过程,双亲委派,正常情况下只加载一次就行,我们还知道同一个classLoader下同一个代理类对象是不能多次加载的,看似没问题,然而由于内部Injector类管理代理类的过程中使用了弱引用WeakReference类 ,导致被回收就会重新加载代理类,按照之前的逻辑好像没问题,重新加载同一个类了,不会加载成功,之前我也是这么想的,直到断点打到这,它抛了个duplicate class之后,还发现打印了Load class日志,大胆猜想,这个可能是jdk的bug,重复加载同一个类,虽然失败,但对应到方法区的内存却没被销毁,最后放开断点,出现大量Loadclass日志,看永久代,大量增加,最终FullGC回收,class对象也在一直增加,重复.其实这也算是JAXB的一个bug,不该重复加载同一个代理对象(说明:在原classLoader.load方法里是有判断是否加载过class的过程,但是JAXB中自己调用了classLoader内部的defineClass、resolveClass方法,是打破了双亲委派机制,导致多次重复加载class,引起内存泄露,本质上来说是JAXB的bug,当然JDK底层抛异常却不释放对内存的占用这也是有问题的,最后警惕对classLoder的使用,尽量使用其对外的load方法)
运单非堆内存溢出问题排查
1、环境及现象
运行环境:JDK版本 1.8.0
现象描述:
运单系统每隔一段时间,内存使用和CPU报警超出阈值85%,通过监控平台可以看到非堆内存持
续增加不回收 。导致频繁FullGC,引起CPU100%。
操作系统监控图:
JVM内存监控
从监控上看非堆内存永久代(JDK8 HotSpot JVM 将移除永久区,使用本地内存来存储类元数据
信息并称之为:元空间(Metaspace))一直增加且无法回收。这部分内存主要用于存储类的信
息、方法数据、方法代码等,正常情况下元空间不会占用很大内存, 所以对于动态生成类的情况比较容易出现永久代的内存溢出。开始怀疑应该是使用反射、代理等技术生成了大量的类加载到元空间无法回收。
问题排查
1、使用jstat 查看内存及GC情况:
各列含义: jstat (oracle.com)
S0C:第一个幸存区的大小
S1C:第二个幸存区的大小
S0U:第一个幸存区的使用大小
S1U:第二个幸存区的使用大小
EC:伊甸园区的大小
EU:伊甸园区的使用大小
OC:老年代大小
OU:老年代使用大小
MC:方法区大小
MU:方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
YGC:年轻代垃圾回收次数
YGCT:年轻代垃圾回收消耗时间
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间
可以看到发生了FullGC, MU 和 CCSU 都很大,FullGC并没有回收掉,再次确认了元空间内存
溢出的可能。
2、打印类加载信息 分析代码
在JAVA_OPION 中添加 -verbose:class 打印类加载信息。重启后观察日志输出
发现以上输出信息,并且一直不停的Loaded。 打印出了相关的业务类.BusinessMessageBody
、BusinessMessage ,看样子是使用Jaxb 序列化成XML时产生的问题。在项目中搜索相关代
码:
有Xml的注解
业务代码中使用 XmlUtil 工具类转成XML 。继续跟进 XmlUtil.ojbectToXmlWithCDATA
注 XML概念:
XML,就是可扩展标记语言Extensible Markup Language,包括XML/DTD/XSD/XPATH的w3c规范,在webservice方 面主要应用有SOAP/WSDL等(WSDL还不是w3c规范)
JAVA规范API统称JAXP,主要有DOM/SAX/STAX/XPATH等标准API,并内置默认实现。并在JAXP的基础上建立了 JAXB/JAX-WS等规范
常见的JAXP API(解析器)实现有xerces/crimson/woodstox/xalan等开源实现,也有一些厂商的实现(如IBM)。
常用的XML操作库如dom4j/jdom是JAXP API的二次封装(其实也封装了其他一些非规范的实现)
常见的webservice库如axis2/xfire/cxf等,按自己的方式实现了SOAP/WSDL等功能(XML相关功能基于JAXP),
由于JAX-WS规范的兴起,这些库也实现了JAX-WS规范
运行期实现类的查找模式都是类似,基本都是参数、配置、SPI、默认实现的顺序。如果有需要(如存在bug/性 能问题),可以根据这个查找顺序更换不同的实现方式。
工具类中使用 JAXB 将对象解析成XML。JAXB(Java Architecture for XML Binding),基于
JAXP(Java API for XML Processing),定义了XML和Java对象的映射处理关系,来看下JAXB 规 范
- 首先,检查配置文件jaxb.properties有没有定义javax.xml.bind.context.factory工厂类,通
过createContext生成 - 如果没有找到,就通过SPI(Service Provider Interface)机制( JDK内置的一种服务提供发现 机制 ),查找有没有实现类定义: META-INF/services/javax.xml.bind.XXX
- 如果没有找到,选择默认内部实现(oracle JDK):com.sun.xml.internal.bind.v2.ContextFactory
在项目目录中未找到 jaxb.properties 文件,但在maven依赖中搜索到了间接引用:
可以看到通过SPI机制 加载com.sun.xml.bind.v2.ContexFactory 实现类来生成JAXBContext。
JAXB 中有个用于访问bean的特定属性的类Accessor,该类定义了一个方法optimize返回优化的
Accessor类,
在optimize方法中 使用 OptimizedAccessorFactory 工厂获取优化的Accessor,来看具体实
现
第一个红框内 newClassName 我们在日志中已经看到了既是新生成的类名。紧接着使用
AccessorInjector.prepare 方法生成对应的Class 对象。AccessorInjector.prepare 方法中又调
用了
Injector.find 和Injector.inject ,这两个方法中 都调用了 下面这个方法用于获取类加载器对应的
Injector 对象,如果已存在缓存的Injector 直接返回,如果为空则会新建WeakReference 放入缓存 injectors (声明为WeakHashMap类型),injectors 里面的Value使用的是WeakReference弱引用 ,当GC发生时,垃圾收集器在某个时间点决定一个对象是弱可达的(weaklyreachable)(也就是说当前指向它的全都是弱引用),这时垃圾收集器会清除所有指向该对象的弱引用。
private static Injector get(ClassLoader cl) {
Injector injector = null;
WeakReference<Injector> wr = (WeakReference)injectors.get(cl);
if (wr != null) {
injector = (Injector)wr.get();
}
if (injector == null) {
try {
injectors.put(cl, new WeakReference(injector = new Injector(cl)));
} catch (SecurityException var4) {
logger.log(Level.FINE, "Unable to set up a back-door for the injector", var4);
return null;
}
}
return injector;
}
如果 injector 不为空这调用下面方法返回对应的 Class :
因为这一行,会重复执行类的定义,一定重复定义,重复定义,在jvm内部会有一次约束检查抛出
LinkageError,但临时创建的结构,等待GC去回收。
那么回过来想,为什么 injectors 被回收后,对应的Class实例未被回收卸载掉呢? 此现象产生的环境差异是因为升级了JDK版本,由JDK7升级到JDK8, 那么JDK8对垃圾回收做了哪些改变,是否这些改变导致了此问题的产生。带着这个疑问检索 google,得到了答案。
在JDK 7中,对Permgen中对象的回收会进行存活性检查,因此重复定义时产生的数据会在GC时被清理。然而在JDK 8中,Metaspace的回收只依赖classloader的存活,当classloader还活着时,它所产生的对象无论存活与否都不会被回收,由此引发了OOM。
从生产环境dump出来的内存文件分析后验证了这一点:
参见 :
https://zhuanlan.zhihu.com/p/25634935
http://lovestblog.cn/blog/2016/04/24/classloader-unload/
http://blog.yongbin.me/2017/03/20/jaxb_metaspace_oom/
文中提到 JAXB 2.2.2 以上版本做了修改,我们找到一个2.2.11 版来分析下差异:
JAXB-impl 2.2.11 版本 inject 版本种增加了一段 findLoadedClass`` 逻辑,按名称查找是否已有 加载的类,避免重复定义加载。
3、本地环境验证测试
把运单的相关代码摘出来测试观察使用JAXB-impl不同版本监控元空间变化规律。
JAXB-Impl 2.1.12 版本 监控详情: 可以看出来 元空间 持续增长,当达到配置的最大值,触发频繁FullGC,同时CPU使用率达到100%,也可看到已加载的类数量有 26501个
JAXB-Impl 2.2.11 版本 监控详情,元空间使用保持在12906832 ,类加载总数保持在 2156,CPU正常,GC正常,运行稳定。
4、线上更新版本观察
非堆内存维持在150M大小,稳定运行。
入库内存泄露总结
由于条件问题,一个查询语句把一个表里所有的记录都查询出来了,数据量很大,把内存打爆,造成现场验收卡,卡,卡…
在LAOS上用jmap -dump命令导出JVM的整个内存信息
然后用MAT艰难的打开文件,如图:
快速定位报表里的泄露嫌疑犯,点击进去,如图,发现这两个嫌疑犯占用了49.90%+44.45%=94,35%的内存,还让其他功能咋用呢??
点击第一个嫌疑犯的堆栈信息链接,仔细看就能发现该嫌疑犯是如何行凶的,如下图:
总结:内存分析工具有很多,使用MAT是其中的一种方法。另外,除了手动导出JVM内存信息外,还可以通过设置JVM参数,在JVM发生内存泄露的时候自动导出文件。
ArrayList递归调用addAll方法导致内存溢出
1、问题现象
casegroupId为7197的分组无法删除成功。
其中一台服务器内存从20%上升至60%,cpu一直处于100%状态。
导致一段时间该服务器无法处理请求并报Network error异常。
日志上报 Java.Lang.OutOfMemoryError:Java heap space内存溢出异常
2、排查过程
根据log日志排查发现,每次服务器内存上升前都有调用删除分组casegroupId为7197接口的操作。
将数据拷贝到本地环境后,复现了该问题,定位到问题代码如下:
3、原因分析
本段递归原思想以ids(ArrayList)为容器,循环添加每个子节点包含的全部分组id,并加上自身节点,进行返回。
但是,由于ids为引用传递,每次addAll操作都会将容器中已有的ids重复添加到容器中,造成每次添加容器中的数据都会发生倍增
子分组数小时,不会发生异常现象。ArrayList 的每次扩容包括分配1.5倍的新数组空间,和老数组历史数据的拷贝。
当子分组数超过27个时,数组长度达到了134217726,当长度超过Integer.MAX_VALUE-8或系统无法给ArrayList分配足够长的连续内存空间时,就会抛OOM异常。
ArrayList的频繁扩容与拷贝操作,也导致了在执行递归方法开始到抛出OOM异常这段过程中,Cpu一直处于100%的状态,无法处理其它请求。
修复后的代码如下,由于ids为引用传递,不需要addAll操作重复添加至容器中。
4、经验总结
1、在写完递归方法后,自测一定要认真测试到递归方法层的输入与返回,功能通过不能代表代码没有问题。
2、在使用ArrayList的时候,如果可以预知数组的大小范围,尽量对其进行容量大小的初始化,避免其频繁扩容。
读取excel引发的内存泄露
1.业务反馈las.im.**.com打开显示502,去查logbook日志发现应用出现内存溢出
2.去ump中jvm监控查dump文件输入路径“-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/export/Instances/las-im-manager-new/server1/logs”,登录运维自
主平台下载dump文件
3.使用MAT工具打开dump文件,查看大对象的具体堆栈信息
at org.apache.poi.xssf.usermodel.XSSFSheet.read(Ljava/io/InputStream;)V (XSSFSheet.java:138)
at org.apache.poi.xssf.usermodel.XSSFSheet.onDocumentRead()V (XSSFSheet.java:130)
at org.apache.poi.xssf.usermodel.XSSFWorkbook.onDocumentRead()V (XSSFWorkbook.java:286)
at org.apache.poi.POIXMLDocument.load(Lorg/apache/poi/POIXMLFactory;)V (POIXMLDocument.java:159)
at org.apache.poi.xssf.usermodel.XSSFWorkbook.<init>(Lorg/apache/poi/openxml4j/opc/OPCPackage;)V
(XSSFWorkbook.java:186)
at
org.apache.poi.ss.usermodel.WorkbookFactory.create(Ljava/io/InputStream;)Lorg/apache/poi/ss/userm
odel/Workbook; (WorkbookFactory.java:73)
at
com.jd.las.im.manager.service.wareservice.impl.ImportExcelWareAddrRelationServiceImpl.importExcel
(Lorg/springframework/web/multipart/MultipartFile;)Lcom/jd/las/im/util/data/Result;
(ImportExcelWareAddrRelationServiceImpl.java:114)
at
com.jd.las.im.manager.action.basis.wareservice.WareAddrRelationController.upload(Lorg/springframe
work/web/multipart/MultipartFile;)Lcom/jd/las/im/util/data/Result;
(WareAddrRelationController.java:401)
4.去程序中查代码,excel导入读取是使用WorkBook的方式,经测试几兆的excel文件导入就占用大量的内存(超1g)
5.去查poi文档http://poi.apache.org/spreadsheet/how-to.html ,发现POI提供了2中读取
Excel的模式,分别是:
用户模式:也就是poi下的usermodel有关包,它对用户友好,有统一的接口在ss包下,但是它是把整个文件读取到内存中的,对于大量数据很容易内存溢出,所以只能用来处理相对较小量的数据;
事件模式:在poi下的eventusermodel包下,相对来说实现比较复杂,但是它处理速度快,占用内存少,可以用来处理海量的Excel数据
6.参考了poi官方example,使用事件模式,读取excel,解决了问题
通用sql查询条件全if导致的内存溢出
现象:
20210726发现grafana平台上 添加复核结果方法出现 17s左右的调点(平时此方法的执行时间约为400-600ms)
问题分析:
1.首先WMS是按照园区部署的。对应看板取得是全国平均值,所以需要使用自定义看板配置 确定对应园区的,配置对应的看板进行园区查看:
发现7月19日出现了一个调用时长 超过42min的ump 告警
2.使用对应umpKey值:查找对应的机器IP,由于 wms客户端调用后台最大等待时间为1.5min,所以怀疑此调用为 服务假死导致无法上报UMP,UMP一直等待profiler.end方法上传,获取到出现问题的机器为172.31.136.xx
3.查询IP 对应机器对应的jvm内存,发现堆内存 在 7月19日17点左右开始飚高,按照监控中
profiler.end的提交时间回推 对应请求的时间大概在16:58左右发起,与图中JVM彪高时间一致
查询地址:
4.目前JVM启动日志中都配置了 内存打满前自动dump,前往对应的机器dump日志进行分析,使用工具为jprofiler,经过分析 发现byte类型占用了435MB的数据,并且调用来源为
ibatis.executor.resultset.ResultWrapper,经过jprofiler分析,怀疑有全表查询语句 返回了大对象导致的内存溢出
5.登录myops进行查询对应数据库是否存在慢sql全表查询
找到罪魁祸首,图中SQL直接关联拣货明细和订单明细进行查询 未添加任何条件,根据查询时间 反查到对应请求调用日志: 确定原因为研发本地手改报文调用服务端 导致的内存溢出(风险点:通用sql为了保证兼容性,对条件进行全if判断,导致全表查询)
问题sql:
修改方案: 针对Dao层对一些基础参数进行强制校验(三要素)
JVM堆栈内存溢出问题分析
一、事件回顾
整体处理时间:2020年07月23日 下午18:10 至 21: 50
涉及主机: 10.176.213.11, 10.176.213.7, 10.176.243.78, 10.176.243.75
关键告警内容:JVM监控堆内存使用率超出阈值,URL探针连续x次访问目标地址出现网络超时或者系统异常;
告警影响范围:个别用户(5个以内)
事件详细描述:
18:10 接收到 10.176.213.11 主机发送来的JVM内存使用率超出告警,随后又收到该
主机发送来的URL探针访问目标地址出现网络超时或者系统异常告警;
18:11 登录NP系统,摘除此主机
18:11 登录J-One,排除人为操作系统
18:12 登录日志系统,查看主机日志输出正常;排除log4j的日志Bug;
18:12 登录UMP系统,查看主机JVM指标:Yong GC 0~1 次/分钟 (正常),Full GC
20+次/分钟(不正常,平时为0),堆内存 3.99G,占比100% (不正常,平时为500M~1.7G,占比不超过50%),线程数 < 1500 (正常)
18:15 返回J-One系统,留存主机堆栈信息和运行日志;
18:16 收到 10.176.213.7 主机发送来的JVM告警,随后几秒接收到该主机发送来的URL探针访问目标地址出现网络超时或者系统异常告警;
18:17 NP上操作 10.176.213.7 主机下线
18:18 在UMP系统查看10.176.213.7 的 JVM各项指标,指标大致与10.176.213.11雷同;
18:20 对主机10.176.213.11 执行应用重启操作
18:28 对主机10.176.213.7 执行应用重启操作
18:30 对主机10.176.213.11 重启完毕,各项指标恢复正常水平,验证后挂回线上;
18:35 主机10.176.213.7 重启完毕,各项指标恢复正常水平,验证后挂回线上;
18:41 接收到 10.176.243.78 主机发送来的JVM内存使用率超出告警,随后又收到该主机发送来的URL探针访问目标地址出现网络超时或者系统异常告警;
18:42 NP上摘除 10.176.243.78 此主机;
18:45 留存10.176.243.78 主机的堆栈日志和运行日志;为了做事故原因分析,此主机未进行重启操作;
21:49 收到 10.176.243.75 主机发送来JVM内存使用率超出告警,随后又收到该主机发送来的URL探针访问目标地址出现网络超时或者系统异常告警;
21:50 在NP上摘除 10.176.243.75 主机;
第二日 上午: 由于已经留存了一台事故主机,于是重启10.176.243.** 主机,验证后挂回;
二、问题分析
数据来源:
出现JVM内存溢出时生成的hprof; 一共两份,分别来源于10.176.243.主机和10.176.213.主
机;
日志:一共四份:分别来源于出现问题的四台主机的eclp_selle.log;
关键数据:
JVM堆栈报告中:大对象
大对象中的占用内存最大的属性
未来得及释放的XML解析数据: 该数据已经导出,在后面
线程调用的HTTP响应方法:
用户上传文件
三、原因分析:
在查看JVM内存堆栈信息分析报告的,Orverview的大对象图表中,说名称为"http-1601-18"的线程事例时占用内存超过2G;继而查看该线程实例包含属性实例明细列表;
发现线程中占用内存最大的实例类为:
com.sun.org.apache.xerces.internal.dom.DeferredDocumentImpl ,占用内存 2G 左右;初
步可以确定此实例的创建造成了JVM内存溢出;
而该实例是POI工具包用于解析xlsx格式文件中的XML文件用的,也就是说是因为该线程执行过程中需要有xlsx文件解析逻辑。
进而查询该线程的调用HTTP业务接口,是:com…master.goods.controller.GoodsNewController#importBatGoods ;
结合代码,获知此方法是用于批量导入事业部商品数据的,其大致逻辑是:
- 接收用户导入的xlsx文件
- 使用POI包对文件进行解析
- 循环遍历解析后的数据,对他们进行数据验证、数据入库(及创建商品)操作
- 返回导入结果
结合的代码逻辑,堆栈信息分析,初步结论为某一用户在执行改操作时,导入了过大文件,导致此次的JVM 内存溢出事故;
然后查询四台主机操作日志:果然发现同一个用户在每次告警前的几分钟,都在商家工作台执行了商品导入操作;
因而得出本次JVM内存溢出的最终原因为:系统并未对导入文件大小做限制或限制太宽松; 从而导致用户导入较大的文件时在解析过程中出现 JVM内存溢出问题;
四、问题修复方案
1、对上传得文件进行大小限制;限制的原则就是根据模板和数据条目上限,计算 出一个合理的数值;根据实践:1000条的数据文件大小约在135K,5000条的文 件大小在619K;也就是说文件大小不应该超过1M; 而本案例中,用户上传的文件大小在26M左右;
2、解析数据时,要先进行数据行数验证,在对行数据进行解析;尽量减少数据转 换次数。
生产环境部分机器内存溢出问题处理
一、摘要
时间:2018.1.31 13:30:00 --2018.1.31 17:00:00
问题:3c联盟用户点击请求时,部分请求出现502的现象;导致部分请求处理失败
原因**:**服务器其中一台服务器,jvm因为内存溢出导致宕机
影响:用户量暂时不大,影响范围较小,5台服务器,一台出现问题
应急措施:将出问题的机器从负载上去掉,保证线上服务正常运行,处理时间约30秒左右
二、事故背景
系统已于11月底上线,一直运行正常,没有问题反馈,前期有持续观察服务器,没有发现问题。于2018年1月31号,接到业务方反馈和预警邮件,部分请求出现502的情况。经查看发现5台服务器中的一台宕机,Tomcat进程已经不存在了。
三、事故分析过程
第一步:把出问题的那台服务器从负载上去掉并解决线上问题之后,用jdos的监控中心对该服务器及负载下的其他服务器的运行状态进行观察发现:该服务器的jvm已经没有数据,其他服务器jvm内存均接近100%,看来其他服务器也岌岌可危啊。
第二步:查看了下宕机的那台服务器日志,关键信息如下:
为了查看该日志文件,和jdos同事,申请开通了 该服务器 和 另外一台濒临崩溃的服务器的 终端连接信息;
该文件信息基本上全是当时崩溃是的内存的一些大小参数(忘记截图),参考意义不大;
第三步:紧接着为了查看内存中到底是什么对象导致了内存的崩溃,由于jvm崩溃了,获取不到现在的一些信息了,于是连接到另外一台“濒危”的服务器上,去查看jvm内存的一些状况,具体情况如下
首先使用查看了下 jvm进程ID为 139
使用该命令 :sudo -u admin ./jmap -histo 139|more 查看到的情况如下:
查到有7000多个线程池,可以定位某个地方在疯狂创建线程池,肯定了第一步的判断
然后全文搜 Executors,发现之前的同事有两处创建线程池,并且是每次该请求接口基本上都会创建一个固定4个大小的线程池!原因终于找到了;此处列举一处:
于是,将宕掉的机子重启,然后频繁的去请求该接口,复现了异常情况,由此可以肯定了判断。此处修改为启动的时候创建一个线程池,请求的时候创建一个Callable实现即可。
续:补上此次服务器的jvm参数,以及dump文件大小
使用命令 sudo -u admin ./jmap -dump:format=b,file=a.hprof 139。
四、事故反思总结
1、将服务器监控预警做到位,此次疏于预警,导致服务器异常,没有及时发现,而是由业务方通知发现的,以后应避免此类事情再次发生。
2、多人合作项目,项目时间长一些细节东西已经记的不清晰了,以后重要的设计点最好有设计问题,方便后人解决问题。
3、有必要进行codeReview,来相互学习,相互进步。
4、应继续加强深入学习jvm相关知识,此处的事故算是一个在学习jvm道路上的一个成功解决案例。
JVM异常终止问题排查
1.现象
11月19号,jdos两台机器JVM突然挂掉(11.26.78.xx、10.190.183.xx),
查看MDC监控,发现jvm挂掉的时间点 机器内存占用很高(99%);
查看UMP-JVM监控,JVM各项指标很正常
堆外内存可能不准确
内存很平稳,每次yong gc,都能降下来;至JVM挂掉之前,未触发过full gc;CPU和线程数也都很正常。
2.问题初步分析定位-尝试Google
linux的OOM killer
Linux 内核有个机制叫OOM killer(Out-Of-Memory killer),该机制会监控那些占用内存过
大,尤其是瞬间很快消耗大量内存的进程,为了防止内存耗尽而内核会把该进程杀掉。 因此,你发现java进程突然没了,首先要怀疑是不是被linux的OOM killer给干掉了!
OK,顺着这个思路,确定到底是不是被oom killer干掉的。
查看系统报错日志: /var/log/messages,发现此文件是空的(后来咨询jdos运维同事得知,docker实例 写此日志被禁用)
查看内核日志:
dmesg输出信息有调用oom-killer,但是从内存来看貌似是宿主机的(total-vm:22120752kB),时间点无法确定;
联系运维查询:
可以确定JVM是被操作系统oom killer干掉了,
问题:docker规格4c4g,为何java进程会占用5.2g?
jdk1.8及之前,JVM是感知不到容器的存在的,所以会使用宿主机的信息来计算,docker -m参数一般用来限制应用内存大小,跟镜像版本也有很大关系,有的版本限制的差不多相当于物理内存的百分之50.
模拟:OOMKilled
案例说明一个问题:遇见jvm异常退出,先找dump文件,dump如果没有,找
hs_err_pid.log日志。如果还没有,翻内核日志。
jvm建议配置
以8G内存为例:
1-垃圾回收器的参数
2-元空间需要配(不配会无限增长)?512,350
3-堆内存最大最小?4G
4-栈大小?512k
5-直接物理内存? nio,配一点点足矣
6-GC日志,
不建议配置的:
各个区域的比例,默认值,