技术开发 频道

一次性能调优实战记录

  2.5使用JMC寻找内存泄露

  resin中没有显示出有内存溢出的日志,但是出现自动重启的原因应该是resin检测到内存使用达到一定限度的自我保护机制,而TPS的提高只能归功于JRocket出色的性能了,在接近堆内存最大值的情况下频繁GC依然保持系统的高速运转,确实是厉害。但是我们的程序还是有内存泄露的问题,要彻底解决才行。

  Jrocket安装好后会附带JMC,它是我见过的最好的内存监控工具,比jvisualvm以及JProfile都要好,而且BEA被Oracle收购后JMC的功能似乎已经没有使用限制了,而且许可也公开了出来,我这里是3.0版。

  使用JMC进行内存实例监控如上图。这是系统刚跑不久的实例情况,随着系统跑的越来越久前面几项都会不停的涨,GC掉的实例数非常少,也是内存泄露的原因所在,而LogObjectBean经过优化后偶尔会超过1W,大多数时候都保持在6100,不是内存泄露的原因。

  首先最前面的char[],byte[],String是jdk中的基本类,其中char和String实例个数是涨的最快的也是最多的,resin重启前char占了将近300M的内存空间,而且基本上实例个数差不多,涨幅也基本一致,也就是说char的增长大都由String泄露引起,虽然char占到了内存使用的40%,但是String才是char使用的根本原因,这个时候追踪String的使用情况,JMC可以轻易的监控一个对象被别的类引用的情况,以及被方法调用的情况。

  监控String的使用:

  从上图看出,开发人员自己写的一个BeanUtil的CopyBeanToBean方法生成了大量的String,达到了200多W个,检查这个方法,该方法是利用反射遍历SubMessage类里所有属性的get 方法,再invoke 遍历LogObjectBean的所有set方法给他赋值,生成新的日志对象,而SubMessage的属性有20个左右,每次都要执行subString方法截取方法名,加起来每次调用要生成将近40个String,每个String就是一个char[],执行该方法非常的消耗,而bean的拷贝已经有非常多成熟的工具,因此直接替换为apache commons-bean的PropertyUtils.copyProperties(logObj,subMessage);

  替换后的效果:

  生成的String和char[]明显少了,然而,经过长时间的测试,内存还是有泄露现象,并没有解决根本问题。

  这时候注意到系统中最常用的SubMessage类,该类是对请求报文和结果报文的封装,如果该类没有被释放,自然会导致其内部大量的string和其他相关对象都不会被GC掉。

  彻底检查代码中SubMessage的使用,仔细检查过几遍后还是没有发现SubMessage有没释放掉的地方,只改掉一个多余的SubMessage的clone后再测试,问题依旧。

  这样,最不大可能不释放资源的类MessageDispatchThread,也就是业务逻辑主线程类,成了唯一的可能。

  2.6问题锁定线程池

  照常理说,一个线程跑完后资源自然会释放,如果使用线程池的话,线程回到池中时也会释放掉之前使用的所有资源,因为他的run方法已经跑完了,而且我们使用的线程池是JDK5.0的并发包的前身也就是Doug Lea教授的并发包jdk1.4编译的版本,有着广泛的应用,应该不会有这么明显的线程执行完毕还资源不释放的bug。

  我在MessageDispatchThread的finally最后打印出“第N条线程执行完毕“的日志,日志里显示确实所有的线程都执行完毕了,再仔细检查线程池使用的代码,似乎也没有什么特别的,试着更改setKeepAlive方法,更改活动线程的存活时间似乎也没有用……

  然而将线程池的执行线程的方法去掉,直接让线程start,所有的问题都解决了,程序非常良好的运行,完全没有内存泄露情况出现,String和char[]也很好的被GC回收了。

  系统终于稳定了下来,但是不使用线程池还是会增加系统的开销,降低性能,因此还是要找出根本原因,这时候想到以前学习concurrent并发包的线程池的时候记得一句话:他的线程池可以执行实现了Runnable接口的线程,以前看他的源代码,入参是Runnable接口。确实,目前系统的线程池的使用与我之前的用法唯一不同就是MessageDispatchThread是继承自Thread实现的线程,而我以前写过的都是implements Runnable。虽然说继承Thread和实现Runnable得到的线程只是Thread提供了更多的功能,按理说运行机制应该没什么不同,但是我将MessageDispatchThread改为implements Runnable后,问题居然就解决了,也就是说继承Thread的线程,在交给jdk1.4并发包的线程池执行完毕后并没有被释放资源,而且也没被再利用,而是白白占着内存,导致内存泄露。导致这样的具体原因可以看下面的讨论http://www.javaeye.com/topic/263928?page=1。简单的说就是JDK1.5之前的Thread初始话的时候就会将自己添加到thread group中,在执行完start后再释放自己的资源,如果是执行他的run方法,那么就不会从thread group中拿掉,导致内存泄露,而Doug Lea的并发包里的线程池就是执行的线程的run方法。也难怪我本机的JDK1.6不会出现泄露。

  3.总结

  从JMC的第一张监控图上其实就可以看出MessageDispatchThread可能会有问题,但是一个线程在一个成熟的线程池管理下会出现泄露情况确实有些出乎意料,虽然走了些弯路,但是还是优化了其他相关模块的代码。

  最后调优的效果是在单台普通服务器上(或者说配置好一点的电脑)LR的100并发下TPS从60波动提高到了90以上稳定,300并发仍然可以290的TPS,500并发最高也能到450的TPS,极大的提高了系统性能。

0
相关文章