第一篇《oracle等待事件1分別用表和索引上資料的訪問來產生db file scattered read等待事件》http://space.itpub.net/26686207/viewspace-751965
第二篇《oracle等待事件2構造一個DB File Sequential Read等待事件和構造一個Direct Path Read等待事件》http://space.itpub.net/26686207/viewspace-751968
第三篇《oracle等待事件3構造一個Direct Path write等待事件和構造一個Log File Sync等待事件》http://space.itpub.net/26686207/viewspace-751969

引言：其實等待事件我想大家都不會陌生，那麼oracle研究出來等待事件是為了什麼呢？它會告訴我們在什麼情況資料庫的效能是快還是慢，我們可以根據資料庫在等待什麼資源來進行效能最佳化（是否資源太忙 idle較多 latch爭用嚴重會話有阻塞了），解決方案例如是增加SGA 還是PGA 還是系統I/O等，我們在日常巡檢的時候也要經常看看資料庫等待事件來給oracle診脈，是否超過了合理閥值，如果超過這時候就會有問題了，需要DBA出手干預。而有些是合理等待事件，這類等待事件是正常允許的，我們可以忽略，關鍵就是如何來區分是合理還是異常。

一 我們先從一個最簡單的等待事件來進入oracle wait event world

實驗環境

Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options

ORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1

System name: Linux

Node name: leonarding1.oracle.com

Release: 2.6.32-200.13.1.el5uek

Version: #1 SMP Wed Jul 27 21:02:33 EDT 2011

Machine: x86_64

Instance name: LEO1

Redo thread mounted by this instance: 1

Oracle process number: 21

Unix process pid: 28039, image: (TNS V1-V3)

搭建平臺：Oracle 資料庫效能最佳化藝術課程專用環境《VirtualBox+OELR5U7x86_64+Oracle11gR2》

LEO1@LEO1> select distinct sid from v$mystat; 我們要知道當前的會話id是什麼，這樣我們就可以在會話等待檢視中檢視對於id的等待事件是什麼了

SID

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

133

LEO1@LEO1> col wait_class for a10

LEO1@LEO1> col state for a15

LEO1@LEO1> select sid,event,wait_class,state,wait_time from v$session_wait;

SID EVENT WAIT_CLASS STATE WAIT_TIME

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

133 SQL*Net message to client Network WAITED SHORT TI -1

SQL*Net message to client 這是一個非常常見的等待事件，在oracle 11g中它算做一個短等待，當客戶端與伺服器建立起會話後，伺服器就會等待客戶端傳送命令，如果此時沒有命令傳輸就會產生這個等待事件。我們舉個例子比較好理解

sqlplus leo1/leo1 我們透過sqlplus登入資料庫，就會建立起會話，此時就會產生上述等待事件

pl/sql Developer 軟體訪問資料庫（這也是客戶端與伺服器建立會話的過程），也會發生上述等待事件

SQL*Net（原來叫net8）是oracle自己的通訊協議，只要安裝了oracle客戶端並透過客戶端連線資料庫就會走這個協議通訊，當然就會產生基於這個協議的等待事件。（這個事件我們可以忽略）

二 分別用表和索引上資料的訪問來產生db file scattered read等待事件，等待事件需要在v$session_wait和10046 trace檔案中顯示出來，貼出整個演示過程。

db file scattered read 等待事件：是由於多資料塊讀操作產生的，當我們檢索資料時從磁碟上讀資料到記憶體中，一次I/O讀取多個資料塊，而資料塊在記憶體中是分散分佈並不是連續的，當資料塊讀取到記憶體這個過程中會產生“db file scattered read”事件

多資料塊讀場景：FTS （full table scan）全表掃描

IFFS （index fast full scan）快速索引全掃描：把索引鏈切割成很多份，多塊並行讀取

LEO1@LEO1> drop table leo1 purge; 清理環境

Table dropped.

SYS@LEO1> show parameter memory_target SGA=652M

NAME TYPE VALUE

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

memory_target big integer 652M

LEO1@LEO1> create table leo1 as select * from dba_objects; 建立一張新表沒有索引

Table created.

LEO1@LEO1> select count(*) from leo1; 統計表資料71961行

COUNT(*)

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

71961

LEO1@LEO1> set autotrace trace exp

FTS掃描

LEO1@LEO1> select count(*) from leo1; oracle進行FTS掃描

Execution Plan

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

Plan hash value: 2716644435

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

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

| 0 | SELECT STATEMENT | | 75071 | 14M| 287 (1)| 00:00:04 |

| 1 | TABLE ACCESS FULL| LEO1 | 75071 | 14M| 287 (1)| 00:00:04 |

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

Note

-----

- dynamic sampling used for this statement (level=2)

由於這個動作非常的快，在v$session_wait檢視中不容易捕捉到，其實我們還可以去10046事件中追蹤一下看看

10046事件分析sql執行效能

解釋：10046事件是發生在sql的執行過程中，它能夠全面分析出sql執行過程和所消耗的資源，讓你瞭解這條sql是否是最優的，10046事件有4個級別

LEVEL 1 等同於SQL_TRACE的功能

LEVEL 4 在LEVEL 1基礎上增加繫結變數資訊

LEVEL 8 在LEVEL 1基礎上增加等待事件資訊

LEVEL 12 等同於LEVEL 4+LEVEL 8，即有繫結變數資訊又有等待事件資訊

LEO1@LEO1> execute dbms_stats.gather_table_stats(ownname=>'LEO1',tabname=>'LEO1',cascade=>TRUE);

PL/SQL procedure successfully completed. 我們先做一個表分析，收集到更多的統計資訊，方便10046正確評估

SYS@LEO1> alter system flush buffer_cache; 清空data_buffer_cache，好顯示多塊讀效果

System altered.

LEO1@LEO1> alter session set events '10046 trace name context forever,level 12'; 啟動10046事件定義級別12，這是最高階別，包括的資訊最全面

LEO1@LEO1> select count(*) from leo1; FTS掃描

COUNT(*)

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

71961

LEO1@LEO1> alter session set events '10046 trace name context off'; 關閉10046事件

Session altered.

[oracle@leonarding1 trace]$ pwd

/u01/app/oracle/diag/rdbms/leo1/LEO1/trace 11g 和 10g trace檔案所在目錄不同請注意

會話133

LEO1@LEO1> select name,value from v$diag_info where name='Default Trace File'; 當前會話寫入trace檔名

NAME VALUE

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

Default Trace File /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_28039.trc

LEO1@LEO1> !vim /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_28039.trc 開啟trace檔案，選取部分有用資訊

*** SESSION ID:(133.6542) 2012-12-27 23:51:54.342 會話133

*** MODULE NAME:(SQL*Plus) 2012-12-27 23:51:54.342 透過sqlplus登入

select count(*) from leo1

END OF STMT

PARSE #3:c=1000,e=1375,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=4191104944,tim=1356623522426980 解析資源

EXEC #3:c=0,e=71,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4191104944,tim=1356623522427140 執行資源

WAIT #3: nam='SQL*Net message to client' ela= 12 driver id=1650815232 #bytes=1 p3=0 obj#=13482 tim=1356623522427305 第一個等待事件，原因上面已經都介紹了

WAIT #3: nam='Disk file operations I/O' ela= 49 FileOperation=2 fileno=5 filetype=2 obj#=73707 tim=1356623522427604

WAIT #3: nam='db file sequential read' ela= 19 file#=5 block#=1458 blocks=1 obj#=73707 tim=1356623522427658

WAIT #3: nam='db file scattered read' ela= 36 file#=5 block#=1459 blocks=5 obj#=73707 tim=1356623522427878

WAIT #3: nam='db file scattered read' ela= 35 file#=5 block#=1464 blocks=8 obj#=73707 tim=1356623522428146

WAIT #3: nam='db file scattered read' ela= 26 file#=5 block#=1473 blocks=7 obj#=73707 tim=1356623522428643

WAIT #3: nam='db file scattered read' ela= 27 file#=5 block#=1480 blocks=8 obj#=73707 tim=1356623522428908

WAIT #3: nam='db file scattered read' ela= 278 file#=5 block#=1489 blocks=7 obj#=73707 tim=1356623522429449

WAIT #3: nam='db file scattered read' ela= 28 file#=5 block#=1496 blocks=8 obj#=73707 tim=1356623522429728

引數解釋：

File#：訪問資料檔案號

LEO1@LEO1> select file#,name from v$datafile where file#=5;

FILE# NAME

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

5 /u01/app/oracle/oradata/LEO1/leo1_01.dbf

Block#：訪問起始資料塊號

Blocks：讀取了多少個資料塊

例 1458+1=1459 –> 1459+5=1464 一直讀取到1496號，可見這些資料塊在檔案中都是連續存放的，讀取機制都是多塊讀，符合產生“db file scattered read”等待事件的條件

LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event; 顯示累計會話等待事件統計資訊

SID EVENT TOTAL_WAITS TIME_WAITED

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

133 db file scattered read 31 0 等待了31次

可以看到這個會話生命週期中經歷了哪些等待

小提示：當你長時間使用sqlplus登入資料庫時在做上面的10046實驗，你可能會發現在trace檔案中只有SQL*Net message to client沒有db file scattered read，解決方法是退出來重新登陸這樣就可以看見db file scattered read了。

IFFS掃描

LEO1@LEO1> select distinct sid from v$mystat; 我的會話id還是133

SID

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

133

LEO1@LEO1> create index idx_leo1 on leo1(object_id); 在表leo1欄位object_id新增一個B-tree索引

Index created.

LEO1@LEO1> select table_name,index_name from user_indexes where table_name='LEO1';

TABLE_NAME INDEX_NAME

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

LEO1 IDX_LEO1

LEO1@LEO1> execute dbms_stats.gather_table_stats(ownname=>'LEO1',tabname=>'LEO1',cascade=>TRUE);

PL/SQL procedure successfully completed.這次分析是把表和索引一起分析一遍，收集索引和表的統計資訊，CBO評估

LEO1@LEO1> set autotrace trace exp

LEO1@LEO1> select count(object_id) from leo1; oracle進行IFFS掃描

Execution Plan

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

Plan hash value: 1365721260

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

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

| 0 | SELECT STATEMENT | | 1 | 5 | 45 (0)| 00:00:01

| 1 | SORT AGGREGATE | | 1 | 5 | |

| 2 | INDEX FAST FULL SCAN| IDX_LEO1 | 71961 | 351K| 45 (0)| 00:00:01

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

LEO1@LEO1> set autotrace off

當有索引之後就開始走IFFS快速索引全掃描了，原理是把這個索引鏈切割成多個區域，多塊並行讀取，既然是多塊讀那麼也可以產生db file scattered read事件。

LEO1@LEO1> alter system flush buffer_cache; 再次清空data_buffer_cache

System altered.

LEO1@LEO1> set serveroutput on 開啟螢幕輸出

LEO1@LEO1> create or replace procedure p1 建立一個儲存過程p1，迴圈3000次

as

leo number;

begin

for i in 1..3000

loop

select count(object_id) into leo from leo1;

end loop;

dbms_output.put_line('successfully');

end;

/

2 3 4 5 6 7 8 9 10 11

Procedure created.

LEO1@LEO1> alter system flush buffer_cache; 每次重新測試的時候一定要提前清空data_buffer_cache，因為如果資料已經在記憶體中那麼就不會在去訪問磁碟的檔案了，也就發生不了“db file scattered read”這個等待事件，切記切記！

LEO1@LEO1> execute p1;

Successfully 當看到“successfully”表明這個p1執行完畢

PL/SQL procedure successfully completed.

會話157

LEO1@LEO1> select sid,event,wait_class,p1,p1text,p2,p2text,p3,p3text from v$session_wait where event like '% db file scattered read %';

SID EVENT WAIT_CLASS P1 P1TEXT P2 P2TEXT P3 P3TEXT

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

133 db file scattered read User I/O 5 file# 2562 block# 42 blocks

在157會話中當對133的儲存過程p1執行過程中，馬上檢視v$session_wait檢視，才能捕捉到“db file scattered read”，如果執行完畢了就看不到這個等待事件了，切記切記切記！

SID：133 會話號

EVENT：db file scattered read 等待事件名

P1：5 資料檔案號

P1TEXT：對p1引數的解釋

P2：2562 訪問起始資料塊號

P2TEXT：對p2引數的解釋

P3：42 讀取了42個資料塊

P3TEXT：對p3引數的解釋

可知索引上資料的訪問也會產生db file scattered read等待事件

LEO1@LEO1> alter system flush buffer_cache; 再次清空data_buffer_cache

System altered.

10046 trace檔案中顯示出來

LEO1@LEO1> alter session set events '10046 trace name context forever,level 12'; 啟動10046事件

Session altered.

LEO1@LEO1> select count(object_id) from leo1; IFFS掃描

COUNT(OBJECT_ID)

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

71961

LEO1@LEO1> alter session set events '10046 trace name context off'; 關閉10046事件

Session altered.

LEO1@LEO1> select name,value from v$diag_info where name='Default Trace File'; 當前會話寫入trace檔名

NAME VALUE

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

Default Trace File /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_6327.trc

LEO1@LEO1> !vim /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_6327.trc 開啟trace檔案，看中間部分

PARSING IN CURSOR #2 len=33 dep=0 uid=85 ct=3 lid=85 tim=1356681643167307 hv=2452024216 ad='80fee680' sqlid='cvf96jk92duws' sql解析的資源

select count(object_id) from leo1

END OF STMT

PARSE #2:c=2000,e=1284,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1365721260,tim=1356681643167301

EXEC #2:c=0,e=67,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1365721260,tim=1356681643167478

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

sequential read：表示索引的入口（根 -> 分支 -> 葉子）逐步的深入，所以是順序讀

WAIT #2: nam='db file sequential read' ela= 20 file#=5 block#=7618 blocks=1 obj#=73708 tim=1356681643167705

scattered read：表示葉子批次多資料塊讀，資料塊在檔案中也是連續存放，可以一次讀5塊 8塊 7塊等

WAIT #2: nam='db file scattered read' ela= 100 file#=5 block#=7619 blocks=5 obj#=73708 tim=1356681643168128

WAIT #2: nam='db file scattered read' ela= 27 file#=5 block#=7624 blocks=8 obj#=73708 tim=1356681643168608

WAIT #2: nam='db file scattered read' ela= 30 file#=5 block#=7633 blocks=7 obj#=73708 tim=1356681643170140

WAIT #2: nam='db file scattered read' ela= 31 file#=5 block#=7640 blocks=8 obj#=73708 tim=1356681643170853

WAIT #2: nam='db file scattered read' ela= 25 file#=5 block#=7649 blocks=7 obj#=73708 tim=1356681643171787

WAIT #2: nam='db file scattered read' ela= 26 file#=5 block#=7656 blocks=8 obj#=73708 tim=1356681643172541

WAIT #2: nam='db file scattered read' ela= 28 file#=5 block#=7665 blocks=7 obj#=73708 tim=1356681643174215

WAIT #2: nam='db file scattered read' ela= 164 file#=5 block#=7672 blocks=8 obj#=73708 tim=1356681643175184

小結：可以看出不論FTS還是IFFS，只要走多資料塊讀就會產生“db file scattered read”等待事件，我們可以開多個並行來加快資料檢索速度，儘量減少這種等待事件的發生，有資源消耗就會有等待事件，我們只能儘量減少而不可避免。

2012.12.28
天津&winter
分享技術~成就夢想
Blog：

oracle等待事件1分別用表和索引上資料的訪問來產生db file scattered read等待事件

相關文章