博客 / 詳情
返回[20251218]測試sql語句子光標的執行性能(21c).txt
--//以前做的測試在11g，別人提示在19c測試不出來，看了以前鏈接，感覺以前測試混亂，重新學習整理看看。
--//順便驗證當時的測試是否存在問題。
--//如果一條sql語句產生的子光標很多,除了消耗共享池內存外,也會導致執行時一些性能問題.測試看看在設置
--//session_cached_cursors=0的情況下，出現軟解析，children number 0 與children number=N執行時是否存在性能差異.
--//注：如果是軟軟解析，應該是測試不出來區別的。
--//以前測試的帖子：
d:\notes>dir /s/b "*子光標*"| grep 202108
d:\notes\2021\202108\[20210812]測試sql語句子光標的性能.txt
d:\notes\2021\202108\[20210813]關於測試sql語句子光標的性能的一些補充.txt
d:\notes\2021\202108\[20210816]測試sql語句子光標的性能2.txt
d:\notes\2021\202108\[20210816]測試sql語句子光標的性能3.txt
d:\notes\2021\202108\[20210817]測試sql語句子光標性能遇到的問題.txt
d:\notes\2021\202108\[20210818]測試sql語句子光標性能遇到的問題2.txt
d:\notes\2021\202108\[20210818]測試sql語句子光標的性能4.txt
1.環境：
SCOTT@book01p> @ ver2
==============================
PORT_STRING : x86_64/Linux 2.4.xx
VERSION : 21.0.0.0.0
BANNER : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID : 0
PL/SQL procedure successfully completed.
SYS@book> @ hidez _cursor_obsolete_threshold
SYS@book> @ pr
==============================
NUM : 3719
N_HEX : E87
CON_ID : 0
NAME : _cursor_obsolete_threshold
DESCRIPTION : Number of cursors per parent before obsoletion.
DEFAULT_VALUE : TRUE
SESSION_VALUE : 8192
SYSTEM_VALUE : 8192
ISSES_MODIFIABLE : TRUE
ISSYS_MODIFIABLE : FALSE
2.建立測試腳本：
create table job_times (sid number, time_ela number,method varchar2(20));
create table t as select rownum id ,cast('test' as varchar2(10)) name from dual ;
alter table t modify ( id not null );
create unique index i_t_id on t(id);
--//分析表略。
$ cat m13.txt
--//alter session set session_cached_cursors=0;
set verify off
variable vmethod varchar2(20);
exec :vmethod := '&&2';
alter session set optimizer_index_cost_adj = &&3;
declare
v_id number;
v_d date;
l_count PLS_INTEGER;
begin
for i in 1 .. &&1 loop
SELECT COUNT(NAME) INTO v_id FROM T WHERE ID=1;
end loop;
end ;
/
quit
--//説明：參數1表示循環次數，參數2表示method(在這裏暫時沒用)，參數3表示設置optimizer_index_cost_adj。
3.測試：
$ seq 128 | xargs -IQ sqlplus -s -l scott/book@book01p @m13.txt 6 xx Q > /dev/null
--//產生128個子光標.
--//每個情況執行6次,保證其在共享池中.sql_id='5zfc9hksnyp90',注意sql語句全部大寫，因為PL/SQL內部做了轉化為大寫。
SYS@book> @ s2h 5zfc9hksnyp90
SQL_ID HASH_VALUE HASH_HEX KGL_BUCKET KGL_BUCKET_HEX
------------- ----------- --------- ---------- --------------
5zfc9hksnyp90 2974766368 b14f5520 87328 15520
--//修改m13.txt腳本，取消alter session set session_cached_cursors=0;的註解：
$ cat m13.txt
alter session set session_cached_cursors=0;
set verify off
variable vmethod varchar2(20);
exec :vmethod := '&&2';
alter session set optimizer_index_cost_adj = &&3;
declare
v_id number;
v_d date;
l_count PLS_INTEGER;
begin
for i in 1 .. &&1 loop
SELECT COUNT(NAME) INTO v_id FROM T WHERE ID=1;
end loop;
end ;
/
quit
--//設置session_cached_cursors=0;這樣每次都是軟解析。
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 1 > /dev/null
real 0m13.484s
user 0m0.232s
sys 0m0.012s
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 128 > /dev/null
real 0m14.704s
user 0m0.240s
sys 0m0.013s
--//顯然兩者差距不是很明顯。但是確實與以前的測試存在很大的不同，我以前的測試children number 0的很慢，children number 127
--//的最快，而現在卻反了過來.
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 64 > /dev/null
real 0m9.641s
user 0m0.235s
sys 0m0.010s
--//中間的反而很快。
4.在11g下重複測試：
SCOTT@book> @ ver1
PORT_STRING VERSION BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
--//建表以及前面的一些步驟不再貼出,僅僅貼出測試結果：
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 1 > /dev/null
real 0m13.374s
user 0m0.191s
sys 0m0.007s
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 128 > /dev/null
real 0m6.199s
user 0m0.194s
sys 0m0.004s
--//確實childnum=127的最快。
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 64 > /dev/null
real 0m9.844s
user 0m0.192s
sys 0m0.014s
--//我當時的結論就是oracle 11g在查詢合適子光標時從最新的子光標開始探查，如何合適採用該執行計劃。這樣children number 0最
--//後探查，選擇children number 0的執行計劃時最慢的，而optimizer_index_cost_adj = 128，馬上探查到，因此執行最快。
--//而且實際上按照CursorDiagnosticsNodes的順序來探查(注：當時僅僅是猜測)
SYS@book> oradebug setmypid
Statement processed.
SYS@book> oradebug dump library_cache 10
Statement processed.
--//查看轉儲文件：
...
CursorDiagnosticsNodes:
ChildNode: ChildNumber=127 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 128 1
ChildNode: ChildNumber=126 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 127 128
ChildNode: ChildNumber=125 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 126 127
ChildNode: ChildNumber=124 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 125 126
....
ChildNode: ChildNumber=74 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 75 76
....
ChildNode: ChildNumber=8 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 9 10
ChildNode: ChildNumber=7 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 8 9
ChildNode: ChildNumber=6 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 7 8
ChildNode: ChildNumber=5 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 6 7
ChildNode: ChildNumber=4 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 5 6
ChildNode: ChildNumber=3 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 4 5
ChildNode: ChildNumber=2 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 3 4
ChildNode: ChildNumber=1 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 2 3
ChildNode: ChildNumber=0 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 1 2
--//當前確實沒有驗證自己的判斷，其實也很容易驗證：
SYS@book> alter system flush shared_pool;
System altered.
SYS@book> /
System altered.
SYS@book> @ sharepool/shp4 5zfc9hksnyp90 -1
no rows selected
$ shuf -i 1-128 | xargs -IQ sqlplus -s -l scott/book@book01p @m13.txt 6 xx Q > /dev/null
--//這樣整個子光標對應optimizer_index_cost_adj的值是亂的。
SYS@book> @ ti
New tracefile_identifier = /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_5203_0002.trc
SYS@book> oradebug dump library_cache 10
Statement processed.
--//查看轉儲文件：
NamespaceDump:
Parent Cursor: sql_id=5zfc9hksnyp90 parent=0x896e4150 maxchild=128 plk=n ppn=n
CursorDiagnosticsNodes:
ChildNode: ChildNumber=126 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 70 53
ChildNode: ChildNumber=125 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 106 70
ChildNode: ChildNumber=124 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 119 106
ChildNode: ChildNumber=123 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 94 119
ChildNode: ChildNumber=122 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 126 94
ChildNode: ChildNumber=121 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 33 126
ChildNode: ChildNumber=120 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 79 33
ChildNode: ChildNumber=119 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 99 79
...
ChildNode: ChildNumber=4 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 43 124
ChildNode: ChildNumber=3 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 64 43
ChildNode: ChildNumber=2 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 120 64
ChildNode: ChildNumber=1 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 26 120
ChildNode: ChildNumber=0 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 65 26
--//這樣最快是optimizer_index_cost_adj=70,奇怪僅僅看到127個子光標,查詢不到optimizer_index_cost_adj=53,沒有像前面形成1個
--//環，應該optimizer_index_cost_adj=53的子光標的執行最快。
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 70 > /dev/null
real 0m6.667s
user 0m0.195s
sys 0m0.006s
--//最慢是optimizer_index_cost_adj=65
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 65 > /dev/null
real 0m12.753s
user 0m0.188s
sys 0m0.010s
$ time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx 53 > /dev/null
real 0m6.208s
user 0m0.192s
sys 0m0.011s
--//該測試驗證我的判斷。
5.回到21c為什麼出現這樣的情況呢？
$ seq 10 10 120 | xargs -IQ bash -c "time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx Q" > /dev/null
real 0m12.289s
user 0m0.241s
sys 0m0.011s
real 0m11.869s
user 0m0.205s
sys 0m0.012s
real 0m11.320s
user 0m0.259s
sys 0m0.018s
real 0m11.146s
user 0m0.243s
sys 0m0.014s
real 0m10.056s
user 0m0.240s
sys 0m0.016s
real 0m9.520s
user 0m0.245s
sys 0m0.013s
real 0m9.001s
user 0m0.213s
sys 0m0.017s
real 0m8.086s
user 0m0.215s
sys 0m0.015s
real 0m7.884s
user 0m0.261s
sys 0m0.010s
real 0m7.274s --//100,對應的child_num=99.因為child_num從0開始。
user 0m0.245s
sys 0m0.010s
real 0m14.090s --//110
user 0m0.254s
sys 0m0.014s
real 0m14.009s
user 0m0.242s
sys 0m0.011s
--//100到110出現跳躍。
$ seq 100 1 110 | xargs -IQ bash -c "time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx Q 2>&1" > /dev/null | grep real
--//最後的grep不起作用,該問題先放一放。
real 0m7.173s --//100
user 0m0.237s
sys 0m0.013s
real 0m13.097s --//101
user 0m0.245s
sys 0m0.007s
real 0m13.129s
user 0m0.251s
sys 0m0.004s
real 0m13.714s
user 0m0.238s
sys 0m0.009s
real 0m13.674s
user 0m0.218s
sys 0m0.011s
real 0m13.796s
user 0m0.217s
sys 0m0.011s
real 0m13.426s
user 0m0.207s
sys 0m0.014s
real 0m13.191s
user 0m0.210s
sys 0m0.010s
real 0m13.495s
user 0m0.253s
sys 0m0.006s
real 0m13.871s
user 0m0.249s
sys 0m0.009s
real 0m13.618s
user 0m0.219s
sys 0m0.017s
--//100與101的測試差距巨大。
$ seq 101 128 | xargs -IQ bash -c "time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx Q 2>&1" > /dev/null | grep real
real 0m13.230s
user 0m0.240s
sys 0m0.013s
real 0m13.352s
user 0m0.235s
sys 0m0.010s
real 0m13.464s
user 0m0.255s
sys 0m0.013s
real 0m13.965s
user 0m0.202s
sys 0m0.008s
real 0m13.295s
user 0m0.212s
sys 0m0.006s
real 0m13.308s
user 0m0.217s
sys 0m0.010s
real 0m13.473s
user 0m0.251s
sys 0m0.011s
real 0m13.473s
user 0m0.250s
sys 0m0.010s
....
real 0m14.362s
user 0m0.254s
sys 0m0.014s
real 0m14.147s
user 0m0.201s
sys 0m0.010s
real 0m14.136s
user 0m0.201s
sys 0m0.008s
real 0m14.375s
user 0m0.253s
sys 0m0.016s
real 0m15.316s
user 0m0.249s
sys 0m0.015s
real 0m14.224s
user 0m0.243s
sys 0m0.008s
real 0m14.389s
user 0m0.249s
sys 0m0.016s
--//相鄰的測試存在一些小誤差，不過還是可以看出探查的規律，從ChildNumber=99作為分界點開始向ChildNumber=0探查，然後再從
--//ChildNumber=100->ChildNumber=127.
--//這樣ChildNumber=99最快，
--//至於出現更多子光標會出現什麼情況，就不是很清楚了，還給繼續測試....
--//註解alter session set session_cached_cursors=0;，如下寫法可以過濾real的信息。
$ seq 100 1 104 | xargs -IQ bash -c "time sqlplus -s -l scott/book@book01p @m13.txt 2e5 xx Q 2>&1 > /dev/null" 2>&1 | grep real
real 0m3.434s
real 0m3.439s
real 0m3.603s
real 0m3.508s
real 0m3.287s
--//可以發現軟軟解析，就看不到前面的情況了。每次僅僅需要3.X秒完成。
6.另外測試了產生1000個子光標的情況下,直接貼出測試結果，情況應該與前面的測試類似。
$ cat m13b.txt
alter session set session_cached_cursors=0;
set verify off
variable vmethod varchar2(20);
exec :vmethod := '&&2';
alter session set optimizer_index_cost_adj = &&3;
declare
v_id number;
v_d date;
l_count PLS_INTEGER;
begin
for i in 1 .. &&1 loop
SELECT /*+ &&2 */ COUNT(*) into v_id FROM T WHERE ID=1;
end loop;
end ;
/
--//quit
--//注：註解最後一行的quit。
--//產生1000個子光標，每個情況執行5次，儘可能保存在共享池。
$ sqlplus -s -l scott/book@book01p <<EOF > /dev/null
$(seq 1000 | xargs -IQ echo @m13b.txt 5 e Q)
quit
EOF
SYS@book> select count(*) from v$sql where sql_id='622knv3914c8h';
COUNT(*)
----------
1000
--//修改m13b.txt，取消最後一行註解。
$ cat m13b.txt
alter session set session_cached_cursors=0;
set verify off
variable vmethod varchar2(20);
exec :vmethod := '&&2';
alter session set optimizer_index_cost_adj = &&3;
declare
v_id number;
v_d date;
l_count PLS_INTEGER;
begin
for i in 1 .. &&1 loop
SELECT /*+ &&2 */ COUNT(*) into v_id FROM T WHERE ID=1;
end loop;
end ;
/
quit
$ time sqlplus -s -l scott/book@book01p @m13b.txt 1e5 e 1 > /dev/null
real 0m6.713s
user 0m0.265s
sys 0m0.011s
$ time sqlplus -s -l scott/book@book01p @m13b.txt 1e5 e 99 > /dev/null
real 0m3.411s
user 0m0.236s
sys 0m0.007s
$ time sqlplus -s -l scott/book@book01p @m13b.txt 1e5 e 100 > /dev/null
real 0m3.505s
user 0m0.221s
sys 0m0.009s
$ time sqlplus -s -l scott/book@book01p @m13b.txt 1e5 e 101 > /dev/null
real 0m6.220s
user 0m0.241s
sys 0m0.008s
$ time sqlplus -s -l scott/book@book01p @m13b.txt 1e5 e 1000 > /dev/null
real 0m32.869s
user 0m0.254s
sys 0m0.009s
--//完全符合我前面測試的規律。
7.補充：
--//另外仔細看了以前的測試筆記，在11g下也遇到中間的某個子光標查詢變快的情況，發現該子光標刷出共享池。
--//換一句話講，前面看到的"規律"僅僅是全部子光標都在的情況下才正確。其探查按照轉儲library_cache中CursorDiagnosticsNodes
--//顯示順序相關.
--//順便貼上當時在11g測試遇到的情況，以下是library_cache轉儲該語句的相關部分：
--//ChildNumber=19到ChildNumber=50 被刷出共享池，執行時又回來，但是順序與以前不同。這樣執行計劃選擇
--//optimizer_index_cost_adj= 48突然變快了.
--//如果按照這個推測，21c應該按照CursorDiagnosticsNodes的順序，從最底下100行對應的子光標開始探查，探查到chile_number=0,
--//然後從101行對應的子光標探查，到最後的子光標。
--//當然這些都是我的猜測，對不對不知道。
--//以下是當時library_cache轉儲該語句的相關部分：
NamespaceDump:
Parent Cursor: sql_id=5zfc9hksnyp90 parent=0x7c5502d0 maxchild=128 plk=n ppn=n
CursorDiagnosticsNodes:
ChildNode: ChildNumber=50 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 51 1
ChildNode: ChildNumber=49 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 50 1
ChildNode: ChildNumber=48 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 49 1
ChildNode: ChildNumber=47 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 48 1
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
ChildNode: ChildNumber=46 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 47 1
ChildNode: ChildNumber=45 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 46 1
ChildNode: ChildNumber=44 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 45 1
ChildNode: ChildNumber=43 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 44 1
ChildNode: ChildNumber=42 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 43 1
ChildNode: ChildNumber=41 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 42 1
ChildNode: ChildNumber=39 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 40 1
ChildNode: ChildNumber=38 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 39 1
ChildNode: ChildNumber=40 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 41 1
ChildNode: ChildNumber=37 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 38 1
ChildNode: ChildNumber=36 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 37 1
ChildNode: ChildNumber=35 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 36 1
ChildNode: ChildNumber=34 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 35 1
ChildNode: ChildNumber=28 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 29 1
ChildNode: ChildNumber=27 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 28 1
ChildNode: ChildNumber=26 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 27 1
ChildNode: ChildNumber=25 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 26 1
ChildNode: ChildNumber=24 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 25 1
ChildNode: ChildNumber=23 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 24 1
ChildNode: ChildNumber=22 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 23 1
ChildNode: ChildNumber=21 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 22 1
ChildNode: ChildNumber=20 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 21 1
ChildNode: ChildNumber=19 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 20 1
ChildNode: ChildNumber=127 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 128 1
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
ChildNode: ChildNumber=126 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 127 128
ChildNode: ChildNumber=125 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 126 127
ChildNode: ChildNumber=124 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 125 126
ChildNode: ChildNumber=123 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 124 125
ChildNode: ChildNumber=122 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 123 124
ChildNode: ChildNumber=121 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 122 123
ChildNode: ChildNumber=120 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 121 122
ChildNode: ChildNumber=119 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 120 121
ChildNode: ChildNumber=118 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 119 120
ChildNode: ChildNumber=117 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 118 119
ChildNode: ChildNumber=116 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 117 118
ChildNode: ChildNumber=115 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 116 117
ChildNode: ChildNumber=114 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 115 116
ChildNode: ChildNumber=113 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 114 115
ChildNode: ChildNumber=112 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 113 114
ChildNode: ChildNumber=111 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 112 113
ChildNode: ChildNumber=110 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 111 112
ChildNode: ChildNumber=109 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 110 111
ChildNode: ChildNumber=108 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 109 110
ChildNode: ChildNumber=107 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 108 109
ChildNode: ChildNumber=106 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 107 108
ChildNode: ChildNumber=105 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 106 107
ChildNode: ChildNumber=104 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 105 106
ChildNode: ChildNumber=103 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 104 105
ChildNode: ChildNumber=102 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 103 104
ChildNode: ChildNumber=101 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 102 103
ChildNode: ChildNumber=100 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 101 102
....
ChildNode: ChildNumber=52 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 53 54
ChildNode: ChildNumber=51 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 52 53
ChildNode: ChildNumber=33 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 34 35
ChildNode: ChildNumber=32 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 33 34
ChildNode: ChildNumber=31 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 32 33
.....
ChildNode: ChildNumber=8 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 9 10
ChildNode: ChildNumber=7 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 8 9
ChildNode: ChildNumber=6 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 7 8
ChildNode: ChildNumber=5 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 6 7
ChildNode: ChildNumber=4 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 5 6
ChildNode: ChildNumber=3 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 4 5
ChildNode: ChildNumber=2 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 3 4
ChildNode: ChildNumber=1 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 2 3
ChildNode: ChildNumber=0 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 1 2
AgedOutCursorDiagnosticNodes:
ChildNode: ChildNumber=50 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 51 1
ChildNode: ChildNumber=49 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 50 1
ChildNode: ChildNumber=48 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 49 1
ChildNode: ChildNumber=47 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 48 1
ChildNode: ChildNumber=46 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 47 1
ChildNode: ChildNumber=45 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 46 1
ChildNode: ChildNumber=44 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 45 1
ChildNode: ChildNumber=43 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 44 1
ChildNode: ChildNumber=42 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 43 1
ChildNode: ChildNumber=41 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 42 1
ChildNode: ChildNumber=39 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 40 1
ChildNode: ChildNumber=38 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 39 1
ChildNode: ChildNumber=50 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 51 52
ChildNode: ChildNumber=49 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 50 51
ChildNode: ChildNumber=48 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 49 50
ChildNode: ChildNumber=47 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 48 49
ChildNode: ChildNumber=46 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 47 48
ChildNode: ChildNumber=45 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 46 47
ChildNode: ChildNumber=44 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 45 46
ChildNode: ChildNumber=43 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 44 45
ChildNode: ChildNumber=42 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 43 44
ChildNode: ChildNumber=41 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 42 43
ChildNode: ChildNumber=40 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 41 42
ChildNode: ChildNumber=39 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 40 41
ChildNode: ChildNumber=38 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 39 40
ChildNode: ChildNumber=37 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 38 39
ChildNode: ChildNumber=36 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 37 38
ChildNode: ChildNumber=35 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 36 37
ChildNode: ChildNumber=34 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 35 36
ChildNode: ChildNumber=28 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 29 30
ChildNode: ChildNumber=27 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 28 29
ChildNode: ChildNumber=26 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 27 28
ChildNode: ChildNumber=25 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 26 27
ChildNode: ChildNumber=24 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 25 26
ChildNode: ChildNumber=23 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 24 25
ChildNode: ChildNumber=22 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 23 24
ChildNode: ChildNumber=21 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 22 23
ChildNode: ChildNumber=20 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 21 22
ChildNode: ChildNumber=19 ID=3 reason=Optimizer mismatch(12) size=2x228 optimizer_index_cost_adj= 20 21
