记一次典型的因应用使用内存不合理而频发的性能问题

    做了中间件的技术支持，遇到的很多应用系统性能相关的问题；在前不久遇到的一次使集成商比较头疼的系统性能问题，经多方努力问题终于解决了，因感觉很具典型性，所以现在拿出来做个分享。

先把其环境和问题症状做个简要的描述：

    os:windows2003 32位机 物理内存：8G 4u CPU

    JDK：1.6

    web application server:apusic 5.1 sp2

    db:oracle

    应用系统：某市市民卡项目，以C#为客户端,java作服务端，应用了SSH等框架;

现场问题症状：

系统不定期宕机，最长一周，短则一上午；宕机时的JVM堆栈及进程信息见附件。显而易见宕机时有很多BLOCK进程，以及相关的资源使用情况，初步怀疑会有两种情况导致了这么多的死锁进程：

1.发生在数据库层面，数据库出现了死锁导致进程死锁;

2.因系统资源消耗殆尽，诸如内存、线程池等；

连线现场，发现宕机时系统CPU正常，内存使用99%；宕机时数据库响应正常，apusic的线程池都正常，查看了APUSIC系统日志，发现曾经有OOM异常出现过，所以基本可以排除上面第一种情况，应该是有内存溢出。开始怀疑JVM内存分配得不够大，于是查看jvm参数：-Xms1024m -Xmx1024m  -XX:MaxPermSize=128m ，现场操作系统为32位机，JVM的最大内存也应该是1.5-2G左右，所以将-Xmx1024m  稍稍调大了些，但应该不治本；

既然涉及到内存，就得分析下GC回收的情况。

      接下去几天里，让现场加了在JVM参数加了GC日志输出的参数；

      可就在刚启服务的次日，还不到一个上午时间里，系统又宕机了。系统产生了GC日志文件,用HPjmeter作为日志的分析工具，percentage of time in GC ,percentage of time in FULL GC  都超过了5%，如附件图：

曲线极其不平滑，内存瞬间暴涨从200M—1.2G只用了1分钟，然后10分钟左右以后，full gc回收了一部分内存，大概200m左右，之后在接近一个小时的时间里，回收的内存越来越少，内存占用不断上涨，后来full gc也回收不了多少内存了在最后一个小时的时间里，系统应该基本是不可用的,一直在做full gc。现场真实的应用是客户端并发上限不超过50个，不存在瞬间高并发发生，也无法用压力测试使问题重现。结合GC回收的图片分析，猜测应该是有什么操作内存申请过大，导致一下子撑死了整个中间件；
      到此为止问题基本有眉目了，接下去是要帮助伙伴定位其应用系统的问题所在；

      几种方式：
      1.通过jprofiler监控系统运行，等内存高位时分析相关的CLASS来进行定位；
      2.添加JVM参数-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=C:\x.hprof，让系统在产生OOM时生成heap dump文件供分析。当然这种方式往往是可遇不可求。

      3.产生GC LOG方式，添加JVM参数 例如：-Xms30m -Xmx30m -Xloggc:c:\gc.log -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC；将会看到gc.log ；可用HPjmeter作为日志的分析工具；
      4.根据GC曲线图，计算大致时间重启服务前的7200S(2小时左右)前后，审计业务日志，由业务操作查业务代码。
最后伙伴还是在其中业务代码里找出了问题，查询报表时候，有个别报表未加过滤，导致一次性返回了大批量数据，至内存飑升！修改后运行平稳，内存稳定在200M-300M！
      解决过程虽然问题根源比较清晰，但伙伴还是提出了不少质疑，比如他们拿了WEBLOGIC做对比，同样的应用做相同操作，WEBLOGIC内存能马上回收，而在APUSIC上未能及时回收，但执行下GC回收内存还是能下来，其实GC的回收是JAVA虚拟机做的事情。此疑问差点使解决过程走弯路。