SQL解析時間過長的調整 案例一則 [複製連結]
某醫院生產庫遷移到11.2.0.3後，使用者抱怨系統變慢。
檢查發現，很多複雜SQL的執行很快，但是解析非常慢。
整個資料庫並不存在任何爭用。
SQL> SELECT SQL_ID,
AVG_HARD_PARSE_TIME_MS
FROM
(SELECT
ROUND(AVG_HARD_PARSE_TIME / 1000, 2)
AVG_HARD_PARSE_TIME_MS,
SQL_ID,
EXECUTIONS
FROM
V$SQLSTATS
ORDER BY AVG_HARD_PARSE_TIME DESC )
WHERE
ROWNUM <= 10;
SQL_ID AVG_HARD_PARSE_TIME_MS
------------- ----------------------
63n9pwutt8yzw 223279.79
8pduputnkhukx 174644.33
gg9m2b0hjky1y 161064.91
g0vn88sqftx3c 66367.09
bbvy8xjs7gjgj 64747.76
7bgzzkwsqr6hc 63303.48
bzhxncjcy1k96 61963.71
8y387dwxggn5t 57265.29
1f25j21vvfv10 54766.09
0br8s1y3ma0qr 53578.61
以上我們可以看到，某些SQL的解析時間超過百秒。
某一SQL，執行若干次後無物理讀：
SQL> /
no rows selected
Elapsed: 00:00:00.11
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
2761 consistent gets
0 physical reads
0 redo size
16589 bytes sent via SQL*Net to client
513 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
3 sorts (memory)
0 sorts (disk)
0 rows processed
在SQL中加入/*hard parse by me*/來硬解析再次執行，同樣的邏輯讀且無物理讀：
no rows selected
Elapsed: 00:00:03.73
Statistics
----------------------------------------------------------
22 recursive calls
0 db block gets
2767 consistent gets
0 physical reads
0 redo size
16589 bytes sent via SQL*Net to client
513 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
3 sorts (memory)
0 sorts (disk)
0 rows processed
以上可見，無硬解析執行0.11秒，因解析執行耗時3.73秒。
這個系統是醫院的系統。
應用較複雜，由於應用本身的原因，大量使用拼接SQL, 雖然使用繫結變數，仍然無法避免大量硬解析。
譬如，查詢一個病例報告，可以根據：
1.病人ID
2.病人名字
3.病人錄入時間
4.手術名稱
5.手術時間
6.主治大夫姓名
7.主治大夫ID
8.疾病種類....
9.疾病嚴重程度.....
10.病人是否住院
11.身體掃描型別:MRI/XRAY
.......
共三十多個選項，醫生可以任意選擇其中的N種組合在一起進行查詢。
再譬如，對病人名字查詢可以使用全匹匹配=,模糊匹配LIKE，大小寫不敏感upper等。
對於時間可以選擇最近一週內>sysdate-7，或者某一段時間between。
任何一點區別都會造成拼接成的SQL重新硬解析。
首先，透過設定以下引數禁用11g的ACS以減少解析次數。
SQL> show parameter cursor
NAME TYPE VALUE
-------------------------------------- --------- ----------------------
_optimizer_adaptive_cursor_sharing boolean FALSE
_optimizer_extended_cursor_sharing string NONE
_optimizer_extended_cursor_sharing_rel string NONE
在設定以上引數後，情況有初步好轉，禁用11g的ACS使得總解析次數減少了80%。
但是，由於每個SQL的解析時間並沒有真正減少，使用者仍會時不時碰到慢（SQL長時間等待解析）的情況。
下面分析SQL的長解析。首先，資料庫不存在任何爭用，在午夜零負載的時候，解析耗費時間長的問題仍可重現。
做10046 trace，透過tkprof可以看到：
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0 0 0
Execute 1 3.30 3.30 0 6 0 0
Fetch 1 0.00 0.00 0 59 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 3.31 3.31 0 65 0 0
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 36
Number of plan statistics captured: 1
以下是10046 raw trace：
PARSING IN CURSOR #18446744071468120416 len=14352 dep=0 uid=36 oct=3 lid=36 tim=40253210782553 hv=3244419326 ad='7a995e8c8' sqlid='d228z5m0q3u7y'
PARSE #18446744071468120416:c=10000,e=9046,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=40253210782549
WAIT #18446744071468120416: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253213924594
WAIT #18446744071468120416: nam='SQL*Net more data to client' ela= 184 driver id=1413697536 #bytes=8145 p3=0 obj#=49430 tim=40253213934106
WAIT #18446744071468120416: nam='SQL*Net message from client' ela= 38091 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253213972419
EXEC #18446744071468120416:c=3310000,e=3313604,p=0,cr=6,cu=0,mis=1,r=0,dep=0,og=1,plh=1738446058,tim=40253217287241
WAIT #18446744071468120416: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217289638
WAIT #18446744071468120416: nam='SQL*Net more data to client' ela= 181 driver id=1413697536 #bytes=8145 p3=0 obj#=49430 tim=40253217299453
WAIT #18446744071468120416: nam='SQL*Net message from client' ela= 3096 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217302788
FETCH #18446744071468120416:c=0,e=3601,p=0,cr=59,cu=0,mis=0,r=0,dep=0,og=1,plh=1738446058,tim=40253217306558
WAIT #18446744071468120416: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217311918
WAIT #18446744071468120416: nam='SQL*Net message from client' ela= 22854 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217334883
以上我們可以看到時間並不是耗費在資料字典上，而耗費在了CBO尋徑，最佳化執行計劃上。
什麼是最佳化執行計劃？為什麼時間耗費在Execute上？
我們知道SQL的解析和執行並不是完全隔離的，一個例子就是bind peek：
譬如我們explain plan for select * from t where c1=:n;的時候就可以生成執行計劃，但是這個執行計劃並是最終的執行計劃。
當真正執行時候，傳入了變數，oracle會根據變數進行分析，在真正執行時繼續調優執行計劃，這就是bind peek。
為了排除bind peek的影響，我們用explain plan for來對完全使用繫結變數的SQL進行分析：
explain plan for select /*hard47*/ .......
DECODE(c.c1,:"SYS_B_14",:"SYS_B_15",:"SYS_B_16"),DECODE(c.c2,:"SYS_B_17",:"SYS_B_18",:"SYS_B_19"),
..........
FROM
TABLE1,TABLE2,VIEW1,VIEW2,VIEW3.....
WHERE NVL(QPQD_EX_KEY,:"SYS_B_60") > :"SYS_B_61" AND a.QPQD_AP_PATKEY = :1
Elapsed: 00:00:03.66
在完全使用繫結變數的情況下，同樣的SQL解析仍然耗時3秒。
為了使試驗更直觀，我尋找了一條新的SQL，這條SQL的解析時間是13秒。接下來我會使用這條解析耗費10秒的SQL進行測試。
首先，HINT肯定可以減少縮小CBO的選擇範圍以減少解析時間，但是對於我們來說不是可選項。
來進行一些基本測試：
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '9.2.0.8'; --- 0.82 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0'; --- 1.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.2.0.1'; --- 4.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.1.0.7'; --- 12.20 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.2.0.3'; --- 12.91 seconds
我們可以看到，當OPTIMIZER_FEATURES_ENABLE是當前的11.2.0.3時，解析時間是13秒，當為9.2.0.8，解析時間是0.82秒。
接下來測試optimizer_mode，和預想的一樣，在OPTIMIZER_FEATURES_ENABLE仍為11.2.0.3的情況下。當把optimizer_mode設定為RULE後，解析時間變成了0.5秒.
可是，在此生產環境中，我們不能更改OPTIMIZER_FEATURES_ENABLE降級和optimizer_mode=RULE。
首先，這2個引數的誤傷/影響範圍過廣，無法在生產庫中輕易嘗試。
其次，這2個引數使得解析時間縮短，但使資料庫中相關和不相關的其它SQL選擇一個錯誤的執行計劃的機率大增。解析時間少了，可執行時間又增加了。
此外，這和提供給使用者的升級方案矛盾，畢竟說服使用者升級，就是描繪了11g新特性美好的藍圖。
所以，我們希望能夠定位問題，然後找到針對此問題的特定引數，能夠準確解決問題，同時最小化對系統的影響。
進一步分析問題，為解析耗時13秒的SQL生成了10053 trace。
生成的trace檔案是44MB。這是一個好訊息。
如果解析用了13秒，但10053 trace只有幾百K，說明CBO遇上了嚴重的BUG，因為幾百K的執行計劃解析是不應該耗費10多秒的。單trace檔案44MB，說明CBO確實有“做事”。
簡單的看下10053的內容。我的純SQL功力只是皮毛，但這不妨礙我們看懂10053 trace的整體框架：
pacsrd1212 $ cat QPROD_ora_8456_10053.trc|grep -i "permutations tried"|grep -v "permutations tried: 1"
Number of join permutations tried: 2
Number of join permutations tried: 6
Number of join permutations tried: 52
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 499
Number of join permutations tried: 84
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 798
Number of join permutations tried: 84
Number of join permutations tried: 80
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 499
Number of join permutations tried: 84
Number of join permutations tried: 451
Number of join permutations tried: 483
Number of join permutations tried: 84
Number of join permutations tried: 2
Number of join permutations tried: 6
Number of join permutations tried: 52
Number of join permutations tried: 435
Number of join permutations tried: 84
我們對比下OPTIMIZER_FEATURES_ENABLE = '9.2.0.8'時只有2M的10053trace：
pacsrd1212 $ cat QPROD_ora_7830_10053_2.trc|grep -i "permutations tried"|grep -v "permutations tried: 1"
Number of join permutations tried: 2
Number of join permutations tried: 6
Number of join permutations tried: 20
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 95
可以看到，OPTIMIZER_FEATURES_ENABLE = '11.2.0.3'時候,CBO考慮瞭如此多的join order，難怪如此耗時。
我們可以透過隱藏引數“_OPTIMIZER_MAX_PERMUTATIONS”來限定CBO的最大排列組合。
經過測試，在設定_OPTIMIZER_MAX_PERMUTATIONS=50後，SQL解析時間從13秒降低到6秒。
但是此引數同樣牽連太廣，同時從44MB的10053後，可以看到：
PPOINTMENT_ITEMS[J]#6 QPQD_LINK[QPQD_LINK]#7 VW_NSO_3[VW_NSO_3]#11 QPQD_MACHINELINKS[K]#12 EXAMS[C]#10 EXAMINATIONS[E]#8 EXAMG
ROUPS[F]#9 VW_PRIORITY_SEQUENCE_PLACER[G]#13
Join order aborted: cost > best plan cost
Join order[449]: QPQDVIEW541[A]#1 PATIENTS[B]#0 QPQD_LINK[Z]#2 APPOINTMENTS[D]#3 APPOINTMENT_ITEMS[H]#4 QPQD_ROOMLINKS[I]#5 A
PPOINTMENT_ITEMS[J]#6 QPQD_LINK[QPQD_LINK]#7 EXAMINATIONS[E]#8 EXAMGROUPS[F]#9 EXAMS[C]#10 VW_NSO_3[VW_NSO_3]#11 QPQD_MACHINEL
INKS[K]#12 VW_PRIORITY_SEQUENCE_PLACER[G]#13
Join order aborted: cost > best plan cost
Considering multiple instances based initial join order.
Best join order so far: 358
CBO在358個join order找到了最優值，所以，如果我們限定_OPTIMIZER_MAX_PERMUTATIONS過小，很可能使得SQL錯過此執行計劃。
我們來隨便看看上面的join order：
QPQDVIEW541[A]#1 PATIENTS[B]#0 QPQD_LINK[Z]#2 APPOINTMENTS[D]#3 APPOINTMENT_ITEMS[H]#4 QPQD_ROOMLINKS[I]#5 A
PPOINTMENT_ITEMS[J]#6 QPQD_LINK[QPQD_LINK]#7 EXAMINATIONS[E]#8 EXAMGROUPS[F]#9 EXAMS[C]#10 VW_NSO_3[VW_NSO_3]#11 QPQD_MACHINEL
INKS[K]#12 VW_PRIORITY_SEQUENCE_PLACER[G]#13
理論上說，14個表，那麼對應的可能的執行順序最多有：14*13*12*11*....*3*2*1種。
當然CBO不會傻到去一一嘗試，CBO會在路徑判斷中忽略大部分必定低效的執行計劃。
而其實我們要做的，就是透過各種方式，譬如CBO的parameter，來限制CBO的選擇集。CBO無用的選擇和嘗試越少，那麼解析時間就會越少。
至此卻陷入困境，不知下一步該怎麼繼續。
這個時候想起，我們嘗試了一個又一個的分析工具，有些時候卻忘記了問題本身。
檢查了若干解析慢的SQL，發現有某些共通的現象，譬如，解析都包含大量表和複雜檢視，已經巢狀若干層的IN/EXIST。
在去掉內層巢狀後，解析時間可以減少一半。
於是嘗試和巢狀/Merge有關的某些引數：
alter session set query_rewrite_enabled = false;
alter session set"_optimizer_table_expansion"=false;
alter session set "_and_pruning_enabled"=false;
alter session set "_subquery_pruning_enabled"=false;
alter session set "_optimizer_fast_access_pred_analysis" =false;
alter session set "_optimizer_sortmerge_join_enabled" = false;
alter session set "_optimizer_sortmerge_join_inequality" = false;
............
都不管用。
這個時候，回想起最開始做的嘗試：
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '9.2.0.8'; --- 0.82 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0'; --- 1.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.2.0.1'; --- 4.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.1.0.7'; --- 12.20 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.2.0.3'; --- 12.91 seconds
於是更精確的測試，然後注意到：
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0.3'; --- 1.40 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0.4'; --- 3.59 seconds
我們知道OPTIMIZER_FEATURES_ENABLE會控制很多和CBO有關的引數，改變OPTIMIZER_FEATURES_ENABLE其實也是在改變這些引數。很可能是這些引數在起作用。
在之前的工作中，我記得有一個引數就是10.1.0.4引入的：
_optimizer_cost_based_transformation
這個神一般的引數自從誕生之日起，帶來了無數的血雨腥風，圍繞它產生的問題罄竹難書。難道？？？？試驗下：
alter session set "_optimizer_cost_based_transformation"=exhaustive; ---- Elapsed: 00:00:14.11
alter session set "_optimizer_cost_based_transformation"=iterative; ---- Elapsed: 00:00:13.71
alter session set "_optimizer_cost_based_transformation"=linear; ---- Elapsed: 00:00:13.97
alter session set "_optimizer_cost_based_transformation"=on; ---- Elapsed: 00:00:13.97
alter session set "_optimizer_cost_based_transformation"=off; ---- Elapsed: 00:00:03.05
在關閉這個引數後，解析時間從10多秒銳減到3秒。
之後，一股做氣，繼續測試了一些調整，透過調整CBO引數繼續控制和裁剪CBO的篩選範圍，包括禁用在10053中看到的佔有一定比例的bitmap index的推演：
alter session set "_b_tree_bitmap_plans"=false;
alter session set "optimizer_index_cost_adj" = 50;
..................
目前，此SQL解析時間已經從13秒降低到了1秒。
檢查發現，很多複雜SQL的執行很快，但是解析非常慢。
整個資料庫並不存在任何爭用。
SQL> SELECT SQL_ID,
AVG_HARD_PARSE_TIME_MS
FROM
(SELECT
ROUND(AVG_HARD_PARSE_TIME / 1000, 2)
AVG_HARD_PARSE_TIME_MS,
SQL_ID,
EXECUTIONS
FROM
V$SQLSTATS
ORDER BY AVG_HARD_PARSE_TIME DESC )
WHERE
ROWNUM <= 10;
SQL_ID AVG_HARD_PARSE_TIME_MS
------------- ----------------------
63n9pwutt8yzw 223279.79
8pduputnkhukx 174644.33
gg9m2b0hjky1y 161064.91
g0vn88sqftx3c 66367.09
bbvy8xjs7gjgj 64747.76
7bgzzkwsqr6hc 63303.48
bzhxncjcy1k96 61963.71
8y387dwxggn5t 57265.29
1f25j21vvfv10 54766.09
0br8s1y3ma0qr 53578.61
以上我們可以看到，某些SQL的解析時間超過百秒。
某一SQL，執行若干次後無物理讀：
SQL> /
no rows selected
Elapsed: 00:00:00.11
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
2761 consistent gets
0 physical reads
0 redo size
16589 bytes sent via SQL*Net to client
513 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
3 sorts (memory)
0 sorts (disk)
0 rows processed
在SQL中加入/*hard parse by me*/來硬解析再次執行，同樣的邏輯讀且無物理讀：
no rows selected
Elapsed: 00:00:03.73
Statistics
----------------------------------------------------------
22 recursive calls
0 db block gets
2767 consistent gets
0 physical reads
0 redo size
16589 bytes sent via SQL*Net to client
513 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
3 sorts (memory)
0 sorts (disk)
0 rows processed
以上可見，無硬解析執行0.11秒，因解析執行耗時3.73秒。
這個系統是醫院的系統。
應用較複雜，由於應用本身的原因，大量使用拼接SQL, 雖然使用繫結變數，仍然無法避免大量硬解析。
譬如，查詢一個病例報告，可以根據：
1.病人ID
2.病人名字
3.病人錄入時間
4.手術名稱
5.手術時間
6.主治大夫姓名
7.主治大夫ID
8.疾病種類....
9.疾病嚴重程度.....
10.病人是否住院
11.身體掃描型別:MRI/XRAY
.......
共三十多個選項，醫生可以任意選擇其中的N種組合在一起進行查詢。
再譬如，對病人名字查詢可以使用全匹匹配=,模糊匹配LIKE，大小寫不敏感upper等。
對於時間可以選擇最近一週內>sysdate-7，或者某一段時間between。
任何一點區別都會造成拼接成的SQL重新硬解析。
首先，透過設定以下引數禁用11g的ACS以減少解析次數。
SQL> show parameter cursor
NAME TYPE VALUE
-------------------------------------- --------- ----------------------
_optimizer_adaptive_cursor_sharing boolean FALSE
_optimizer_extended_cursor_sharing string NONE
_optimizer_extended_cursor_sharing_rel string NONE
在設定以上引數後，情況有初步好轉，禁用11g的ACS使得總解析次數減少了80%。
但是，由於每個SQL的解析時間並沒有真正減少，使用者仍會時不時碰到慢（SQL長時間等待解析）的情況。
下面分析SQL的長解析。首先，資料庫不存在任何爭用，在午夜零負載的時候，解析耗費時間長的問題仍可重現。
做10046 trace，透過tkprof可以看到：
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0 0 0
Execute 1 3.30 3.30 0 6 0 0
Fetch 1 0.00 0.00 0 59 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 3.31 3.31 0 65 0 0
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 36
Number of plan statistics captured: 1
以下是10046 raw trace：
PARSING IN CURSOR #18446744071468120416 len=14352 dep=0 uid=36 oct=3 lid=36 tim=40253210782553 hv=3244419326 ad='7a995e8c8' sqlid='d228z5m0q3u7y'
PARSE #18446744071468120416:c=10000,e=9046,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=40253210782549
WAIT #18446744071468120416: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253213924594
WAIT #18446744071468120416: nam='SQL*Net more data to client' ela= 184 driver id=1413697536 #bytes=8145 p3=0 obj#=49430 tim=40253213934106
WAIT #18446744071468120416: nam='SQL*Net message from client' ela= 38091 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253213972419
EXEC #18446744071468120416:c=3310000,e=3313604,p=0,cr=6,cu=0,mis=1,r=0,dep=0,og=1,plh=1738446058,tim=40253217287241
WAIT #18446744071468120416: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217289638
WAIT #18446744071468120416: nam='SQL*Net more data to client' ela= 181 driver id=1413697536 #bytes=8145 p3=0 obj#=49430 tim=40253217299453
WAIT #18446744071468120416: nam='SQL*Net message from client' ela= 3096 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217302788
FETCH #18446744071468120416:c=0,e=3601,p=0,cr=59,cu=0,mis=0,r=0,dep=0,og=1,plh=1738446058,tim=40253217306558
WAIT #18446744071468120416: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217311918
WAIT #18446744071468120416: nam='SQL*Net message from client' ela= 22854 driver id=1413697536 #bytes=1 p3=0 obj#=49430 tim=40253217334883
以上我們可以看到時間並不是耗費在資料字典上，而耗費在了CBO尋徑，最佳化執行計劃上。
什麼是最佳化執行計劃？為什麼時間耗費在Execute上？
我們知道SQL的解析和執行並不是完全隔離的，一個例子就是bind peek：
譬如我們explain plan for select * from t where c1=:n;的時候就可以生成執行計劃，但是這個執行計劃並是最終的執行計劃。
當真正執行時候，傳入了變數，oracle會根據變數進行分析，在真正執行時繼續調優執行計劃，這就是bind peek。
為了排除bind peek的影響，我們用explain plan for來對完全使用繫結變數的SQL進行分析：
explain plan for select /*hard47*/ .......
DECODE(c.c1,:"SYS_B_14",:"SYS_B_15",:"SYS_B_16"),DECODE(c.c2,:"SYS_B_17",:"SYS_B_18",:"SYS_B_19"),
..........
FROM
TABLE1,TABLE2,VIEW1,VIEW2,VIEW3.....
WHERE NVL(QPQD_EX_KEY,:"SYS_B_60") > :"SYS_B_61" AND a.QPQD_AP_PATKEY = :1
Elapsed: 00:00:03.66
在完全使用繫結變數的情況下，同樣的SQL解析仍然耗時3秒。
為了使試驗更直觀，我尋找了一條新的SQL，這條SQL的解析時間是13秒。接下來我會使用這條解析耗費10秒的SQL進行測試。
首先，HINT肯定可以減少縮小CBO的選擇範圍以減少解析時間，但是對於我們來說不是可選項。
來進行一些基本測試：
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '9.2.0.8'; --- 0.82 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0'; --- 1.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.2.0.1'; --- 4.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.1.0.7'; --- 12.20 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.2.0.3'; --- 12.91 seconds
我們可以看到，當OPTIMIZER_FEATURES_ENABLE是當前的11.2.0.3時，解析時間是13秒，當為9.2.0.8，解析時間是0.82秒。
接下來測試optimizer_mode，和預想的一樣，在OPTIMIZER_FEATURES_ENABLE仍為11.2.0.3的情況下。當把optimizer_mode設定為RULE後，解析時間變成了0.5秒.
可是，在此生產環境中，我們不能更改OPTIMIZER_FEATURES_ENABLE降級和optimizer_mode=RULE。
首先，這2個引數的誤傷/影響範圍過廣，無法在生產庫中輕易嘗試。
其次，這2個引數使得解析時間縮短，但使資料庫中相關和不相關的其它SQL選擇一個錯誤的執行計劃的機率大增。解析時間少了，可執行時間又增加了。
此外，這和提供給使用者的升級方案矛盾，畢竟說服使用者升級，就是描繪了11g新特性美好的藍圖。
所以，我們希望能夠定位問題，然後找到針對此問題的特定引數，能夠準確解決問題，同時最小化對系統的影響。
進一步分析問題，為解析耗時13秒的SQL生成了10053 trace。
生成的trace檔案是44MB。這是一個好訊息。
如果解析用了13秒，但10053 trace只有幾百K，說明CBO遇上了嚴重的BUG，因為幾百K的執行計劃解析是不應該耗費10多秒的。單trace檔案44MB，說明CBO確實有“做事”。
簡單的看下10053的內容。我的純SQL功力只是皮毛，但這不妨礙我們看懂10053 trace的整體框架：
pacsrd1212 $ cat QPROD_ora_8456_10053.trc|grep -i "permutations tried"|grep -v "permutations tried: 1"
Number of join permutations tried: 2
Number of join permutations tried: 6
Number of join permutations tried: 52
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 499
Number of join permutations tried: 84
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 798
Number of join permutations tried: 84
Number of join permutations tried: 80
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 499
Number of join permutations tried: 84
Number of join permutations tried: 451
Number of join permutations tried: 483
Number of join permutations tried: 84
Number of join permutations tried: 2
Number of join permutations tried: 6
Number of join permutations tried: 52
Number of join permutations tried: 435
Number of join permutations tried: 84
我們對比下OPTIMIZER_FEATURES_ENABLE = '9.2.0.8'時只有2M的10053trace：
pacsrd1212 $ cat QPROD_ora_7830_10053_2.trc|grep -i "permutations tried"|grep -v "permutations tried: 1"
Number of join permutations tried: 2
Number of join permutations tried: 6
Number of join permutations tried: 20
Number of join permutations tried: 2
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 3
Number of join permutations tried: 95
可以看到，OPTIMIZER_FEATURES_ENABLE = '11.2.0.3'時候,CBO考慮瞭如此多的join order，難怪如此耗時。
我們可以透過隱藏引數“_OPTIMIZER_MAX_PERMUTATIONS”來限定CBO的最大排列組合。
經過測試，在設定_OPTIMIZER_MAX_PERMUTATIONS=50後，SQL解析時間從13秒降低到6秒。
但是此引數同樣牽連太廣，同時從44MB的10053後，可以看到：
PPOINTMENT_ITEMS[J]#6 QPQD_LINK[QPQD_LINK]#7 VW_NSO_3[VW_NSO_3]#11 QPQD_MACHINELINKS[K]#12 EXAMS[C]#10 EXAMINATIONS[E]#8 EXAMG
ROUPS[F]#9 VW_PRIORITY_SEQUENCE_PLACER[G]#13
Join order aborted: cost > best plan cost
Join order[449]: QPQDVIEW541[A]#1 PATIENTS[B]#0 QPQD_LINK[Z]#2 APPOINTMENTS[D]#3 APPOINTMENT_ITEMS[H]#4 QPQD_ROOMLINKS[I]#5 A
PPOINTMENT_ITEMS[J]#6 QPQD_LINK[QPQD_LINK]#7 EXAMINATIONS[E]#8 EXAMGROUPS[F]#9 EXAMS[C]#10 VW_NSO_3[VW_NSO_3]#11 QPQD_MACHINEL
INKS[K]#12 VW_PRIORITY_SEQUENCE_PLACER[G]#13
Join order aborted: cost > best plan cost
Considering multiple instances based initial join order.
Best join order so far: 358
CBO在358個join order找到了最優值，所以，如果我們限定_OPTIMIZER_MAX_PERMUTATIONS過小，很可能使得SQL錯過此執行計劃。
我們來隨便看看上面的join order：
QPQDVIEW541[A]#1 PATIENTS[B]#0 QPQD_LINK[Z]#2 APPOINTMENTS[D]#3 APPOINTMENT_ITEMS[H]#4 QPQD_ROOMLINKS[I]#5 A
PPOINTMENT_ITEMS[J]#6 QPQD_LINK[QPQD_LINK]#7 EXAMINATIONS[E]#8 EXAMGROUPS[F]#9 EXAMS[C]#10 VW_NSO_3[VW_NSO_3]#11 QPQD_MACHINEL
INKS[K]#12 VW_PRIORITY_SEQUENCE_PLACER[G]#13
理論上說，14個表，那麼對應的可能的執行順序最多有：14*13*12*11*....*3*2*1種。
當然CBO不會傻到去一一嘗試，CBO會在路徑判斷中忽略大部分必定低效的執行計劃。
而其實我們要做的，就是透過各種方式，譬如CBO的parameter，來限制CBO的選擇集。CBO無用的選擇和嘗試越少，那麼解析時間就會越少。
至此卻陷入困境，不知下一步該怎麼繼續。
這個時候想起，我們嘗試了一個又一個的分析工具，有些時候卻忘記了問題本身。
檢查了若干解析慢的SQL，發現有某些共通的現象，譬如，解析都包含大量表和複雜檢視，已經巢狀若干層的IN/EXIST。
在去掉內層巢狀後，解析時間可以減少一半。
於是嘗試和巢狀/Merge有關的某些引數：
alter session set query_rewrite_enabled = false;
alter session set"_optimizer_table_expansion"=false;
alter session set "_and_pruning_enabled"=false;
alter session set "_subquery_pruning_enabled"=false;
alter session set "_optimizer_fast_access_pred_analysis" =false;
alter session set "_optimizer_sortmerge_join_enabled" = false;
alter session set "_optimizer_sortmerge_join_inequality" = false;
............
都不管用。
這個時候，回想起最開始做的嘗試：
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '9.2.0.8'; --- 0.82 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0'; --- 1.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.2.0.1'; --- 4.03 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.1.0.7'; --- 12.20 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '11.2.0.3'; --- 12.91 seconds
於是更精確的測試，然後注意到：
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0.3'; --- 1.40 seconds
ALTER SESSION SET OPTIMIZER_FEATURES_ENABLE = '10.1.0.4'; --- 3.59 seconds
我們知道OPTIMIZER_FEATURES_ENABLE會控制很多和CBO有關的引數，改變OPTIMIZER_FEATURES_ENABLE其實也是在改變這些引數。很可能是這些引數在起作用。
在之前的工作中，我記得有一個引數就是10.1.0.4引入的：
_optimizer_cost_based_transformation
這個神一般的引數自從誕生之日起，帶來了無數的血雨腥風，圍繞它產生的問題罄竹難書。難道？？？？試驗下：
alter session set "_optimizer_cost_based_transformation"=exhaustive; ---- Elapsed: 00:00:14.11
alter session set "_optimizer_cost_based_transformation"=iterative; ---- Elapsed: 00:00:13.71
alter session set "_optimizer_cost_based_transformation"=linear; ---- Elapsed: 00:00:13.97
alter session set "_optimizer_cost_based_transformation"=on; ---- Elapsed: 00:00:13.97
alter session set "_optimizer_cost_based_transformation"=off; ---- Elapsed: 00:00:03.05
在關閉這個引數後，解析時間從10多秒銳減到3秒。
之後，一股做氣，繼續測試了一些調整，透過調整CBO引數繼續控制和裁剪CBO的篩選範圍，包括禁用在10053中看到的佔有一定比例的bitmap index的推演：
alter session set "_b_tree_bitmap_plans"=false;
alter session set "optimizer_index_cost_adj" = 50;
..................
目前，此SQL解析時間已經從13秒降低到了1秒。
來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/500314/viewspace-1317401/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- 調整WebLogic的時間Web
- 系統時間的調整
- 引數調整案例總結
- linux時間調整Linux
- SQL調整：‘以空間換效能’調整一例SQL
- SQL語句效能調整原則(zt)SQL
- 調整sql臨時記錄SQL
- 一次通過stream複製解決資料單向複製的案例
- 【TOOLS】PL/SQL DEVELOPER 時間格式顯示效果調整方法SQLDeveloper
- 一些Q複製實踐的連結
- SQL優化案例一則--複合索引沒有被使用SQL優化索引
- linux調整系統時間Linux
- 隨機連結串列的複製隨機
- 故障分析 | MySQL 異地從庫複製延遲案例一則MySql
- Oracle_SQL部分_時間轉換(案例一)OracleSQL
- 透過案例學調優之--Oracle Time Model（時間模型）Oracle模型
- 調整Kali Linux的鎖屏時間Linux
- 面試題35：複雜連結串列的複製面試題
- 【資料操作】SQL語句效能調整原則SQL
- SQL最佳化案例一則--複合索引沒有被使用SQL索引
- ORACLE sql 語句的執行過程(SQL效能調整)OracleSQL
- Oracle中表的連線及其調整(一)Oracle
- js實現複製連結JS
- [Linux] ntpdate slew模式調整時間Linux模式
- Activity Monitor log儲存時間調整
- RAC環境調整系統時間
- 複製錯誤案例分享（一）
- Linux調整系統時間和時區的方法Linux
- 調整linux系統時間和時區Linux
- （轉）用NSDateFormatter調整時間格式的程式碼ORM
- 時區調整對job的執行時間的影響
- SQL Server一次SQL調優案例SQLServer
- 【Linux-時間設定】-設定時區並調整時間Linux
- linux中cp複製時處理軟連結的兩種方式Linux
- ORACLE SQL Developer4資料庫複製案例OracleSQLDeveloper資料庫
- PostgreSQL複製槽相關機制在各版本調整SQL
- 因為距上一次與此伺服器複製的時間已經超過了tombstone生存時間伺服器
- Oracle資料庫SQL語句效能調整的基本原則 （3）Oracle資料庫SQL