Hi,
The environment
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit
8K block size
db_file_multiblock_read_count is 128
show sga
Total System Global Area 1.6702E+10 bytes
Fixed Size 2219952 bytes
Variable Size 7918846032 bytes
Database Buffers 8724152320 bytes
Redo Buffers 57090048 bytes
16GB of SGA with 8GB of db buffer cache.
-- database is built on Solid State Disks
-- SQL trace and wait events
DBMS_MONITOR.SESSION_TRACE_ENABLE ( waits=>true )
-- The underlying table is called tdash. It has 1.7 Million rows based on data in all_objects. NO index
TABLE_NAME Rows Table Size/MB Used/MB Free/MB
------------------------------ ------------ ------------- ------------ ----------
TDASH 1,729,204 15,242 15,186 56
TABLE_NAME Allocated blocks Empty blocks Average space/KB Free list blocks
------------------------------ ---------------- ------------ ---------------- ----------------
TDASH 1,943,823 7,153 805 0
Objectives
To show that when serial scans are performed on database built on Solid State Disks (SSD) compared to Magnetic disks (HDD), the performance gain is far less compared to random reads with index scans on SSD compared to HDD
Approach
We want to read the first 100 rows of tdash table randomly into buffer, taking account of wait events and wait times generated. The idea is that on SSD the wait times will be better compared to HDD but not that much given the serial nature of table scans.
The code used
ALTER SESSION SET TRACEFILE_IDENTIFIER = 'test_with_tdash_ssdtester_noindex';
DECLARE
type array is table of tdash%ROWTYPE index by binary_integer;
l_data array;
l_rec tdash%rowtype;
BEGIN
SELECT
a.*
,RPAD('*',4000,'*') AS PADDING1
,RPAD('*',4000,'*') AS PADDING2
BULK COLLECT INTO
l_data
FROM ALL_OBJECTS a;
DBMS_MONITOR.SESSION_TRACE_ENABLE ( waits=>true );
FOR rs IN 1 .. 100
LOOP
BEGIN
SELECT * INTO l_rec FROM tdash WHERE object_id = l_data(rs).object_id;
EXCEPTION
WHEN NO_DATA_FOUND THEN NULL;
END;
END LOOP;
END;
/
Server is rebooted prior to any tests
Whern run as default, the optimizer (although some attribute this to the execution engine) chooses
direct path read into PGA in preference to
db file scattered read.
With this choice it takes 6,520 seconds to complete the query. The results are shown below
SQL ID: 78kxqdhk1ubvq
Plan Hash: 1148949653
SELECT *
FROM
TDASH WHERE OBJECT_ID = :B1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 2 47 0 0
Execute 100 0.00 0.00 1 51 0 0
Fetch 100 10.88 6519.89 194142802 194831012 0 100
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 201 10.90 6519.90 194142805 194831110 0 100
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 96 (SSDTESTER) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL TDASH (cr=1948310 pr=1941430 pw=0 time=0 us cost=526908 size=8091 card=1)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
1 TABLE ACCESS MODE: ANALYZED (FULL) OF 'TDASH' (TABLE)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
Disk file operations I/O 3 0.00 0.00
db file sequential read 2 0.00 0.00
direct path read 1517504 0.05 6199.93
asynch descriptor resize 196 0.00 0.00
********************************************************************************
DECLARE
type array is table of tdash%ROWTYPE index by binary_integer;
l_data array;
l_rec tdash%rowtype;
BEGIN
SELECT
a.*
,RPAD('*',4000,'*') AS PADDING1
,RPAD('*',4000,'*') AS PADDING2
BULK COLLECT INTO
l_data
FROM ALL_OBJECTS a;
DBMS_MONITOR.SESSION_TRACE_ENABLE ( waits=>true );
FOR rs IN 1 .. 100
LOOP
BEGIN
SELECT * INTO l_rec FROM tdash WHERE object_id = l_data(rs).object_id;
EXCEPTION
WHEN NO_DATA_FOUND THEN NULL;
END;
END LOOP;
END;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 3.84 4.03 320 48666 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 3.84 4.03 320 48666 0 1
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 96 (SSDTESTER)
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 0.00 0.00
********************************************************************************
SQL ID: 9babjv8yq8ru3
Plan Hash: 0
BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END;
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 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 96 (SSDTESTER)
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 0.00 0.00
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 2 3.84 4.03 320 48666 0 2
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 3.84 4.03 320 48666 0 2
Misses in library cache during parse: 0
Misses in library cache during execute: 1
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
SQL*Net message from client 2 0.00 0.00
log file sync 1 0.00 0.00
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 9 0.01 0.00 2 47 0 0
Execute 129 0.01 0.00 1 52 2 1
Fetch 140 10.88 6519.89 194142805 194831110 0 130
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 278 10.91 6519.91 194142808 194831209 2 131
Misses in library cache during parse: 9
Misses in library cache during execute: 8
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 5 0.00 0.00
Disk file operations I/O 3 0.00 0.00
direct path read 1517504 0.05 6199.93
asynch descriptor resize 196 0.00 0.00
102 user SQL statements in session.
29 internal SQL statements in session.
131 SQL statements in session.
1 statement EXPLAINed in this session.
********************************************************************************
Trace file: mydb_ora_16394_test_with_tdash_ssdtester_noindex.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
102 user SQL statements in trace file.
29 internal SQL statements in trace file.
131 SQL statements in trace file.
11 unique SQL statements in trace file.
1 SQL statements EXPLAINed using schema:
ssdtester.plan_table
Schema was specified.
Table was created.
Table was dropped.
1531657 lines in trace file.
6520 elapsed seconds in trace file.
I then force the query not to use direct path read by invoking
ALTER SESSION SET EVENTS '10949 trace name context forever, level 1' -- No Direct path read ;
In this case the optimizer uses
db file scattered read predominantly and the query takes 4,299 seconds to finish which is around 34% faster than using direct path read (default).
The report is shown below
SQL ID: 78kxqdhk1ubvq
Plan Hash: 1148949653
SELECT *
FROM
TDASH WHERE OBJECT_ID = :B1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 2 47 0 0
Execute 100 0.00 0.00 2 51 0 0
Fetch 100 143.44 4298.87 110348670 194490912 0 100
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 201 143.45 4298.88 110348674 194491010 0 100
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 96 (SSDTESTER) (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL TDASH (cr=1944909 pr=1941430 pw=0 time=0 us cost=526908 size=8091 card=1)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
1 TABLE ACCESS MODE: ANALYZED (FULL) OF 'TDASH' (TABLE)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
Disk file operations I/O 3 0.00 0.00
db file sequential read 129759 0.01 17.50
db file scattered read 1218651 0.05 3770.02
latch: object queue header operation 2 0.00 0.00
********************************************************************************
DECLARE
type array is table of tdash%ROWTYPE index by binary_integer;
l_data array;
l_rec tdash%rowtype;
BEGIN
SELECT
a.*
,RPAD('*',4000,'*') AS PADDING1
,RPAD('*',4000,'*') AS PADDING2
BULK COLLECT INTO
l_data
FROM ALL_OBJECTS a;
DBMS_MONITOR.SESSION_TRACE_ENABLE ( waits=>true );
FOR rs IN 1 .. 100
LOOP
BEGIN
SELECT * INTO l_rec FROM tdash WHERE object_id = l_data(rs).object_id;
EXCEPTION
WHEN NO_DATA_FOUND THEN NULL;
END;
END LOOP;
END;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 3.92 4.07 319 48625 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1 3.92 4.07 319 48625 0 1
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 96 (SSDTESTER)
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 0.00 0.00
********************************************************************************
SQL ID: 9babjv8yq8ru3
Plan Hash: 0
BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END;
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 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 96 (SSDTESTER)
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 0.00 0.00
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 2 3.92 4.07 319 48625 0 2
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 3.92 4.07 319 48625 0 2
Misses in library cache during parse: 0
Misses in library cache during execute: 1
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
SQL*Net message from client 2 0.00 0.00
log file sync 1 0.00 0.00
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 9 0.01 0.00 2 47 0 0
Execute 129 0.00 0.00 2 52 2 1
Fetch 140 143.44 4298.87 110348674 194491010 0 130
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 278 143.46 4298.88 110348678 194491109 2 131
Misses in library cache during parse: 9
Misses in library cache during execute: 8
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 129763 0.01 17.50
Disk file operations I/O 3 0.00 0.00
db file scattered read 1218651 0.05 3770.02
latch: object queue header operation 2 0.00 0.00
102 user SQL statements in session.
29 internal SQL statements in session.
131 SQL statements in session.
1 statement EXPLAINed in this session.
********************************************************************************
Trace file: mydb_ora_26796_test_with_tdash_ssdtester_noindex_NDPR.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
102 user SQL statements in trace file.
29 internal SQL statements in trace file.
131 SQL statements in trace file.
11 unique SQL statements in trace file.
1 SQL statements EXPLAINed using schema:
ssdtester.plan_table
Schema was specified.
Table was created.
Table was dropped.
1357958 lines in trace file.
4299 elapsed seconds in trace file.
I note that there are 1,517,504 waits with
direct path read with total time of nearly 6,200 seconds. In comparison with no direct path read, there are 1,218,651
db file scattered read waits with total wait time of 3,770 seconds. My understanding is that direct path read can use single or multi-block read into the PGA. However db file scattered reads do multi-block read into multiple discontinuous SGA buffers. So it is possible given the higher number of direct path waits that the optimizer cannot do multi-block reads (contigious buffers within PGA) and hence has to revert to single blocks reads which results in more calls and more waits?.
Appreciate any advise and apologies for being long winded.
Thanks,
Mich