Cardinality Feedback
I ran into an interesting issue last week having to do with plan stability. The problem description went something like this:
“I have a statement that runs relatively quickly the first time I run it (around 12 seconds). Subsequent executions always run much slower, usually around 20 or 30 minutes. If I flush the shared pool and run it again elapsed time is back to 12 seconds or so.”
The query looked a little like this:
SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
d1.c10 AS c10,
d1.c11 AS c11
FROM ((SELECT DISTINCT d1.c1 AS c1,
Lpad(' ', 1) AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
d1.c10 AS c10,
d1.c11 AS c11
FROM (SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
d1.c10 AS c10,
d1.c11 AS c11
FROM (SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
d1.c10 AS c10,
d1.c11 AS c11,
Row_number() OVER (PARTITION BY d1.c2, d1.c3,
d1.c5,
d1.c6 ORDER
BY
d1.c2 ASC,
d1.c3 ASC, d1.c5 ASC, d1.c6 ASC) AS c12
FROM (SELECT d1.c1
AS c1
,
d1.c2
AS c2
,
d1.c3
AS c3,
d1.c4
AS c4
,
d1.c5
AS c5,
d1.c6
AS c6
,
d1.c7
AS c7,
d1.c8
AS c8
,
d1.c9
AS c9,
MIN(d1.c10) OVER (PARTITION BY d1.c5,
d1.c2,
d1.c6,
d1.c3) AS
c10,
MIN(d1.c11) OVER (PARTITION BY d1.c2,
d1.c5,
d1.c6,
d1.c3) AS
c11
FROM (SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
CASE
WHEN CASE d1.c12
WHEN 1 THEN d1.c9
ELSE NULL
END IS NOT NULL THEN
Rank() OVER ( PARTITION BY
d1.c5
ORDER BY
CASE
d1.c12 WHEN 1 THEN d1.c9 ELSE
NULL END DESC NULLS LAST )
END AS c10,
CASE
WHEN CASE d1.c13
WHEN 1 THEN d1.c9
ELSE NULL
END IS NOT NULL THEN
Rank() OVER ( ORDER BY CASE
d1.c13
WHEN 1
THEN d1.c9
ELSE NULL END DESC NULLS
LAST )
END AS c11
FROM (SELECT
0
AS
c1
,
d1.c7
AS c2,
d1.c8
AS
c3
,
d1.c9
AS c4,
d1.c10
AS
c5
,
d1.c11
AS c6,
CASE
WHEN d1.c6 = 0.0 THEN 0
ELSE Nvl(Nvl(d1.c5 + d1.c4 + d1.c3 +
d1.c2 +
d1.c1, 0)
/
Nullif(Nvl(d1.c6, 0), 0), 0)
* 100.0
END
AS
c7
,
d1.c6
AS c8,
d1.c5 + d1.c4 + d1.c3 + d1.c2 + d1.c1
AS
c9
,
Row_number() OVER (PARTITION BY d1.c10,
d1.c7,
d1.c11,
d1.c8
ORDER BY
d1.c10
DESC, d1.c7 DESC, d1.c11 DESC, d1.c8
DESC) AS
c12
,
Row_number() OVER
(PARTITION BY d1.c7, d1.c10, d1.c11,
d1.c8
ORDER BY
d1.c7 DESC
, d1.c10 DESC, d1.c11 DESC, d1.c8 DESC)
AS
c13
FROM (SELECT d2.c6 AS c1,
d2.c7 AS c2,
d2.c8 AS c3,
d2.c9 AS c4,
d2.c10 AS c5,
d2.c11 AS c6,
d1.c5 AS c7,
d1.c1 AS c8,
d1.c2 AS c9,
d1.c3 AS c10,
d1.c4 AS c11
FROM (SELECT DISTINCT
CONCAT(
CONCAT(t702396.child_nod_dtl,
' - '),
t702396.node_descr) AS
c1,
CASE
WHEN t702396.child_nod_dtl IN
(SELECT
member_char AS c1
FROM
wc_abunitbyreg_tree_closure
t702410
/* Dim_WC_ABUNITBYREG_TREE_CLOSURE_Receivables_Org */
WHERE
(
is_leaf
= 1 )
)
THEN 1
ELSE 0
END
AS c2,
t702396.child_nod_dtl
AS c3,
t702396.tree_node
AS c4,
t31796.org_name
AS c5
FROM wc_abunitbyreg_tree t702396
/* Dim_WC_ABUNITBYREG_TREE_Receivables_Org */
,
wc_abunitbyreg_tree_closure
t702410
/* Dim_WC_ABUNITBYREG_TREE_CLOSURE_Receivables_Org */
,
wc_ar_aging_accruals_f t699904
/* Dim_WC_AR_AGING_ACCRUALS_F */
,
w_int_org_d t435564
/* Dim_W_INT_ORG_D_Receivables_Org */
,
w_party_org_d t31796,
w_day_d t31328
/* Dim_W_DAY_D_Common */
,
wc_ar_aging_accruals_f t699868
/* Fact_WC_AR_AGING_ACCRUALS_F */
WHERE ( t699868.row_wid =
t699904.row_wid
AND t435564.row_wid =
t699868.bu_wid
AND t31796.row_wid =
t699868.cust_wid
AND t31328.row_wid =
t699868.snapshot_dt_wid
AND t699868.business_unit =
t702410.member_char
AND t31328.cal_month = 6
AND t31328.cal_year = 2011
AND t699904.class = 'Billed'
AND t702396.child_nod_dtl =
t702410.ancestor_char
AND CONCAT(
CONCAT(t435564.x_consol_cd,
'-'),
t435564.x_consol_cd_longnm) =
'A-Transocean Inc & Subs'
AND ( t31796.x_customer_type IN
( 'STD', 'UNS' ) )
AND t699904.due_terms <> 'Not Aged' ))
d1,
(SELECT SUM(CASE
WHEN t699868.due_terms =
'> 365 Days' THEN
t699868.total_usd_due
ELSE 0
END) AS c6,
SUM(CASE
WHEN t699868.due_terms =
'91-365 Days'
THEN
t699868.total_usd_due
ELSE 0
END) AS c7,
SUM(CASE
WHEN t699868.due_terms = '61-90'
THEN
t699868.total_usd_due
ELSE 0
END) AS c8,
SUM(CASE
WHEN t699868.due_terms = '31-60'
THEN
t699868.total_usd_due
ELSE 0
END) AS c9,
SUM(CASE
WHEN t699868.due_terms = '1-30'
THEN
t699868.total_usd_due
ELSE 0
END) AS c10,
SUM(t699868.total_usd_due) AS c11,
t31796.org_name AS c12,
t702396.child_nod_dtl AS c13
FROM wc_abunitbyreg_tree t702396
/* Dim_WC_ABUNITBYREG_TREE_Receivables_Org */
,
wc_abunitbyreg_tree_closure t702410
/* Dim_WC_ABUNITBYREG_TREE_CLOSURE_Receivables_Org */
,
wc_ar_aging_accruals_f t699904
/* Dim_WC_AR_AGING_ACCRUALS_F */
,
w_int_org_d t435564
/* Dim_W_INT_ORG_D_Receivables_Org */
,
w_party_org_d t31796,
w_day_d t31328
/* Dim_W_DAY_D_Common */
,
wc_ar_aging_accruals_f t699868
/* Fact_WC_AR_AGING_ACCRUALS_F */
WHERE ( t699868.row_wid = t699904.row_wid
AND t435564.row_wid = t699868.bu_wid
AND t31796.row_wid = t699868.cust_wid
AND t31328.row_wid =
t699868.snapshot_dt_wid
AND t699868.business_unit =
t702410.member_char
AND t31328.cal_month = 6
AND t31328.cal_year = 2011
AND t699904.class = 'Billed'
AND t702396.child_nod_dtl =
t702410.ancestor_char
AND CONCAT(CONCAT(t435564.x_consol_cd,
'-'),
t435564.x_consol_cd_longnm) =
'A-Transocean Inc & Subs'
AND ( t31796.x_customer_type IN
( 'STD', 'UNS' ) )
AND t699904.due_terms <> 'Not Aged' )
GROUP BY t31796.org_name,
t702396.child_nod_dtl
HAVING SUM(CASE
WHEN t699868.due_terms = '1-30'
THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms
=
'31-60' THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms =
'61-90'
THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms =
'91-365 Days'
THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms =
'> 365 Days' THEN t699868.total_usd_due
ELSE 0
END) <>
0) d2
WHERE ( d1.c3 = d2.c13
AND Sys_op_map_nonnull(d1.c5) = Sys_op_map_nonnull(d2.c12) ))
d1) d1) d1) d1
WHERE ( ( d1.c5 IN ( 'APPLIED DRILLING', 'CHALLENGER MINERAL', 'FEA',
'GGA',
'IME', 'MED', 'NAM', 'NRS',
'NRY', 'SAM', 'TI', 'WAS' ) )
AND d1.c10 <= 10 )) d1
WHERE ( d1.c12 = 1 )) d1
UNION ALL
SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
d1.c10 AS c10,
d1.c11 AS c11
FROM (SELECT d1.c1
AS c1
,
d1.c2
AS c2,
d1.c3
AS c3
,
d1.c4
AS c4,
d1.c5
AS c5
,
d1.c6
AS c6,
d1.c7
AS c7
,
d1.c8
AS c8,
d1.c9
AS c9
,
d1.c10
AS c10,
d1.c11
AS
c11,
Row_number() OVER (PARTITION BY d1.c2 ORDER BY d1.c2 ASC
) AS
c12
FROM (SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
d1.c10 AS c10,
MIN(d1.c11) OVER (PARTITION BY d1.c2) AS c11
FROM (SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
CASE
WHEN d1.c9 IS NOT NULL THEN
Rank() OVER ( PARTITION BY d1.c12
ORDER BY
d1.c9
DESC NULLS LAST )
END AS c10,
CASE
WHEN CASE d1.c13
WHEN 1 THEN d1.c9
ELSE NULL
END IS NOT NULL THEN
Rank() OVER ( ORDER BY CASE
d1.c13
WHEN 1
THEN d1.c9
ELSE NULL END DESC NULLS
LAST )
END AS c11
FROM (SELECT 1
AS c1
,
d1.c7
AS c2
,
Lpad(' ', 1)
AS c3,
CAST(NULL AS INTEGER)
AS c4
,
Lpad(' ', 1)
AS c5,
Lpad(' ', 1)
AS c6
,
CASE
WHEN d1.c6 = 0.0 THEN 0
ELSE Nvl(Nvl(d1.c5 + d1.c4 +
d1.c3 +
d1.c2 +
d1.c1, 0)
/
Nullif(Nvl(d1.c6, 0),
0), 0)
* 100.0
END
AS c7
,
d1.c6
AS c8,
d1.c5 + d1.c4 + d1.c3 + d1.c2 +
d1.c1
AS c9
,
d1.c9
AS c12,
Row_number() OVER (PARTITION BY
d1.c7
ORDER BY
d1.c7
DESC) AS
c13
FROM (SELECT SUM(d1.c1) OVER (
PARTITION BY
d1.c7) AS
c1,
SUM(d1.c2) OVER (
PARTITION BY
d1.c7) AS
c2,
SUM(d1.c3) OVER (
PARTITION BY
d1.c7) AS
c3,
SUM(d1.c4) OVER (
PARTITION BY
d1.c7) AS
c4,
SUM(d1.c8) OVER (
PARTITION BY
d1.c7) AS
c5,
SUM(d1.c6) OVER (
PARTITION BY
d1.c7) AS
c6,
d1.c7
AS
c7,
d1.c8
AS
c8,
d1.c9
AS
c9
FROM (SELECT SUM(CASE
WHEN t699868.due_terms =
'> 365 Days' THEN
t699868.total_usd_due
ELSE 0
END)
AS c1
,
SUM(CASE
WHEN t699868.due_terms =
'91-365 Days'
THEN
t699868.total_usd_due
ELSE 0
END) AS c2,
SUM(CASE
WHEN t699868.due_terms = '61-90'
THEN
t699868.total_usd_due
ELSE 0
END) AS c3,
SUM(CASE
WHEN t699868.due_terms = '31-60'
THEN
t699868.total_usd_due
ELSE 0
END) AS c4,
SUM(t699868.total_usd_due) AS c6,
t31796.org_name AS c7,
SUM(CASE
WHEN t699868.due_terms = '1-30'
THEN
t699868.total_usd_due
ELSE 0
END) AS c8,
t702396.child_nod_dtl AS c9
FROM wc_abunitbyreg_tree t702396
/* Dim_WC_ABUNITBYREG_TREE_Receivables_Org */
,
wc_abunitbyreg_tree_closure t702410
/* Dim_WC_ABUNITBYREG_TREE_CLOSURE_Receivables_Org */
,
wc_ar_aging_accruals_f t699904
/* Dim_WC_AR_AGING_ACCRUALS_F */
,
w_int_org_d t435564
/* Dim_W_INT_ORG_D_Receivables_Org */
,
w_party_org_d t31796,
w_day_d t31328
/* Dim_W_DAY_D_Common */
,
wc_ar_aging_accruals_f t699868
/* Fact_WC_AR_AGING_ACCRUALS_F */
WHERE ( t699868.row_wid = t699904.row_wid
AND t435564.row_wid = t699868.bu_wid
AND t31796.row_wid = t699868.cust_wid
AND t31328.row_wid =
t699868.snapshot_dt_wid
AND t699868.business_unit =
t702410.member_char
AND t31328.cal_month = 6
AND t31328.cal_year = 2011
AND t699904.class = 'Billed'
AND t702396.child_nod_dtl =
t702410.ancestor_char
AND t702396.child_nod_dtl = 'TI'
AND CONCAT(CONCAT(t435564.x_consol_cd,
'-'),
t435564.x_consol_cd_longnm) =
'A-Transocean Inc & Subs'
AND ( t31796.x_customer_type IN
( 'STD', 'UNS' ) )
AND t699904.due_terms <> 'Not Aged' )
GROUP BY t31796.org_name,
t702396.child_nod_dtl) d1) d1
WHERE ( d1.c5 + d1.c4 + d1.c3 + d1.c2 + d1.c1 <> 0 )) d1) d1)
d1
WHERE ( d1.c10 <= 10 )) d1
WHERE ( d1.c12 = 1 )
UNION ALL
SELECT d1.c1 AS c1,
d1.c2 AS c2,
d1.c3 AS c3,
d1.c4 AS c4,
d1.c5 AS c5,
d1.c6 AS c6,
d1.c7 AS c7,
d1.c8 AS c8,
d1.c9 AS c9,
d1.c10 AS c10,
d1.c11 AS c11
FROM (SELECT 2 AS c1,
d1.c7 AS c2,
Lpad(' ', 1) AS c3,
CAST(NULL AS INTEGER) AS c4,
d1.c8 AS c5,
Lpad(' ', 1) AS c6,
CASE
WHEN d1.c6 = 0.0 THEN 0
ELSE Nvl(Nvl(d1.c5 + d1.c4 + d1.c3 + d1.c2 + d1.c1, 0)
/
Nullif(Nvl(d1.c6, 0), 0), 0)
* 100.0
END AS c7,
d1.c6 AS c8,
d1.c5 + d1.c4 + d1.c3 + d1.c2 + d1.c1 AS c9,
CAST(NULL AS INTEGER) AS c10,
CASE
WHEN d1.c5 + d1.c4 + d1.c3 + d1.c2 + d1.c1 IS NOT NULL
THEN
Rank() OVER ( ORDER BY d1.c5 + d1.c4 + d1.c3 + d1.c2 +
d1.c1
DESC
NULLS LAST )
END AS c11,
CASE
WHEN d1.c5 + d1.c4 + d1.c3 + d1.c2 + d1.c1 IS NOT NULL
THEN
Rank() OVER ( PARTITION BY d1.c8 ORDER BY d1.c5 +
d1.c4 +
d1.c3
+
d1.c2 +
d1.c1
DESC NULLS LAST )
END AS c12
FROM (SELECT SUM(CASE
WHEN t699868.due_terms = '> 365 Days' THEN
t699868.total_usd_due
ELSE 0
END) AS c1,
SUM(CASE
WHEN t699868.due_terms = '91-365 Days'
THEN
t699868.total_usd_due
ELSE 0
END) AS c2,
SUM(CASE
WHEN t699868.due_terms = '61-90' THEN
t699868.total_usd_due
ELSE 0
END) AS c3,
SUM(CASE
WHEN t699868.due_terms = '31-60' THEN
t699868.total_usd_due
ELSE 0
END) AS c4,
SUM(CASE
WHEN t699868.due_terms = '1-30' THEN
t699868.total_usd_due
ELSE 0
END) AS c5,
SUM(t699868.total_usd_due) AS c6,
t31796.org_name AS c7,
t702396.child_nod_dtl AS c8
FROM wc_abunitbyreg_tree t702396
/* Dim_WC_ABUNITBYREG_TREE_Receivables_Org */
,
wc_abunitbyreg_tree_closure t702410
/* Dim_WC_ABUNITBYREG_TREE_CLOSURE_Receivables_Org */
,
wc_ar_aging_accruals_f t699904
/* Dim_WC_AR_AGING_ACCRUALS_F */
,
w_int_org_d t435564
/* Dim_W_INT_ORG_D_Receivables_Org */
,
w_party_org_d t31796,
w_day_d t31328
/* Dim_W_DAY_D_Common */
,
wc_ar_aging_accruals_f t699868
/* Fact_WC_AR_AGING_ACCRUALS_F */
WHERE ( t699868.row_wid = t699904.row_wid
AND t435564.row_wid = t699868.bu_wid
AND t31796.row_wid = t699868.cust_wid
AND t31328.row_wid = t699868.snapshot_dt_wid
AND t699868.business_unit =
t702410.member_char
AND t31328.cal_month = 6
AND t31328.cal_year = 2011
AND t699904.class = 'Billed'
AND t702396.child_nod_dtl =
t702410.ancestor_char
AND t702396.child_nod_dtl = 'TI'
AND CONCAT(CONCAT(t435564.x_consol_cd, '-'),
t435564.x_consol_cd_longnm) =
'A-Transocean Inc & Subs'
AND ( t31796.x_customer_type IN
( 'STD', 'UNS' ) )
AND t699904.due_terms <> 'Not Aged' )
GROUP BY t31796.org_name,
t702396.child_nod_dtl
HAVING SUM(CASE
WHEN t699868.due_terms = '1-30' THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms =
'31-60' THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms =
'61-90'
THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms =
'91-365 Days'
THEN
t699868.total_usd_due
ELSE 0
END) + SUM(CASE
WHEN t699868.due_terms =
'> 365 Days' THEN t699868.total_usd_due
ELSE 0
END) <>
0
) d1)
d1
WHERE ( d1.c12 <= 10 ))) d1
ORDER BY c1
Simple right?
As expected based on the problem description, there were many cursors with different plans and very different statistics in the shared pool. So I had them run a script showing some statistical info about the various plans:
SQL_ID PLAN_HASH_VALUE EXECS AVG_ETIME AVG_CPU_TIME AVG_LIO AVG_PIO
------------- --------------- -------------- ------------ ------------ ---------------- - ---------------
9tx5b0cctd8j5 1512746808 5 .618 .398 5,608.4 8.0
9tx5b0cctd8j5 310704641 1 1.496 .900 4,672.0 6.0
9tx5b0cctd8j5 2273374088 1 1.531 .950 5,810.0 8.0
9tx5b0cctd8j5 2878409905 1 1.432 1.080 5,810.0 8.0
9tx5b0cctd8j5 2225548639 1 14.193 10.310 1,057,712.0 8.0
9tx5b0cctd8j5 2174863591 1 13.623 10.660 1,049,157.0 8.0
9tx5b0cctd8j5 2214096856 1 13.573 10.720 1,057,955.0 8.0
9tx5b0cctd8j5 4111066445 1 13.187 11.090 1,049,157.0 10.0
9tx5b0cctd8j5 2307125907 1 13.411 11.200 1,057,779.0 8.0
9tx5b0cctd8j5 983902177 2 12.356 11.245 1,057,614.5 70.5
9tx5b0cctd8j5 2070474756 1 12.940 11.310 1,049,157.0 8.0
9tx5b0cctd8j5 986683435 1 12.158 11.590 1,026,638.0 8.0
9tx5b0cctd8j5 2004450975 1 12.463 11.700 1,049,167.0 8.0
9tx5b0cctd8j5 3593472063 1 12.336 11.710 1,026,638.0 30.0
9tx5b0cctd8j5 453801037 1 13.494 11.820 1,057,931.0 8.0
9tx5b0cctd8j5 3874155392 1 12.252 11.850 1,049,157.0 8.0
9tx5b0cctd8j5 1048579546 1 12.974 11.930 1,057,712.0 8.0
9tx5b0cctd8j5 936861260 1 72.135 66.720 11,711,783.0 2.0
9tx5b0cctd8j5 2279755221 2 128.250 121.020 21,775,758.0 .0
9tx5b0cctd8j5 1351237956 1 554.598 495.800 82,680,484.0 1.0
9tx5b0cctd8j5 116866680 2 539.060 521.715 83,920,850.5 .0
9tx5b0cctd8j5 3869018014 1 1,230.521 585.880 117,828,348.0 .0
9tx5b0cctd8j5 3732072456 2 662.755 644.470 104,823,026.5 2.0
9tx5b0cctd8j5 3282940025 1 825.540 811.690 132,362,095.0 .0
9tx5b0cctd8j5 2292909572 1 957.555 923.070 153,126,414.0 3.0
As you can imagine, the plans are pretty long as well. I'll spare you the detail of them but show you the notes section of the plans:
-- one of the 12 second ones
Note
-----
- star transformation used for this statement
-- multiple slow ones
Note
-----
- star transformation used for this statement
- cardinality feedback used for this statement
One of the statements showed about a 12 second average execution time without a note saying cardinality feedback had been used. The rest of the plans showed that cardinality feedback had been used. I suggested that maybe cardinality feedback was introducing the instability and disabling it might be a reasonable thing to try. They tried it using an alter session and the statement consistently ran in 11-12 seconds. I should note that you can also disable this feature for an individual statement by using an OPT_PARAM hint like so:
select /*+ opt_param('_optimizer_use_feedback' 'false') */ ...
By the way, as you may have already noticed, it's clear from the stats that the problem description did not exactly match the data. If you'll look back at the stats by plan hash value output you'll see that there are also several plans that produced results in the 1 second range (which they failed to mention). It appears that cardinality feedback actually enabled some pretty good plans that reduced the time by an order of magnitude from the original 12 second plan . But the client wasn't really looking for the absolute best performance, what they were looking for was stability. They were actually quite happy with 12 seconds, as long as it did that all the time. Had I had access to the system we might have a attempted to lock in the 1 second plan. But this was all done via email without actually logging into the system (which is a bit like performing surgery with a blind fold on - with someone else describing what you're cutting in to).
I'm used to seeing plan stability issues (often caused by bind variable peeking), but this is the first time I've seen this type of behavior due to the new 11g Cardinality Feedback feature. Generally speaking, this feature is a really good idea because it compares cardinality estimates that the optimizer calculates with actual row counts when a query runs. This is actually a very good technique for SQL tuning and Wolfgang Breitling has written an excellent paper on the subject. The basic idea is that if the estimated cardinality and the actual row counts are way off on any of the steps, the optimizer can automatically apply a fudge factor to correct the optimizer's calculation. The correction is exposed in a 10053 trace file by the application of an OPT_ESTIMATE hint (you know, the same one that is used by SQL Profiles created by the SQL Tuning Advisor). Unfortunately, these hints are not exposed in the OTHER_XML field of the V$SQL_PLAN table or any place else that I've uncovered thus far (although it must be stored in memory somewhere). So the only way I know to determine what modifications are being made is to Wolfgang the statement and look at the trace file. Here's a little excerpt from a 10053 trace file that has used this feature:
...
******************************************
----- Current SQL Statement for this session (sql_id=2ajw1uv0gpzwq) -----
select product_name
from oe.order_items o, oe.product_information p
where o.unit_price = 15 and quantity > 1
and p.product_id = o.product_id
*******************************************
...
Final query after transformations:******* UNPARSED QUERY IS *******
SELECT /*+ OPT_ESTIMATE (TABLE "P" MIN=1.000000 ) OPT_ESTIMATE (INDEX_SCAN "P" "PRODUCT_INFORMATION_PK" MIN=1.000000 ) OPT_ESTIMATE (INDEX_FILTER "P" "PRODUCT_INFORMATION_PK" MIN=1.000000 ) OPT_ESTIMATE (TABLE "O" ROWS=13.000000 ) */ "P"."PRODUCT_NAME" "PRODUCT_NAME" FROM "OE"."ORDER_ITEMS" "O","OE"."PRODUCT_INFORMATION" "P" WHERE "O"."UNIT_PRICE"=15 AND "O"."QUANTITY">1 AND "P"."PRODUCT_ID"="O"."PRODUCT_ID"
kkoqbc: optimizing query block SEL$1 (#0)
...
Content of other_xml column
===========================
cardinality_feedback: yes
db_version : 11.2.0.2
parse_schema : SYS
plan_hash : 1553478007
plan_hash_2 : 2615131494
Outline Data:
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('11.2.0.2')
DB_VERSION('11.2.0.2')
OPT_PARAM('optimizer_dynamic_sampling' 0)
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
FULL(@"SEL$1" "O"@"SEL$1")
FULL(@"SEL$1" "P"@"SEL$1")
LEADING(@"SEL$1" "O"@"SEL$1" "P"@"SEL$1")
USE_HASH(@"SEL$1" "P"@"SEL$1")
END_OUTLINE_DATA
*/
...
You can see all the OPT_ESTIMATE hints that have been added to the statement. V$SQL_SHARED_CURSOR does have a flag to indicate whether a cursor has been marked to use this feature. So you can do a little investigation on your own system to see how often this feature is kicking in.
SYS@SANDBOX1> @find_card_feedback_cursors.sql
SYS@SANDBOX1> col sql_text for a80 word_wrap
SYS@SANDBOX1> select a.sql_id, child_number child_no, b.sql_text from v$sql_shared_cursor a, v$sqlstats b
2 where a.sql_id = b.sql_id
3 and USE_FEEDBACK_STATS = 'Y'
4 and a.sql_id like nvl('&sql_id',a.sql_id)
5 and upper(sql_text) like upper(nvl('&sql_text',sql_text))
6 and child_number > 0
7 order by 1, 2
8 /
Enter value for sql_id:
Enter value for sql_text: %oe.%
SQL_ID CHILD_NO SQL_TEXT
------------- ---------- --------------------------------------------------------------------------------
0cm4r08vj075r 2 select /*+ monitor */ product_name from oe.order_items o, oe.product_information
p where o.unit_price = 15 and quantity > 1 and p.product_id = o.product_id
0cm4r08vj075r 3 select /*+ monitor */ product_name from oe.order_items o, oe.product_information
p where o.unit_price = 15 and quantity > 1 and p.product_id = o.product_id
2ajw1uv0gpzwq 1 select product_name from oe.order_items o, oe.product_information p where
o.unit_price = 15 and quantity > 1 and p.product_id = o.product_id
This feature is similar to another 11g feature call Adaptive Cursor Sharing which also attempts to automatically recognize performance problems and create new cursors to overcome the issues. Both features share a couple of traits.
- The statement must be run at least once without benefit of the feature in order to discover that there is a potential problem.
- The data collected about the statement is not persisted. So any event that causes a statement to be flushed from the shared pool will cause the "learning process" to be repeated.
There is not much available on the web about this feature yet. Here are a few posts that provide some insight.
By Tom Kite
By Dion Cho
By The Optimizer Development Group
One of the comments that Tom makes in his discussion is that SQL Plan Management (Baselines) could be used to curb potential instability issues caused by this new feature. I thought this was an interesting idea so I thought it might be worthwhile to look into the interaction between the Cardinality Feedback feature and Baselines. Note, the client I worked with on the aforementioned issue had actually tried using baselines to keep the plans from changing. But without having access to the system it was just too difficult to try to understand what had or hadn't been done with the baselines. So I did a little investigation on our Exadata lab environment. After finding a statement that causes Cardinality Feedback to kick in, I flushed the shared pool and ran it a few times. I then create a baseline to force it to go back to the original plan.
SYS@SANDBOX1> !cat b.sql
select /*+ monitor */ product_name
from oe.order_items o, oe.product_information p
where o.unit_price = 15 and quantity > 1
and p.product_id = o.product_id;
SYS@SANDBOX1> set termout off
SYS@SANDBOX1> @b
. . .
SYS@SANDBOX1> @b
SYS@SANDBOX1> set termout on
SYS@SANDBOX1>
SYS@SANDBOX1> -- let's check the shared pool now
SYS@SANDBOX1> @fsx
Enter value for sql_text:
Enter value for sql_id: 0cm4r08vj075r
SQL_ID CHILD PLAN_HASH EXECS AVG_ETIME AVG_PX OFFLOAD IO_SAVED_% SQL_TEXT
------------- ------ ---------- ------ ---------- ------ ------- ---------- ----------------------------------------------------------------------
0cm4r08vj075r 0 1255158658 1 .04 0 No .00 select /*+ monitor */ product_name from oe.order_items o, oe.product_i
0cm4r08vj075r 1 1553478007 4 .00 0 No .00 select /*+ monitor */ product_name from oe.order_items o, oe.product_i
2 rows selected.
SYS@SANDBOX1>
SYS@SANDBOX1> -- yes we have two cursors with different plans
SYS@SANDBOX1> -- let's see what the plans look like
SYS@SANDBOX1> @dplan
Enter value for sql_id: 0cm4r08vj075r
Enter value for child_no:
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 0cm4r08vj075r, child number 0
-------------------------------------
select /*+ monitor */ product_name from oe.order_items o,
oe.product_information p where o.unit_price = 15 and quantity > 1 and
p.product_id = o.product_id
Plan hash value: 1255158658
-------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 7 (100)| |
| 1 | NESTED LOOPS | | | | | |
| 2 | NESTED LOOPS | | 4 | 128 | 7 (0)| 00:00:01 |
|* 3 | TABLE ACCESS STORAGE FULL | ORDER_ITEMS | 4 | 48 | 3 (0)| 00:00:01 |
|* 4 | INDEX UNIQUE SCAN | PRODUCT_INFORMATION_PK | 1 | | 0 (0)| |
| 5 | TABLE ACCESS BY INDEX ROWID| PRODUCT_INFORMATION | 1 | 20 | 1 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - storage(("O"."UNIT_PRICE"=15 AND "QUANTITY">1))
filter(("O"."UNIT_PRICE"=15 AND "QUANTITY">1))
4 - access("P"."PRODUCT_ID"="O"."PRODUCT_ID")
SQL_ID 0cm4r08vj075r, child number 1
-------------------------------------
select /*+ monitor */ product_name from oe.order_items o,
oe.product_information p where o.unit_price = 15 and quantity > 1 and
p.product_id = o.product_id
Plan hash value: 1553478007
--------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 9 (100)| |
|* 1 | HASH JOIN | | 13 | 416 | 9 (12)| 00:00:01 |
|* 2 | TABLE ACCESS STORAGE FULL| ORDER_ITEMS | 13 | 156 | 3 (0)| 00:00:01 |
| 3 | TABLE ACCESS STORAGE FULL| PRODUCT_INFORMATION | 288 | 5760 | 5 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - access("P"."PRODUCT_ID"="O"."PRODUCT_ID")
2 - storage(("O"."UNIT_PRICE"=15 AND "QUANTITY">1))
filter(("O"."UNIT_PRICE"=15 AND "QUANTITY">1))
Note
-----
- cardinality feedback used for this statement
54 rows selected.
SYS@SANDBOX1> --
SYS@SANDBOX1> -- so the second cursor (1) has a new plan (1553478007) because of cardinality feedback
SYS@SANDBOX1> -- let's create a baseline to force it to stick with the original plan (1255158658)
SYS@SANDBOX1> @create_baseline
Enter value for sql_id: 0cm4r08vj075r
Enter value for plan_hash_value: 1255158658
Enter value for fixed (NO):
Enter value for enabled (YES):
Enter value for plan_name (SQLID_sqlid_planhashvalue):
sql_id: 0cm4r08vj075r
plan_hash_value: 1255158658
fixed: NO
enabled: YES
plan_name: SQLID_0cm4r08vj075r_1255158658
sql_handle: SQL_7912d4b3adf9c3b4
Baseline SQLID_0cm4r08vj075r_1255158658 created.
PL/SQL procedure successfully completed.
SYS@SANDBOX1> -- now let's run the statement a few more times
SYS@SANDBOX1> set termout off
SYS@SANDBOX1> @b
SYS@SANDBOX1> @b
. . .
SYS@SANDBOX1> @b
SYS@SANDBOX1> @b
SYS@SANDBOX1> set termout on
SYS@SANDBOX1> -- and check the children and plans
SYS@SANDBOX1> @fsx
Enter value for sql_text:
Enter value for sql_id: 0cm4r08vj075r
SQL_ID CHILD PLAN_HASH EXECS AVG_ETIME AVG_PX OFFLOAD IO_SAVED_% SQL_TEXT
------------- ------ ---------- ------ ---------- ------ ------- ---------- ----------------------------------------------------------------------
0cm4r08vj075r 0 1255158658 1 .00 0 No .00 select /*+ monitor */ product_name from oe.order_items o, oe.product_i
0cm4r08vj075r 1 1553478007 1 .00 0 No .00 select /*+ monitor */ product_name from oe.order_items o, oe.product_i
0cm4r08vj075r 2 1255158658 1 .00 0 No .00 select /*+ monitor */ product_name from oe.order_items o, oe.product_i
0cm4r08vj075r 3 1255158658 1 .00 0 No .00 select /*+ monitor */ product_name from oe.order_items o, oe.product_i
0cm4r08vj075r 5 1255158658 4 .00 0 No .00 select /*+ monitor */ product_name from oe.order_items o, oe.product_i
Interesting that it created a bunch of new cursors - 2,3 (presumably 4 that got flushed for some reason) and 5. Looks like it finally settled down with 5, since child 5 has been executed 4 times. And look what the plan looks like for the one it settled down on:
SYS@SANDBOX1> @dplan
Enter value for sql_id: 0cm4r08vj075r
Enter value for child_no: 5
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID 0cm4r08vj075r, child number 5
-------------------------------------
select /*+ monitor */ product_name from oe.order_items o,
oe.product_information p where o.unit_price = 15 and quantity > 1 and
p.product_id = o.product_id
Plan hash value: 1255158658
-------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 16 (100)| |
| 1 | NESTED LOOPS | | | | | |
| 2 | NESTED LOOPS | | 13 | 416 | 16 (0)| 00:00:01 |
|* 3 | TABLE ACCESS STORAGE FULL | ORDER_ITEMS | 13 | 156 | 3 (0)| 00:00:01 |
|* 4 | INDEX UNIQUE SCAN | PRODUCT_INFORMATION_PK | 1 | | 0 (0)| |
| 5 | TABLE ACCESS BY INDEX ROWID| PRODUCT_INFORMATION | 1 | 20 | 1 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - storage(("O"."UNIT_PRICE"=15 AND "QUANTITY">1))
filter(("O"."UNIT_PRICE"=15 AND "QUANTITY">1))
4 - access("P"."PRODUCT_ID"="O"."PRODUCT_ID")
Note
-----
- SQL plan baseline SQLID_0CM4R08VJ075R_1255158658 used for this statement
- cardinality feedback used for this statement
31 rows selected.
Hmmm ... Oracle says it used both the baseline and cardinality feedback, but the plan stayed the same as without the cardinality feedback. It seems a little weird that cardinality feedback would be applied to statement that already has a baseline on it. But it makes sense that the plan would stay consistent because the hints would generally limit the CBO's choices down to the point where adjustments to cardinality calculations wouldn't matter. At any rate, it's an interesting bit of trivia.
Note that I have used several scripts in this post:
- create_baseline.sql - create a Baseline on a statement in the shared pool
- dplan.sql - produces XPLAN output for a statement in the shared pool
- find_card_feedback_cursors.sql - looks for cursors using cardinality feedback
- fsx.sql - shows SQL statements in the shared pool along with indication if Exadata Smart Scans were used
Cardinality Feedback Wrap Up
In general I think Cardinality Feedback is a great new feature, but in this particular case it did introduce some instability. This may be the result of some unintended behavior but we did not open an SR to track that down since disabling the feature provided an adequate solution in this case. I would still like to find where it stores those fudge factors used by the OPT_ESTIMATE hints. I was hoping I could find it in one of the SQL Profile objects like sqlobj$data, but haven't had any luck with that line of investigation so far. So if you have any ideas please let me know.
Great analysis.
Some time ago, while upgrading one of my 10.2.0.3 databases to 11.2.0.2, I have experienced very similar (if not identical) plan instability.
In 11.2.0.2, the SQL in question has returned its rows in less than one second in first run and it took more than 20 seconds for every consecutive execution. No need to mention that same SQL has been running stable in 10g for years.
Trace file clearly showed that cardinality feedback was used after first run. Disabling that feature put response time back to normal for every run.
Since we were in initial testing phase, I did not want to start optimizing new db by using hints (to disable ‘cardinality feedback’ on SQL level).
I did not want to disable that feature on database level either.
The solution came as a side-effect from some other SQLs optimization work … it turned out that some other SQLs required a ‘optimizer_index_cost_adj’ parameter decreased from its default value (in order to favorize index usage in some situations). This change also helped our ‘original’ SQL running with stable and optimal plan and sub-second response time for every execution.
Like you mentioned in your post, most likely, cardinality did not play any role after CBO limited number of possible plans by using new value for ‘optimizer_index_cost_adj’.
Cheers,
Milan N.
Good Sum up Kerry,
I had similar issues with version 11.2.0.1 for which there are already 4-5 bugs reported but never had the issue for 11.2.0.2
There is also another improvement for cardinality feedback tracking on 11.2.0.2 is that additional USE_FEEDBACK_STATS column in v$sql_shared_cursor.
I also find it handy to check the cardinality feedback plans from time to time to see if they are helping. It is really annoying to see performance decrease from something which supposed to improve the performance
Note: find_card_feedback_cursors.sql is not available to the public. looks like link is broken
=
Hi Coskan,
Thanks for pointing out the broken link (I forgot to stick that file on the blog). It’s fixed now. The script actually queries v$sql_shared_cursor using the USE_FEEDBACK_STATS column as you had previously mentioned.
Hi Kerry,
I was writing a comment but it was getting way too long so I’m turning it into a blog post – but there are so many little things that go off in a tangent.
So, in the meantime…
I believe those fudge factors are independent of the baseline – that is the cardinality feedback loop comes only from previous executions.
So, for example, if you create the baseline then flush the shared pool you should get the baselined plan but with different estimates because there’s no feedback loop.
Having said that, I’ve got a demo that shows the above but I can’t then seem to get the statement with the baseline to then use cardinality feedback as well.
Cardinality feedback is obviously a new feature and no doubt subtley tweaked fairly often, etc.
For example, in Tom’s demo which you linked to above, he uses bind variables to populate a collection. According to my experiments, cardinality feedback won’t kick in here because the collection is a bind. This is backed up by what the optimizer group say in their article which you linked to.
Not sure if this all makes sense. Hopefully the blog article will give some context to my witterings.
Cheers,
Dominic
And I suppose we can’t really be sure that those opt_estimate hints actually exist anywhere.
As Tanel said here:
http://blog.tanelpoder.com/2011/06/28/knowing-what-you-want-to-achieve-before-thinking-of-how-to-achieve-it-a-query-optimization-example-2/
“Note that the “unparsed” query text in CBO tracefile is FYI only. It is not the real query text actually executed …. It’s just FYI, for debugging.”
Hi Dominic,
Yeah – I think your right that the feature may be still getting tweaked fairly often. It’s a very cool feature and I’ve been wanting to spend some time looking at it for a while but haven’t had a lot of free time. I expect we’ll open an SR as I do think that this feature is very useful most of the time and I am not really satisfied with just turning it off as a long term solution, even for a few statements.
On the 10053 Final Version comment: I agree it’s not actual SQL and the hints themselves may not be stored anywhere.
Please ping me or add a note here when you get your post done.
Kerry
There is a lot to digest here. Quick question – the “scripts” that analyze a bunch of plans based on costs, that looks a lot like SQLT PROFILE. Coincidence? =)
Thanks for putting this out there…. now I’ll keep reading.
[…] True to form, Kerry Osborne has another excellent post, this time on Cardinality Feedback. […]
Hi Charles,
No, that script is just an aggregate of stats that I wrote a long time ago (before I even knew SQLT existed). But it’s not too surprising that there would be something similar in SQLT since it’s a good idea to look at what plans have been used and how the have behaved when you’re dealing with seemingly erratic behavior. Another one I use pretty often produces a date ordered list of plan usage out of AWR so I can see how a statements plans have changed in a time based context. Pretty easy to see plan stability issues that way if they are flipping back and forth between a couple of plans on a regular basis. I wrote a blog post about those two scripts a while back.
Plan Stability
I really need to look into SQLT as I have really only used it a little (specifically with regard to manipulating SQL Profiles).
Kerry
Cool writeup and analysis as always.
Side question – any chance you have the the DML for the schema definitions and/or the table stats.
Curious to play with the statement.
– Kyle Hailey
Hi Kyle,
I do have the stats on the tables (there are quite a few) but I don’t have dml (although I might could get that). I’ll see what I can come up with.
Kerry
Thanks for this helpful post. I recently ran into this issue at my job where I was using false statistics on a staging table to get the plan I wanted. The optimizer used the plan i wanted at first and then switched to a suboptimal plan based on cardinality feedback. I implemented a fixed sql plan baseline and the optimzer still choose to use the plan based on cardinality feedback over the fixed sql plan baseline. I think the optimizer should use the fixed baseline at all times so I have submiteed a SR to Oracle.
Hi Robert,
I have not had time to open an SR on our issue but I would be interested to hear what Support says about it. I agree that a fixed Baseline should override (i.e. turn off) cardinality feedback.
Kerry
Very Good
[…] feedback for volatile tables with locked statistics is can be one, although not the only, reason for plan instability. Oracle should modify MOS Best Practices for Automatic Statistics […]
[…] Cardinality Feedback […]
[…] http://kerryosborne.oracle-guy.com/2011/07/cardinality-feedback/ […]
[…] CBO to generate the best execution plan: ACS or Cardinality Feedback (even thought that Dominic and Kerry Osborne have already investigated the Interaction of SPM and Cardinality Feedback where they both […]
Thanks for the detailed post Kerry, just hit this problem and was wringing my hands until finding your post!
[…] See a good explanation on Kerry Osborne’s blog: http://kerryosborne.oracle-guy.com/2011/07/cardinality-feedback/ […]
This has actually been causing a significant number of problems in our Prod environment (11g 11.2.0.3.0 64-bit). I have a number of complex examples and sadly one trivially simple one (get the most recent record where the amounts differ):
select * from
(select * from b_posting where amount <> orig_amount order by id desc)
where rownum <= 1;
b_posting has nearly 800 million records but the query runs in < 1 sec the first time. I don't know how long subsequent runs take. I usually kill it after a few minutes. Once I killed it after 3 hours and 58 minutes so I could go home.
Even with the worst imaginable plan (maybe full table scan in id asc order?) it shouldn't take 4+ hours.
Today's example was much more complex but I just killed an insert statement after 30 minutes. After using the /*+ opt_param(‘_optimizer_use_feedback’ ‘false’) */ hint the same statement ran in 217 ms. Thanks so much! Even the "Ask Tom" guys didn't share that one with me when I asked about the problem.
That said, this problem is utterly ridiculous and completely inexcusable IMO. Feels like a half-baked it-usually-works-but-it-also-may-really-screw-things-up feature that wasn't thoroughly tested. That's even inexcusable from a small mom-and-pop development shop, let alone from Oracle.