db file sequential read等待事件

skzhuga發表於2018-11-07

db file sequential read等待事件有三個引數,屬於User I/O類的等待:

 SQL> select name,parameter1,parameter2,parameter3,wait_class from v$event_name where name = 'db file sequential read';

 NAME                           PARAMETER1 PARAMETER2 PARAMETER3 WAIT_CLASS

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

 db file sequential read        file#      block#     blocks     User I/O

 file#:要讀取的資料塊鎖在資料檔案的檔案號。

 block#:要讀取的起始資料塊號。

 blocks:要讀取的資料塊數目(這裡應該等於1)。


當程式需要訪問一個在SGA中不存在的block時,程式會等待Oracle將此block從disk讀取到SGA中。在這個過程中發生的等待事件即db file sequential read,過程如圖:

db file sequential read等待事件是發生的常見原因:

 1.索引的訪問及回表

 2.訪問undo segment或者回滾操作

 3.直接以ROWID方式訪問表中的資料


在此,我們來分別對3種情況進行驗證。

首先,建立測試表及索引:

 SQL> create table scott.tb_test(id int,age int,name varchar2(20));

 Table created.

 SQL> create index scott.idx_id on scott.tb_test(id);

 Index created.


插入測試資料:

 SQL> begin

  2  for i in 1..1000 loop

  3  insert into scott.tb_test values(i,i+1,'test');

  4  end loop;

  5  commit;

  6  end;

  7  /

 PL/SQL procedure successfully completed.


在另外的session中對當前session進行10046追蹤:

 SQL> oradebug setospid 3836

 Oracle pid: 22, Unix process pid: 3836, image: oracle@zhuga (TNS V1-V3)

 SQL> oradebug event 10046 trace name context forever,level 12

 Statement processed.

 SQL> oradebug tracefile_name

 /opt/app/oracle/diag/rdbms/bddev2/BDDEV2/trace/BDDEV2_ora_3836.trc

持續觀察追蹤檔案的輸出


1.索引的訪問

 檢視當前session的累積等待資訊:

 SQL> SELECT   INST_ID

  2  ,SID

  3  ,EVENT

  4  ,TOTAL_WAITS WAITS_CNT

  5  ,TIME_WAITED

  6  ,AVERAGE_WAIT/100 "AVERAGE_WAIT(S)"

  7  ,MAX_WAIT/100 "MAX_WAIT(S)"

  8    FROM   GV$SESSION_EVENT 

  9   WHERE SID=&INPUT_SID

 10  ORDER BY TOTAL_WAITS DESC;

 Enter value for input_sid: 812

 old   9:  WHERE SID=&INPUT_SID

 new   9:  WHERE SID=812

 

    INST_ID        SID EVENT                           WAITS_CNT TIME_WAITED AVERAGE_WAIT(S) MAX_WAIT(S)

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

          1        812 db file sequential read               207           15           .0007         .01

          1        812 SQL*Net message to client              29           0               0           0

          1        812 SQL*Net message from client            28      215952         77.1256      680.52

          1        812 Disk file operations I/O                6           0           .0001           0

          1        812 log file sync                           5           0           .0005           0

          1        812 events in waitclass Other               3           5           .0156         .02

          1        812 db file scattered read                  1           0               0           0

 當前session中執行如下語句:

 SQL> alter system flush buffer_cache;

 System altered.

 SQL> select /*+ index(tb_test,idx_id)*/ age from scott.tb_test where id = 500;


 追蹤檔案內容:

 PARSING IN CURSOR #140128573892064 len=72 dep=0 uid=0 oct=3 lid=0 tim=1541577174155088 hv=968314915 ad='55a3880b0' sqlid='d53f2unwvfn13'

 select /*+ index(tb_test,idx_id)*/ age from scott.tb_test where id = 500

 END OF STMT

 PARSE #140128573892064:c=94,e=93,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1923716061,tim=1541577174155086

 EXEC #140128573892064:c=42,e=42,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1923716061,tim=1541577174155379

 WAIT #140128573892064: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=91021 tim=1541577174155417

  WAIT #140128573892064: nam='db file sequential read' ela= 11 file#=5 block#=147 blocks=1 obj#=91022 tim=1541577174155531

 WAIT #140128573892064: nam='db file sequential read' ela= 11 file#=5 block#=150 blocks=1 obj#=91022 tim=1541577174155602

 WAIT #140128573892064: nam='db file sequential read' ela= 11 file#=5 block#=134 blocks=1 obj#=91021 tim=1541577174155659

 FETCH #140128573892064:c=227,e=239,p=3,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=1923716061,tim=1541577174155687

 WAIT #140128573892064: nam='SQL*Net message from client' ela= 154 driver id=1650815232 #bytes=1 p3=0 obj#=91021 tim=1541577174155878

 FETCH #140128573892064:c=101,e=100,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=1,plh=1923716061,tim=1541577174156014

 STAT #140128573892064 id=1 cnt=1 pid=0 pos=1 obj=91021 op='TABLE ACCESS BY INDEX ROWID TB_TEST (cr=4 pr=3 pw=0 time=217 us cost=1 size=26 card=1)'

 STAT #140128573892064 id=2 cnt=1 pid=1 pos=1 obj=91022 op='INDEX RANGE SCAN IDX_ID (cr=3 pr=2 pw=0 time=256 us cost=1 size=0 card=1)'

 WAIT #140128573892064: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=91021 tim=1541577174156117

 

 SQL> select owner,object_name,object_type from dba_objects where object_id = 91022;

 OWNER                OBJECT_NAME          OBJECT_TYPE

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

 SCOTT                IDX_ID               INDEX

 或者

 SQL> select owner,segment_name,segment_type from dba_extents where file_id = 5 and 134 between block_id and block_id+blocks-1;

 OWNER                SEGMENT_NAME   SEGMENT_TYPE

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

 SCOTT                TB_TEST        TABLE

 可看到發生了 三次db file sequential read等待,其中兩次是訪問索引(一次訪問索引頭塊,另一次是訪問真正資料塊),一次是回表

 此時檢視當前session的累積等待資訊:

    INST_ID        SID EVENT                             WAITS_CNT TIME_WAITED AVERAGE_WAIT(S) MAX_WAIT(S)

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

          1        812 db file sequential read                 210          15           .0007         .01

          1        812 SQL*Net message to client                32           0               0           0

          1        812 SQL*Net message from client              31      233915         75.4564      680.52

          1        812 Disk file operations I/O                  6           0           .0001           0

          1        812 log file sync                             5           0           .0005           0

          1        812 events in waitclass Other                 4           6           .0152         .02

          1        812 db file scattered read                    1           0               0           0


 可看到資訊是一致的。


2.訪問undo或回滾

 在另外的session中修改scott.tb_test資料,不提交:

 SQL> update scott.tb_test set age = 100 where id = 500;

 1 row updated.

 在當前session執行:

 SQL> alter system flush buffer_cache;

 System altered.

 SQL> select age from scott.tb_test where id = 500;

        AGE

 ----------

        501

 PARSING IN CURSOR #140128575016040 len=44 dep=0 uid=0 oct=3 lid=0 tim=1541577933156059 hv=2526155070 ad='55a80a9a0' sqlid='0x9dgqqb9449y'

 select age from scott.tb_test where id = 500

 END OF STMT

 PARSE #140128575016040:c=0,e=125,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1923716061,tim=1541577933156058

 EXEC #140128575016040:c=0,e=49,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1923716061,tim=1541577933156190

 WAIT #140128575016040: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=91021 tim=1541577933156224

  WAIT #140128575016040: nam='db file sequential read' ela= 18 file#=5 block#=147 blocks=1 obj#=91022 tim=1541577933156326

 WAIT #140128575016040: nam='db file sequential read' ela= 12 file#=5 block#=150 blocks=1 obj#=91022 tim=1541577933156396

 WAIT #140128575016040: nam='db file sequential read' ela= 11 file#=5 block#=134 blocks=1 obj#=91021 tim=1541577933156456

 WAIT #140128575016040: nam='db file sequential read' ela= 12 file#=3 block#=176 blocks=1 obj#=0 tim=1541577933156512

 WAIT #140128575016040: nam='db file sequential read' ela= 12 file#=3 block#=32616 blocks=1 obj#=0 tim=1541577933156594

 FETCH #140128575016040:c=140,e=410,p=5,cr=5,cu=0,mis=0,r=1,dep=0,og=1,plh=1923716061,tim=1541577933156658

 WAIT #140128575016040: nam='SQL*Net message from client' ela= 164 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1541577933156863

 FETCH #140128575016040:c=88,e=88,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=1,plh=1923716061,tim=1541577933156988

 STAT #140128575016040 id=1 cnt=1 pid=0 pos=1 obj=91021 op='TABLE ACCESS BY INDEX ROWID TB_TEST (cr=6 pr=5 pw=0 time=409 us cost=1 size=26 card=1)'

 STAT #140128575016040 id=2 cnt=1 pid=1 pos=1 obj=91022 op='INDEX RANGE SCAN IDX_ID (cr=3 pr=2 pw=0 time=262 us cost=1 size=0 card=1)'

 WAIT #140128575016040: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1541577933157090


 可看到,除了 兩次索引訪問和一次回表 之外,還有 兩次db file sequential read等待是發生在file#=3,block#為176和32616上 ,其中176是物件的頭塊,檢視此物件(dba_extents或者DBA_UNDO_EXTENTS):

 SQL> select segment_name,segment_type from dba_extents where file_id = 3 and 176 between block_id and block_id + blocks - 1

   2  union all

   3  select segment_name,segment_type from dba_extents where file_id = 3 and 32616 between block_id and block_id + blocks - 1

   4  ;

 

 SEGMENT_NAME                                                                      SEGMENT_TYPE

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

 _SYSSMU4_1254879796$                                                              TYPE2 UNDO

 _SYSSMU4_1254879796$                                                              TYPE2 UNDO

 說明對undo段的訪問可引起db file sequential read等待。

 

3.透過ROWID訪問表資料其實與索引回表是一樣的,因此不再單獨驗證。


注意:

 1.對db file sequential read等待來說,絕大多數系統無法避免。db file sequential read等待比較多也不算是壞事,關鍵要看是否合理

 2.平均等待時間不應該超過7ms, 否則證明儲存存在爭用。

 3.最佳化方式:加大SGA, 降低總體物理讀,提高儲存效能,選擇合理的索引,對頻繁訪問的表做cache等


檢視各session的db file sequential read等待情況:

select a.sid,

       a.event,

       a.total_waits,

       a.time_waited,

       a.time_waited / c.sum_time_waited * 100 pct_wait_time,

       round((sysdate - b.logon_time) * 24) hours_connected

from   v$session_event a, v$session b,

       (select sid, sum(time_waited) sum_time_waited

        from   v$session_event

        where  wait_class <> 'Idle'

        having sum(time_waited) > 0 group by sid) c

where  a.sid         = b.sid

and    a.sid         = c.sid

and    a.time_waited > 0

and    a.event       = 'db file sequential read'

order by hours_connected desc, pct_wait_time;


檢視db file sequential read等待的物件:

select b.session_id,

       nvl(substr(a.object_name,1,30),

                  'P1='||b.p1||' P2='||b.p2||' P3='||b.p3) object_name,

       a.subobject_name,

       a.object_type

from   dba_objects a, v$active_session_history b, x$bh c

where  c.obj = a.object_id(+)

and    b.p1 = c.file#(+)

and    b.p2 = c.dbablk(+)

and    b.event = 'db file sequential read'

union

select b.session_id,

       nvl(substr(a.object_name,1,30),

                  'P1='||b.p1||' P2='||b.p2||' P3='||b.p3) object_name,

       a.subobject_name,

       a.object_type

from   dba_objects a, v$active_session_history b, x$bh c

where  c.obj = a.data_object_id(+)

and    b.p1 = c.file#(+)

and    b.p2 = c.dbablk(+)

and    b.event = 'db file sequential read'

order  by 1;


檢視資料檔案上單塊讀的平均等待時間:

select a.file#, 

       b.file_name, 

       a.singleblkrds, --總等待次數

       a.singleblkrdtim, --總等待時間(釐秒)

       a.singleblkrdtim/a.singleblkrds average_wait

from   v$filestat a, dba_data_files b 

where  a.file# = b.file_id   

and    a.singleblkrds > 0

order by average_wait;

          

某個session自登入以來所有等待事件的情況:

SELECT INST_ID,

       SID,

       EVENT,

       TOTAL_WAITS WAITS_CNT,

       TIME_WAITED,

       AVERAGE_WAIT/100 "AVERAGE_WAIT(S)",

       MAX_WAIT/100 "MAX_WAIT(S)"

FROM GV$SESSION_EVENT 

WHERE SID=&INPUT_SID

ORDER BY TOTAL_WAITS DESC;


來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/31544156/viewspace-2219110/,如需轉載,請註明出處,否則將追究法律責任。

相關文章