Please help for Resolving Issue for Explain plan as query taking long time for execution [message #641011] |
Sun, 09 August 2015 04:47 |
|
msol25
Messages: 396 Registered: June 2011
|
Senior Member |
|
|
Dear Experts,
Please help for resolving issues with Query execution Plan:
select /*+ parallel(s 8) */row_id
from table s
where pr_id = '1-3BRSC92V'
select *
from table(dbms_xplan.display)
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | TQ |IN-OUT| PQ Distrib |
-----------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 2593 | 54453 | 29678 (11)| 00:00:02 | | | |
| 1 | PX COORDINATOR | | | | | | | | |
| 2 | PX SEND QC (RANDOM) | :TQ10000 | 2593 | 54453 | 29678 (11)| 00:00:02 | Q1,00 | P->S | QC (RAND) |
| 3 | PX BLOCK ITERATOR | | 2593 | 54453 | 29678 (11)| 00:00:02 | Q1,00 | PCWC | |
|* 4 | TABLE ACCESS STORAGE FULL| table | 2593 | 54453 | 29678 (11)| 00:00:02 | Q1,00 | PCWP | |
-----------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
4 - storage("PR_ID"='1-3BRSC92V')
filter("PR_ID"='1-3BRSC92V')
[Updated on: Sun, 09 August 2015 04:53] Report message to a moderator
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
Re: Please help for Resolving Issue for Explain plan as query taking long time for execution [message #641430 is a reply to message #641188] |
Fri, 14 August 2015 12:27 |
|
Kevin Meade
Messages: 2103 Registered: December 1999 Location: Connecticut USA
|
Senior Member |
|
|
So you want 2 rows out of 90 million? The best solution here should be obvious, create an index; UNLESS there is some overriding reason why you cannot. What is that reason?
Also, I would point out that you are on an EXADATA box yes? I see the STORAGE key word that tells me so. I am very worried, since EXADATA should blow through 90 million rows in about 25 seconds, not 25 minutes. More over, if you are getting advantage of SMARTSCAN, then this query should be answered in about .25 seconds on an EXADATA box the second and subsequence times you execute it.
I wager there is a major issue to contend with here:
1. hardware failure somewhere causing lots of retries
2. storage indexes are not being utilized by EXADATA
3. you are dropping back to traditional block level shipping instead of using SMARTSCAN
4. you are using compression and the size of your result is to large to ship via IDB so you are doing falling back to traditional block level shipping and uncompressing on the database server side
These are just guesses of course. You need to find out if SMARTSCAN is working or not. Here is an extract from tuning book, see if you can interpret it and use it to construct a sequence of queries to see what kind of lift you are actually getting from SMARTSCAN. Sorry about the formatting. It is the cut/paste, can't help it.
Proving SMARTSCAN Happened
Proving that SMARTSCAN features have been used when a query was executed takes about the same amount of work as any of the other tuning techniques we have used in this book.
First understand that SMARTSCAN is a runtime decision, not a plan generation time decision. The database optimizer has no clue what SMARTSCAN is and so a simple EXPLAIN PLAN followed by DBMS_XPLAN to dump it will not result in query plan output that can be used to determine if a SMARTSCAN will happen. A query must be executed in order to observe if SMARTSCAN does happen.
Second there is no breakdown provided that I know of which describes how much savings can be attributed to each SMARTSCAN feature used. In a testing environment, if one knows the hidden parameters needed, it is possible to selectively toggle various features and run tests in a specific order, to demonstrate the benefits a specific feature can provided. But in real use this does not happen. So what you are after is clear proof that one or more features of SMARTSCAN was used, and how much work was avoided in total.
There are several ways to check if a query has done a SMARTSCAN and how much SMARTSCAN helped. But by far the most interesting and effective method for me is the use of the /*+ MONITOR */ hint along with the database supplied DBMS_SQL_TUNE.REPORT_SQL_MONITOR packaged function. To use the MONITOR hint, three steps are followed.
Three steps toward using the MONITOR hint.
• The query being examined needs to be executed using the hint.
• The query is identified by finding it in the cursor cache.
• The report is run using a packaged procedure call.
Using this function is very much like using GATHER_PLAN_STATISTICS.
select /*+ monitor */ count(*)
from WORK_TABLE
where age between 20 and 30
/
select sql_id,inst_id,sql_text
from gv$sql_monitor
where username = user
and upper(sql_text) like '%WORK_TABLE%'
/
select dbms_sqltune.report_sql_monitor(sql_id=>'???'
,inst_id=>???
,report_level=>'ALL') text
from dual
/
Which will produce this kind of output.
00:53:51 SQL> select /*+ monitor */ count(*)
00:53:52 2 from WORK_TABLE
00:53:52 3 where age between 20 and 30
00:53:52 4 /
COUNT(*)
----------
1268360
1 row selected.
00:54:16 SQL> select sql_id,inst_id,sql_text
00:54:16 2 from gv$sql_monitor
00:54:16 3 where username = user
00:54:16 4 and upper(sql_text) like '%WORK_TABLE%'
00:54:16 5 /
SQL_ID INST_ID SQL_TEXT
------------- ---------- ---------------------------------
1jmxg1p4u3thy 2 select /*+ monitor */ count(*)
1 row selected.
00:54:16 SQL> select dbms_sqltune.report_sql_monitor(sql_id=>'1jmxg1p4u3thy'
00:54:16 2 ,inst_id=>2
00:54:16 3 ,report_level=>'ALL') text
00:54:16 4 from dual
00:54:16 5 /
TEXT
-------------------------------
SQL Monitoring Report
SQL Text
------------------------------
select /*+ monitor */ count(*)
from WORK_TABLE
where age between 20 and 30
Global Information
------------------------------
Status : DONE (ALL ROWS)
Instance ID : 2
Session : KM12345 (277:61979)
SQL ID : 1jmxg1p4u3thy
SQL Execution ID : 33554436
Execution Started : 07/30/2014 00:53:51
First Refresh Time : 07/30/2014 00:53:51
Last Refresh Time : 07/30/2014 00:54:15
Duration : 24s
Module/Action : SQL*Plus/-
Service : CLDW_MFG
Program : sqlplus.exe
Fetch Calls : 1
Global Stats
========================================================
| Elapsed | Queuing | Cpu | IO | Application |
| Time(s) | Time(s) | Time(s) | Waits(s) | Waits(s) |
========================================================
| 47 | 0.00 | 3.88 | 23 | 0.00 |
========================================================
===============================================
| Cluster | Other | Fetch | Buffer | Read |
| Waits(s) | Waits(s) | Calls | Gets | Reqs |
===============================================
| 3.60 | 17 | 1 | 504K | 4043 |
===============================================
===================
| Read | Cell |
| Bytes | Offload |
===================
| 4GB | 67.43% |
===================
Parallel Execution Details (DOP=2 , Servers Allocated=2)
Instances : 2
=========================================================
| Instance | Name | Type | Server# | Elapsed |
| | | | | Time(s) |
=========================================================
| 2 | PX Coordinator | QC | | 1.24 |
| 3 | p009 | Set 1 | 1 | 23 |
| | | | | |
| 2 | p017 | Set 1 | 2 | 23 |
=========================================================
Lots of stats skipped here, mostly wait stats.
========================================================
| Read | Cell | Wait Events |
| Bytes | Offload | (sample #) |
========================================================
| . | NaN% | PX Deq: Signal ACK EXT (1) |
| 1GB | NaN% | gc cr block congested (3) |
| | | cell multiblock physical read (16) |
| 3GB | 92.20% | cell smart table scan (6) |
========================================================
Instance Drill-Down
==========================================================
| Instance | Process Names | Elapsed | Queuing | Cpu |
| | | Time(s) | Time(s) | Time(s) |
==========================================================
| 2 | QC p017 | 24 | 0.00 | 0.51 |
| | | | | |
| 3 | p009 | 23 | | 3.37 |
| | | | | |
==========================================================
More stats skipped, mostly wait stats.
========================================================
| Read | Cell | Wait Events |
| Bytes | Offload | |
========================================================
| 3GB | 92.20% | PX Deq: Signal ACK EXT (1) |
| | | cell smart table scan (6) |
| 1GB | NaN% | gc cr block congested (3) |
| | | cell multiblock physical read (16) |
========================================================
SQL Plan Monitoring Details (Plan Hash Value=662663540)
=================================================================
| Id | Operation | Name |
| | | |
=================================================================
| 0 | SELECT STATEMENT | |
| 1 | SORT AGGREGATE | |
| 2 | PX COORDINATOR | |
| | | |
| 3 | PX SEND QC (RANDOM) | :TQ10000 |
| 4 | SORT AGGREGATE | |
| 5 | PX BLOCK ITERATOR | |
| 6 | TABLE ACCESS STORAGE FULL | WORK_TABLE |
| | | |
| | | |
| | | |
=================================================================
===========================================================
| Rows | Cost | Time | Start | Execs | Rows |
| (Estim) | | Active(s) | Active | | (Actual) |
===========================================================
| | | 1 | +24 | 1 | 1 |
| 1 | | 1 | +24 | 1 | 1 |
| | | 5 | +21 | 3 | 2 |
| | | | | | |
| 1 | | 1 | +23 | 2 | 2 |
| 1 | | 22 | +2 | 2 | 2 |
| 1M | 77839 | 22 | +2 | 2 | 1M |
| 1M | 77839 | 24 | +1 | 26 | 1M |
| | | | | | |
| | | | | | |
| | | | | | |
===========================================================
=====================================
| Read | Read | Cell | Activity |
| Reqs | Bytes | Offload | (%) |
=====================================
| | | | |
| | | | |
| | | | 4.35 |
| | | | |
| | | | |
| | | | |
| | | | |
| 4043 | 4GB | 67.43% | 95.65 |
| | | | |
| | | | |
| | | | |
=====================================
======================================
| Activity Detail |
| (# samples) |
======================================
| |
| |
| Cpu (1) |
| PX Deq: Signal ACK EXT (1) |
| |
| |
| |
| gc cr block congested (3) |
| Cpu (19) |
| cell multiblock physical read (16) |
| cell smart table scan (6) |
======================================
Note from GLOBAL STATS, the CELL OFFLOAD column shows the percentage of offloading that was done. Column READ BYTES shows the total bytes read regardless of which bytes came from SMARTSCAN and which bytes did not. ELAPSED TIME is wall clock for the query, CPU TIME (self-explanatory).
Note from PARALLEL EXECUTION DETAILS similar info.
Note from SQL PLAN MONITORING DETAILS, similar info broken down for each plan step in addition to the cardinality as has been seen when using other methods discussed in this book (FRP SPREADSHEET and GATHER_PLAN_STATISTICS). This report clearly indicates that SMARTSCAN was used because offloading was done. Further it states what percentage of data was removed.
SMARTSCAN operations removed 67% of the data. This query got about a 3 to 1 lift from SMARTSCAN. This is of course a gross calculation but it is easy for your Boss to understand.
As an interesting note, 67% though nice, does not sound to me like it would result in a 10X to 40X improvement in query runtime. Just saying.
As another interesting note, this query took 3.46 seconds to complete. Later on I reran the query while data was being updated in the table. As was described earlier under RECONSTRUCTING A CONSISTENT BLOCK, this means the need to rebuild prior images of data which causes EXADATA to abandon SMARTSCAN and revert back to the old style of working. When this was done, the query took 3 minutes to run. There were no SMARTSCAN savings at all during this execution. But the real truth is that consistent read block rebuilds added all the increased time, not the additional data being fetched because of a lack of SMARTSCAN. This should clue you to how important it is to avoid updating data when you want SMARTSCAN to speed things up for you.
Kevin
|
|
|