最近在一个项目中采用JXL做excel导出的功能,但是项目上线后时不时的出现服务器CPU使用率达到99%的问题。查来查去发现问题尽然出在JXL导出excel上。后来通过Google搜索发现JXL会强制调用System.gc()方法。要知道在J2EE应用服务器中,是极力反对这种应用调度GC的做法的,因为System.gc()会极度影响系统性能和稳定性。但是JXL为了挽回这种强制调用,它提供 了setGCDisable()方法来控制是否调用 System.gc().
下面我们通过一个例子并结合GC日志来说明这个问题。
测试环境(windows xp + jdk1.6 + jxl-2.6.6.jar)
测试过程如下
以下代码的开头都注释了执行时所需要设置的虚拟机启动参数,这些参数对实验结果有直接影响,请调试代码的时候不要忽略掉. 第一步:
package org.felix.jxl;/** * * @author felix * VM args:-Xms20m -Xmx20m - Xmn10m -verbose:gc -XX:+PrintGCDetails */public class TestJxlGC1 { private static final int _1MB = 1024*1024; public static void main(String[] args) throws Exception{ byte[] allocation1 = new byte [1*_1MB]; }}
运行并输出GC日志
Heap
def new generation total 9216K, used 1531K [0x305d0000, 0x30fd0000, 0x30fd0000)
eden space 8192K, 18% used [0x305d0000, 0x3074ef10, 0x30dd0000)
from space 1024K, 0% used [0x30dd0000, 0x30dd0000, 0x30ed0000)
to space 1024K, 0% used [0x30ed0000, 0x30ed0000, 0x30fd0000)
tenured generation total 10240K, used 0K [0x30fd0000, 0x319d0000, 0x319d0000)
the space 10240K, 0% used [0x30fd0000, 0x30fd0000, 0x30fd0200, 0x319d0000)
compacting perm gen total 12288K, used 373K [0x319d0000, 0x325d0000, 0x359d0000)
the space 12288K, 3% used [0x319d0000, 0x31a2d680, 0x31a2d800, 0x325d0000)
ro space 10240K, 54% used [0x359d0000, 0x35f4e4a8, 0x35f4e600, 0x363d0000)
rw space 12288K, 55% used [0x363d0000, 0x36a722a0, 0x36a72400, 0x36fd0000)
看红色部分,我们会发现1MB的 allocation1 对象被顺利的分配到Eden中。
第二步: package org.felix.jxl;import java.io.File;import jxl.Workbook;import jxl.WorkbookSettings;/** * * @author felix * VM args:-Xms20m -Xmx20m - Xmn10m -verbose:gc -XX:+PrintGCDetails */public class TestJxlGC2 { private static final int _1MB = 1024*1024; public static void main(String[] args) throws Exception{ byte[] allocation1 = new byte [1*_1MB]; TestJxlGC2.readExcelFile("D:/test.xls" ); } public static void readExcelFile(String excelFileName) throws Exception{ File excelFile = new File(excelFileName); /*自动分配new byte[5242880]*/ WorkbookSettings workbookSettings = new WorkbookSettings(); //workbookSettings.setGCDisabled(true); Workbook workbook = Workbook. getWorkbook(excelFile, workbookSettings); /*close的同时触发System.gc();*/ workbook.close(); }}
在 byte [] allocation1 = new byte [1* _1MB ];后面加入一行利用JXL读取test.xls的代码
运行并输出日志如下
[Full GC (System) [Tenured: 0K->6311K(10240K), 0.0199411 secs] 7111K->6311K(19456K), [Perm : 519K->519K(12288K)], 0.0200235 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]
[Full GC (System) [Tenured: 6311K->6413K(10240K), 0.0138054 secs] 7257K->6413K(19456K), [Perm : 698K->698K(12288K)], 0.0138708 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
Heap
def new generation total 9216K, used 163K [0x305d0000, 0x30fd0000, 0x30fd0000)
eden space 8192K, 2% used [0x305d0000, 0x305f8fd0, 0x30dd0000)
from space 1024K, 0% used [0x30dd0000, 0x30dd0000, 0x30ed0000)
to space 1024K, 0% used [0x30ed0000, 0x30ed0000, 0x30fd0000)
tenured generation total 10240K, used 6413K [0x30fd0000, 0x319d0000, 0x319d0000)
the space 10240K, 62% used [0x30fd0000, 0x31613550, 0x31613600, 0x319d0000)
compacting perm gen total 12288K, used 698K [0x319d0000, 0x325d0000, 0x359d0000)
the space 12288K, 5% used [0x319d0000, 0x31a7e828, 0x31a7ea00, 0x325d0000)
ro space 10240K, 54% used [0x359d0000, 0x35f4e4a8, 0x35f4e600, 0x363d0000)
rw space 12288K, 55% used [0x363d0000, 0x36a722a0, 0x36a72400, 0x36fd0000)
看红色部分,系统发生一次GC操作然后重新分配堆空间。1MB的 allocation1 对象被分配到老年代中。新生代使用率仅为2%。另外在 new WorkbookSettings()的同时也会生成大概5MB的大对象,GC后也被分配到老年代里。
第三步 package org.felix.jxl;import java.io.File;import jxl.Workbook;import jxl.WorkbookSettings;/** * * @author felix * VM args:-Xms20m -Xmx20m - Xmn10m -verbose:gc -XX:+PrintGCDetails */public class TestJxlGC2 { private static final int _1MB = 1024*1024; public static void main(String[] args) throws Exception{ byte[] allocation1 = new byte [1*_1MB]; TestJxlGC2. readExcelFile("D:/test.xls"); } public static void readExcelFile(String excelFileName) throws Exception{ File excelFile = new File(excelFileName); /*自动分配new byte[5242880]*/ WorkbookSettings workbookSettings = new WorkbookSettings(); workbookSettings.setGCDisabled(true); Workbook workbook = Workbook. getWorkbook(excelFile, workbookSettings); /*close的同时触发System.gc();*/ workbook.close(); }}
加入 workbookSettings .setGCDisabled( true )后(红色部分),运行并输出GC日志
Heap
def new generation total 9216K, used 7945K [0x305d0000, 0x30fd0000, 0x30fd0000)
eden space 8192K, 96% used [0x305d0000, 0x30d92590, 0x30dd0000)
from space 1024K, 0% used [0x30dd0000, 0x30dd0000, 0x30ed0000)
to space 1024K, 0% used [0x30ed0000, 0x30ed0000, 0x30fd0000)
tenured generation total 10240K, used 0K [0x30fd0000, 0x319d0000, 0x319d0000)
the space 10240K, 0% used [0x30fd0000, 0x30fd0000, 0x30fd0200, 0x319d0000)
compacting perm gen total 12288K, used 698K [0x319d0000, 0x325d0000, 0x359d0000)
the space 12288K, 5% used [0x319d0000, 0x31a7e850, 0x31a7ea00, 0x325d0000)
ro space 10240K, 54% used [0x359d0000, 0x35f4e4a8, 0x35f4e600, 0x363d0000)
rw space 12288K, 55% used [0x363d0000, 0x36a722a0, 0x36a72400, 0x36fd0000)
显然没有发生GC,对象都被分配到新生代中。
最后查看一下JXL源码来验证我们的猜想。(大家可以从直接下载源码或者下载jxl.jar包然后反编译)
查看jxl.Workbook的源码
package jxl;.... public static Workbook getWorkbook(java.io.File file, WorkbookSettings ws) throws IOException, BiffException { FileInputStream fis = new FileInputStream(file); jxl.read.biff.File dataFile = null; try { dataFile = new jxl.read.biff.File(fis, ws); } catch (IOException e) { fis.close(); throw e; } catch (BiffException e) { fis.close(); throw e; } fis.close(); Workbook workbook = new WorkbookParser(dataFile, ws); workbook.parse(); return workbook; } .....}
查看 jxl. WorkbookParser的close()方法实现源码
public class WorkbookParser extends Workbook implements ExternalSheet, WorkbookMethods{....public void close() { if (this.lastSheet != null) { this.lastSheet.clear(); } this.excelFile.clear(); if (!(this.settings.getGCDisabled())) { System.gc(); } }....}
在close()中有System.gc();验证了我们的猜想。------------------------------------------------全文完-------------------------------------------