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 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:
|
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_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:
|
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.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:
|
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
但是不會當時生效，需要過一段時間，所以需要提前禁用。