- 如何判斷CPU高?
有很多操作系統的命令可以看出來,比如ps -elf,iostat, vmstat, top/topas,
- 收集數據
CPU高分為usr高和sys高,前者表示系統在執行應用代碼,一般需要應用(比如Db2)來查原因。後者表示系統在執行kernal code,一般需要OS工程師協助分析。
- sys CPU高
如果是%sys CPU高,這意味著系統在執行kernel code,這種情況下需要操作系統工程師一塊支持,來從操作系統層面收集數據,例如:
AIX:
1) OS trace — perfpmr.sh
Solaris:
1) dtrace script
Linux:
1) systemTap 工具
2) 如果能確定是Db2進程導致的,則收集db2sysc進程的strace -c 數據。
Db2:
Db2層面也可以收集一些數據,Db2導致的sys CPU高時,往往伴隨著很多的latch,所以建議收集db2pd -latch和db2pd -stack的數據。
- usr CPU高
如果是%usr CPU高,一般意味著系統正在執行應用的代碼,很大可能是Db2執行的SQL語句導致的。需要找到佔用CPU較多的SQL語句,看看在執行什麼操作:
B1. 可以通過mon_get_pkg_cache_stmt找到佔用CPU較多的動態SQL語句
db2 “select TOTAL_CPU_TIME/NUM_EXEC_WITH_METRICS as AVG_CPU_TIME, NUM_EXEC_WITH_METRICS, substr(STMT_TEXT,1,100) as STMT_TEXT from table( mon_get_pkg_cache_stmt (null, null,null,null)) as T where T.NUM_EXEC_WITH_METRICS <> 0 order by AVG_CPU_TIME DESC”
如果是routine佔用了較多的CPU,比如存儲過程,可以參考下面的鏈接:
調查routine的高 CPU 佔用率
https://www.ibm.com/support/knowledgecenter/zh/SSEPGG_10.5.0/com.ibm.db2.luw.admin.mon.doc/doc/t0060667.html
B2. 可以通過db2pd -edus interval=120 來收集120秒之內每個edu佔用的CPU時間,結合其他的信息,比如db2pd -eve、application snapshot的輸出,來看一下edu對應的應用,以及應用執行的SQL語句是什麼,針對這些SQL語句來優化。
SQL語句使用CPU較多的原因,簡單說幾個
–頻繁地掃描環境池中的表、join操作、排序操作都會使用較多的CPU。
–獲取鎖和釋放鎖的過程,也要用較多的CPU。
對於如何解決,一般就是調優SQL了,比如通過建立適當的索引來避免表掃描、當需要鎖較多時而對並發性要求不高時,直接在整個表上加鎖、不需要那麼多數據的時候使用fetch first xxx rows only等。這裡不做闡述(因為我也不擅長),有興趣的可以看參考資料。
- 一個示例
環境: db2 10.5.0.5, suse linux 11
問題:%usr CPU高,大約95%,db2sysc進程使用的最多
數據收集:
在問題出現期間,收集了以下數據:
vmstat 1 10 > vmstat.1
ps -elf > pself.1
ps aux > psaux.1
iostat 1 10 > iostat.1
db2pd -eve > db2pd_eve.out
db2pd -edus interval=120 > db2pd_edu_120.out
db2pd -stack all
db2 GET SNAPSHOT FOR APPLICATIONS ON <db_name> GLOBAL > applications.log
db2 GET SNAPSHOT FOR DATABASE ON <db_name> GLOBAL > DB.log
db2 get snapshot for all on <db_name> > dbsnap
數據分析:
3.1
iostat 輸出顯示 user CPU 很高.
avg-cpu: %user %nice %system %iowait %steal %idle
89.42 0.01 4.55 1.89 0.00 4.12
avg-cpu: %user %nice %system %iowait %steal %idle
94.41 0.00 5.59 0.00 0.00 0.00
avg-cpu: %user %nice %system %iowait %steal %idle
95.42 0.00 4.58 0.00 0.00 0.00
avg-cpu: %user %nice %system %iowait %steal %idle
94.67 0.00 5.33 0.00 0.00 0.00
3.2
ps aux的輸出顯示db2sysc進程使用了最多的CPU
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.0 0.0 10540 884 ? Ss Oct15 0:01 init [5]
root 2 0.0 0.0 0 0 ? S Oct15 0:00 [kthreadd]
…
root 7065 0.0 0.2 1029412 75296 ? Sl Oct15 0:00 db2wdog 0 [db2inst1]
db2inst1 7067 1127 69.2 29760484 22761184 ? Sl Oct15 13895:25 db2sysc 0
root 7069 0.0 0.1 1035728 47704 ? S Oct15 0:02 db2ckpwd 0
root 7070 0.0 0.1 1035728 47632 ? S Oct15 0:02 db2ckpwd 0
root 7071 0.0 0.1 1035728 47632 ? S Oct15 0:02 db2ckpwd 0
db2inst1 7079 0.0 0.1 502756 41276 ? S Oct15 0:00 db2vend (PD Vendor Process – 1) 0
db2inst1 7089 0.0 0.1 592156 33260 ? Sl Oct15 0:22 db2acd 0 ,0,0,0,1,0,0,0,0000,1,0,995bc4,14,1e014,2,0,1,41fc0,0x210000000,0x210000000,1600000,c8010,2,128021
…
root 27022 50.0 0.0 4940 972 pts/1 R+ 13:59 0:00 ps aux
root 27499 0.0 0.0 0 0 ? S 12:06 0:00 [kworker/9:0]
patrol 27604 0.0 0.0 11300 1048 ? Ss Oct15 0:00 /bin/bash
patrol 27605 0.0 0.0 11300 1052 ? Ss Oct15 0:00 /bin/bash
root 28654 0.0 0.0 0 0 ? S Oct15 0:01 [kworker/8:1]
3.3
db2pd_edu_120.out 輸出按照對EDU按照佔用的CPU時間排序
- Database Member 0 — Active — Up 0 days 21:21:14 — Date 2017-10-16-14.48.37.897471
- List of all EDUs for database member 0
- db2sysc PID: 7067
- db2wdog PID: 7065
- db2acd PID: 7089
- EDU ID TID Kernel TID EDU Name USR (s) SYS (s) USR DELTA SYS DELTA
- ========================================================================================================================================
- 110 140354128963328 28988 db2agent (SAMPLE) 0 590000 478.060000 42.250000 1.080000
- 85 140354313512704 16300 db2agent (SAMPLE) 0 440000 454.140000 40.980000 0.900000
- 87 140354531616512 16316 db2agent (SAMPLE) 0 870000 446.600000 40.830000 0.850000
- 122 140353910859520 348 db2agent (SAMPLE) 0 420000 430.300000 40.600000 1.000000
- 88 140354514839296 16324 db2agent (SAMPLE) 0 550000 443.450000 40.640000 0.900000
- 91 140354464507648 16327 db2agent (SAMPLE) 0 210000 438.320000 40.660000 0.880000
- 114 140354061854464 13529 db2agent (SAMPLE) 0 820000 436.550000 40.540000 0.900000
- 79 140354900715264 8439 db2agent (SAMPLE) 0 830000 450.830000 40.540000 0.840000
- 108 140354162517760 21738 db2agent (SAMPLE) 0 730000 450.920000 40.430000 0.920000
- 106 140354196072192 21722 db2agent (SAMPLE) 0 360000 445.650000 40.440000 0.900000
- 119 140353961191168 21841 db2agent (SAMPLE) 0 160000 427.530000 40.450000 0.850000
- 80 140354883938048 16295 db2agent (SAMPLE) 0 770000 443.420000 40.270000 1.020000
- 115 140353776641792 15710 db2agent (SAMPLE) 0 610000 435.050000 40.340000 0.920000
- 111 140354112186112 29588 db2agent (SAMPLE) 0 810000 446.610000 40.340000 0.900000
- 117 140353994745600 16907 db2agent (SAMPLE) 0 840000 433.260000 40.330000 0.910000
- 109 140354145740544 28987 db2agent (SAMPLE) 0 250000 450.080000 40.220000 1.010000
- 84 140354816829184 16299 db2agent (SAMPLE) 0 960000 443.260000 40.250000 0.980000
- 112 140354095408896 6654 db2agent (SAMPLE) 0 780000 445.550000 40.270000 0.920000
- 118 140353977968384 18404 db2agent (SAMPLE) 0 640000 419.450000 39.990000 0.960000
- 78 140354917492480 8433 db2agent (SAMPLE) 0 590000 442.670000 39.970000 0.930000
- 121 140353927636736 23958 db2agent (SAMPLE) 0 700000 427.340000 39.910000 0.970000
- 116 140354011522816 15711 db2agent (SAMPLE) 0 390000 437.080000 39.990000 0.870000
- 81 140354867160832 16296 db2agent (SAMPLE) 0 230000 448.500000 39.830000 1.020000
- 104 140354229626624 19731 db2agent (SAMPLE) 0 980000 450.790000 39.910000 0.920000
- 123 140353894082304 1767 db2agent (SAMPLE) 0 450000 423.550000 39.840000 0.930000
- 113 140354078631680 7525 db2agent (SAMPLE) 0 950000 437.310000 39.740000 0.870000
- 124 140353877305088 2185 db2agent (SAMPLE) 0 260000 423.640000 39.640000 0.910000
- …
3.4
這裡以EDU ID 110為例子,可以通過db2pd_eve.out找到其執行的SQL語句(這裡可能不準確,因為抓取的是當前正在執行的SQL, 推薦結合mon_get_pkg_cache_stmt的輸出)
- Dynamic SQL Statements:
- Address AnchID StmtUID NumEnv NumVar NumRef
- NumExe Text
- …
- 0x00007FAC67B6C640 740 1 1 1 41 41
- select * from TEST1 where KPICODE like ‘2222|!|!|%’ order
- by DCTIME desc fetch first 20 rows only with ur
- …
3.5
Application SNAPSHOT顯示sort、rows read都非常高
Application Snapshot
Application handle = 109
Application status = UOW Executing
..
Rows inserted = 12335
Rows updated = 0
Rows selected = 25680
Rows read = 175961810541
Rows written = 12335
..
Total sorts = 1284
..
以下文章點擊率最高
Loading…