作者 | 劉娣，多年資料庫服務經驗、主要服務於移動經營商，具有豐富的資料庫效能優化、故障處理經驗，擅長SQL稽核和效能優化。

1. 問題背景

研發反饋某核心業務資料庫 dbtime 使用率相比昨天有了明顯的波動。

從截圖中可以看到9點到11點15分取樣區間內dbtime波動明顯，選取了11點到11點15分的awr報告分析。

2. 問題分析過程

2.1. 資料庫負載對比

相比29號同時段awr報告，30號的資料庫DBTime變化明顯，可以看到Average Active Sessions由27.3變為114.4，變化非常明顯。但是邏輯讀、IOPS、事務量變化並不是很明顯。

 

 2.2. 檢視top event

7月30日11點-11點15的awr區間內的TOP10的等待事件中，排名第一的DB CPU佔比只有32.3%，加上排名第二的log file sync，總共也不過43%左右，TOP 10加在一起不超過50%。對於這種情況而言，應該是有大量的時間資料庫沒有計算到，常見的情況為時間消耗在CPU佇列中。

 從監控系統看到11點左右CPU使用率高達59%，雖然看起來CPU不到60%，但是考慮到這個值是30秒鐘的平均值，很可能在短時間內出現CPU衝高，大量會話在CPU佇列中等待的現象。 這是一套平均CPU使用率在20%以下的系統，基本可以推斷是由於高CPU引起DBTIME波動，因此主要關注資料庫中CPU排行第一的SQL，就是SQL_ID d1h5mbfv77au，對比其他時間段發現該SQL執行頻率是平時的10多倍。

 

 2.3. 定位SQL

2.3.1. SQL語義

SQL_ID：d1h5mbfv77au

select to_char(lengthb(endnum), 'FM000') || chr(0) num_length,

      endnum,

      beginnum,

      region,

      numtype

 from tab t

where not exists (select 1

         from tab a

        where a.beginnum <= t.beginnum

          and a.endnum >= t.endnum

          and a.rowid <> t.rowid

          and lengthb(a.beginnum) = lengthb(t.beginnum))

order by 1, 2, 3;

我們來看一下where條件的語義，是需要找到滿足這樣條件的2條記錄，然後丟掉第二條，並且對於重複的資料全部去掉:

【第一條記錄的初始號段<=第二條記錄的初始號段

第一條記錄的結束號段>=第二條記錄的結束號段

不能是同一行並且初始號段的長度還要一樣】

這個SQL有去重和去掉子號段的效果，構造出這樣的兩條資料，第二條的記錄就是要被丟棄的：

我們選取表中不符合條件的幾條記錄來分析一下：

以下兩條記錄是重複的，需要全部丟棄掉；

以下兩條記錄初始號段hy00<hy_0，結束號段hyzz>hy_z，因此第二條記錄就是要被丟棄的：

2.3.2. 表和索引統計資訊

進一步看下錶的基本統計資訊，TAB表資料量5萬左右：

 

2.3.3. 執行計劃

執行計劃中CPU主要消耗在hash join anti這步,對於這種子查詢的SQL，可以強制子查詢不展開走filter的執行計劃，下面我們測試一下子查詢不展開的執行計劃：

 

filter的執行計劃消耗了1000多萬的邏輯讀，執行時間5分鐘左右，高邏輯讀也會引發高CPU；

hash join anti的執行計劃邏輯讀756，執行計劃5分鐘左右，僅是對比這兩個執行計劃的話，還是hash join anti資源消耗更低。可是仍然有個疑問：hash join怎麼會消耗這麼高的cpu？

 2.3.4. 回顧Hash連線

再解答這個疑問之前，我們先來回顧一下hash join連線：

Oracle7.3以後引入了hash join連線，這是一種在表連線的時候依靠hash運算得到關聯結果集的表連線方法，只執行在CBO優化器中，hash join只能作用於等值連線，即使是hash反連線，Oracle實際上也是將其轉化為等價的等值連線來處理。

Hash join的過程：

1、兩個表做關聯，根據where條件將過濾後的結果集計做A、B，假設關聯列是A.ID=B.ID

2、取A中的每一條資料根據關聯列ID列做兩個hash運算 計做hashvalue1  hashvalue2

3、根據hashvalue1將A中的資料分作N個partition稱作Ai和N個bucket(包含查詢列、關聯列、hashvalue2，如果Ai過大，需要將記錄數最多的bucket寫入temp)，同時Oracle會構建一個點陣圖，用來標記Ai中所包含的每一個bucket是否有記錄，如果Ai都在記憶體中，就不會啟用點陣圖過濾了。

4、讀取B中的每一條記錄並按照連線列ID做運算，計算出hashvalue1和hashvalue2，根據hashvalue1去Ai中尋找匹配的bucket並校驗，如果在匹配的bucket中找到符合條件的記錄就返回，如果找不到記錄需要去訪問步驟3中構造的點陣圖，如果點陣圖中顯示該bucket在Ai中記錄數大於0，那說明bucket對應的記錄不在記憶體在磁碟，需要將B中對應的記錄以partition的形式寫回磁碟。 

5、記憶體中的bucket對比結束後再對比temp中的，將temp裡面的bucket裡的資料根據hashvalue2重新分bucket然後匹配計算

2.3.5. 是否關聯列上的函式運算消耗過多的CPU

上面SQL的關聯列是【lengthb(a.beginnum) = lengthb(t.beginnum)】，我們知道在列上做運算是會消耗CPU資源的，所以開始猜測是因為對beginnum列做了運算導致消耗了非常多的CPU，我們先測試一下對列做函式運算是否會消耗大量的CPU資源：

test表的id列是沒有索引的，以上兩個語句走的都是全表掃描的執行計劃，但是CPU時間和執行時間相差都非常大。這兩個SQL的區別就是是否對id列做了運算。因此我們平時寫SQL的時候，儘量避免在列上做運算，會消耗額外的系統資源。

那麼我們這個SQL語句是否也是因為在關聯列上做length運算導致消耗過多的cpu呢？我們繼續測試對TAB表的beginnum欄位做length運算，測試消耗的CPU資源是否非常大：

從上面測試結果可以看出加了length運算消耗了更多的CPU（30000-20000=10000ms），比起上面的hash join執行了5分多鐘差距較大，由此可見在列上做運算的確會造成CPU資源的額外消耗，但是並不是我們這個SQL消耗CPU資源的主要原因，那麼到底為什麼hash join會消耗如此高的CPU呢？下面我們通過10104事件分析hash連線。

2.3.6. 10104分析為什麼產生高CPU

我們知道hash join是發生在PGA中的，所以它是不消耗邏輯讀的，因此上面講的這個SQL消耗的邏輯讀非常低這是能理解的，但是為什麼hash join anti這一步消耗的CPU卻非常高呢？

我們藉助10104事件所產生的trc檔案來觀察一下目標SQL在做hash連線時的大致過程和一些統計資訊（比如用了多少hash partition、多個hash bucket以及各個bucket中分別有多少條記錄），10104事件在實際診斷hash連線的效能問題時非常有用，具體過程如下：

oradebug setmypid

oradebug event 10104 trace name context forever，level 1

set autot traceonly

oradebug tracefile_name

10104事件產生的trc檔案部分內容如下：

從上面trc檔案中

Number of in-memory partitions (may have changed): 8

Final number of hash buckets: 131072

Total buckets: 131072 Empty buckets: 131048 Non-empty buckets: 24

Total number of rows: 49379

Maximum number of rows in a bucket: 31356

Average number of rows in non-empty buckets: 2057.458252

Disabled bitmap filtering: filtered rows=0 minimum required=50 out of=1000

可以看出hash連線驅動結果集的行數為49379，共分配了8個hash partition，131072個hash bucket，其中有131048個空的bucket，真正存放結果集記錄數的bucket有24個，包含最多的記錄數的bucket所含的記錄數是31356行，以及上述hash連線沒有啟用點陣圖過濾。

2.3.7. 10046檢視等待事件

我們繼續再思考一下，在該SQL高併發執行的時候資料庫有沒有什麼等待？我又生成了一份10046來繼續分析這個問題，相關trc內容如下：

===================== PARSING IN CURSOR #11529215044982124440 len=431 dep=0 uid=49 oct=3 lid=0 tim=43008810081644 hv=3439201088 ad='c000000feda18a80' sqlid='c4s85nb6gw2u0' select to_char(lengthb(endnum), 'FM000') || chr(0) num_length,        endnum,        beginnum,        region,        numtype   from tab t  where not exists (select 1           from tab a          where a.beginnum <= t.beginnum            and a.endnum >= t.endnum            and a.rowid <> t.rowid            and lengthb(a.beginnum) = lengthb(t.beginnum))  order by 1, 2, 3 END OF STMT PARSE #11529215044982124440:c=0,e=5067,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=807524954,tim=43008810081640 EXEC #11529215044982124440:c=0,e=70,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=807524954,tim=43008810081938 WAIT #11529215044982124440: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=43008810081974   然後在這裡一直卡住沒有繼續生成trc內容，檢視等待事件是 SQL*Net message to client sys@PUBDB>select event,status,sid from v$session where sql_id='c4s85nb6gw2u0'; 過了幾分鐘trc檔案內容繼續：   *** 2018-09-05 16:38:29.205 FETCH #11529215044982124440:c=367160000,e=368492595,p=0,cr=756,cu=0,mis=0,r=1,dep=0,og=1,plh=807524954,tim=43009178581250 WAIT #11529215044982124440: nam='SQL*Net message from client' ela= 863 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=43009178588631 WAIT #11529215044982124440: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=43009178588735 FETCH #11529215044982124440:c=0,e=193,p=0,cr=0,cu=0,mis=0,r=100,dep=0,og=1,plh=807524954,tim=43009178588903 WAIT #11529215044982124440: nam='SQL*Net message from client' ela= 910 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=43009178589853 WAIT #11529215044982124440: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=43009178589884 FETCH #11529215044982124440:c=0,e=212,p=0,cr=0,cu=0,mis=0,r=100,dep=0,og=1,plh=807524954,tim=43009178590091 WAIT #11529215044982124440: nam='SQL*Net message from client' ela= 891 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=43009178591017 WAIT #11529215044982124440: nam='SQL*Net message to client' ela= 0 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=43009178591045 ......

 將10046 trc檔案格式化

Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 49   Number of plan statistics captured: 2

從trc檔案可以看到該SQL在執行過程中fetch了1014次，消耗的時間是743.88秒，花在cpu上的時間是741.62秒，消耗的一致性邏輯讀是1512，fetch回的行數是101116行（對於select語句而言，有execute階段，但是execute階段的disk、query、current一般為0，都算在了fetch階段）。 資料庫對應的等待事件是【SQL*Net message to client和SQL*Net message from client】，下面解釋一下這兩個等待事件：

SQL*Net message from client

表示服務端等待著客戶端發來請求，如果客戶端一直沒有向伺服器端傳送任何請求，那麼在伺服器端會話就會處於SQL*Net message from client等待事件

SQL*Net message to client

這個等待事件發生在一個伺服器程式已經向客戶端傳送訊息或資料並等待客戶端回覆的時候，這個等待事件通常被認為是一個網路等待事件，一般意味著網路瓶頸或不正確的TCP連線配置。但是它不能做為對網路延遲的準確評估或量化。

2.3.8. ASH報告檢視SQL對應等待事件

生成該SQL的ash報告：

DB Time=所有前臺會話等待的時間=CPU時間+IO時間+非空閒等待時間+在CPU佇列中等待的時間。其中在CPU佇列中等待的時間就是CPU Wait，在ASH中可以清楚的看到CPU +Wait for CPU，這個狀態代表了一個會話正在使用CPU或者正在等待CPU來執行，是不算做Oracle的任何一種等待事件的。

故障時間段CPU的使用率最高達到59%，說明CPU資源並沒有被耗盡，並不是因為CPU不足造成的等待。Oracle程式並不是一直持有CPU資源的，程式持有CPU一段時間後會釋放CPU，然後進入CPU等待佇列中，然後繼續持有CPU或者其他IO資源，可以參照下面的圖理解：’

3. 問題結論

到這裡可以得出為什麼上面的SQL執行很久都沒有結束而且還造成了非常高的CPU：因為表中的資料length之後只有很少的distinct值，而表中絕大多數資料length之後的長度是一樣的，因此造成單個hash bucket裡面包含的記錄數太多，大部分時間消耗在遍歷bucket中所有的記錄數，而這個掃描過程是需要CPU資源的；而因為hash join發生在PGA，所以不耗費邏輯讀。
查詢表中的資料驗證：

所以length(beginnum)=11的bucket和length(beginnum)=13的bucket的兩個桶需要內部做31356*31356+17185*17185次對比的，當然就會造成大量的CPU消耗。

4. 解決方法

這是一個重新整理共享記憶體的SQL，同時會有幾十個程式併發重新整理，併發量一旦增加就會造成CPU波動明顯，研發修改程式將原來的10分鐘重新整理一次改為半小時重新整理一次，相當於控制了併發，問題得到緩解。

但是僅依靠降低併發只能暫時緩解這個問題，後續又跟研發商討出以下解決方案：

1）新增一個表把不滿足條件的結果集儲存下來，並增加一個程式定期去更新該表(該表資料量較小，只有一千多條)，只有一個程式執行這個操作： create table tab_child as select *   from tab t where exists (select 1           from tab a          where t.beginnum >= a.beginnum            and t.endnum <= a.endnum            and a.rowid <> t.rowid            and lengthb(a.beginnum) = lengthb(t.beginnum));    2）把子查詢的表替換成上述新增的表，由於子查詢的表資料量只有1000多條，hash連線的成本降低明顯： select to_char(lengthb(endnum), 'FM000') || chr(0) num_length,        endnum,        beginnum,        region,        numtype   from tab t where not exists (select 1           from tab_child a          where a.beginnum <= t.beginnum            and a.endnum >= t.endnum            and lengthb(a.beginnum) = lengthb(t.beginnum)) order by 1, 2, 3;

 就這個問題後續我又諮詢了楊長老，他認為對於這種對自關聯的SQL語句，使用分析函式改寫會有非常好的效果，上面的這個SQL效率低是因為自關聯的條件的選擇度很差，需要靠不等條件來過濾資料，而分析函式避免了自關聯，改寫之後SQL變成了一個單表掃描，執行時間由5分多鐘降為1.35秒，效能提升非常明顯：

我們關注一下max(endnum) over(partition by lengthb(beginnum) order by beginnum, endnum desc) endnum這個分析函式，其ORDER BY語句中包含了beginnum，endnum desc，這說明這個max()函式獲取的視窗範圍是按照beginnum從小到大、endnum從大到小的排序，其實就是包含了原SQL語義中想要的beginnum最小+endnum最大的要求，然後我們通過row_number() over(partition by lengthb(beginnum), endnum order by beginnum) rn =1和count(*) over(partition by lengthb(beginnum), oldendnum, beginnum) cn=1去掉所有子號段和重複的資料，這樣就保持了和原SQL同樣的語義。

Oracle裡的優化需要聯絡實際業務，有時候理解了業務場景的含義，對於我們優化SQL會有很大的幫助，上面的這則case就是根據業務含義進行了適當的改寫，改寫之後效能提升明顯：

1. 我們日常需要注意的是儘量避免在列上做運算，一個簡單的id=1 和id+1=2，消耗的資源可能會相差很大；

2. 如果遇到了自關聯的SQL，分析函式是避免自關聯的利器，可以嘗試進行改寫。

3. 實際情況中並不是所有的問題SQL在資料庫層面都有優化的方法，有些時候SQL就是沒有條件沒有辦法進一步優化，這種情況下業務層面的調整、加併發或者控制執行頻率都是可以考慮的方式。

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/31556440/viewspace-2286784/，如需轉載，請註明出處，否則將追究法律責任。