java trace优化_Tomcat/JVM常见问题排除及性能优化

最近一个SSH2项目升级了框架，部署后发现执行一段时间就会无法访问(Tomcat及其下其它Web可以正常访问)。

MyEclipse中进行“压力测试”时报错：

Exception in thread "com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0"

java.lang.OutOfMemoryError: PermGen space

之后的现象跟测试机上部署的一样，初步判断就是这个原因。结合这个Exception，究其根本的原因，可能是框架第三方Jar包，class文件占有量变大；另一方面，有些模块请求历史数据时随着时间累积会返回较多的JSON数据，存放在Action的成员String变量中，通过Struts框架返回给前端，而前面说的这些，正好是存放在永久代(PermGen)里的。还有一个是测试部署的时候出现：

Exception loading sessions from persistent storage

java.io.WriteAbortedException: writing aborted; java.io.NotSerializableException: ...

当时的解决方法是相应的Bean继承Serializable接口，同时把work/Catalina/localhost/的项目文件夹给删了。总所周知，这个是jsp编译后的文件存放的目录，而PermGen OutOfMemoryError也容易发生在web服务器对JSP进行pre compile的时候。综上所述，那么就先看看PermGen的分配使用情况吧。

jstat内存监控(http://docs.oracle.com/javase/1.5.0/docs/tooldocs/share/jstat.html)：

例如查看PermGen：jstat -gcpermcapacity pid

Windows上查看进程：tasklist | findstr javaw.exe

调用jstat出现pid not found：

在服务器上对部署的项目查看PermGen时，jstat出现pid not found的问题。jstat的基本原理是会生成一个hsperfdata_username的目录(里面存有pid文件，记录进程的信息)，默认是在java.io.tmpdir目录下(linux上默认是/tmp下)，但是我执行jstat的时候这个目录下没有pid文件。而网上资料说jdk1.6.0.23/24版本兼容性问题，而我正好使用了0.23，踩坑了。

While it's true that 6u23/24 introduce this issue, it's not a bug in jps. Rather a change in behavior of the VM itself. On GNU/Linux Jps and the likes seem to only look at /tmp but not necessarily your CATALINA_TMPDIR. If set or not, try to export CATALINA_TMPDIR=/tmp which translates to "-Djava.io.tmpdir=/tmp" and after restarting the Tomcat process you should see Tomcat's data as "/tmp/hsperfdata_/" and Jps will most likely work again as well.

解决办法是修改VM的配置文件，在tomcat/bin/catalina.sh中，找到CATALINA_TMPDIR，改为CATALINA_TMPDIR=/tmp，在重启tomcat就可以了。

继续在本地进行“压力测试”，结果出现问题时，PermGen的PGC/PC已被消耗光，YGC/FGC次数不断攀升，同时FGCT/GCT也持续增加，很明显，JVM尝试不断进行GC试图释放PermGen，但是似乎力不从心，导致程序一直被阻塞。那么，改PermGen参数咯。

更改Tomcat的JVM PermGen参数：

因为是本地MyEclipse以debug方式启动tomcat的，在按照网上所说的方法在%CATALINA_HOME%/bin/catalina.bat中Execute The Requested Command后增加set JAVA_OPTS=%JAVA_OPTS%-server -XX:PermSize=128m -XX:MaxPermSize=256m后，debug启动无效，其实这个时候tomcat是被调用tomcat7.exe启动，所以无法使得catalina.bat中的参数生效。

正确的方式是在MyEclipse -> Preferences -> Servers -> Tomcat -> Tomcat x.x -> JDK的Optional Java VM arguments中增加一下参数，再重启即可。

-XX:PermSize=128M

-XX:MaxPermSize=256M

本来PermSize设置为64M，Web项目启动执行过程中，如果不够用时它会按照某种方式增量分配，比如FGC一下，PGC/PC增到140M，接下来还会适时地FGC，又减到135M、130M之类。这样多累啊，不如初始分配时多一点，分配128M咯，然后再测试，执行时观察过程中并没有发生FGC。

就这样？其实我也想从代码上进行优化，以提高内存利用率，排除可能存在的内存泄露之类的问题。但是老代码太多(问题是升级过程中，大部分代码并未动过，只是新增了部分小模块)，很怀疑是SSH框架(Spring3.2.1、Struts2.3.4、Hibernate3.3.2)的问题。这方面，大家有经验的请多指教。平常关注业务，都没时间去挖掘技术细节了。。。

jstack(Java Stack Trace)查看Java堆栈信息：

‍‍某天，也就是今天，又出现项目Hung现象，看来问题还没有彻底排除，痛定思痛，于是乎用jstack查看了堆栈信息：‍

使用方法：jstack pid

"http-bio-8080-exec-24" daemon prio=10 tid=0x00007ff028005000 nid=0x99c in Object.wait() [0x00007ff0f9c56000]

java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)

at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)

- locked <0x000000041752e940> (a com.mchange.v2.resourcepool.BasicResourcePool)

at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)

at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)

at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)

百度了下Object.wait()的大致含义，结合C3p0连接池的错误信息，猜测可能是数据库连接池阻塞导致了项目无法响应。回顾了下，自己确实调整过com.mchange.v2.c3p0.ComboPooledDataSource的配置。于是调整了相应参数再部署，初步“压力”测试下来一切正常。如果还有问题，那就继续写博客咯。

c3p0连接池无法释放：

果然，意料之中的事情还是发生了，依旧出现了上述问题，请求无响应。直接用jstack查看日志，跟上一段的类似：

"http-bio-8080-exec-13" daemon prio=10 tid=0x00007f4d4c1a2800 nid=0x5cd7 in Object.wait() [0x00007f4e25ee2000]

java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)

at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)

- locked <0x00000004178cb420> (a com.mchange.v2.resourcepool.BasicResourcePool)

at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)

at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)

at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)

可能连接池又爆了……写了端代码实时查看连接池使用的情况：

try {

DataSource ds = dataSource;

if (ds instanceof PooledDataSource) {

PooledDataSource pds = (PooledDataSource) ds;

debugMap.put("NumBusyConnections", pds.getNumBusyConnections());

debugMap.put("NumBusyConnectionsAllUsers", pds.getNumBusyConnectionsAllUsers());

debugMap.put("NumBusyConnectionsDefaultUser", pds.getNumBusyConnectionsDefaultUser());

debugMap.put("NumConnections", pds.getNumConnections());

debugMap.put("NumConnectionsAllUsers", pds.getNumConnectionsAllUsers());

debugMap.put("NumConnectionsDefaultUser", pds.getNumConnectionsDefaultUser());

debugMap.put("NumIdleConnections", pds.getNumIdleConnections());

debugMap.put("NumIdleConnectionsAllUsers", pds.getNumIdleConnectionsAllUsers());

debugMap.put("NumIdleConnectionsDefaultUser", pds.getNumIdleConnectionsDefaultUser());

} else

System.err.println("Not a c3p0 PooledDataSource!");

} catch (SQLException e1) {

e1.printStackTrace();

}

果然，请求一次，当前使用的连接多一次，很快100个容量就被用完。于是排查连接无法释放的原因，因为使用的SSH，数据库连接池都在配置文件中，而dataSource最终是由Hibernate接管的，看了下最有可能出问题的便是事务，事务配置不合理导致hibernate没有正常关闭连接。在aop的poincut中，我的expression是execution(* com.xxx.manager.service.*.*(..))，但不仅是service层，dao层也有相应的连接请求，于是，一概而论，把表达式改成了execution(* com.xxx.manager.*.*.*(..))，测试后，果然好了。

1、execution(): 表达式主体。

2、第一个*号：表示返回类型，*号表示所有的类型。

3、包名：表示需要拦截的包名，后面的两个句点表示当前包和当前包的所有子包，com.sample.service.impl包、子孙包下所有类的方法。

4、第二个*号：表示类名，*号表示所有的类。

5、*(..):最后这个星号表示方法名，*号表示所有的方法，后面括弧里面表示方法的参数，两个句点表示任何参数