In this Blog we will see how the DBMS_STATS.GATHER_TABLE_STATS will behave in exadata. Whether this full
take full advantage of smart scan capabilities? We will see this in this blog.
rdbms&crs version - 11.2.0.3.0
Before taking and starting about investigation about the Smart Scan, we should bear in mind that following
are the requirements for smart scan to kick in
1) Database must choose Direct path read of its operation
2) Table should have parallel degree defined(if its a small table and satisfying the _small_table_threashold value)
3) If table is large (as defined by _small_table_threashold) then serial direct path read is performed(no parallel degree in this case)
4) Explain plan should have 'STORAGE' word in rowsource operation. For example in non-exadata operation
is something like 'Table Access Full' but in Exadata
its should be as 'Table Access Storage Full'
5) In Predicate section of Explain Plan, it should have storage clause
Note- Even if above conditions are satisfied, its not guranted smart scan would take place. We will see why this can happen in some cases.
However optimizer is not completely aware about the existence of exadata and direct path read decision is made
after optimizer does its job. So there are some heuristics involved when to choose Direct path read operation somethink
like segment size,numbers of blocks already in buffer cahce
, SGA
size etc etc.
There is no direct way to check if Smart Scan has happened or not for a query and also how effective the smart
scan is, is not known easily. However there are specific performance counters and some wait events for which we can check if a) Smart Scan happened at all or b) how much effective was the SMart
scan. So we will use these tow techniques to check smart scan optimization.
I logged in to session and executed below query:
SQL> select s.name,m.value from v$sysstat s,v$mystat m where s.STATISTIC#=m.STATISTIC# and name like '%cell%';
NAME VALUE
---------------------------------------------------------------- ----------
cell physical IO interconnect bytes 0
cell physical IO bytes saved during optimized file creation 0
cell physical IO bytes saved during optimized RMAN file restore 0
cell physical IO bytes eligible for predicate offload 0
cell physical IO bytes saved by storage index 0
cell physical IO bytes sent directly to DB node to balance CPU 0
cell smart IO session cache lookups 0
cell smart IO session cache hits 0
cell smart IO session cache soft misses 0
cell smart IO session cache hard misses 0
cell smart IO session cache hwm 0
NAME VALUE
---------------------------------------------------------------- ----------
cell num smart IO sessions in rdbms block IO due to user 0
cell num smart IO sessions in rdbms block IO due to no cell mem 0
cell num smart IO sessions in rdbms block IO due to big payload 0
cell num smart IO sessions using passthru mode due to user 0
cell num smart IO sessions using passthru mode due to cellsrv 0
cell num smart IO sessions using passthru mode due to timezone 0
cell num smart file creation sessions using rdbms block IO mode 0
cell physical IO interconnect bytes returned by smart scan 0
cell num fast response sessions 0
cell num fast response sessions continuing to smart scan 0
cell statistics spare1 0
NAME VALUE
---------------------------------------------------------------- ----------
cell statistics spare2 0
cell statistics spare3 0
cell statistics spare4 0
cell statistics spare5 0
cell statistics spare6 0
cell scans 0
cell blocks processed by cache layer 0
cell blocks processed by txn layer 0
cell blocks processed by data layer 0
cell blocks processed by index layer 0
cell commit cache queries 0
NAME VALUE
---------------------------------------------------------------- ----------
cell transactions found in commit cache 0
cell blocks helped by commit cache 0
cell blocks helped by minscn optimization 0
chained rows skipped by cell 0
chained rows processed by cell 0
chained rows rejected by cell 0
cell simulated physical IO bytes eligible for predicate offload 0
cell simulated physical IO bytes returned by predicate offload 0
cell CUs sent uncompressed 0
cell CUs sent compressed 0
cell CUs sent head piece 0
NAME VALUE
---------------------------------------------------------------- ----------
cell CUs processed for uncompressed 0
cell CUs processed for compressed 0
cell IO uncompressed bytes 0
cell index scans 0
cell flash cache read hits 0
49 rows selected.
SO there are 49 critical performance counters which can tell us the effiectivnes of smart scan optimization.
As it can be seen all these have zero values since this was fresh login to database(Note we used v%sysstat
and v$mystat, as we are only concern about our session)
SQL> select s.name,m.value from v$sysstat s,v$mystat m where s.STATISTIC#=m.STATISTIC# and name like '%physical%';
NAME VALUE
---------------------------------------------------------------- ----------
physical read total IO requests 0
physical read total multi block requests 0
physical read requests optimized 0
physical read total bytes optimized 0
physical read total bytes 0
physical write total IO requests 0
physical write total multi block requests 0
physical write total bytes 0
cell physical IO interconnect bytes 0
physical reads 0
physical reads cache 0
NAME VALUE
---------------------------------------------------------------- ----------
physical read flash cache hits 0
physical reads direct 0
physical read IO requests 0
physical read bytes 0
physical writes 0
physical writes direct 0
physical writes from cache 0
physical write IO requests 0
physical reads direct temporary tablespace 0
physical writes direct temporary tablespace 0
physical write bytes 0
NAME VALUE
---------------------------------------------------------------- ----------
physical writes non checkpoint 0
physical reads cache prefetch 0
physical reads prefetch warmup 0
physical reads retry corrupt 0
physical reads direct (lob) 0
physical writes direct (lob) 0
physical reads for flashback new 0
cell physical IO bytes saved during optimized file creation 0
cell physical IO bytes saved during optimized RMAN file restore 0
cell physical IO bytes eligible for predicate offload 0
cell physical IO bytes saved by storage index 0
NAME VALUE
---------------------------------------------------------------- ----------
cell physical IO bytes sent directly to DB node to balance CPU 0
cell physical IO interconnect bytes returned by smart scan 0
cell simulated physical IO bytes eligible for predicate offload 0
cell simulated physical IO bytes returned by predicate offload 0
37 rows selected.
We wanted to generate the Tracefile for this session
16:06:42 SQL> alter session set tracefile_identifier='tracing_gatherstats';
Session altered.
Elapsed: 00:00:00.00
16:06:57 SQL> alter session Set MAX_DUMP_FILE_SIZE='unlimited';
Session altered.
Elapsed: 00:00:00.00
16:07:04 SQL>
16:07:05 SQL> Alter session set events '10046 trace name context forever, level 12';
Session altered.
Elapsed: 00:00:00.00
From other session we first checked the DEGREE parameter for following table:
SQL> select degree from dba_tables where table_name='ACCT_STATEMENT';
DEGREE
----------------------------------------
1
-----
Now we run the actual command for which we want to see the Smart Scan:
16:07:20 SQL> exec dbms_stats.gather_table_stats('BOB_PROD_ODS','ACCT_STATEMENT', estimate_percent => dbms_stats.auto_sample_size, method_opt => 'for all columns size 1');
PL/SQL procedure successfully completed.
Elapsed: 00:03:28.23
Note- We have not used the parallel attribute to cause this job to run in parallel and we have also used
AUTO_SAMPLE_SIZE. This table is around 10GB in size.
Notice the time is took for further references
16:11:22 SQL> select s.name,m.value from v$sysstat s,v$mystat m where s.STATISTIC#=m.STATISTIC# and name like '%cell%';
NAME VALUE
---------------------------------------------------------------- ----------
cell physical IO interconnect bytes 6611836928
cell physical IO bytes saved during optimized file creation 0
cell physical IO bytes saved during optimized RMAN file restore 0
cell physical IO bytes eligible for predicate offload 0
cell physical IO bytes saved by storage index 0
cell physical IO bytes sent directly to DB node to balance CPU 0
cell smart IO session cache lookups 0
cell smart IO session cache hits 0
cell smart IO session cache soft misses 0
cell smart IO session cache hard misses 0
cell smart IO session cache hwm 0
NAME VALUE
---------------------------------------------------------------- ----------
cell num smart IO sessions in rdbms block IO due to user 0
cell num smart IO sessions in rdbms block IO due to no cell mem 0
cell num smart IO sessions in rdbms block IO due to big payload 0
cell num smart IO sessions using passthru mode due to user 0
cell num smart IO sessions using passthru mode due to cellsrv 0
cell num smart IO sessions using passthru mode due to timezone 0
cell num smar
t file creation sessions using rdbms block IO mode 0
cell physical IO interconnect bytes returned by smart scan 0
cell num fast response sessions 0
cell num fast response sessions continuing to smart scan 0
cell statistics spare1 0
NAME VALUE
---------------------------------------------------------------- ----------
cell statistics spare2 0
cell statistics spare3 0
cell statistics spare4 0
cell statistics spare5 0
cell statistics spare6 0
cell scans 0
cell blocks processed by cache layer 0
cell blocks processed by txn layer 0
cell blocks processed by data layer 0
cell blocks processed by index layer 0
cell commit cache queries 0
NAME VALUE
---------------------------------------------------------------- ----------
cell transactions found in commit cache 0
cell blocks helped by commit cache 0
cell blocks helped by minscn optimization 0
chained rows skipped by cell 0
chained rows processed by cell 0
chained rows rejected by cell 0
cell simulated physical IO bytes eligible for predicate offload 0
cell simulated physical IO bytes returned by predicate offload 0
cell CUs sent uncompressed 0
cell CUs sent compressed 0
cell CUs sent head piece 0
NAME VALUE
---------------------------------------------------------------- ----------
cell CUs processed for uncompressed 0
cell CUs processed for compressed 0
cell IO uncompressed bytes 0
cell index scans 0
cell flash cache read hits 803266
49 rows selected.
Some observation made from above:
cell physical IO interconnect bytes is high i.e around 6GB, this means the amount of data flown through
Interconnects which included everything.(including buffer blocks)
cell physical IO bytes eligible for predicate offload is Zero (No smart scan)
cell physical IO bytes saved by storage index is Zero (No Storage index optimization here)
cell physical IO interconnect bytes returned by smart scan is Zero (No Smart scan Optimization)
cell flash cache read hits has non-zero value: (Flash cache helped us a bit)
Conclusion for above result is dbms_stats job didn't get any benefit outof smartscan.
Its time to get the same conclusion from Trace file:
Let check the Tkprof of trace:
********************************************************************************
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.09 0.28 0 51 232 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.09 0.29 0 51 232 1
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 3 0.00 0.00
SQL*Net message from client 2 33.99 45.55
SQL*Net break/reset to client 2 0.00 0.00
Disk file operations I/O 940 0.00 0.00
DFS lock handle 32 0.10 0.19
row cache lock 40 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 361 0.02 0.03 0 0 0 0
Execute 697 0.11 0.13 10 2233 806 294
Fetch 360 186.02 207.79 807099 1306746 4 433
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1418 186.17 207.95 807109 1308979 810 727
Misses in library cache during parse: 4
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
asynch descriptor resize 1 0.00 0.00
enq: TM - contention 3 0.00 0.00
gc current block 3-way 48 0.00 0.00
Disk file operations I/O 8 0.00 0.00
gc current block 2-way 21477 0.00 1.93
gc current grant 2-way 9 0.00 0.00
cell single block physical read 2103 0.01 1.19
gc cr block 2-way 10 0.00 0.00
gc current grant busy 1 0.00 0.00
gc cr multi block request 17039 0.01 5.89
gc current block congested 74 0.00 0.00
cell multiblock physical read 1223 0.03 1.06
cell list of blocks physical read 9047 0.05 28.80
latch: gcs resource hash 2 0.00 0.00
latch: gc element 12 0.00 0.00
gc cr grant 2-way 25 0.00 0.00
gc cr block busy 115 0.00 0.06
latch free 1 0.00 0.00
3 user SQL statements in session.
233 internal SQL statements in session.
236 SQL statements in session.
********************************************************************************
From above output also its confirmed that no smart scan happened here, if it were then we could have seen
'Cell smart scan' wait event.
Also notice high waits for '
cell single block physical read' and '
cell list of blocks physical read'
which clearly shows that operation was mostly depend upon the single path access plan.
Let put table in degree of 10 and see the performance(by doing this we are satisfying the requirements for smart
scan)
SQL> alter table bob_prod_ods.ACCT_STATEMENT parallel 10;
Table altered.
SQL*Plus: Release 11.2.0.3.0 Production on Wed Jul 11 16:17:52 2012
Copyright (c) 1982, 2011, Oracle. All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
SQL> select s.name,m.value from v$sysstat s,v$mystat m where s.STATISTIC#=m.STATISTIC# and name like '%cell%';
NAME VALUE
---------------------------------------------------------------- ----------
cell physical IO interconnect bytes 0
cell physical IO bytes saved during optimized file creation 0
cell physical IO bytes saved during optimized RMAN file restore 0
cell physical IO bytes eligible for predicate offload 0
cell physical IO bytes saved by storage index 0
cell physical IO bytes sent directly to DB node to balance CPU 0
cell smart IO session cache lookups 0
cell smart IO session cache hits 0
cell smart IO session cache soft misses 0
cell smart IO session cache hard misses 0
cell smart IO session cache hwm 0
NAME VALUE
---------------------------------------------------------------- ----------
cell num smart IO sessions in rdbms block IO due to user 0
cell num smart IO sessions in rdbms block IO due to no cell mem 0
cell num smart IO sessions in rdbms block IO due to big payload 0
cell num smart IO sessions using passthru mode due to user 0
cell num smart IO sessions using passthru mode due to cellsrv 0
cell num smart IO sessions using passthru mode due to timezone 0
cell num smart file creation sessions using rdbms block IO mode 0
cell physical IO interconnect bytes returned by smart scan 0
cell num fast response sessions 0
cell num fast response sessions continuing to smart scan 0
cell statistics spare1 0
NAME VALUE
---------------------------------------------------------------- ----------
cell statistics spare2 0
cell statistics spare3 0
cell statistics spare4 0
cell statistics spare5 0
cell statistics spare6 0
cell scans 0
cell blocks processed by cache layer 0
cell blocks processed by txn layer 0
cell blocks processed by data layer 0
cell blocks processed by index layer 0
cell commit cache queries 0
NAME VALUE
---------------------------------------------------------------- ----------
cell transactions found in commit cache 0
cell blocks helped by commit cache 0
cell blocks helped by minscn optimization 0
chained rows skipped by cell 0
chained rows processed by cell 0
chained rows rejected by cell 0
cell simulated physical IO bytes eligible for predicate offload 0
cell simulated physical IO bytes returned by predicate offload 0
cell CUs sent uncompressed 0
cell CUs sent compressed 0
cell CUs sent head piece 0
NAME VALUE
---------------------------------------------------------------- ----------
cell CUs processed for uncompressed 0
cell CUs processed for compressed 0
cell IO uncompressed bytes 0
cell index scans 0
cell flash cache read hits 0
49 rows selected.
Again notice the zero values for critical performance counters:
Setting the trace:
SQL> set time on timing on;
16:18:15 SQL> alter session set tracefile_identifier='tracing_gatherstats_parallel';
Session altered.
Elapsed: 00:00:00.00
16:18:23 SQL> alter session Set MAX_DUMP_FILE_SIZE='unlimited';
Session altered.
Elapsed: 00:00:00.00
16:18:27 SQL> Alter session set events '10046 trace name context forever, level 12';
Session altered.
Elapsed: 00:00:00.00
16:19:00 SQL> exec dbms_stats.gather_table_stats('BOB_PROD_ODS','ACCT_STATEMENT',
estimate_percent => dbms_stats.auto_sample_size, method_opt => 'for all columns size 1');
PL/SQL procedure successfully completed.
Elapsed: 00:00:43.31
-wow, did you notice the time difference?
Also note the
dbms_stats.auto_sample_size in the job
16:19:57 SQL> select s.name,m.value from v$sysstat s,v$mystat m where s.STATISTIC#=m.STATISTIC# and name like '%cell%';
NAME VALUE
---------------------------------------------------------------- ----------
cell physical IO interconnect bytes 5514297160
cell physical IO bytes saved during optimized file creation 0
cell physical IO bytes saved during optimized RMAN file restore 0
cell physical IO bytes eligible for predicate offload 1.0614E+10
cell physical IO bytes saved by storage index 0
cell physical IO bytes sent directly to DB node to balance CPU 0
cell smart IO session cache lookups 146
cell smart IO session cache hits 146
cell smart IO session cache soft misses 10
cell smart IO session cache hard misses 0
cell smart IO session cache hwm 0
NAME VALUE
---------------------------------------------------------------- ----------
cell num smart IO sessions in rdbms block IO due to user 0
cell num smart IO sessions in rdbms block IO due to no cell mem 0
cell num smart IO sessions in rdbms block IO due to big payload 0
cell num smart IO sessions using passthru mode due to user 0
cell num smart IO sessions using passthru mode due to cellsrv 0
cell num smart IO sessions using passthru mode due to timezone 0
cell num smart file creation sessions using rdbms block IO mode 0
cell physical IO interconnect bytes returned by smart scan 5507768136
cell num fast response sessions 0
cell num fast response sessions continuing to smart scan 0
cell statistics spare1 0
NAME VALUE
---------------------------------------------------------------- ----------
cell statistics spare2 0
cell statistics spare3 0
cell statistics spare4 0
cell statistics spare5 0
cell statistics spare6 0
cell scans 156
cell blocks processed by cache layer 1428684
cell blocks processed by txn layer 1428684
cell blocks processed by data layer 1300170
cell blocks processed by index layer 0
cell commit cache queries 0
NAME VALUE
---------------------------------------------------------------- ----------
cell transactions found in commit cache 0
cell blocks helped by commit cache 0
cell blocks helped by minscn optimization 1428684
chained rows skipped by cell 0
chained rows processed by cell 0
chained rows rejected by cell 0
cell simulated physical IO bytes eligible for predicate offload 0
cell simulated physical IO bytes returned by predicate offload 0
cell CUs sent uncompressed 0
cell CUs sent compressed 0
cell CUs sent head piece 0
NAME VALUE
---------------------------------------------------------------- ----------
cell CUs processed for uncompressed 0
cell CUs processed for compressed 0
cell IO uncompressed bytes 1.0651E+10
cell index scans 0
cell flash cache read hits 15209
49 rows selected.
Its time to explain some the these performance counters(i will cover it detail explanation later)
cell physical IO bytes eligible for predicate offload has around 10GB of value (smart scan if confirmed)
cell physical IO interconnect bytes returned by smart scan has gottan value, this performance counter is the
critical one to know whether smart scan happened or not. Generally the bytes sent back to database node through
smart scan is quite low, but in our case its quite high. But one thing we made sure that smart scan has kicked in
cell blocks processed by cache layer
cell blocks processed by txn layer
cell blocks processed by data layer
All above counters got almost same amount of values which means there are 1428684 approx blocks which were processed
by smart scan during optimization.(I will cover its details explanation later) These three holds the critical information like how much effective was smart Scan when scanning the blocks.
16:20:44 SQL> select s.name,m.value from v$sysstat s,v$mystat m where s.STATISTIC#=m.STATISTIC# and name like '%physical%';
NAME VALUE
---------------------------------------------------------------- ----------
physical read total IO requests 15242
physical read total multi block requests 12540
physical read requests optimized 15209
physical read total bytes optimized 1.0603E+10
physical read total bytes 1.0621E+10
physical write total IO requests 0
physical write total multi block requests 0
physical write total bytes 0
cell physical IO interconnect bytes 5514297160
physical reads 1296460
physical reads cache 797
NAME VALUE
---------------------------------------------------------------- ----------
physical read flash cache hits 0
physical reads direct 1295663
physical read IO requests 15242
physical read bytes 1.0621E+10
physical writes 0
physical writes direct 0
physical writes from cache 0
physical write IO requests 0
physical reads direct temporary tablespace 0
physical writes direct temporary tablespace 0
physical write bytes 0
NAME VALUE
---------------------------------------------------------------- ----------
physical writes non checkpoint 0
physical reads cache prefetch 473
physical reads prefetch warmup 0
physical reads retry corrupt 0
physical reads direct (lob) 0
physical writes direct (lob) 0
physical reads for flashback new 0
cell physical IO bytes saved during optimized file creation 0
cell physical IO bytes saved during optimized RMAN file restore 0
cell physical IO bytes eligible for predicate offload 1.0614E+10
cell physical IO bytes saved by storage index 0
NAME VALUE
---------------------------------------------------------------- ----------
cell physical IO bytes sent directly to DB node to balance CPU 0
cell physical IO interconnect bytes returned by smart scan 5507768136
cell simulated physical IO bytes eligible for predicate offload 0
cell simulated physical IO bytes returned by predicate offload 0
From above its obvious that any physical read shown here had actually turned into smart scan. Look at
physical read total bytes optimized - which shows how many bytes has either optimized using
a)storage index b) flash cache or smart scan.
Let confirm this from Trace file as will. Since we job ran in parallel(degree 10), so we got 10 traces in
trace directory. But we can confirm smart scan only by checking QC and one out of 10 Slave process trace,
Trace file for QC:
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 5 0.00 0.00 0 0 0 0
Execute 5 0.08 0.29 0 51 178 1
Fetch 9 0.25 0.25 0 0 0 86
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 19 0.34 0.56 0 51 178 87
Misses in library cache during parse: 2
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 13 0.00 0.00
SQL*Net message from client 13 64.43 209.74
SQL*Net break/reset to client 2 0.00 0.00
Disk file operations I/O 940 0.00 0.00
DFS lock handle 32 0.10 0.22
row cache lock 40 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 196 0.02 0.02 0 0 0 0
Execute 548 0.09 1.78 0 2233 692 238
Fetch 368 27.28 41.20 797 11019 2 445
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 1112 27.39 43.02 797 13252 694 683
Misses in library cache during parse: 5
Misses in library cache during execute: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
asynch descriptor resize 1 0.00 0.00
gc cr block 2-way 10 0.00 0.00
gc current block 2-way 171 0.00 0.02
enq: TM - contention 3 0.00 0.00
gc current block 3-way 101 0.01 0.03
Disk file operations I/O 5 0.00 0.00
gc current grant busy 2 0.00 0.00
gc current block busy 1 0.00 0.00
enq: KO - fast object checkpoint 4 0.66 0.66
reliable message 1 0.00 0.00
enq: PS - contention 3 0.01 0.01
os thread startup 8 0.15 0.98
PX Deq: Join ACK 10 0.00 0.01
PX Deq: Parse Reply 10 0.00 0.00
PX Deq: Execute Reply 720 1.06 13.40
PX Deq: Signal ACK RSG 10 0.00 0.00
PX Deq: Signal ACK EXT 10 0.00 0.01
PX Deq: Slave Session Stats 10 0.00 0.00
gc cr multi block request 1055 0.00 0.33
gc cr grant 2-way 25 0.00 0.00
cell single block physical read 161 0.00 0.08
cell list of blocks physical read 81 0.00 0.04
gc current block congested 2 0.00 0.00
cell multiblock physical read 82 0.00 0.08
gc cr block busy 76 0.00 0.04
enq: HW - contention 1 0.00 0.00
Observation:
We still see 'cell single block physical read' but this time its very less. There is no 'Cell Smart Scan' in above trace
but remember its the slave process job to scan the segments, so would expect this wait events to appear
in slave process trace.
Trace file for slave process:
Posting only rel event information:
PARSING IN CURSOR #46950731292240 len=6956 dep=1 uid=84 oct=3 lid=0 tim=1342003755944863 hv=3787614688 ad='76e8e9790' sqlid='079nqsmhw4ug0'
/* SQL Analyze(0) */ select /*+ full(t) parallel(t,10) parallel_index(t,10) dbms_stats cursor_sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitoring no_substrb_pad */to_char(count("ACCT_ID")),to_char(substrb(dump(min("ACCT_ID")
----------------------
Above is the very first statement ran by slave processes( i have cut the rest of the lines and only shoed the prefix of this query)
Notice, optimzier has included parallel and Full hint for table segments and for its indexes.
Some initial lines from tracefiles..
END OF STMT
PARSE #46950731292240:c=0,e=120,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=3385837045,tim=1342003755944862
WAIT #47183537774160: nam='Disk file operations I/O' ela= 264 FileOperation=2 fileno=1281 filetype=2 obj#=-1 tim=1342003755961284
WAIT #47183537774160: nam='
Disk file operations I/O' ela= 3 FileOperation=2 fileno=1280 filetype=2 obj#=-1 tim=1342003755961329
WAIT #47183537774160: nam='Disk file operations I/O' ela= 4 FileOperation=2 fileno=1279 filetype=2 obj#=-1 tim=1342003755961346
WAIT #47183537774160: nam='Disk file operations I/O' ela= 3 FileOperation=2 fileno=1278 filetype=2 obj#=-1 tim=1342003755961360
WAIT #47183537774160: nam='Disk file operations I/O' ela= 3 FileOperation=2 fileno=1277 filetype=2 obj#=-1 tim=1342003755961377
WAIT #47183537774160: nam='Disk file operations I/O' ela= 5 FileOperation=2 fileno=1276 filetype=2 obj#=-1 tim=1342003755961391
WAIT #47183537774160: nam='Disk file operations I/O' ela= 2 FileOperation=2 fileno=1275 filetype=2 obj#=-1 tim=1342003755961405
WAIT #47183537774160: nam='Disk file operations I/O' ela= 1 FileOperation=2 fileno=1274 filetype=2 obj#=-1 tim=1342003755961426
WAIT #47183537774160: nam='Disk file operations I/O' ela= 2 FileOperation=2 fileno=1273 filetype=2 obj#=-1 tim=1342003755961441
WAIT #47183537774160: nam='Disk file operations I/O' ela= 5 FileOperation=2 fileno=1272 filetype=2 obj#=-1 tim=1342003755961463
WAIT #47183537774160: nam='Disk file operations I/O' ela= 4 FileOperation=2 fileno=1271 filetype=2 obj#=-1 tim=1342003755961487
WAIT #47183537774160: nam='Disk file operations I/O' ela= 3 FileOperation=2 fileno=1270 filetype=2 obj#=-1 tim=1342003755961505
WAIT #47183537774160: nam='Disk file operations I/O' ela= 5 FileOperation=2 fileno=1269 filetype=2 obj#=-1 tim=1342003755961523
WAIT #47183537774160: nam='Disk file operations I/O' ela= 2 FileOperation=2 fileno=1268 filetype=2 obj#=-1 tim=1342003755961537
WAIT #47183537774160: nam='Disk file operations I/O' ela= 3 FileOperation=2 fileno=1267 filetype=2 obj#=-1 tim=1342003755961550
WAIT #47183537774160: nam='Disk file operations I/O' ela= 13 FileOperation=2 fileno=1266 filetype=2 obj#=-1 tim=1342003755961578
WAIT #47183537774160: nam='Disk file operations I/O' ela= 10 FileOperation=2 fileno=1265 filetype=2 obj#=-1 tim=1342003755961601
WAIT #47183537774160: nam='Disk file operations I/O' ela= 6 FileOperation=2 fileno=1264 filetype=2 obj#=-1 tim=1342003755961616
WAIT #47183537774160: nam='Disk file operations I/O' ela= 3 FileOperation=2 fileno=1263 filetype=2 obj#=-1 tim=1342003755961631
WAIT #47183537774160: nam='Disk file operations I/O' ela= 3 FileOperation=2 fileno=1262 filetype=2 obj#=-1 tim=1342003755961645
WAIT #47183537774160: nam='Disk file operations I/O' ela= 9 FileOperation=2 fileno=1261 filetype=2 obj#=-1 tim=1342003755961662
WAIT #47183537774160: nam='Disk file operations I/O' ela= 4 FileOperation=2 fileno=1260 filetype=2 obj#=-1 tim=1342003755961676
WAIT #47183537774160: nam='Disk file operations I/O' ela= 3 FileOperation=2 fileno=1258 filetype=2 obj#=-1 tim=1342003755961689
WAIT #47183537774160: nam='Disk file operations I/O' ela= 5 FileOperation=2 fileno=1190 filetype=2 obj#=-1 tim=1342003755961706
WAIT #47183537774160: nam='Disk file operations I/O' ela= 1 FileOperation=2 fileno=1189 filetype=2 obj#=-1 tim=1342003755961726
WAIT #47183537774160: nam='Disk file operations I/O' ela= 4 FileOperation=2 fileno=1188 filetype=2 obj#=-1 tim=1342003755961741
WAIT #47183537774160: nam='Disk file operations I/O' ela= 4 FileOperation=2 fileno=1187 filetype=2 obj#=-1 tim=1342003755961777
WAIT #47183537774160: nam='Disk file operations I/O' ela= 10 FileOperation=2 fileno=1186 filetype=2 obj#=-1 tim=1342003755961798
WAIT #47183537774160: nam='Disk file operations I/O' ela= 2 FileOperation=2 fileno=1185 filetype=2 obj#=-1 tim=1342003755
------------------------------
WAIT #46950731292240: nam='PX Deq: Execution Msg' ela= 3990 sleeptime/senderid=268566527 passes=1 p3=31829234640 obj#=-1 tim=1342003755952048
WAIT #46950731292240: nam='
cell smart table scan' ela= 171 cellhash#=1170179701 p2=0 p3=0 obj#=75635 tim=1342003755963472
WAIT #46950731292240: nam='cell smart table scan' ela= 151 cellhash#=2167730007 p2=0 p3=0 obj#=75635 tim=1342003755964454
WAIT #46950731292240: nam='cell smart table scan' ela= 138 cellhash#=3675430230 p2=0 p3=0 obj#=75635 tim=1342003755965431
WAIT #46950731292240: nam='cell smart table scan' ela= 132 cellhash#=3883045144 p2=0 p3=0 obj#=75635 tim=1342003755966388
WAIT #46950731292240: nam='cell smart table scan' ela= 156 cellhash#=1423418432 p2=0 p3=0 obj#=75635 tim=1342003755967396
WAIT #46950731292240: nam='cell smart table scan' ela= 122 cellhash#=1731298062 p2=0 p3=0 obj#=75635 tim=1342003755968112
WAIT #46950731292240: nam='cell smart table scan' ela= 122 cellhash#=1557764708 p2=0 p3=0 obj#=75635 tim=1342003755968826
WAIT #46950731292240: nam='cell smart table scan' ela= 141 cellhash#=3126672640 p2=0 p3=0 obj#=75635 tim=1342003755969535
WAIT #46950731292240: nam='cell smart table scan' ela= 181 cellhash#=3737599385 p2=0 p3=0 obj#=75635 tim=1342003755970278
WAIT #46950731292240: nam='cell smart table scan' ela= 118 cellhash#=283595207 p2=0 p3=0 obj#=75635 tim=1342003755971101
WAIT #46950731292240: nam='cell smart table scan' ela= 194 cellhash#=3222317718 p2=0 p3=0 obj#=75635 tim=1342003755971870
WAIT #46950731292240: nam='cell smart table scan' ela= 147 cellhash#=406411811 p2=0 p3=0 obj#=75635 tim=1342003755972587
WAIT #46950731292240: nam='cell smart table scan' ela= 108 cellhash#=2548483693 p2=0 p3=0 obj#=75635 tim=1342003755973309
WAIT #46950731292240: nam='cell smart table scan' ela= 736 cellhash#=1170179701 p2=0 p3=0 obj#=75635 tim=1342003755974470
WAIT #46950731292240: nam='cell smart table scan' ela= 763 cellhash#=2167730007 p2=0 p3=0 obj#=75635 tim=1342003755975271
So we have seen may 'cell smart table scan' in out traces which confirms us that smart scan has happened.
I have cover the reason for seeing too much 'Disk file operations I/O' wait event
here.
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 12.91 13.13 130372 131275 42 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 12.91 13.13 130372 131275 42 0
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
---------- ---------- ---------- ---------------------------------------------------
0 0 0 SORT AGGREGATE (cr=0 pr=0 pw=0 time=0 us)
0 0 0 PX COORDINATOR (cr=0 pr=0 pw=0 time=0 us)
0 0 0 PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
1 1 1 SORT AGGREGATE (cr=131275 pr=130372 pw=0 time=13131299 us)
4040662 4040662 4040662 APPROXIMATE NDV AGGREGATE (cr=131275 pr=130372 pw=0 time=6992899 us cost=39917 size=5126019212 card=40362356)
4040662 4040662 4040662 PX BLOCK ITERATOR (cr=131275 pr=130372 pw=0 time=2517894 us cost=39917 size=5126019212 card=40362356)
4040662 4040662 4040662
TABLE ACCESS STORAGE FULL ACCT_STATEMENT (cr=131275 pr=130372 pw=0 time=2201673 us cost=39917 size=5126019212 card=40362356)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PX Deq: Execution Msg 78 0.37 0.38
Disk file operations I/O 677 0.00 0.00
latch free 6 0.00 0.00
cell smart table scan 348 0.00 0.15
********************************************************************************
OVERALL TOTALS FOR ALL NON-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
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
latch free 1 0.00 0.00
cell smart table scan 14 0.00 0.00
PX Deq: Slave Session Stats 1 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 12.91 13.13 130372 131275 42 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 12.91 13.13 130372 131275 42 0
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PX Deq: Execution Msg 78 0.37 0.38
Disk file operations I/O 677 0.00 0.00
latch free 6 0.00 0.00
cell smart table scan 348 0.00 0.15
1 user SQL statements in session.
0 internal SQL statements in session.
1 SQL statements in session.
********************************************************************************
Observation:
1) We saw '
TABLE ACCESS STORAGE FULL ACCT_STATEMENT' in explain plan for query.(which is one of the requirement
for smart scan)
2) Cell Smart Scan appeared for 348 times(recursive though). And also 14 times for non recursive query
3) Cell smart scan is the major contribute in wait evens for recursive and non recursive queries.
So trace of slave process also confirm us that smart scan has been used for this job
