2007-06-15
IBM WebSphere Application Server 诊断和调优(二)
关键字: WebSphere 内存泄漏 Java虚拟机
上篇： http://www.javaeye.com/topic/74737
续写这篇文章，已经过去一个半月了。直到现在，系统一直运行平稳。
先说说我接手这项工作的经历吧：该项目大部分是06年10月就部署在客户那边了，到07年3月份，WAS宕机问题实在无法忍受，我才加入进来，前半年有另外一位同事断断续续处理，但对问题一直都无可奈何，而且项目负责人也没有引起足够的重视。可想而知，最后付出的代价是非常惨重的。在这近半年的时间内，服务器宕机63次。每次宕机时，WAS的JVM会dump出一个heapdump.phd文件(heap快照)，然后JVM就死掉了，当然，此时WAS也停止了响应。一般我们的做法是重启，最后是干脆AIX每天晚上定时重启。有时候一天还死多次。大家见附件的截图（all-GC.png）。这是我接手后，用IBM的分析工具得到的截图。对截图的分析，留给后面对应的部分吧。
服务器不稳定、宕机问题，拖延到最后，客户愤怒了，公司高层也害怕了，部门还专门成立了八人攻关组。当然了，我当时的压力也非常大，因为我是技术负责人，也就是实实在在干活、想主意的。
服务器诊断那段时间，从前到后，我们也是沿着一条线走下来，虽然最后发现很多路都走不通。现在就按这个思路，也就是时间先后一步步叙述吧。我想，大家如果也碰到类似应用服务器诊断，应该思路差不多。
术语说明：
IBM Websphere Application Server：WAS，WebSphere本身是一个平台，产品家族
OutOfMemoryError：OOM，内存泄漏，内存溢出
Gabage Collection：GC，自动垃圾回收
Content Management System：CMS，就是给新闻类门户网站编辑们用的系统
我们诊断大体上经历了以下几个阶段：
1、按Job调度线程池引起内存泄漏诊断：因为很多次OOM是发生在某个特定时候，譬如14：30、22：40左右。
2、按应用程序引起内存泄漏诊断：用JProfiler等工具探测：因为总是发生OOM。
3、分离WAS怀疑有OOM的应用：因为每个WAS应用太多，20来个，混一起没法定位。
4、用IBM官方heap、GC分析工具。以及和IBM技术支持联系。WAS、AIX参数优化。
5、隔离出WAS超级恶魔程序：一个CMS产品。
6、WAS、AIX参数优化、设置。
我们走到第5步时，才出现效果。计算一下，那时已经过去一个月了。服务器宕机、系统不稳定，在这个验收的时候，客户已经忍无可忍，以致后来的每一次行动都得胆战心惊得去做。
一、按Job调度线程池导致内存泄漏诊断
因为从我们WAS的日志(默认是native_stderr.log)来看，最近半年的宕机时间都有一个明显时间规律。见附件截图Job1-1.png。
我想，做过Java服务器性能调优的朋友，都知道在Web容器里面启线程池是个不太好的做法，因为Web容器本身有一个线程池，譬如Servlet线程池（Tomcat默认起25个），而自启的线程池很容易导致Servlet线程管理混乱，最终导致GC问题。我们的现象似乎和那很符合。如果我们沿着这个思路做下去，具体怎样实施呢？
我们的WAS上部署了20个左右的Web应用，譬如Lucene全文检索、B2B行业数据同步等，都是通过Quartz的Job调度做的，当然还有很多其它调度。当时，由我负责，通知相关负责人，将定时调度暂时去掉。观察了几天，后来发现问题依然存在，不过时间有点随机了。
不过，最后还是发现OOM不是由Job调度引起的。
也就是说，我们这个方案是失败的。而且，我们的很多想法都是臆测的，没有可靠的根据，也没有方向，再加上我是第一次处理这种问题，这导致后来查找问题的艰难。但是，仔细想想，我们又能拿什么做依据呢？出现OOM错误，我想大多数人想到的，除了JVM参数设置，就是内存泄漏。其实，OOM发生有很多种情况，在IBM、Sun、BEA等不同虚拟机上，因为GC机制不一样，所以原因一般都不同，容易定位难度也不一样。下文会谈到。
于是，我们干脆釜底抽薪分析问题吧：用JProfiler检测。
二、按应用程序导致内存泄漏诊断，JProfiler检测
如果遇到OOM问题，我想大家都会想到内存检测工具，现在最可靠的还是下面三种分析工具：Borland 的Optimizeit Suite，Quest的JProbe，ej-technologies的JProfiler。但面临三个问题：
1、三个都是商业产品，公司暂时没有买，必须自己下载，而且要找序列号。
2、工具必须支持AIX5.3＋JDK1.42＋WAS6.0，不是Windows平台。
3、工具必须在客户真实环境下部署，对客户的业务不能有冲击，也就是说部署测试工具前，必须做个大量测试，对工具非常熟练，遇到意外可以立即恢复现场。
Note:项目上线后，而不是测试或试运行阶段遇到此类问题，非常考验人；另外一个，就是性能和可伸缩性问题，很可能把整个项目给毁了。
当我决定要这么做后，就立即动手查阅这些工具的官方文档，用emule下载，最终都下载到了。试用后，最终选择了JProfiler4.03，比起其它工具，它界面美观、清晰、功能强大、集成度高(Heap,Memory,CPU,Thread都统一了)。另外，JProbe没有AIX版本，这也是放弃它的一个原因。
JVM的Profiler原理，都是通过JVM内置的的标准C语言Profiler 接口收集数据，然后通过Profiler工具的客户端展现。也就是说各厂商的Profiler工具，都有两个部分，一个部分是Profiler Agent，和JVM绑定，负责收集JVM内部数据，譬如方法调用次数、耗费时间等；另外一个部分就是Profiler front-end。通过Profiler工具的自定义local或remote协议传输到front-end，其实，我们最常用的JavaIDE的debug功能就是在此基础上的（JPDA）。（JProfiler的截图http://www.ej-technologies.com/products/jprofiler/screenshots.html ）。
下面是Sun官方文档：
JDK1.42及以前是JVM PI：http://java.sun.com/j2se/1.4.2/docs/guide/jvmpi/jvmpi.html
JDK1.5是JVM TI：http://java.sun.com/j2se/1.5.0/docs/guide/jvmti/jvmti.html
具体到JProfiler的配置上，专门针对JDK1.4和1.5的JVM配置差别很大。
我用的JProfiler是4.31版本，透露给大家一个万能序列号吧(这东西不太好找)，对各版本应该都支持。深入了解Java，这类工具是不可少的：
Name: License for You
Lincese Code: A-G667#42616F-10kg1r134fq9m#2217
为了保证真实环境的检测成功，我做了大量的试验，譬如：
1、Windows系列的本地、远程测试。
2、AIX的远程测试。
3、Tomcat5.0、WebLogic8.14、WebSphere6.02，以及上述两种方式的组合测试，排列组合，场景不下10个。
当时也参阅了大量JVM文档，JProfiler官方几百页英文文档，辅助的JProbe对照。而且也制造过内存泄漏造成的OOM场景。
当然，要是在几个月前，在客户那边部署的测试环境时，就进行测试该多好啊。
在公司内部，我用JProfiler测试了我们当时部署的几个应用，没有发现内存泄漏，所以，我们最怀疑的是就是CMS系统。因为出问题的那个WAS上它占去了90％的负荷（我们有多台AIX、WAS服务器）。该CMS超级庞大，感觉著名的赛迪网就用它，当时该CMS厂商给我们部署都花了快一个月。所以再重新部署一套测试环境也挺困难。另外，CMS提供商不给lisence。现在测试，客户早就对我们恼火了，当然不怎么配合，这对我们工作的开展就有很大的挑战。
在大致可以确定万无一失的情况下，我们最终决定在客户的真实环境下测试。也就是让JProfiler的agent端直接在WAS的JVM里面启动（北京IDC），然后远程（大连）监控。
本来该模式在另外几个应用的测试都通过了（因为北京IDC那边好几台AIX服务器）。但一部署上，客户的一些编辑用CMS时就感觉超级慢，尽管我们用了JProfiler的最小负载模式。半个小时后，客户实在无法忍受，打电话过来，又把我们部长和经理训了一顿，还要写书面报告。我们被迫马山中止测试，恢复现场。
虽然JProfiler也支持客户那边的环境，但还是有bug，至少负载一高就有严重的性能问题，几乎导致系统挂起，这是我当时没有料到的。JProfiler一启动，WAS的启动时间就由原来的3分钟降到10分钟，而且系统响应明显变慢，我们具体的环境如下（排列组合恐怕不下20种）：
1、AIX5.3，Power PC64位（不是32位）
2、WebSphere6.0
3、IBM JVM1.42
4、Remote 模式
我后来仔细读了一下JProfiler的changeLog，发现对上面的环境支持不够也很正常，因为官方在最近的4.3.x版本下陆续有对IBM JVM和Websphere6.0的features和bug fix：http://www.ej-technologies.com/download/jprofiler/changelog.html
进行到这一步，我忽然觉得无计可施了
，此时已经过了三周。
上面的策略，我认为是很正统的处理方法。谁怪我们当初项目上线时没有进行充分的测试呢？其实，这类测试没做也正常，OOM这类问题谁都无法预测。
到这个时候，我想肯定有人会问我？你知道导致JVM的OOM有几种情况吗？在当时，我想到了以下五种：
1、JVM的heap最小、最大值没有设，或不合理。
2、JVM的maxPermSize没有设置（这个IBM的JVM没有，一设置JVM就起不来）。
对于Sun和BEA的JVM，以上两种参数设置，可以排除90％以上的非程序内存溢出导致的OOM。
3、程序内存泄漏
4、有的JVM，当在80%的CPU时间内，不能GC出2%的heap时，也发生OOM（IBM的JVM就是，但我没有验证）
5、JVM本身内存泄漏（JVM有bug不是不可能）
现在的难题是，如果是那个可怕的CMS程序本身有内存溢出，在产品环境下，我们怎么去验证？我们自己开发的10来个web应用，测试并不是很难，在公司测试都可以。但是，我现在最想解决的，就是CMS测试的问题。而且，在我们那种环境下，该CMS产品供应商并没有透露成功案例。
其实，最后发现，并不是内存泄漏造成的，因为我们的heap走势都很平稳。纳闷的是，有1000M的heap，每次在heap只被占用400来M时就发生OOM，没有任何预兆。大家猜猜，会是什么原因
？这个问题我到后面相关章节再说吧。
既然我们所有的矛头都指向那个可怕的CMS系统，现在就是考虑隔离的问题。如果我们验证这个问题是CMS造成的，那么大部分责任就应该由CMS厂商承担
。
既然CMS我们不敢移（费劲，而且客户在正式用），那我就移我们开发的10来个web系统吧。
三、移出除CMS系统以外的所有应用
说起来容易啊，做呢？ 隔离（移动）工作由我负责，具体涉及到10来个相关负责人。
转移工作，必须处理好很多问题，就说几个印象最深的吧：
1、某些应用，如Blog和BBS，都涉及到文件、图片上传目录和产品本身的环境，如 JDBC连接池、Cache位置。
2、目标服务器本身的环境，WAS安装环境、网络等。
3、移植时的先后顺序、调度，各应用内部本身的约束关系。
4、移植后的测试。
当然，还有一个最严峻的问题，客户允许我们这么做吗？对它们目前运行的系统有多大影响？风险如何评估？
这个工作持续了一天，已经完成了80％的工作，到第二天，客户又恼火了：WAS又宕机了。
为什么？这确实是WAS的一个bug：WAS的后台随便一操作，heap就会突然上升几百M，导致JVM内存不够。不过WAS撑住的话，过半小时后就会降下来，我估计是WAS后台对用户操作状态、文件都缓存到Session里面。你们可以检查类似这样的一个文件夹：d:\IBM\WebSphere\AppServer\profiles\AppSrv01\wstemp，我不知道为什么WAS不主动去清除它，它偷偷的就上升到几个G，系统硬盘可能不久就后就会空间不足，WAS莫名迟缓、最后死掉。听过WAS6.0以前这个目录更夸张。大家见我附件的截图WAS_Console.png那个尖峰。
咋办？经理也已经不敢让我们继续铤而走险了。这个方案最终又以失败告终。
不过，最后我们还是发现问题出在CMS上。我们以前把这个问题向CMS技术支持反映，有大量依据和现象，并且把相关日志都给它们。过了两天，他们最后竟然只回了一句话“从给我的两个日志来看，没有找到任何与XXX有关的东西....”。TMD！我真的很生气
，它们的产品都折磨我们半年之久了。不过，看他们对IBM的WAS和JVM也不懂，我也就不想再说什么了。下面是我的邮件，公司机密部分都隐去了：
文中说到了IBM的两个分析工具，这也是我们后来的救星：我们就是需要这种离线分析工具，因为实时检测已经证明不现实。但我始终对该分析出来的结果抱怀疑态度，直到我去深入IBM的JVM以及和IBM的技术支持交流......
柳暗花明啊
，至少看到了一点希望，不过最后我们还是失望而返。
四、用IBM的HeapAnalyzer和GarbageCollector检测
找到这两个工具，已经是够费劲了，因为以前找的IBM HeapRoot工具，让我对这类工具很失望。而且，这两个工具，只有在IBM的Techinical Support网站能够搜索到，但很不容易，因为那两个工具，并不是象IBM的Websphere产品那样宣传，它只在IBM Techinical Support文章的某些角落里出现。要知道，Techinical Support是IBM很重要的收入来源，这类文档，他们并不会让你很轻易就拿到，比起BEA WLS的支持网站dev2dev差远了。
具体诊断细节我就不详述了。我认为，IBM的WAS或JVM出了性能和OOM问题，这两个工具是最有效的，而且是离线分析工具，比起那些实时Profiler工具，某些场合有绝对的优势：譬如我们目前的产品环境，你只能分析宕机后的日志，实时分析前面已经验证是不可行的。
从日志分析，我们最终得出结论，我们购买的CMS系统有严重的碎片（大对象）问题，而该问题是OOM的罪魁祸首，而且IBM工程师也得出了同一结论。不过，在起先我们得出这一结论一周后，我还始终不相信heap碎片会导致OOM，直到IBM工程师总是向我强调。
我想很多人也是不太相信，因为大多数人用的都是Sun的JVM，譬如Windows、Solaris上的hotspot。而且，Sun JVM出问题，如果是配置的问题，一般通过配置heap最大最小值，以及maxPermSize都可以解决。Heap碎片导致的OOM，只有BEA的JRockit和IBM JVM上发生，不过JRockit有专门文档说明，而且很容易找到（就在jdk的文档里面）。
配置heap最小最大值，我想大多数人都有经验。对于Sun的JVM来说，一般可以设置heap最大最小值一致，也是推荐的做法。因为它的GC策略默认是复制、分代算法。也就是说，它会将heap分成不同的几个区，譬如Solaris JVM中最上面有两个大小相等的区。GC时刻，将一个区的存活对象复制到另外一个对等区，垃圾对象就算遗弃了。这样在heap里面，就不存在碎片问题。另外，根据Java对象的存活期不同，将之转移到不同的区（Tenured区），存活最长的在最底部（火车算法），这也就是分代模型。具体请参考官方文档：http://java.sun.com/docs/hotspot/gc1.4.2/
对于maxPermSize（Permanent Generation），主要和那些加载到JVM里面的Java Class对象相关，它的空间不是在Java Heap里面分配。如果你当前的heap有1000M，permSize是200M，那么JVM至少占用1200M。
在这个空间内的对象的生存期和JVM是一样的，譬如JDK的核心类库，它们被System Classloader加载到JVM的Method Area（方法区）后，就不会被GC掉的，这些对象一般是Class对象，而不是普通的实例对象，也就是JVM的元数据。我们在用反射时经常用到它们。所以，对于现在象Spring、Hibernate这些框架经常通过反射创建实例，可能对maxPermSize要求就大了，缺省的64M很多时候是不够的，特别是对于应用服务器里的应用，象JSP就会产生和加载很多classes。不过，如果是它导致的OOM，一般会有类似 perm size提示。
但是，对于IBM的JVM，情况就完全不一样。它的默认GC策略并没有采取复制、分代。这个可以从GC日志分析出来。它不像Sun的JVM那样，有个单独的方法区，它的方法区就放在Java Heap里面。JVM规范里面并没有要求方法区的必须存放的位置，因为它只是一个JVM实现问题。
在IBM的JVM里面，这些对象一般分配在称为k-cluster和p-cluster里（cluster又是属于Heap），而后者一般是临时在heap里面申请。并且，这些cluster是不能GC，或是被移动重排的（Compact过程）。这就导致Java Heap里面就如同马蜂窝，但不同的蜂孔又不能合并，于是，当我们程序里面产生一个大对象，譬如2M的数组(数组必须分配在连续的内存区)时，就没有可分配空间了，于是就报告OOM。这些不能被移动的cluster就称为所谓的碎片。此时，JVM的Heap利用率可能不到50%。
当然，通过一定时期的GC日志，可以计算出cluster的合理大小（专门在Java Heap的底部），另外，还可以为这些大对象专门分配大对象区的（超过64k的对象）。
通过上面的理论介绍，我想大家一定知道了为什么IBM的JVM里面不推荐heap的最大最小值相同，因为这样碎片问题会非常严重：如果我们每次大对象申请内存时，heap都扩展5%，譬如50M，碎片问题很大程度上可以避开，程序性能也高些（寻找可用空隙和分配耗时，以及每次GC时间拉长）。
以上的具体阐述，请参考我在上文推荐的几个URL，另外再推荐三个宝贵的链接：
http://www-1.ibm.com/support/docview.wss?rs=180&context=SSEQTP&q1=fragmentation&uid=swg21176363&loc=en_US&cs=utf-8&lang=en
http://www-900.ibm.com/cn/support/viewdoc/detail?DocId=2447476A10000（IBM 技术支持告诉我的，太重要了！）
http://www-900.ibm.com/cn/support/viewdoc/detail?DocId=2847476B08000
我想大家应该会问：我怎么能够肯定我的OOM问题是heap碎片造成的呢？下面的方法可以验证。
在OOM发生时，JVM会产生一个heapdump文件。然后用GarbageCollector分析出该OOM发生时刻，JVM去申请的空间，譬如约235k。此时，你再用HeapAnalyzer去分析此时的heap快照里面的gap size大小（空隙大小）和各自的可用数目。你会发现，大于235k的空隙个数为0。这就是碎片导致OOM的证据。
另外，有人会问：我怀疑我的OOM是因为程序内存泄漏造成的，怎么去验证？
你可以用HeapAnalyzer分析发生OOM时刻的heap快照，工具会罗列出哪些对象怀疑有内存泄漏，譬如Cache对象都非常大（但你可以确定它不是内存泄漏）。另外，分析这次宕机（从这次虚拟机启动到宕机这段时间）的heap走势，如果曲线明显是向上倾斜，也就是那种典型的内存泄漏图，就有可能是内存泄漏。当然，还必须结合heap快照。
内存持续上升在JVM开始一段时间很正常，因为JVM对第一次访问到的Class 对象，譬如一个典型的Web应用，就有jdk的class、Spring或Hibernate的class对象，它们都会被缓存下来(ClassLoader原理)，一般均不会被GC。当大多数class对象缓存差不多（当然还可能有一些Singleton对象，不过不怎么占分量），JVM的Heap就平稳了，呈一水平波浪或锯齿线。
如果可以用JProfiler这类工具实时监控，就更容易确诊了。
经过一番周折，我们终于看到了一线希望了。
在一定的准备后，我们决定对WAS进行性能调优了。WAS的调优参数，可以分为两个部分：JVM级别和WAS级别：
JVM：主要是GC和Heap。
WAS：Thread Pool，JDBC DataSource。
当然要调节，你需要明白你的目标是什么，调节依据是什么，怎么计算，绝对不是凭空想象的，譬如heap最小值1024M，日志证明，该参数非常不适合我们的环境。具体细节，留给后文吧。
战战兢兢地，中午12:00，我们给产品环境下的WAS调节参数、重启，同时优化了AIX的IO相关参数。
我试着设置了一下JVM的k-cluster和p-cluster。下午15:00左右，WAS挂了，AIX也挂了。这下麻烦可大了。我们都慌了，马山客户的老总就来电话了，一阵哗哗啦啦。实在无奈，让客户那边工作人员通知机房（服务器托管处）工作人员重启AIX。我也不得不强行更改刚才的参数，立即设为另外一个值。
其实，我把那个两个cluster值确实设置太大了，我把它们设置为推荐值的5倍，譬如p-cluster是65k×110%×5。另外一个愚蠢的设置就是把最小heap设置为2048M(AIX有4G内存)。
后来我恢复到约正常的值，也就是去掉那个cluster的5，另外分配了一个30%的大对象区（如果1000M的heap，就是700M＋300M）。
就这样，系统持续正常运行了三天，以前可是一天一down。当在三天后再次宕机时，我们都没有自信了
。不得不通过AIX的cron，继续每天深夜11点的WAS定时重启。
不过，那次宕机，包括以后的几次宕机，再也没有出现OOM错误了，但系统依然不稳定。虽然我可以说OOM问题解决了，但领导和客户需要的并不是这种结果。
其实，在这个时候，我们已经发现我们系统的四大问题：
1、WAS和JVM参数：OOM问题
2、AIX的IO和Paging Spacing不足：AIX日志后来显示错误
3、AIX的WAS分区空间不够：WAS的日志膨胀一周就把那个opt分区塞满了。
4、应用程序的JDBC连接池：我们20来个应用，一个20 connections，DB2数据库有时被撑死。
也就是说，我们最初在客户那儿部署时，用的默认值根本不行。而且，部署涉及多人，人员之间出现断层。如果我们只是按OOM，无疑是走入死胡同，必须全局考虑！
但是，项目组实力薄弱，公司范围内就没有对AIX精通的。不过项目组原来有一个搞银行系统，在AIX下开发，就他熟悉些。我当时对AIX也比较陌生，你们从Linux转到AIX，你就知道它有多别扭了。命令都自定一套（也许因为是Unix元老吧），那个shell也超级别扭，而且参考书特少。不是自诩，我两年前负责一个高负载的Linux服务器管理一年多，也是玩得很转的。
就这样，他负责AIX的相关问题，我负责WAS相关的。
但是，现实环境，已经不允许我们再试验下去了。我们必须找到一条绝对可靠的对策！
这就是下文的CMS系统大迁移，服务器再次优化。
文章太长（上万字），我把剩下部分发表在回复贴里面吧。
续写这篇文章，已经过去一个半月了。直到现在，系统一直运行平稳。
先说说我接手这项工作的经历吧：该项目大部分是06年10月就部署在客户那边了，到07年3月份，WAS宕机问题实在无法忍受，我才加入进来，前半年有另外一位同事断断续续处理，但对问题一直都无可奈何，而且项目负责人也没有引起足够的重视。可想而知，最后付出的代价是非常惨重的。在这近半年的时间内，服务器宕机63次。每次宕机时，WAS的JVM会dump出一个heapdump.phd文件(heap快照)，然后JVM就死掉了，当然，此时WAS也停止了响应。一般我们的做法是重启，最后是干脆AIX每天晚上定时重启。有时候一天还死多次。大家见附件的截图（all-GC.png）。这是我接手后，用IBM的分析工具得到的截图。对截图的分析，留给后面对应的部分吧。
服务器不稳定、宕机问题，拖延到最后，客户愤怒了，公司高层也害怕了，部门还专门成立了八人攻关组。当然了，我当时的压力也非常大，因为我是技术负责人，也就是实实在在干活、想主意的。
服务器诊断那段时间，从前到后，我们也是沿着一条线走下来，虽然最后发现很多路都走不通。现在就按这个思路，也就是时间先后一步步叙述吧。我想，大家如果也碰到类似应用服务器诊断，应该思路差不多。
术语说明：
IBM Websphere Application Server：WAS，WebSphere本身是一个平台，产品家族
OutOfMemoryError：OOM，内存泄漏，内存溢出
Gabage Collection：GC，自动垃圾回收
Content Management System：CMS，就是给新闻类门户网站编辑们用的系统
我们诊断大体上经历了以下几个阶段：
1、按Job调度线程池引起内存泄漏诊断：因为很多次OOM是发生在某个特定时候，譬如14：30、22：40左右。
2、按应用程序引起内存泄漏诊断：用JProfiler等工具探测：因为总是发生OOM。
3、分离WAS怀疑有OOM的应用：因为每个WAS应用太多，20来个，混一起没法定位。
4、用IBM官方heap、GC分析工具。以及和IBM技术支持联系。WAS、AIX参数优化。
5、隔离出WAS超级恶魔程序：一个CMS产品。
6、WAS、AIX参数优化、设置。
我们走到第5步时，才出现效果。计算一下，那时已经过去一个月了。服务器宕机、系统不稳定，在这个验收的时候，客户已经忍无可忍，以致后来的每一次行动都得胆战心惊得去做。
一、按Job调度线程池导致内存泄漏诊断
因为从我们WAS的日志(默认是native_stderr.log)来看，最近半年的宕机时间都有一个明显时间规律。见附件截图Job1-1.png。
我想，做过Java服务器性能调优的朋友，都知道在Web容器里面启线程池是个不太好的做法，因为Web容器本身有一个线程池，譬如Servlet线程池（Tomcat默认起25个），而自启的线程池很容易导致Servlet线程管理混乱，最终导致GC问题。我们的现象似乎和那很符合。如果我们沿着这个思路做下去，具体怎样实施呢？
我们的WAS上部署了20个左右的Web应用，譬如Lucene全文检索、B2B行业数据同步等，都是通过Quartz的Job调度做的，当然还有很多其它调度。当时，由我负责，通知相关负责人，将定时调度暂时去掉。观察了几天，后来发现问题依然存在，不过时间有点随机了。
不过，最后还是发现OOM不是由Job调度引起的。
也就是说，我们这个方案是失败的。而且，我们的很多想法都是臆测的，没有可靠的根据，也没有方向，再加上我是第一次处理这种问题，这导致后来查找问题的艰难。但是，仔细想想，我们又能拿什么做依据呢？出现OOM错误，我想大多数人想到的，除了JVM参数设置，就是内存泄漏。其实，OOM发生有很多种情况，在IBM、Sun、BEA等不同虚拟机上，因为GC机制不一样，所以原因一般都不同，容易定位难度也不一样。下文会谈到。
于是，我们干脆釜底抽薪分析问题吧：用JProfiler检测。
二、按应用程序导致内存泄漏诊断，JProfiler检测
如果遇到OOM问题，我想大家都会想到内存检测工具，现在最可靠的还是下面三种分析工具：Borland 的Optimizeit Suite，Quest的JProbe，ej-technologies的JProfiler。但面临三个问题：
1、三个都是商业产品，公司暂时没有买，必须自己下载，而且要找序列号。
2、工具必须支持AIX5.3＋JDK1.42＋WAS6.0，不是Windows平台。
3、工具必须在客户真实环境下部署，对客户的业务不能有冲击，也就是说部署测试工具前，必须做个大量测试，对工具非常熟练，遇到意外可以立即恢复现场。
Note:项目上线后，而不是测试或试运行阶段遇到此类问题，非常考验人；另外一个，就是性能和可伸缩性问题，很可能把整个项目给毁了。
当我决定要这么做后，就立即动手查阅这些工具的官方文档，用emule下载，最终都下载到了。试用后，最终选择了JProfiler4.03，比起其它工具，它界面美观、清晰、功能强大、集成度高(Heap,Memory,CPU,Thread都统一了)。另外，JProbe没有AIX版本，这也是放弃它的一个原因。
JVM的Profiler原理，都是通过JVM内置的的标准C语言Profiler 接口收集数据，然后通过Profiler工具的客户端展现。也就是说各厂商的Profiler工具，都有两个部分，一个部分是Profiler Agent，和JVM绑定，负责收集JVM内部数据，譬如方法调用次数、耗费时间等；另外一个部分就是Profiler front-end。通过Profiler工具的自定义local或remote协议传输到front-end，其实，我们最常用的JavaIDE的debug功能就是在此基础上的（JPDA）。（JProfiler的截图http://www.ej-technologies.com/products/jprofiler/screenshots.html ）。
下面是Sun官方文档：
JDK1.42及以前是JVM PI：http://java.sun.com/j2se/1.4.2/docs/guide/jvmpi/jvmpi.html
JDK1.5是JVM TI：http://java.sun.com/j2se/1.5.0/docs/guide/jvmti/jvmti.html
具体到JProfiler的配置上，专门针对JDK1.4和1.5的JVM配置差别很大。
我用的JProfiler是4.31版本，透露给大家一个万能序列号吧(这东西不太好找)，对各版本应该都支持。深入了解Java，这类工具是不可少的：
Name: License for You
Lincese Code: A-G667#42616F-10kg1r134fq9m#2217
为了保证真实环境的检测成功，我做了大量的试验，譬如：
1、Windows系列的本地、远程测试。
2、AIX的远程测试。
3、Tomcat5.0、WebLogic8.14、WebSphere6.02，以及上述两种方式的组合测试，排列组合，场景不下10个。
当时也参阅了大量JVM文档，JProfiler官方几百页英文文档，辅助的JProbe对照。而且也制造过内存泄漏造成的OOM场景。
当然，要是在几个月前，在客户那边部署的测试环境时，就进行测试该多好啊。
在公司内部，我用JProfiler测试了我们当时部署的几个应用，没有发现内存泄漏，所以，我们最怀疑的是就是CMS系统。因为出问题的那个WAS上它占去了90％的负荷（我们有多台AIX、WAS服务器）。该CMS超级庞大，感觉著名的赛迪网就用它，当时该CMS厂商给我们部署都花了快一个月。所以再重新部署一套测试环境也挺困难。另外，CMS提供商不给lisence。现在测试，客户早就对我们恼火了，当然不怎么配合，这对我们工作的开展就有很大的挑战。
在大致可以确定万无一失的情况下，我们最终决定在客户的真实环境下测试。也就是让JProfiler的agent端直接在WAS的JVM里面启动（北京IDC），然后远程（大连）监控。
本来该模式在另外几个应用的测试都通过了（因为北京IDC那边好几台AIX服务器）。但一部署上，客户的一些编辑用CMS时就感觉超级慢，尽管我们用了JProfiler的最小负载模式。半个小时后，客户实在无法忍受，打电话过来，又把我们部长和经理训了一顿，还要写书面报告。我们被迫马山中止测试，恢复现场。
虽然JProfiler也支持客户那边的环境，但还是有bug，至少负载一高就有严重的性能问题，几乎导致系统挂起，这是我当时没有料到的。JProfiler一启动，WAS的启动时间就由原来的3分钟降到10分钟，而且系统响应明显变慢，我们具体的环境如下（排列组合恐怕不下20种）：
1、AIX5.3，Power PC64位（不是32位）
2、WebSphere6.0
3、IBM JVM1.42
4、Remote 模式
我后来仔细读了一下JProfiler的changeLog，发现对上面的环境支持不够也很正常，因为官方在最近的4.3.x版本下陆续有对IBM JVM和Websphere6.0的features和bug fix：http://www.ej-technologies.com/download/jprofiler/changelog.html
进行到这一步，我忽然觉得无计可施了
，此时已经过了三周。
上面的策略，我认为是很正统的处理方法。谁怪我们当初项目上线时没有进行充分的测试呢？其实，这类测试没做也正常，OOM这类问题谁都无法预测。
到这个时候，我想肯定有人会问我？你知道导致JVM的OOM有几种情况吗？在当时，我想到了以下五种：
1、JVM的heap最小、最大值没有设，或不合理。
2、JVM的maxPermSize没有设置（这个IBM的JVM没有，一设置JVM就起不来）。
对于Sun和BEA的JVM，以上两种参数设置，可以排除90％以上的非程序内存溢出导致的OOM。
3、程序内存泄漏
4、有的JVM，当在80%的CPU时间内，不能GC出2%的heap时，也发生OOM（IBM的JVM就是，但我没有验证）
5、JVM本身内存泄漏（JVM有bug不是不可能）
现在的难题是，如果是那个可怕的CMS程序本身有内存溢出，在产品环境下，我们怎么去验证？我们自己开发的10来个web应用，测试并不是很难，在公司测试都可以。但是，我现在最想解决的，就是CMS测试的问题。而且，在我们那种环境下，该CMS产品供应商并没有透露成功案例。
其实，最后发现，并不是内存泄漏造成的，因为我们的heap走势都很平稳。纳闷的是，有1000M的heap，每次在heap只被占用400来M时就发生OOM，没有任何预兆。大家猜猜，会是什么原因
？这个问题我到后面相关章节再说吧。
既然我们所有的矛头都指向那个可怕的CMS系统，现在就是考虑隔离的问题。如果我们验证这个问题是CMS造成的，那么大部分责任就应该由CMS厂商承担
。
既然CMS我们不敢移（费劲，而且客户在正式用），那我就移我们开发的10来个web系统吧。
三、移出除CMS系统以外的所有应用
说起来容易啊，做呢？ 隔离（移动）工作由我负责，具体涉及到10来个相关负责人。
转移工作，必须处理好很多问题，就说几个印象最深的吧：
1、某些应用，如Blog和BBS，都涉及到文件、图片上传目录和产品本身的环境，如 JDBC连接池、Cache位置。
2、目标服务器本身的环境，WAS安装环境、网络等。
3、移植时的先后顺序、调度，各应用内部本身的约束关系。
4、移植后的测试。
当然，还有一个最严峻的问题，客户允许我们这么做吗？对它们目前运行的系统有多大影响？风险如何评估？
这个工作持续了一天，已经完成了80％的工作，到第二天，客户又恼火了：WAS又宕机了。
为什么？这确实是WAS的一个bug：WAS的后台随便一操作，heap就会突然上升几百M，导致JVM内存不够。不过WAS撑住的话，过半小时后就会降下来，我估计是WAS后台对用户操作状态、文件都缓存到Session里面。你们可以检查类似这样的一个文件夹：d:\IBM\WebSphere\AppServer\profiles\AppSrv01\wstemp，我不知道为什么WAS不主动去清除它，它偷偷的就上升到几个G，系统硬盘可能不久就后就会空间不足，WAS莫名迟缓、最后死掉。听过WAS6.0以前这个目录更夸张。大家见我附件的截图WAS_Console.png那个尖峰。
咋办？经理也已经不敢让我们继续铤而走险了。这个方案最终又以失败告终
。
不过，最后我们还是发现问题出在CMS上。我们以前把这个问题向CMS技术支持反映，有大量依据和现象，并且把相关日志都给它们。过了两天，他们最后竟然只回了一句话“从给我的两个日志来看，没有找到任何与XXX有关的东西....”。TMD！我真的很生气
，它们的产品都折磨我们半年之久了。不过，看他们对IBM的WAS和JVM也不懂，我也就不想再说什么了。下面是我的邮件，公司机密部分都隐去了：
引用
附件是我们这段时间服务器宕机的日志。我们用IBM Pattern Modeling and Analysis Tool for Java Garbage Collector Version 1.3.2分析了一下虚拟机日志，没有发现是内存泄漏导致；用IBM HeapAnalyzer Version 1.4.4 分析heap文件，也没有发现很可疑的内存泄漏。
我想以前你们也这样做过，现在我们分析错误日志，发现有一个现象，在宕机时，总是找不到文件，我看就是Websphere或是AIX IO资源不够，不知道是什么导致的。但是，我们自己的应用，基本上没有什么IO，除了一次load几个配置文件。不过，我觉得你们WCM的IO操作挺多的，不知道你对日志有什么新的发现。
客观的说，这几个月来，宕机那台服务器，除了你们的XXX，就以论坛和blog为主，而且他们都是开源的。在频繁宕机的06年11月份，我们的论坛和blog还没有上线。现在我们不得不每天晚上11点定时重启，但这也不是长久之计。
现在，我们进行分离遇到很大阻力，原来想把你们的XXX单独分离出来，在当前的环境下，不是很现实，如安装、测试（负载、定时服务），所以现在分离我们自己的应用，但当前在产品环境下，客户方阻力也很大。
希望尽快能够得到你们的问题建议和方案。
我想以前你们也这样做过，现在我们分析错误日志，发现有一个现象，在宕机时，总是找不到文件，我看就是Websphere或是AIX IO资源不够，不知道是什么导致的。但是，我们自己的应用，基本上没有什么IO，除了一次load几个配置文件。不过，我觉得你们WCM的IO操作挺多的，不知道你对日志有什么新的发现。
客观的说，这几个月来，宕机那台服务器，除了你们的XXX，就以论坛和blog为主，而且他们都是开源的。在频繁宕机的06年11月份，我们的论坛和blog还没有上线。现在我们不得不每天晚上11点定时重启，但这也不是长久之计。
现在，我们进行分离遇到很大阻力，原来想把你们的XXX单独分离出来，在当前的环境下，不是很现实，如安装、测试（负载、定时服务），所以现在分离我们自己的应用，但当前在产品环境下，客户方阻力也很大。
希望尽快能够得到你们的问题建议和方案。
文中说到了IBM的两个分析工具，这也是我们后来的救星：我们就是需要这种离线分析工具，因为实时检测已经证明不现实。但我始终对该分析出来的结果抱怀疑态度，直到我去深入IBM的JVM以及和IBM的技术支持交流......
柳暗花明啊
，至少看到了一点希望，不过最后我们还是失望而返。
四、用IBM的HeapAnalyzer和GarbageCollector检测
找到这两个工具，已经是够费劲了，因为以前找的IBM HeapRoot工具，让我对这类工具很失望。而且，这两个工具，只有在IBM的Techinical Support网站能够搜索到，但很不容易，因为那两个工具，并不是象IBM的Websphere产品那样宣传，它只在IBM Techinical Support文章的某些角落里出现。要知道，Techinical Support是IBM很重要的收入来源，这类文档，他们并不会让你很轻易就拿到，比起BEA WLS的支持网站dev2dev差远了。
具体诊断细节我就不详述了。我认为，IBM的WAS或JVM出了性能和OOM问题，这两个工具是最有效的，而且是离线分析工具，比起那些实时Profiler工具，某些场合有绝对的优势：譬如我们目前的产品环境，你只能分析宕机后的日志，实时分析前面已经验证是不可行的。
从日志分析，我们最终得出结论，我们购买的CMS系统有严重的碎片（大对象）问题，而该问题是OOM的罪魁祸首，而且IBM工程师也得出了同一结论。不过，在起先我们得出这一结论一周后，我还始终不相信heap碎片会导致OOM，直到IBM工程师总是向我强调。
我想很多人也是不太相信，因为大多数人用的都是Sun的JVM，譬如Windows、Solaris上的hotspot。而且，Sun JVM出问题，如果是配置的问题，一般通过配置heap最大最小值，以及maxPermSize都可以解决。Heap碎片导致的OOM，只有BEA的JRockit和IBM JVM上发生，不过JRockit有专门文档说明，而且很容易找到（就在jdk的文档里面）。
配置heap最小最大值，我想大多数人都有经验。对于Sun的JVM来说，一般可以设置heap最大最小值一致，也是推荐的做法。因为它的GC策略默认是复制、分代算法。也就是说，它会将heap分成不同的几个区，譬如Solaris JVM中最上面有两个大小相等的区。GC时刻，将一个区的存活对象复制到另外一个对等区，垃圾对象就算遗弃了。这样在heap里面，就不存在碎片问题。另外，根据Java对象的存活期不同，将之转移到不同的区（Tenured区），存活最长的在最底部（火车算法），这也就是分代模型。具体请参考官方文档：http://java.sun.com/docs/hotspot/gc1.4.2/
对于maxPermSize（Permanent Generation），主要和那些加载到JVM里面的Java Class对象相关，它的空间不是在Java Heap里面分配。如果你当前的heap有1000M，permSize是200M，那么JVM至少占用1200M。
在这个空间内的对象的生存期和JVM是一样的，譬如JDK的核心类库，它们被System Classloader加载到JVM的Method Area（方法区）后，就不会被GC掉的，这些对象一般是Class对象，而不是普通的实例对象，也就是JVM的元数据。我们在用反射时经常用到它们。所以，对于现在象Spring、Hibernate这些框架经常通过反射创建实例，可能对maxPermSize要求就大了，缺省的64M很多时候是不够的，特别是对于应用服务器里的应用，象JSP就会产生和加载很多classes。不过，如果是它导致的OOM，一般会有类似 perm size提示。
但是，对于IBM的JVM，情况就完全不一样。它的默认GC策略并没有采取复制、分代。这个可以从GC日志分析出来。它不像Sun的JVM那样，有个单独的方法区，它的方法区就放在Java Heap里面。JVM规范里面并没有要求方法区的必须存放的位置，因为它只是一个JVM实现问题。
在IBM的JVM里面，这些对象一般分配在称为k-cluster和p-cluster里（cluster又是属于Heap），而后者一般是临时在heap里面申请。并且，这些cluster是不能GC，或是被移动重排的（Compact过程）。这就导致Java Heap里面就如同马蜂窝，但不同的蜂孔又不能合并，于是，当我们程序里面产生一个大对象，譬如2M的数组(数组必须分配在连续的内存区)时，就没有可分配空间了，于是就报告OOM。这些不能被移动的cluster就称为所谓的碎片。此时，JVM的Heap利用率可能不到50%。
当然，通过一定时期的GC日志，可以计算出cluster的合理大小（专门在Java Heap的底部），另外，还可以为这些大对象专门分配大对象区的（超过64k的对象）。
通过上面的理论介绍，我想大家一定知道了为什么IBM的JVM里面不推荐heap的最大最小值相同，因为这样碎片问题会非常严重：如果我们每次大对象申请内存时，heap都扩展5%，譬如50M，碎片问题很大程度上可以避开，程序性能也高些（寻找可用空隙和分配耗时，以及每次GC时间拉长）。
以上的具体阐述，请参考我在上文推荐的几个URL，另外再推荐三个宝贵的链接：
http://www-1.ibm.com/support/docview.wss?rs=180&context=SSEQTP&q1=fragmentation&uid=swg21176363&loc=en_US&cs=utf-8&lang=en
http://www-900.ibm.com/cn/support/viewdoc/detail?DocId=2447476A10000（IBM 技术支持告诉我的，太重要了！）
http://www-900.ibm.com/cn/support/viewdoc/detail?DocId=2847476B08000
我想大家应该会问：我怎么能够肯定我的OOM问题是heap碎片造成的呢？下面的方法可以验证。
在OOM发生时，JVM会产生一个heapdump文件。然后用GarbageCollector分析出该OOM发生时刻，JVM去申请的空间，譬如约235k。此时，你再用HeapAnalyzer去分析此时的heap快照里面的gap size大小（空隙大小）和各自的可用数目。你会发现，大于235k的空隙个数为0。这就是碎片导致OOM的证据。
另外，有人会问：我怀疑我的OOM是因为程序内存泄漏造成的，怎么去验证？
你可以用HeapAnalyzer分析发生OOM时刻的heap快照，工具会罗列出哪些对象怀疑有内存泄漏，譬如Cache对象都非常大（但你可以确定它不是内存泄漏）。另外，分析这次宕机（从这次虚拟机启动到宕机这段时间）的heap走势，如果曲线明显是向上倾斜，也就是那种典型的内存泄漏图，就有可能是内存泄漏。当然，还必须结合heap快照。
内存持续上升在JVM开始一段时间很正常，因为JVM对第一次访问到的Class 对象，譬如一个典型的Web应用，就有jdk的class、Spring或Hibernate的class对象，它们都会被缓存下来(ClassLoader原理)，一般均不会被GC。当大多数class对象缓存差不多（当然还可能有一些Singleton对象，不过不怎么占分量），JVM的Heap就平稳了，呈一水平波浪或锯齿线。
如果可以用JProfiler这类工具实时监控，就更容易确诊了。
经过一番周折，我们终于看到了一线希望了
。
在一定的准备后，我们决定对WAS进行性能调优了。WAS的调优参数，可以分为两个部分：JVM级别和WAS级别：
JVM：主要是GC和Heap。
WAS：Thread Pool，JDBC DataSource。
当然要调节，你需要明白你的目标是什么，调节依据是什么，怎么计算，绝对不是凭空想象的，譬如heap最小值1024M，日志证明，该参数非常不适合我们的环境。具体细节，留给后文吧。
战战兢兢地，中午12:00，我们给产品环境下的WAS调节参数、重启，同时优化了AIX的IO相关参数。
我试着设置了一下JVM的k-cluster和p-cluster。下午15:00左右，WAS挂了，AIX也挂了。这下麻烦可大了。我们都慌了，马山客户的老总就来电话了，一阵哗哗啦啦。实在无奈，让客户那边工作人员通知机房（服务器托管处）工作人员重启AIX。我也不得不强行更改刚才的参数，立即设为另外一个值。
其实，我把那个两个cluster值确实设置太大了，我把它们设置为推荐值的5倍，譬如p-cluster是65k×110%×5。另外一个愚蠢的设置就是把最小heap设置为2048M(AIX有4G内存)。
后来我恢复到约正常的值，也就是去掉那个cluster的5，另外分配了一个30%的大对象区（如果1000M的heap，就是700M＋300M）。
就这样，系统持续正常运行了三天，以前可是一天一down。当在三天后再次宕机时，我们都没有自信了
。不得不通过AIX的cron，继续每天深夜11点的WAS定时重启。
不过，那次宕机，包括以后的几次宕机，再也没有出现OOM错误了，但系统依然不稳定。虽然我可以说OOM问题解决了，但领导和客户需要的并不是这种结果。
其实，在这个时候，我们已经发现我们系统的四大问题：
1、WAS和JVM参数：OOM问题
2、AIX的IO和Paging Spacing不足：AIX日志后来显示错误
3、AIX的WAS分区空间不够：WAS的日志膨胀一周就把那个opt分区塞满了。
4、应用程序的JDBC连接池：我们20来个应用，一个20 connections，DB2数据库有时被撑死。
也就是说，我们最初在客户那儿部署时，用的默认值根本不行。而且，部署涉及多人，人员之间出现断层。如果我们只是按OOM，无疑是走入死胡同，必须全局考虑！
但是，项目组实力薄弱，公司范围内就没有对AIX精通的。不过项目组原来有一个搞银行系统，在AIX下开发，就他熟悉些。我当时对AIX也比较陌生，你们从Linux转到AIX，你就知道它有多别扭了。命令都自定一套（也许因为是Unix元老吧），那个shell也超级别扭，而且参考书特少。不是自诩，我两年前负责一个高负载的Linux服务器管理一年多，也是玩得很转的。
就这样，他负责AIX的相关问题，我负责WAS相关的。
但是，现实环境，已经不允许我们再试验下去了
。我们必须找到一条绝对可靠的对策！
这就是下文的CMS系统大迁移，服务器再次优化。
文章太长（上万字），我把剩下部分发表在回复贴里面吧。
- 描述:
- 大小: 14.9 KB
- 描述:
- 大小: 78.5 KB
- 描述:
- 大小: 18.7 KB
- 18:16
- 浏览 (21534)
- 评论 (39)
- 分类: Java技术
- 进入论坛
- 发布在 大连JAVAeyer群 圈子
- 相关推荐
评论
dmewy
2008-05-14
研究了一个月.
现在算是能用websphere开发了..
公司都用的wsad..
我觉得不爽,用了myeclipse 的blue版本.
现在感觉也还可以.
总的来说websphere要求太严格了.
很多地方很麻烦..
现在算是能用websphere开发了..
公司都用的wsad..
我觉得不爽,用了myeclipse 的blue版本.
现在感觉也还可以.
总的来说websphere要求太严格了.
很多地方很麻烦..
zhongsiwu
2007-09-29
zwchen,
你好.
我也是刚刚接触websphere,以前觉得它挺麻烦的,读了你的两篇文章和大家的一些回复,感觉对我帮助很大,我按照上边的实践,解决了很多问题.不过现在又遇到了一些问题,就是用jprofiler监控Websphere6.1的时候,通过jprofiler启动Websphere的时候,老出错,提示:
-------------------------------
failed to start
startServer return code = -1
-------------------------------
在Websphere日志native_stderr.log中出现
-------------------------------------------------------
<verbosegc version="20060501_AA">
JVMJ9TI001E Agent library jprofilerti could not be opened (找不到指定的模块。 )
JVMJ9VM015W Initialization error for library j9jvmti23(-3): JVMJ9VM009E J9VMDllMain failed
</verbosegc>
无法创建 Java 虚拟机。
--------------------------------------------------------
在我的server1的配置文件server.xml中,jprofiler添加的内容如下:
---------------------------------------------------------
genericJvmArguments="-agentlib:jprofilerti=port=8849 -Xbootclasspath/a:F:\JPROFI~2\bin\agent.jar"
---------------------------------------------------------
我在baidu和google上搜索关于jprofiler的Websphere资料,可惜却几乎找不到,你能帮-帮-我吗~?将你以前使用jprofiler的情况帮我整理一下.我的邮箱是zhongwu@tom.com , 谢谢了.
你好.
我也是刚刚接触websphere,以前觉得它挺麻烦的,读了你的两篇文章和大家的一些回复,感觉对我帮助很大,我按照上边的实践,解决了很多问题.不过现在又遇到了一些问题,就是用jprofiler监控Websphere6.1的时候,通过jprofiler启动Websphere的时候,老出错,提示:
-------------------------------
failed to start
startServer return code = -1
-------------------------------
在Websphere日志native_stderr.log中出现
-------------------------------------------------------
<verbosegc version="20060501_AA">
JVMJ9TI001E Agent library jprofilerti could not be opened (找不到指定的模块。 )
JVMJ9VM015W Initialization error for library j9jvmti23(-3): JVMJ9VM009E J9VMDllMain failed
</verbosegc>
无法创建 Java 虚拟机。
--------------------------------------------------------
在我的server1的配置文件server.xml中,jprofiler添加的内容如下:
---------------------------------------------------------
genericJvmArguments="-agentlib:jprofilerti=port=8849 -Xbootclasspath/a:F:\JPROFI~2\bin\agent.jar"
---------------------------------------------------------
我在baidu和google上搜索关于jprofiler的Websphere资料,可惜却几乎找不到,你能帮-帮-我吗~?将你以前使用jprofiler的情况帮我整理一下.我的邮箱是zhongwu@tom.com , 谢谢了.
摆渡人
2007-09-28
我们这里也有WebSphere6.0,同样的代码我们布署在bea weblogic8都没问题，可是一放在websphere上
基本天天down 机。也不知怎么办。现场人员又不知出了什么事。只是偶尔发一两个日志。搞不懂。IBM的东东实在不懂的用呀？
[07-9-25 12:29:49:643 CST] 000000c0 SystemErr R java.lang.NullPointerException
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.SocketIOChannel.attemptWriteToSocket(SocketIOChannel.ja
va:830)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.WorkQueueManager.attemptIO(WorkQueueManager.java:629)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.WorkQueueManager.workerRun(WorkQueueManager.java:952)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.WorkQueueManager$Worker.run(WorkQueueManager.java:1039)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1471)
基本天天down 机。也不知怎么办。现场人员又不知出了什么事。只是偶尔发一两个日志。搞不懂。IBM的东东实在不懂的用呀？
[07-9-25 12:29:49:643 CST] 000000c0 SystemErr R java.lang.NullPointerException
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.SocketIOChannel.attemptWriteToSocket(SocketIOChannel.ja
va:830)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.WorkQueueManager.attemptIO(WorkQueueManager.java:629)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.WorkQueueManager.workerRun(WorkQueueManager.java:952)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.tcp.channel.impl.WorkQueueManager$Worker.run(WorkQueueManager.java:1039)
[07-9-25 12:29:49:644 CST] 000000c0 SystemErr R at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1471)
aurora
2007-09-26
今年看的最好的关于websphere的帖子，楼主继续努力
indexchen
2007-09-04
IBM就喜欢把简单问题复杂化，一个 WAS害了多少应用程序，其实看看这些应用程序本身并不复杂，用其他技术如php,rails来实现不会有那么多问题，甚至跑在tomcat上也不会有那么多问题。不要迷信WebSphere
hunter006
2007-08-28
看和做两种感觉，感谢楼主的分享。Java最大的毛病就是规范太多，导致实现不同，虽然大体思路一致，不过实现细节差别很大，具体项目应用比较头疼。不过这好像也是java各种思想百花齐放的原因吧，具体看项目负责人的取舍和对相应实现的理解程度了。
hrdede
2007-08-16
我这边的生产环境现在也报内存溢出的问题，现在每天都定时重启
可在测试环境又不能重现问题，真是头痛啊
生产环境又不能取消重启的动作，希望各位给点意见
可在测试环境又不能重现问题，真是头痛啊
生产环境又不能取消重启的动作，希望各位给点意见
programmer
2007-08-12
下面是我和搂主的消息讨论，感觉还有点用，所以就贴出来了：
我的发言：
window 32bit 确实java heap 最大可以分配到2047M（2G-1），不能超过这个，但通常情况这个大小也设置不了，这个大小os限制的。整个jvm使用的内存不仅仅局限在heap，heap之外还有 JIT,JNI....,所以我当我在websphere5.1的时候分配2047M 的时候 系统自动把我的heap 最大值 限制在1.5G左右。
windows 确实可以扩展2G-1的限制，windows 里有一个 boot.ini 文件，里面可以进行设置。
还有些问题请教，我通过长时间的优化系统的一些性能表现：
gc 平均收集间隔时间是：1.2分钟。
gc的平均收集时间是：511ms
请问这样的性能表现，怎么样，一般的性能参照值是多少？谢谢！
附件是一个 有关windows 内存限制的 ibm 技术文档
楼主的回复：
你附件里面的文档比我以前上传的一篇IBM JVM文档详细多了。而且你上面的分析很客观，Heap只是JVM占内存一个部分，大约是80%，这个很容易验证。
说到性能调优，你看看网上这个blog的系列文章吧：http://songsun.spaces.live.com/，很详细，而且也很客观。
你的GC频率有点偏高，GC收集时间也有点偏大，譬如3－4分钟，每次0.3s左右就差不多了（一般JVM默认就可以是这个值）。不过，说实话，这个都不太重要，把GC收集时间优化大点就可以了。
一般来说，JVM的调优主要是适应硬件和特殊情况，譬如我的服务器有四个cpu，就要调节JVM的concurrent GC特性；我用到了特别的内存Cache，就要专门把Heap弄大点。
应用的性能，主要是程序本身来决定，譬如架构、DB设计、list列表分页，Hibernate二级缓存等，JVM关系不大。真正对JVM的GC敏感的是Java的嵌入式系统，实时系统。MIS系统关系不大。
我的发言：
window 32bit 确实java heap 最大可以分配到2047M（2G-1），不能超过这个，但通常情况这个大小也设置不了，这个大小os限制的。整个jvm使用的内存不仅仅局限在heap，heap之外还有 JIT,JNI....,所以我当我在websphere5.1的时候分配2047M 的时候 系统自动把我的heap 最大值 限制在1.5G左右。
windows 确实可以扩展2G-1的限制，windows 里有一个 boot.ini 文件，里面可以进行设置。
还有些问题请教，我通过长时间的优化系统的一些性能表现：
gc 平均收集间隔时间是：1.2分钟。
gc的平均收集时间是：511ms
请问这样的性能表现，怎么样，一般的性能参照值是多少？谢谢！
附件是一个 有关windows 内存限制的 ibm 技术文档
楼主的回复：
你附件里面的文档比我以前上传的一篇IBM JVM文档详细多了。而且你上面的分析很客观，Heap只是JVM占内存一个部分，大约是80%，这个很容易验证。
说到性能调优，你看看网上这个blog的系列文章吧：http://songsun.spaces.live.com/，很详细，而且也很客观。
你的GC频率有点偏高，GC收集时间也有点偏大，譬如3－4分钟，每次0.3s左右就差不多了（一般JVM默认就可以是这个值）。不过，说实话，这个都不太重要，把GC收集时间优化大点就可以了。
一般来说，JVM的调优主要是适应硬件和特殊情况，譬如我的服务器有四个cpu，就要调节JVM的concurrent GC特性；我用到了特别的内存Cache，就要专门把Heap弄大点。
应用的性能，主要是程序本身来决定，譬如架构、DB设计、list列表分页，Hibernate二级缓存等，JVM关系不大。真正对JVM的GC敏感的是Java的嵌入式系统，实时系统。MIS系统关系不大。
zengxxcn
2007-07-19
推荐使用JPROF及其相关的TPROF, HDUMP, ITRACE等工具，没有图形界面，不会像jprofiler那样占用大量资源，配合WAS产品比较合适。
http://perfinsp.sourceforge.net/jprof.html
http://perfinsp.sourceforge.net/jprof.html
programmer
2007-07-18
文章非常不错，我们系统碰到了一个几乎和你碰到差不多的问题，试试你的方法，成功后上来告诉你。
leobluewing
2007-07-09
好贴！！
关于heapdump的解析问题，推荐IBM Support Assistant里面的一个解析插件，Memory Dump Diagnostic for Java (MDD4J）非常好用，解析后的信息非常清晰，唯一美中不足的是非常占用内存。
我在4，5月份也是在调优一个项目的WS宕机问题，当时的宕机情况基本是1天1次，异常严重。我之前根本没接触过WS,全部是现学现卖，把自己整的累死，要是当时早点看到楼主的帖子，估计就没这么多事了。
说下我这个项目大概情况，一般刚开始运行服务以后，WS的内存占用量在500MB左右，可是以前一般在24小时之内，内存占用可以飙升到1.5G以上。
很明显是内存溢出。然后基本也是按照楼主的排查思路，不过我们一开始是去找IBM的WS补丁，在打完补丁无效后，去查是否是WS配置问题，一开始以为是最大堆设置太大了（不是写错，有的溢出原因就是因为最大堆设置太大而不是太小），于是减小到1.5G，溢出更快了。然后又调整了其他几个参数，基本没什么大用，于是想到不是因为WS设置问题。
然后找heapdump分析工具，就是我前面说的MDD4J，不过需要安装IBM的jdk，然后又在本地跑了个WS服务,用JProfiler本地监视哪些对象没有被释放。 然后和MDD4J的分析亮相比较，确定了是一个静态对象没有被GC掉，最后查出还是程序的问题，一个静态类中的log日志写法有错，导致一直新建对象而不能释放。最后改写代码以后，使用内存基本稳定600MB，最高1G左右，基本没有宕机发生，问题解决。
总的来说，Jprofiler和MDD4J是好东西。
关于heapdump的解析问题，推荐IBM Support Assistant里面的一个解析插件，Memory Dump Diagnostic for Java (MDD4J）非常好用，解析后的信息非常清晰，唯一美中不足的是非常占用内存。
我在4，5月份也是在调优一个项目的WS宕机问题，当时的宕机情况基本是1天1次，异常严重。我之前根本没接触过WS,全部是现学现卖，把自己整的累死，要是当时早点看到楼主的帖子，估计就没这么多事了。
说下我这个项目大概情况，一般刚开始运行服务以后，WS的内存占用量在500MB左右，可是以前一般在24小时之内，内存占用可以飙升到1.5G以上。
很明显是内存溢出。然后基本也是按照楼主的排查思路，不过我们一开始是去找IBM的WS补丁，在打完补丁无效后，去查是否是WS配置问题，一开始以为是最大堆设置太大了（不是写错，有的溢出原因就是因为最大堆设置太大而不是太小），于是减小到1.5G，溢出更快了。然后又调整了其他几个参数，基本没什么大用，于是想到不是因为WS设置问题。
然后找heapdump分析工具，就是我前面说的MDD4J，不过需要安装IBM的jdk，然后又在本地跑了个WS服务,用JProfiler本地监视哪些对象没有被释放。 然后和MDD4J的分析亮相比较，确定了是一个静态对象没有被GC掉，最后查出还是程序的问题，一个静态类中的log日志写法有错，导致一直新建对象而不能释放。最后改写代码以后，使用内存基本稳定600MB，最高1G左右，基本没有宕机发生，问题解决。
总的来说，Jprofiler和MDD4J是好东西。
zwchen
2007-06-28
magic4u 写道
从初级GC是可以分析大对象的。
当JVM里面的GC选项打开后，会在native_stderr.log里面出现相关的内存回收信息。例如:
从上面的日志可以看出来，内存中有2359304bytes的对象创建，也就是一个对象有2M左右。
如果这样的大对象反复创建，（应用中代码实现狠容易出现这样的问题），狠容易出现频繁的垃圾回收。
当连续内存不能满足请求时，就会出现我们经常看到的JVM Hungup的情况。如下：
当JVM里面的GC选项打开后，会在native_stderr.log里面出现相关的内存回收信息。例如:
<AF[30]: Allocation Failure. need 2359304 bytes, 7545 ms since last AF> <AF[30]: managing allocation failure, action=2 (181553016/268433920)> <GC(30): GC cycle started Mon Jun 11 11:28:22 2007 <GC(30): freed 18561072 bytes, 74% free (200114088/268433920), in 92 ms> <GC(30): mark: 80 ms, sweep: 12 ms, compact: 0 ms> <GC(30): refs: soft 0 (age >= 32), weak 0, final 56, phantom 0> <AF[30]: completed in 93 ms>
从上面的日志可以看出来，内存中有2359304bytes的对象创建，也就是一个对象有2M左右。
如果这样的大对象反复创建，（应用中代码实现狠容易出现这样的问题），狠容易出现频繁的垃圾回收。
当连续内存不能满足请求时，就会出现我们经常看到的JVM Hungup的情况。如下：
<AF[14]: Allocation Failure. need 1179656 bytes, 943 ms since last AF> <AF[14]: managing allocation failure, action=2 (149244320/276298240)> .......... <GC(14): unloaded and freed 101 classes> <GC(14): GC cycle started Mon Jun 11 10:58:06 2007 <GC(14): freed 31484232 bytes, 65% free (180728552/276298240), in 236 ms> <GC(14): mark: 97 ms, sweep: 16 ms, compact: 123 ms> <GC(14): refs: soft 34 (age >= 6), weak 0, final 199, phantom 1> <GC(14): moved 215615 objects, 12782856 bytes, IC reason=14> <AF[14]: completed in 249 ms> JVMDG217: Dump Handler is Processing a Signal - Please Wait. JVMDG303: JVM Requesting Java core file JVMDG304: Java core file written to C:\IBM\WebSphere\AppServer\javacore.20070611.105808.5220.txt JVMDG215: Dump Handler has Processed Exception Signal 11.
谢谢你分享的分析，我再说明几点：
从你们的log来看，你们的dump发生时机是“heap压缩、扩展无效的时候”（moved 215615 objects和managing allocation failure, action=2 以及reason=14），并且你们的GC采用了增量式压缩（IC reason=14），当时你们的heap还有65% free。
我也说说自己的体会吧。看下面两个典型发生OutOfMemory的log事件，这是我们WAS的JVM的：
引用
<AF[649]: Allocation Failure. need 147480 bytes, 5 ms since last AF>
<AF[649]: managing allocation failure, action=2 (2879712/536869376)>
<GC(649): mark stack overflow[250]>
<GC(649): GC cycle started Mon Oct 23 11:09:05 2006
<GC(649): freed 362008 bytes, 0% free (3241720/536869376), in 3263 ms>
<GC(649): mark: 559 ms, sweep: 41 ms, compact: 2663 ms>
<GC(649): refs: soft 0 (age >= 32), weak 0, final 3, phantom 0>
<GC(649): moved 3407930 objects, 316730880 bytes, reason=1, used 32 more bytes>
<AF[649]: managing allocation failure, action=3 (3241720/536869376)>
<AF[649]: managing allocation failure, action=4 (3241720/536869376)>
<AF[649]: managing allocation failure, action=6 (3241720/536869376)>
JVMDG217: Dump Handler is Processing OutOfMemory - Please Wait.
JVMDG315: JVM Requesting Heap dump file
JVMDG318: Heap dump file written to /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/heapdump467034.1161619745.phd
JVMDG303: JVM Requesting Java core file
[ JVMST080: verbosegc is enabled ]
[ JVMST082: -verbose:gc output will be written to stderr ]
<AF[649]: managing allocation failure, action=2 (2879712/536869376)>
<GC(649): mark stack overflow[250]>
<GC(649): GC cycle started Mon Oct 23 11:09:05 2006
<GC(649): freed 362008 bytes, 0% free (3241720/536869376), in 3263 ms>
<GC(649): mark: 559 ms, sweep: 41 ms, compact: 2663 ms>
<GC(649): refs: soft 0 (age >= 32), weak 0, final 3, phantom 0>
<GC(649): moved 3407930 objects, 316730880 bytes, reason=1, used 32 more bytes>
<AF[649]: managing allocation failure, action=3 (3241720/536869376)>
<AF[649]: managing allocation failure, action=4 (3241720/536869376)>
<AF[649]: managing allocation failure, action=6 (3241720/536869376)>
JVMDG217: Dump Handler is Processing OutOfMemory - Please Wait.
JVMDG315: JVM Requesting Heap dump file
JVMDG318: Heap dump file written to /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/heapdump467034.1161619745.phd
JVMDG303: JVM Requesting Java core file
[ JVMST080: verbosegc is enabled ]
[ JVMST082: -verbose:gc output will be written to stderr ]
从上面的GC可以看出，OutOfMemory是由于Heap最大值不够引起的（heap只有0% free ）。
该OOM发生时，我们JVM heap最大值设置为512M左右。
引用
<AF[914]: Allocation Failure. need 1698624 bytes, 8 ms since last AF>
<AF[914]: managing allocation failure, action=2 (489123912/1073740288)>
<GC(932): GC cycle started Wed Nov 1 14:15:39 2006
<GC(932): freed 930168 bytes, 45% free (490054080/1073740288), in 1817 ms>
<GC(932): mark: 426 ms, sweep: 53 ms, compact: 1338 ms>
<GC(932): refs: soft 0 (age >= 32), weak 0, final 2, phantom 0>
<GC(932): moved 482920 objects, 37943712 bytes, reason=1, used 24 more bytes>
<AF[914]: managing allocation failure, action=3 (490054080/1073740288)>
<AF[914]: managing allocation failure, action=4 (490054080/1073740288)>
<AF[914]: managing allocation failure, action=6 (490054080/1073740288)>
JVMDG217: Dump Handler is Processing OutOfMemory - Please Wait.
JVMDG315: JVM Requesting Heap dump file
JVMDG318: Heap dump file written to /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/heapdump356412.1162412139.phd
JVMDG303: JVM Requesting Java core file
[ JVMST080: verbosegc is enabled ]
[ JVMST082: -verbose:gc output will be written to stderr ]
<AF[914]: managing allocation failure, action=2 (489123912/1073740288)>
<GC(932): GC cycle started Wed Nov 1 14:15:39 2006
<GC(932): freed 930168 bytes, 45% free (490054080/1073740288), in 1817 ms>
<GC(932): mark: 426 ms, sweep: 53 ms, compact: 1338 ms>
<GC(932): refs: soft 0 (age >= 32), weak 0, final 2, phantom 0>
<GC(932): moved 482920 objects, 37943712 bytes, reason=1, used 24 more bytes>
<AF[914]: managing allocation failure, action=3 (490054080/1073740288)>
<AF[914]: managing allocation failure, action=4 (490054080/1073740288)>
<AF[914]: managing allocation failure, action=6 (490054080/1073740288)>
JVMDG217: Dump Handler is Processing OutOfMemory - Please Wait.
JVMDG315: JVM Requesting Heap dump file
JVMDG318: Heap dump file written to /opt/IBM/WebSphere/AppServer/profiles/AppSrv01/heapdump356412.1162412139.phd
JVMDG303: JVM Requesting Java core file
[ JVMST080: verbosegc is enabled ]
[ JVMST082: -verbose:gc output will be written to stderr ]
这次才可能是由于大对象（1698624 bytes）创建引起（内存碎片：Heap中instance对象可以move，但class对象不能移动），此时heap 45% free，490054080 bytes，非常大的空闲。
该OOM发生时，是我们一周后（看GC日期）将JVM的Heap最大值从上面的512M调节到1024M后。但OOM依然发生。
说明：action=2,reason=1,这些数字在IBM JVM参考手册上有详细介绍。
zwchen
2007-06-26
bromon 写道
AppSrv01\wstemp这个目录在管理员操作之后大小暴涨的原因是低版本was6的bug。登录控制台之后was会在wstemp目录产生大量临时文件，但是在用户没有正常注销或者超时之后，这些文件又没有自动删除造成的。wstemp目录下的东西一般都可以直接删，关于这个问题developerworks上有描述
我在客户这边用的是was 6.0.2，似乎已经解决了这个bug，我经常看到wstemp文件夹大小是0字节
我在客户这边用的是was 6.0.2，似乎已经解决了这个bug，我经常看到wstemp文件夹大小是0字节
听说是解决了，不过没有验证。因为我们的WAS控制台又很多同事在上面发布版本，没有注销是经常的事情。所以那个目录经常还是很大，1G左右吧。我喜欢delete那几个temp相关的目录，但产品环境下就比较少了。
leadyu
2007-06-25
我也来说两句，关于WAS性能调优，我想我还是有一定发言权的。
在去年9月份开始，我们遇到的问题几乎和楼主一模一样，一天宕几次，最后才组织人员攻关。后面我就加入了那个小组。
之前为什么一直没有很好解决性能问题，其实，最难的就是对于瓶颈的定位，特别是我们的系统业务非常多，应用面也很广，瓶颈可能有很多处，不大可能是一处问题造成频繁宕机。
我认为，造成系统性能问题，可能有几个大的方面：
1）自己的程序写的不好（最大可能）
2）系统架构上的问题（比如远程调用，WAS部署方面等）
3)使用面很广的通用组件（比如连接池，缓存组件，或者一些其他的）
首先，第一点--自己的程序，我的思路就是不停的对生产系统进行监控（通过监控工具），对测试环境监控和压力测试，有作用，但是很难模拟真实环境，不能解决大部分问题。那么采用什么监控工具就很重要，jprofiler没有采用，基本不大可能在生产上大范围使用，所以后面我自己开发工具，通过classloader，字节码修改，连接池代理，堆栈跟踪等技术，重点监控数据库操作和调用堆栈，以及类的方法调用，http请求等。组件会自动把执行时间过长的程序细节记录下来，定期收集分析。3个月后，系统再也没有宕过机，所有程序执行时间都在30S以内了，中间发现的程序问题太多，有些很低级，大都是自身程序的问题，当然后面还有一些其他原因，比如SSO算法。
根除了大部分自身问题，再从架构上考虑性能问题，比如应用的分离，因为大的系统不断有新需求开发，日后很难保证新开发的程序没有问题，哪怕是个高手开发的，所以要从架构上，解决物理伸缩问题，才能长远保证系统稳定。
在架构上，还可以考虑比如群集策略，远程调用等等，这些都有可能造成性能瓶颈。
在去年9月份开始，我们遇到的问题几乎和楼主一模一样，一天宕几次，最后才组织人员攻关。后面我就加入了那个小组。
之前为什么一直没有很好解决性能问题，其实，最难的就是对于瓶颈的定位，特别是我们的系统业务非常多，应用面也很广，瓶颈可能有很多处，不大可能是一处问题造成频繁宕机。
我认为，造成系统性能问题，可能有几个大的方面：
1）自己的程序写的不好（最大可能）
2）系统架构上的问题（比如远程调用，WAS部署方面等）
3)使用面很广的通用组件（比如连接池，缓存组件，或者一些其他的）
首先，第一点--自己的程序，我的思路就是不停的对生产系统进行监控（通过监控工具），对测试环境监控和压力测试，有作用，但是很难模拟真实环境，不能解决大部分问题。那么采用什么监控工具就很重要，jprofiler没有采用，基本不大可能在生产上大范围使用，所以后面我自己开发工具，通过classloader，字节码修改，连接池代理，堆栈跟踪等技术，重点监控数据库操作和调用堆栈，以及类的方法调用，http请求等。组件会自动把执行时间过长的程序细节记录下来，定期收集分析。3个月后，系统再也没有宕过机，所有程序执行时间都在30S以内了，中间发现的程序问题太多，有些很低级，大都是自身程序的问题，当然后面还有一些其他原因，比如SSO算法。
根除了大部分自身问题，再从架构上考虑性能问题，比如应用的分离，因为大的系统不断有新需求开发，日后很难保证新开发的程序没有问题，哪怕是个高手开发的，所以要从架构上，解决物理伸缩问题，才能长远保证系统稳定。
在架构上，还可以考虑比如群集策略，远程调用等等，这些都有可能造成性能瓶颈。
bromon
2007-06-23
AppSrv01\wstemp这个目录在管理员操作之后大小暴涨的原因是低版本was6的bug。登录控制台之后was会在wstemp目录产生大量临时文件，但是在用户没有正常注销或者超时之后，这些文件又没有自动删除造成的。wstemp目录下的东西一般都可以直接删，关于这个问题developerworks上有描述
我在客户这边用的是was 6.0.2，似乎已经解决了这个bug，我经常看到wstemp文件夹大小是0字节
我在客户这边用的是was 6.0.2，似乎已经解决了这个bug，我经常看到wstemp文件夹大小是0字节
zwchen
2007-06-22
顺便说一下我文中忘了写的一个WAS问题诊断方法：分析WAS宕机时JVM线程，也就是javacore文件分析。
该文件是在JVM意外中止时，和heapdump文件一起产生，号称javadump。
该文件可以用IBM的“IBM Thread and Monitor Dump Analyzer for Java Technology”工具来分析，不过人工分析也行，因为它和GC日志一样是可读的。该工具可以在这儿下载：http://www.alphaworks.ibm.com/tech/jca/
Note:WAS诊断的三个非常重要的离线诊断工具：IBM GC分析工具、IBM heap分析工具，以及现在这个Java dump分析工具。
从该文件，可以提供诊断时的重要依据，譬如，可以分析出线程挂起、死锁、资源瓶颈的原因。以及发生异常时的系统环境：譬如WAS当时有多少线程（每个线程的详细信息），当时的heap情况，JVM中止的原因（Cause of thread dump）。
如果系统默认情况下没有产生该javacore文件，可以在WAS控制台里，设置JVM的环境变量“IBM_HEAPDUMP=TRUE”。
如果想随时产生一个（譬如当前系统响应非常缓慢，你怀疑有线程挂起），可以通过“kill -3 <pid>”命令，产生一个javacore和heapdump。产生的javacore的命名规则和heapdump差不多，譬如javacore1347790.1181781840.txt，也就是javacore＋PID＋.＋系统时间。
附件截图是AIX下的BEA的WebLogic7.0、IBM的JVM，产生的javacore的分析结果。如果结合GC和Heap，就很容易分析出问题。
注意：可能大家用“kill -3 <pid>”命令时，并不能产生javacore文件，一般情况下，如果是AIX平台，可以执行：export DISABLE_JAVADUMP=true
再执行上面的kill命令，如果还是不行，请参考IBM的support文档：
http://www-1.ibm.com/support/docview.wss?rs=180&context=SSCMPB9&q1=MustGatherDocument&uid=swg21145345&loc=en_US&cs=utf-8&lang=en
可能有人报告说kill命令产生不了heapdump，请参考：
http://www-1.ibm.com/support/docview.wss?uid=swg21242497
另外，关于系统没有响应或是性能下降，可以参考IBM这篇文档来收集系统必要数据进行分析，我按文档的步骤做一遍，需要约半个小时的时间，非常麻烦：
http://www-1.ibm.com/support/docview.wss?rs=180&context=SSCMPB9&q1=MustGatherDocument&uid=swg21052641&loc=en_US&cs=utf-8&lang=en
该文件是在JVM意外中止时，和heapdump文件一起产生，号称javadump。
该文件可以用IBM的“IBM Thread and Monitor Dump Analyzer for Java Technology”工具来分析，不过人工分析也行，因为它和GC日志一样是可读的。该工具可以在这儿下载：http://www.alphaworks.ibm.com/tech/jca/
Note:WAS诊断的三个非常重要的离线诊断工具：IBM GC分析工具、IBM heap分析工具，以及现在这个Java dump分析工具。
从该文件，可以提供诊断时的重要依据，譬如，可以分析出线程挂起、死锁、资源瓶颈的原因。以及发生异常时的系统环境：譬如WAS当时有多少线程（每个线程的详细信息），当时的heap情况，JVM中止的原因（Cause of thread dump）。
如果系统默认情况下没有产生该javacore文件，可以在WAS控制台里，设置JVM的环境变量“IBM_HEAPDUMP=TRUE”。
如果想随时产生一个（譬如当前系统响应非常缓慢，你怀疑有线程挂起），可以通过“kill -3 <pid>”命令，产生一个javacore和heapdump。产生的javacore的命名规则和heapdump差不多，譬如javacore1347790.1181781840.txt，也就是javacore＋PID＋.＋系统时间。
附件截图是AIX下的BEA的WebLogic7.0、IBM的JVM，产生的javacore的分析结果。如果结合GC和Heap，就很容易分析出问题。
注意：可能大家用“kill -3 <pid>”命令时，并不能产生javacore文件，一般情况下，如果是AIX平台，可以执行：export DISABLE_JAVADUMP=true
再执行上面的kill命令，如果还是不行，请参考IBM的support文档：
http://www-1.ibm.com/support/docview.wss?rs=180&context=SSCMPB9&q1=MustGatherDocument&uid=swg21145345&loc=en_US&cs=utf-8&lang=en
可能有人报告说kill命令产生不了heapdump，请参考：
http://www-1.ibm.com/support/docview.wss?uid=swg21242497
另外，关于系统没有响应或是性能下降，可以参考IBM这篇文档来收集系统必要数据进行分析，我按文档的步骤做一遍，需要约半个小时的时间，非常麻烦：
http://www-1.ibm.com/support/docview.wss?rs=180&context=SSCMPB9&q1=MustGatherDocument&uid=swg21052641&loc=en_US&cs=utf-8&lang=en
zwchen
2007-06-22
to magic4u:谢谢你的建议！
从低级的GC的确可以发现部分问题，但不能确诊。因为大对象产生并不代表就一定有大对象问题，譬如IBM的console就经常创建大对象。我在文中的一个截图里（就是按Job调度引起OOM诊断时），发现这个现象（经常创建23M左右的大对象），不过当时没有警觉，因为在GC日志里面这类大对象创建很频繁。而且，创建大对象时，只要JVM heap里面有足够大的gap，或者expand heap可以进行，就不会出问题。
后来，我们干脆专门分出一个大对象区来存放Large of Object（LOA Area）。
我觉得，可以拿最后的结果，去印证某种推断，但结果未证实前，分析原始GC需要很高水平和耐心，因为GC动辄好几十M，几万行。
关于数据源，我当时WAS有四五个不同数据库的DataSource，在测试时是Spring里面配置的DBCP。
从低级的GC的确可以发现部分问题，但不能确诊。因为大对象产生并不代表就一定有大对象问题，譬如IBM的console就经常创建大对象。我在文中的一个截图里（就是按Job调度引起OOM诊断时），发现这个现象（经常创建23M左右的大对象），不过当时没有警觉，因为在GC日志里面这类大对象创建很频繁。而且，创建大对象时，只要JVM heap里面有足够大的gap，或者expand heap可以进行，就不会出问题。
后来，我们干脆专门分出一个大对象区来存放Large of Object（LOA Area）。
我觉得，可以拿最后的结果，去印证某种推断，但结果未证实前，分析原始GC需要很高水平和耐心，因为GC动辄好几十M，几万行。
关于数据源，我当时WAS有四五个不同数据库的DataSource，在测试时是Spring里面配置的DBCP。
magic4u
2007-06-22
另外关于Datasource的问题，我想有些误解，我建议的是，WAS管理所有的Datasource，不过每个应用使用各自的Datasource instance，在WAS配置中分别对各个Datasource进行connection pool配置。当然这个看个人爱好。
magic4u
2007-06-22
从初级GC是可以分析大对象的。
当JVM里面的GC选项打开后，会在native_stderr.log里面出现相关的内存回收信息。例如:
从上面的日志可以看出来，内存中有2359304bytes的对象创建，也就是一个对象有2M左右。
如果这样的大对象反复创建，（应用中代码实现狠容易出现这样的问题），狠容易出现频繁的垃圾回收。
当连续内存不能满足请求时，就会出现我们经常看到的JVM Hungup的情况。如下：
当JVM里面的GC选项打开后，会在native_stderr.log里面出现相关的内存回收信息。例如:
<AF[29]: Allocation Failure. need 524 bytes, 16044 ms since last AF> <AF[29]: managing allocation failure, action=0 (189649544/268433920)> <GC(29): GC cycle started Mon Jun 11 11:28:14 2007 <GC(29): freed 12219984 bytes, 75% free (201869528/268433920), in 94 ms> <GC(29): mark: 83 ms, sweep: 11 ms, compact: 0 ms> <GC(29): refs: soft 0 (age >= 32), weak 0, final 43, phantom 0> <AF[29]: completed in 95 ms> <AF[30]: Allocation Failure. need 2359304 bytes, 7545 ms since last AF> <AF[30]: managing allocation failure, action=2 (181553016/268433920)> <GC(30): GC cycle started Mon Jun 11 11:28:22 2007 <GC(30): freed 18561072 bytes, 74% free (200114088/268433920), in 92 ms> <GC(30): mark: 80 ms, sweep: 12 ms, compact: 0 ms> <GC(30): refs: soft 0 (age >= 32), weak 0, final 56, phantom 0> <AF[30]: completed in 93 ms> <AF[31]: Allocation Failure. need 1898608 bytes, 111086 ms since last AF> <AF[31]: managing allocation failure, action=2 (157454864/268433920)> <GC(31): GC cycle started Mon Jun 11 11:30:13 2007 <GC(31): freed 29256480 bytes, 69% free (186711344/268433920), in 105 ms> <GC(31): mark: 93 ms, sweep: 12 ms, compact: 0 ms> <GC(31): refs: soft 0 (age >= 32), weak 0, final 482, phantom 1> <AF[31]: completed in 110 ms>
从上面的日志可以看出来，内存中有2359304bytes的对象创建，也就是一个对象有2M左右。
如果这样的大对象反复创建，（应用中代码实现狠容易出现这样的问题），狠容易出现频繁的垃圾回收。
当连续内存不能满足请求时，就会出现我们经常看到的JVM Hungup的情况。如下：
<AF[14]: Allocation Failure. need 1179656 bytes, 943 ms since last AF> <AF[14]: managing allocation failure, action=2 (149244320/276298240)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor1(1009E630)> <GC(14): freeing class sun.reflect.GeneratedConstructorAccessor7(1034CF48)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor1(1035F5B8)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor3(10364C50)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor4(10364AC0)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor6(103663E0)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor7(10366C08)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor8(10366A78)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor9(103668E8)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor10(103670F8)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor11(10366F68)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor13(10367B20)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor14(10367990)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor15(1036EFE0)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor16(1036EE50)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor17(1036ECC0)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor18(1036EB30)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor19(1036E280)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor20(1036E0F0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor3(1036DF60)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor21(10370E90)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor22(10371BF8)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor23(103715B8)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor24(10376C00)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor25(10376A70)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor26(103768E0)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor27(10376750)> <GC(14): freeing class sun.reflect.GeneratedConstructorAccessor23(10376360)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor28(10378990)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor29(10378800)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor30(10378670)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor32(10378350)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor33(103781C0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor7(10377C08)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor34(10378FD8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor11(1037D9A8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor12(1037F010)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor13(1037EE80)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor17(1037FD30)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor18(1037FBA0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor19(1037FA10)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor23(10382EE8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor26(10384160)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor27(10383EA0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor30(10385260)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor35(102374B0)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor42(10238130)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor43(10238C00)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor44(10238940)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor36(103D7F40)> <GC(14): freeing class sun.reflect.GeneratedSerializationConstructorAccessor45(103DF4B0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor39(103EE788)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor46(103EC938)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor48(1041B1A8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor49(1041FA48)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor50(10420EC0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor51(10420D30)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor52(10421AD8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor53(10421948)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor54(104217B8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor55(10421628)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor56(10421368)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor57(104211D8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor58(10422128)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor59(10421F98)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor60(10421E08)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor61(10421C78)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor64(1042DBE0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor70(10430978)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor72(10459B90)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor73(1045F0C0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor74(1045EF30)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor75(1045EDA0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor76(1045E950)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor77(1045E7C0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor78(1045E630)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor79(1045E4A0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor80(1045E1E0)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor81(1045E050)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor82(10461148)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor83(10460FB8)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor84(10460E28)> <GC(14): freeing class sun.reflect.GeneratedMethodAccessor85(10460C98)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor2(1047CDA8)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor3(1047CC18)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor4(1047CA88)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor5(1047C8F8)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor6(1047C768)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor7(1047C5D8)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor8(1047C448)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor9(1047C2B8)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor10(1047C128)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor11(1047BF98)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor12(1047E050)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor13(1047DEC0)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor14(1047E4D0)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor15(1047EBB0)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor16(1047EA20)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor17(1047E890)> <GC(14): freeing class sun.reflect.GeneratedFieldAccessor18(10480168)> <GC(14): freeing class sun.reflect.GeneratedConstructorAccessor65(10488310)> <GC(14): unloaded and freed 101 classes> <GC(14): GC cycle started Mon Jun 11 10:58:06 2007 <GC(14): freed 31484232 bytes, 65% free (180728552/276298240), in 236 ms> <GC(14): mark: 97 ms, sweep: 16 ms, compact: 123 ms> <GC(14): refs: soft 34 (age >= 6), weak 0, final 199, phantom 1> <GC(14): moved 215615 objects, 12782856 bytes, IC reason=14> <AF[14]: completed in 249 ms> JVMDG217: Dump Handler is Processing a Signal - Please Wait. JVMDG303: JVM Requesting Java core file JVMDG304: Java core file written to C:\IBM\WebSphere\AppServer\javacore.20070611.105808.5220.txt JVMDG215: Dump Handler has Processed Exception Signal 11.
zwchen
2007-06-22
magic4u 写道
PS，如果我没有理解错误，WAS服务器上所有应用共用一个datasource，用来减少数据库的连接。这样的方法不可取。还是建议每个应用使用自己的datasource，虽然配置麻烦，但是相对隔离还是比较好的。
另外，JDK的升级，最好还是先考虑考虑。特别对于64位操作系统上，安装64位JDK，对于内存分配会好很多。
另外，JDK的升级，最好还是先考虑考虑。特别对于64位操作系统上，安装64位JDK，对于内存分配会好很多。
1、我们开始是每个应用有自己的datasource，但二三十个应用，所有的DB Connection加起来就有好几百，DB2根本受不了。我们开始是你说的这样的，最后改成WAS公共的DataSource，效果好多了，DB2稳定，程序也稳定些。
另外，用WAS的DataSource有个很大的好处，就是可以跟踪数据库连接情况，譬如连接池泄漏的问题很容易发现（从WAS控制台一眼可以看出来），定位也容易些，这是两个很重要的IBM技术支持链接（虽然是针对WAS5.1）：
http://www-1.ibm.com/support/docview.wss?uid=swg21203225
http://www-1.ibm.com/support/docview.wss?uid=swg21217062
2、我们是64位AIX，不能用32位JDK。
zwchen
- 浏览: 179452 次
- 性别:
- 来自: 大连
- 详细资料
搜索本博客
我的相册
共 1 张
最近加入圈子
最新评论
-
辞职感言
回家从不开机，除了看电影时
-- by shxiao -
辞职感言
bcccs 写道fyting 写道metaphy 写道fyting 写道我遇到过 ...
-- by zhangxi123 -
辞职感言
我现在在公司开Eclipse, 在家开gcc, 写C有种让脑袋运动的感觉, 写J ...
-- by 。。。 -
辞职感言
metaphy 写道fyting 写道我遇到过更奇怪的事情: 一天我和某同事吃饭 ...
-- by hardPass -
Frameset引起的内部第三方 ...
我是ie7.问题解决不了
-- by defier
评论排行榜