一.摘要
此文档描述XXX年X月XX日XX局YY系统中间件weblogic服务器cpu100%问题,从现场取得server日记,和所做线程快照,以及根据Oracle原厂的指导建议,现进行故障分析,并提出解决方案。
二.故障分析
2.1 域基本配置信息
......
2.2 故障表象描述
中间件服务器CPU异常100%,影响业务正常使用,重启中间件服务器后回复正常。一定时间以后,CPU又达到100%,影响业务正常使用。
2.3 故障影响
营销系统应用访问缓慢,部分用户无法访问应用。
2.4 分析过程
登录linux系统,用top命令,查看cpu使用相关情况,找到占用cpu高的进程。其中server01,server03等的进程占用cpu非常高。针对server01,server03,继续分析。
获取server01,server03的日记文件server01.log、server03.log。并对server01、server03对应的进程,做线程快照,得到文件server01threaddump127.out、server03threddump127.out。
分析日记文件,及线程快照文件,锁定问题。
从线程快照文件中,发现了大量的stuck线程,并且都有相似的堆栈,都是在调用HashMap.put方法时出现问题。导致线程超时挂起,进而导致cpu使用率异常高。
"[STUCK] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" id=14 idx=0x70 tid=6582 prio=1 alive, daemon
at java/util/HashMap.put(HashMap.java:1681)[optimized]
at java/util/HashSet.add(HashSet.java:194)[inlined]
at weblogic/rmi/internal/dgc/DGCServerImpl.addPhantomRef(DGCServerImpl.java:136)[inlined]
at weblogic/rmi/internal/BasicServerRef.getLocalRef(BasicServerRef.java:729)[inlined]
at weblogic/rmi/internal/BasicServerRef.getStubReference(BasicServerRef.java:709)[optimized]
at weblogic/rmi/internal/OIDManager.getReplacement(OIDManager.java:180)[inlined]
at weblogic/rmi/extensions/StubFactory.getStub(StubFactory.java:62)[inlined]
at weblogic/jdbc/rmi/internal/PreparedStatementImpl.interopWriteReplace(PreparedStatementImpl.java:59)[optimized]
at weblogic/rmi/utils/io/InteropObjectReplacer.replaceObject(InteropObjectReplacer.java:43)[optimized]
at weblogic/utils/io/ChunkedObjectOutputStream.replaceObject(ChunkedObjectOutputStream.java:42)[inlined]
at weblogic/utils/io/ChunkedObjectOutputStream$NestedObjectOutputStream.replaceObject(ChunkedObjectOutputStream.java:151)[optimized]
at java/io/ObjectOutputStream.writeObject0(ObjectOutputStream.java:1045)[inlined]
at java/io/ObjectOutputStream.writeObject(ObjectOutputStream.java:302)[optimized]
at weblogic/rjvm/MsgAbbrevOutputStream.writeObject(MsgAbbrevOutputStream.java:614)
at weblogic/utils/io/ChunkedObjectOutputStream.writeObject(ChunkedObjectOutputStream.java:73)[optimized]
at weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_PoolConnection_oracle_jdbc_driver_T4CConnection_WLSkel.internalInvoke1(ILweblogic/rmi/spi/InboundRequest;Lweblogic/rmi/spi/OutboundResponse;Ljava/lang/Object;)Lweblogic/rmi/spi/OutboundResponse;(Unknown Source)
at weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_PoolConnection_oracle_jdbc_driver_T4CConnection_WLSkel.invoke(ILweblogic/rmi/spi/InboundRequest;Lweblogic/rmi/spi/OutboundResponse;Ljava/lang/Object;)Lweblogic/rmi/spi/OutboundResponse;(Unknown Source)
at weblogic/rmi/internal/BasicServerRef.invoke(BasicServerRef.java:553)[optimized]
at weblogic/rmi/internal/BasicServerRef$1.run(BasicServerRef.java:443)[inlined]
at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:363)[inlined]
at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:147)[inlined]
at weblogic/rmi/internal/BasicServerRef.handleRequest(BasicServerRef.java:439)[inlined]
at weblogic/rmi/internal/BasicServerRef.access$300(BasicServerRef.java:61)[inlined]
at weblogic/rmi/internal/BasicServerRef$BasicExecuteRequest.run(BasicServerRef.java:983)[optimized]
at weblogic/work/ExecuteThread.execute(ExecuteThread.java:209)[optimized]
at weblogic/work/ExecuteThread.run(ExecuteThread.java:181)
at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
-- end of trace
与Oracle原厂进行沟通,进一步锁定问题确实是HashMap方法的bug。HashMap方法是针对单线程的,在weblogic9.2.3 版本下的HashMap方法存在bug、兼容性不高,在多线程模式下容易出现stuck状态,HashMap本身在多个线程同时做get/put/remove等操作的时候,由于synchronize方面
的局限,会出现锁。
B:你好!
A- 早于 1 小时前 [Update from Customer]
您好,
发生hashmap的那个线程,为什么会持有锁,持有之后,为什么没有正常释放?
Oracle 技术支持 - 早于 1 小时前 [Call - Outbound]
Call - Outbound
------------------------------
1,向用户说明如何查找和下载补丁;
2,hashMap本身的同步存在问题,因此在多线程操作时可能会被触发。建议在应用代码中尽量避免hashMap的使用。
从目前的stacktrace看,weblogic/rmi/internal/dgc/DGCServerImpl.addPhantomRef(DGCServerImpl.java)本身用到HashMap,补丁中用concurrentHashMap替换。
A - 早于 1 小时前 [Update from Customer]
Bug 8311369 这个bug找不到下载补丁链接
A - 早于 1 小时前 [Update from Customer]
您好,
您的这个解释只是简单说了一下,hashmap相关的机理。但是详细的触发原因,并未解释。客户这边以前并没有出现问题,只是更新了一些应用之后,才开始出现问题。有没有更详细的触发点?
Oracle 技术支持 - 早于 1 小时前 [Notes]
您好,
请参考我们之前的更新,第一个的stackTrace与目前的threaddump最为类似。后面两个可以一并打上。
>>>>>
Bug 8178661 -- Adding phantomRef to concurrentHashMap to fix stuck threads
Bug 8311369 -- support the concurrent access to the hash map in ApplicationContextImpl
Bug 9322540 -- CPU USAGE RATE BECOMES HIGHER AT HASHMAP.PUT
<<<<<<
Bug中的stacktrace,供您参考:
@ '[STUCK] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning) ''id=21 idx=0x6c tid=2544 prio=1 alive, daemon
@ at java/util/HashMap.put(HashMap.java:1681)
@ at java/util/HashSet.add(HashSet.java:194)
@ at weblogic/rmi/internal/dgc/DGCServerImpl.addPhantomRefDGCServerImpl.java:136)
@ at weblogic/rmi/internal/BasicServerRef.getLocalRefBasicServerRef.java:729)
@ at weblogic/rmi/internal/BasicServerRef.getStubReferenceBasicServerRef.java:709)
@ at weblogic/rmi/internal/OIDManager.getReplacement(OIDManager.java:180)
@ at weblogic/rmi/extensions/StubFactory.getStub(StubFactory.java:62)
@ at weblogic/jdbc/rmi/internal/CallableStatementImpl.interopWriteReplace(CallableStatementImpl.java:57)
@ at weblogic/rmi/utils/io/InteropObjectReplacer.replaceObjectInteropObjectReplacer.java:43)
@ at weblogic/utils/io/ChunkedObjectOutputStream.replaceObjectChunkedObjectOutputStream.java:42)
@ at weblogic/utils/io/ChunkedObjectOutputStream$NestedObjectOutputStream.replaceObject(ChunkedObjectOutputStream.java:151)
@ at java/io/ObjectOutputStream.writeObject0(ObjectOutputStream.java:1045) [inlined]
@ at java/io/ObjectOutputStream.writeObject(ObjectOutputStream.java:302) [optimized]
@ at weblogic/rjvm/MsgAbbrevOutputStream.writeObject(MsgAbbrevOutputStream.java:614)
@ at weblogic/utils/io/ChunkedObjectOutputStream.writeObject(ChunkedObjectOutputStream.java:73)
@ at weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_PoolConnection_oracle_jdbc_driver_T4CConnection_WLSkel.internalInvoke1ILweblogic/rmi/spi/InboundRequest;Lweblogic/rmi/spi/OutboundResponse;Ljava/lang/Object;)Lweblogic/rmi/spi/OutboundResponse;(Unknown Source)
@ at weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_PoolConnection@ _oracle_jdbc_driver_T4CConnection_WLSkel.invokeILweblogic/rmi/spi/InboundRequest;Lweblogic/rmi/spi/OutboundResponse;Ljava/lang/Object;)Lweblogic/rmi/spi/OutboundResponse;(UnknownSource)
这并没有什么详细的触发点,应该说就是JDK本身的问题。
A - 早于 1 小时前 [Update from Customer]
您好,
如果打补丁的话,总共有多少补丁,可以给我一个详细的列表吧。
A - 早于 1 小时前 [Update from Customer]
您好,
您的这个解释只是简单说了一下,hashmap相关的机理。但是详细的触发原因,并未解释。客户这边是开始并没有出现问题,只是更新了一些应用之后,才开始出现问题。有没有更详细的触发点?
Oracle 技术支持 - 早于 2 小时前 [Call - Inbound]
Call - Inbound
----------------------------
您好,
由于小版本的不同,所以bug的stackTrace与实际收集的threaddump中的stacktrace可能有一些小的差别,这是我们说‘类似’的原因。
Hashmap本身在多个线程同时做get/put/remove等操作的时候,由于synchronize方面的局限,会出现锁。实际上目前的版本中一般都已经用concurrentHashMap取代。
但是由于WLS923不会再出新的补丁,所以我们建议把与hashmap有关的类似补丁打上,以尽量避免问题。
A - 早于 2 小时前 [Update from Customer]
你好!
这个类似的bug客户那边不太认可,需要进一步分析是哪部分触发所导致的,需要哪方面的信息我们这边会尽快提供。
Oracle 技术支持 - 早于 3 小时前 [Call - Outbound]
Template Question Responses
---------------------------------------------------
1) Describe how this problem is impacting your business. Include relevant information such as critical events (i.e., upgrade or project milestones), dates (i.e., go live dates), number of users affected, financial impact, etc.
weblogic version : 9.2.3.0
jdk version: 1.5
三.故障原因
根据上述有关分析,造成本次故障的根本原因是hashmap方法是针对单线程的,在weblogic9.2.3 版本下的hashmap方法存在bug、兼容性不高,在多线程模式下容易出现stuck状态,Hashmap本身在多个线程同时做get/put/remove等操作的时候,由于synchronize方面的局限,会出现锁。
实际上目前的版本中一般都已经用concurrentHashMap取代。但是由于WLS923不会再出新的补丁,所以我们建议把与hashmap有关的类似补丁打上,以尽量避免问题。
在以往的运行环境中由于线程同步操作hashmap未达到触发条件,因此在原来的运行环境中出现故障的几率比较小,据应用厂家反馈133和135服务器在5月份时曾出现过cpu使用率100%的现象。在目前新增一台服务器的机群环境中,在遇到营销系统计划任务程序执行大量的线程数时,触发weblogic的hashmap的bug,产生大量的stuck状态的线程,引起大量线程阻塞在获取锁的过程中,从而导致cpu运行占用率非常高。
四.故障解决方案
oracle原厂建议给weblogic 9.2.3这个版本打上3个补丁p8178661_923_Generic.zip、p8311369_923_Generic.zip、p9322540_923_Generic.zip,将用concurrentHashMap替换HashMap使用。
安装补丁的步骤:
对WLS_HOME全备份、并停掉此WLS_HOME下的所有java进程。
查看此weblogic的版本
通过如下命令,进行查看:
$ . $WL_HOME/server/bin/setWLSEnv.sh
$ java weblogic.version
查看此weblogic所安装的补丁集。
通过如下命令,进行查看:
cd $WL_HOME/utils/bsu
./bsu.sh -prod_dir=<weblogic_home> -patch_download_dir=<download dir of patch> -status=applied -verbose -view
For example:
./bsu.sh -prod_dir=/opt/bea/weblogic92 -status=applied -verbose -view
安装补丁
执行如下命令,进行安装:
cd {MW_HOME}/utils/bsu directory.
./bsu.sh -install -patch_download_dir={MW_HOME}/utils/bsu/cache_dir -patchlist={PATCH_ID} -prod_dir={MW_HOME}/{WL_HOME}
2、hashMap本身的同步存在问题,因此在多线程操作时可能会被触发。建议在应用代码中尽量避免hashMap的使用。