記一次伺服器運營事故

我們的網頁遊戲伺服器上線2個月了，一直運行平穩，沒出什麼重大BUG。前兩天剛更新了一個版本，結果今天早上GM報過來一個BUG，讓我折騰了整整一天。

事情是這樣的，早上GM報告說某台伺服器上有玩家抱怨線上時間獎勵無法領取，用戶端上顯示線上時間已經到了，點擊領取伺服器卻報錯說線上時間不足。一開始懷疑是否用戶端計時和伺服器是否不同步，但很快排除了這個可能性。反覆實驗後發現是伺服器上的玩家線上時間一直沒有更新。查閱了一下伺服器代碼，玩家的線上時間變數是每隔60秒加1，這裡判斷時間間隔是用的系統的tick count，tick count是一個32位的int，單位是毫秒，每隔40天會溢出，因此就懷疑是不是tick count溢出，造成了時間判斷錯誤（但是實際上tick count迴圈相減也是能夠得到正確值的）。

雖然一時難以確定是tick count溢出造成的問題，不過還是順手把tick count改為了更加可靠的DateTime計時方式。但就在修改的過程中，GM又收到了更多的玩家抱怨，其他和時間相關的重新整理功能都報出了問題，最要命的是我們的遊戲有每日零點自動回復資源的設計，伺服器是美國太平洋時間也就是我們早上10點會自動重新整理資源，結果線上的玩家都沒有在這個時間點上重新整理資源，於是玩家開始造反了，各種投訴和抱怨不斷。

繼續查閱代碼來分析問題，零點重新整理的代碼是用的DateTime來計時的，這樣就排除了Tick count的問題，根據所掌握的情況，跟時間相關的功能都多多少少出了問題，但也不應該是代碼的問題，因為其他伺服器都正常啟動並執行。難道是系統本身的時間出了問題嗎？貌似只能這樣解釋了...不過，當你開始懷疑編譯器、系統或者硬體出問題的時候，往往是自己犯低級錯誤的時候。所以我決定在關閉、遷移伺服器之前再好好檢查一下伺服器的log記錄，以定位問題所在。

在生產環境中的伺服器是沒辦法用調試器去檢查問題的，要分析問題只能看log記錄。但是正式運營的伺服器是不開DEBUG級的log的，（開了的話每秒會輸出幾千條資訊，那就把伺服器徹底搞崩潰了），所以能夠看到的log資訊很少，也沒有發現明顯的異常出錯log，要定位這個問題就比較困難了。不過我在伺服器上整合了一個即時profile的功能，能夠統計並列印每個重要函數（感興趣的函數）的執行次數和執行時間，profile了幾次，終於發現了一條重要線索：伺服器的主定時器OnUpdate函數不執行了。因為大部分時間相關的重新整理都是在OnUpdate裡執行的，這個函數不執行可想而知伺服器問題有多嚴重，難怪玩家抱怨不斷了。

伺服器的定時器代碼是我自己實現的，之前跑了那麼久一直都沒出過問題，怎麼這次突然會出問題呢？分析了一下代碼終於找到了原因，Timer的調度函數在每次執行完Timer的事件代碼之後會重新把Timer添加到Timer隊列裡以便下次執行（如果這個Timer是多次或者無限次啟動並執行話），由於Timer函數可能因為BUG會拋異常，所以調度函數是會處理例外狀況事件並記錄出錯log的。但是在接住異常後My Code就不會再將這個Timer添加到Timer隊列裡了，從邏輯上說這個策略是為了保護服務的安全性考慮，一旦Timer函數出現了異常，那麼下次就不應該再去調度這個Timer，否則可能會不斷的出異常把伺服器拖慢甚至拖死。但是我的伺服器OnUpdate也是依賴的Timer來實現的，如果OnUpdate裡拋出了異常，OnUpdate就再也不會被執行了，這樣就出大問題了。以前沒發生過這種問題是因為我的OnUpdate代碼從來沒有出過錯，而其他的Timer事件雖然有出過異常，但都是臨時的一次性Timer，下次不會再被調度，因此掩蓋了這個問題。出了這次的事故之後，我決定把這個坑填上，即使Timer事件發生異常也保證Timer可以繼續被調度，因為頻繁的報錯總好過不知不覺的把Timer關掉，這樣有利與使用者查錯。

那麼OnUpdate怎麼會拋異常的呢？繼續翻閱了之前的伺服器log記錄，發現前面確實有好幾條異常報錯的log，其中有一條就是在OnUpdate裡拋出來的，就是這條致命的異常log引發的血案。一般伺服器在處理Bug所引發的異常時通常是採取容錯策略，也就是在靠近外層的函數上接住異常，做好記錄以備排查，然後把相關的使用者session關閉，繼續正常運行。這樣的策略可以讓伺服器存在一些BUG的情況下依然可以健壯的運行，但也容易讓人產生一些錯覺。因為之前伺服器已經穩定運行了很久了，對自己的代碼過分的自信，所以現在很少會去檢查錯誤log，很多Bug其實也就失去了被及時發現和修正的機會了。而前兩天伺服器代碼剛剛更新過，有新來的同事添加過新的功能代碼，引入新的BUG也是很正常的事情。亡羊補牢，根據伺服器上的錯誤記錄，把代碼好好檢查了一下，修正了3處會導致異常的代碼Bug。然後更新版本重啟伺服器，才把這次的運營事故圓滿的解決了。

總結一下這次的運營事故，在實踐中容錯策略和速錯策略的權衡需要更加的小心。這次的問題是由於在伺服器上更偏重容錯策略，使得問題難以在第一時間被發現，雖然容錯沒有讓這些Bug搞垮伺服器，但是問題會以另一種形式呈現，最終讓服務難以為繼。萬不可認為有了容錯就可以高枕無憂啊。