[20150320]逻辑读增加.txt

--昨天在看awr报表发现一个奇怪的现象，一个小表在全表扫描时逻辑读增加许多。

--有一个小表逻辑读很高比平时高，一开始以为是高水位的问题，检查发现不是。后来才发现一开发在做维护后，在执行select for
-- upate查看,然后离开办别的事情，忘记提交或者回滚。导致其它用户执行时访问回滚段，导致逻辑读增加。我kill后恢复正常。

--我做一个简单的例子来说明：

1.session 1:
SCOTT@test> select * from emp for update ;

2.session 2:
SCOTT@test> alter session set statistics_level=all ;

Session altered.

SCOTT@test> select * from emp ;
SCOTT@test> @dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  g5wp7pwtq4kwp, child number 0
-------------------------------------
select * from emp
Plan hash value: 3956160932
--------------------------------------------------------------------------------------------------------------------
| Id  | Operation         | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
--------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |      1 |        |       |     3 (100)|          |     14 |00:00:00.01 |      22 |
|   1 |  TABLE ACCESS FULL| EMP  |      1 |     14 |   532 |     3   (0)| 00:00:01 |     14 |00:00:00.01 |      22 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
   1 - SEL$1 / EMP@SEL$1

--逻辑读增加到22.

3.回到session 1：
SCOTT@test> @xid
X
------------------------------
12.12.12998

    XIDUSN    XIDSLOT     XIDSQN     UBAFIL     UBABLK     UBAREC     UBASQN STATUS            USED_UBLK  USED_UREC XID              ADDR             C70
---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------------- ---------- ---------- ---------------- ---------------- ----------------------------------------------------------------------
        12         12      12998          3      12225          6       2897 ACTIVE                    2         14 0C000C00C6320000 00000000BBF8F000 ALTER SYSTEM DUMP UNDO BLOCK '_SYSSMU12_1585900997$' XID 12 12 12998;
                                                                                                                                                      ALTER SYSTEM DUMP UNDO HEADER '_SYSSMU12_1585900997$';
SCOTT@test> @viewlock;
   SID    SERIAL# USERNAME   OSUSER     MACHINE    LOCK_TYPE    MODE_HELD  MODE_REQUE LOCK_ID1   LOCK_ID2   OWNER  OBJECT_TYP OBJECT_NAME          BLOCK LOCKWAIT
------ ---------- ---------- ---------- ---------- ------------ ---------- ---------- ---------- ---------- ------ ---------- -------------------- ----- --------------------
   395       2201 SCOTT      oracle11g  hisdg      DML(TM)      Row-X (SX) None       73201      0          SCOTT  TABLE      EMP                  No
   395       2201 SCOTT      oracle11g  hisdg      Transaction  Exclusive  None       786444     12998                                             No

--可以发现有事务在emp表上。

SCOTT@test> rollback ;
Rollback complete.

--回到session 2：

SCOTT@test> select * from emp ;
SCOTT@test> @dpc '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  g5wp7pwtq4kwp, child number 0
-------------------------------------
select * from emp
Plan hash value: 3956160932
--------------------------------------------------------------------------------------------------------------------
| Id  | Operation         | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
--------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |      1 |        |       |     3 (100)|          |     14 |00:00:00.01 |       7 |
|   1 |  TABLE ACCESS FULL| EMP  |      1 |     14 |   532 |     3   (0)| 00:00:01 |     14 |00:00:00.01 |       7 |
--------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
   1 - SEL$1 / EMP@SEL$1

--逻辑读=7.

--有许多开发习惯在修改数据时，使用pl/developer时执行select * from t where ... for update;来操作，应该提醒做这些维护完成
--后，及时提交。

--我定位走了1个弯路。使用10200事件看看。
$ oerr ora 10200
10200, 00000, "consistent read buffer status"
// *Cause:
// *Action:

SCOTT@test> alter session set events '10200 trace name context forever, level 10';
Session altered.

SCOTT@test> select * from emp ;

SCOTT@test> alter session set events '10200 trace name context off';
Session altered.

ktrget2(): started for block  objd: 0x00011df1
env [0x2a97481924]: (scn: 0x0002.cbb97d23  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: 0x0002.cbb97b08  flg: 0x00000661)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a97481924]: (scn: 0x0002.cbb97d23  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a97481924]: (scn: 0x0002.cbb97d23  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a97481924]: (scn: 0x0002.cbb97d23  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a97481924]: (scn: 0x0002.cbb97d23  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 1 on:  0x9afaac18  cr-scn: 0x0002.cbb97c9f  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c9f  sfl: 0
ktrexf(): returning 1 on:  0x8dfbd038  cr-scn: 0x0002.cbb97c02  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c02  sfl: 0
ktrexf(): returning 1 on:  0xa0f76ba8  cr-scn: 0x0002.cbb97b18  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97b18  sfl: 0
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrexf(): returning 1 on:  0x93fb4ec8  cr-scn: 0x0002.cbb95c13  xid: 0x000c.00c.000032c6  uba: 0x00c02fc0.0b51.25  cl-scn: 0x0002.cbb95c13  sfl: 0
showing 0x94fcd3d8 c000c0 (3) dscn 0:0 bcrp 2:cbb44400, bestcrp (nil)
new dscn 0:0 ret=3
showing 0x90f846e8 c000c0 (1) dscn 0:0 bcrp ffff:ffffffff, bestcrp (nil)
new dscn 0:0 ret=2
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg updating CR fields for 0x9aff7068, 16777367; 2:cbb97d23
kcbchg new CR fields for 0x9aff7068, 16777367; 2:cbb97d23
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a97481924]: (scn: 0x0002.cbb97d23  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 9 on:  0x9aff70d8  cr-scn: 0x0002.cbb97d23  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97d23  sfl: 0
ktrexf(): returning 1 on:  0x9afaac18  cr-scn: 0x0002.cbb97c9f  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c9f  sfl: 0
ktrexf(): returning 1 on:  0x8dfbd038  cr-scn: 0x0002.cbb97c02  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c02  sfl: 0
ktrexf(): returning 1 on:  0xa0f76ba8  cr-scn: 0x0002.cbb97b18  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97b18  sfl: 0
ktrexf(): returning 1 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrexf(): returning 1 on:  0x93fb4ec8  cr-scn: 0x0002.cbb95c13  xid: 0x000c.00c.000032c6  uba: 0x00c02fc0.0b51.25  cl-scn: 0x0002.cbb95c13  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1

SCOTT@test> @xid
X
------------------------------

XIDUSN    XIDSLOT     XIDSQN     UBAFIL     UBABLK     UBAREC     UBASQN STATUS  USED_UBLK  USED_UREC XID              ADDR             C70
------ ---------- ---------- ---------- ---------- ---------- ---------- ------ ---------- ---------- ---------------- ---------------- ----------------------------------------------------------------------
     5         15      48565          3      10948         36      12070 ACTIVE          1         14 05000F00B5BD0000 00000000BBF8F000 ALTER SYSTEM DUMP UNDO BLOCK '_SYSSMU5_2973757209$' XID 5 15 48565;
 
-- bdb5 = 48565,还是从xid可以看出，为了构造CR，逻辑读增加。

--提交后，再做跟踪：

*** 2015-03-20 10:08:01.956
ktrget2(): started for block  objd: 0x00011df1
env [0x2a9753a34c]: (scn: 0x0002.cbb97f8a  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: 0x0002.cbb97b08  flg: 0x00000661)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a9753a34c]: (scn: 0x0002.cbb97f8a  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a9753a34c]: (scn: 0x0002.cbb97f8a  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a9753a34c]: (scn: 0x0002.cbb97f8a  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a9753a34c]: (scn: 0x0002.cbb97f8a  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 1 on:  0x9aff70d8  cr-scn: 0x0002.cbb97d23  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97d23  sfl: 0
ktrexf(): returning 1 on:  0x9afaac18  cr-scn: 0x0002.cbb97c9f  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c9f  sfl: 0
ktrexf(): returning 1 on:  0x8dfbd038  cr-scn: 0x0002.cbb97c02  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c02  sfl: 0
ktrexf(): returning 1 on:  0xa0f76ba8  cr-scn: 0x0002.cbb97b18  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97b18  sfl: 0
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1
ktrget2(): started for block  objd: 0x00011df1
env [0x2a9753a34c]: (scn: 0x0002.cbb97f8a  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: 0x0002.cbb97b08  flg: 0x00000660)
ktrexf(): returning 1 on:  0x9aff70d8  cr-scn: 0x0002.cbb97d23  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97d23  sfl: 0
ktrexf(): returning 1 on:  0x9afaac18  cr-scn: 0x0002.cbb97c9f  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c9f  sfl: 0
ktrexf(): returning 1 on:  0x8dfbd038  cr-scn: 0x0002.cbb97c02  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97c02  sfl: 0
ktrexf(): returning 1 on:  0xa0f76ba8  cr-scn: 0x0002.cbb97b18  xid: 0x0005.00f.0000bdb5  uba: 0x00c02ac4.2f26.17  cl-scn: 0x0002.cbb97b18  sfl: 0
ktrexf(): returning 9 on:  0xb9f42b0  cr-scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  cl-scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  objd: 0x00011df1
ktrget3(): completed for  block objd: 0x00011df1

--注意看没有kcbchg函数的调用。