While discussing with some tuning gurus, I was made aware about this feature. It is not so far from the adaptive cursor sharing perfectly described in Chris Antognini’s blog: http://antognini.ch/papers/BindVariablePeeking_20090718.pdf
This feature compares the real execution (number of returned/actual rows – “A-rows”) with some expectations (number of expected rows – “E-rows”) and chooses another plan for the next executions if the difference between the expectation and the actual result is too big. “Cardinality Feedback” is not well documented in the Oracle documentation.
The purpose of this post is not to dive into the technical details, but just to make you aware that this feature exists :-), it might explain some strange figures :-). The first execution time of some SQL statements might be poor/slow and afterwards they may be very fast. Not due to caching, not due to parsing, but due to a complete explain plan change – even if data and statistics are exactly the same.
Let’s have a look. First of all, we deactivated this functionality with the parameter below :
SQL> alter session set "_optimizer_use_feedback"=false;
Session altered.
Then, we start an SQL statement several times – the result was always “slow” (>20s) as you can see below:
SQL> set timing on SQL> select /* HERVE TEST ADVISOR */ all d.object_name, f.r_folder_path from dev_common_sp d, loby_az.DM_TABLEB_R f, loby_az.DM_BIG_TABLE_R s where ((d.r_lock_owner='loby eh 3') and (s.r_object_id=d.r_object_id) and (s.i_folder_id=f.r_object_id) and f.r_folder_path != ' ' and d.object_name != ' ' and (d.i_is_reference=0)) and (d.i_has_folder = 1 and d.i_is_deleted = 0) and ( ( d.owner_name in ('loby eh 3','loby clinical reader')) or (exists (select 1 from dm_acl_s ACL_S0, dm_acl_r ACL_R where ACL_S0.r_object_id = ACL_R.r_object_id and d.acl_domain = ACL_S0.owner_name and d.acl_name = ACL_S0.object_name and ((ACL_R.r_accessor_name in ('loby eh 3','dm_world') or (ACL_R.r_is_group = 1 and (ACL_R.r_accessor_name in ('loby eh 3','loby clinical reader','dm_world','loby crd luda','loby cp contributor','loby luda','ploby reader','loby users','loby reader','rr reader','loby old products reader','loby users','loby contributor','enterprise reader','ploby users','test dz','loby enterprise reader','enterprise loby_az reader')))) and ((ACL_R.r_permit_type = 0 or ACL_R.r_permit_type is null) and (((ACL_R.r_accessor_permit >= 2))))))));
OBJECT_NAME R_FOLDER_PATH ----------------------------------- ---------------------------------------- 1234test /loby Projects/X/WDBIOA/BLOG studies/CSP 00012abcd_2011-march-13 16:23:1510 /loby Projects/X/WDBIOA/BLOG studies/CSP Elapsed: 00:00:27.23 SQL> / OBJECT_NAME R_FOLDER_PATH -------------------------- ---------------------------------------- 1234test /loby Projects/X/WDBIOA/BLOG studies/CSP 00012abcd_2011-march-13 16:23:1510 /loby Projects/X/WDBIOA/BLOG studies/CSP Elapsed: 00:00:23.97
If Cardinality Feedback is deactivated, the statement is always slow and it uses an identical execution plan – which is bad. Then, we activate the functionality again (true = default as of 11.2):
SQL> alter session set "_optimizer_use_feedback"=true; Session altered.
In order to see how Oracle handles the Cardinality Feedback feature, we decided to collect the “plan statistics” to print out the estimations calculated by Oracle using the hint “/*+ gather_plan_statistics */”
SQL> select /*+ gather_plan_statistics */ all d.object_name, f.r_folder_path from dev_common_sp d, loby_az.DM_TABLEB_R f, loby_az.DM_BIG_TABLE_R s where ((d.r_lock_owner='loby eh 3') and (s.r_object_id=d.r_object_id) and (s.i_folder_id=f.r_object_id) and f.r_folder_path != ' ' and d.object_name != ' ' and (d.i_is_reference=0)) and (d.i_has_folder = 1 and d.i_is_deleted = 0) and ( ( d.owner_name in ('loby eh 3','loby clinical reader')) or (exists (select 1 from dm_acl_s ACL_S0, dm_acl_r ACL_R where ACL_S0.r_object_id = ACL_R.r_object_id and d.acl_domain = ACL_S0.owner_name and d.acl_name = ACL_S0.object_name and ((ACL_R.r_accessor_name in ('loby eh 3','dm_world') or (ACL_R.r_is_group = 1 and (ACL_R.r_accessor_name in ('loby eh 3','loby clinical reader','dm_world','loby crd luda','loby cp contributor','loby luda','ploby reader','loby users','loby reader','rr reader','loby old products reader','loby users','loby contributor','enterprise reader','ploby users','test dz','loby enterprise reader','enterprise loby_az reader')))) and ((ACL_R.r_permit_type = 0 or ACL_R.r_permit_type is null) and (((ACL_R.r_accessor_permit >= 2)))))))); OBJECT_NAME R_FOLDER_PATH -------------------------- ---------------------------------------- 1234test /loby Projects/X/WDBIOA/BLOG studies/CSP 00012abcd_2011-march-13 16:23:1510 /loby Projects/X/WDBIOA/BLOG studies/CSP Elapsed: 00:00:35.04
SQL> select * from table (dbms_xplan.display_cursor (format=>'ALLSTATS LAST')); ------------------------------------------------------------------------------------ | Id | Operation | Name | Starts | E-Rows | A-Rows | |----------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | 1 | |* 1 | FILTER | | 1 | | 1 | |* 2 | HASH JOIN | | 1 | 945K| 1 | |* 3 | TABLE ACCESS FULL | DM_TABLEB_R | 1 | 1379K| 1382K| |* 4 | HASH JOIN | | 1 | 626K| 1 | |* 5 | HASH JOIN | | 1 | 429K| 1 | |* 6 | TABLE ACCESS BY INDEX | DM_BIGTABLE | 1 | 429K| 1 | |* 7 | INDEX RANGE SCAN | D_1F0095AF8000002A | 1 | 3439K| 1 | | 8 | INDEX FAST FULL SCAN | D_1F0095AF80000500 | 1 | 4613K| 4633K| |* 9 | INDEX FAST FULL SCAN | D_1F0095AF80000010 | 1 | 6943K| 6961K| | 10 | NESTED LOOPS | | 0 | | 0 | | 11 | NESTED LOOPS | | 0 | 1 | 0 | |* 12 | INDEX RANGE SCAN | D_1F0095AF80002D01 | 0 | 1 | 0 | |* 13 | INDEX RANGE SCAN | D_1F0095AF80000102 | 0 | 12 | 0 | |* 14 | TABLE ACCESS BY INDEX | DM_ACL_R | 0 | 1 | 0 | ------------------------------------------------------------------------------------
As you can see, there is a huge difference between the E-rows and the A-rows in some lines of the plan. In particular this one:
|* 7 | INDEX RANGE SCAN | D_1F0095AF8000002A | 1 | 3439K| 1 |00:00:00.01 | 3 | SQL> / OBJECT_NAME R_FOLDER_PATH -------------------------- ---------------------------------------- 1234test /loby Projects/X/WDBIOA/BLOG studies/CSP 00012abcd_2011-march-13 16:23:1510 /loby Projects/X/WDBIOA/BLOG studies/CSP Elapsed: 00:00:23.97
The second execution of this statement was fast. Once again, not due to caching or faster parsing, but due to “Cardinality Feedback”. Oracle tried to take care of these large differences between E-Rows and A-Rows.
The second time, the explain plan is completely reconsidered:
OBJECT_NAME R_FOLDER_PATH -------------------------- ---------------------------------------- 1234test /loby Projects/X/WDBIOA/BLOG studies/CSP 00012abcd_2011-march-13 16:23:1510 /loby Projects/X/WDBIOA/BLOG studies/CSP Elapsed: 00:00:00.01
This second start was fast because of the recalculation of the plan. The estimated rows (E-rows) and the real output rows (A-rows) had too much differences in the first run, therefore Oracle recalculated the plan.
If you generate the SQL plan for this statement, you will see in the “Note” at the end if “Cardinality Feedback” was used :
SQL> select * from table (dbms_xplan.display_cursor (format=>'ALLSTATS LAST')); PLAN_TABLE_OUTPUT -------------------------------------------------------------------------------- SQL_ID 5w3td7kauxkkh, child number 1 ------------------------------------- select /*+ gather_plan_statistics */ all d.object_name, f.r_folder_path from dev_common_sp d, loby_az.DM_TABLEB_R f, loby_az.DM_BIG_TABLE_R s where ((d.r_lock_owner='loby eh 3') and (s.r_object_id=d.r_object_id) and (s.i_folder_id=f.r_object_id) and f.r_folder_path != ' ' and d.object_name != ' ' and (d.i_is_reference=0)) and (d.i_has_folder = 1 and d.i_is_deleted = 0) and ( ( d.owner_name in ('loby eh 3','credi clinical reader')) or (exists (select 1 from dm_acl_s ACL_S0, dm_acl_r ACL_R where ACL_S0.r_object_id = ACL_R.r_object_id and d.acl_domain = ACL_S0.owner_name and d.acl_name = ACL_S0.object_name and ((ACL_R.r_accessor_name in ('loby eh 3','dm_world') or (ACL_R.r_is_group = 1 and (ACL_R.r_accessor_name in ('loby eh 3','cr Plan hash value: 683492381 ------------------------------------------------------------------------------------------ | Id | Operation | Name | Starts | E-Rows | A-Rows | ------------------------------------------------------------------------------------------ | 0 | SELECT STATEMENT | | 1 | | 1 | |* 1 | FILTER | | 1 | | 1 | | 2 | NESTED LOOPS | | 1 | | 1 | | 3 | NESTED LOOPS | | 1 | 2 | 6 | | 4 | NESTED LOOPS | | 1 | 1 | 1 | | 5 | NESTED LOOPS | | 1 | 1 | 1 | |* 6 | TABLE ACCESS BY INDEX ROWID| DM_BIG_TABLE | 1 | 1 | 1 | |* 7 | INDEX RANGE SCAN | D_1F0095AF8000002A | 1 | 1 | 1 | |* 8 | INDEX UNIQUE SCAN | D_1F0095AF80000500 | 1 | 1 | 1 | |* 9 | TABLE ACCESS BY INDEX ROWID | DM_BIG_TABLE_R | 1 | 1 | 1 | |* 10 | INDEX RANGE SCAN | D_1F0095AF80000109 | 1 | 4 | 4 | |* 11 | INDEX RANGE SCAN | D_1F0095AF80000132 | 1 | 7 | 6 | |* 12 | TABLE ACCESS BY INDEX ROWID | DM_TABLEB_R | 6 | 2 | 1 | | 13 | NESTED LOOPS | | 0 | | 0 | | 14 | NESTED LOOPS | | 0 | 1 | 0 | |* 15 | INDEX RANGE SCAN | D_1F0095AF80002D01 | 0 | 1 | 0 | |* 16 | INDEX RANGE SCAN | D_1F0095AF80000102 | 0 | 12 | 0 | |* 17 | TABLE ACCESS BY INDEX ROWID | DM_ACL_R | 0 | 1 | 0 | ------------------------------------------------------------------------------------------
Here, the E-rows and A-rows are quite similar, Oracle will not re-evaluate the plan in the future.
Query Block Name / Object Alias (identified by operation id): ------------------------------------------------------------- 1 - SEL$F5BB74E1 PLAN_TABLE_OUTPUT ----------------------------- 6 - SEL$F5BB74E1 / YG_@SEL$2 7 - SEL$F5BB74E1 / YG_@SEL$2 8 - SEL$F5BB74E1 / OTC_@SEL$2 9 - SEL$F5BB74E1 / S@SEL$1 10 - SEL$F5BB74E1 / S@SEL$1 11 - SEL$F5BB74E1 / F@SEL$1 12 - SEL$F5BB74E1 / F@SEL$1 13 - SEL$3 15 - SEL$3 / ACL_S0@SEL$3 16 - SEL$3 / ACL_R@SEL$3 17 - SEL$3 / ACL_R@SEL$3 Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter((INTERNAL_FUNCTION("YG_"."OWNER_NAME") OR IS NOT NULL)) 6 - filter(("YG_"."I_HAS_FOLDER"=1 AND "YG_"."I_IS_DELETED"=0 AND "YG_"."I_IS_REFERENCE"=0 AND "YG_"."OBJECT_NAME"<>' ')) 7 - access("YG_"."R_LOCK_OWNER"='loby eh 3') 8 - access("YG_"."R_OBJECT_ID"="OTC_"."R_OBJECT_ID") 9 - filter("S"."I_FOLDER_ID" IS NOT NULL) 10 - access("S"."R_OBJECT_ID"="YG_"."R_OBJECT_ID") 11 - access("S"."I_FOLDER_ID"="F"."R_OBJECT_ID") 12 - filter("F"."R_FOLDER_PATH"<>' ') 15 - access("ACL_S0"."OWNER_NAME"=:B1 AND "ACL_S0"."OBJECT_NAME"=:B2) 16 - access("ACL_S0"."R_OBJECT_ID"="ACL_R"."R_OBJECT_ID") 17 - filter(((INTERNAL_FUNCTION("ACL_R"."R_ACCESSOR_NAME") OR ("ACL_R"."R_IS_GROUP"=1 AND INTERNAL_FUNCTION("ACL_R"."R_ACCESSOR_NAME"))) AND "ACL_R"."R_ACCESSOR_PERMIT">=2 AND ("ACL_R"."R_PERMIT_TYPE"=0 OR "ACL_R"."R_PERMIT_TYPE" IS NULL))) Column Projection Information (identified by operation id): ----------------------------------------------------------- 1 - "YG_"."OBJECT_NAME"[VARCHAR2,255], "F"."R_FOLDER_PATH"[VARCHAR2,740] 2 - "YG_"."OBJECT_NAME"[VARCHAR2,255], "YG_"."OWNER_NAME"[VARCHAR2,32],"YG_"."ACL_DOMAIN"[VARCHAR2,32], "YG_"."ACL_NAME"[VARCHAR2,32],"F"."R_FOLDER_PATH"[VARCHAR2,740] 3 - "YG_"."OBJECT_NAME"[VARCHAR2,255], "YG_"."OWNER_NAME"[VARCHAR2,32],"YG_"."ACL_DOMAIN"[VARCHAR2,32], "YG_"."ACL_NAME"[VARCHAR2,32], "F".ROWID[ROWID,10] 4 - "YG_"."OBJECT_NAME"[VARCHAR2,255], "YG_"."OWNER_NAME"[VARCHAR2,32],"YG_"."ACL_DOMAIN"[VARCHAR2,32], "YG_"."ACL_NAME"[VARCHAR2,32], "S"."I_FOLDER_ID"[VARCHAR2,16] 5 - "YG_"."R_OBJECT_ID"[VARCHAR2,16], "YG_"."OBJECT_NAME"[VARCHAR2,255],"YG_"."OWNER_NAME"[VARCHAR2,32], "YG_"."ACL_DOMAIN"[VARCHAR2,32], "YG_"."ACL_NAME"[VARCHAR2,32] 6 - "YG_"."R_OBJECT_ID"[VARCHAR2,16], "YG_"."OBJECT_NAME"[VARCHAR2,255],"YG_"."OWNER_NAME"[VARCHAR2,32], "YG_"."ACL_DOMAIN"[VARCHAR2,32], "YG_"."ACL_NAME"[VARCHAR2,32] 7 - "SYS_ALIAS_2".ROWID[ROWID,10] 9 - "S"."I_FOLDER_ID"[VARCHAR2,16] PLAN_TABLE_OUTPUT ------------------------------------------------------------------------------------------------------- 10 - "S".ROWID[ROWID,10] 11 - "F".ROWID[ROWID,10] 12 - "F"."R_FOLDER_PATH"[VARCHAR2,740] 14 - "ACL_R".ROWID[ROWID,10] 15 - "ACL_S0"."R_OBJECT_ID"[VARCHAR2,16] 16 - "ACL_R".ROWID[ROWID,10] Note ----- - cardinality feedback used for this statement <===== !!! Cardinality Feedback has been used !!! 105 rows selected.
However in this particular case, we have not solved anything, since the first execution was important.
I will tell you in the next posts how I have solved the problem and identified the real problem 🙂