do_not_analyze_me

Playing recently a little with one of the databases having as a task improvement of its overall performance I had noticed a group of queries with hundreds of child cursors.

Let me show you one of them. Looks more or less like this – logic doesn’t matter at the moment.

select distinct I.CHICKENID,
                I.CHICKENDESC,
                I.TESTER,
                I.CHICKENTYPE
FROM
                CHICKENS I,
                TABITYPE_PR ACT,
                TAB2_SOMETHINGS PD,
                APP_CHICKENSTATUS RPS,
                CHICKENGROUP IG,
                CHICKEN_ORG TO
WHERE
(I.SINACTIVE is null or I.SINACTIVE = :"SYS_B_0")
AND I.SCHICKENTYPE = ACT.SCHICKENTYPE
AND ACT.SOMETHINGSID = RPS.SOMETHINGSID
AND ACT.ACTIVITYID = RPS.ACTIVITYID
AND ACT.SOMETHINGSID = PD.SSOMETHINGSID
AND TO.STEAMID = IG.STEAMID
AND IG.CHICKENID = I.CHICKENID
AND PD.TESTID = :TESTDEFID
AND RPS.STATUSID = :STATUSDEFID
AND TO.DRIVER = :DRIVER
AND TO.NAME = :NAME
ORDER BY I.TESTER DESC

Let’s find the query in v$sql

SQL> set linesize 120
SQL> set pagesize 3000

SQL> column is_obsolete format a10
SQL> column is_shareable format a10
SQL> column is_bind_sensitive format a10
SQL> column is_bind_aware format a10 
SQL> column is_reoptimizable format a10
SQL> column is_resolved_adaptive_plan format a10

SQL> SELECT sql_id, child_number, plan_hash_value,
		is_obsolete, 
		is_shareable,
		is_bind_sensitive,
		is_bind_aware,
		is_reoptimizable,
		is_resolved_adaptive_plan 
from v$sql where SQL_ID ='a3jdkjas7844zg'

SQL_ID          CHILD  PLAN_HASH_VALUE  IS_OBSOLET IS_SHAREAB IS_BIND_SE IS_BIND_A  IS_REOPTIM IS_RESOLVE
-------------	-----  ---------------	---------- ---------- ---------- ---------- ---------- ----------
a3jdkjas7844zg  0      3327959259       N          N          Y          N          Y          Y
a3jdkjas7844zg  1      3327959259       N          N          Y          N          Y          Y
a3jdkjas7844zg  2      1283519565       N          N          Y          N          Y          Y
a3jdkjas7844zg  3      498199707        N          N          Y          N          N          Y
a3jdkjas7844zg  4      829330110        N          N          Y          Y          Y          Y
a3jdkjas7844zg  5      1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  6      1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  7      1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  8      1898577247       N          N          Y          N          N          Y
a3jdkjas7844zg  9      829330110        N          N          Y          Y          Y          Y
a3jdkjas7844zg  10     1283519565       N          N          Y          Y          N          Y
a3jdkjas7844zg  11     1283519565       N          N          Y          Y          N          Y
a3jdkjas7844zg  12     1283519565       N          N          Y          Y          N          Y
a3jdkjas7844zg  13     1283519565       N          N          Y          Y          N          Y
a3jdkjas7844zg  14     1283519565       N          N          Y          Y          N          Y
a3jdkjas7844zg  15     1283519565       N          N          Y          Y          N          Y
a3jdkjas7844zg  16     1283519565       N          N          Y          Y          N          Y
a3jdkjas7844zg  17     3327959259       N          N          Y          Y          Y          Y
a3jdkjas7844zg  18     3327959259       N          N          Y          Y          Y          Y
a3jdkjas7844zg  19     829330110        N          N          Y          Y          N          Y

........ ~850 lines removed for better clarity.....

a3jdkjas7844zg  959    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  960    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  961    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  962    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  963    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  964    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  965    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  966    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  967    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  968    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  969    1283519565       N          N          Y          Y          Y          Y
a3jdkjas7844zg  970    1283519565       N          Y          Y          Y          Y          Y

A Little summary

ALL ROWS       IS_OBSOLETE  IS_SHAREAB	IS_BIND_SE  IS_BIND_AW	IS_REOPTIM  IS_RESOLVE
-------------  -----------  ----------  ----------  ----------  ----------  ----------
971            0            12          971         966	        946         971       
 
  • As you can see there are almost 1K children. Only 12 of them can be used as they have is_shareable set to Y. It may show up because it turned out that after building a new cursor for specific bind variables, the plan already exists, so the selectivity ranges of predicates of the existing cursor for that plan and the new cursor were combined under the new cursor. In that case the old cursor is marked as IS_SHAREABLE=N.
     
  • All of the cursors were resolved by the Adaptive Reoptimization – cardinality feedback has been used. Additionally each cursor child used Adaptive Plans to resolve its plan on runtime.
     
  • All childs are bind sensitive. What does that mean the cursor is bind sensitive? SQL Tuning guide explains it here https://docs.oracle.com/database/121/TGSQL/tgsql_cursor.htm#TGSQL94741
     

    Bind-Sensitive Cursors
    A bind-sensitive cursor is a cursor whose optimal plan may depend on the value of a bind variable.
    The database has examined the bind value when computing cardinality, and considers the query “sensitive” to plan changes based on different bind values.
    The database monitors the behavior of a bind-sensitive cursor that uses different bind values to determine whether a different plan is beneficial.

    The optimizer uses the following criteria to decide whether a cursor is bind-sensitive:

    • The optimizer has peeked at the bind values to generate cardinality estimates
    • The bind is used in an equality or a range predicate.
     

    For each execution of the query with a new bind value, the database records the execution statistics for the new value and compares them to the execution statistics for the previous value.If execution statistics vary greatly, then the database marks the cursor bind-aware.

     
  • Almost all of the child cursors are bind aware, so the oracle controlled or still controls (depending if cursor is still shareable) if bind variables fit in the selectivity ranges of the query predicates fixed to the existing cursor. You can take a look at those ranges in v$sql_cs_selectivity view.
     
  • What makes me suspicious is that all the child cursors used Adaptive Reoptimization. As the doc states:
     

    Reoptimization: Statistics Feedback
    A form of reoptimization known as statistics feedback (formerly known as cardinality feedback) automatically improves plans for repeated queries that have cardinality misestimates. The optimizer can estimate cardinalities incorrectly for many reasons, such as missing statistics, inaccurate statistics, or complex predicates.

    Accordingly to this theory my understanding is that in my case each time the cursor child is created by reoptimization oracle still believes it can be improved by reoptimization in the next run. Hm shouldn’t be the reoptimization eventually completed after few tries, not after hundreds!! My bet was that some stats may be missing and CBO got crazy :).

I have checked all the tables involved in the query and also the one related to the following predicates

AND TO.DRIVER = :DRIVER
AND TO.NAME = :NAME

the CHICKEN_ORG table has become my candidate to become a culprit. I checked DBA_TAB_COLS_STATISTICS and found out there is no histogram for any of the columns.

SQL> select table_name,column_name,histogram from dba_tab_col_statistics where table_name='CHICKEN_ORG';

TABLE_NAME    COLUMN_NAME                     HISTOGRAM
------------- ------------------------------  ---------
CHICKEN_ORG   SYS_STSY00FOL9RCZFW3#JF5FHV8U0  NONE
CHICKEN_ORG   DRIVER                          NONE
CHICKEN_ORG   NAME                            NONE
CHICKEN_ORG   STEAMID                         NONE      

Furthermore oracle decided to create a column group out of DRIVER and NAME columns as SYS_STSY00FOL9RCZFW3#JF5FHV8U0 virtual column, but there were no stats as well for it. I thought they should be gathered automatically during the dbms_stats autotask run last night. Not the slightest sign of them :)

Before I get into the details why there is so many cursors I need to check how the dbms_stats behaves for this table. I am gonna try to gather statistics for the table with METHOD_OPT set to FOR ALL COLUMNS SKEWONLY

SQL> execute dbms_stats.gather_table_stats(ownname=>'MYSCHEMA',tabname=>'CHICKEN_ORG',method_opt=>'FOR ALL COLUMNS SIZE SKEWONLY'); 

Let’s now check what’s up with the stats for CHICKEN_ORG

SQL> select table_name,column_name,histogram from dba_tab_col_statistics where table_name='CHICKEN_ORG';

TABLE_NAME    COLUMN_NAME                     HISTOGRAM
------------- ------------------------------  ---------
CHICKEN_ORG   SYS_STSY00FOL9RCZFW3#JF5FHV8U0  HYBRID
CHICKEN_ORG   DRIVER                          HYBRID
CHICKEN_ORG   NAME                            FREQUENCY
CHICKEN_ORG   STEAMID                         NONE      

Here they come. Nice, but why weren’t they gathered during the night statistics run. Don’t know yet. Let’s know find the query cursor and flush it from the shared pool. Of course you can flush whole the shared_pool but I avoid it if It is not required.

SQL> select ADDRESS, HASH_VALUE from V$SQLAREA where SQL_ID ='a3jdkjas7844zg';

ADDRESS          HASH_VALUE
---------------- ----------
0000000216968038  244278271

SQL> exec DBMS_SHARED_POOL.PURGE ('0000000216968038, 244278271', 'C');

-- Check if it is not there (if in use you can't remove it successfully)

SQL> select ADDRESS, HASH_VALUE from V$SQLAREA where SQL_ID ='a3jdkjas7844zg';

ADDRESS          HASH_VALUE
---------------- ----------
0000000216968038  244278271

SQL> exec DBMS_SHARED_POOL.PURGE ('0000000216968038, 244278271', 'C');

PL/SQL procedure successfully completed.

SQL> select ADDRESS, HASH_VALUE from V$SQLAREA where SQL_ID ='a3jdkjas7844zg';
no rows selected
     

So the second run of the flush did the job. Now I need to let my db work for a while to check how the cursors look like for the query with stats in place.

SQL> select sql_id,child_number,plan_hash_value,executions,is_obsolete,is_shareable,is_bind_sensitive,is_bind_aware,is_reoptimizable,is_resolved_adaptive_plan from v$sql where SQL_ID ='a3jdkjas7844zg';

SQL_ID        CHILD_NUMBER PLAN_HASH_VALUE EXECUTIONS IS_OBSOLET IS_SHAREAB IS_BIND_SE IS_BIND_AW IS_REOPTIM IS_RESOLVE
------------- ------------ --------------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
a3jdkjas7844zg           0       829330110         34 N          Y          Y          Y          N          Y
a3jdkjas7844zg           1       829330110          1 N          Y          Y          Y          N          Y
a3jdkjas7844zg           2       829330110         39 N          Y          Y          Y          N          Y
a3jdkjas7844zg           3       829330110         40 N          Y          Y          Y          N          Y
a3jdkjas7844zg           4      2981880008         47 N          Y          Y          Y          N          Y
a3jdkjas7844zg           5       829330110         25 N          Y          Y          Y          N          Y
a3jdkjas7844zg           6       829330110         17 N          Y          Y          Y          N          Y
a3jdkjas7844zg           7      3327959259          3 N          Y          Y          Y          N          Y

8 rows selected.   

Wow, how beautifully it looks now. No reoptimization. I still don’t understand why child 0 is still shareable and is marked as bind aware.

 

Accordingly to the documentation https://docs.oracle.com/database/121/TGSQL/tgsql_cursor.htm#TGSQL94743 child 0 should be marked as non-shareable and from the example in the doc it seems that only the new created child 1 should be marked as bind aware cursor. I have seen some examples with BIND_AWARE hint that could cause this, but here I don’t use it and Advanced Cursor Sharing should do its job. BIND_AWARE hint tells the optimizer that we believe the query is bind-sensitive, so it should use bind-aware cursor sharing from the first execution skipping the bind aware cursor discovery steps performed by ACS mechanism.

If you have any ideas please enlighten me!!

 

Job done, can go home!! :)

 

Next day comes, I want to check this query and… holy moley.. again hundreds of cursors, what happend?

Let’s check histograms again

SQL> select table_name,column_name,histogram from dba_tab_col_statistics where table_name='CHICKEN_ORG';

TABLE_NAME    COLUMN_NAME                     HISTOGRAM
------------- ------------------------------  ---------
CHICKEN_ORG   SYS_STSY00FOL9RCZFW3#JF5FHV8U0  NONE
CHICKEN_ORG   DRIVER                          NONE
CHICKEN_ORG   NAME                            NONE
CHICKEN_ORG   STEAMID                         NONE      
 

None again. Hm… Is there something wrong with the statistics configiruation for the Automatic Statistics Gathering job?

 
SQL> select dbms_stats.get_prefs('METHOD_OPT','MYSCHEMA','CHICKEN_ORG') from dual;

DBMS_STATS.GET_PREFS('METHOD_OPT','MYSCHEMA','CHICKEN_ORG')
------------------------------------------------------------------------------------------------------------------------
FOR ALL COLUMNS SIZE AUTO

SQL> select dbms_stats.get_prefs('METHOD_OPT','MYSCHEMA') from dual;

DBMS_STATS.GET_PREFS('METHOD_OPT','MYSCHEMA')
------------------------------------------------------------------------------------------------------------------------
FOR ALL COLUMNS SIZE AUTO

SQL> select dbms_stats.get_prefs('METHOD_OPT') from dual;

DBMS_STATS.GET_PREFS('METHOD_OPT')
------------------------------------------------------------------------------------------------------------------------
FOR ALL COLUMNS SIZE AUTO     
 

Accordingly to the definition of “FOR ALL COLUMNS SIZE AUTO” depicted here https://docs.oracle.com/database/121/ARPLS/d_stats.htm

– AUTO : Oracle determines the columns on which to collect histograms based on data distribution and the workload of the columns.

The column SYS_STSY00FOL9RCZFW3#JF5FHV8U0 has skewed data so a histogram should be build upon it.

Let’s try again to gather stats but using default values set in the db

 
SQL> execute dbms_stats.gather_table_stats(ownname=>'MYSCHEMA',tabname=>'CHICKEN_ORG'); 

SQL> select table_name,column_name,histogram from dba_tab_col_statistics where table_name='CHICKEN_ORG';

TABLE_NAME    COLUMN_NAME                     HISTOGRAM
------------- ------------------------------  ---------
CHICKEN_ORG   SYS_STSY00FOL9RCZFW3#JF5FHV8U0  HYBRID
CHICKEN_ORG   DRIVER                          HYBRID
CHICKEN_ORG   NAME                            FREQUENCY
CHICKEN_ORG   STEAMID                         NONE  
 

Histogram are back again. Hm.. Maybe.. maybe someone is using ANALYZE TABLE the legacy command to gather stats in the prior releases 8i,9i. Let’s try to do it

SQL> ANALYZE TABLE CHICKEN_ORG COMPUTE STATISTICS;

SQL> select table_name,column_name,histogram from dba_tab_col_statistics where table_name='CHICKEN_ORG';

TABLE_NAME    COLUMN_NAME                     HISTOGRAM
------------- ------------------------------  ---------
CHICKEN_ORG   SYS_STSY00FOL9RCZFW3#JF5FHV8U0  NONE
CHICKEN_ORG   DRIVER                          NONE
CHICKEN_ORG   NAME                            NONE
CHICKEN_ORG   STEAMID                         NONE    
 

No stats again. After some investigation and correlating of LAST_ANALYZED on CHICKEN_ORG with sessions active during that time it turned out that some old jobs ran in the night after the stats had been gathered by Autotask. That jobs were using using analyze table to compute stats after some table data manipulations. The culprit was found.

 


ANALYZE TABLE COMPUTE STATISTICS removes histograms!!!

 

Remeber: Do not use ANALYZE TABLE or ANALYZE INDEX to compute statistics, as this is deprecated command for many releases (11g and 12c 100%)

About the author

 
maciej tokar
Maciej Tokar

An Oracle technology geek and crazy long distance runner, DBA24 Owner
Senior Oracle DBA / Consultant / [OCP10g, OCP12c, OCE RAC 10g] / [experience: 9y+]
Currently working for Bluegarden (Oslo Norway) by Miratech Group
Past: Mastercard / Trevica by Britenet, Citi International PLC, PZU

 
View Maciej Tokar's profile on LinkedIn         logoDB4
LinkedIn Auto Publish Powered By : XYZScripts.com