记一次RAC环境性能诊断过程

查看原文

其他

记一次RAC环境性能诊断过程

2015-07-08 杨廷琨 云和恩墨

这是一次协助地方公司解决数据库性能的过程。虽然现在并不负责这个数据库的维护工作，但是对这个数据库还是很熟悉的，因为这个数据库RAC环境的建立以及后期的一次数据迁移都为本人实施的，这也使得定位和解决问题的时候少了很多障碍。

1. 详细诊断过程

SQL> selectinst_id, event, count(*)

2 fromgv$session

3 where username is not null

4 group by inst_id, event

5 having count(*) > 5

6 order by 2, 1;

INST_ID EVENT COUNT(*)

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

1 SQL*Net message from client 20

2 SQL*Net message from client 27

1 enq: TX - row lock contention 10

2 enq: TX - row lock contention 10

1 gc buffer busy 49

2 gc buffer busy 47

1 gc cr multi block request 18

2 gc cr multi block request 18

1 gc cr request 8

2 gc cr request 6

已选择10行。

发现绝大部分的等待都是与RAC有关的全局等待事件。第一反应是两个节点间的通信是否存在什么问题。检查了操作系统和CLUSTER的状态，并没有发现什么异常。

前不久碰到由于CLUSTER组件本身的问题，导致RAC数据库两个节点在相互通信时存在异常，并最终导致数据库崩溃的情况。不过检查CLUSTER组件，并没有发现异常之处，除了GC相关的等待特别多以外，其他的方面和以前碰到的情况并不完全相同。而且如果问题是CLUSTER组件造成的，那么在整个CLUSTER环境重启之后就会消失。可是现在碰到的这个问题，在重启CLUSTER和数据库后仍然出现。

因此判断这并不由于通信和CLUSTER组件导致的问题，而是数据库本身的问题。

既然第一条路没有走通，那么先从其他方面入手。上面的等待事件中如果排除gc相关的，那么基本上就剩下enq: TX - row lock contention了。查询对应这个事件对应的SQL语句，发现等待的会话在对ORD_ORDER_RECEIVE表进行删除。删除语句本身没有特别之处，但是这些删除操作持有锁的时间都出奇的长，于是检查这些删除语句的执行计划：

SQL> explain plan for

2 Delete from ord_order_receive

3 where order_item_id = '805D972E6F5153DC38E5AD26'

4 andsend_lot = 1;

已解释。

SQL> select *from table(dbms_xplan.display);

PLAN_TABLE_OUTPUT

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

Plan hash value:3884926111

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

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

| 0 | DELETE STATEMENT | | 1 | 140 | 71799 (1)| 00:16:46 |

|* 2 | TABLE ACCESS FULL| ORD_ORDER_RECEIVE | 1 | 140 | 71799 (1)| 00:16:46 |

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

PredicateInformation (identified by operation id):

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

2 -filter("ORDER_ITEM_ID"='805D972E6F5153DC38E5AD26' AND"SEND_LOT"=1)

已选择14行。

ORD_ORDER_RECEIVE表的记录数超过了1000万，但是上面的删除语句却没有选择索引扫描，这肯定会导致严重的性能问题。不仅如此，根据V$SESSION_WAIT视图找到的很多长时间等待的查询语句，同样是扫描这张表，同样选择了全表扫描，而没有使用索引。

在上面的DELETE语句中，用来过滤记录的ORDER_ITEM_ID列的选择度是非常高的，在这个表中仅次于主键，因此查询没有使用索引是很奇怪的。

SQL> SELECT INDEX_NAME, COLUMN_NAME,COLUMN_POSITION

2 FROMUSER_IND_COLUMNS

3 WHERE TABLE_NAME = 'ORD_ORDER_RECEIVE';

INDEX_NAME COLUMN_NAME COLUMN_POSITION

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

PK_ORD_ORDER_RECEIVE ID 1

TU_ORD_ORDER_RECEIVE_PROD_ID PRODUCT_ID 1

IND_ORD_ORDER_REC_REC_DATE RECEIVE_DATE 1

IND_ORD_RECEIVE_BUYERSENDER BUYER_ID 1

IND_ORD_RECEIVE_BUYERSENDER SENDER_ID 2

查询ORD_ORDER_RECEIVE表的索引情况，竟然发现ORDER_ITEM_ID这个列上没有创建任何索引，而这是不可思议的。从数据库的大量运行的SQL可以看出，这张表的这个字段是经常且大量被访问的，因此没有道理不创建索引：

SQL> SELECT COLUMN_NAME, NUM_DISTINCT,DENSITY

2 FROMUSER_TAB_COLUMNS

3 WHERE TABLE_NAME = 'ORD_ORDER_RECEIVE'

4 ANDCOLUMN_NAME = 'ORDER_ITEM_ID';

COLUMN_NAME NUM_DISTINCT DENSITY

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

ORDER_ITEM_ID 8433019 1.1858E-07

幸运的是存在一个和产品环境结构完全一致的测试环境，而且这个测试环境是前不久才建立的，登陆测试环境检查ORD_ORDER_RECEIVE表的索引情况：

SQL> SELECT INDEX_NAME, COLUMN_NAME,COLUMN_POSITION

2 FROMUSER_IND_COLUMNS

3 WHERE TABLE_NAME = 'ORD_ORDER_RECEIVE';

INDEX_NAME COLUMN_NAME COLUMN_POSITION

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

PK_ORD_ORDER_RECEIVE ID 1

TU_ORD_ORDER_RECEIVE_PROD_ID PRODUCT_ID 1

TU_ORD_ORDER_COMB_ITEM_FLAG ORDER_ITEM_ID 1

TU_ORD_ORDER_COMB_ITEM_FLAG RECEIVE_FLAG 2

IND_ORD_ORDER_REC_REC_DATE RECEIVE_DATE 1

IND_ORD_RECEIVE_BUYERSENDER BUYER_ID 1

IND_ORD_RECEIVE_BUYERSENDER SENDER_ID 2

已选择7行。

测试环境中是存在ORDER_ITEM_ID列和RECEIVE_FLAG列上建立了一个复合索引，而在产品环境上没有索引。产品环境前一段时间一直正常，只有最近两天才出现了性能问题，问题多半就是由于这个索引被误删除所致。

这个问题是根据enq: TX - row lock contention等待事件为线索找到的，可是最开始检查系统时发现绝大部分等待事件都与gc的等待有关，那么下面需要检查是否gc相关的等待也与ORD_ORDER_RECEIVE表缺少索引有关。

检查数据库中等待事件为gc buffer busy会话对应的SQL语句：

SQL> select sql_text

2 fromv$sqltext_with_newlines

3 where address in

4 (select sql_address

5 fromv$session

6 where sid = 484)

7 order by address, piece;

SQL_TEXT

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

SELECTORD_ORDER_RECEIVE.ID, ORD_ORDER_RECEIVE.PRODUCT_ID, ORD_O

RDER_RECEIVE.SEND_LOT,ORD_ORDER_RECEIVE.LOT_NO, ORD_ORDER_RECEI

VE.RECEIVE_QTY,ORD_ORDER_RECEIVE.RECEIVE_USERID, ORD_ORDER_RECE

IVE.RECEIVE_DATE,ORD_ORDER_RECEIVE.RECEIVE_REMARK, ORD_ORDER_RE

CEIVE.BALANCE_FLAG,ORD_ORDER_RECEIVE.BALANCE_DATE, ORD_ORDER_RE

CEIVE.ORDER_ITEM_ID,ORD_ORDER_RECEIVE.READY_USERID, ORD_ORDER_R

ECEIVE.READY_DATE,ORD_ORDER_RECEIVE.RECEIVE_FLAG, ORD_ORDER_REC

EIVE.INVOICE_NO,ORD_ORDER_RECEIVE.INVOICE_DATE, ORD_ORDER_RECEI

VE.SYNC_STATE, ORD_ORDER_RECEIVE.REPOSITORY_ID,ORD_ORDER_RECEIV

E.ORDER_ID,ORD_ORDER_RECEIVE.READY_REMARK, ORD_ORDER_RECEIVE.IN

VOICE_EFFECT_DATE,ORD_ORDER_RECEIVE.INVOICE_EXPIRE_DATE, ORD_OR

DER_RECEIVE.INVOICE_TOTAL,ORD_ORDER_RECEIVE.INVOICE_TRADE_PRICE

, ORD_ORDER_RECEIVE.INVOICE_RETAIL_PRICE,ORD_ORDER_RECEIVE.INVO

ICE_DISCOUNT_RATE,ORD_ORDER_RECEIVE.TRADE_QTY, ORD_ORDER_RECEIV

E.OPERATOR_FLAG,ORD_ORDER_RECEIVE.APP_NUM, ORD_ORDER_RECEIVE.BU

YER_ID,ORD_ORDER_RECEIVE.SENDER_ID, ORD_ORDER_RECEIVE.PLAT_ID F

ROM ORD_ORDER_RECEIVEWHERE ORD_ORDER_RECEIVE.ORDER_ITEM_ID='ZJJ

Y10000000000043680032'

已选择18行。

果然这个会话也与ORD_ORDER_RECEIVE表的ORDER_ITEM_ID列有关，勿庸置疑这个SQL语句的执行计划一定是全表扫描：

SQL> select count(*)

2 fromv$sqltext

3 where address in

4 (select sql_address

5 fromv$session

6 where event = 'gc buffer busy')

7 andlower(sql_text) like '%order_item_id%';

COUNT(*)

----------

不难看出导致大量gc buffer busy等待事件的SQL，都包含ORDER_ITEM_ID列。现在已经可以做出判断，正是ORDER_ITEM_ID列上索引的缺失导致了系统的性能问题。

获取测试环境中的索引定义：

SQL> SELECTDBMS_METADATA.GET_DDL('INDEX', 'TU_ORD_ORDER_COMB_ITEM_FLAG') FROM DUAL;

DBMS_METADATA.GET_DDL('INDEX','TU_ORD_ORDER_COMB_ITEM_FLAG')

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

CREATE INDEX"ZHEJIANG"."TU_ORD_ORDER_COMB_ITEM_FLAG" ON"ZHEJIANG"."ORD_ORDER_RECEIVE" ("ORDER_ITEM_ID","RECEIVE_FLAG")

PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTESTATISTICS

STORAGE(INITIAL 65536 NEXT 2097152 MINEXTENTS1 MAXEXTENTS 2147483645

PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1BUFFER_POOL DEFAULT)

TABLESPACE "ZHEJIANG"

将这个索引创建到产品环境中，由于产品环境这张表被大量并发的会话锁定，因此创建索引的操作被锁，短时间内无法完成。利用GV$SESSION找到所有锁住创建索引的会话，在操作系统中将这些会话杀掉：

SQL> SELECT INST_ID, SID

2 FROMGV$LOCK

3 WHERE ID1 =

4 (SELECT OBJECT_ID

5 FROMDBA_OBJECTS

6 WHERE OWNER = 'ZHEJIANG'

7 ANDOBJECT_NAME = 'ORD_ORDER_RECEIVE'

8 AND OBJECT_TYPE = 'TABLE');

INST_ID SID

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

1 489

1 496

1 498

. . .

2 1085

2 1090

已选择31行。

SQL> SELECTSID

2 FROMV$SESSION S, V$SQL SQL

3 WHERE S.SQL_ADDRESS = SQL.ADDRESS

4 ANDS.SQL_HASH_VALUE = SQL.HASH_VALUE

5 ANDSQL_TEXT LIKE 'CREATE INDEX TU_ORD_ORDER_COMB_ITEM_FLAG%';

SID

----------

496

SQL> SELECT'kill -9 ' || SPID

2 FROMV$PROCESS

3 WHERE ADDR IN

4 (SELECT PADDR

5 FROMV$SESSION A, V$LOCK B

6 WHERE A.SID = B.SID

7 ANDA.SID != 496

8 ANDID1 =

9 (SELECT OBJECT_ID

10 FROMDBA_OBJECTS

11 WHERE OWNER = 'ZHEJIANG'

12 ANDOBJECT_NAME = 'ORD_ORDER_RECEIVE'

13 ANDOBJECT_TYPE = 'TABLE'));

'KILL-9'||SPID

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

kill -9 16504

kill -9 29364

. . .

kill -9 26579

已选择19行。

SQL> host

$ kill -9 16504

$ kill -9 29364

. . .

$ kill -9 26579

SQL> SELECT'kill -9 ' || SPID

2 FROMGV$PROCESS

3 WHERE INST_ID = 2

4 ANDADDR IN

5 (SELECT PADDR

6 FROMGV$SESSION A, GV$LOCK B

7 WHERE A.SID = B.SID

8 ANDA.INST_ID = B.INST_ID

9 ANDB.INST_ID = 2

10 ANDID1 =

11 (SELECT OBJECT_ID

12 FROMDBA_OBJECTS

13 WHERE OWNER = 'ZHEJIANG'

14 ANDOBJECT_NAME = 'ORD_ORDER_RECEIVE'

15 ANDOBJECT_TYPE = 'TABLE'));

'KILL-9'||SPID

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

kill -9 17781

kill -9 10302

. . .

kill -9 15904

已选择15行。

在节点2上kill对应的进程：

bash-3.00$ kill-9 17781

bash-3.00$ kill-9 10302

. . .

bash-3.00$ kill-9 15904

分别在两个节点上清除掉除CREATE INDEX以外的锁住ORD_ORDER_RECEIVE表的进程，创建索引的语句得以完成，数据库的性能也逐渐恢复了正常。

2. 小结

导致问题产生的原因很简单，有人误删除了一个重要的索引。然而通过这个问题得到的经验和教训却不少：

第一点，诊断问题时切忌想当然：以这个问题为例，如果一看到大部分等待事件都与gc有关，就从RAC的CLUSTER方面入手去诊断问题，可能就会走很多的弯路，甚至是误入歧途。这个问题之所以导致了大量gc相关的等待，是因为两个节点上都存在大量的会话对问题表执行全表扫描操作，从9i开始Oracle认为利用RAC节点间通信获取远端节点内存中的BLOCK缓存要比本地读取数据文件中的BLOCK快，而每个实例的DB_CACHE中都保存了表的一部分缓存，于是两个节点之间在不停交换CACHE，这就是开始检查数据库时发现绝大部分会话都在等待gc buffer的原因。

第二点，建立结构和产品环境保持一致的测试环境至关重要。有了测试环境，复杂或危险的维护操作可以先在测试环境上执行，这样可以减少出现错误的可能，而且类似当前这种结构异常变化的问题，也可以通过对比结构而快速的定位问题。

第三点，产品数据库的维护、管理操作应该有专门的DBA来负责，如果很多人都可以随意登陆甚至是修改数据库结构，则系统安全性将无法保证。

文章来源:《Oracle DBA手记 3》杨廷琨的DBA工作手记作者：杨廷琨

配图来源: http://www.totaljobs.com/graduate/careers-advice/the-truth-about-jobs/~/media/tj/jobseekers/graduate/ITComputers.ashx

高三女生醉酒后被强奸致死？检方回应

高三女生醉酒后被强奸致死？检方回应

那些内心强大的孩子，童年被允许做过这1件事

波罗的海，电缆断裂！

关晓彤突然官宣喜讯！粉丝欢呼：恭喜啊，终于等到这一天