记一次性能调优经历

记一次性能调优经历

最近项目需要将数据库表的数据生成报文，报文以XML文件形式保存。由于这些数据是全国38个省市数千个指标的数据，因此，数据量并不小。平均每期的数据大概有25万。同时，根据业务需求的要求，需要将每期的数据保存到同一个报文里。

    我使用了dom4j库来实现这些功能需求。部分代码如下：

在如上代码中，while循环的是从数据库查询出来的25万条数据。在每一次循环里，首先生成RW节点，然后在RW节点下分别添加ACOut节点、ACIN节点、VV节点及VV2节点，再把对应的数据库数据保存到对应的节点。其中tempContent保存的当前循环内的数据，并用竖线“|”分隔。setSignElement()方法保存了每个循环内的tempContent内容，即随着循环次数的逐渐增加，signElement的值就越来越大。

如上的代码执行后效果并不理想。报文生成结束后使用了将近22分钟。日志如下所示：

 
       通过查看GC日志，发现代码在执行过程中，进行了很多次的Full GC。GC日志如一所示：
 

       后来我使用HPjmeter.jar来查看代码执行过程产生的GC日志，发现垃圾回收时间占用整个代码执行时间的7.571%，Full GC时间占用了1.058%，更严重的是，Full GC占用整个GC时间高达13.97%。HPjmeter.jar分析结果图如下所示：

根据如上的分析结果，大致可以得出结论：由于Full GC的次数太多导致需要花费大量生成报文。

    接下来，我使用visualvm工具来查看在报文生成过程当中，JAVA内存的动态使用情况。根据观察的结果，发现年老代内存有大量内存分配并迅速被回收，而此时，年轻代内存却没有明显的分配过程。根据内存的分配策略，可以断定，这是由于代码里生成了大量的大对象，而大对象会直接进入老年代导致这样的结果。知道了原因后，我将代码如下修改（即修改了生成大数据对象的代码），见红色框框部分：

        修改完后再次执行代码，日志如下：

这次执行过程所使用时间只用了29秒，提高了45倍多。真是让我无比惊讶啊。

可见，代码的编写质量对应用的性能影响是相当的巨大啊。

        最后，再把这两次执行结果贴出来对比一下。