solaris10/weblogic9测试weblogic进程占用 CPU高

慧9建

部署一个造成CPU高的应用后进行如下操作：

-bash-3.00# prstat -L -p 550 1 1
   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/LWPID      
   550 root      568M  382M run     10    0   0:01:19  97% java/14   
   550 root      568M  382M sleep   59    0   0:00:11 0.1% java/2
   550 root      568M  382M sleep   59    0   0:00:02 0.0% java/8
   550 root      568M  382M sleep   59    0   0:00:03 0.0% java/20
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/13
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/22
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/10
   550 root      568M  382M sleep   59    0   0:00:02 0.0% java/6
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/33
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/32
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/31
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/30
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/28
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/29
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/26
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/25
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/24
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/23
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/21
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/19
   550 root      568M  382M sleep   59    0   0:00:09 0.0% java/18
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/17
   550 root      568M  382M sleep   59    0   0:00:11 0.0% java/16
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/15
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/12
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/11
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/9
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/7
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/5
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/4
   550 root      568M  382M sleep   59    0   0:00:00 0.0% java/3
   550 root      568M  382M sleep   59    0   0:00:04 0.0% java/1

可以看到LWPID为14的线程占用CPU特高


-bash-3.00# pstack 550
550:/usr/jdk/instances/jdk1.5.0/bin/java -client -Xms256M -Xmx256M -Xverif
-----------------  lwp# 1 / thread# 1  --------------------
d2afaaf5 lwp_cond_wait (8075810, 80757f8, 0, 0)
d26b7bfc __1cCosHSolarisFEventEpark6M_v_ (80757d0) + 4c
d26b72a6 __1cNObjectMonitorEwait6MxipnGThread__v_ (812618c, 0, 0, 1, 8074c10) + 346
d26b6c20 __1cSObjectSynchronizerEwait6FnGHandle_xpnGThread__v_ (80751b0, 0, 0, 8074c10) + 70
d26b6974 JVM_MonitorWait (8074cd0, 8046220, 0, 0, 80461ec, aa200298) + 234
cd00806d * java/lang/Object.wait(J)V+0
cd002b3b * java/lang/Object.wait()V+2 (line 474)
cd002b3b * weblogic/t3/srvr/T3Srvr.waitForDeath()V+46 (line 730)
cd002b3b * weblogic/t3/srvr/T3Srvr.run([Ljava/lang/String;)I+120 (line 380)
cd002a8f * weblogic/Server.main([Ljava/lang/String;)V+43 (line 67)
cd000214 * StubRoutines (1)
d26a8d97 __1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_ (80464d0, 80463d8, 8046408, 8074c10, 80463cc, d26a8be8) + 187
d26a8c04 __1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_ (d26a8c10, 80464d0, 80463d8, 8046408, 8074c10) + 14
d26a8be8 __1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_ (80464d0, 80751a4, 8046408, 8074c10) + 28
d26b9f40 __1cRjni_invoke_static6FpnHJNIEnv__pnJJavaValue_pnI_jobject_nLJNICallType_pnK_jmethodID_pnSJNI_ArgumentPusher_pnGThread__v_ (8074cd0, 80464d0, 0, 0, 8072049, 80464dc) + 180
d271d52c jni_CallStaticVoidMethod (8074cd0, 8075704, 8072049, 8075714) + 14c
08051e87 main     (0, 806fba8, 8046de4) + af4
080512fa ???????? (13, 8046f38, 8046f5d, 8046f65, 8046f6e, 8046f77) + 80512fa

……………………………………………………

-----------------  lwp# 14 / thread# 14  --------------------
d2387a2f ???????? (53a4da98, bfd4bec3) + 2599
d2385496 ???????? (54442d18, 400921fb) + 5450
d2380046 Java_java_lang_StrictMath_exp (841d718, c5e1a824, 54442d18, 400921fb, c5e1a828, 6eb09339) + 26
cd7a3403 * *java/lang/StrictMath.exp(D)D+0
cd7a362b * *java/lang/Math.exp(D)D+1 (line 237)
cd7a362b * *tdy218/alg/DeadLoop.service(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;)V+3 (line 17)
cd071c80 * tdy218/alg/DeadLoop.service(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;)V+0
cd002b3b * javax/servlet/http/HttpServlet.service(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V+30 (line 856)
cd715ac6 * *weblogic/servlet/internal/StubSecurityHelper$ServletServiceAction.run()Ljava/lang/Object;+43 (line 227)
cd716ad8 * *weblogic/servlet/internal/StubSecurityHelper.invokeServlet(Ljavax/servlet/ServletRequest;Ljavax/servlet/http/HttpServletRequest;Lweblogic/servlet/internal/ServletRequestImpl;Ljavax/servlet/ServletResponse;Ljavax/servlet/http/HttpServletResponse;Ljavax/ser+110 (line 125)
cd71a7ae * *weblogic/servlet/internal/ServletStubImpl.execute(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;Lweblogic/servlet/internal/FilterChainImpl;)V+295 (line 283)
cd72be8e * *weblogic/servlet/internal/ServletStubImpl.execute(Ljavax/servlet/ServletRequest;Ljavax/servlet/ServletResponse;)V+4 (line 175)
cd06bd80 * alignment_frame_return Runtime1 stub
cd002b3b * weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.run()Ljava/lang/Object;+164 (line 3244)
cd760cc8 * *weblogic/security/acl/internal/AuthenticatedSubject.doAs(Lweblogic/security/subject/AbstractSubject;Ljava/security/PrivilegedAction;)Ljava/lang/Object;+34 (line 321)
cd06bd80 * alignment_frame_return Runtime1 stub
cd002a64 * weblogic/security/service/SecurityManager.runAs(Lweblogic/security/acl/internal/AuthenticatedSubject;Lweblogic/security/acl/internal/AuthenticatedSubject;Ljava/security/PrivilegedAction;)Ljava/lang/Object;+18 (line 121)
cd002a64 * weblogic/servlet/internal/WebAppServletContext.securedExecute(Ljavax/servlet/http/HttpServletRequest;Ljavax/servlet/http/HttpServletResponse;Z)V+277 (line 2010)
cd002b3b * weblogic/servlet/internal/WebAppServletContext.execute(Lweblogic/servlet/internal/ServletRequestImpl;Lweblogic/servlet/internal/ServletResponseImpl;)V+270 (line 1916)
cd002b3b * weblogic/servlet/internal/ServletRequestImpl.run()V+215 (line 1366)
cd6bacce * *weblogic/work/ExecuteThread.execute(Ljava/lang/Runnable;)V+29 (line 209)
cd06bd80 * alignment_frame_return Runtime1 stub
cd002b3b * weblogic/work/ExecuteThread.run()V+42 (line 181)
cd000214 * StubRoutines (1)
d26a8d97 __1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_ (c5e1ae58, c5e1ad50, c5e1adb4, 841d658, c5e1ad44, d26a8be8) + 187
d26a8c04 __1cCosUos_exception_wrapper6FpFpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v2468_v_ (d26a8c10, c5e1ae58, c5e1ad50, c5e1adb4, 841d658) + 14
d26a8be8 __1cJJavaCallsEcall6FpnJJavaValue_nMmethodHandle_pnRJavaCallArguments_pnGThread__v_ (c5e1ae58, 83529c0, c5e1adb4, 841d658) + 28
d26b664e __1cJJavaCallsMcall_virtual6FpnJJavaValue_nLKlassHandle_nMsymbolHandle_4pnRJavaCallArguments_pnGThread__v_ (c5e1ae58, 83529b4, d29eb47c, d29eb550, c5e1adb4, 841d658) + be
d26b657d __1cJJavaCallsMcall_virtual6FpnJJavaValue_nGHandle_nLKlassHandle_nMsymbolHandle_5pnGThread__v_ (c5e1ae58, 83529b0, 83529b4, d29eb47c, d29eb550, 841d658) + 6d
d26b64f0 __1cMthread_entry6FpnKJavaThread_pnGThread__v_ (841d658, 841d658) + d0
d26b63f1 __1cKJavaThreadRthread_main_inner6M_v_ (841d658) + 51
d26b6395 __1cKJavaThreadDrun6M_v_ (841d658) + 105
d28d0552 __1cG_start6Fpv_0_ (841d658) + d2
d2af7055 _thr_setup (cfa86200) + 4e
d2af7340 _lwp_start (cfa86200, 0, 0, c5e1aff8, d2af7340, cfa86200)


可以看到LWP为14的在进行DeadLoop.service操作

做下thread dump
把14转化为16进制，找到对应的nid

如下：
"[ACTIVE] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x0841d658 nid=0xe runnable [0xc5e1a000..0xc5e1acb8]
        at java.lang.StrictMath.exp(Native Method)
        at java.lang.Math.exp(Math.java:237)
        at tdy218.alg.DeadLoop.service(DeadLoop.java:17)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
        at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
        at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
        at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:283)
        at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:175)
        at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3244)
        at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
        at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:121)
        at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2010)
        at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:1916)
        at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1366)
        at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
        at weblogic.work.ExecuteThread.run(ExecuteThread.java:181)

再次验证是在进行DeadLoop.service操作

另外，从server日志里也能看到：

####<Feb 24, 2010 11:01:31 AM EST> <Error> <WebLogicServer> <solaris10> <AdminServer> <[ACTIVE] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1267027291184> <BEA-000337> <[STUCK] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "655" seconds working on the request "Http Request: /DeadLoop.jspx", which is more than the configured time (StuckThreadMaxTime) of "600" seconds. Stack trace:
java.lang.StrictMath.exp(Native Method)
java.lang.Math.exp(Math.java:237)
tdy218.alg.DeadLoop.service(DeadLoop.java:17)
javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:227)
weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:125)
weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:283)
weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:175)
weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3244)
weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
weblogic.security.service.SecurityManager.runAs(SecurityManager.java:121)
weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2010)
weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:1916)
weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1366)
weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
weblogic.work.ExecuteThread.run(ExecuteThread.java:181)
>