oracle等待事件3構造一個Direct Path write等待事件和構造一個Log File Sync等待事件

五 構造一個Direct Path write等待事件，等待事件需要在v$session_wait和10046 trace檔案中顯示出來，貼出整個演示過程。

Direct path write 等待事件：發生在“寫入磁碟”的時候，因為寫也是一種中間狀態，只要是中間狀態資料就沒有必要共享給其他使用者，所以這些資料也不會放在SGA中共享，從PGA中 -> 直接寫入 -> 磁碟。

場景： append方式插入資料，這種方式插入資料的時候會跳過SGA的data_buffer_cache，直接插入資料檔案，並且還不會掃描資料檔案中的空閒空間直接插入到檔案尾所以效率較高

       當資料排序時候，如果PGA被裝滿，就會被寫入到磁碟的temp表空間裡，因為排序的資料是中間狀態也不會經過SGA，所以會產生“direct path write”等待事件

LEO1@LEO1> select table_name,index_name from user_indexes where table_name='LEO1';  利用leo1表

TABLE_NAME                     INDEX_NAME

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

LEO1                           IDX_LEO1

LEO1@LEO1> select count(*) from leo1;                                            有71959行記錄

  COUNT(*)

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

     71959

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

PL/SQL procedure successfully completed.  統計分析

v$session_wait檢視中顯示出來

LEO1@LEO1> set serveroutput on

LEO1@LEO1> create or replace procedure p4

as

begin

     for i in 1..8

     loop

         insert /*+ append */ into leo1 select * from leo1;

     rollback;

     end loop;

     dbms_output.put_line('successfully');

end;

/

  2    3    4    5    6    7    8    9   10   11  

Procedure created.
建立儲存過程p4迴圈8次，新增了append  hint執行直接插入，在這個期間會發生“direct path write”等待事件

Append 注意事項

Append方式叫做直接路徑載入，使用這種方式是因為oracle不會在掃描freelist連結串列中的空閒塊，直接在高水線之後插入資料，所以速度比較快。

（1）append方式不記錄redo，一旦在插入的過程中沒有儲存到磁碟或者發生掉電情況那麼插入的資料不能恢復

（2）由於不在利用表的空閒空間，那麼這種方式比較浪費儲存空間，就是以空間換時間

（3）insert /*+ append */ into leo1 select * from leo1;會對這個表新增一個6級鎖，意味著在沒有commit/rollback前提下任何會話 insert  update  delete  select 等操作都不允許，否則會報錯

ORA-12838: cannot read/modify an object after modifying it in parallel

解釋如下：

ORA-12838 cannot read/modify an object after modifying it in parallel
Cause: Within the same transaction, an attempt was made to add read or modification statements on a table after it had been modified in parallel or with direct load. This is not permitted.
Action: Rewrite the transaction, or break it up into two transactions: one containing the initial modification and the second containing the parallel modification operation

會話133

LEO1@LEO1> execute p4;                                  當看到“successfully”表明這個p4執行完畢

successfully

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 '%direct%';

SID   EVENT           WAIT_CLASS      P1 P1TEXT         P2    P2TEXT         P3  P3TEXT

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

133   direct path write   User I/O          5 file numbe      10528  first dba        32  block cnt

133   direct path write   User I/O          5 file numbe      11232  first dba        32  block cnt

P1：寫入的資料檔案             即 5號資料檔案

P2：寫入起始資料塊號        即 10528     11232號資料塊

P3：寫入了多少個資料塊   即 32個資料塊

同理

會話133

LEO1@LEO1> create or replace procedure p5

as

begin

     for i in 1..5

     loop

         insert /*+ append */ into leo1 select * from leo1 order by object_name;

     rollback;

     end loop;

     dbms_output.put_line('successfully');

end;

/

  2    3    4    5    6    7    8    9   10   11  

Procedure created.

建立儲存過程p5迴圈5次，先進行order by操作在插入，這會就有更多的“direct path write”等待事件

LEO1@LEO1> execute p5;                                當看到“successfully”表明這個p5執行完畢

successfully

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 '%direct%';

SID   EVENT           WAIT_CLASS      P1 P1TEXT         P2    P2TEXT         P3  P3TEXT

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

133   direct path write   User I/O          5 file numbe      18816  first dba        32  block cnt

133   direct path write   User I/O          5 file numbe      17984  first dba        32  block cnt

133   direct path write   User I/O          5 file numbe      17856  first dba        32  block cnt

產生的密度大

10046 trace檔案中顯示出來

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_19807.trc

[oracle@leonarding1 trace]$ > LEO1_ora_19807.trc

先把這個19807trace檔案清空，方便看新生成的內容

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

Session altered.

LEO1@LEO1> insert /*+ append */ into leo1 select * from leo1;                                            直接路徑載入

143918 rows created.

LEO1@LEO1> rollback;      回滾

Rollback complete.

LEO1@LEO1> insert /*+ append */ into leo1 select * from leo1 order by object_name;     先排序在載入

143918 rows created.

LEO1@LEO1> rollback;      再回滾

Rollback complete.

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';

NAME                    VALUE

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

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

LEO1@LEO1> !vim /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_19807.trc     檢視trace檔案內容

====================================================================================================

insert /*+ append */ into leo1 select * from leo1                                                         直接路徑載入

END OF STMT

PARSE #4:c=3999,e=76261,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3641460699,tim=1356802437870566

WAIT #4: nam='direct path write' ela= 207 file number=5 first dba=17028 block cnt=28 obj#=-1 tim=1356802437889828

WAIT #4: nam='direct path write' ela= 160 file number=5 first dba=17056 block cnt=32 obj#=-1 tim=1356802437895744

WAIT #4: nam='direct path write' ela= 166 file number=5 first dba=17088 block cnt=32 obj#=-1 tim=1356802437900674

WAIT #4: nam='direct path write' ela= 392 file number=5 first dba=17120 block cnt=32 obj#=-1 tim=1356802437905561

====================================================================================================

insert /*+ append */ into leo1 select * from leo1 order by object_name                先排序在載入

END OF STMT

PARSE #13:c=1000,e=945,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3541504125,tim=1356802457804803

WAIT #13: nam='db file sequential read' ela= 29628 file#=5 block#=9334 blocks=1 obj#=73717 tim=1356802457932078

WAIT #13: nam='db file sequential read' ela= 1211 file#=5 block#=9336 blocks=1 obj#=73717 tim=1356802457933541

WAIT #13: nam='db file scattered read' ela= 1015 file#=5 block#=9338 blocks=6 obj#=73717 tim=1356802457934811

WAIT #13: nam='db file scattered read' ela= 6766 file#=5 block#=9346 blocks=77 obj#=73717 tim=1356802457942608

WAIT #13: nam='db file scattered read' ela= 2076 file#=5 block#=9423 blocks=49 obj#=73717 tim=1356802457951133

WAIT #13: nam='db file scattered read' ela= 4840 file#=5 block#=9474 blocks=77 obj#=73717 tim=1356802457960205

WAIT #13: nam='db file scattered read' ela= 1960 file#=5 block#=9551 blocks=49 obj#=73717 tim=1356802457968629

WAIT #13: nam='db file scattered read' ela= 5017 file#=5 block#=9602 blocks=77 obj#=73717 tim=1356802457976948

WAIT #13: nam='db file scattered read' ela= 2079 file#=5 block#=9679 blocks=49 obj#=73717 tim=1356802457984742

WAIT #13: nam='db file scattered read' ela= 4975 file#=5 block#=9730 blocks=77 obj#=73717 tim=1356802457994911

WAIT #13: nam='db file scattered read' ela= 4289 file#=5 block#=9807 blocks=49 obj#=73717 tim=1356802458005146

WAIT #13: nam='db file scattered read' ela= 29 file#=5 block#=9858 blocks=4 obj#=73717 tim=1356802458009596

WAIT #13: nam='direct path write' ela= 177 file number=5 first dba=17028 block cnt=28 obj#=73717 tim=1356802458061160

WAIT #13: nam='direct path write' ela= 300 file number=5 first dba=17056 block cnt=32 obj#=73717 tim=1356802458069767

WAIT #13: nam='direct path write' ela= 116 file number=5 first dba=17088 block cnt=32 obj#=73717 tim=1356802458078466

WAIT #13: nam='direct path write' ela= 1237 file number=5 first dba=17120 block cnt=32 obj#=73717 tim=1356802458087435

WAIT #13: nam='direct path write' ela= 358 file number=5 first dba=17152 block cnt=32 obj#=73717 tim=1356802458095653

WAIT #13: nam='direct path write' ela= 174 file number=5 first dba=17184 block cnt=32 obj#=73717 tim=1356802458103262

WAIT #13: nam='direct path write' ela= 187 file number=5 first dba=17216 block cnt=32 obj#=73717 tim=1356802458113053

WAIT #13: nam='direct path write' ela= 180 file number=5 first dba=17248 block cnt=32 obj#=73717 tim=1356802458120071

WAIT #13: nam='direct path write' ela= 166 file number=5 first dba=17280 block cnt=32 obj#=73717 tim=1356802458126193

小結：trace檔案中也能看到db file sequential read和db file scattered read，當然更多的是direct path write事件！

六 構造一個Log File Sync等待事件，並從相關檢視中找到等待事件的資訊，貼出整個演示過程。

Log File Sync等待事件：發生在“寫入redo log file”的時候，既然要寫入檔案那麼就會有磁碟I/O，有磁碟I/O就需要時間，有時間就會發生等待。

場景： commit/rollback 操作會做2個動作

      （1）觸發LGWR程式把log_buffer中重做日誌資料寫入到log_file中。

      （2）然後會同步線上日誌檔案與控制檔案的scn號，此時會發生“log file sync”等待事件

注：commit一次就會發生一次“log file sync”事件

我們還是利用Leo1表來實驗，都是現成的，比較方便了，有個表有個索引

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

TABLE_NAME                     INDEX_NAME

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

LEO1                            IDX_LEO1

我們先做個小實驗，修改資料塊（就會產生redo資料）然後commit提交看看v$session_event檢視的統計值是不是根據commit一次提交-> log file sync的值增加了一個

會話157

LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';

       SID  EVENT               TOTAL_WAITS  TIME_WAITED

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

       133  log file sync           45           206

會話133

刪除11220行 -> 修改了資料塊內容 -> 也就產生了redo資料

LEO1@LEO1> delete from leo1 where object_type='leonarding';   

11220 rows deleted.

LEO1@LEO1> commit;              提交

Commit complete.

會話157

LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';

       SID  EVENT               TOTAL_WAITS  TIME_WAITED

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

       133  log file sync           46           209

log file sync總次數增加了1次，等待時間增加了3秒

會話133

LEO1@LEO1> update leo1 set object_type='leonarding' where object_type='VIEW';  修改了表內容也當然於修改資料塊

20112 rows updated.

LEO1@LEO1> commit;               提交

Commit complete.

會話157

LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';

       SID  EVENT               TOTAL_WAITS  TIME_WAITED

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

       133  log file sync           47           209

總次數又增加了1次，由於很快所以時間沒有變

注：有時update一次不一定會增加TOTAL_WAITS次數，可以多操作幾遍就會有反應的（因為1次資料量太少oracle的LGWR程式立刻就處理完了還來不及生成log file sync等待事件，所以總次數沒有變化）

會話133

LEO1@LEO1> insert into leo1 select * from leo1;           插入記錄改變資料塊內容

276616 rows created.

LEO1@LEO1> commit;               提交

Commit complete.

會話157

LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';

       SID  EVENT               TOTAL_WAITS  TIME_WAITED

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

       133  log file sync          48           215

log file sync總次數增加了1次，等待時間增加了6秒，這次時間長了一點

如果有頻繁的DML操作而且伴隨著頻繁的commit動作，LGWR程式處理不過來，等待事件就會經常發生。

會話133   測試rollback動作產生log file sync事件

LEO1@LEO1> insert into leo1 select * from leo1;

553232 rows created.

LEO1@LEO1> rollback;

Rollback complete.

會話157

LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';

       SID  EVENT               TOTAL_WAITS  TIME_WAITED

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

       133  log file sync           49           550

我們看到在v$session_event檢視中TOTAL_WAITS又增加了1次，等待時間累加到550

10046事件

====================================================================================================

rollback

END OF STMT

PARSE #11:c=0,e=190,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1356716970693590

XCTEND rlbk=1, rd_only=0, tim=1356716970693691

WAIT #11: nam='db file sequential read' ela= 33 file#=201 block#=3329 blocks=1 obj#=-1 tim=1356716970798534

EXEC #11:c=71989,e=105375,p=1,cr=35,cu=8914,mis=0,r=0,dep=0,og=0,plh=0,tim=1356716970799035

WAIT #11: nam='log file sync' ela= 18162 buffer#=6808 sync scn=1478996 p3=0 obj#=73718 tim=1356716970817237

WAIT #11: nam='SQL*Net message to client' ela= 10 driver id=1650815232 #bytes=1 p3=0 obj#=73718 tim=1356716970817390

WAIT #11: nam='SQL*Net message from client' ela= 652 driver id=1650815232 #bytes=1 p3=0 obj#=73718 tim=1356716970818072

小結：10046的trace檔案中我們也看到rollback操作導致的log file sync等待事件，完結！如有建議務必提，共同學習共進步

Leonarding
2012.12.30
天津&winter
分享技術~成就夢想
Blog：www.leonarding.com