In previous blog posts here and here, I have demonstrated Full Table Scans of a table called ALL_OBJECTS_MANY_LIST being executed via Direct Path Reads (shown as 'direct path read') in the Wait Events.
This sort of read does NOT use the Buffer Cache and the read from disk directly goes to the user's server process PGA. Thus, the blocks read are not shareable with other users. Multiple users reading the same table(s) via Direct Path Read are not able to share the Buffer Cache, resulting in Disk Reads being repeated for every Full Table Scan request. (Note : The OS may be using a File System Buffer Cache or the Storage may be using a Storage Cache to service the Disk Reads, but Oracle will always see every re-read of the table as a Disk Read).
Pre-11g, this behaviour could only be possible for Parallel Query.
However, 11g introduced the feature of "serial_direct_read" which allows non-PQ FullTableScans to bypass the Buffer Cache. This behaviour is predicated by the size of the table (segment) vis-a-vis the Buffer Cache, in relation to what is called "small_table_threshold". A table exceeding a certain multiple of the "small_table_threshold" (which, by default, is a certain ratio of the Buffer Cache) is read via Direct Path Reads.
The Pre-11g and the 11g behaviour for smaller tables is to use Disk Reads that feed into the Buffer Cache, making the buffers shareable for repeated reads by either the same session or other sessions. This obviates the need to make Disk Read calls for subsequent requests (as long as the blocks are still in the Buffer Cache). The Wait Event we'd see for such Disk Reads is the (well known) "db file scattered read".
Here's a demo with a smaller table ALL_OBJECTS_SHORT_LIST.
The first query is the Dynamic Sampling query (because no statistics exist on the target table). As in example 8a, this is done with a mix of single block ("db file sequential read") and multiblock ("db file scattered read") waits. Here is a sampling of the waits for the Dynamic Sampling query :
This is the execution of the actual FullTableScan (the count(*) query submitted by me) :
This sort of read does NOT use the Buffer Cache and the read from disk directly goes to the user's server process PGA. Thus, the blocks read are not shareable with other users. Multiple users reading the same table(s) via Direct Path Read are not able to share the Buffer Cache, resulting in Disk Reads being repeated for every Full Table Scan request. (Note : The OS may be using a File System Buffer Cache or the Storage may be using a Storage Cache to service the Disk Reads, but Oracle will always see every re-read of the table as a Disk Read).
Pre-11g, this behaviour could only be possible for Parallel Query.
However, 11g introduced the feature of "serial_direct_read" which allows non-PQ FullTableScans to bypass the Buffer Cache. This behaviour is predicated by the size of the table (segment) vis-a-vis the Buffer Cache, in relation to what is called "small_table_threshold". A table exceeding a certain multiple of the "small_table_threshold" (which, by default, is a certain ratio of the Buffer Cache) is read via Direct Path Reads.
The Pre-11g and the 11g behaviour for smaller tables is to use Disk Reads that feed into the Buffer Cache, making the buffers shareable for repeated reads by either the same session or other sessions. This obviates the need to make Disk Read calls for subsequent requests (as long as the blocks are still in the Buffer Cache). The Wait Event we'd see for such Disk Reads is the (well known) "db file scattered read".
Here's a demo with a smaller table ALL_OBJECTS_SHORT_LIST.
SQL> exec dbms_session.session_trace_enable(waits=>TRUE);
PL/SQL procedure successfully completed.
SQL> select count(*) from all_objects_short_list;
COUNT(*)
----------
28117
SQL> exec dbms_session.session_trace_disable();
PL/SQL procedure successfully completed.
SQL> select value from v$diag_info where name = 'Default Trace File';
VALUE
--------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_3029.trc
SQL> exit
[oracle@ora11204 ~]$ tkprof /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_3029.trc \
> SHORT_LIST.PRF aggregate=NO sys=NO
TKPROF: Release 11.2.0.4.0 - Development on Sun Nov 29 23:13:43 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
[oracle@ora11204 ~]$
SQL ID: 69hzxtrb3dv1b Plan Hash: 1680768796
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 /*+ NO_PARALLEL("ALL_OBJECTS_SHORT_LIST")
FULL("ALL_OBJECTS_SHORT_LIST") NO_PARALLEL_INDEX("ALL_OBJECTS_SHORT_LIST")
*/ :"SYS_B_2" AS C1, :"SYS_B_3" AS C2 FROM
"HEMANT"."ALL_OBJECTS_SHORT_LIST" SAMPLE BLOCK (:"SYS_B_4" , :"SYS_B_5")
SEED (:"SYS_B_6") "ALL_OBJECTS_SHORT_LIST") 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.00 0.11 437 72 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.01 0.11 437 72 0 1
Misses in library cache during parse: 1
isses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 87 (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=72 pr=437 pw=0 time=110985 us)
3289 3289 3289 TABLE ACCESS SAMPLE ALL_OBJECTS_SHORT_LIST (cr=72 pr=437 pw=0 time=173325 us cost=19 size=61752 card=5146)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 7 0.04 0.05
db file scattered read 9 0.02 0.05
--------------------------------------------------------------------------------
SQL ID: 5ayuqj4djbjxh Plan Hash: 3180576180
select count(*)
from
all_objects_short_list
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.02 2 2 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.09 140 580 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.01 0.11 142 582 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 87
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=580 pr=140 pw=0 time=90644 us)
28117 28117 28117 TABLE ACCESS FULL ALL_OBJECTS_SHORT_LIST (cr=580 pr=140 pw=0 time=110678 us cost=158 size=0 card=30071)
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
db file scattered read 21 0.02 0.07
db file sequential read 3 0.00 0.00
SQL*Net message from client 2 9.76 9.76
********************************************************************************
The first query is the Dynamic Sampling query (because no statistics exist on the target table). As in example 8a, this is done with a mix of single block ("db file sequential read") and multiblock ("db file scattered read") waits. Here is a sampling of the waits for the Dynamic Sampling query :
WAIT #139712598070504: nam='db file sequential read' ela= 16 file#=1 block#=61344 blocks=1 obj#=35064 tim=1448809955554822 WAIT #139712598070504: nam='db file sequential read' ela= 951 file#=1 block#=61350 blocks=1 obj#=35064 tim=1448809955555840 WAIT #139712598070504: nam='db file scattered read' ela= 956 file#=1 block#=61362 blocks=6 obj#=35064 tim=1448809955556893 WAIT #139712598070504: nam='db file sequential read' ela= 720 file#=1 block#=61370 blocks=1 obj#=35064 tim=1448809955557710 WAIT #139712598070504: nam='db file sequential read' ela= 837 file#=1 block#=61378 blocks=1 obj#=35064 tim=1448809955558589 WAIT #139712598070504: nam='db file scattered read' ela= 1020 file#=1 block#=61385 blocks=7 obj#=35064 tim=1448809955559711 WAIT #139712598070504: nam='db file sequential read' ela= 804 file#=1 block#=61392 blocks=1 obj#=35064 tim=1448809955560643 WAIT #139712598070504: nam='db file scattered read' ela= 1270 file#=1 block#=61400 blocks=8 obj#=35064 tim=1448809955562000
This is the execution of the actual FullTableScan (the count(*) query submitted by me) :
EXEC #139712598962024:c=0,e=36,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3180576180,tim=1448809955666350 WAIT #139712598962024: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=35064 tim=1448809955666420 WAIT #139712598962024: nam='db file scattered read' ela= 28044 file#=1 block#=61345 blocks=5 obj#=35064 tim=1448809955695578 WAIT #139712598962024: nam='db file sequential read' ela= 1691 file#=1 block#=61351 blocks=1 obj#=35064 tim=1448809955697475 WAIT #139712598962024: nam='db file scattered read' ela= 11 file#=1 block#=61352 blocks=8 obj#=35064 tim=1448809955697539 WAIT #139712598962024: nam='db file scattered read' ela= 64 file#=1 block#=61360 blocks=2 obj#=35064 tim=1448809955697790 WAIT #139712598962024: nam='db file scattered read' ela= 468 file#=1 block#=61368 blocks=2 obj#=35064 tim=1448809955698673 WAIT #139712598962024: nam='db file scattered read' ela= 1493 file#=1 block#=61371 blocks=5 obj#=35064 tim=1448809955700255 WAIT #139712598962024: nam='db file scattered read' ela= 64 file#=1 block#=61376 blocks=2 obj#=35064 tim=1448809955700510 WAIT #139712598962024: nam='db file scattered read' ela= 1856 file#=1 block#=61379 blocks=5 obj#=35064 tim=1448809955702457 WAIT #139712598962024: nam='db file sequential read' ela= 11 file#=1 block#=61384 blocks=1 obj#=35064 tim=1448809955702568 WAIT #139712598962024: nam='db file scattered read' ela= 1184 file#=1 block#=61393 blocks=7 obj#=35064 tim=1448809955703916 WAIT #139712598962024: nam='db file scattered read' ela= 5970 file#=1 block#=61408 blocks=8 obj#=35064 tim=1448809955710042 WAIT #139712598962024: nam='db file scattered read' ela= 263 file#=1 block#=61424 blocks=7 obj#=35064 tim=1448809955710475 WAIT #139712598962024: nam='db file scattered read' ela= 2461 file#=1 block#=82176 blocks=8 obj#=35064 tim=1448809955713060 WAIT #139712598962024: nam='db file scattered read' ela= 2585 file#=1 block#=82184 blocks=8 obj#=35064 tim=1448809955715814 WAIT #139712598962024: nam='db file scattered read' ela= 70 file#=1 block#=82192 blocks=8 obj#=35064 tim=1448809955716030 WAIT #139712598962024: nam='db file scattered read' ela= 687 file#=1 block#=82200 blocks=3 obj#=35064 tim=1448809955716832 WAIT #139712598962024: nam='db file scattered read' ela= 28205 file#=1 block#=82204 blocks=4 obj#=35064 tim=1448809955745140 WAIT #139712598962024: nam='db file scattered read' ela= 13 file#=1 block#=82208 blocks=8 obj#=35064 tim=1448809955745285 WAIT #139712598962024: nam='db file scattered read' ela= 1070 file#=1 block#=82216 blocks=8 obj#=35064 tim=1448809955746453 WAIT #139712598962024: nam='db file sequential read' ela= 5960 file#=1 block#=82304 blocks=1 obj#=35064 tim=1448809955752560 WAIT #139712598962024: nam='db file scattered read' ela= 15 file#=1 block#=82538 blocks=5 obj#=35064 tim=1448809955754269 WAIT #139712598962024: nam='db file scattered read' ela= 15 file#=1 block#=82560 blocks=8 obj#=35064 tim=1448809955754481 WAIT #139712598962024: nam='db file scattered read' ela= 22 file#=1 block#=82674 blocks=14 obj#=35064 tim=1448809955755267 WAIT #139712598962024: nam='db file scattered read' ela= 18 file#=1 block#=82688 blocks=12 obj#=35064 tim=1448809955755460 FETCH #139712598962024:c=9997,e=90650,p=140,cr=580,cu=0,mis=0,r=1,dep=0,og=1,plh=3180576180,tim=1448809955757097 STAT #139712598962024 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=580 pr=140 pw=0 time=90644 us)' STAT #139712598962024 id=2 cnt=28117 pid=1 pos=1 obj=35064 op='TABLE ACCESS FULL ALL_OBJECTS_SHORT_LIST (cr=580 pr=140 pw=0 time=110678 us cost=158 size=0 card=30071)'
The Segment Header is in Block#61344 which has already been read into the Buffer Cache by the Dynamic Sampling query. So, we don't see a Wait Event for it in the count(*) query. The Disk Reads start from Block#61345. From 61345 onwards, 5 blocks are read from disk (61345 to 61349). Block#61350 has already been read into the Buffer Cache by the Dynamic Sampling query. Block#61351 is the last block of the Extents (8 blocks beginning at #61344) so it is a singe block read ("db file sequential read"). Even when Extents are contigous, Oracle will not make a read call that spans Extents. The next Extent starts at Block#61352 and Oracle does a proper 8 block read.
At Block#61360, Oracle does a 2 block read because Block#61362 has already been read by the Dynamic Sampling query and is in the Buffer Cache.
All the Extents for this table are very small
Thus, you can see that multiblock reads using the "db file scattered read" wait event are reads that also rely on knowing which blocks are already present in the Buffer Cache. Oracle does not do a "db file scattered read" read for a block that is already present in the Buffer Cache.
(What about Blocks 61363 to 61367 ? Unfortunately, not every read call does get reported into the trace file, sometimes there may be "holes". Not every Read Call is reported as being read to the last block in the Extent.
If you look at the Block# IDs being reported above and compare them with the Extents allocated, you will see that Oracle may not have reported every block as a Read Wait Event.
SQL> l 1 select extent_id, file_id, block_id, blocks 2 from dba_extents 3 where 4 owner = 'HEMANT' 5 and segment_name = 'ALL_OBJECTS_SHORT_LIST' 6* order by 1, 2, 3 SQL> / EXTENT_ID FILE_ID BLOCK_ID BLOCKS ---------- ---------- ---------- ---------- 0 1 61344 8 1 1 61352 8 2 1 61360 8 3 1 61368 8 4 1 61376 8 5 1 61384 8 6 1 61392 8 7 1 61400 8 8 1 61408 8 9 1 61424 8 10 1 82176 8 11 1 82184 8 12 1 82192 8 13 1 82200 8 14 1 82208 8 15 1 82216 8 16 1 82304 128 17 1 82432 128 18 1 82560 128 19 1 82688 128 20 rows selected. SQL>
Also, once again note that file#1 indicates that these are in the SYSTEM Tablespace. .
.
.
1 comment:
Big thanks for all those wonderful insights you share ,
Kind regards,
Foued
Post a Comment