如何使錯誤日誌更加方便地排查問題

發表於2015-03-09

在程式中打錯誤日誌的主要目標是為更好地排查問題和解決問題提供重要線索和指導。但是在實際中打的錯誤日誌內容和格式變化多樣,錯誤提示上可能殘缺不全、沒有相關背景、不明其義,使得排查解決問題成為非常不方便或者耗時的操作。而實際上,如果程式設計的時候稍加用心,就會減少排查問題的很多無用功。 在闡述如何編寫有效的錯誤日誌之前, 瞭解錯誤是怎麼產生的,  非常重要。

錯誤是如何煉成的

對於當前系統來說, 錯誤的產生由三個地方引入:

1.  上層系統引入的非法引數。 對於非法引數引入的錯誤, 可以通過引數校驗和前置條件校驗來截獲錯誤;

2.  與下層系統互動產生的錯誤。 與下層互動產生的錯誤, 有兩種:

a.  下層系統處理成功了,但是通訊出錯了, 這樣會導致子系統之間的資料不一致;

對於這種情況, 可以採用超時補償機制,預先將任務記錄下來,通過定時任務在後續將資料訂正過來。

更好的設計方案 ?

b.  通訊成功了,但是下層處理出錯了。

對於這種情況, 需要與下層開發人員溝通, 協調子系統之間的互動;

需要根據下層返回的錯誤碼和錯誤描述做適當的處理或給予合理的提示資訊。

無論哪一種情況, 都要假設下層系統可靠性一般, 做好出錯的設計考慮。

3.  本層系統處理出錯。

本層系統產生錯誤的原因:

原因一: 疏忽導致。疏忽是指程式設計師能力完全可避免此類錯誤但實際上沒做到。比如將 && 敲成了 & , == 敲成了 = ;  邊界錯誤, 複合邏輯判斷錯誤等。 疏忽要麼是程式設計師注意力不夠集中, 比如處於疲倦狀態、加班通宵、邊開會邊寫程式; 要麼是急著實現功能,沒有顧及程式的健壯性等。

改進措施:  使用程式碼靜態分析工具,通過單元測試行覆蓋可有效避免此類問題。

原因二: 錯誤與異常處理不夠周全導致的。 比如輸入問題。 計算兩個數相加, 不僅要考慮計算溢位問題, 還要考慮輸入非法的情形。對於前者,可能通過了解、犯錯或經驗就可以避免, 而對於後者,則必須加以限定,以使之處於我們的智商能夠控制的範圍內,比如使用正規表示式過濾掉不合法的輸入。對於正規表示式必須進行測試。對於不合法輸入, 要給出儘可能詳細、易懂、友好的提示資訊、原因及建議方案。

改進措施:  儘可能周全地考慮各種錯誤情形和異常處理。在實現主流程之後,增加一個步驟:仔細推敲可能的各種錯誤和異常,返回合理錯誤碼和錯誤描述。每個介面或模組都有效處理好自己的錯誤和異常,可有效避免因場景互動複雜導致的bug. 譬如,一個業務用例由場景A.B.C互動完成。實際執行A.B成功了,C失敗了,這時B需要根據C返回合理的程式碼和訊息進行回滾並返回給A合理的程式碼和訊息,A根據B的返回進行回滾,並返回給客戶端合理的程式碼和訊息。這是一種分段回滾的機制,要求每個場景都必須考慮異常情況下的回滾。

原因三: 邏輯耦合緊密導致。 由於業務邏輯耦合緊密, 隨著軟體產品一步步發展, 各種邏輯關係錯綜複雜, 難以看到全域性狀況, 導致區域性修改影響波及到全域性範圍,造成不可預知的問題。

改進措施:  編寫短函式和短方法, 每個函式或方法最好不超過 50 行。 編寫無狀態函式和方法, 只讀全域性狀態, 相同的前提條件總是會輸出相同的結果, 不會依賴外部狀態而變更自己的行為; 定義合理的結構、 介面和邏輯段, 使介面之間的互動儘可能正交、低耦合; 對於服務層, 儘可能提供簡單、正交的介面; 持續重構, 保持應用模組化和鬆耦合, 理清邏輯依賴關係。對於有大量業務介面相互影響的情況, 必須整理各個業務介面的邏輯流程及相互依賴關係, 從整體上進行優化; 對於有大量狀態的實體, 也需要梳理相關的業務介面, 整理狀態之間的轉換關係。

原因四: 演算法不正確導致。

改進措施: 首先將演算法從應用中分離出來。 若演算法有多種實現, 可以通過交叉校驗的單元測試找出來, 比如排序操作; 如果演算法具有可逆性質, 可以通過可逆校驗的單元測試找出來, 比如加密解密操作。

原因五: 相同型別的引數,傳入順序錯誤導致。比如,modifyFlow(int rx, int tx), 實際呼叫為 modifyFlow(tx,rx)

改進措施: 儘可能使型別具體化, 該用浮點數就用浮點數, 該用字串就用字串, 該用具體物件型別就用具體物件型別; 相同型別的引數儘可能錯開; 如果上述都無法滿足, 就必須通過介面測試來驗證, 介面引數值務必是不同的。

原因六: 空指標異常。 空指標異常通常是物件沒有正確初始化, 或者使用物件之前沒有對物件是否非空做檢測。

改進措施: 對於配置物件, 檢測其是否成功初始化; 對於普通物件, 獲取到實體物件使用之前, 檢測是否非空。

原因七: 網路通訊錯誤。 網路通訊錯誤通常是因為網路延遲、阻塞或不通導致的錯誤。網路通訊錯誤通常是小概率事件, 但小概率事件很可能會導致大面積的故障、 難以復現的BUG。

改進措施: 在前一個子系統的結束點和後一個子系統的入口點分別打 INFO 日誌。 通過兩者的時間差提供一點線索。

原因八: 事務與併發錯誤。 事務與併發結合在一起, 很容易產生非常難以定位的錯誤。

改進措施:  對於程式中的併發操作, 涉及到共享變數及重要狀態修改的, 要加 INFO 日誌。更有效的做法???

原因九: 配置錯誤。

改進措施: 在啟動應用或啟動相應配置時, 檢測所有的配置項,  列印相應的INFO日誌,  確保所有配置都載入成功。

原因十: 業務不熟悉導致的錯誤。 在中大型系統, 部分業務邏輯和業務互動都比較複雜, 整個的業務邏輯可能存在於多個開發同學的大腦裡, 每個人的認識都不是完整的。這很容易導致業務編碼錯誤。

改進措施: 通過多人討論和溝通, 設計正確的業務用例, 根據業務用例來編寫和實現業務邏輯; 最終的業務邏輯和業務用例必須完整存檔; 在業務介面中註明該業務的前置條件、處理邏輯、後置校驗和注意事項; 當業務變化時, 需要同步更新業務註釋; 程式碼REVIEW。 業務註釋是業務介面的重要文件, 對業務理解起著重要的快取作用。

原因十一: 設計問題導致的錯誤。比如同步序列方式會有效能、響應慢的問題, 而併發非同步方式可以解決效能、響應慢的問題, 但會帶來安全、正確性的隱患。非同步方式會導致程式設計模型的改變, 新增非同步訊息推送和接收等新的問題。使用快取能夠提高效能, 但是又會存在快取更新的問題。

改進措施: 編寫和仔細評審設計文件。 設計文件必須闡述背景、需求、所滿足的業務目標、要達到的業務效能指標、可能的影響、設計總體思路、詳細方案、預見該方案的優缺點及可能的影響; 通過測試和驗收, 確保改設計方案確實滿足業務目標和業務效能指標。

原因十二: 未知細節問題導致的錯誤。 比如緩衝區溢位、 SQL 注入攻擊。 從功能上看是沒有問題的, 但是從惡意使用上看, 是存在漏洞的。 再比如, 選擇 jackson 庫做 JSON 字串解析, 預設情況下, 當物件新增欄位時會導致解析出錯。必須在物件上加 @JsonIgnoreProperties(ignoreUnknown = true) 註解才能正確應對變化。如果選用其他 JSON 庫就不一定有這個問題。

改進措施:  一方面要通過經驗積累, 另一方面, 考慮安全問題和例外情況, 選擇成熟的經過嚴格測試的庫。

原因十三: 隨時間變化而出現的bug。有些解決方案在過去看來是很不錯的,但在當前或者未來的情景中可能變得笨拙甚至不中用,也是常見的事情。比如像加密解密演算法, 在過去可能認為是完善的, 在破解之後就要慎重使用了。

改進措施:  關注變化以及漏洞修復訊息,及時修正過時的程式碼、庫、行為。

原因十四: 硬體相關的錯誤。 比如記憶體洩露, 儲存空間不足,  OutOfMemoryError 等。

改進措施: 增加對應用系統的 CPU / 記憶體 / 網路等重要指標的效能監控。

系統出現的常見錯誤:

  1. 實體在資料庫中的記錄不存在, 必須指明是哪個實體或實體標識;
  2. 實體配置不正確, 必須指明是哪個配置有問題,正確的配置應該是什麼;
  3. 實體資源不滿足條件, 必須指明當前資源是什麼,資源要求是什麼;
  4. 實體操作前置條件不滿足, 必須指明需要滿足什麼前置條件,當前的狀態是什麼;
  5. 實體操作後置校驗不滿足, 必須指明需要滿足什麼後置校驗, 當前的狀態是什麼;
  6. 效能問題導致超時, 必須指明是什麼導致的效能問題,後續如何優化;
  7. 多個子系統互動通訊出錯導致之間的狀態或資料不一致?

一般難以定位的錯誤會出現在比較底層的地方。 因為底層無法預知具體的業務場景, 給出的錯誤訊息都是比較通用的。

這就要求在業務上層提供儘可能豐富的線索。錯誤的產生一定是多個系統或層次互動的過程中在某一層棧上不滿足前置條件導致。在程式設計時, 在每一層棧中儘可能確保所有必須的前置條件滿足,儘可能避免錯誤的引數傳遞到底層, 儘可能地將錯誤截獲在業務層。

大多數錯誤都是由多種原因組合產生。 但每一種錯誤必定有其原因。 在解決錯誤之後, 要深入分析錯誤是如何發生的, 如何避免這些錯誤再次發生。 努力就能成功, 但是: 反思才能進步 !

如何編寫更容易排查問題的錯誤日誌

打錯誤日誌的基本原則:

  1. 儘可能完整。 每一條錯誤日誌都完整描述了: 什麼場景下發生了什麼錯誤, 什麼原因(或者哪些可能原因), 如何解決(或解決提示);
  2. 儘可能具體。 比如 NC 資源不足, 究竟具體指什麼資源不足, 是否可以通過程式直接指明; 通用錯誤,比如 VM NOT EXIST , 要指明在什麼場景下發生的,可能便於後續統計的工作。
  3. 儘可能直接。 最理想的錯誤日誌應該讓人在第一直覺下能夠知道是什麼原因導致,該怎麼去解決,而不是還要通過若干步驟去查詢真正的原因。
  4. 將已有經驗整合直接到系統中。 所有已經解決過的問題及經驗都要儘可能以友好的方式整合到系統中,給新進人員更好的提示,而不是埋藏在其他地方。
  5. 排版要整潔有序, 格式統一化規範化。 密密麻麻、隨筆式的日誌看著就揪心, 相當不友好, 也不便於排查問題。
  6. 採用多個關鍵字唯一標識請求,突出顯示關鍵字: 時間、實體標識(比如vmname)、操作名稱。

排查問題的基本步驟:

登入到應用伺服器 -> 開啟日誌檔案 -> 定位到錯誤日誌位置 -> 根據錯誤日誌的線索的指導去排查、確認問題和解決問題。

其中:

  1. 從登陸到開啟日誌檔案: 由於應用伺服器有多臺, 要逐一登入上去檢視實在不方便。 需要編寫一個工具放在 AG 上直接在 AG 上檢視所有伺服器日誌, 甚至直接篩選出所需要的錯誤日誌。
  2. 定位錯誤日誌位置。 目前日誌的排版密密麻麻,不易定位到錯誤日誌。一般可以先採用”時間”來定位到錯誤日誌的附近前面的地方, 然後使用 實體關鍵字 / 操作名稱 組合來鎖定錯誤日誌地方。 根據 requestId 定位錯誤日誌雖然比較符合傳統,但是要先找到 requestId , 並且不具有描述性。最好能直接根據時間/內容關鍵字來定位錯誤日誌位置。
  3. 分析錯誤日誌。 錯誤日誌的內容最好能夠更加直接明瞭, 能夠明確指明與當前要排查的問題特徵是吻合的, 並且給出重要線索。

通常, 程式錯誤日誌的問題就是日誌內容是針對當前程式碼情境才能理解,看上去簡潔, 但總是寫的不全, 半英文格式;一旦離開程式碼情境, 就很難知道究竟說的是什麼, 非要讓人思考一下或者去看看程式碼才能明白日誌說的是什麼含義。 這不是自己給自己罪受?

比如:

zone 要支援什麼 storage type 才是正確的?   Do Not Let Me Think !

錯誤日誌應該做到: 即使離開程式碼情境,也能清晰地描述發生了什麼。

此外,如果能夠直接在錯誤日誌中說明清楚原因, 在做巡檢日誌的時候也可以省些力氣。

從某種意義上來說, 錯誤日誌也可以是一種非常有益的文件,記錄著各種不合法的執行用例。

目前程式錯誤日誌的內容可能存在如下問題:

1.  錯誤日誌沒有指明錯誤引數和內容:

沒有指明插入失敗的 control ip. 如果加上 control ip 關鍵字, 更容易搜尋和鎖定錯誤。

類似的還有:

log.error(“Get some errors when insert subnet and its IPs into database. Add subnet or IP failure.”, e);

沒有指明是哪個 subnet 的它下屬的哪些 IP. 值得注意的是, 要指明這些要額外做一些事情, 可能會稍微影響效能。這時候需要權衡效能和可除錯性。

解決方案: 使用 String.format(“Some msg to ErrorObj: %s”, errobj) 方法指明錯誤引數及內容。

這通常要求對 DO 物件編寫可讀的 toString 方法。

2.  錯誤場景不明確:

log.error(“nc has exist, nc ip” + request.getIp());

在 createNc 中檢測到 NC 已經存在報錯。 但是日誌上沒有指明錯誤場景, 讓人猜測,為什麼會報NC已存在錯誤。

可以改為

log.error(“nc has exist when want to create nc, please check nc parameters. Given nc ip: ” + request.getIp());

log.error(“[create nc] nc has exist, please check nc parameters. Given nc ip: ” + request.getIp());

類似的還有:

log.error(“not all vm destroyed, nc id ” + request.getNcId());

改成 log.error(“[delete nc] some vms [%s] in the nc are not destroyed. nc id: %s”, vmNames, request.getNcId());

解決方案: 錯誤訊息加上 when 字句, 或者錯誤訊息前加上 【介面名】,  指明錯誤場景,直接從錯誤日誌就知道明白了。一般能夠知道 executor 的可以加上 【介面名】, service 加上 when 字句。

3.  內容不明確, 或不明其義:

改為:log.error(“aliMonitorReporter is null, probably not initialized properly, please check configuration in file xxx.”);

類似的還有:

改為 log.error(“[modify disk attribute] None of [diskWbps,diskRbps,diskWiops,diskRiops] is specified for disk id:” + diskId);

解決方案: 更清晰貼切地描述錯誤內容。

4. 排查問題的引導內容不明確:

log.error(“get gw group ip segment failed. zkPath: ” + LockResource.getGwGroupIpSegmnetLockPath(request.getGwGroupId()));

zkPath ?  如何去排查這個問題? 我該去找誰? 到哪裡去查詢更具體的線索?

解決方案: 加上相應的背景知識和引導排查措施。

5. 錯誤內容不夠具體細緻:

究竟是什麼資源不夠? 目前剩餘多少? 現在需要多少? 值得注意的是, 要指明這些要額外做一些事情, 可能會稍微影響效能。這時候需要權衡效能和可除錯性。

解決方案:  通過改程式序或程式技巧, 儘可能揭示出具體的差異所在, 減少人工比對的操作。

6. 半英文句式讀起來不夠清晰明白,需要思考來拼湊起完整的意思:

log.warn(“cache status conflict, device id “+deviceDO.getId()+” db status “+deviceDO.getStatus() +”, nc status “+ status);

改為:

log.warn(String.format(“[query cache status] device cache status conflicts between regiondb and nc, status of device ‘%s’ in regiondb is %s , but is %s in nc.”, deviceDO.getId(), deviceDO.getStatus(), status));

解決方案: 改為自然可讀的英文句式。

總結起來, 錯誤日誌格式可以為:

log.error(“[介面名或操作名] [Some Error Msg] happens. [params] [Probably Because]. [Probably need to do].”);

log.error(String.format(“[介面名或操作名] [Some Error Msg] happens. [%s]. [Probably Because]. [Probably need to do].”, params));

log.error(“[Some Error Msg] happens to 錯誤引數或內容 when [in some condition]. [Probably Because]. [Probably need to do].”);

log.error(String.format(“[Some Error Msg] happens to %s when [in some condition]. [Probably Because]. [Probably need to do].”, parameters));

[Probably Reason]. [Probably need to do]. 在某些情況下可以省略; 在一些重要介面和場景下最好能說明一下。

每一條錯誤日誌都是獨立的,儘可能完整、具體、直接說明何種場景下發生了什麼錯誤,由什麼原因導致,要採用什麼措施或步驟。

問題:

  1. String.format 的效能會影響打日誌嗎? 一般來說, 錯誤日誌應該是比較少的, 使用 String.format 的頻度並不會太高,不會對應用和日誌造成影響。
  2. 開發時間非常緊張時, 有時間去斟酌字句嗎? 建立一個標準化的內容格式,將內容往格式套,可以節省斟酌字句的時間。
  3. 什麼時候使用 info, warn , error ?

info 用於列印程式應該出現的正常狀態資訊, 便於追蹤定位;

warn 表明系統出現輕微的不合理但不影響執行和使用;

error 表明出現了系統錯誤和異常,無法正常完成目標操作。

http://stackoverflow.com/questions/2031163/when-to-use-log-level-warn-vs-error

錯誤日誌是排查問題的重要手段之一。 當我們程式設計實現一項功能時, 通常會考慮可能發生的各種錯誤及相應原因:

要排查出相應的原因, 就需要一些關鍵描述來定位原因。這就會形成三元組:

錯誤現象 -> 錯誤關鍵描述 -> 最終的錯誤原因。

需要針對每一種錯誤儘可能提供相應的錯誤關鍵描述,從而定位到相應的錯誤原因。

也就是說,程式設計的時候,要仔細思考, 哪些描述是非常有利於定位錯誤原因的, 儘可能將這些描述新增到錯誤日誌中。

文中沒有指出的問題或困難,  請提出你的建議。

相關文章