Excessive query parsing time with extended statistics and long in-lists

Recently, I spotted several sessions in a long “cursor: pin S wait on X” wait. The waiters and the mutex holder ( the blocker) executed the same query. The blocker was burning CPU and the 10046 trace was not showing any progress. After turning on the 10053 trace it became obvious that the cursor was still parsed. After 20 minutes the parsing was not completed yet! Over and over again, the optimizer took more time for the same operation – calculating selectivity from the extended statistics:

ColGroup Usage:: PredCnt: 4  Matches Full: #1  Partial:

I sampled the Oracle dedicated process with pstack and found out that the process spent most of the time in the function kkestGetMCSelInlist. The name implies that the function has something to do with in lists. Indeed, the query – coming from a software vendor – was quite unusual in this respect: it had 11 in-lists each containing 90 elements! The search on the bug database with the keyword kkestGetMCSelInlist returned a known bug 16825679 : PARSING NEVER ENDS. The suggested workaround – setting the undocumented parameter _optimizer_extended_stats_usage_control to 224 – reduced the parsing time from 30 minutes to a couple of seconds.

What did happen here?

The bug note doesn’t describe what exactly got changed after the new value was set. Therefore, I compared the 10053 traces with and without the workaround and found out that the extended statistics have not been used at all after setting the parameter:

_optimizer_extended_stats_usage_control=default
ColGroup Usage:: PredCnt: 4  Matches Full: #1  Partial:

_optimizer_extended_stats_usage_control=224
ColGroup Usage:: PredCnt: 4  Matches Full:  Partial:
=> no matches in this case

But, are the extended statistics completely disabled now or just in some cases? As I couldn’t find any details on this hidden parameter on Metalink, I decided to set up a test case in order to understand the impact of the change.

First, to set the scene, I am creating a table with two columns and the extended statistics:

CREATE TABLE t
  AS
  SELECT rownum n1, rownum AS n2
    FROM dual
    CONNECT BY level <= 1000; 

SELECT dbms_stats.create_extended_stats(
  ownname=>user, tabname=>'t', extension=>'(n1,n2)')
  FROM dual;

execute dbms_stats.gather_table_stats(user,'t') ;

Second, I’m running the explain plan for two queries with both columns in the where clause. The one query has the equal filter predicates, the other has an in-list.

EXPLAIN PLAN FOR
  SELECT *
  FROM t
  WHERE n1 = 1 AND n2 = 1 ;

--10053 trace: ColGroup Usage:: PredCnt: 2  Matches Full: #1  Partial:  Sel: 0.001000

EXPLAIN PLAN FOR
  SELECT *
  FROM t
  WHERE n1 = 42 AND n2 in ( 42 ,43) ;

--10053 trace: ColGroup Usage:: PredCnt: 2  Matches Full: #1  Partial:  Sel: 0.002000

As expected, the optimizer 10053 trace provides the evidence that the extended statics were used in both queries.

Finally, both queries will be executed again, but this time with _optimizer_extended_stats_usage_control set to 224.

alter session set "_optimizer_extended_stats_usage_control"=224 ;

EXPLAIN PLAN FOR
  SELECT *
  FROM t
  WHERE n1 = 42 AND n2 in ( 42 ,43) ;

--10053: no lines with ColGroup Usage found in the trace!

EXPLAIN PLAN FOR
  SELECT  *
  FROM t
  WHERE n1 = 1 AND n2 = 1 ;

--10053 trace: ColGroup Usage:: PredCnt: 2  Matches Full: #1  Partial:  Sel: 0.001000

In conclusion, when _optimizer_extended_stats_usage_control is set to 224 the extended events are not used just in the case of the in-list in the where clause. In the case of equal predicates, the extended statistics are used.