고정 헤더 영역
상세 컨텐츠
본문
<<새로운 hr 세션에서>>
HR@ora11g> exec dbms_application_info.set_client_info('sess_2')
# 다이렉트 패스 리드 방식을 안하겠다는 이벤트
HR@ora11g> alter session set events '10949 trace name context forever, level 1';
Session altered.
HR@ora11g> select count(*) from ind_random where owner = 'SYS';
COUNT(*)
----------
29856
SYS@ora11g> select client_info, sid from v$session where client_info = 'sess_2';
CLIENT_INFO SID
---------------------------------------------------------------- ----------
sess_2 185
SYS@ora11g> select sid, event, total_waits, time_waited from v$session_event where sid = 185;
SID EVENT
---------- ----------------------------------------------------------------
TOTAL_WAITS TIME_WAITED
----------- -----------
185 Disk file operations I/O 1 0
185 db file scattered read 30 0 --- 멀티 블록 I/O 발생
185 SQL*Net message to client 15 0
SID EVENT TOTAL_WAITS TIME_WAITED
---------- --------------------------------------------------------------------------- -----------
185 SQL*Net message from client 14 3653
# 이벤트 설정 종료
SYS@ora11g> alter session set events '10949 trace name context off';
Session altered.
종료 후 조회를 다시 하면: direct path read 방식으로 가게 된다.
SYS@ora11g> alter system flush buffer_cache;
System altered.
SYS@ora11g> /
System altered.
HR@ora11g> alter session set events '10949 trace name context forever, level 1';
Session altered.
HR@ora11g> alter session set tracefile_identifier = 'hr';
Session altered.
HR@ora11g> alter session set events '10046 trace name context forever, level 8';
Session altered.
level 8 = SQL 문에 대한 트레이스도 뜨고 + 대기이벤트도 저장
HR@ora11g> select count(*) from ind_random where owner = 'SYS';
COUNT(*)
----------
29856
HR@ora11g> alter session set events '10046 trace name context off';
Session altered.
HR@ora11g> alter session set events '10949 trace name context off';
Session altered.
<<hr 로 다시 접속>>
HR@ora11g> !
[oracle@oracle ~]$ cd $ORACLE_BASE/diag/rdbms/ora11g/ora11g/trace
[oracle@oracle trace]$ ls *hr.trc
ora11g_ora_30696_hr.trc
[oracle@oracle trace]$ tkprof ora11g_ora_30696_hr.trc test1.ext
TKPROF: Release 11.2.0.4.0 - Development on Wed Feb 14 11:05:28 2024
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
[oracle@oracle trace]$ cat test1.ext
더보기
[oracle@oracle trace]$ cat test1.ext
TKPROF: Release 11.2.0.4.0 - Development on Wed Feb 14 11:05:28 2024
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: ora11g_ora_30696_hr.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
SQL ID: 6xpydnkm336jb Plan Hash: 3059062694
SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE
NO_PARALLEL(SAMPLESUB) opt_param('parallel_execution_enabled', 'false')
NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"),
NVL(SUM(C2),:"SYS_B_1")
FROM
(SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("IND_RANDOM") FULL("IND_RANDOM")
NO_PARALLEL_INDEX("IND_RANDOM") */ :"SYS_B_2" AS C1, CASE WHEN
"IND_RANDOM"."OWNER"=:"SYS_B_3" THEN :"SYS_B_4" ELSE :"SYS_B_5" END AS C2
FROM "HR"."IND_RANDOM" SAMPLE BLOCK (:"SYS_B_6" , :"SYS_B_7") SEED
(:"SYS_B_8") "IND_RANDOM") SAMPLESUB
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.02 0.29 269 58 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.02 0.29 269 58 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 84 (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=58 pr=269 pw=0 time=291183 us) 3677 3677 3677 TABLE ACCESS SAMPLE IND_RANDOM (cr=58 pr=269 pw=0 time=345 us cost=19 size=149234 card=5146)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 10 0.00 0.00
db file scattered read 33 0.00 0.00
********************************************************************************
SQL ID: 0bpvu28df5xzp Plan Hash: 3056395443
select count(*)
from
ind_random where owner = 'SYS'
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.02 0.29 270 59 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 4 0.04 0.68 717 1980 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 8 0.07 0.98 987 2039 0 2
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84
Number of plan statistics captured: 2
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=990 pr=358 pw=0 time=343882 us)
29856 29856 29856 TABLE ACCESS FULL IND_RANDOM (cr=990 pr=358 pw=0 time=5580 us cost=276 size=428281 card=25193)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 4 0.00 0.00
SQL*Net message from client 4 26.64 31.59
db file sequential read 3 0.00 0.00
db file scattered read 58 0.00 0.00
--- db file scattered read 가 50개가 넘어갈 경우: flush 하고 다시 해보자.
db file scattered read 는 extent 크기에 종속된다.
********************************************************************************
SQL ID: 06nvwn223659v Plan Hash: 0
alter session set events '10046 trace name context off'
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 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 0 0 0 0
Misses in library cache during parse: 0
Parsing user id: 84
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.02 0.29 270 59 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 4 0.04 0.68 717 1980 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10 0.07 0.98 987 2039 0 2
Misses in library cache during parse: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 5 0.00 0.00
SQL*Net message from client 5 41.16 72.76
db file sequential read 3 0.00 0.00
db file scattered read 58 0.00 0.00
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.02 0.29 269 58 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.02 0.29 269 58 0 1
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 10 0.00 0.00
db file scattered read 33 0.00 0.00
4 user SQL statements in session.
0 internal SQL statements in session.
4 SQL statements in session.
********************************************************************************
Trace file: ora11g_ora_30696_hr.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
4 user SQL statements in trace file.
0 internal SQL statements in trace file.
4 SQL statements in trace file.
3 unique SQL statements in trace file.
183 lines in trace file.
32 elapsed seconds in trace file.
SYS@ora11g> show parameter db_file_multiblock_read_count
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_file_multiblock_read_count integer 98
select extent_id, block_id, bytes, blocks
from dba_extents
where owner = 'HR'
and segment_name = 'IND_RANDOM';
extent_id 0번의 block_id = extent의 첫번째 블록 아이디, 그다음부터는 순서대로 넘버링된다.
0번부터 16번까지는 8개 블록으로 구성된 extent 이므로
하나의 I/O 콜을 이용할 때 : 98개씩 읽어들일 수 있는데
익스텐트 안에 8개밖에 없으므로 그냥 8개 읽어들인다.
그러면 0번부터 16번까지는 8개씩 읽어들이고
그 뒤부터는 블록이 128개이므로 2건씩 나누어 읽어들인다.
그래서 7번은 2번에 걸쳐 읽어들이므로 17번 + 14번 = 31번...
인데 나는 왜 58번이야?
멀티 블록 I/O 성능을 좋게 하려면:
SYS@ora11g> alter system flush buffer_cache;
System altered.
/
<<새로운 hr 세션에서>>
hr@ora11g> alter session set db_file_multiblock_read_count = 128;
Session altered.
hr@ora11g> alter session set events '10949 trace name context forever, level 1';
Session altered.
HR@ora11g> alter session set tracefile_identifier = 'hr';
Session altered.
HR@ora11g> alter session set events '10046 trace name context forever, level 8';
Session altered.
HR@ora11g> select count(*) from ind_random where owner = 'SYS';
COUNT(*)
----------
29856
HR@ora11g> alter session set events '10046 trace name context off';
Session altered.
HR@ora11g> alter session set events '10949 trace name context off';
Session altered.
HR@ora11g> !
[oracle@oracle ~]$ cd $ORACLE_BASE/diag/rdbms/ora11g/ora11g/trace
[oracle@oracle trace]$ ls *hr.trc
ora11g_ora_31910_hr.trc
[oracle@oracle trace]$ tkprof ora11g_ora_31910_hr.trc test2.txt
TKPROF: Release 11.2.0.4.0 - Development on Wed Feb 14 11:29:07 2024
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
[oracle@oracle trace]$ cat test2.txt
더보기
[oracle@oracle trace]$ cat test2.txt
TKPROF: Release 11.2.0.4.0 - Development on Wed Feb 14 11:29:07 2024
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: ora11g_ora_31910_hr.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
SQL ID: 0bpvu28df5xzp Plan Hash: 3056395443
select count(*)
from
ind_random where owner = 'SYS'
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.05 0.63 986 990 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.05 0.63 986 990 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 84
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=990 pr=986 pw=0 time=630144 us)
29856 29856 29856 TABLE ACCESS FULL IND_RANDOM (cr=990 pr=986 pw=0 time=5387 us cost=177 size=428281 card=25193)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
Disk file operations I/O 1 0.00 0.00
db file sequential read 1 0.00 0.00
db file scattered read 23 0.11 0.62
SQL*Net message from client 2 3.84 3.84
********************************************************************************
SQL ID: 06nvwn223659v Plan Hash: 0
alter session set events '10046 trace name context off'
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 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 0 0 0 0
Misses in library cache during parse: 0
Parsing user id: 84
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.05 0.63 986 990 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.05 0.63 986 990 0 1
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 3.84 7.33
Disk file operations I/O 1 0.00 0.00
db file sequential read 1 0.00 0.00
db file scattered read 23 0.11 0.62
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 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 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
2 user SQL statements in session.
0 internal SQL statements in session.
2 SQL statements in session.
********************************************************************************
Trace file: ora11g_ora_31910_hr.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
2 user SQL statements in trace file.
0 internal SQL statements in trace file.
2 SQL statements in trace file.
2 unique SQL statements in trace file.
77 lines in trace file.
4 elapsed seconds in trace file.
'오라클 퍼포먼스 튜닝' 카테고리의 다른 글
| 2024년 2월 14일 4교시 (0) | 2024.02.14 |
|---|---|
| 2024년 2월 14일 3교시 (0) | 2024.02.14 |
| 2024년 2월 14일 (발렌타인데이 ㅠㅠ) 1교시 (0) | 2024.02.14 |
| 2024년 2월 8일 1교시 (0) | 2024.02.08 |
| 2024년 2월 7일 5교시 (0) | 2024.02.07 |
