1. https://www.pythian.com/blog/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:
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
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 781byug0cc5vn416 /* SQL Analyze(1) */ select /*+ full(t) no_parallel(t) no_parallel_index(t) 43bkvvr4azs1n6z /* SQL Analyze(1) */ select /*+ full(t) no_parallel(t) no_parallel_index(t) 2146sy4dfg3xbfn /* 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:
|
1
2
3
4
5
6
7
8
|
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_INTERNALPACKAGE
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:
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
|
SELECT RPAD(' ', (level-1)*2, ' ') || fi.owner || '.' || fi.module AS name, fi.function, pci.subtree_elapsed_time, pci.function_elapsed_time, pci.callsFROM dbmshp_parent_child_info pci JOIN dbmshp_function_info fi ON pci.runid = fi.runid AND pci.childsymid = fi.symbolidWHERE pci.runid = 1CONNECT 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:
|
1
|
/* 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+).
附录1：
(approximate NDV calculation : Column statistics data is an important factor for CBO to estimate cost of execution plan. There are generally two kinds of statistics data on columns, one is the synopses, such as NDV, ACL and maximum/minimum data; the other is histogram. A single scanning table can get those synopses. To analyze the large tables with low cost, we normally sampling the data.)
附录2：
解释：are using DBMS_STATS.AUTO_SAMPLE_SIZE as the ESTIMATE_PERCENT (which is the default & recommended value in 11g+).
1. If, during processing, the procedure determines that the returned information for the sample is insufficient for accurate access path selection, the sample can be increased by a factor of ten and restarted. For example, if AUTO_SAMPLE_SIZE started with around 5500 rows, when the procedure determines that the sample is insufficient, then it will then increase the sample (for example to 55000) and restart. If this is insufficient, it increases by another factor of 10, and so on. However, if the sample size exceeds 25% of the table size, it will switch automatically to COMPUTE (100% sample).
2. There is a case where the sample taken is sufficient for accurate statistics, but the number of rows is judged to be poorly estimated (either for the table or an index). Sample_size is set at the lower value, but then dbms_stats will take an accurate row count by using SELECT COUNT(*) from the table and index. As well as setting the num_rows, dbms_stats will also set the sample_size to this value (as this is the number of rows sampled to produce num_rows). In this case, the sample_size, although accurate for the last operation, is misleading as far as the full sample taken for the other gathered statistics.
2.
http://blog.csdn.net/stevendbaguo/article/details/50856002
接到现场数据库维护厂商发出的警告，有一条 insert语句执行了几千秒。
开发排查，从select * from dba_source s where s.text like '%XXX%';查到是一个存储过程，于是找到存储过程，将其改名。
但问题没有解决，隔天又收到警告。
难道是存储过程改名有问题，我远程到现场看了下，并没有问题。再次查看数据库报告：
SQL Module 是 DBMS_SCHEDULER，确定无疑是Oracle JOB调用，奇怪的是SQL语句有 /* SQL Analyze(194, 1) */ 这样的提示。
如果想定位到这条SQL，最好是找到这条SQL历史执行的session,希望找到蛛丝马迹。
select * from dba_hist_active_sess_history s where s.sql_id='29yrhxqdk2d1q';
TOP_LEVEL_SQL_ID 为5zruc4v6y32f9：说明是sql_id为5zruc4v6y32f9的调用的这条sql
MODULE：DBMS_SCHEDULER
PLSQL_ENTRY_OBJECT_ID：9013
根据上面的信息再进行查询：
9013;--结果是owner=sys object_name=dbms_sqltune
5zruc4v6y32f9
DECLARE
job BINARY_INTEGER := :job;
next_date TIMESTAMP WITH TIME ZONE := :mydate;
broken BOOLEAN := FALSE;
job_name VARCHAR2(30) := :job_name;
job_subname VARCHAR2(30) := :job_subname;
job_owner VARCHAR2(30) := :job_owner;
job_start TIMESTAMP WITH TIME ZONE := :job_start;
job_scheduled_start TIMESTAMP WITH TIME ZONE := :job_scheduled_start;
window_start TIMESTAMP WITH TIME ZONE := :window_start;
window_end TIMESTAMP WITH TIME ZONE := :window_end;
chain_id VARCHAR2(14) := :chainid;
credential_owner varchar2(30) := :credown;
credential_name varchar2(30) := :crednam;
destination_owner varchar2(30) := :destown;
destination_name varchar2(30) := :destnam;
job_dest_id varchar2(14) := :jdestid;
log_id number := :log_id;
BEGIN
DECLARE
ename VARCHAR2(30);
BEGIN
ename := dbms_sqltune.execute_tuning_task('SYS_AUTO_SQL_TUNING_TASK');
END;
:mydate := next_date;
IF broken THEN
:b := 1;
ELSE
:b := 0;
END IF;
END;
这是数据库SQL优化的包，自己调用的，终于明白 /* SQL Analyze(194, 1) */的意思了，是标记这种优化包调用的。
3.
http://blog.itpub.net/23718752/viewspace-1252180/
在昨天晚上10点开始，数据库的性能开始下降，出现了一些j00开头的进程。
而且持续了比较长的时间，简单分析了一下，对应的进程执行的sql语句如下。
####### Process Information from OS level as below ########
oraccbs1 16184 1 23 22:00 ? 00:03:09 ora_j000_PETCUS1
oraccbs1 20829 12754 0 22:14 pts/12 00:00:00 ksh showpid.sh 16184
##############################################
SID SERIAL# USERNAME OSUSER
MACHINE PROCESS TERMINAL TYPE
LOGIN_TIME
---------- ---------- --------------- ---------------
-------------------- --------------- --------------- ----------
-------------------
1139 1071 SYS oraccbs1
xxxxxx 16184 UNKNOWN USER
2014-08-14 22:00:43
.
SQL_ID SQL_TEXT
------------------------------ ------------------------------------------------------------
6fwshkjydz9ph /* SQL Analyze(1) */ select /*+ full(t) no_parallel(t) n
o_parallel_index(t) dbms_stats cursor_sharing_exact use_weak
_name_resl dynamic_sampling(0) no_monitoring no_substrb_pad
*/to_char(count("PERIOD_KEY")),to_char(substrb(dump(min("PE
RIOD_KEY"),16,0,32),1,120)),to_char(substrb(dump(max("PERIOD
_KEY"),16,0,32),1,120)),to_char(count("PARTITION_ID")),to_ch
ar(substrb(dump(min("PARTITION_ID"),16,0,32),1,120)),to_char
(substrb(dump(max("PARTITION_ID"),16,0,32),1,120)),to_char(c
ount("DEBIT_ID")),to_char(substrb(dump(min("DEBIT_ID"),16,0,
32),1,120)),to_char(substrb(dump(max("DEBIT_ID"),16,0,32),1,
120)),to_char(count("SYS_CREATION_DATE")),to_char(substrb(du
mp(min("SYS_CREATION_DATE"),16,0,32),1,120)),to_char(substrb
(dump(max("SYS_CREATION_DATE"),16,0,32),1,120)),to_char(coun
t("SYS_UPDATE_DATE")),to_char(substrb(dump(min("SYS_UPDATE_D
ATE"),16,0,32),1,120)),to_char(substrb(dump(max("SYS_UPDATE_
DATE"),16,0,32),1,120)),to_char(count("OPERATOR_ID")),to_cha
r(substrb(dump(min("OPERATOR_ID"),16,0,3
PREV_SQL_ID SQL_TEXT
------------------------------ ------------------------------------------------------------
fhzj09a7fnrnb SELECT DBTIMEZONE, LENGTH(DBTIMEZONE) FROM SYS.DUAL
看起来是在做一些后台的维护工作。在11g中引入了几个schedule job，简单查询，结果如下。可以看到在每天都设置了对应的window。
在10点开始做一些工作。以下是禁用以后的状态。
SQL> execute DBMS_AUTO_TASK_ADMIN.DISABLE;
PL/SQL procedure successfully completed.
SQL> select * from DBA_AUTOTASK_WINDOW_CLIENTS;
WINDOW_NAME
WINDOW_NEXT_TIME
WINDO AUTOTASK OPTIMIZE SEGMENT_ SQL_TUNE HEALTH_M
------------------------------
---------------------------------------------------------------------------
----- -------- -------- -------- -------- --------
MONDAY_WINDOW 18-AUG-14 10.00.00.000000 PM
ASIA/PHNOM_PENH FALSE DISABLED ENABLED
ENABLED ENABLED DISABLED
TUESDAY_WINDOW 19-AUG-14 10.00.00.000000 PM
ASIA/PHNOM_PENH FALSE DISABLED ENABLED
ENABLED ENABLED DISABLED
WEDNESDAY_WINDOW 20-AUG-14 10.00.00.000000 PM
ASIA/PHNOM_PENH FALSE DISABLED ENABLED
ENABLED ENABLED DISABLED
THURSDAY_WINDOW 14-AUG-14 10.00.00.000000 PM
ASIA/PHNOM_PENH TRUE DISABLED ENABLED
ENABLED ENABLED DISABLED
FRIDAY_WINDOW 15-AUG-14 10.00.00.000000 PM
ASIA/PHNOM_PENH FALSE DISABLED ENABLED
ENABLED ENABLED DISABLED
SATURDAY_WINDOW 16-AUG-14 06.00.00.000000 AM
ASIA/PHNOM_PENH FALSE DISABLED ENABLED
ENABLED ENABLED DISABLED
SUNDAY_WINDOW 17-AUG-14 06.00.00.000000 AM
ASIA/PHNOM_PENH FALSE DISABLED ENABLED
ENABLED ENABLED DISABLED
7 rows selected.
其实3个主要的后台job可以选择关掉。
SQL> select client_name,status from DBA_AUTOTASK_CLIENT;
CLIENT_NAME STATUS
---------------------------------------------------------------- --------
auto optimizer stats collection ENABLED
auto space advisor ENABLED
sql tuning advisor ENABLED
使用如下的pl/sql来禁用。
begin
DBMS_AUTO_TASK_ADMIN.DISABLE(client_name => 'auto optimizer stats collection',
operation => NULL,
window_name => NULL);
end;
/
begin
DBMS_AUTO_TASK_ADMIN.DISABLE(client_name => 'auto space advisor',
operation => NULL,
window_name => NULL);
end;
/
begin
DBMS_AUTO_TASK_ADMIN.DISABLE(client_name => 'sql tuning advisor',
operation => NULL,
window_name => NULL);
end;
/
禁用以后，状态如下：
SQL> select client_name,status from DBA_AUTOTASK_CLIENT;
CLIENT_NAME STATUS
---------------------------------------------------------------- --------
auto optimizer stats collection DISABLED
auto space advisor DISABLED
sql tuning advisor DISABLED
但是不会当时生效，需要过一段时间，所以需要提前禁用。