查看當前運行時間長的 SQL 語句
Db2 出現運行緩慢如果不是因為鎖或者 latch 的等待問題。這時就需要看看當前哪些 SQL 運行的時間比較長。我會挑選 10 條運行時間最長的 SQL 來分析。
清單 10. 查看 activestatements
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
AGDPCMB1:/home/db2gdpc$db2pd -d chgmdb -activestatements Database Member 0 -- Database CHGMDB -- Active -- Up 21 days 00:37:29 -- Date 2018-03-01-16.11.48.180193 Active Statement List:Address AppHandl [nod-index] UOW-ID StmtID AnchID StmtUID EffISO EffLockTOut EffDegree EntryTime StartTime LastRefTime 0x0A0005024E322860 15657 [000-15657] 5 1 548 1 1 3000 0 Thu Mar 1 16:11:38 Thu Mar 1 16:11:38 Thu Mar 1 16:11:380x0A0005024DF5CE60 14933 [000-14933] 2 1 317 1 1 3000 0 Thu Mar 1 16:00:33 Thu Mar 1 16:00:33 Thu Mar 1 16:00:330x0A0005024E147CC0 19008 [000-19008] 6 1 365 2 1 3000 0 Thu Mar 1 16:11:42 Thu Mar 1 16:11:42 Thu Mar 1 16:11:42 |
這個輸出里面需要關注的是 StartTime，按照這個排序就可以找到運行時間最長的語句了。和分析鎖堵塞問題里的方法一樣。這里的 AnchID 和 StmtUID 可以在 dynamic cache 里面定位到唯一的 SQL 語句。這個在一鍵檢查工具里面是自動收集展示的。
清單 11. 一鍵檢查工具查看 TOP SQL
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
AGDPCMB1:/home/db2gdpc$python db2_check_hang_105.py chgmdb stmt ################################################################################ Show top 10 running stmt ################################################################################ #Check active statements for: CHGMDBThe apphdl is: 14933 , started at : Thu Mar 1 16:00:33 SELECT ID,substr(HOME_HOST,:L0 ,:L1 ) as HOME_HOST,substr(CURRENT_HOST,:L2 ,:L3 ) asCURRENT_HOST,STATE,ALERT FROM SYSIBMADM.DB2_MEMBERThe apphdl is: 15657 , started at : Thu Mar 1 16:11:38 update t set c1 =:L0The apphdl is: 19008 , started at : Thu Mar 1 16:11:42 delete from t |
這個工具基于執行時間排序，只抓取前 10 的 SQL 語句。獲得這些信息后就可以分析有沒有異常。
查看熱表和相關 SQL 語句
Db2 運行緩慢不可忽視的誘因之一就是存在熱點數據。通常熱點數據會伴隨鎖等待和 latch 等待等現象，但不是完全堵塞的狀態?，F象就是熱點表相關的 SQL 會比正常情況下慢很多，從而導致整個數據庫運行緩慢。
獲取熱點表
當數據庫出現緩慢的時候，如果想要從熱點數據的角度去分析問題，找到對應的表，然后再找到對應的熱點語句，就可以分析是否存在問題，是否需要優化。db2top 首頁鍵入 T 可以進入 Tables 的監控界面。在這個界面里能看到 Delta RowsRead 和 Delta RowsWritten 等信息，從而獲取當前熱點表信息。
清單 12. db2top 查看熱點表
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
|
[/]15:52:03,refresh=2secs(0.003) Tables AIX,member=[4/4],DB2GDPC:CHGMDB[d=Y,a=N,e=N,p=ALL] [qp=off] Table Delta Delta Name RowsRead/s RowsWritten/s ---------------------------------------- -------------- -------------- DB2GDPC.TEST 0 0 SYSIBM.SYSCOLUMNS 0 0 SYSIBM.SYSCONTEXTATTRIBUTES 0 0 SYSIBM.SYSCONTEXTS 0 0 SYSIBM.SYSDBAUTH 0 0 SYSIBM.SYSEVENTMONITORS 0 0 SYSIBM.SYSEVENTTABLES 0 0 SYSIBM.SYSHISTOGRAMTEMPLATEBINS 0 0 SYSIBM.SYSHISTOGRAMTEMPLATES 0 0 SYSIBM.SYSHISTOGRAMTEMPLATEUSE 0 0 SYSIBM.SYSINDEXES 0 0 SYSIBM.SYSNODEGROUPS 0 0 SYSIBM.SYSPLAN 0 0 SYSIBM.SYSROLEAUTH 0 0 SYSIBM.SYSROUTINES 0 0 SYSIBM.SYSSERVICECLASSES 0 0 SYSIBM.SYSSTOGROUPS 0 0Quit: q, Help: h L: top temp storage consumers db2top 2. |
db2top 最強的地方就是能夠自動獲取兩次捕獲信息之間的差異并計算出 Delta 值展示出來。其他監控工具只能獲取當前累計值，需要手工計算和排序。然而就像之前所擔心的那樣，db2top 在數據庫緩慢的情況下不一定能工作。這個時候只有 db2pd 工具能夠正常使用。db2pd 的 tcbstats 選項可以展示表和索引的累計訪問信息。
清單 13. db2pd 查看表信息
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
|
AGDPCMB1:/home/db2gdpc$db2pd -d chgmdb -tcbstats nocatalog Database Member 0 -- Database CHGMDB -- Active -- Up 0 days 01:27:49 -- Date 2018-03-07-15.58.13.184798 TCB Table Information:Address TbspaceID TableID PartID MasterTbs MasterTab TableName SchemaNm ObjClass DataSize LfSize LobSize XMLSize IxReqRebld0x0A0005024DDDDAB0 2 -1 n/a 2 -1 INTERNAL SYSIBM Perm 1 0 0 0 No0x0A0005024DCF9430 3 1540 n/a 3 1540 LOCKS DB2GDPC Perm 1787 0 64 0 No0x0A0005024DCF6EB0 3 -1 n/a 3 -1 INTERNAL SYSIBM Perm 7 0 0 0 No0x0A0005024DDDE8B0 2 5 n/a 2 5 TEST DB2GDPC Perm 8013 0 0 0 No TCB Table Stats:Address TableName SchemaNm Scans UDI RTSUDI PgReorgs NoChgUpdts Reads FscrUpdates Inserts Updates Deletes OvFlReads OvFlCrtes PgDictsCrt CCLogReads StoreBytes BytesSaved0x0A0005024DDDDAB0 INTERNAL SYSIBM 0 0 0 0 0 4 0 0 0 0 0 0 0 0 - - 0x0A0005024DCF9430 LOCKS DB2GDPC 0 147 147 0 0 0 0 0 0 0 0 0 0 0 - - 0x0A0005024DCF6EB0 INTERNAL SYSIBM 0 0 0 0 0 7 0 0 0 0 0 0 0 0 - - 0x0A0005024DDDE8B0 TEST DB2GDPC 1 0 0 0 0 592865 0 0 0 0 0 0 0 0 - - |
db2pd 的這個輸出里面關注 Scans，Reads，Inserts，Updates 和 Deletes。其中 Scans 表示發生了表掃描的次數。Reads，Inserts，Updates 和 Deletes 分別是讀增改刪的次數。這些值都是累計值。如果需要當前實際的訪問數量，需要通過抓取多次取差值排序才能知道。這個是非常不直觀的。我在一鍵分析工具里面將個思路實現，最終通過計算出 Reads，Inserts，Updates 和 Deletes 的差值總和來排序獲取到熱點表。
獲取相關應用和 SQL
獲取到熱點表之后的下一步就是找到當前訪問這個熱點表的應用 AppHDL 和對應的 SQL 語句。Db2 的默認隔離級別是 RS。即便是查詢語句，也會在表上加共享鎖。所以通過查看當前的數據庫鎖信息，找到在熱點表上加了鎖的應用就好了。
清單 14. db2pd 查看表鎖信息
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
|
AGDPCMB1:/home/db2gdpc$db2pd -d chgmdb -lock showlocks|more Database Member 0 -- Database CHGMDB -- Active -- Up 0 days 02:00:29 -- Date 2018-03-07-16.30.53.779832 Locks:Address TranHdl Lockname Type Mode Sts Owner Dur HoldCount Att ReleaseFlg rrIID TableNm SchemaNm 0x0A0005000761CD00 40 414141414166416415C78BFEC1 PlanLock ..S G 40 1 0 0x00000000 0x40000000 0 N/A N/A 414141414166416415C78BFEC1 SQLP_PLAN ({41414141 41664164 15C78BFE}, loading=0)0x0A000500075BD600 13 00030604000000000000000054 TableLock .IX G 13 1 1 0x00202000 0x40000000 0 LOCKS DB2GDPC 00030604000000000000000054 SQLP_TABLE (obj={3;1540})0x0A000500075C2F80 14 00030604000000000000000054 TableLock .IX G 14 1 1 0x00202000 0x40000000 0 LOCKS DB2GDPC 00030604000000000000000054 SQLP_TABLE (obj={3;1540})0x0A000500075C6380 15 00030604000000000000000054 TableLock .IX G 15 1 1 0x00202000 0x40000000 0 LOCKS DB2GDPC 00030604000000000000000054 SQLP_TABLE (obj={3;1540})0x0A0005000761D400 40 00020005000000000000000054 TableLock .IS G 40 1 0 0x00003000 0x40000000 0 TEST DB2GDPC 00020005000000000000000054 SQLP_TABLE (obj={2;5}) |
通過 TableNm 和 SchemaNm 匹配到熱點表，獲取到 TranHdl，然后通過 db2pd 的 transactions 選項找到對應的 AppHandl。例如在這個案例里面 TEST 是一張熱點表。從鎖信息來看 TranHdl 為 40 的事務占用了鎖。下一步通過 TranHdl 找 AppHandl：
清單 15. db2pd 查看事務信息
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
|
AGDPCMB1:/home/db2gdpc$db2pd -d chgmdb -transactions 40 Database Member 0 -- Database CHGMDB -- Active -- Up 0 days 02:04:26 -- Date 2018-03-07-16.34.50.447672 Transactions:Address AppHandl [nod-index] TranHdl Locks State Tflag Tflag2 Firstlsn Lastlsn Firstlso Lastlso LogSpace SpaceReserved TID AxRegCnt GXID ClientUserID ClientWrkstnName ClientApplName ClientAccntng 0x0A00050001064480 19451 [000-19451] 40 3 READ 0x00000000 0x00000000 0x0000000000000000 0x0000000000000000 0 0 0 0 0x0000081DB04F 1 0 n/a n/a n/a n/a Total application commits : 806 Total application rollbacks : 25 |
最后通過應用的 AppHandl 找到對應的 SQL，過程和前面幾個案例一樣。
一鍵分析熱點表問題
我在一鍵檢查工具里將上述分析過程自動化處理，間隔 10 秒抓取兩次表訪問數據，計算差值，然后獲取到熱點表。基于每個熱點表的當前加鎖信息找到對應的事務和應用，展示出當前正在執行的 SQL。
清單 16. db2pd 查看事務信息
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
|
AGDPCMB1:/home/db2gdpc$python db2_check_hang_105.py chgmdb hottable ################################################################################ Show hot tables and its statements ################################################################################ #DB2GDPC.TEST is hot.#Reads: 12266 Inserts: 0 Updates: 0 Deletes: 0 Scans: 0#The apphdl on this table are: ['19451', '19452', '19453']************statements 1 ***********The current stmt is:NULL . The last stmt is: select * from test . ************statements 2 ***********The current stmt is:NULL . The last stmt is: select * from test . ************statements 3 ***********The current stmt is:NULL . The last stmt is: select * from test . |
這個輸出里面的語句是同一個，執行時間應該都超過了 10 秒，所以 Scans 差值為 0。但事實上這個 SQL 是走的表掃描。通過這個工具可以立刻看到當前的熱表，對應的 apphdl 和 SQL。而 apphdl 可以用來殺 SQL。
查看占用臨時表的 SQL 語句
Db2 數據庫的 SQL 排序是在內存里進行的。SHEAPTHRES_SHR 參數是限制總的排序內存大小。SORTHEAP 參數是限制單個排序能占用的內存大小。當 SQL 排序的時候超出任意一個限制，那么數據需要放到系統臨時表里面來排序。相對于內存里排序，這個開銷就非常大，SQL 也會變得慢。如果系統臨時表對應的磁盤出現瓶頸，那整個數據庫也會運行緩慢。
誰在占用臨時表
系統臨時表是存儲在系統臨時表空間的一種數據庫自動創建和刪除的臨時表。通過查看 db2pd 的 tcbstats 選項能夠找到正在使用的臨時表。
清單 17. db2pd 查看臨時表
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
|
AGDPCMB1:/home/db2gdpc$db2pd -d chgmdb -tcbstats nocatalog Database Member 0 -- Database CHGMDB -- Active -- Up 0 days 19:13:27 -- Date 2018-03-08-09.43.51.707946 TCB Table Information:Address TbspaceID TableID PartID MasterTbs MasterTab TableName SchemaNm ObjClass DataSize LfSize LobSize XMLSize IxReqRebld0x0A0005024DDDDAB0 2 -1 n/a 2 -1 INTERNAL SYSIBM Perm 1 0 0 0 No0x0A0005024DCF9430 3 1540 n/a 3 1540 LOCKS DB2GDPC Perm 1787 0 64 0 No0x0A0005024DCF6EB0 3 -1 n/a 3 -1 INTERNAL SYSIBM Perm 7 0 0 0 No0x0A0005024E1132B0 1 2 n/a 1 2 TEMP (00001,00002) <54365>< Temp 8045 0 0 0 No0x0A0005024DDDE8B0 2 5 n/a 2 5 TEST DB2GDPC Perm 8013 0 0 0 No TCB Table Stats:Address TableName SchemaNm Scans UDI RTSUDI PgReorgs NoChgUpdts Reads FscrUpdates Inserts Updates Deletes OvFlReads OvFlCrtes PgDictsCrt CCLogReads StoreBytes BytesSaved0x0A0005024DDDDAB0 INTERNAL SYSIBM 0 0 0 0 0 10 0 0 0 0 0 0 0 0 - - 0x0A0005024DCF9430 LOCKS DB2GDPC 0 147 147 0 0 0 0 0 0 0 0 0 0 0 - - 0x0A0005024DCF6EB0 INTERNAL SYSIBM 0 0 0 0 0 7 0 0 0 0 0 0 0 0 - - 0x0A0005024E1132B0 TEMP (00001,00002) <54365>< 0 0 0 0 0 60386 0 592865 0 0 0 0 0 0 126720902 0 0x0A0005024DDDE8B0 TEST DB2GDPC 5 0 0 0 0 2964325 0 0 0 0 0 0 0 0 - - |
查找表名是 TEMP 的記錄，案例里面是"TEMP (00001,00002)" ，對應的 SchemaNm 是"<54365><DB2GDPC >"（案例里的命令加上 full 選項就能看到全部內容：db2pd -d chgmdb -tcbstats nocatalog -full ） 。這里的 54365 就是應用的鏈接句柄 AppHdl。DB2GDPC 是連接用戶也就是 schema。下面基于 AppHdl 就可以找到正在運行的 SQL 是什么了。
我在一鍵檢查工具里面通過 db2pd 獲取到所有占用了臨時表的應用鏈接句柄 AppHDL，然后將 SQL 都展示出來。
清單 18. 一鍵檢查工具查看臨時表
|
1
2
3
4
5
6
7
8
9
|
AGDPCMB1:/home/db2gdpc$python db2_check_hang_105.py chgmdb temptable ################################################################################ Show applications using temptable ################################################################################ ************Statements for application: 54365 ***********The current stmt is:NULL . The last stmt is: select * from test order by c5 . |
獲取到了 SQL 就可以分析是否有異常，如果有異常，判斷是否基于 apphdl 來殺 SQL。
查看當前運行的管理操作
Db2 的一些管理類操作也可能影響數據庫的性能。所以當數據庫緩慢的時候，我們還需要查看一下當前數據庫內有哪些管理性的操作。
是否存在統計信息收集
統計信息收集（runstats）的對象是表和索引。Db2 在做 runstats 的時候需要掃描大量數據并計算，因此是一類開銷比較大的操作。db2pd 的 runstats 選項可以查看當前正在執行的 runstats。
清單 19. db2pd 查看 runstats
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
|
AGDPCMB1:/home/db2gdpc$db2pd -d chgmdb -runstats Database Member 0 -- Database CHGMDB -- Active -- Up 12 days 20:23:45 -- Date 2017-12-18-11.02.56.265437 Table Runstats Information: Retrieval Time: 12/18/2017 11:02:56TbspaceID: -6 TableID: -32768Schema: CHGMDB TableName: SERVICE_LOG Status: In Progress Access: Allow writeSampling: No Sampling Rate: -Start Time: 12/18/2017 11:02:43 End Time: - Total Duration: -Cur Count: 61797 Max Count: 500841 Retrieval Time: 12/18/2017 11:02:56TbspaceID: 2 TableID: 5 Schema: DB2GDPC TableName: TEST Status: Completed Access: Allow writeSampling: No Sampling Rate: -Start Time: 12/18/2017 11:01:48 End Time: 12/18/2017 11:01:48Total Duration: 00:00:01Cur Count: 0 Max Count: 0 Index Runstats Information: Retrieval Time: 12/18/2017 11:02:56TbspaceID: 2 TableID: 5 Schema: DB2GDPC TableName: TEST Status: Completed Access: Allow writeStart Time: 12/18/2017 11:01:48 End Time: 12/18/2017 11:01:49Total Duration: 00:00:01Prev Index Duration [1]: 00:00:01Prev Index Duration [2]: -Prev Index Duration [3]: -Cur Index Start: 12/18/2017 11:01:48Cur Index: 2 Max Index: 2 Index ID: 2 Cur Count: 0 Max Count: 0 |
其中 End Time 為空的記錄就是當前正在做的 runstats。這里能看到具體是表還是索引正在做 runstats。結合當前的熱點表，長時間運行的 SQL 等信息一起分析數據庫變慢的原因。
是否存在表重組
數據庫的表和索引重組需要將磁盤上的數據重新整理一遍。這也是一個比較漫長和耗資源的操作。db2pd 的 reorgs 選項能找到當前正在執行的重組操作。
清單 20. db2pd 查看 reorgs
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
AGDPCMB1:/home/db2gdpc$db2pd -d chgmdb -reorgsDatabase Member 0 -- Database CHGMDB -- Active -- Up 21 days 01:26:55 -- Date 2017-12-26-16.06.06.495099 Table Reorg Information:Address TbspaceID TableID PartID MasterTbs MasterTab TableName Type IndexID TempSpaceID0x0A0006024E14FB00 2 5 n/a n/a n/a TEST Offline 0 2 Table Reorg Stats:Address TableName Start End PhaseStart MaxPhase Phase CurCount MaxCount Status Completion0x0A0006024E14FB00 TEST 12/26/2017 16:05:54 n/a 12/26/2017 16:05:55 3 Build 3007 8012 Started 0 |
找到了正在重組的表，再結合當前的熱點表，長時間運行的 SQL 等信息一起分析數據庫變慢的原因。
是否存在 load 和 backup
Db2 內部有一個內存塊叫做 Utilities heap，用來做一些管理類的操作。這個內存塊的大小由數據庫參數 UTIL_HEAP_SZ 來控制。例如 load 和 backup 這兩種操作就需要使用這塊內存。這個內存不足會導致 load 和 backup 變慢或者失敗。而 load 和 backup 也是開銷比較大的操作。db2pd 工具提供了 utilities 選項查看實例級別的此類操作。
清單 21. db2pd 查看 utilities
|
1
2
3
4
5
6
7
8
9
10
11
|
AGDPCMB1:/home/db2gdpc$db2pd -utilities Database Member 0 -- Active -- Up 0 days 20:11:37 -- Date 2018-03-08-10.40.23.994613 Utilities:Address ID Type State Invoker Priority StartTime DBName NumPhases CurPhase Description Progress:Address ID PhaseNum CompletedWork TotalWork StartTime Description |
數據庫緩慢的時候第一時間發現是否存在管理類的操作很有必要。這對于分析堵塞問題的方向很有幫助。這類管理性的操作不能隨便處理。需要具體分析它的影響。例如 load 操作如果殺掉，會導致當前表不可用，需要 load 重置?？赡軐е赂鼔牡慕Y果。但是基于表的大小，load 的數據量可以估算還需要多長時間這個操作會完成，期間是否可以有辦法加速等。
一鍵檢查分析工具介紹
根據上述各種導致數據庫堵塞的場景和分析方法，我編寫了一個 python 腳本的一鍵檢查分析工具，用來快速定位和分析數據庫堵塞問題。這個腳本完全基于 db2pd 命令，可以在數據庫堵塞的情況下，避免連接數據庫失敗，從內存直接獲取診斷信息。這個腳本是基于 Db2 10.5 版本編寫的，不適用與其他版本。
清單 22. 一鍵檢查工具使用方法
|
1
2
3
4
5
6
7
8
9
10
|
AGDPCMB1:/home/db2gdpc$python db2_check_hang_105.pyusage ./db2_check_hang.py <dbname> <option>#Valid <options> are:all :collect all information, which is default.lock : show lock chains and statements of holders, and print killcmd.latch : show latch chains and get snapshot, stack for holders. print killcmd.stmt : show top 10 running statements and its apolication handler.hottable : show top tables(siud > 1000 in 10 seconds), get running stmt and apphdl.util : show runstats, reorgs, loads, backup.temptable: show applications using temtable, and show the sql statement. |
這是個 python 腳本，需要安裝 python 來調用。執行用戶為數據庫實例用戶。dbname 是數據庫名。option 選項可以選擇案例里的內容。如果不輸入 option，默認是 all，收集全部內容。如果輸入單項，例如 lock，那么只收集鎖等待相關的信息。
總結
導致數據庫堵塞的問題根源可能性非常多。處理緊急問題最忌慌亂，找錯方向浪費時間，選擇錯誤的處理步驟，還可能導致問題更嚴重。我經歷過一個反面案例：某個分區數據庫發生了堵塞問題，管理員分析定位到是一個大事務造成的。這個事務查詢了大量數據并在做插入操作。數據庫管理員一著急殺掉了這個事務，導致事務回滾。結果這個事務回滾非常慢，整整花了兩天才釋放。期間業務完全受影響。其實如果當時評估下實際完成的數據量是不是已經很多，是不是快要完成了，然后耐心等待事務完成可能會更快。當然這方面的判斷需要依賴數據庫管理員的處理經驗。
這個文章里面將一些常見的原因做了分析和處理。借助一鍵檢查工具，快速分析問題和找到解決方案。
參考資源
- Db2 for Linux UNIX and Windows：獲得 DB2 家族產品和特性的描述。
- 參考 IBM DB2 database and SAP software，了解更多 DB2 SAP 相關內容。
- 通過訪問 developerWorks 中國 Information Management 專區 的 Information Management 技術資源中心獲得更多的文章、教程和多媒體課件等學習資源。
好了，以上就是這篇文章的全部內容了，希望本文的內容對大家的學習或者工作具有一定的參考學習價值，如果有疑問大家可以留言交流，謝謝大家對服務器之家的支持。
原文鏈接：https://www.ibm.com/developerworks/cn/analytics/library/db2-common-blocking-problem-analyze/index.html
