weblogic程式高CPU使用率分析

quanshengaa發表於2015-11-06

WLS 的異常高 CPU 佔用率


問題描述
系統管理員或使用者注意到 WebLogic Server 程式消耗大量的 CPU 資源,並想要了解是哪個方面消耗了大量 CPU 資源,以及導致出現這種現象的原因。

故障排除
請注意,並非下面所有任務都需要完成。有些問題僅透過執行幾項任務就可以解決。

快速連結
為什麼發生此問題?
收集高 CPU 佔用率的資料
Solaris
Linux
AIX
HP-UX
Windows
外部資源

為什麼發生此問題?
發生此問題有許多原因:WebLogic Server 本身、使用者建立的執行緒、不良編碼習慣或第三方軟體。遺憾的是,證明在什麼地方發生此問題有時候非常困難。本模式嘗試透過利用特定操作命令和收集資料來幫助排除此問題。

返回頁首

收集高 CPU 佔用率的資料
對於有關收集高 CPU 佔用率的資料的特定操作資訊,請根據您的作業系統執行以下步驟。

重要說明:
這些作業系統的所有資訊都基於 Sun JVM。 目前在 JRockit 中還沒有辦法將 PID 從說明 CPU 佔用率的作業系統命令(prstat、top、pslist 等等)對映到 Thread Dump 中的正確執行緒。 從 Jrockit 的 70SP4RP2 和 81SP2RP1 以後的版本起,就可實現此對映。 例如,在 Linux 中,Thread Dump 在以後的版本中將採用如下形式(PID 顯示在 Thread Dump 中):


"ExecuteThread: '20' for queue: 'default'" id: 0x00000e80 prio: 5 ACTIVE, DAEMON, GCABLE
thread: 0x469b0af0 lastj: 0xac0f19c
pt_thr: 237596 pid: 23166
at COM.jrockit.vm.Classes.defineClass0(Native Method)@0x8b4b798
at COM.jrockit.vm.Classes.defineClass(Unknown Source)@0x8b4b8b1
at java.lang.ClassLoader.defineClass(Unknown Source)@0x8b4b46f
在上例中,PID 是 23166,您可以透過 Linux 或任何所在系統上的 top(或任何您需要在作業系統上使用的特定命令)輸出直接關聯該 PID。

轉換為十六進位制號碼

備註:為協助您計算在本模式中討論的十六進位制值,您可以在 Shell 指令碼中使用下列行將十進位制號碼轉換為十六進位制號碼。如果您使用 Unix 作業系統,那麼轉換會很方便。

dec2hex.sh:

printf "dec -> hex: %d = %x \n" ${1} ${1}
用法:

$ sh dec2hex.sh 755

dec -> hex: 755 = 2f3

返回頁首


Solaris

在 Java 程式中執行 prstat命令。重複幾次這個操作,以便您能夠看到一種模式。例如:prstat -L -p <PID> 1 1
在 Java 程式中執行 pstack命令以獲得從輕量型程式 (LWP) 到 PID(程式 ID)的對映。
示例:pstack 9499 並將輸出結果重定向到一個檔案。
如果您使用 Solaris 中的常規執行緒庫(即,在 LD_LIBRARY_PATH 中沒有 /usr/lib/lwp),LWP 就不會直接對映到作業系統執行緒,因此您必須從程式中執行 pstack(所以檢檢視您是否正在使用替代執行緒庫)。
經過一段時間後對伺服器進行若干 Thread Dump,確保您執行正確的執行緒。
您可以透過在 Java 程式中執行 kill -3 <PID>來達到此目的。
將 LWP ID 對映到 Java 執行緒 ID。
例如,如果上述的 LWP 為“8”,它可以對映到 Java 執行緒“76”。然後將 76 換算為十六進位制值 0x4c。
檢查 Thread Dump,找到匹配“nid= <上述識別符號/值>”的執行緒。
在本示例中,您找到匹配“nid=0x4c”的執行緒,而該執行緒就是正在消耗 CPU 資源的那個執行緒。
您將需要:
確定為什麼在您的程式碼中會發生這個問題

或者,如果堆疊的最頂端輸出來自 WebLogic,請與 BEA 客戶支援部門聯絡。
下面是 Solaris 系統中上述程式的一個示例:
在 Java 程式中執行 prstat 命令。

$ prstat -L -p 9499 1 1
PID USERNAME SIZE RSS STATE PRI NICE TIME CPU PROCESS/LWPID
9499 usera 153M 100M sleep 58 0 0:00.22 0.6% java/8
9499 usera 153M 100M sleep 58 0 0:00.10 0.2% java/10
9499 usera 153M 100M sleep 58 0 0:00.11 0.1% java/9
9499 usera 153M 100M sleep 58 0 0:00.03 0.0% java/5
9499 usera 153M 100M sleep 58 0 0:01.01 0.0% java/1
9499 usera 153M 100M sleep 58 0 0:00.00 0.0% java/12
9499 usera 153M 100M sleep 58 0 0:00.00 0.0% java/11
9499 usera 153M 100M sleep 58 0 0:00.00 0.0% java/14
9499 usera 153M 100M sleep 58 0 0:00.00 0.0% java/13
9499 usera 153M 100M sleep 59 0 0:00.07 0.0% java/7
9499 usera 153M 100M sleep 59 0 0:00.00 0.0% java/6
9499 usera 153M 100M sleep 59 0 0:00.00 0.0% java/4
9499 usera 153M 100M sleep 58 0 0:00.11 0.0% java/3
9499 usera 153M 100M sleep 58 0 0:00.00 0.0% java/2

執行 pstack 命令。
示例:pstack 9499 並將輸出結果重定向到一個檔案。
如果您使用 Solaris 中的常規執行緒庫(即,在 LD_LIBRARY_PATH 中沒有 /usr/lib/lwp),LWP 就不會直接對映到作業系統執行緒,因此您必須從程式中執行 pstack(所以檢檢視您是否正在使用替代執行緒庫)。

上述示例顯示“java/8”程式在 prstat 的頂端。

為“lwp# 8”檢驗 pstack輸出結果。
您會發現“lwp# 8”從 pstack 輸出結果對映到“thread# 76”,如下所示。
lwp# 8 / thread# 76 ff29d190 poll (e2e81548, 0, bb8)
ff24d154 select (0, 0, 0, e2e81548, ff2bf1b4, e2e81548) + 348
ff36b134 select (0, bb8, 7fffffff, fe4c8000, 0, bb8) + 34
fe0f62e4 __1cCosFsleep6FpnGThread_xl_i_ (0, bb8, fe4c8000, 1, 0, 1e2fd8) + 234
fe23f050 JVM_Sleep (2, 0, bb8, fe4de978, fe4c8000, 1e2fd8) + 22c
0008f7ac ???????? (e2e818d4, bb8, 1e2fd8, 984a4, 0, 109a0)
0008c914 ???????? (e2e8194c, 1, fe4d6a80, 98564, 8, e2e81868)
fe5324e8 __1cMStubRoutinesG_code1_ (e2e819d8, e2e81c10, a, f6cb5000, 4, e2e818f0) + 3ec
fe0cbe94 __1cJJavaCallsLcall_helper6FpnJJavaValue_pnMmethodHandle_pnRJavaCallArguments_pnGThread__v_ (e2e81c08,fe4c8000, e2e81b54, 1e2fd8, 8e764, e2e81c10) +308
fe1f6dbc __1cJJavaCallsMcall_virtual6FpnJJavaValue_nLKlassHandle_nMsymbolHandlee81c08, e2e81b54) + 150pnGThread__v_(f6cb64b8, e2e81b40, e2e81b44, fe4c8000, e2d8) + 60e_5pnGThread__v_ (e2e81c08, e2e81c04, e2e81c00,e2e81bf4, e2e81bec, 1e2f8000, e2e81d10, 1e, e) + 120FpnKJavaThread_pnGThread__v_ (f6817ff8, 1e2fd8, fe4c
7fd70) + 3d8cKJavaThreadDrun6M_v_ (e2e02000, fe4d3e34, fe4c8000, 7fd70, 1e2fd8,
fe213ec8 _start (fe4c8000, fe625d10, 0, 5, 1, fe401000) + 20
ff36b728 _thread_start (1e2fd8, 0, 0, 0, 0, 0) + 40

透過在 Java 程式中執行以下命令對伺服器進行 Thread Dump:
kill -3 <PID>。
由於 lwp# 8 對映到 thread #76,您可以將 76 換算為十六進位制值 4c。
該值對映到 JVM Thread Dump 中的 nid=0x4c:

"Thread-6" prio=5 tid=0x1e2fd8 nid=0x4c waiting on monitor [0xe2e81000..0xe2e819d8]
at java.lang.Thread.sleep(Native Method)
at weblogic.management.deploy.GenericAppPoller.run(GenericAppPoller.java:139)

在此示例中,佔用最多 CPU 資源的執行緒實際上正處於休眠狀態。應用程式輪詢程式在開發模式啟動的伺服器上執行。由於它每隔 30 秒執行一次,因此顯然無法及時捕捉 Thread Dump 以瞭解此執行緒中的活動。

理想狀態下,應當迅速並且連續完成全部三個步驟,以便儘可能及時地捕捉資料。這可以透過類似下面的一個簡單的 shell 指令碼來完成。

#
# Takes an argument (PID of the WLS process) and loops three times. This will append the prstat information to a file called dump_high_cpu.txt. The thread dump information will either be in file where stdout was redirected or printed on the screen.
#

for loopnum in 1 2 3
do
prstat -L -p $1 1 1 >> dump_high_cpu.txt
pstack $1 >> dump_high_cpu.txt
kill -3 $1
echo "prstat, pstack, and thread dump done. #" $loopnum
sleep 1
echo "Done sleeping."
done

然後,您可以檢查該執行緒以確定它正在執行的任務以及是否出現問題。
返回頁首

Linux

獲得最頂端輸出並查詢與之前啟動了現佔用 CPU 的 WLS 的那個使用者 ID 相關聯的 PID。
透過 kill -3 <PID> 對 WebLogic Server 進行若干 Thread Dump
將步驟 1 中的 PID 號轉換為一個十六進位制值。
(用於 Linux 的 JVM 將 Java 執行緒作為本地執行緒實現,這使每個執行緒成為一個獨立的 Linux 程式。)
在 Thread Dump 中搜尋 nid 的值等於上一步驟中所得到的十六進位制值的執行緒。
這將為您揭示造成高 CPU 佔用率問題的執行緒。
確定為什麼在您的程式碼中會發生這個問題,或者,如果堆疊的最頂端輸出來自 WebLogic,請與 BEA 客戶支援部門聯絡。
下面是 Linux 系統中上述程式的一個示例:
獲得 top輸出並查詢與之前啟動了現佔用 CPU 的 WLS 的那個使用者 ID 相關聯的 PID。
將該號轉換為一個十六進位制值。
請參閱下面的 top 輸出示例(這只是一個程式碼片斷,因為對於單個 WLS 程式將啟動更多的執行緒)。

在 Linux 中,每個執行緒對映到一個不同於其它 Unix 形式的程式中。

PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
...........
22962 usera 9 0 86616 84M 26780 S 0.0 4.2 0:00 java
...........

如果 PID 為 22962,則十六進位制值將是:0x59B2
使用此十六進位制值並在 Thread Dump 中查詢哪個 nid 等於該值,以便從 Thread Dump 中獲取正確的執行緒。
例如,如果 ExecuteThread 0 出現問題,則 0x59B2 將對應於該執行緒:

"ExecuteThread: '0' for queue: 'default'" daemon prio=1 tid=0x83da550 nid=0x59b2 waiting on monitor [0x56138000..0x56138870]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:415)
at weblogic.kernel.ExecuteThread.waitForRequest(ExecuteThread.java:146)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:172)

然後,您可以檢查該執行緒以確定它正在執行的任務以及是否出現問題。
在上述示例中,由於該執行緒此時佔用 0% 的 CPU,所以只顯示執行此操作的程式。理想狀態下,應當迅速並且連續完成全部三個步驟,以便儘可能及時地捕捉資料。這可以透過類似下面的一個簡單的 shell 指令碼來完成。

#
# Takes an argument (PID of the WLS process) and loops three times. This will append the prstat information to a file called dump_high_cpu.txt. The thread dump information will either be in file where stdout was redirected or printed on the screen.
#

for loopnum in 1 2 3
do
top -b -n1>> dump_high_cpu.txt
kill -3 $1
echo "cpu snapshot and thread dump done. #" $loopnum
sleep 1
echo "Done sleeping."
done


AIX

執行: ps -mp <WLS_PID> -o THREAD 以查詢正在佔用 CPU 的 tid。
您應當檢視“CP”列(表示 CPU 佔用率),看其中哪些執行緒的此項值比較高並從中挑選一個執行緒。
透過執行以下命令對伺服器進行 Thread Dump:
kill -3 <WLS_PID>
執行: dbx -a <WLS_PID>
在 dbx 中時,執行 dbx thread命令(以列出所有執行緒)。
查詢與您透過 ps -mp <PID -o THREAD 命令獲取的 TID 匹配的行。
該行中的號碼應當採用“$t<NUM>”格式,其中“NUM”是一個號碼。
在 dbx 中時,執行 dbx 命令 th info <TID>(此 TID 來自上一步驟,該步驟在 $t<NUM>後面列出號碼)以獲取關於該執行緒的資訊。
從第 3 步驟的輸出中,在“general”下查詢“pthread_t”,並記錄該十六進位制號碼。
非常重要說明:在 dbx 提示符下,您需要在完成操作時在 dbx 命令列鍵入“detach”,否則,如果您在連線到程式時只要一退出,dbx 將終止該程式!
記下“p_thread_t”輸出中的十六進位制值,並在 Thread Dump 中搜尋其中哪個執行緒的“native ID”等於該值。
這將為您揭示造成高 CPU 佔用率問題的執行緒。

確定為什麼在您的程式碼中正在發生這個問題,或者,如果堆疊的最頂端輸出來自 WebLogic,請與 BEA 客戶支援部門聯絡。
下面是 AIX 系統中上述程式的一個示例:
ps -mp 250076 -o THREAD 將顯示以下內容:

USER PID PPID TID ST CP PRI SC WCHAN F TT BND COMMAND
usera 250076 217266 - A 38 60 72 * 242011 pts/0 - /wwsl/sharedInstalls/aix/jdk130/...
- - - 315593 Z 0 97 1 - c00007 - - -
- - - 344305 S 0 60 1 f1000089c020e200 400400 - - -
- - - 499769 S 0 60 1 f1000089c0213a00 400400 - - -
- - - 540699 S 0 60 1 f100008790008440 8410400 - - -
- - - 544789 S 0 60 1 f100008790008540 8410400 - - -
- - - 548883 S 0 60 1 f100008790008640 8410400 - - -
- - - 552979 S 0 60 1 f100008790008740 8410400 - - -
- - - 565283 Z 0 60 1 - c00007 - - -
- - - 585783 S 0 60 1 f100008790008f40 8410400 - - -
- - - 589865 Z 0 80 1 - c00007 - - -
- - - 593959 S 1 60 1 f100008790009140 8410400 - - -
- - - 610365 S 0 60 1 f100008790009540 8410400 - - -
- - - 614453 S 0 60 1 f100008790009640 8410400 - - -
- - - 618547 S 0 60 1 f100008790009740 8410400 - - -
- - - 622645 S 0 60 1 f100008790009840 8410400 - - -
- - - 626743 S 0 60 1 f100008790009940 8410400 - - -
- - - 630841 S 0 60 1 f100008790009a40 8410400 - - -
- - - 634941 S 0 60 1 f100008790009b40 8410400 - - -
- - - 639037 S 0 60 1 f100008790009c40 8410400 - - -
- - - 643135 S 0 60 1 f100008790009d40 8410400 - - -
- - - 647233 S 0 60 1 f100008790009e40 8410400 - - -
- - - 651331 S 0 60 1 f100008790009f40 8410400 - - -
- - - 655429 S 0 60 1 f10000879000a040 8410400 - - -
- - - 659527 S 0 60 1 f10000879000a140 8410400 - - -
- - - 663625 S 0 60 1 f10000879000a240 8410400 - - -
- - - 667723 S 37 78 1 f1000089c020f150 400400 - - -
- - - 671821 S 0 60 1 f10000879000a440 8410400 - - -
- - - 675919 S 0 60 1 - 418400 - - -
- - - 680017 S 0 60 1 f10000879000a640 8410400 - - -
- - - 684115 S 0 60 1 f10000879000a740 8410400 - - -
- - - 688213 S 0 60 1 f10000879000a840 8410400 - - -
- - - 692311 S 0 60 1 f10000879000a940 8410400 - - -
- - - 696409 S 0 60 1 f10000879000aa40 8410400 - - -
- - - 712801 S 0 60 1 f10000879000ae40 8410400 - - -
- - - 716899 S 0 60 1 f10000879000af40 8410400 - - -
- - - 721011 S 0 60 1 f10000879000b040 8410400 - - -
- - - 725095 S 0 60 1 f10000879000b140 8410400 - - -
- - - 729193 S 0 60 1 f10000879000b240 8410400 - - -
- - - 733291 S 0 60 1 f10000879000b340 8410400 - - -
- - - 737389 S 0 60 1 f10000879000b440 8410400 - - -
- - - 741487 S 0 60 1 f10000879000b540 8410400 - - -
- - - 745585 S 0 60 1 f10000879000b640 8410400 - - -
- - - 749683 S 0 60 1 f10000879000b740 8410400 - - -
- - - 753781 S 0 60 1 f10000879000b840 8410400 - - -
- - - 757879 S 0 60 1 f10000879000b940 8410400 - - -
- - - 761977 S 0 60 1 f10000879000ba40 8410400 - - -
- - - 766075 S 0 60 1 f10000879000bb40 8410400 - - -
- - - 770173 S 0 60 1 f10000879000bc40 8410400 - - -
- - - 774271 Z 0 60 1 - c00007 - - -
- - - 778373 S 0 60 1 f10000879000be40 8410400 - - -
- - - 782467 S 0 60 1 f10000879000bf40 8410400 - - -
- - - 786565 S 0 60 1 f10000879000c040 8410400 - - -
- - - 790663 S 0 60 1 f10000879000c140 8410400 - - -
- - - 794761 S 0 60 1 f10000879000c240 8410400 - - -
- - - 798859 S 0 60 1 f10000879000c340 8410400 - - -
- - - 802957 S 0 60 1 f10000879000c440 8410400 - - -
- - - 807055 S 0 60 1 f10000879000c540 8410400 - - -
- - - 811153 S 0 60 1 f10000879000c640 8410400 - - -
- - - 815253 S 0 60 1 f10000879000c740 8410400 - - -
- - - 819357 S 0 60 1 f10000879000c840 8410400 - - -
- - - 823447 S 0 60 1 f10000879000c940 8410400 - - -
- - - 827545 S 0 60 1 f10000879000ca40 8410400 - - -
- - - 831643 S 0 60 1 f10000879000cb40 8410400 - - -
- - - 835741 S 0 60 1 f10000879000cc40 8410400 - - -
- - - 839839 S 0 60 1 f10000879000cd40 8410400 - - -
- - - 843937 S 0 60 1 f10000879000ce40 8410400 - - -
- - - 848037 S 0 60 1 f10000879000cf40 8410400 - - -
- - - 852135 S 0 60 1 f10000879000d040 8410400 - - -
- - - 856257 S 0 60 1 f10000879000d140 8410400 - - -
- - - 868527 S 0 60 1 f10000879000d440 8410400 - - -
- - - 872623 S 0 60 1 f10000879000d540 8410400 - - -
- - - 876725 S 0 60 1 f10000879000d640 8410400 - - -

透過 kill -3 <WLS_PID> 進行該 WLS_PID 的 Thread Dump
檢查 ps -mp <WLS_PID> -o THREAD命令所輸出的資訊。
注意,TID "667723" 在 CP 列中有一個高值(它達到“37”,而其它 TID 幾乎為 0)。
執行 dbx -a 250076以連線到 WebLogic Server 程式。
執行 thread 命令以列出所有本地執行緒。
下面只顯示相關執行緒的一個程式碼片斷:

thread state-k wchan state-u k-tid mode held scope function
.....

$t15 wait 0xf10000879000a140 blocked 659527 k no sys _event_sleep
$t16 wait 0xf10000879000a240 blocked 663625 k no sys _event_sleep
$t17 run running 667723 k no sys JVM_Send
$t18 wait 0xf10000879000a440 blocked 671821 k no sys _event_sleep
$t19 wait running 675919 k no sys poll
$t20 wait 0xf10000879000a640 blocked 680017 k no sys _event_sleep
.....

執行 th info 17 命令以獲取關於該本地執行緒的必要資訊:

(dbx) th info 17
thread state-k wchan state-u k-tid mode held scope function
$t17 run running 667723 k no sys JVM_Send

general:
pthread addr = 0x3ea55c68 size = 0x244
vp addr = 0x3e69e5e0 size = 0x2a8
thread errno = 2
start pc = 0x300408b0
joinable = no
pthread_t = 1011
scheduler:
kernel =
user = 1 (other)
event :
event = 0x0
cancel = enabled, deferred, not pending
stack storage:
base = 0x3ea15000 size = 0x40000
limit = 0x3ea55c68
sp = 0x3ea55054

非常重要說明:在 dbx 提示符下執行“detach”以從 WebLogic 程式中分離。
記下上述“pthread_t”的數值,並用來查詢 WebLogic Server 程式的 Thread Dump 中的正確執行緒。
從早期進行的 Thread Dump 中,您可以將十六進位制號碼“1011”與 Thread Dump 中在“native ID”之後的號碼進行匹配。
下面是匹配此十六進位制號碼並造成高 CPU 佔用率問題的執行緒示例:

"ExecuteThread: '11' for queue: 'default'" (TID:0x31cf86d8, sys_thread_t:0x3e5ea108, state:R, native ID:0x1011) prio=5
at java.net.SocketOutputStream.socketWrite(Native Method)
at java.net.SocketOutputStream.write(SocketOutputStream.java(Compiled Code))
at weblogic.servlet.internal.ChunkUtils.writeChunkTransfer(ChunkUtils.java(Compiled Code))
at weblogic.servlet.internal.ChunkUtils.writeChunks(ChunkUtils.java(Compiled Code))
at weblogic.servlet.internal.ChunkOutput.flush(ChunkOutput.java(Compiled Code))
at weblogic.servlet.internal.ChunkOutput.checkForFlush(ChunkOutput.java(Compiled Code))
at weblogic.servlet.internal.ChunkOutput.write(ChunkOutput.java(Compiled Code))
at weblogic.servlet.internal.ChunkOutput.write(ChunkOutput.java(Compiled Code))
at weblogic.servlet.internal.ChunkOutputWrapper.write(ChunkOutputWrapper.java(Compiled Code))
at weblogic.servlet.internal.ChunkWriter.write(ChunkWriter.java(Compiled Code))
at java.io.Writer.write(Writer.java(Compiled Code))
at java.io.PrintWriter.write(PrintWriter.java(Compiled Code))
at java.io.PrintWriter.write(PrintWriter.java(Compiled Code))
at java.io.PrintWriter.print(PrintWriter.java(Compiled Code))
at java.io.PrintWriter.println(PrintWriter.java(Compiled Code))
at examples.servlets.HelloWorldServlet.service(HelloWorldServlet.java(Compiled Code))
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at weblogic.servlet.internal.ServletStubImpl$ServletInvocationAction.run(ServletStubImpl.java:1058)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:401)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:306)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:5445)
at weblogic.security.service.SecurityServiceManager.runAs(SecurityServiceManager.java(Compiled Code))
at weblogic.servlet.internal.WebAppServletContext.invokeServlet(WebAppServletContext.java:3105)
at weblogic.servlet.internal.ServletRequestImpl.execute(ServletRequestImpl.java:2588)
at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java(Compiled Code))
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:189)

Native Stack sysSend
JVM_Send
Java_java_net_SocketOutputStream_socketWrite



HP-UX


HP 目前沒有提供類似 prstat- 的命令來收集獨立的執行緒 ID,以將它們轉換回 Thread Dump,BEA 技術支援部門開發了一種簡單的實用程式,可以顯示程式 ID (PID)、與 PID 關聯的輕量型程式 ID (LWPID)、使用者時間和所使用的系統時間。您可以使用該程式作為一個大致指南,因為在高 CPU 佔用的情況中,LWPID 使用越來越多的 CPU,您會看到使用者時間在很短的時間之內便增加了。您可以使用 BEA 的 hp_prstat 實用程式,並定期測量每個 LWPID 的使用者時間以瞭解哪一個正在隨時間推移而增加。使用者時間只能顯示為一個整數,因為由 HP 提供的 API 在這種情況下無法進行更精細的測量。

若要收集 HP-UX 的資料:

單擊 hp_prstat 以下載 BEA 技術支援部門開發的 hp_prstat 實用程式。
在 Java 程式中執行 hp_prstat命令。
透過在 Java 程式中執行以下命令對伺服器進行若干 Thread Dump: kill -3 <PID>。
稍後,完成另一個 hp_prstat <PID>快照。
檢查兩次 hp_prstat迭代的輸出結果以找到已經迅速增加使用者時間的出現問題的 LWPID。
一旦您獲得該號碼 (LWPID),請檢查 Thread Dump,以查詢您已經完成的 Thread Dump 中哪一項的 lwp_id=<等於您所獲得的 LWPID>。
這將匹配將要佔用完 CPU 的有問題的執行緒。

確定為什麼在您的程式碼中會發生這個問題,或者,如果堆疊的最頂端輸出來自 WebLogic,請與 BEA 客戶支援部門聯絡。
下面是 HP-UX 系統中上述程式的一個示例:
在 Java 程式中執行 hp_prstat 命令。
示例: hp_prstat <PID>
每隔幾分鐘執行一次上述操作,執行數次,同時觀察發生高 CPU 佔用率的情況。
下面是輸出示例:

lwpid pid pri status UsrTime SysTime

285365 4426 154 1 29 3
285381 4426 154 1 0 7
285382 4426 154 1 2 7
285383 4426 154 1 0 7
285384 4426 154 1 0 7
285385 4426 168 1 0 7
285386 4426 154 1 0 7
285387 4426 154 1 0 7
285388 4426 154 1 0 7
285389 4426 154 1 30 7
285404 4426 168 1 0 7
285405 4426 154 1 0 7
285406 4426 154 1 0 7
285407 4426 154 1 0 7
285408 4426 154 1 0 7
285409 4426 154 1 0 7
285410 4426 154 1 0 7
285411 4426 154 1 0 7
285412 4426 154 1 0 7
285413 4426 154 1 0 7
285414 4426 154 1 0 7
285415 4426 154 1 0 7
285416 4426 154 1 0 7
285417 4426 154 1 0 7
285418 4426 154 1 0 7
285419 4426 154 1 0 7
285420 4426 154 1 0 7
285421 4426 154 1 0 7
285422 4426 154 1 0 7
285423 4426 154 1 0 7
285424 4426 154 1 0 7
285425 4426 154 1 0 7
285426 4426 154 1 0 7
285427 4426 154 1 0 7
285428 4426 154 1 0 7
285429 4426 154 1 0 7
285430 4426 154 1 0 7
285431 4426 154 1 0 7
285432 4426 154 1 0 7
285433 4426 154 1 0 7
285434 4426 154 1 0 7
285435 4426 154 1 0 7
285436 4426 154 1 0 7
285439 4426 154 1 0 7
285441 4426 154 1 0 7
285442 4426 154 1 0 7
285443 4426 154 1 0 7
285444 4426 154 1 0 7
285445 4426 154 1 0 7
285446 4426 154 1 0 7
285449 4426 154 1 0 7
285450 4426 154 1 0 7
285451 4426 154 1 0 7
285452 4426 154 1 0 7
285453 4426 154 1 0 7
285454 4426 154 1 0 7
285455 4426 154 1 0 7
285456 4426 154 1 0 7
285457 4426 154 1 0 7
285458 4426 154 1 0 7
285459 4426 154 1 0 7
285460 4426 154 1 0 7
285461 4426 154 1 0 7
285462 4426 154 1 0 7
285463 4426 154 1 0 7
285464 4426 168 1 0 7
285468 4426 178 4 0 7
285469 4426 154 1 0 7
285470 4426 154 1 0 7
285471 4426 154 1 0 7
285472 4426 154 1 0 7
285473 4426 154 1 0 7
285475 4426 168 1 1 7
285477 4426 154 1 0 7
285478 4426 154 1 0 7

透過在 Java 程式中執行以下命令對伺服器進行 Thread Dump: kill -3 <PID>。
稍後,完成另一個 hp_prstat <PID> 快照。
注意,與第一個快照對比,兩個 LWPID(285475 和 285416)比較大。

您需要檢查這兩個 LWPID。

lwpid pid pri status UsrTime SysTime

285365 4426 154 1 29 3
285381 4426 154 1 0 7
285382 4426 154 1 2 7
285383 4426 154 1 0 7
285384 4426 154 1 0 7
285385 4426 168 1 0 7
285386 4426 154 1 0 7
285387 4426 154 1 0 7
285388 4426 154 1 0 7
285389 4426 154 1 32 7
285404 4426 168 1 0 7
285405 4426 154 1 0 7
285406 4426 154 1 0 7
285407 4426 154 1 0 7
285408 4426 154 1 0 7
285409 4426 154 1 0 7
285410 4426 154 1 0 7
285411 4426 154 1 0 7
285412 4426 154 1 0 7
285413 4426 154 1 0 7
285414 4426 154 1 0 7
285415 4426 154 1 0 7
285416 4426 154 1 13 7
285417 4426 154 1 0 7
285418 4426 154 1 0 7
285419 4426 154 1 0 7
285420 4426 154 1 0 7
285421 4426 154 1 0 7
285422 4426 154 1 0 7
285423 4426 154 1 0 7
285424 4426 154 1 0 7
285425 4426 154 1 0 7
285426 4426 154 1 0 7
285427 4426 154 1 0 7
285428 4426 154 1 0 7
285429 4426 154 1 0 7
285430 4426 154 1 0 7
285431 4426 154 1 0 7
285432 4426 154 1 0 7
285433 4426 154 1 0 7
285434 4426 154 1 0 7
285435 4426 154 1 0 7
285436 4426 154 1 0 7
285439 4426 154 1 0 7
285441 4426 154 1 0 7
285442 4426 154 1 0 7
285443 4426 154 1 0 7
285444 4426 154 1 0 7
285445 4426 154 1 0 7
285446 4426 154 1 0 7
285449 4426 154 1 0 7
285450 4426 154 1 0 7
285451 4426 154 1 0 7
285452 4426 154 1 0 7
285453 4426 154 1 0 7
285454 4426 154 1 0 7
285455 4426 154 1 0 7
285456 4426 154 1 0 7
285457 4426 154 1 0 7
285458 4426 154 1 0 7
285459 4426 154 1 0 7
285460 4426 154 1 0 7
285461 4426 154 1 0 7
285462 4426 154 1 0 7
285463 4426 154 1 0 7
285464 4426 168 1 0 7
285468 4426 178 4 0 7
285469 4426 154 1 0 7
285470 4426 154 1 0 7
285471 4426 154 1 0 7
285472 4426 154 1 0 7
285473 4426 154 1 0 7
285475 4426 168 1 5 7
285477 4426 154 1 0 7
285478 4426 154 1 0 7

透過在 Java 程式中執行以下命令對伺服器進行另一個 Thread Dump: kill -3 <PID>,確保您捕捉到佔用完 CPU 資源的正確執行緒。
從 hp_prstat 輸出中獲取 LWPID,該輸出在形式上與使用者時間相似,且不斷增大。一旦您獲得該號碼 (LWPID),請檢查 Thread Dump,以查詢您已經完成的 Thread Dump 中哪一項的 lwp_id 等於<您所獲得的 LWPID>。
可以檢查以下這兩個 LWPID:

"Thread-6" prio=8 tid=0x0004f620 nid=75 lwp_id=285475 waiting on monitor [0x66d5e000..0x66d5e500]
at java.lang.Thread.sleep(Native Method)
at weblogic.management.deploy.GenericAppPoller.run(GenericAppPoller.java:139)

"ExecuteThread: '11' for queue: 'default'" daemon prio=10 tid=0x0004ad00 nid=23 lwp_id=285416 runnable [0x67874000..0x67874500]
at java.net.SocketOutputStream.socketWrite(Native Method)
at java.net.SocketOutputStream.write(Unknown Source)
at weblogic.servlet.internal.ChunkUtils.writeChunkTransfer(ChunkUtils.java:222)
at weblogic.servlet.internal.ChunkUtils.writeChunks(ChunkUtils.java:198)
at weblogic.servlet.internal.ChunkOutput.flush(ChunkOutput.java:285)
at weblogic.servlet.internal.ChunkOutput.checkForFlush(ChunkOutput.java:345)
at weblogic.servlet.internal.ChunkOutput.write(ChunkOutput.java:222)
at weblogic.servlet.internal.ChunkOutput.write(ChunkOutput.java:237)
at weblogic.servlet.internal.ChunkOutputWrapper.write(ChunkOutputWrapper.java:86)
at weblogic.servlet.internal.ChunkWriter.write(ChunkWriter.java:37)
at java.io.Writer.write(Unknown Source)
- locked <0x753408e8> (a weblogic.servlet.internal.ChunkWriter)
at java.io.PrintWriter.write(Unknown Source)
- locked <0x753408e8> (a weblogic.servlet.internal.ChunkWriter)
at java.io.PrintWriter.write(Unknown Source)
at java.io.PrintWriter.print(Unknown Source)
at java.io.PrintWriter.println(Unknown Source)
- locked <0x753408e8> (a weblogic.servlet.internal.ChunkWriter)
at examples.servlets.HelloWorldServlet.service(HelloWorldServlet.java:28)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at weblogic.servlet.internal.ServletStubImpl$ServletInvocationAction.run(ServletStubImpl.java:1058)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:401)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:306)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:5445)
at weblogic.security.service.SecurityServiceManager.runAs(SecurityServiceManager.java:780)
at weblogic.servlet.internal.WebAppServletContext.invokeServlet(WebAppServletContext.java:3105)
at weblogic.servlet.internal.ServletRequestImpl.execute(ServletRequestImpl.java:2588)
at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:213)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:189)

顯然,實際造成問題的是 LWPID 285416。
您可以檢查該 Servlet 的服務方法,以查明圍繞此行號發生的情況(HelloWorldServlet.java第 28 行)並確定問題所在。

Windows

使用 pslist
您可以在 Windows 中使用 pslist 並獲取 java 程式的執行緒詳細資訊。 pslist可從以下網址得到:

執行 pslist -d <Java PID> 並將輸出結果重定向到一個檔案。

重複幾次這個操作,以便您能夠看到一種模式。
您將看到“使用者時間”和“核心時間”不斷增加。

在若干次迭代後對 WLS 伺服器進行 Thread Dump。
記下步驟 1 中看起來正在增加的執行緒 ID 號,將十進位制值改為十六進位制值(您可以使用 Windows 中的計算功能)。
根據“nid=0x<步驟 3 的十六進位制值>”檢查 Thread Dump,直到您找到出現問題的執行緒。
確定為什麼在您的程式碼中會發生這個問題,或者,如果堆疊的最頂端輸出來自 WebLogic,請與 BEA 客戶支援部門聯絡。
使用 Process Explorer
您還可以使用 Systinternals 提供的 Process Explorer 。 該工具直觀動態顯示 CPU 佔用率。 由於 Process Explorer 沒有記錄功能或歷史記錄,您必須監視該程式並記錄佔用幾乎全部 CPU 資源的 Java 程式的執行緒 ID。 若要透過 Process Explorer 達到上述目的:

查詢 java 程式,然後右鍵單擊並選擇屬性。
單擊“Threads”選項卡以顯示與此 java 程式關聯的所有執行緒。
您可以單擊以“MSVCRT.dll+<一些十六進位制偏移量>”形式列出的其中一個執行緒。
您可以看到在下面窗格中列出的“Thread ID”。

觀察哪一個執行緒佔用最多 CPU 資源。
進行 WLS 伺服器的 Thread Dump。
記下步驟 4 中看起來正在佔用 CPU 的執行緒 ID 號,將十進位制值改為十六進位制值(您可以使用 Windows 中的計算功能)。
根據“nid=0x<十六進位制值>”檢查 Thread Dump,直到您找到出現問題的執行緒。
確定為什麼在您的程式碼中會發生這個問題,或者,如果堆疊的最頂端輸出來自 WebLogic,請與 BEA 客戶支援部門聯絡。
下面是僅使用 pslist 和 Thread Dump 的步驟示例:
執行 pslist -d 172

java 1720:
Tid Pri Cswtch State User Time Kernel Time Elapsed Time
1520 8 9705 Wait:UserReq 0:00:23.734 0:00:01.772 0:04:55.264
1968 9 2233 Wait:UserReq 0:00:04.606 0:00:00.040 0:04:54.874
1748 15 146 Wait:UserReq 0:00:00.010 0:00:00.010 0:04:54.863
1744 11 62 Wait:UserReq 0:00:00.010 0:00:00.000 0:04:54.853
1420 15 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:54.563
1856 15 7 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:54.563
1860 9 3157 Wait:UserReq 0:00:03.314 0:00:00.160 0:04:54.563
412 15 5888 Wait:DelayExec 0:00:00.000 0:00:00.000 0:04:54.553
1864 8 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:50.567
1660 15 61 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:42.125
2020 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:42.025
1532 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:42.015
1332 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:42.005
1696 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.995
2060 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.995
1552 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.985
2072 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.985
2068 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.975
2044 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.975
2000 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.965
588 9 4744 Wait:UserReq 0:00:02.814 0:00:00.110 0:04:41.965
1784 9 132 Wait:UserReq 0:00:00.080 0:00:00.000 0:04:41.955
1756 9 196 Wait:UserReq 0:00:00.931 0:00:00.000 0:04:41.955
1716 8 6 Wait:Queue 0:00:00.000 0:00:00.000 0:04:41.945
1800 9 1457 Wait:Queue 0:00:00.761 0:00:00.210 0:04:41.945
1996 8 47 Wait:UserReq 0:00:00.170 0:00:00.000 0:04:41.835
1992 11 18 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.434
1988 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.424
1984 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.414
1976 8 231 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.274
1956 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.234
1740 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.224
1944 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.214
1964 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.204
1972 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.204
1280 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.194
1960 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.194
1872 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.184
1884 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.184
1952 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.174
1940 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.174
1936 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:41.164
1932 6 4 Wait:UserReq 0:00:00.010 0:00:00.000 0:04:39.291
1928 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:31.880
1916 8 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:31.870
1912 8 4 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:31.860
1908 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:31.860
1904 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:31.850
1900 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:31.840
1896 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.889
2064 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.879
1828 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.869
1892 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.859
1888 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.859
1852 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.849
1848 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.849
1844 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.839
1412 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.839
332 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.829
1840 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.829
1440 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.819
1796 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.819
1240 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.809
568 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:30.809
1732 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:29.797
2056 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:15.006
1688 8 4 Wait:UserReq 0:00:00.000 0:00:00.010 0:04:14.996
1776 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:14.986
1648 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:14.976
1768 8 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:04:14.976
284 8 188 Wait:UserReq 0:00:00.190 0:00:00.040 0:04:08.887
576 9 123 Wait:UserReq 0:00:00.070 0:00:00.020 0:04:07.515

一段時間後再次進行相同的輸出,以獲得執行緒的另一個快照,查明哪一個執行緒已經顯著增大。
確定要進一步檢查的執行緒 ID (TID)。
再次執行 pslist: pslist -d 1720

java 1720:
Tid Pri Cswtch State User Time Kernel Time Elapsed Time
1520 8 9705 Wait:UserReq 0:00:23.734 0:00:01.772 0:08:14.511
1968 8 6527 Wait:UserReq 0:00:06.309 0:00:00.070 0:08:14.120
1748 15 157 Wait:UserReq 0:00:00.010 0:00:00.010 0:08:14.110
1744 10 68 Wait:UserReq 0:00:00.010 0:00:00.000 0:08:14.100
1420 15 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:13.810
1856 15 18 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:13.810
1860 8 3169 Wait:UserReq 0:00:03.314 0:00:00.160 0:08:13.810
412 15 9890 Wait:DelayExec 0:00:00.000 0:00:00.000 0:08:13.800
1864 8 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:09.814
1660 15 188 Wait:UserReq 0:00:00.010 0:00:00.010 0:08:01.372
2020 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.272
1532 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.262
1332 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.252
1696 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.241
2060 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.241
1552 9 40 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.231
2072 8 13 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.231
2068 8 20 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.221
2044 8 15 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:01.221
2000 8 657 Wait:UserReq 0:00:00.090 0:00:00.010 0:08:01.211
588 10 59123 Wait:UserReq 0:00:48.830 0:00:02.633 0:08:01.211
1784 8 150 Wait:UserReq 0:00:00.090 0:00:00.000 0:08:01.201
1756 8 251 Wait:UserReq 0:00:00.941 0:00:00.000 0:08:01.201
1716 8 6 Wait:Queue 0:00:00.000 0:00:00.000 0:08:01.191
1800 8 1457 Wait:Queue 0:00:00.761 0:00:00.210 0:08:01.191
1996 8 47 Wait:UserReq 0:00:00.170 0:00:00.000 0:08:01.081
1992 10 29 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.681
1988 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.671
1984 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.661
1976 9 400 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.520
1956 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.480
1740 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.470
1944 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.460
1964 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.450
1972 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.450
1280 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.440
1960 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.440
1872 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.430
1884 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.430
1952 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.420
1940 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.420
1936 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:08:00.410
1932 6 4 Wait:UserReq 0:00:00.010 0:00:00.000 0:07:58.538
1928 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:51.127
1916 8 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:51.117
1912 8 5 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:51.107
1908 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:51.107
1904 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:51.097
1900 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:51.087
1896 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.136
2064 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.126
1828 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.115
1892 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.105
1888 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.105
1852 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.095
1848 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.095
1844 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.085
1412 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.085
332 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.075
1840 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.075
1440 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.065
1796 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.065
1240 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.055
568 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:50.055
1732 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:49.044
2056 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:34.253
1688 8 4 Wait:UserReq 0:00:00.000 0:00:00.010 0:07:34.243
1776 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:34.233
1648 8 2 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:34.223
1768 8 3 Wait:UserReq 0:00:00.000 0:00:00.000 0:07:34.223
284 9 416 Ready 0:00:00.420 0:00:00.100 0:07:28.134
576 8 123 Wait:UserReq 0:00:00.070 0:00:00.020 0:07:26.762

注意,執行緒 ID 588 正在使用最多的使用者/核心時間,因此佔用最多的 CPU 資源。顯然,該執行緒有問題。
記錄執行緒 ID 號 588,並將其轉換為十六進位制值 (0x24)。
檢視您在出現問題時所記下的 Thread Dump,並查詢“nid=0x24”。
從以下輸出中可以看出,它對應於 Thread Dump 中的 ExecuteThread 10:

"ExecuteThread: '10' for queue: 'default'" daemon prio=5 tid=0x20d75808 nid=0x24c runnable [219ff000..219ffd90]
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at weblogic.servlet.internal.ChunkUtils.writeChunkTransfer(ChunkUtils.java:222)
at weblogic.servlet.internal.ChunkUtils.writeChunks(ChunkUtils.java:198)
at weblogic.servlet.internal.ChunkOutput.flush(ChunkOutput.java:284)
at weblogic.servlet.internal.ChunkOutput.checkForFlush(ChunkOutput.java:344)
at weblogic.servlet.internal.ChunkOutput.write(ChunkOutput.java:221)
at weblogic.servlet.internal.ChunkOutput.write(ChunkOutput.java:236)
at weblogic.servlet.internal.ChunkOutputWrapper.write(ChunkOutputWrapper.java:95)
at weblogic.servlet.internal.ChunkWriter.write(ChunkWriter.java:37)
at java.io.Writer.write(Writer.java:150)
- locked <0x11d0d1c0> (a weblogic.servlet.internal.ChunkWriter)
at java.io.PrintWriter.write(PrintWriter.java:230)
- locked <0x11d0d1c0> (a weblogic.servlet.internal.ChunkWriter)
at java.io.PrintWriter.write(PrintWriter.java:247)
at java.io.PrintWriter.print(PrintWriter.java:378)
at java.io.PrintWriter.println(PrintWriter.java:515)
- locked <0x11d0d1c0> (a weblogic.servlet.internal.ChunkWriter)
at examples.servlets.HelloWorld2.service(HelloWorld2.java:94)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at weblogic.servlet.internal.ServletStubImpl$ServletInvocationAction.run(ServletStubImpl.java:1058)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:401)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:306)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:5412)
at weblogic.security.service.SecurityServiceManager.runAs(SecurityServiceManager.java:744)
at weblogic.servlet.internal.WebAppServletContext.invokeServlet(WebAppServletContext.java:3086)
at weblogic.servlet.internal.ServletRequestImpl.execute(ServletRequestImpl.java:2544)
at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:153)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:134)
顯然,問題出現在 socketWrite本地方法上,但表面看起來是 HelloWorld2.service()出錯。

檢查行號(HelloWorld2.java的第 94 行)以確定發生的情況。
從 service()方法的 HelloWorld2.java 程式碼片斷:

89 out.println(ExampleUtils.returnHtmlHeader("Hello World 2"));
90 out.println("
");
91 for (int i=0;i<100000000;i++) {
92 int j = 0;
93 j = j +i;
94 out.println(defaultGreeting + " " + defaultName + "!");
95 }
96
97 out.println("
");
98 out.println(ExampleUtils.returnHtmlFooter());
可以看出,由於某種原因,輸出流是用一個非常長的“for loop”語句編寫的。這是錯誤所在,也是此示例中造成高 CPU 佔用率的原因。

如果改正此程式碼,則 CPU 就不會被完全佔用.

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/15797451/viewspace-1824765/,如需轉載,請註明出處,否則將追究法律責任。

相關文章