WAS宕机的日志收集及分析用友软件股份有限公司NC技术支持部2011-12-16日目录目录一WAS宕机的现象二WAS宕机的几类原因三WAS宕机时收集那些相关信息四WAS宕机时如何获取信息五WAS宕机日志的分析1、登录NC系统时，访问不了或者系统悬停，停止响应。2、NC系统开始使用正常，过一段时间后，越来越慢，总后访问不了。3、登录NC系统时，有时登录可以正常访问，有时登录不进去，再次登录时又能登录到NC使用等。……………WAS宕机的现象根据WAS宕机的现象，简单分为下面的情况：1、因为outofmemory导致的系统down机。2、WAS或NC系统造成的宕机。3、其它异常导致的系统down机。……………………………….WAS宕机的几类原因WAS宕机时收集那些相关信息1、WAS本身的日志信息：../profiles/Appsrv01/logs/server名下所有日志如\IBM\AppServer\profiles\AppSrv01\logsGc垃圾收集信息native_stderr.log如：IBM\AppServer\profiles\AppSrv01\logs\ncMem01\native_stdout.log2、HTTPServer与Plugin日志信息../logs下相关日志如:\IBM\HTTPServer\logs\IBM\HTTPServer\Plugins\logs3、当前时刻线程状态信息线程当前运行状态信息日志：JavaCore文件NMC监控工具可以生成4、当前时刻java内存堆信息当前java进程内存堆信息：heapdump*.phd文件NMC监控工具可以生成5、NMC中的消息及快照信息WAS宕机时收集那些相关信息6、java虚拟机内存信息、连接池信息Was控制台性能监控模块NC目录下Sysmonitor工具NMC监控工具7、超长sql语句信息NC日志系统、NC目录下Sysmonitor工具可设置NMC监控工具8、cpu利用率、内存使用情况操作系统命令9、系统磁盘IO、网络IO、页交换情况操作系统命令WAS宕机时如何获取信息1、如何获取WASGC内存垃圾收集信息服务器>应用服务器>server1（或自定义服务器名）>JAVA和进程管理>进程定义>Java虚拟机>选中详细垃圾回收选项日志输出native_stderr.log中如\IBM\AppServer\profiles\AppSrv01\logs\native_stderr.logWAS宕机时如何获取信息2、如何获取当前线程状态信息（javacore文件）方式一：was命令（1）：wsadmin>setjvm[$AdminControlcompleteObjectNametype=JVM,process=server1,*]（2）：wsadmin>$AdminControlinvoke$jvmdumpThreads进入wsadmin如was启用了安全，需要输入有登录was控制台的用户名及密码D:\IBM\WebSphere\AppServer\bin>wsadmin-userwasadmin-passwordpassword生成javacore设置jvm环境变量::---server1是was中的服务器名或者was集群中的成员名，如ncMem01等wsadmin>setjvm[$AdminControlcompleteObjectNametype=JVM,process=server1,*]生成javacore文件:wsadmin>$AdminControlinvoke$jvmdumpThreads方式二：操作系统命令Unix下：kill-3PIDWindows下：在当前进程dos窗口运行ctrl+break;或者运用工具SendSignal.exePID(注：在当前java进程dos窗口生成线程堆栈信息）WAS宕机时如何获取信息3、如何获取java内存堆信息（heapdump文件）（1）．找到JVM对象名字。wsadmin>setobjectNameWebSphere:type=JVM,process=,node=<节点名字>,*]（2）．对JVMMBean调用generateHeapDump操作。$AdminControlinvoke$objectNamegenerateHeapDump如：生成heapdump找到JVM对象名字:---server1是was中的服务器名或者was集群中的成员名，如ncMem01等wsadmin>setobjectName[$AdminControlqueryNamesWebSphere:type=JVM,process=server1,*]生成heapdump文件:wsadmin>$AdminControlinvoke$objectNamegenerateHeapDumpWAS宕机时如何获取信息生成javacore和heapdump例子:D:\IBM\AppServer\profiles\AppSrv01\bin>wsadmin.batWASX7209I:使用SOAP连接器连接到节点javavagNode01上的进程“server1”；进程的类型为：UnManagedProcessWASX7029I:要获取帮助，请输入：“$Helphelp”wsadmin>setjvm[$AdminControlcompleteObjectNametype=JVM,process=server1,*]WebSphere:name=JVM,process=server1,platform=proxy,node=javavagNode01,j2eeType=JVM,J2EEServer=server1,version=6.1.0.11,type=JVM,mbeanIdentifier=JVM,cell=javavagNode01Cell,spec=1.0wsadmin>$AdminControlinvoke$jvmdumpThreads生成的javacore位置为:D:\IBM\AppServer\profiles\AppSrv01\javacore.20090410.153958.3564.txtwsadmin>setobjectName[$AdminControlqueryNamesWebSphere:type=JVM,process=server1,*]WebSphere:name=JVM,process=server1,platform=proxy,node=javavagNode01,j2eeType=JVM,J2EEServer=server1,version=6.1.0.11,type=JVM,mbeanIdentifier=JVM,cell=javavagNode01Cell,spec=1.0wsadmin>$AdminControlinvoke$objectNamegenerateHeapDumpwsadmin>生成的Heapdump文件位置为:D:\IBM\AppServer\profiles\AppSrv01\heapdump.20090410.154059.3564.phdWAS宕机时如何获取信息4、NMC中生成JAVACORE和Heapdump方法Dumpthread:对选择中的Server生成Dumpthread。DumpHeap:对选择中的Server生成DumpHeap。WAS宕机时如何获取信息5、NMC中的消息及快照信息在NMC客户端消息中心将宕机对应时间段的消息及快照信息抓取出来。或者消息从服务器上同步到客户端后，将\nmc\client\logdb\logdb.mdb文件收集上来。WAS宕机日志的分析Heapdump分析:分析工具:ha23.jar是分析heapdump的工具包\java\bin>java-Xmx3000M-jarha23.jarWAS宕机日志的分析Heapdump分析:WAS宕机日志的分析Heapdump常常和javacore结合在一起,如在上面heapdump中看到的DapGetRtVouc业务，在对应的javacore文件中也记录了nc/bs/dap/out/DapGetRtVouch.createRtVouch的调用情况,针对该项目是应收应付中核销数据多,核销完后,生成实时凭证时数据量太大(占用1.9G左右内存)造成的。找对应的开发处理。……………………………3XMTHREADINFO"WebContainer:13"(TID:0x000000002B0C9100,sys_thread_t:0x000000001536BE80,state:CW,nativeID:0x0000000000000D90)prio=54XESTACKTRACEatnc/bs/dap/out/DapGetRtVouch.createRtVouch(DapGetRtVouch.java:1204(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.createRtVouch(DapBO.java:549(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.procAddMessage(DapBO.java:1647(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.addMessage(DapBO.java:236(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.sendDapMessage(DapBO.java:3083(CompiledCode))4XESTACKTRACEatnc/impl/dap/pub/DapPubBS.sendMessage(DapPubBS.java:192(CompiledCode))4XESTACKTRACEatnc/gejb/fip/cmt/FipDAPEJBEjbBean.sendMessage(FipDAPEJBEjbBean.java:271(CompiledCode))Heapdump分析:WAS宕机日志的分析JAVACORE分析:JAVACORE的组成：TITLE信息块：描述JAVACORE产生的原因，时间以及文件的路径。GPINFO信息块：GPF信息。GPF是GeneralProtectionFault的缩写，表明应用程序发生了一般性保护错误，这种错误常常导致JVM突然崩溃。ENVINFO信息块：系统运行时的环境及JVM启动参数。MEMINFO信息块：内存的使用情况和垃圾回收记录。LOCKS信息块：用户监视器(Monitor)和系统监视器(Monitor)。THREADS信息块：所有java线程的状态信息和执行堆栈。CLASSES信息块：类加载信息。表示系统中有哪些Class类被加载进来。下面将我们遇到的几种情况做简单介绍：WAS宕机日志的分析JAVACORE分析:TITLE信息块：描述JAVACORE产生的原因，时间以及文件的路径。内存溢出：OutOfMemoryError从javacore中可以看到内存溢出OutOfMemoryErrorNULL------------------------------------------------------------------------0SECTIONTITLEsubcomponentdumproutineNULL===============================1TISIGINFODumpEvent"systhrow"(00040000)Detail"java/lang/OutOfMemoryError"received1TIDATETIMEDate:2011/11/30at09:54:57同时从下面的自由内存也可以看出内存已经使用完了-------------------------0SECTIONMEMINFOsubcomponentdumproutineNULL=================================1STHEAPFREEBytesofHeapSpaceFree:0------0M1STHEAPALLOCBytesofHeapSpaceAllocated:80000000-----2048M对于这样的问题，如果JAVA的最大堆已经设置为2048,则需要和heapdump配合找到是哪个业务造成的内存溢出。WAS宕机日志的分析JAVACORE分析:线程无法创建在javacore文件最上面会出现内存溢出的信息如下图，但是除了outofmemory之外还附带了一个信息：failedtoforkOSthread,这个信息很重要,这个信息表明操作系统无法创建线程。该问题是java在32位操作系统上创建线程受限制问题。需要升级到64位操作系统。WAS宕机日志的分析LOCKS信息块：用户监视器(Monitor)和系统监视器(Monitor)。0SECTIONLOCKSsubcomponentdumproutineNULL===============================NULL1LKPOOLINFOMonitorpoolinfo:2LKPOOLTOTALCurrenttotalnumberofmonitors:128NULL1LKMONPOOLDUMPMonitorPoolDump(flat&inflatedobject-monitors):2LKMONINUSEsys_mon_t:0x0000000009C25C58infl_mon_t:0x0000000009C25CD8:3LKMONOBJECTorg/eclipse/osgi/framework/eventmgr/EventManager$EventThread@00000000135EC710/00000000135EC728:3LKNOTIFYQWaitingtobenotified:3LKWAITNOTIFY"FrameworkEventDispatcher"(0x0000000004D70100)2LKMONINUSEsys_mon_t:0x0000000009C25DA8infl_mon_t:0x0000000009C25E28:3LKMONOBJECTorg/eclipse/osgi/framework/eventmgr/EventManager$EventThread@0000000013603758/0000000013603770:3LKNOTIFYQWaitingtobenotified:JAVACORE分析:WAS宕机日志的分析THREADS信息块：所有java线程的状态信息和执行堆栈。线程一般处于state:CW,state:B和state:R状态。CW-ConditionWait:条件等待.这种等待一般是线程主动等待或者正在进行某种IO操作，而并非等待其它线程释放资源。比如sleep()，wait()，join()等方法的调用。B-Blocked:线程被阻塞，与条件等待不同，线程被阻塞一般不是线程主动进行的，而是由于当前线程需要的资源正在被其他线程占用，因此不得不等待资源释放以后才能继续执行，例如synchronized代码块。state:R表示runnable。0SECTIONTHREADSsubcomponentdumproutine……………………………3XMTHREADINFO"WebContainer:13"(TID:0x000000002B0C9100,sys_thread_t:0x000000001536BE80,state:CW,nativeID:0x0000000000000D90)prio=54XESTACKTRACEat-----应收应付中核销数据nc/bs/dap/out/DapGetRtVouch.createRtVouch(DapGetRtVouch.java:1204(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.createRtVouch(DapBO.java:549(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.procAddMessage(DapBO.java:1647(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.addMessage(DapBO.java:236(CompiledCode))4XESTACKTRACEatnc/bs/dap/out/DapBO.sendDapMessage(DapBO.java:3083(CompiledCode))4XESTACKTRACEatnc/impl/dap/pub/DapPubBS.sendMessage(DapPubBS.java:192(CompiledCode))4XESTACKTRACEatnc/gejb/fip/cmt/FipDAPEJBEjbBean.sendMessage(FipDAPEJBEjbBean.java:271(CompiledJAVACORE分析:JAVACORE分析:CLASSES信息块：类加载信息。表示系统中有哪些Class类被加载进来.。加载的class过多:WAS宕机日志的分析如某项目WAS中间件JAVA进程使用内存不停上涨问题:WAS中间件启动后，JAVA进程使用的内存一直上涨到2G,3G...直到服务器死机。问题解决：在生成的javacore文件中,Classloader有90多万行，文件大小为80M左右，正常情况下只有几万行，文件大小为几M左右。检查nchome/modules目录，发现在modules目录下有一个同样的目录modules,导致NC部署到WAS里面后类加载陷入死循环，最终加载了90多万个类导致！删除该目录，再重新生成部署，重新启动WAS后正常。类循环加载的现象如下:0SECTIONCLASSESsubcomponentdumproutineNULL=================================1CLTEXTCLLOSClassloadersummaries………………………………………..2CLTEXTCLLOADLoadernc/bs/framework/loading/ModuleVarClassLoader(0x0000000052D74FA8)2CLTEXTCLLOADLoadernc/bs/framework/loading/ModulePrivateClassLoader(0x0000000052D76AD0)2CLTEXTCLLOADWAS宕机日志的分析JAVACORE分析:分析工具:jca14.jar是分析javacore的工具包\java\bin>java-Xmx256M-jarjca14.jarWAS宕机日志的分析WAS宕机日志的分析
