1.分别用表和索引上数据的访问来产生db file scattered read等待事件,等待事件需要在v$session_wait和10046 trace文件中显示出来,贴出整个演示过程。
1.1基于表的db file scatter read等待事件演示:
session1执行查询:
SQL> drop table t purge;
Table dropped.
SQL> create table t as select * from dba_objects;
Table created.
SQL> select * from v_mystat;
SID PID SPID
---------- ---------- ------------------------
277 56 25141
SQL> alter session set tracefile_identifier='TEST1A';
Session altered.
SQL> alter system flush buffer_cache;
System altered.
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> select count(*) from t,t;
--等待执行完成
session2查询等待事件:
SQL> select sid, event from v$session_wait where sid=233;
SID EVENT
---------- ----------------------------------------------------------------
277 db file scattered read
SQL>
由于session1执行时间过长,直接中断session1后检查trace:
tkprof RCLSH_ora_25141_TEST1A.trc RCLSH_ora_25141_TEST1A.trc.prf sys=no
view RCLSH_ora_25141_TEST1A.trc.prf
...
********************************************************************************
SQL ID: 5b5nrqm95fd8m
Plan Hash: 840385502
select count(*)
from
t,t
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.01 112 234 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.01 0.01 112 234 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 65
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 16 0.00 0.00
SQL*Net message to client 1 0.00 0.00
db file scattered read 423 0.01 0.05
********************************************************************************
...
1.2基于索引的db file scatter read等待事件演示:
session1执行查询:
SQL> drop table t purge;
Table dropped.
SQL> create table t as select * from dba_objects where object_id is not null;
Table created.
SQL> create index idx_t_objid on t(object_id);
Index created.
SQL> alter table t modify object_id not null;
Table altered.
SQL> select * from v_mystat;
SID PID SPID
---------- ---------- ------------------------
219 29 32671
SQL> alter session set tracefile_identifier='TEST1B';
Session altered.
SQL> alter system flush buffer_cache;
System altered.
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> select /*+ index_ffs(t) */count(t.object_id) from t, t t1;
--等待执行完成
session2查询等待事件:
SQL> select sid, event from v$session_wait where sid=219;
SID EVENT
---------- ----------------------------------------------------------------
219 db file scattered read
SQL>
由于session1执行时间过长,直接中断session1后检查trace:
tkprof RCLSH_ora_32671_TEST1B.trc RCLSH_ora_32671_TEST1B.trc.prf sys=no
view RCLSH_ora_32671_TEST1B.trc.prf
...
********************************************************************************
SQL ID: ccuwpvmn6rp9t
Plan Hash: 401390606
select count(t.object_id)
from
t, t t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 3 5 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 3 5 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 65
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file scattered read 514 0.00 0.00
SQL*Net message to client 1 0.00 0.00
********************************************************************************
...
--EOF--
2.构造一个DB File Sequential Read等待事件,等待事件需要在v$session_wait和10046 trace文件中显示出来,贴出整个演示过程。
session1执行查询:
SQL> drop table t purge;
Table dropped.
SQL> create table t as select * from dba_objects where object_id is not null;
Table created.
SQL> create index idx_t_objid on t(object_id);
Index created.
SQL> alter table t modify object_id not null;
Table altered.
SQL> select * from v_mystat;
SID PID SPID
---------- ---------- ------------------------
373 36 32327
SQL> alter session set tracefile_identifier='TEST2';
Session altered.
SQL> alter system flush buffer_cache;
System altered.
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> select count(t.object_id) from t, t t1;
--等待执行完成
session2查询等待事件:
SQL> select sid, event from v$session_wait where sid=373;
SID EVENT
---------- ----------------------------------------------------------------
373 db file sequential read
SQL>
由于session1执行时间过长,直接中断session1后检查trace:
tkprof RCLSH_ora_32327_TEST2.trc RCLSH_ora_32327_TEST2.trc.prf sys=no
view RCLSH_ora_32327_TEST2.trc.prf
...
********************************************************************************
SQL ID: 59h8m7c83fhvp
Plan Hash: 2140043906
select count(t.object_id)
from
t, t t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 3 5 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 3 5 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 65
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 903 0.00 0.00
SQL*Net message to client 1 0.00 0.00
********************************************************************************
...
--EOF--
3.构造一个Direct Path Read等待事件,等待事件需要在v$session_wait和10046 trace文件中显示出来,贴出整个演示过程。
session1构造等待事件:
SQL> select * from v_mystat;
SID PID SPID
---------- ---------- ------------------------
219 45 28590
SQL> drop table t purge;
Table dropped.
SQL> create table t as select * from dba_objects;
Table created.
SQL> insert /*+ append */ into t select * from t;
393493 rows created.
SQL> commit;
Commit complete.
SQL> insert /*+ append */ into t select * from t;
786986 rows created.
SQL> commit;
Commit complete.
SQL> insert /*+ append */ into t select * from t;
1573972 rows created.
SQL> commit;
Commit complete.
SQL> insert /*+ append */ into t select * from t;
3147944 rows created.
SQL> commit;
Commit complete.
SQL> select count(*) from t;
COUNT(*)
----------
6295888
SQL> alter system set pga_aggregate_target=10m;
System altered.
SQL> CREATE OR REPLACE PROCEDURE test3 (p_min IN NUMBER)
2 AS
3 l_stop_time DATE := SYSDATE + p_min / 24 / 60;
4 l_cnt NUMBER;
5 BEGIN
6 WHILE SYSDATE < l_stop_time
7 LOOP
8 SELECT COUNT (*)
9 INTO l_cnt
10 FROM t
11 ORDER BY object_name;
12 END LOOP;
13 END test3;
14 /
Procedure created.
SQL> alter session set tracefile_identifier = 'TEST3';
Session altered.
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> exec test3(1);
PL/SQL procedure successfully completed.
SQL> alter session set events '10046 trace name context off';
Session altered.
SQL>
session2在test3执行时查询v$session_wait:
SQL> select sid,event from v$session_wait where sid=219;
SID EVENT
---------- ----------------------------------------------------------------
219 direct path read
SQL>
检查trace:
tkprof RCLSH_ora_28590_TEST3.trc RCLSH_ora_28590_TEST3.trc.prf sys=noview RCLSH_ora_28590_TEST3.trc.prf
...
********************************************************************************
SQL ID: 8hy0xx6bq34ns
Plan Hash: 0
BEGIN test3(1); END;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 65
********************************************************************************
SQL ID: c929ph6tbkmda
Plan Hash: 2966233522
SELECT COUNT (*)
FROM
T ORDER BY OBJECT_NAME
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 27 0.00 0.00 0 0 0 0
Fetch 26 22.25 22.68 2299809 2308882 0 26
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 53 22.26 22.68 2299809 2308882 0 26
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 65 (recursive depth: 1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 66 0.00 0.00
db file scattered read 5349 0.00 0.23
direct path read 82573 0.00 8.02
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 6.95 6.95
enq: KO - fast object checkpoint 2 0.00 0.00
********************************************************************************
...
--EOF--
4.构造一个Direct Path write等待事件,等待事件需要在v$session_wait和10046 trace文件中显示出来,贴出整个演示过程。
session1构造等待事件:
SQL> select * from v_mystat;
SID PID SPID
---------- ---------- ------------------------
219 45 26091
SQL> alter session set tracefile_identifier = 'TEST4';
Session altered.
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> insert /*+ append */ into t select * from dba_objects where object_id is not null;
393400 rows created.
SQL> ALTER SESSION SET EVENTS '10046 trace name context off';
Session altered.
SQL>
session2在insert执行时查询v$session_wait:
SQL> select sid,event from v$session_wait where sid=219;
SID EVENT
---------- ----------------------------------------------------------------
219 direct path write
SQL>
检查trace:
tkprof RCLSH_ora_26091_TEST4.trc RCLSH_ora_26091_TEST4.trc.prf sys=no
view RCLSH_ora_26091_TEST4.trc.prf
...
********************************************************************************
SQL ID: 95p32dvgm8dx7
Plan Hash: 631105660
insert /*+ append */ into t select * from dba_objects where object_id is not
null
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.05 1 5 0 0
Execute 1 2.90 3.39 2318 39294 34267 393400
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 2.92 3.45 2319 39299 34267 393400
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 65
Rows Row Source Operation
------- ---------------------------------------------------
1 LOAD AS SELECT (cr=80852 pr=2336 pw=5541 time=0 us)
393400 VIEW DBA_OBJECTS (cr=38623 pr=2319 pw=0 time=17332 us cost=1519 size=42124500 card=203500)
393400 UNION-ALL (cr=38623 pr=2319 pw=0 time=16600 us)
0 TABLE ACCESS BY INDEX ROWID SUM$ (cr=770 pr=2 pw=0 time=0 us cost=2 size=11 card=1)
768 INDEX UNIQUE SCAN I_SUM$_1 (cr=23 pr=0 pw=0 time=0 us cost=1 size=0 card=1)(object id 319)
0 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=0 pr=0 pw=0 time=0 us cost=4 size=28 card=1)
0 INDEX RANGE SCAN I_OBJ1 (cr=0 pr=0 pw=0 time=0 us cost=3 size=0 card=1)(object id 3290792)
393400 FILTER (cr=37853 pr=2317 pw=0 time=9768 us)
398772 HASH JOIN (cr=5372 pr=0 pw=0 time=7034 us cost=1519 size=47876518 card=423686)
425 TABLE ACCESS FULL USER$ (cr=41 pr=0 pw=0 time=1 us cost=12 size=5052 card=421)
398772 HASH JOIN (cr=5331 pr=0 pw=0 time=4270 us cost=1501 size=42792286 card=423686)
425 INDEX FULL SCAN I_USER2 (cr=3 pr=0 pw=0 time=2 us cost=3 size=9262 card=421)(object id 3290799)
398772 TABLE ACCESS FULL OBJ$ (cr=5328 pr=0 pw=0 time=2232 us cost=1492 size=33471194 card=423686)
59373 TABLE ACCESS BY INDEX ROWID IND$ (cr=32481 pr=2317 pw=0 time=0 us cost=2 size=9 card=1)
61862 INDEX UNIQUE SCAN I_IND1 (cr=4813 pr=213 pw=0 time=0 us cost=1 size=0 card=1)(object id 36)
0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=4 size=30 card=1)
0 INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=3 size=10 card=1)(object id 3290795)
0 INDEX RANGE SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 3290799)
0 FILTER (cr=0 pr=0 pw=0 time=0 us)
0 HASH JOIN (cr=0 pr=0 pw=0 time=0 us cost=16 size=3034 card=82)
0 TABLE ACCESS FULL LINK$ (cr=0 pr=0 pw=0 time=0 us cost=3 size=2050 card=82)
0 TABLE ACCESS FULL USER$ (cr=0 pr=0 pw=0 time=0 us cost=12 size=5052 card=421)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
control file sequential read 5 0.00 0.00
db file sequential read 2319 0.00 0.02
direct path write 198 0.15 0.30
direct path sync 2 0.15 0.15
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 7.90 7.90
********************************************************************************
...
--EOF--
5.构造一个Log File Sync等待事件,并从相关视图中找到等待事件的信息,贴出整个演示过程。
session1构造等待事件:
SQL> select * from v_mystat;
SID PID SPID
---------- ---------- ------------------------
251 115 23785
SQL> drop table t purge;
Table dropped.
SQL> create table t as select * from dba_objects where rownum=1;
Table created.
SQL> CREATE OR REPLACE PROCEDURE test5 (p_min IN NUMBER)
2 AS
3 l_stop_time DATE := SYSDATE + p_min / 24 / 60;
4 l_cnt NUMBER;
5 BEGIN
6 WHILE SYSDATE < l_stop_time
7 LOOP
8 UPDATE t
9 SET object_name = object_name;
10 COMMIT WORK WRITE WAIT IMMEDIATE;
11 END LOOP;
12 END test5;
13 /
Procedure created.
SQL> alter session set tracefile_identifier = 'TEST5';
Session altered.
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> exec test5(1);
PL/SQL procedure successfully completed.
SQL> alter session set events '10046 trace name context off';
Session altered.
SQL>
session2在test5执行时查询v$session_wait:
SQL> select sid,event from v$session_wait where sid=251;
SID EVENT
---------- ------------------------------
251 log file sync
SQL>
检查trace:
tkprof tm12_ora_23785_TEST5.trc tm12_ora_23785_TEST5.trc.prf sys=no
view tm12_ora_23785_TEST5.trc.prf
...
********************************************************************************
SQL ID: b0ghz5khmybbn
Plan Hash: 0
BEGIN test5(1); END;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 65
********************************************************************************
SQL ID: b4qmv9ufx5cb3
Plan Hash: 931696821
UPDATE T SET OBJECT_NAME = OBJECT_NAME
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 13271 0.70 1.18 0 39813 39813 13271
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 13272 0.70 1.18 0 39813 39813 13271
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 65 (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
0 UPDATE T (cr=3 pr=0 pw=0 time=0 us)
1 TABLE ACCESS FULL T (cr=3 pr=0 pw=0 time=0 us cost=3 size=66 card=1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 5.53 5.53
log file sync 13270 0.00 1.90
********************************************************************************
...