[20151214]exadata-豆腐渣系統的保護神.txt

[20151214]exadata-豆腐渣系統的保護神.txt

--很久以前寫的http://www.itpub.net/thread-1927992-1-1.html，忘記貼到blog，補上。

--這個完全是由感而發,這個是前幾個星期遇到的事情,由於上面統一發票格式,對程式做一些改動.
--上線後我發現一條sql語句存在問題,實際加入的部分使用union all連線起來,前面那部分以前也是存在問題的,
--我使用sql profile把執行計劃穩定下來,在加入union all後,執行計劃再次回到原來的狀態.

--其中2個表1個500M,1個7.XG,全表掃描,做bloom filter,再使用hash join連線起來,我看了大約有10臺機器在執行這個語句,
--是一個刷屏命令,30秒定時執行1次.這樣1個小時大約1200次.

--我自己執行看了大約4秒執行完成,真快!!我這次沒有使用sql profile穩定計劃,因為即使那樣,邏輯度也很高.
--我直接提交要求開發改程式碼.當然我並沒有講如何改,因為我認為開發應該很容易發現問題修改程式碼.

--結果,沒有任何人重視,就這樣一直拖了2個星期,直到星期六早上出現效能問題,我事後看了報表:

--10:11點:

Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                            Tota    Wait   % DB          
Event                                 Waits Time Avg(ms)   time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
DB CPU                                      10.8           48.9          
gc buffer busy acquire           12,869,510 4860       0   22.0 Cluster  
read by other session            10,487,086 4153       0   18.8 User I/O 
cell single block physical rea    5,050,453 1499       0    6.8 User I/O 
cell multiblock physical read     3,725,544 1301       0    5.9 User I/O 
SQL*Net more data from client       230,252 157.       1     .7 Network  
SQL*Net more data to client       4,702,358 57.2       0     .3 Network  
log file sync                       115,817 44.2       0     .2 Commit   
SQL*Net break/reset to client       137,108 37.7       0     .2 Applicatio
SQL*Net message to client        14,156,077 30.1       0     .1 Network  

--很明顯問題出在rac的內聯方面。

--檢視SQL ordered by Cluster Wait Time部分：

SQL ordered by Cluster Wait Time        DB/Inst: DBCN/dbcn1  Snaps: 5465-5466
-> %Total - Cluster Time  as a percentage of Total Cluster Wait Time
-> %Clu   - Cluster Time  as a percentage of Elapsed Time
-> %CPU   - CPU Time      as a percentage of Elapsed Time
-> %IO    - User I/O Time as a percentage of Elapsed Time
-> Only SQL with Cluster Wait Time > .005 seconds is reported
-> Total Cluster Wait Time (s):           4,863
-> Captured SQL account for   98.1% of Total

       Cluster                        Elapsed                                  
Wait Time (s)   Executions %Total    Time(s)   %Clu   %CPU    %IO    SQL Id   
-------------- ------------ ------ ---------- ------ ------ ------ -------------
       4,772.2        1,050   98.1   18,000.4   26.5   38.0   37.6 dz7bbcwhuhhp7
Module: XXX.EXE
SELECT MS_CF01.CFHM, MS_CF01.CFSB, MS_CF01.BRXM,
MS_CF01.BRID, MS_CF01.FPHM, MS_CF01.CFLX, MS_CF0
1.KFRQ, MS_CF01.CFTS, MS_CF01.FYRQ, MS_CF01.
FYCK, MS_CF01.KSDM, MS_CF01.YSDM, MS_MZXX.CZGH,

--在另外的例項2上看到:

SQL ordered by Cluster Wait Time        DB/Inst: DBCN/dbcn2  Snaps: 5465-5466
-> %Total - Cluster Time  as a percentage of Total Cluster Wait Time
-> %Clu   - Cluster Time  as a percentage of Elapsed Time
-> %CPU   - CPU Time      as a percentage of Elapsed Time
-> %IO    - User I/O Time as a percentage of Elapsed Time
-> Only SQL with Cluster Wait Time > .005 seconds is reported
-> Total Cluster Wait Time (s):               2
-> Captured SQL account for   54.4% of Total

       Cluster                        Elapsed                                  
Wait Time (s)   Executions %Total    Time(s)   %Clu   %CPU    %IO    SQL Id   
-------------- ------------ ------ ---------- ------ ------ ------ -------------
           1.0            1   56.2       13.0    7.4   73.6   11.1 b6usrg82hwsa3
Module: DBMS_SCHEDULER
call dbms_stats.gather_database_stats_job_proc ( )

--估計是系統分析了表ms_cf01導致資料大部分在第2個例項，導致出現cluster相關的等待事件。
--實際上我看最後的分析時間並沒有變化,並沒有分析成功.有點不明白?而且上面的執行時間很短僅僅13秒.
--我們正常這條語句都在例項1上執行,為什麼表ms_cf01資料大量在例項2上,還是不明白?

--例項1上：
Segments by Global Cache Buffer Busy

    % of Capture shows % of GC Buffer Busy for each top segment compared
    with GC Buffer Busy for all segments captured by the Snapshot

Owner     Tablespace Name     Object Name     Subobject Name     Obj. Type     GC Buffer Busy     % of Capture
xxxxxx_xxx     xxxxxx_xxx     MS_CF01                                TABLE     18,524,883         100.00

--實際上當時緊急修改了程式碼,但是依舊有機器在執行這條語句.我們的系統要退出才會自動升級.
--至少當時的下午已經恢復正常.

--我那這條語句在dg上執行,第1次4分鐘,第2次1分鐘多一點.

--正好前一陣子幫別人解決問題，聽說對方也準備上exadata，我感覺國內許多大單位都有意上exadata，而不願意花精力在解決程式以及
--設計的問題上。