[转载]---Oracle等待事件2之构造一个DB File Sequential Read等待事件和构造一个Direct Path Read等待事件
第一篇: 《Oracle等待事件1之分别用表和索引上数据的访问来产生db file scattered read等待事件》
第二篇: 《Oracle等待事件2之构造一个DB File Sequential Read等待事件和构造一个Direct Path Read等待事件》
第三篇: 《暂无》
三、构造一个DB File Sequential Read等待时间,等待事件需要在v$session_wait和10046 trace文件中显示出来,贴出整个演示过程。
db file sequential read等待事件:是由于数据块顺序读产生的,当数据块(索引块)从磁盘一个一个读到内存中时,在这个过程中oracle会发生"db file sequential read"等待事件。
块顺序读场景:索引块顺序读、数据块顺序读、undo回滚构造一致性读、磁盘I/O瓶颈
一般来讲如果检索数据时走索引范围扫描INDEX RANGE SCAN就会发生数据块顺序读的现象,先读取一个索引块,根据索引键值对应ROWID信息在去读ROWID所在的数据块,接下来继续找下一个索引块,在读对应的数据块,就这样一个一个把数据块读取到内存中,这个过程中就会产生"db file sequential read"等待事件。
下面我们来使用索引块顺序读来产生"db file sequential read"
----创建表jack----从上面的查询可以看到出现了db file sequential read等待事件
1 SQL> create table jack as select * from dba_objects; 2 3 Table created. 4 ----object_id字段上创建索引,我们要利用索引块顺序读----
5 SQL> create index jack_ind on jack(object_id); 6 7 Index created. 8 9 SQL> col table_name for a30; 10 SQL> col index_name for a30; 11 SQL> select table_name,index_name from user_indexes where table_name='JACK'; 12 13 TABLE_NAME INDEX_NAME 14 ------------------------------ ------------------------------ 15 JACK JACK_IND 16 ----在这里需要收集表数据分布情况,看看有没有数据倾斜,在看看索引键值重复率,表和索引存放的位置和大小等,有了这些信息方便CBO更加客观评价执行计划----
17 SQL> execute dbms_stats.gather_table_stats(user,'jack',cascade=>true); 18 19 PL/SQL procedure successfully completed. 20 21 SQL> set linesize 150; 22 SQL> set autotrace trace exp; 23 ----我们查询100-200之间的数据,走的是索引范围扫描,就是先读索引块,通过索引键值找到ROWID,在读数据块,这样一个一个读到内存中,就是数据块顺序读类型----
24 SQL> select owner,object_id,object_name,object_type,status from jack where object_id>=100 and object_id<=200; 25 26 Execution Plan 27 ---------------------------------------------------------- 28 Plan hash value: 2860868395 29 30 ---------------------------------------------------------------------------------------- 31 | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | 32 ---------------------------------------------------------------------------------------- 33 | 0 | SELECT STATEMENT | | 99 | 5049 | 5 (0)| 00:00:01 | 34 | 1 | TABLE ACCESS BY INDEX ROWID| JACK | 99 | 5049 | 5 (0)| 00:00:01 | 35 |* 2 | INDEX RANGE SCAN | JACK_IND | 99 | | 2 (0)| 00:00:01 | 36 ---------------------------------------------------------------------------------------- 37 38 Predicate Information (identified by operation id): 39 --------------------------------------------------- 40 41 2 - access("OBJECT_ID">=100 AND "OBJECT_ID"<=200) 42 43 SQL> set autotrace off; 44 45 SQL> select distinct sid from v$mystat; 46 47 SID 48 ---------- 49 1 50 51 SQL> select sid,event,total_waits,time_waited from v$session_event; 52 SID EVENT TOTAL_WAITS TIME_WAITED 53 ---------- ------------------------------------ ----------- ----------- 54 1 Disk file operations I/O 8 0 55 1 direct path sync 2 27 56 1 enq: RO - fast object reuse 1 2 57 1 enq: KO - fast object checkpoint 2 0 58 1 log file sync 1 2 59 1 db file sequential read 2165 160 60 1 db file scattered read 538 1 ----在这里我们先标记一下db file sequential read的等待次数,如果一会次数增加那么说明成功触发了这个等待事件----
61 ----打开输出,并创建一个存储过程p2循环800000次(循环的越多执行的时间越长),在循环的过程中我们可以在v$session_wait视图上捕捉到
"db file sequential read" select count(*) into echo from jack where object_id>=100 and object_id<=200与上面的sql执行过程类似只是多了一个汇总,也走的是索引范围扫描。----
62 SQL> set serveroutput on 63 SQL> create or replace procedure p2 64 2 as 65 3 echo number; 66 4 begin 67 5 for i in 1..800000 68 6 loop 69 7 select count(*) into echo from jack where object_id>=100 and object_id<=200; 70 8 end loop; 71 9 dbms_output.put_line('successfully'); 72 10 end; 73 11 / 74 75 Procedure created. 76 ----需要先清空一下buffer_cache里面的----
77 SQL> alter system flush buffer_cache; 78 79 System altered. 80 81 SQL> alter system flush buffer_cache; 82 83 System altered. 84 ----当看到"successfully"表名这个p2执行完毕----
85 SQL> execute p2; 86 successfully 87 88 PL/SQL procedure successfully completed. ----下面这个查询是执行完上面的存储过程后的一个查询----
89 SQL> select sid,event,total_waits,time_waited from v$session_event where sid=1;
SID EVENT TOTAL_WAITS TIME_WAITED
------- ----------------------------------- ----------- -----------
1 db file sequential read 2444 22
----在执行上面存储过程的时候,在会话31中查询v$session_wait视图,捕捉到"db file sequential read",如果执行完毕了就看不到这个等待事件。----
90 SQL> select distinct sid from v$mystat; 91 92 SID 93 ---------- 94 31 95 96 SQL> set linesize 200; 97 SQL> col event for a40; 98 SQL> col p1text for a10; 99 SQL> col p2text for a10; 100 SQL> col p3text for a10; 101 SQL> col wait_class for a20; 102 SQL> select sid,event,wait_class,p1,p1text,p2,p2text,p3,p3text from v$session_wait where event like '%sequential%'; 103 104 SID EVENT WAIT_CLASS P1 P1TEXT P2 P2TEXT P3 P3TEXT 105 ---------- ------------------------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- 106 1 db file sequential read User I/O 7 file# 772 block# 1 blocks
小提示:当你进行多次实验后,会发现要访问的trace文件非常的大,在里面找到自己测试sql语句是一件很麻烦的事,这时我们可以选择先清空它再进行测试。
1 SQL> @/u01/scripts/showtrace 2 3 trace_file_name 4 ----------------------------------------------------------------------------/u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_4758.trc 5 6 [oracle@yft ~]$ ll /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_4758.trc 7 -rw-r--r-- 1 oracle oinstall 1937 Feb 26 09:00 /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_4758.trc 8 [oracle@yft ~]$ >/u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_4758.trc 9 [oracle@yft ~]$ ll /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_4758.trc 10 -rw-r--r-- 1 oracle oinstall 0 Feb 26 09:00 /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_4758.trc
10046trace文件显示等待事件:
----清空重新抽取数据----
1 SQL> alter system flush buffer_cache; 2 3 System altered. 4 ----启动10046事件----
5 SQL> alter session set events '10046 trace name context forever,level 12'; 6 7 Session altered. 8 ----索引范围扫描----
9 SQL> select count(*) from jack where object_id>=100 and object_id<=200; 10 11 COUNT(*) 12 ---------- 13 94 14 ----再清空----
15 SQL> alter system flush buffer_cache; 16 17 System altered. 18 19 SQL> select count(*) from jack where object_id>=100 and object_id<=200; 20 21 COUNT(*) 22 ---------- 23 94 24 25 SQL> alter system flush buffer_cache; 26 27 System altered. 28 ----插入数据也会产生顺序读----
29 SQL> insert into jack select * from jack; 30 31 72530 rows created. 32 33 SQL> insert into jack select * from jack; 34 35 145060 rows created. 36 ----关闭10046事件----
37 SQL> alter session set events '10046 trace name context off'; 38 39 Session altered. 40 ----trace文件信息----
41 select count(*) from jack where object_id>=100 and object_id<=200 42 END OF STMT 43 PARSE #13:c=7999,e=24432,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=538454857,tim=1361840628594049 44 EXEC #13:c=0,e=252,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=538454857,tim=1361840628594604 45 WAIT #13: nam='SQL*Net message to client' ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1361840628594748 46 WAIT #13: nam='db file sequential read' ela= 165 file#=7 block#=771 blocks=1 obj#=74838 tim=1361840628595339 47 WAIT #13: nam='db file sequential read' ela= 153 file#=7 block#=772 blocks=1 obj#=74838 tim=1361840628595853 48 FETCH #13:c=1000,e=1219,p=2,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=538454857,tim=1361840628596104 49 STAT #13 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=2 pr=2 pw=0 time=0 us)' 50 STAT #13 id=2 cnt=94 pid=1 pos=1 obj=74838 op='INDEX RANGE SCAN JACK_IND (cr=2 pr=2 pw=0 time=279 us cost=2 size=495 card=99)' 51 WAIT #13: nam='SQL*Net message from client' ela= 1336 driver id=1650815232 #bytes=1 p3=0 obj#=74838 tim=1361840628597981 52 FETCH #13:c=0,e=6,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=538454857,tim=1361840628598117 53 WAIT #13: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=74838 tim=1361840628598183 54 WAIT #13: nam='SQL*Net message from client' ela= 1916 driver id=1650815232 #bytes=1 p3=0 obj#=74838 tim=1361840628600139 ----在上面的信息中因为读取的数据量较少,发生的"db file sequential read"也不是很多
55
56 ===================== 57 PARSING IN CURSOR #17 len=65 dep=0 uid=91 oct=3 lid=91 tim=1361840638457476 hv=2567383207 ad='33614884' sqlid='1n5tj6qchfa57' 58 select count(*) from jack where object_id>=100 and object_id<=200 59 END OF STMT 60 PARSE #17:c=1000,e=232,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=538454857,tim=1361840638457471 61 EXEC #17:c=0,e=65,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=538454857,tim=1361840638457685 62 WAIT #17: nam='SQL*Net message to client' ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1361840638457784 63 WAIT #17: nam='db file sequential read' ela= 228 file#=7 block#=771 blocks=1 obj#=74838 tim=1361840638458277 64 WAIT #17: nam='db file sequential read' ela= 59 file#=7 block#=772 blocks=1 obj#=74838 tim=1361840638458477 65 FETCH #17:c=1000,e=603,p=2,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=538454857,tim=1361840638458593 66 STAT #17 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=2 pr=2 pw=0 time=0 us)' 67 STAT #17 id=2 cnt=94 pid=1 pos=1 obj=74838 op='INDEX RANGE SCAN JACK_IND (cr=2 pr=2 pw=0 time=186 us cost=2 size=495 card=99)' 68 WAIT #17: nam='SQL*Net message from client' ela= 263 driver id=1650815232 #bytes=1 p3=0 obj#=74838 tim=1361840638459154 69 FETCH #17:c=0,e=6,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=538454857,tim=1361840638459234 70 WAIT #17: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=74838 tim=1361840638459291 71 WAIT #17: nam='SQL*Net message from client' ela= 1396 driver id=1650815232 #bytes=1 p3=0 obj#=74838 tim=1361840638461079 ----两次查询出现的等待时间不多
72 ----下面内容是两次插入的操作----
73 ===================== 74 PARSING IN CURSOR #16 len=35 dep=0 uid=91 oct=2 lid=91 tim=1361840656334367 hv=1953898233 ad='336157f4' sqlid='3g3n5r9u7c7rt' 75 insert into jack select * from jack 76 END OF STMT 77 PARSE #16:c=38994,e=38870,p=5,cr=5,cu=0,mis=1,r=0,dep=0,og=1,plh=949574992,tim=1361840656334362 78 WAIT #16: nam='db file sequential read' ela= 788 file#=7 block#=130 blocks=1 obj#=74837 tim=1361840656335719 79 WAIT #16: nam='db file scattered read' ela= 145 file#=7 block#=131 blocks=2 obj#=74837 tim=1361840656336308 80 WAIT #16: nam='db file sequential read' ela= 180 file#=7 block#=129 blocks=1 obj#=74837 tim=1361840656337231 81 WAIT #16: nam='db file sequential read' ela= 117 file#=7 block#=640 blocks=1 obj#=74837 tim=1361840656337435 82 WAIT #16: nam='db file sequential read' ela= 29 file#=3 block#=224 blocks=1 obj#=0 tim=1361840656338534 83 WAIT #16: nam='db file sequential read' ela= 16 file#=3 block#=292 blocks=1 obj#=0 tim=1361840656338654 84 WAIT #16: nam='db file sequential read' ela= 51 file#=7 block#=771 blocks=1 obj#=74838 tim=1361840656339324 85 WAIT #16: nam='db file sequential read' ela= 47 file#=7 block#=772 blocks=1 obj#=74838 tim=1361840656339437 86 WAIT #16: nam='db file sequential read' ela= 97 file#=3 block#=208 blocks=1 obj#=0 tim=1361840656340117 87 WAIT #16: nam='db file sequential read' ela= 32 file#=3 ----插入数据操作中,95%会发生大量的"db file sequential read"等待事件,偶尔也能看到"db file scattered read"
----因为什么呢?我们想一想插入流程是不是:第一、先从数据文件中把数据块读到内存里面,这时会发生大量的"db file sequential read"等待事件,
第二、再把内存中数据插入到数据文件里。
88 ----第二次插入发生"db file sequential read"的次数就少了,是因为第一次已经把大部分数据加载到内存里了,第二次的时候就可以直接从内存里往磁盘上插入数据了,省略了再从磁盘读这一步。----
89 ===================== 90 PARSING IN CURSOR #1 len=35 dep=0 uid=91 oct=2 lid=91 tim=1361840662586829 hv=1953898233 ad='336157f4' sqlid='3g3n5r9u7c7rt' 91 insert into jack select * from jack 92 END OF STMT 93 PARSE #1:c=0,e=93,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=949574992,tim=1361840662586825 94 WAIT #1: nam='db file scattered read' ela= 65 file#=7 block#=131 blocks=2 obj#=74837 tim=1361840662587458 95 WAIT #1: nam='db file sequential read' ela= 23 file#=7 block#=772 blocks=1 obj#=74838 tim=1361840662588206 96 WAIT #1: nam='db file scattered read' ela= 23 file#=7 block#=133 blocks=2 obj#=74837 tim=1361840662589060 97 WAIT #1: nam='db file sequential read' ela= 36 file#=6 block#=687 blocks=1 obj#=74838 tim=1361840662589813 98 WAIT #1: nam='db file sequential read' ela= 24 file#=7 block#=773 blocks=1 obj#=74838 tim=1361840662591319 99 WAIT #1: nam='db file sequential read' ela= 20 file#=7 block#=135 blocks=1 obj#=74837 tim=1361840662591858 100 WAIT #1: nam='db file scattered read' ela= 28 file#=7 block#=136 blocks=2 obj#=74837 tim=1361840662592819 101 WAIT #1: nam='db file scattered read' ela= 26 file#=7 block#=138 blocks=2 obj#=74837 tim=1361840662594614 102 WAIT #1: nam='db file sequential read' ela= 40 file#=3 block#=240 blocks=1 obj#=0 tim=1361840662595599 103 WAIT #1: nam='db file sequential read' ela= 121 file#=6 block#=689 blocks=1 obj#=74838 tim=1361840662595998 104 WAIT #1: nam='db file scattered read' ela= 26 file#=7 block#=140 blocks=2 obj#=74837 tim=1361840662596640 105 WAIT #1: nam='db file sequential read' ela= 64 file#=3 block#=192 blocks=1 obj#=0 tim=1361840662597439 106 WAIT #1: nam='db file sequential read' ela= 25 file#=7 block#=774 blocks=1 obj#=74838 tim=1361840662597764 107 WAIT #1: nam='db file scattered read' ela= 35 file#=7 block#=142 blocks=2 obj#=74837 tim=1361840662599490 108 WAIT #1: nam='db file scattered read' ela= 30 file#=7 block#=145 blocks=2 obj#=74837 tim=1361840662601746 109 WAIT #1: nam='db file sequential read' ela= 25 file#=7 block#=769 blocks=1 obj#=74838 tim=1361840662603010