Oracle Internal Event:10201 consistent read undo application诊断事件

之前我介绍了<Oracle Internal Event:10200 Consistent Read诊断事件>一致性逻辑读诊断事件的用法和trace含义,10201 “consistent read undo application”是另一个十分有用的内部诊断事件,该事件可以用于诊断一致性读取时的UNDO应用情况。

 

10201 event可以用于探测为了创建CR(consistent read) block块以满足要求的SCN需要应用多少undo,该10201 event还可以配和10200 event使用。利用该10201 event,我们可以验证一些内部问题,例如何时会发生块上的cleanup。

注意启用10201 event可能导致在短期内产生大量的trace文件,所以不要随意在生产系统中使用。
10201 Internal Event主要会被ktrgcm( CR-rollback (ktrgcm() ) 、 ktrrbkblk  、 ktrcrf 这三个Oracle内核函数触发,这三个Internal Function的主要作用:

 

  • ktrgcm – common CR read code
    CR Requestor-Side Algorithm
    The following statistics are incremented by ktrgcm:
    “cleanouts and rollbacks – consistent read” is incremented if UNDO is applied to BUFFER and CLEANOUT is performed.
    “rollbacks only – consistent read gets” is incremented if UNDO is applied to BUFFER and no CLEANOUT is performed.
    “cleanouts only – consistent read gets” is incremented if no UNDO is applied and CLEANOUT is performed.
    “no work – consistent read gets” is incremented if no UNDO is applied and no CLEANOUT is performed.
    When UNDO is applied to produce a CR BUFFER, other UNDO blocks should be read.
    When CLEANOUT is performed, the TX transaction table must be read.
  • ktrrbkblk retrieves previous row version with ktundo,When all rows checked, calls ktrrbkblk to rollback block (calls ktundo)      常见的stack call : ktrviupk kdiulk kcoubk ktundo kturbk ktrrbkblk ktrvfxs qerixFetch qertbFetchByRowID
  •   ktrcrf (rdbms/kernel/knl/ktr.c kcbchg1 ==> ktrcrf)

 

 

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS for Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
www.askmac.cn & www.askmac.cn

SQL> create table maclean (t1 int);

Table created.

SQL> insert into maclean values(1);

1 row created.

SQL> commit;

Commit complete.

SQL> select current_scn from v$database;

CURRENT_SCN
-----------
    1213588

SQL> delete maclean;

1 row deleted.

SQL> commit;

Commit complete.

SQL> alter system flush buffer_cache;

System altered.

SQL> alter system flush buffer_cache;

System altered.

SQL>  alter session set events '10201 trace name context forever,level 10';

Session altered.

SQL> select * from maclean as of scn 1213588;

        T1
----------
         1

trace content=====================================

Applying CR undo to block 0 : 408a81 itl entry 02:
          xid:  0x0009.00b.0000017d uba: 0x00c00212.0092.2d
          flg: --U-    lkc:  1     fsc: 0x0007.0012849c
CRS upd rd env [0x2ac2ec7b5660]: (scn: 0x0000.00128494  xid: 0x0000.000.00000000
uba: 0x00000000.0000.00  statement num=0  parent xid: 0x0000.000.00000000  st-scn: 0x
0000.00000000  hi-scn: 0x0000.00000000  ma-scn: 0x0000.00000000  flg: 0x00000800)
undo env [0x7fffe8b74d10]: (
scn: 0x0000.0012849b  xid: 0x0009.00b.0000017d  uba: 0x00c00212.0092.2d  statement num=151548811
parent xid: 0x0000.000.00000000  st-scn: 0x0000.00000000  hi-scn: 0x9
f58.00000000  ma-scn: 0x2ac2.ec7b9c88  flg: 0x00002ac2)
CRS upd (before): 0x69bdfe68  cr-scn: 0x0000.00128494  xid: 0x0000.000.00000000
uba: 0x00000000.0000.00  cl-scn: 0x0000.001287c1  sfl: 0
CRS upd (after) : 0x69bdfe68  cr-scn: 0x0000.00128494  xid: 0x0009.00b.0000017d
uba: 0x00c00212.0092.2d  cl-scn: 0x0000.001287c1  sfl: 0

以上trace中各代码的含义如下:

Applying CR undo to block 0 : 408a81 itl entry 02:
这里的0是 tablespace number, 408a81 是 DBA
而 itl entry 02 是被回滚的事务槽记录

CRS upd rd env [0x2ac2ec7b5660]: (scn: 0x0000.00128494 …..undo env [0x7fffe8b74d10]: (
以上为当前读取的环境信息,包括env_scn等

CRS upd (before): 0x69bdfe68 cr-scn: 0x0000.00128494
xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 cl-scn: 0x0000.001287c1 sfl: 0
CRS upd (before)为回滚完成前的Buffer descriptor

CRS upd (after) : 0x69bdfe68 cr-scn: 0x0000.00128494 CR-SCN为1213588 如查询语句所要求的
xid: 0x0009.00b.0000017d uba: 0x00c00212.0092.2d cl-scn: 0x0000.001287c1 sfl: 0

CRS upd (after) 为回滚完成后的Buffer descriptor

Oracle Internal Event:10200 Consistent Read诊断事件

10200(consistent read buffer status)内部诊断事件可以用于探测一致性读CR(consistent read)块的访问情况,虽然cr读的统计信息可以从v$sysstat或AWR/statspack中获取,但是10200 event还是我们研究Consistent Read一致性读的有力工具。该事件可以通过在会话session级别设置ALTER SESSION SET EVENTS 或 DBMS_SYSTEM.SET_EV. Set 来开启,一般调用级别为Level 10。

该事件返回的trace跟踪文件,记录了为了实现一致性读的目的,哪些数据块以及这些块的各历史版本在执行过程中被创建(CR block creation)并检验(CR block inspection),以找出Best CR block满足Consistent一致性。

注意10200 Internal Event主要是被ktrgtc和ktrget(call ktrget to get one block ->calling KTR layer to apply RBS to have consistent read Block;)这2个Oracle内核功能函数触发,这2个内部函数Internal Function的主要作用:

ktrget:

  • Initializes a buffer cache CR scan request
  • Calls kcbgtcr for the best resident buffer to start from to build the CR buffer
  • Calls ktrgcm to build the CR buffer by applying undo
  • Returns CR buffer to the requestor

kcbgtcr:

  • If successful, returns the “best” candidate (performed by ktrexf or examination function)
  • Scans the hash bucket for the DBA for buffers that may be used to build a CR buffer
  • If not successful, calls kcbget

 

10200 event trace example:

 

[oracle@rh2 ~]$ sqlplus / as sysdba

SQL*Plus: Release 10.2.0.4.0 - Production on Fri Sep 30 21:23:47 2011

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.

Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing option

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
www.askmac.cn & www.askmac.cn

SQL> create table tv(t1 int);

Table created.

SQL> alter session set events '10200 trace name context forever,level 10';

Session altered.

SQL> select * from tv;

        T1
----------
         1

10200 trace

Consistent read started for block 0 : 0040081a
  env: (scn: 0x0000.000cf852 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00  statement num=0

parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 8sch: scn: 0x0000.00000000)
 CR exa ret 2 on: 0x600139d0  scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00

scn: 0xffff.ffffffff  sfl: 0

Consistent read finished for block 0 : 40081a

Consistent read started for block 0 : 0040e508
  env: (scn: 0x0000.000cf852  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  statement num=0
parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 8sch: scn:
 0x0000.00000000)
Consistent read finished for block 0 : 40e508

 

以上trace中各代码的含义如下:

Consistent read started for block 0 : 0040081a
0 -> tablespace number 0040081a -> DBA

 

env: (scn: 0x0000.000cf852 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00
以上为环境/会话信息,这个scn是env_scn ,一般就是数据库的current_scn

 

SFL :0  -> SFL 为 Snapshot Flag

 

CR exa ret 2 -> 此处的ret为reture code返回代码,是ktrgtc/ktrget函数的返回码

 

以下为ktrgtc/ktrget函数部分可能返回代码的含义:

 

#define KCBRSTOP (8|0) /* return this one now */
#define KCBRSAVE (8|1) /* save this one and continue */
#define KCBRSKIP (0|1) /* skip over this one and continue */
#define KCBRQUIT (0|2) /* chuck all, return nothing and stop */
#define KCBRLAST (0|3) /* quit if read from disk else skip */

 

10200诊断事件在11g中得到了加强,通过该event我们可以获得更多有用的trace信息了:

 

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
PL/SQL Release 11.2.0.3.0 - Production
CORE    11.2.0.3.0      Production
TNS for Linux: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
MACLEAN

SQL> alter session set events '10200 trace name context forever, level 10';

Session altered.

SQL> select * from tv;

        T1
----------
         1

SQL> oradebug setmypid;
Statement processed.

SQL> oradebug tracefile_name;
/s01/orabase/diag/rdbms/vprod/VPROD1/trace/VPROD1_ora_28365.trc

trace content

ktrget2(): started for block   objd: 0x000040e1
env [0x2b54cde2a704]: (scn: 0x0000.0026b064  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00
statement num=0  parent xid: 0x0000.000.00000000  st-scn: 0x0000.00000000  hi-scn: 0x0000.00000000
ma-scn: 0x0000.0026b053  flg: 0x00000660)
ktrexf(): returning 9 on:  0xbb132d0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000
uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block   objd: 0x000040e1
ktrget3(): completed for  block  objd: 0x000040e1

EVENT:10226 trace CR applications of undo for data

Error:  ORA 10226
Text:   trace CR applications of undo for data operations
-------------------------------------------------------------------------------
Explanation:
        This is NOT an error but is a special EVENT code. It can be used
        to signal Oracle to perform SQL_TRACE actions.

	This event causes application of UNDO for producing CR copies of
	blocks. It can produce a lot of output (in the form of REDO
	application dump to rewind the block)

沪ICP备14014813号-2

沪公网安备 31010802001379号