Skip to Main Content
  • Questions
  • Query with same plan has double the execution time in 12.1.0.2 vs. 11.2.0.3

Breadcrumb

Question and Answer

Connor McDonald

Thanks for the question, Timothy.

Asked: September 02, 2016 - 6:46 pm UTC

Last updated: September 05, 2016 - 3:24 am UTC

Version: 12.1.0.2.160719

Viewed 1000+ times

You Asked

The following query has double the number of buffer gets and double the CPU execution in 12.1.0.2.160719 time but seems to have the same runtime plan (except for the TABLE ACCESS BY INDEX ROWID BATCHED method instead of TABLE ACCESS BY INDEX ROWID.


CABPSQA (11.2.0.3.15)

********************************************************************************

SQL ID: a0k83vvt022rk Plan Hash: 174751389

SELECT SUM(NVL(TLI.ITEM_BILL_QTY,0)) MIX_CUMULATIVE_QTY
FROM
TICKETS TICK, TICKETS MIXTICK, TICK_LINE_ITEMS TLI, PRODUCTS PROD WHERE
TICK.ORD_ID = MIXTICK.ORD_ID AND TICK.TICK_ID = :B1 AND MIXTICK.TICK_ID =
TLI.TICK_ID AND MIXTICK.TICK_ID IN (SELECT TICK2.TICK_ID FROM TICKETS TICK2
WHERE TICK2.ORD_ID = TICK.ORD_ID AND TICK2.TICK_SENT_DATE <=
TICK.TICK_SENT_DATE AND TICK2.TICK_STAT_CODE NOT IN ('NEW','VOID','PEND
VOID') AND TICK2.TICK_ID < TICK.TICK_ID) AND TLI.PROD_ORG_ID = PROD.ORG_ID
AND TLI.PROD_NUM = PROD.PROD_NUM AND PROD.MIX_IND = 'Y'


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1987 0.07 0.09 0 0 0 0
Fetch 1987 0.91 12.81 2622 55212 0 1987
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3975 0.99 12.90 2622 55212 0 1987

Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 146 (recursive depth: 1)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=9 pr=3 pw=0 time=12651 us)
0 0 0 NESTED LOOPS (cr=9 pr=3 pw=0 time=12643 us)
0 0 0 NESTED LOOPS (cr=9 pr=3 pw=0 time=12641 us cost=13 size=166 card=2)
0 0 0 NESTED LOOPS (cr=9 pr=3 pw=0 time=12640 us cost=11 size=136 card=2)
0 0 0 NESTED LOOPS (cr=9 pr=3 pw=0 time=12638 us cost=8 size=47 card=1)
1 1 1 TABLE ACCESS BY INDEX ROWID TICKETS (cr=4 pr=0 pw=0 time=25 us cost=3 size=19 card=1)
1 1 1 INDEX UNIQUE SCAN TICK_PK (cr=3 pr=0 pw=0 time=17 us cost=2 size=0 card=1)(object id 82739)
0 0 0 TABLE ACCESS BY INDEX ROWID TICKETS (cr=5 pr=3 pw=0 time=12612 us cost=5 size=28 card=1)
2 2 2 INDEX RANGE SCAN TICK_ORD_FK_I (cr=3 pr=3 pw=0 time=12575 us cost=2 size=0 card=3)(object id 82738)
0 0 0 TABLE ACCESS BY INDEX ROWID TICK_LINE_ITEMS (cr=0 pr=0 pw=0 time=0 us cost=3 size=42 card=2)
0 0 0 INDEX RANGE SCAN TICKLI_PRICE_APPROVE_IND_I (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=2)(object id 82755)
0 0 0 INDEX UNIQUE SCAN PROD_PK (cr=0 pr=0 pw=0 time=0 us cost=0 size=0 card=1)(object id 82431)
0 0 0 TABLE ACCESS BY INDEX ROWID PRODUCTS (cr=0 pr=0 pw=0 time=0 us cost=1 size=15 card=1)

********************************************************************************​

CAB12c (12.1.0.2.160719) with Recommended patches from Doc ID: 2034610.1

********************************************************************************

SQL ID: a0k83vvt022rk Plan Hash: 1316962549

SELECT SUM(NVL(TLI.ITEM_BILL_QTY,0)) MIX_CUMULATIVE_QTY
FROM
TICKETS TICK, TICKETS MIXTICK, TICK_LINE_ITEMS TLI, PRODUCTS PROD WHERE
TICK.ORD_ID = MIXTICK.ORD_ID AND TICK.TICK_ID = :B1 AND MIXTICK.TICK_ID =
TLI.TICK_ID AND MIXTICK.TICK_ID IN (SELECT TICK2.TICK_ID FROM TICKETS TICK2
WHERE TICK2.ORD_ID = TICK.ORD_ID AND TICK2.TICK_SENT_DATE <=
TICK.TICK_SENT_DATE AND TICK2.TICK_STAT_CODE NOT IN ('NEW','VOID','PEND
VOID') AND TICK2.TICK_ID < TICK.TICK_ID) AND TLI.PROD_ORG_ID = PROD.ORG_ID
AND TLI.PROD_NUM = PROD.PROD_NUM AND PROD.MIX_IND = 'Y'


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1989 0.07 0.08 0 0 0 0
Fetch 1989 1.31 24.60 2466 116228 0 1989
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3979 1.39 24.69 2466 116228 0 1989

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 146 (recursive depth: 1)
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 SORT AGGREGATE (cr=299 pr=27 pw=0 time=396312 us)
28 28 28 NESTED LOOPS (cr=299 pr=27 pw=0 time=533798 us cost=15 size=332 card=4)
96 96 96 NESTED LOOPS (cr=203 pr=27 pw=0 time=112678 us cost=15 size=332 card=4)
96 96 96 NESTED LOOPS (cr=105 pr=27 pw=0 time=110082 us cost=11 size=272 card=4)
28 28 28 NESTED LOOPS (cr=20 pr=3 pw=0 time=55031 us cost=8 size=47 card=1)
1 1 1 TABLE ACCESS BY INDEX ROWID TICKETS (cr=4 pr=0 pw=0 time=21 us cost=3 size=19 card=1)
1 1 1 INDEX UNIQUE SCAN TICK_PK (cr=3 pr=0 pw=0 time=15 us cost=2 size=0 card=1)(object id 82739)
28 28 28 TABLE ACCESS BY INDEX ROWID BATCHED TICKETS (cr=16 pr=3 pw=0 time=54983 us cost=5 size=28 card=1)
39 39 39 INDEX RANGE SCAN TICK_ORD_FK_I (cr=3 pr=2 pw=0 time=54343 us cost=2 size=0 card=3)(object id 82738)
96 96 96 TABLE ACCESS BY INDEX ROWID BATCHED TICK_LINE_ITEMS (cr=85 pr=24 pw=0 time=311209 us cost=3 size=63 card=3)
96 96 96 INDEX RANGE SCAN TICKLI_PRICE_APPROVE_IND_I (cr=58 pr=14 pw=0 time=219084 us cost=2 size=0 card=3)(object id 82755)
96 96 96 INDEX UNIQUE SCAN PROD_PK (cr=98 pr=0 pw=0 time=515 us cost=0 size=0 card=1)(object id 82431)
28 28 28 TABLE ACCESS BY INDEX ROWID PRODUCTS (cr=96 pr=0 pw=0 time=311 us cost=1 size=15 card=1)

********************************************************************************

The databases are close copies as shown by the number of rows fetched. The disk i/o count is similar. The number of blocks in query are double the ones in 11.2.0.3. Why should this occur when the execution plan is the same.

Thanks,
-- Tim

and Connor said...

The plans might look the same, but the data doesnt look the same to me.

In v11, you executed the query 1987 times, and the (sampled) row sources suggest we never found a "product" or "ticket price approve" (Its very hard to tell because you didnt format your output with code tags, so we've lost the indenting...sigh).

In v12, you executed the query 1989 times, and the row sources suggest we *did* find "product" or "ticket price approve" entries, which means more work was done.

Try narrowing it down to the a single execution of the query with the same data in each, and do something like:

spool blah
set serveroutput off
set linesize 180
set trimspool on
set pagesize 999
alter session set statistics_level = all;
{run the query}
select * from table(dbms_xplan.display_cursor(null,null,'allstats last 
outline'));
alter session set statistics_level = typical;
spool off


That gives you a better report of the queries in each db

Is this answer out of date? If it is, please let us know via a Comment

More to Explore

Performance

Get all the information about database performance in the Database Performance guide.