查看当前运行时间长的 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 等待等现象，但不是完全堵塞的状态。现象就是热点表相关的 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 重置。可能导致更坏的结果。但是基于表的大小，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
