记一次PermGen持续增长的解决过程

前言

这个问题的起因,是一次PermGen持续增长的报警,而问题的解决,是PermGen、类加载、Spring、JDK等知识的融合。

本次问题,从发生到最终解决,经历了很长的时间,这个过程中,有工程方法,有JVM优化,有源码追踪,有思想碰撞,最终解决问题后,发现是Spring 4.1.1.RELEASE的BUG,从4.2.4之后,这个BUG就修复了,这次问题的解决,对于我们从Low到Hight的过程,深有裨益。

问题的解决,是多位同事合作的结果,我再一次总结一遍,以求加深理解,并对读者有所裨益。

背景

SRE给jvm.memory.perm.used.percent增加报警,于是,开始不断收到报警。

报警之后,我们用jstat -gccause -h10 pid 1000,监控进程,发现PermGen满了之后,又被FullGC回收掉了,下一步,我们需要查出PermGen持续增长的原因。

Falcon监控

永久代

GC

Load Class

原因初步排查

TraceClassLoading

到底是什么原因导致了PermGen持续增长呢,猜不到,就采用一些帮助定位问题的方法。

在应用启动参数中增加 -XX:+TraceClassLoading ,每加载一个类,都会加载一个类,于是,我们看到:

[Loaded sun.reflect.GeneratedSerializationConstructorAccessor10037 from __JVM_DefineClass__]
[Loaded sun.reflect.GeneratedSerializationConstructorAccessor10038 from __JVM_DefineClass__]

MAT

这还有一种看类的办法,首先通过 jmap -dump:format=b,file=xxx pid dump堆,然后通过MAT工具查看,如下图。

求助Google,http://rednaxelafx.iteye.com/blog/548536,发现如下代码和日志吻合。

BTrace

到底是什么调用了这个代码呢,通过Btrace打出调用栈,定位出产生问题的业务代码。Btrace代码如下。

@BTrace
public class ClassloadTester {

    @OnMethod(clazz="java.lang.reflect.Constructor", method="acquireConstructorAccessor")
    public static void defineclass(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod) {
        print(Strings.strcat("entered ", probeClass));
        println(Strings.strcat(".", probeMethod));
        jstack();
        println("==========================");
    }
}

原因初步找到了,就是一个ApplicationContext.getBean操作,从Spring容器中拿出一个Prototype类,由于这个类被设计成了有状态的,所以不能用singleton。

原因似乎找到了,但还是有诸多疑问,原型类多个实例没问题,难道会有多个Class被生成,如果这样,那岂不是所有使用了Spring容器存储Prototpe类的场景,都会有问题,并且,我们也没有看到不断Load我们业务相关的类啊?

这些疑问当时都被搁置了,想对业务类进行非状态改造,发现工作量挺大,于是暂时搁置了。

JVM优化

老报警也不是个事,查到两个JVM参数:

-XX:+CMSPermGenSweepingEnabled

-XX:CMSInitiatingPermOccupancyFraction=70

CMS接管Perm,70%时并发进行垃圾收集,避免满了再FullGC。

通过图示,我们可以看到,在permgen 90%~100%之间,执行了full gc,回收了新生代、老年代、永久代。

增加了permgen参数,在70%的时候,进行垃圾回收,回收了新生代、永久代,不会回收老年代,如下图。

PermGen 90%报警,我70%就给你回收了,领导也不会收到报警了,这其实没有根本解决问题,只是歪门邪道:)只是比直接关掉报警强一点。

原因进一步排查

对编程相关的知识有怀疑,写一段代码验证一下,是一个好办法。

于是,有同事开始写一段和业务代码非常类似的代码,但是简单很多,方便改动、调试、执行。

最最重要的,通过简单的代码,我们可以定位到是在哪行代码之后出现问题,于是,我们就能知道为什么在这行代码之后会出现问题。

看代码调用链

  1. ApplicationContext.getBean("errorService", ErrorService.class)
  2. AbstractApplicationContext.getBean
  3. AbstractRefreshableApplicationContext.getBeanFactory
  4. AbstractBeanFactory.getBean、doGetBean
  5. AbstractAutowireCapableBeanFactory.createBean、doCreateBean、createBeanInstance、instantiateBean、applyBeanPostProcessorsAfterInitialization
  6. CglibAopProxy.getProxy
  7. ObjenesisCglibAopProxy.createProxyClassAndInstance
  8. ObjenesisBaseget.newInstance、getInstantiatorOf
  9. StdInstantiatorStrategy.newInstantiatorOf
  10. NativeMethodAccessorImpl.invoke
  11. DelegatingMethodAccessorImpl.invoke
  12. Method.invoke
  13. NativeMethodAccessorImpl.invoke
  14. MethodAccessorGenerator.generate
  15. ClassDefiner.defineClass

说几个重点代码

1、在PROTOTYPE标注的类上使用aop注入后,spring在生成aop代理时,是每次都会生成一个新的class吗?

我们可以看到,Enhancer每次都调用createClass()方法,但是,生成类时使用了cache,保证同一个类加载器里面,一个类同样的增强配置时,只有生成一个类。

2、产生问题的代码截图

3.产生问题的根本原因

通过上面的截图,我们看到,这个类"sun.reflect.GeneratedSerializationConstructorAccessor10037",是Objenesis帮我们生成对象的过程中加载的。

查询Objenesis的相关资料,原来它是Spring用来实例化类的,用它实例化类有很多好处,可以看官方文档。

难道用Objenesis实例化类,每次都要加载这个类吗?继续看官方说明,可以看到:

原来官方推荐单例使用的,而Spring4.1.1中用错了,非单例的;CglibAopProxy是通过ProxyFactory来生成的,因此每次都会new一个,所以Objenesis也会new一个。试着用Spring的更高版本,发现从4.2.4开始,Spring已经修正了这个Bug,改成静态的了。

强调一下

这个问题是ObjenesisCglibAopProxy中的Bug引起的,而在Spring4.2.4开始,已经修复了这个Bug。

什么情况下,我们会踩到这个Bug?

当服务声明为Prototype,并且方法上有注解存在时,因为只有这种场景,才有使用到ObjenesisCglibAopProxy。

代码演示

https://github.com/pumadong/cl-roadshow/tree/master/roadshow-app/src/main/java/com/cl/roadshow/spring/perm

另一个15次代码优化问题

我们在Debug过程中,发现另外一种现象,截图如下:

即,每当一个类从Sping容器中取出15次后,第16次取出的时候,也会加载这样一个类,为什么呢?

看这个帖子:http://rednaxelafx.iteye.com/blog/548536 。

总结

这个问题,主要经过两个阶段:

第一个阶段,使用工程方法,比如falcon监控、jstack、jmap、mat、TraceClassLoading、BTrace,定位出问题所在;

第二个阶段,在找不出根本原因的情况下,化繁为简,通过简单的演示代码,复现问题,并通过Debug的细致跟踪,找出Spring 4.1.1在“ObjenesisCglibAopProxy”中,使用“ObjenesisStd”实例化类时的Bug。

第一个阶段重点是工程方法,分析问题的步骤;第二个阶段是重点是代码分析,通过Debug逐步定位到问题代码。

处理过程中的本应该做出的推断:

1、“Loaded sun.reflect.GeneratedSerializationConstructorAccessor10037 from __JVM_DefineClass__”,这个提示是很明显的,虽然PermGen满了,但是是被这个类填充的,不是我们的业务类,所以,我们不应该怀疑是我们的业务类被增强而产生了多个;因为没有我们的业务类被增强并被Loaded的提示;所以,只要找出这个类加载的原因就好了;

2、Btrace已经帮我们定位了调用栈,所以如果想从根本上解决问题,尽早写测试代码来重现问题即可,错误不重现,不能说找到了根本原因,那么如果在生产改了,很可能产生错误的解决办法。

参考

http://hg.openjdk.java.net/jdk7u/jdk7u/jdk/file/70e3553d9d6e/src/share/classes/sun/reflect/MethodAccessorGenerator.java

http://rednaxelafx.iteye.com/blog/548536

http://objenesis.org/tutorial.html

http://objenesis.org/

时间: 2024-11-05 18:43:26

记一次PermGen持续增长的解决过程的相关文章

记一次ora-1652错误的解决过程

报错现象: 通过v$RMAN_BACKUP_JOB_DETAILS查看备份状态,一直卡着不出结果,很长一段时间之后抛出ORA-1652: unable to extend temp segment by 128 in tablespace ,此时查看临时表空间使用情况,发现占用很少,然后重新执行查询,在另一个窗口查看临时表空间使用,临时表空间共25G,使用率从1%一直不断的涨,结果就是一直涨到100%,然后查询备份的窗口又报出ora-1652, 查看ora 1652错误,还是比较简单,就是临时表

(原)记一次CentOS7 磁盘空间大小异常的解决过程

环境:kvm系统:CentOS7故障描述:10g的ssd,可使用大小仅有2g解决过程: ? ? 某次重装系统后,安装软件总提示磁盘空间不足,检查之下发现仅有2G空间,实则明明是10G的ssd,以下为排错过程: 1.df -h查看vda1大小为2.7G #df -h Filesystem Size Used Avail Use% Mounted on /dev/vda1 2.7G 2.4G 236M 91% / devtmpfs 234M 0 234M 0% /dev tmpfs 244M 0 2

[转]线上GC故障解决过程记录

排查了三四个小时,终于解决了这个GC问题,记录解决过程于此,希望对大家有所帮助.本文假定读者已具备基本的GC常识和JVM调优知识,关于JVM调优工具使用可以查看我在同一分类下的另一篇文章: http://my.oschina.net/feichexia/blog/196575 背景说明 发生问题的系统部署在Unix上,发生问题前已经跑了两周多了. 其中我用到了Hadoop源码中的CountingBloomFilter,并将其修改成了线程安全的实现(详情见:AdjustedCountingBloo

记一次公司仓库服务器死锁过程

记一次公司仓库服务器死锁过程 仓库拣货卡死,排查了数据库的很多地方,都没有头绪,最后到SQL Server 错误日志里查看,终于发现了蛛丝马迹 EXEC xp_readerrorlog 0,1,NULL,NULL,'2015-09-21','2015-10-10','DESC' waiter id=process5c30e08 mode=U requestType=wait waiter-list owner id=process5c26988 mode=X owner-list keylock

jenkins内存溢出的一些解决过程

公司内网测试jenkins服务器,最近总是出现PermGen space(内存溢出)的问题,解决过程记录如下 1.重启jenkins查看日志: 3, 2017 10:54:54 udson.ExtensionFinder$Sezpoz _find WARNING: Failed to load org.jenkinsci.plugins.github.pullrequest.events.impl.GitHubPRLabelExistsEvent$DescriptorImpl java.lang

OutOfMemoryError PermGen space 的解决办法(头痛了几天)

解决 OutOfMemoryError: PermGen space ,过程是痛苦的,结果是舒畅的 最近自己的程序在 Redeploy 重新部署的时候,老提示 OutOfMemoryError: PermGen space 错误,在网络上搜索了相关的资料,但是按照做后还是存在这个问题.由 于我是第一次碰到这个问题, 花费了我 2 天时间, 过程比较痛苦, 结果还是比较 圆满的.我将我的经历写下来,供我自己以后参考,也提供给大家分享. 在网络上关于 OutOfMemoryError: PermGe

一次线上GC故障解决过程记录

排查了三四个小时,终于解决了这个GC问题,记录解决过程于此,希望对大家有所帮助.本文假定读者已具备基本的GC常识和JVM调优知识,关于JVM调优工具使用可以查看我在同一分类下的另一篇文章: http://my.oschina.net/feichexia/blog/196575 背景说明 发生问题的系统部署在Unix上,发生问题前已经跑了两周多了. 其中我用到了Hadoop源码中的CountingBloomFilter,并将其修改成了线程安全的实现(详情见:AdjustedCountingBloo

linux中企业网站中病毒的解决过程

1.1 处理过程 和运维人员确认确实出问题了,并详细确认问题情况. 指定处理方案,先备份已有数据,然后执行命令批量修改回来. 写解决说明,写完发给他们的运维. 询问处理结果,并告知详细查看日志,寻找问题发生来源. 提供亡羊补牢解决方案 1.2 从发现到解决过程 运营人员.网站客户发现问题,网站有弹窗广告. 运营人员报给开发人员,开发联系运维人员,开发和运维共同解决. 开发发现的问题原因就是所有站点目录被嵌入一段JS代码. 详细查看日志,寻找问题发生来源. 提供亡羊补牢解决方案

【夯实Mysql基础】记一次mysql语句的优化过程!

1. [事件起因] 今天在做项目的时候,发现提供给客户端的接口时间很慢,达到了2秒多,我第一时间,抓了接口,看了运行的sql,发现就是 2个sql慢,分别占了1秒多. 一个sql是 链接了5个表同时使用了 2个 order by和 1个limit的分页 sql. 一个sql是上一个sql的count(*),即链接了5个表,当然没有limit了(取总数). 2. [着手优化] 1)[优化思路] 第一条是 做client调用 service层的数据缓存 第二条就是 优化sql本身. 这里着重讲一下