一次波折的現場服務

風雲突變的升級

 

5月２９日，咱們在大連一個重要的客戶把應用升級到新的版本，升級過程還算順利，在接下來的周6、週日全天運行正常，項目組的同事老吳等人彷佛看到了升級成功的但願，若是系統可以在週一順利運行，就能夠宣佈升級工做基本完成了。週一這天，黃曆上寫着"諸事不宜",果真到了週一上午的8:00開始，服務器的CPU資源開始很是緊張,UNIX系統平均負載達到11左右,CPU佔用基本在100%左右運行,而升級前,UNIX平均負載在0.3 如下,CPU佔用率在20%左右.出現問題之後，公司也遠程提出了一些解決方案，但畢竟是由於程序升級，致使的問題，加上醫院是5月份採購的新機器,用戶對此意見比較大,對處理的狀況也不是很滿意。在公司分析的狀況來看,問題應該是出在註冊函數上,邏輯讀很高.致使了大量的熱塊衝突。

從發過來的awr來看，性能確實到了很糟糕的地步：

1. 邏輯讀次數到了近百W/S,而升級以前全都在30W/S如下。

Load Profile

	Per Second	Per Transaction
Redo size:	57,155.04	7,476.09
Logical reads:	998,031.42	130,546.26
Block changes:	366.81	47.98
Physical reads:	91.61	11.98
Physical writes:	19.54	2.56
User calls:	1,333.07	174.37
Parses:	281.84	36.87
Hard parses:	14.85	1.94
Sorts:	137.82	18.03
Logons:	1.13	0.15
Executes:	490.68	64.18
Transactions:	7.65

2.Top Event來看，典型的熱塊衝突致使的性能降低：

 

Top 5 Timed Events

Event	Waits	Time(s)	Avg Wait(ms)	% Total Call Time	Wait Class
latch: cache buffers chains	76,560	33,283	435	48.7	Concurrency
CPU time		23,129		33.8
log file sync	28,057	2,754	98	4.0	Commit
db file sequential read	312,477	2,169	7	3.2	User I/O
log file parallel write	24,580	633	26	.9	System I/O

3. CPU資源，確實很是緊張，因爲沒有采集到OS數據，只能用AWR中的信息來計算CPU資源的利用率：

BUSY_TIME	2,411,841
IDLE_TIME	469,791

CPU%=BUSY_TIME/(BUSY_TIME+IDLE_TIME)*100%

咱們這裏的利用率爲： 2,411,841 /(2,411,841 + 469,791)*100%=83.70%,cpu平均佔用確實到了很高的地步，若是業務進一步增長，系統down機只是時間問題。

4. 註冊驗證程序相關的SQL的Buffer Gets很高，平均達到幾十萬的水平，這對於一個簡單的註冊碼驗證的簡單功能來講，過高了。

Buffer Gets	Executions	Gets per Exec	%Total	CPU Time (s)	Elapsed Time (s)	SQL Id	SQL Module	SQL Text
3,367,187,482	13,157	255,923.65	93.68	19448.75	58115.40	47vyxbdrj6zy9	ZLHIS+.exe	Select Text as 功能 From Table(C...
3,357,269,803	9,683	346,717.94	93.40	19184.41	55317.49	7rn***hwt8p84	ZLHIS+.exe	SELECT /*+ ALL_ROWS */ T_REG_...

 

乾綱專斷的會議

 

週一下午，通過遠程的一些處理狀況無明顯好轉，因而組織了幾位當事人當面溝通，肯定解決方案;與以往不一樣的是老大參加了此次的會議。討論接近尾聲，你們彷佛未就解決方案達成一致，這時候HT的眼神遊離到了個人身上，"老賀，仍是你去一趟吧？"。

會議結束已是下午5點了，幸運的定到了最後一個班航班的最後一張機票。在與公司小羅一塊兒去機場的路上，聊到幾年前的一次江湖救急，凌晨兩點去客戶現場的經歷，歷史老是驚人的類似,所不一樣的只是地域的差別；而想到即將面對的工做，與幾年前的情形並沒有二致，回憶多了，就感受本身的年華慢慢的逝去了。。。。

 

深夜的爭論

 

晚上9:30左右出了大連機場，給老婆發了個短信報平安。醫院離機場比較近，不一下子就到了醫院。到達辦公室，看到老吳、老陳等同事，彷佛都比較疲憊，你們有氣無力的寒暄了幾句，就進入正題。晚上因爲系統比較閒，能夠作一些維護，必須快速肯定實施的方案。與M主任和老孫商量解決方案,我提出直接從RBO轉到CBO下來運行，具體方案以下:

1. 利用晚上的時間收集數據庫對象的統計信息
2. 早上6:00左右改爲CBO運行,若是能在登陸高峯期8:30之前不出現CPU 100%的狀況,就能夠堅持使用CBO,出現的性能問題,經過調整應用的SQL來解決.
3. 若是不能撐過8:30,改爲RBO運行,並刪除統計信息,並收集註冊函數相關的統計信息;這步須要的時間很短,能夠快速恢復到RBO下.
4. 若是上面方案都不能起效果,就採用修改的註冊函數,取消產品的註冊驗證,繞過有問題的SQL,這一步是萬不得已的選擇，這樣作會帶來後續不少的工做和商務上的工做。

醫院是前二週剛剛從9i升級到10g的，在9i中一直使用RBO,升級到10g時，爲了與9i的執行計劃儘可能保持一致，在10g中就繼續沿用了rbo。在10g中，通常推薦使用cbo，他們也是咱們用戶中僅存的運行rbo的較大規模且比較"頑固"的用戶。使用rbo不必定是形成這次問題的緣由，但因爲時間緊迫，沒法詳細追查產生註冊函數大量邏輯讀的緣由，醫院的要求也是快速有效的解決問題；根據以往的經驗，在10g的cbo下，應用的大部分SQL是能得到相對較好的執行計劃,正是基於這一點，我提出了上述直接轉換到CBO運行的方案。

因爲醫院M主任對咱們在公司的處理狀況有意見,不太承認我提出的方案,認爲應該調整實施順序,直接使用周韜修改的註冊函數,直接上cbo的變化太大.我向其說明了各類利弊,在咱們的一再堅持下,並保證根據以往的經驗,在cbo不會有太大的問題,M主任最終贊成了咱們提出的方案；但M主任同時提醒，週二的業務量比周一還要大，若是轉換不成功，代價將會更大，同時週二李興華會帶一個目標客戶過來參觀;這樣個人壓力就更大了。這個時候，咱們知道任何技術都是有風險的，作技術要求膽大心細，這時候"膽大"的成份佔了上風，我認爲這個時候，必定的冒險精神是必須的。

 

意料以外的錯誤

 

寫好了收集統計信息後的腳本後,爲了加快收集速度,開了8個併發進程進行收集，對歷史數據採樣10%，在線數據採樣20%；用unix下的nohup放到操做系統後臺來跑，處理完腳本這時已是晚上11:30了。爲了保證次日有足夠的精力處理問題,就準備回賓館休息,老孫家離醫院很遠，我建議他與我一塊兒到醫院附近的賓館去住，明天早上一塊兒過來，這樣能多睡會兒,看得出來老孫這幾天在醫院受到的煎熬,臉上掛滿了疲憊。睡覺前感受特別餓，忽然想起今天晚上除了吃了點飛機餐，還沒吃晚飯呢，老孫和我不約而同的抱怨到作技術所承擔的壓力、微薄的收宜、身體的傷害。。。甚至談到了轉行的話題。都是些技術人員抱怨的老三篇,但仍是不得不把手機的鬧鐘設置到早上6:00，不一下子就入睡了。。。

東北的太陽起來的早，不到6:00 左右太陽就射進了窗戶,鬧鐘也響了，咱們極不情願的從牀上爬了起來。早上6:30左右到了醫院,要開腳本輸出的日誌，看到昨天的腳本有一個失敗,在收集歷史數據表出錯了,出錯的緣由是這部分由於數據很大,排序時temp表空間不夠引發的.這下麻煩了,不少應用是鏈接歷史表進行查詢的,這部分統計信息不可或缺,通過商量後,咱們決定對歷史數據的表執行5%的採樣,收集統計信息,若是能在7:40前收集完,就繼續實施cbo方案,不然就只能回退到rbo方案。同時打開郵箱,發現同事修改的註冊函數新腳本已經發過來了,實在不行就只能換函數運行.老孫這邊當即着手新函數的簡單測試,我這邊接着跑採樣收集的腳本.所幸的是在7:35左右跑完了腳本,採樣5%可否獲得相對好的執行計劃?我內心打起了鼓….

 

僅憑感受的調整

 

切換到CBO還須要調整幾個參數，接下來就是切換到cbo,修改幾個參數,切換到cbo:

optimizer_mode=all_rows

optimizer_features_enable='9.2.0.8'

設置optimizer_features_enable='9.2.0.8',能夠禁用一些10g cbo的一些新特性,保證執行計劃與9i儘可能一致,這也是一個經驗值,不少HIS的sql在10g下,因爲物理設計的緣由執行計劃比較奇怪，好比複合索引採用的較少，不少sql分別走兩個單列索引再鏈接的狀況。這樣作的另外一個緣由是大部分SQL原來在9I的時候，運行的狀況都比較好。修改完參數,醫院M主任和小T等人就到了,一看時間還不到7:50,看來M主任他們對咱們的方案仍是比較擔憂,這也是能夠理解的，RBO換CBO這件事，咱們跟醫院提過屢次了，時間上也拖好幾年了，提一次被否決一次，此次調整可以成功嗎？何況rbo到cbo也是比較大的調整了。

 

峯迴路轉

 

接下來的就是等待業務高峯的來臨,辦公室這時的氣氛忽然凝重了許多,醫院上班時間在8:00，這個時間是集中登陸的時間，若是可以撐過這個時間，就證實換CBO的方案基本可行。我在ssh的unix終端上,打開HP-UX的glance開始監控系統狀態;看着系統負載一點上來了,鏈接的用戶數也愈來愈多,一直持續到8:20左右,process達到最高值800左右,這時cpu佔用率在40-60左右波動,看來cpu可以撐過業務的最高峯了.你們都鬆了一口氣,氣氛開始變得輕鬆起來,可我仍是比較擔憂後面的應用問題，感受不可能這麼順利,雖然今天黃曆上只寫着"忌：嫁娶.安牀.探病.做竈",咱們的作的事情彷佛不是今天忌諱的範圍。。。

這個時候最怕的是電話響,擔憂的事情仍是發生了,電話不斷的打進來,HIS中的幾個經常使用功能,比之前慢.一些窗口開始出現了排隊現象.主要集中在幾個經常使用的功能上:

1. 收費界面直接切換到掛號界面
2. 掛號安排修改
3. 醫囑發送爲費用
4. LIS中的條碼生成
5. 體檢中的模塊登陸

…..

這個時候,用awr、ash或sql_trace手段提取出問題的sql，發現這些sql在rbo方式下都執行得很是好，這時老孫說"老賀，要不咱們仍是退回rbo吧？"，最不想看到的狀況仍是來了，環視一週，辦公室全部人幾乎都贊成老孫的意見，這時只有我本身支持本身了。。。

我把影響sql執行計劃幾個因素梳理了一篇：

1. 系通通計信息，如cpu時間，多塊讀時間，單塊讀時間等;經過dbms_stats.gather_system_stats收集
2. 數據庫對象的統計信息，這部分咱們已經作了
3. 優化器相關的初始化參數

　　通常狀況下，跑咱們的應用,系通通計信息不收集也問題不大，我查詢sys.aux_stats$視圖，發現cpu速度和io 相關的指標都沒有收集，用腳本收集了這部分的統計信息後，發現幾個功能的sql執行計劃已經正常。但有2個功能的sql仍是不正常,這時能影響執行計劃的就只有調整初始化參數了，由於那邊不可能快速修改應用，是期望不上的；但調整初始化參數的影響比較大，可能會影響部分正常的sql語句，最後通過在session級反覆測試，肯定如下值：

　optimizer_index_caching =50

optimizer_index_cost_adj =21

在這樣的設置下，幾個重要功能的sql 執行計劃終於都走正確了，嘗試這對參數設置的時間，反覆試了十幾種不一樣的組合，老孫在旁邊看着說，"老賀，你真是能折騰！"。

處理完些事情後，已經到了10:30了，業務高峯期已通過了，看來今天cbo的切換初步大功告成，這時候李興華帶過來參觀的用戶也來了，他們到辦公室的時候，我申出頭打了個招呼，感受咱們的調整，彷佛沒有影響到潛在客戶對軟件的映象,呵呵。。。

下午的時候，我讓老孫不斷的取awr和ash,把top sql取出來，不停的分析，又處理了些執行計劃不正常的sql;不知不覺，到了下午的6:00了。今天的調整整體來講，還算成功！咱們都長舒了一口氣。　

 

最後的虛驚

 

週二的處理還算成功，不過Ｍ主任仍是要求週三上午再觀察一下，才能讓我走，我答應了M主任的要求。晚上與老吳、老陳等人一塊兒找了很久，也沒找到一家正宗的東北菜館，吃了頓感受更象魯菜的東北菜，多是與山東隔渤海相望，確實大連的飲食習慣更象山東。吃完了飯，咱們又去了臨近的星海公園逛逛，看見了一對對年輕的情侶,生活真美好呀。。。

週三早上8:00左右，就被老吳的電話吵醒了，說醫院的體檢出了嚴重的系統性能問題；我一下懵了，不會這麼殘忍吧。。。。

等我到醫院時，老陳已經處理好體檢的sql了，剛纔的問題就是由於一個sql執行計劃不正確，致使系統總體降低明顯;原來是虛驚一場。系統順利度過了業務最繁忙的時間，cpu佔用率在15-25%之間波動，unix 平均負載全都在0.3如下，基本上與升級前的狀況相同；10:00左右，向M主任彙報了處理的狀況,贊成我打道回府。 回顧此次處理狀況，都是些比較「粗糙」的技術，因爲事發忽然，根本沒時間讓你仔細分析和測試，這個時候就只有靠直覺去解決問題。

 

回家！

 

定了下午13:55的機票 ,飛回了重慶。出了重慶機場，感嘆到今年重慶的氣候真好，難倒三峽工程對氣候的影響變好了?按照咱們家的"小傳統"，一人出差回來，另外一人必然準備好豐盛的家宴迎接。。。。回家真好！！