Statistics gathering and SQL Tuning Advisor

Our monitoring software found a long running job on one of our client’s databases. The job was an Oracle’s auto task running statistics gathering for more than 3 hours. I was curious to know why it took so long and used a query to ASH to find out the most common SQL during the job run based on the module name. Results were surprising to me: top SQL was coming with SQL Tuning Advisor comment.

Here is the SQL I used:

SQL> select s.sql_id, t.sql_text, s.cnt
  2  from
  3    (select *
  4     from
  5      (
  6        select sql_id, count(*) cnt
  7        from v$active_session_history
  8        where action like ‘ORA$AT_OS_OPT_SY%’
  9        group by sql_id
 10        order by count(*) desc
 11      )
 12     where rownum <= 5
 13    ) s,
 14    dba_hist_sqltext t
 15  where s.sql_id = t.sql_id;
SQL_ID        SQL_TEXT                                                                                CNT
————- ——————————————————————————– ———-
020t65s3ah2pq select substrb(dump(val,16,0,32),1,120) ep, cnt from (select /*+ no_expand_table        781
byug0cc5vn416 /* SQL Analyze(1) */ select /*+  full(t)    no_parallel(t) no_parallel_index(t)          43
bkvvr4azs1n6z /* SQL Analyze(1) */ select /*+  full(t)    no_parallel(t) no_parallel_index(t)          21
46sy4dfg3xbfn /* SQL Analyze(1) */ select /*+  full(t)    no_parallel(t) no_parallel_index(t)        1559

So most queries are coming with “SQL Analyze” comment right in the beginning of SQL which is running from DBMS_STATS call, which is confusing. After some bug search I have found a MOS Doc ID 1480132.1 which includes a PL/SQL stack trace from a DBMS_STATS procedure call, and it is going up to DBMS_SQLTUNE_INTERNAL, which means DBMS_STATS has a call to the SQL Tuning package; very odd:

SQL> select * from dba_dependencies where name = ‘DBMS_STATS_INTERNAL’ and referenced_name = ‘DBMS_SQLTUNE_INTERNAL’;
OWNER                          NAME                           TYPE               REFERENCED_OWNER       REFERENCED_NAME
—————————— —————————— —————— —————————— ———————————-
REFERENCED_TYPE    REFERENCED_LINK_NAME                                                                                                     DEPE
—————— ——————————————————————————————————————————-
SYS                            DBMS_STATS_INTERNAL            PACKAGE BODY       SYS                    DBMS_SQLTUNE_INTERNAL
PACKAGE                                                                                                                                     HARD

Turns out, this call has nothing to do with the SQL Tuning. It is just a call to a procedure in this package, which happen to look like an SQL from SQL Tuning Advisor. I have traced a GATHER_TABLE_STATS call in a test database first with SQL trace and then with DBMS_HPROF and here is how the call tree looks like:

SELECT RPAD(‘ ‘, (level-1)*2, ‘ ‘) || fi.owner || ‘.’ || fi.module AS name,
       fi.function,
       pci.subtree_elapsed_time,
       pci.function_elapsed_time,
       pci.calls
FROM   dbmshp_parent_child_info pci
       JOIN dbmshp_function_info fi ON pci.runid = fi.runid AND pci.childsymid = fi.symbolid
WHERE  pci.runid = 1
CONNECT BY PRIOR childsymid = parentsymid
  START WITH pci.parentsymid = 27;
NAME                                     FUNCTION                       SUBTREE_ELAPSED_TIME FUNCTION_ELAPSED_TIME                CALLS
—————————————- —————————— ——————– ——————— ——————–
…
SYS.DBMS_STATS_INTERNAL                  GATHER_SQL_STATS                           21131962                 13023                    1
  SYS.DBMS_ADVISOR                       __pkg_init                                       88                    88                    1
  SYS.DBMS_SQLTUNE_INTERNAL              GATHER_SQL_STATS                           21118776                  9440                    1
    SYS.DBMS_SQLTUNE_INTERNAL            I_PROCESS_SQL                              21107094              21104225                    1
      SYS.DBMS_LOB                       GETLENGTH                                        37                    37                    1
      SYS.DBMS_LOB                       INSTR                                            42                    42                    1
      SYS.DBMS_LOB                       __pkg_init                                       15                    15                    1
      SYS.DBMS_SQLTUNE_INTERNAL          I_VALIDATE_PROCESS_ACTION                        74                    39                    1
        SYS.DBMS_UTILITY                 COMMA_TO_TABLE                                   35                    35                    1
      SYS.DBMS_SQLTUNE_UTIL0             SQLTEXT_TO_SIGNATURE                            532                   532                    1
      SYS.DBMS_SQLTUNE_UTIL0             SQLTEXT_TO_SQLID                                351                   351                    1
      SYS.XMLTYPE                        XMLTYPE                                        1818                  1818                    1
    SYS.DBMS_SQLTUNE_UTIL0               SQLTEXT_TO_SQLID                                528                   528                    1
    SYS.DBMS_UTILITY                     COMMA_TO_TABLE                                   88                    88                    1
    SYS.DBMS_UTILITY                     __pkg_init                                       10                    10                    1
    SYS.SQLSET_ROW                       SQLSET_ROW                                       33                    33                    1
    SYS.XMLTYPE                          XMLTYPE                                        1583                  1583                    1
  SYS.DBMS_STATS_INTERNAL                DUMP_PQ_SESSTAT                                  73                    73                    1
  SYS.DBMS_STATS_INTERNAL                DUMP_QUERY                                        2                     2                    1
…

So there is a procedure DBMS_SQLTUNE_INTERNAL.GATHER_SQL_STATS which is being called by DBMS_STATS_INTERNAL, and this procedure actually runs a SQL like this:

/* SQL Analyze(0) */ select /*+  full(t)    no_parallel(t) no_parallel_index(t) dbms_stats cursor_sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitoring no_substrb_pad  */to_char(count("ID")),to_char(substrb(dump(min("ID"),16,0,32),1,120)),to_char(substrb(dump(max("ID"),16,0,32),1,120)),to_char(count("X")),to_char(substrb(dump(min("X"),16,0,32),1,120)),to_char(substrb(dump(max("X"),16,0,32),1,120)),to_char(count("Y")),to_char(substrb(dump(min("Y"),16,0,32),1,120)),to_char(substrb(dump(max("Y"),16,0,32),1,120)),to_char(count("PAD")),to_char(substrb(dump(min("PAD"),16,0,32),1,120)),to_char(substrb(dump(max("PAD"),16,0,32),1,120)) from "TIM"."T1" t  /* NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL,NDV,NIL,NIL*/

Which is basically approximate NDV calculation. So, nothing to be afraid of, it’s just the way the code is organized: DBMS_STATS uses API of SQL Tuning framework when you are using DBMS_STATS.AUTO_SAMPLE_SIZE as the ESTIMATE_PERCENT (which is the default & recommended value in 11g+).