Oracle 性能优化-trigger问题

问题现象:

谓词通过唯一性索引，更新一条记录，耗时很长；

通过AWR查看TOP SQL，这个UPDATESQL语句逻辑读，物理读等都非常高；

初步怀疑执行计划出现变化，index unique scan变成table access full，但是通过DBA_HIST_SQL_PLAN发现近期执行计划并没有改变；

通过10046查看SQL执行计划，显示这个更新语句耗时，逻辑读，物理读等都非常低；

问题原因:

触发器导致的；

更新语句A执行前，触发了trigger B，其中trigger B内部执行较慢，导致A一直在等待；

由于trigger B执行过程中占用大量的资源，在AWR中会将trigger消耗的资源也加到update语句上，有时可能会干扰问题诊断；

问题结论：

当发现某个语句执行突然变慢了，执行时间，逻辑读，物理读等突然飙升，

在排查数据量，执行计划等都没有异常，可以查看是否存在不合理的触发器；

问题重现举例:

---1 创建测试用户

SQL> createuserc##chenjch identifiedbya;

SQL> grantconnect,resource,dbatoc##chenjch;

---2 创建测试表，索引并插入数据

SQL> createtabletest01(idnumber);

SQL> createtabletest02 asselect*fromdba_objects;

SQL>

begin

fori in1.. 100000loop

insertintotest01 values(i);

commit;

endloop;

end;

SQL> createuniqueindexui_test_id ontest01(id);

SQL> insertintotest02 select*fromtest02;

SQL> commit;

/

/

......

selectcount(*)fromtest02;---2329536

---3 创建触发器

SQL>

createorreplacetriggerTG_TEST01_UPDATE

BEFOREUPDATEONTEST01

foreachrow

begin

insertintotest02

SELECT*FROMTEST02;

end;

---4 生成快照

SQL>

begin

dbms_workload_repository.create_snapshot;

end;

SQL>

selectSNAP_ID,BEGIN_INTERVAL_TIME,FLUSH_ELAPSED,SNAP_LEVEL

fromdba_hist_snapshot

orderbysnap_id desc;

---5 update test01通过唯一性索引，更新一条数据

SQL> set timing on

SQL> set autotrace on

SQL> alter session set tracefile_identifier='10046';

Session altered.

Elapsed: 00:00:00.00

SQL> ALTER SESSION SET EVENTS '10046 trace name context forever, level 12';

Session altered.

Elapsed: 00:00:00.03

---耗时19秒

SQL> update test01 set id=1000000000 where id=1;

1 row updated.

Elapsed: 00:00:19.49

Execution Plan

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

Plan hash value: xxxxx

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

| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time

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

| 0 | UPDATE STATEMENT | | 1 | 13 | 1 (0)| 00:00:01

| 1 | UPDATE | TEST01 | | | |

|* 2 | INDEX UNIQUE SCAN| UI_TEST_ID | 1 | 13 | 1 (0)| 00:00:01

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

Predicate Information (identified by operation id):

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

2 - access("ID"=1)

Statistics

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

637 recursive calls

351598 db block gets

103565 consistent gets

38393 physical reads

374300700 redo size

858 bytes sent via SQL*Net to client

962 bytes received via SQL*Net from client

3 SQL*Net roundtrips to/from client

102 sorts (memory)

0 sorts (disk)

1 rows processed

SQL> ALTER SESSION SET EVENTS '10046 trace name context off';

Session altered.

Elapsed: 00:00:00.01

SQL> select value from v$diag_info where name='Default Trace File';

VALUE

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

/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_56542_10046.trc

Elapsed: 00:00:00.06

SQL> @?/rdbms/admin/awrrpt.sql

AWR显示update语句消耗资源很高

select*fromtable(dbms_xplan.display_cursor('afqfknn3nwwpw'));

10046显示update语句消耗的资源很少；

欢迎关注我的微信公众号"IT小Chen"，共同学习，共同成长！！！