如何使錯誤日志更加友善排查問題

在程式中打錯誤日志的主要目标是為更好地排查問題和解決問題提供重要線索和指導。但是在實際中打的錯誤日志内容和格式變化多樣，錯誤提示上可能殘缺不全、沒有相關背景、不明其義，使得排查解決問題成為非常不友善或者耗時的操作。而實際上，如果程式設計的時候稍加用心，就會減少排查問題的很多無用功。

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

       錯誤是如何煉成的

      對于目前系統來說， 錯誤的産生由三個地方引入：

      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.  分析錯誤日志。 錯誤日志的内容最好能夠更加直接明了， 能夠明确指明與目前要排查的問題特征是吻合的， 并且給出重要線索。

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

比如：

if ((storageType == StorageType.dfs1 || storageType == StorageType.dfs2)
                && (zone.hasStorageType(StorageType.io3) || zone.hasStorageType(StorageType.io4))) {
// 進入dfs1 和dfs2 在io3 io4 存儲。
} else {
      log.info("zone storage type not support, zone: " + zone.getZoneId() + ", storageType: "
+ storageType.name());
      throw new BizException(DeviceErrorCode.ZONE_STORAGE_TYPE_NOT_SUPPORT);
}      

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

錯誤日志應該做到： 即使離開代碼情境，也能清晰地描述發生了什麼。

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

從某種意義上來說， 錯誤日志也可以是一種非常有益的文檔，記錄着各種不合法的運作用例。

目前程式錯誤日志的内容可能存在如下問題：

1.  錯誤日志沒有指明錯誤參數和内容：

catch(Exception ex){
      log.error("control ip insert failed", ex);
      return new ResultSet<AddControlIpResponse>(
ControlIpErrorCode.ERROR_CONTROL_IP_INSERT_FAILURE);
}      

沒有指明插入失敗的 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.  内容不明确, 或不明其義：

if(aliMonitorReporter == null) {
        log.error("aliMonitorReporter is null!");
} else {
       aliMonitorReporter.attach(new ThreadPoolMonitor(namePrefix, asynTaskThreadPool.getThreadPoolExecutor()));
}      

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

if (diskWbps == null && diskRbps == null && diskWiops == null    && diskRiops == null) {
      log.error("none of attribute is specified for modifying");
      throw new BizException(DeviceErrorCode.NO_ATTRIBUTE_FOR_MODIFY);
}      

改為 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. 錯誤内容不夠具體細緻：

if (!ncResourceService.isNcResourceEnough(ncResourceDO,    vmResourceCondition)) {
      log.error("disk space is not enough at vm's nc, nc id:" + vmDO.getNcId());
      throw new BizException(ResourceErrorCode.ERROR_RESOURCE_NOT_ENOUGH);
}      

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

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

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

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

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

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

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

也就是說，程式設計的時候，要仔細思考， 哪些描述是非常有利于定位錯誤原因的， 盡可能将這些描述添加到錯誤日志中。

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