DB2 性能分析工具介绍：Event Monitor 篇（转）

https://www.ibm.com/developerworks/cn/data/library/techarticle/dm-1112qiaob/

引言

DB2 提供了两个比较常用的数据库性能分析工具，分别是 Event Monitor 和 Snapshot。两者都可以用来实时采集并分析数据库的使用情况，例如数据库 buffer pool 的使用状况；即时的数据库 locking 状态；SQL 语句的信息等等。本文将就 Event Monitor 的使用方法作简单的介绍。

Event Monitor 是事件驱动的。这就意味着，只要 monitor 是打开的状态，一旦其对应的数据库事件发生，就会被记录下来。这种记录是持续性的。也正是因为这种持续性，使用 Event Monitor 会对目标数据库系统产生一定额外的性能压力。所以如果目标数据库系统本身就是个比较繁忙的系统，在使用 Event Monitor 采集数据时就需要考虑如何尽量地降低对系统的性能影响。

Event Monitor 类型

表 1. Event Monitor 类型 :

Deadlocks	只提供参与到 deadlock 的应用名。
Deadlocks with Details	不止提供参与到 deadlock 的应用名，还提供引起 deadlock 的 SQL 语句以及同时存在的其它数据库锁。相对于 DEADLOCKS, 使用 DEADLOCKS WITH DETAILS 时由于采集了额外的信息，会产生一定的性能开销。
Deadlock with Details History	比 DEADLOCKS WITH DETAILS 提供更多的信息，例如相关 SQL 语句的历史信息。相应地，其产生的性能开销也比 DEADLOCKS WITH DETAILS 略大。
Deadlock with Details History Values	比 DEADLOCKS WITH DETAILS HISTORY 更多提供了相关 SQL 语句执行时的一些系统变量的值。其对系统性能的影响也更显著。
Statements	SQL 语句开始 / 结束时间，CPU 使用情况，动态 SQL 语句文本，语句执行结果，以及 fetch 记录数量等信息。
Transactions	UOW 开始 / 结束时间，CPU 使用情况，locking 以及 logging 等信息。
Connections	第 3 行中的第 3 个单元格
Database	所有数据库级别的信息。
Bufferpools	各 buffer pool 的预读，page 切换以及直接 I/O 等信息。
Tablespaces	各 table space 的预读，page 切换以及直接 I/O 等信息。
Tables	各数据库表的读 / 写行数。

如何使用 Event Monitor

在进一步讨论如何降低使用 Event Monitor 带来的性能压力前，让我们先看一下有几种形式的 Monitor。

DB2 一共提供了三种形式的 Monitor：表形式的 Event Monitor，文件形式的 Event Monitor，以及管道形式的 Event Monitor。

它们各自的区别就在于事件信息记录的格式：

表形式的 Event Monitor 把事件信息记录在数据库表里，文件形式的 Event Monitor 把事件信息记录在文件里，而管道形式的 Event Monitor 则把事件信息发送到预定义的管道里由外部程序接收。相对于管道形式的 Event Monitor，前两种形式更常用。所以本文也会着重介绍如何使用表形式和文件形式的 Event Monitor。

表 2. 降低性能影响的注意点

通用注意点	Eventtype	CREATE EVENT MONITOR emon1 FOR CONNECTIONS, DEADLOCKS WITH DETAILS WRITE TO TABLE STATEMENTS monitor 是产生额外系统负载最重的一个 monitor。如果系统性能是个问题时，最好不要把 STATEMENTS monitor 与其它 monitor 同时使用。
Buffersize	CREATE EVENT MONITOR emon1 FOR CONNECTIONS WRITE TO TABLE BUFFERSIZE 8 为了尽量减少频繁数据库表插入或是文件写入造成的系统开销，事件记录会先被写入内存里的一段缓存区间。当缓存被写满后，所有记录会一次性插入数据库表或写入文件。基于性能方面的考虑，比较活跃的 Event Monitor 应该分配相对更大的缓存空间。BUFFERSIZE 表示了缓存空间的大小（4K 页的数量）。该缓存空间是从数据库的 monitor heap 里分配的，所以分配给所有 Event Monitor 的总内存空间不应该超过 monitor heap 的大小（使用 `“db2 get dbm cfg \| grep MON_HEAP_SZ”`来查询 monitor heap 的值）。
Blocked/Nonblocked	CREATE EVENT MONITOR emon1 FOR CONNECTIONS WRITE TO TABLE BLOCKED CREATE EVENT MONITOR emon1 FOR CONNECTIONS WRITE TO TABLE NONBLOCKED 如果设定成 BLOCKED ，在事件记录被从缓存移至数据库表或文件时，事件发生器会等待记录移动结束才恢复工作。在这种情况下，能够保证事件信息不丢失，但是会造成系统性能的下降。所以，当性能是个问题时，该参数应该被设定成 NONBLOCKED。该设定可能会造成事件信息丢失，但是对数据库性能的影响可以被降到最小。
表形式专用	Logic Data Groups	CREATE EVENT MONITOR emon1 FOR DEADLOCKS WITH DETAILS WRITE TO TABLE DLCONN (EXCLUDES(agent_id, lock_wait_start_time)), DLLOCK (INCLUDES(lock_mode, table_name)) 每个 Event Monitor 会使用几个数据库表来保存收集到的事件信息。例如，Statements Event Monitor 采集 SQL 语句信息并保存在下列数据库表中：CONNHEADER, STMT, SUBSECTION, 及 CONTROL。可以通过把不需要的事件表或字段排除出数据采集列表来最小化对数据库性能的影响。
Tablespace	CREATE EVENT MONITOR emon1 FOR CONNECTIONS WRITE TO TABLE CONN (TABLE conns, IN mytablespace) 可以为事件数据库表指定表空间。通过这种方法来避免事件记录写至过于繁忙的表空间。
PCTDEACTIVATE	CREATE EVENT MONITOR emon1 FOR CONNECTIONS WRITE TO TABLE CONN PCTDEACTIVATE 90 参数 PCTDEACTIVATE 可以被用来控制 Event Monitor 的磁盘空间使用。该参数是一个百分数。举例来说，如果设置 PCTDEACTIVATE 为 90，当事件数据库表所在的 tablespace 被 90% 写满时，Event Monitor 会被自动关闭。该参数只有在使用 DMS（Database Managed Tablespace）时才有效。
文件形式专用	Maxfiles/Maxfilesize	与 PCTDEACTIVATE 参数类似，Maxfiles 及 Maxfilesize 能被用来控制文件形式的 Event Monitor 能使用多大的磁盘空间。 MAXFILESZIE 定义了单个 Event Monitor 文件最大能占用多少个 4K 页。当最大文件空间被写满后，新的事件文件将被创建用来保存事件信息。该过程一直持续至创建的文件个数达到了预定义的 MAXFILES。在这个时候，该 Event Monitor 将被自动关闭。

在做好了所有的设定以后，以下两项措施也有助于进一步降低在生产系统中使用 Event Monitor 的风险：

1. 在生产环境使用 Event Monitor 前，在测试环境先进行一定的测试或者在生产环境里做一下短时间的试运行来预测一下风险可能会有多大。

2. 设定一定的性能阈值 ( 例如：CPU 使用率达到 90%) 并且密切监视该性能指标。一旦超过了预设的阈值则需要立即停止 Event Monitor 的运行。

如何解读 Event Monitor 信息

事件信息都收集好后，就可以根据这些信息作进一步的分析了。

Statements Event Monitor 生成的报告可以用来做 SQL 语句分析。如果使用的是文件形式的 Monitor，还需要对数据文件做一定的预处理

1	`db2evmon – path event_files_directory > output_filename`

该命令可以把二进制的事件记录文件转成文本文件。

清单 1. SQL 语句 Event Monitor 报告样例

1) Statement Event ...

Appl Handle: 53793

Appl Id: *LOCAL.db2inst1.101126060601

Appl Seq number: 00003

Record is the result of a flush: FALSE

-------------------------------------------

Type : Dynamic

Operation: Describe

Section : 201

Creator : NULLID

Package : SQLC2G15

Consistency Token : AAAAALIY

Package Version ID :

Cursor : SQLCUR201

Cursor was blocking: TRUE

Text : select * from schema.table

-------------------------------------------

Start Time: 11/26/2010 15:06:35.641755

Stop Time: 11/26/2010 15:06:35.665380

Elapsed Execution Time: 0.023625 seconds

Number of Agents created: 1

User CPU: 0.003768 seconds

System CPU: 0.000000 seconds

Statistic fabrication time (milliseconds): 0

Synchronous runstats time (milliseconds): 0

Fetch Count: 62

Sorts: 0

Total sort time: 0

Sort overflows: 0

Rows read: 62

Rows written: 0

Internal rows deleted: 0

Internal rows updated: 0

Internal rows inserted: 0

Bufferpool data logical reads: 1

Bufferpool data physical reads: 0

Bufferpool temporary data logical reads: 0

Bufferpool temporary data physical reads: 0

Bufferpool index logical reads: 0

Bufferpool index physical reads: 0

Bufferpool temporary index logical reads: 0

Bufferpool temporary index physical reads: 0

Bufferpool xda logical page reads: 0

Bufferpool xda physical page reads: 0

Bufferpool temporary xda logical page reads: 0

Bufferpool temporary xda physical page reads: 0

SQLCA:

sqlcode: 0

sqlstate: 00000

Text 字段显示的是运行的 SQL 语句。Elapsed Execution Time 字段则表明了该 SQL 语句的执行时间。同一条 SQL 语句的执行时间相加就得到了该语句在被监视期间的累计执行时间。通常情况下，累计执行时间越长的 SQL 语句就是越值得分析的对象。选定了分析对象的 SQL 语句后就可以利用 DB2 提供的一系列的工具来寻找优化方案。Visual Explain，db2exfmt，以及 db2expln 可以用来分析该语句的执行计划。db2advis 可以用来确定是否可以通过优化数据库索引的途径来提高语句执行效率。

Deadlock 分析

Deadlock Event Monitor 生成的报告提供了 deadlock 产生的原因及其历史的详细信息，可以用来做 deadlock 分析。

清单 2. Deadlock Event Monitor 报告样例

100

101

3382) Deadlocked Connection ...

Deadlock ID: 1

Participant no.: 2

Participant no. holding the lock: 1

Appl Id: 10.207.4.51.40897.100826202041

Appl Seq number: 03988

Tpmon Client Workstation: server01

Appl Id of connection holding the lock: 10.207.4.51.39361.100826202035

Seq. no. of connection holding the lock: 00001

Lock wait start time: 08/27/2010 10:38:13.168058

Lock Name : 0x020012032900E9161100000052

Lock Attributes : 0x00000000

Release Flags : 0x20000000

Lock Count : 1

Hold Count : 0

Current Mode : none

Deadlock detection time: 08/27/2010 10:38:22.765817

Table of lock waited on : table

Schema of lock waited on : schema

Data partition id for table : 0

Tablespace of lock waited on : USERSPACE1

Type of lock: Row

Mode of lock: X - Exclusive

Mode application requested on lock: U - Update

Node lock occured on: 0

Lock object name: 73398812713

Application Handle: 957

Deadlocked Statement:

Type : Dynamic

Operation: Fetch

Section : 1

Creator : NULLID

Package : SYSSH200

Cursor : SQL_CURSH200C1

Cursor was blocking: FALSE

Text : SELECT value1, value2 FROM schema.table WHERE value1 = ? for update with rs

List of Locks:

……

Lock Name : 0x020012032900EC161100000052

Lock Attributes : 0x00000000

Release Flags : 0x00000080

Lock Count : 1

Hold Count : 0

Lock Object Name : 73399009321

Object Type : Row

Tablespace Name : table

Table Schema : schema

Table Name : EXCLUSION

Data partition id : 0

Mode : U - Update

……

13384) Deadlocked Connection ...

Deadlock ID: 1

Participant no.: 1

Participant no. holding the lock: 2

Appl Id: 10.207.4.51.39361.100826202035

Appl Seq number: 09195

Tpmon Client Workstation: server01

Appl Id of connection holding the lock: 10.207.4.51.40897.100826202041

Seq. no. of connection holding the lock: 00001

Lock wait start time: 08/27/2010 10:38:13.166513

Lock Name : 0x020012032900EC161100000052

Lock Attributes : 0x00000000

Release Flags : 0x40000000

Lock Count : 1

Hold Count : 0

Current Mode : none

Deadlock detection time: 08/27/2010 10:38:22.787777

Table of lock waited on : table

Schema of lock waited on : schema

Data partition id for table : 0

Tablespace of lock waited on : USERSPACE1

Type of lock: Row

Mode of lock: U - Update

Mode application requested on lock: U - Update

Node lock occured on: 0

Lock object name: 73399009321

Application Handle: 951

Deadlocked Statement:

Type : Dynamic

Operation: Execute

Section : 1

Creator : NULLID

Package : SYSSH200

Cursor : SQL_CURSH200C1

Cursor was blocking: FALSE

Text : UPDATE schema.table SET v2 = ?, v3 = ? WHERE value1 IN (?,?,?)

List of Locks:

Lock Name : 0x020012032900E9161100000052

Lock Attributes : 0x00000000

Release Flags : 0x40000000

Lock Count : 1

Hold Count : 0

Lock Object Name : 73398812713

Object Type : Row

Tablespace Name : USERSPACE1

Table Schema : schema

Table Name : table

Data partition id : 0

Mode : X - Exclusive

……

以上的报告样例里很清楚地显示了死锁是由哪两个数据库锁造成的。相应锁的类型及相关的 SQL 语句也可以在报告里找到。分析并修改相关的 SQL 语句就有可能可以降低死锁发生的概率。

Bufferpool 分析

Bufferpool 分析需要利用 Bufferpools Event Monitor 生成的报告。

清单 3. Bufferpool Event Monitor 报告样例

3) Bufferpool Event ...

Bufferpool Name: IBMDEFAULTBP

Database Name: database

Database Path: /shared/dbg/db2inst3/db2inst3/NODE0000/SQL00001/

Buffer Pool Statistics:

Buffer pool data logical page reads: 14871152

Buffer pool data physical page reads: 1699818

Buffer pool data page writes: 53823

Buffer pool index logical page reads: 8606405

Buffer pool index physical page reads: 290822

Buffer pool index page writes: 272282

Buffer pool xda logical page reads: 0

Buffer pool xda physical page reads: 0

Buffer pool xda page writes: 0

Buffer pool read time (milliseconds): 1536574

Buffer pool write time (milliseconds): 353641

Files closed: 0

Buffer pool asynch data page reads: 1694131

Buffer pool asynch data page read reqs: 59110

Buffer pool asynch data page writes: 53371

Buffer pool asynch index page reads: 227455

Buffer pool asynch index page read reqs: 8527

Buffer pool asynch index page writes: 270292

Buffer pool asynch xda page reads: 0

Buffer pool asynch xda page read reqs: 0

Buffer pool asynch xda writes: 0

Buffer pool asynch read time: 1327887

Buffer pool asynch write time: 347809

No victim buffers available: 1509238

Unread prefetch pages: 2995

Direct I/O Statistics:

Sectors read directly: 13610

Sectors written directly: 1695616

Direct read requests: 1382

Direct write requests: 3763

Direct read time: 3758

Direct write time: 22236

Vectored IOs: 67407

Pages from vectored IOs: 1921234

Block IOs: 0

Pages from block IOs: 0

一个简单的计算 bufferpool 使用效率的公式是：

1 – (Bufferpool 数据逻辑页读取数 + Bufferpool 索引逻辑页读取数 ) / (Bufferpool 数据物理页读取数 + Bufferpool 索引物理页读取数 )

一般来说，如果计算出的 bufferpool 使用效率低于 90%，就可以考虑通过增加 bufferpool 的大小来提升系统性能了。

Memory 分析

Database Event Monitor 生成的报告可以用来做 Memory 分析。

清单 4. Memory Event Monitor 报告样例

3) Database Event

Record is the result of a flush: FALSE

Lock Statistics:

Lock Waits: 0

Total time waited on locks (milliseconds): 0

Deadlocks: 0

Lock escalations: 0

X lock escalations: 0

Lock timeouts: 0

Sort Statistics:

Sorts: 844

Total sort time (milliseconds): 160043

Sort overflows: 80

Sort share heap high water mark: 9851

Post Shared Memory Threshold Sorts: 20

Hash Statistics:

Hash Joins: 25

Hash Loops: 0

Hash Join Small Overflows: 0

Hash Join Overflows: 0

Post Shared Memory Threshold Hash Joins: 0

……

Node Number: 0

Memory Pool Type: Backup/Restore/Util Heap

Current size (bytes): 65536

High water mark (bytes): 196608

Configured size (bytes): 319815680

如果观察到的 Lock escalations 和 X lock escalations 数量比较大的话，可能就说明了分配的 LOCKLIST memory 过小。过高的 Sort overflow 率 (Sort overflows / Sorts) 或是过高的 Hash Join overflow 率 ((Hash Join Small Overflows + Hash Join Overflows) / Hash Joins) 就意味着没有分配足够的 SORTHEAP memory。另外，如果 memory High water mark 接近于 Configured size 就说明配置的 memory 数量不足。

Tablespace/Table 分析

Tablespaces/Tables Event Monitor 报告里的信息可以用来发现哪些 tablespace/table 是比较繁忙的。

清单 5. Tablespace/Table Event Monitor 报告样例

5) Tablespace Event ...

Tablespace Name: USERSPACE1

Record is the result of a flush: FALSE

File System Caching: Yes

Buffer Pool Statistics:

Buffer pool data logical page reads: 14846454

Buffer pool data physical page reads: 1699227

Buffer pool data page writes: 31111

Buffer pool index logical page reads: 8593610

Buffer pool index physical page reads: 290381

Buffer pool index page writes: 272125

Buffer pool xda logical page reads: 0

Buffer pool xda physical page reads: 0

Buffer pool xda page writes: 0

Buffer pool read time (milliseconds): 1529939

Buffer pool write time (milliseconds): 350770

Files closed: 0

Buffer pool asynch data page reads: 1693042

Buffer pool asynch data page read reqs: 58409

Buffer pool asynch data page writes: 30761

Buffer pool asynch index page reads: 227412

Buffer pool asynch index page read reqs: 8489

Buffer pool asynch index page writes: 270137

Buffer pool asynch xda page reads: 0

Buffer pool asynch xda page read reqs: 0

Buffer pool asynch xda writes: 0

Buffer pool asynch read time: 1325077

Buffer pool asynch write time: 345169

No victim buffers available: 1435565

Unread prefetch pages: 2982

Direct I/O Statistics:

Sectors read directly: 3488

Sectors written directly: 1695176

Direct read requests: 436

Direct write requests: 3752

Direct read time: 476

Direct write time: 22217

4) Table Event ...

Table schema: SCHEMA

Table name: TEMP (00001,00002)

Data partition id: 0

Record is the result of a flush: FALSE

Table type: Temporary

Data object pages: 1

Index object pages: 0

Lob object pages: 0

Long object pages: 0

Rows read: 3

Rows written: 1

Overflow Accesses: 0

Page reorgs: 0

Tablespace id: 1

Tablespace 和 table 的读写次数是该 tablespace/table 是否繁忙的指标。如果读写频繁的 Table Space 或 Table 是和其它数据库对象共享一个磁盘，则把该 Table Space 或 Table 迁移到一个独立的磁盘会显著提高系统的效率。另外，创建一个跨磁盘的 Table Space/Table 对系统性能的提高也有一定的帮助。