<> 第6周 等待事件

时间:2022-06-07 05:59:49

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=no

view 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
********************************************************************************
...


--EOF--