無法避免自行實作 logger 時,真正必要的最小要件是什麼:實務要件與整合測試觀點

· · Windows 開發, Logging, 整合測試, 測試設計, 可靠性

如果可以使用現成的 logging framework,那當然比較安全。即便如此,因為應用端的限制或運維上的現實,有時還是不得不自己做 logger。這時最先會卡住的是:到底實作到哪才算「不太粗糙、又不太笨重」?

本文把目標範圍聚焦在障礙調查用的應用程式日誌。不把稽核軌跡、分散式追蹤、指標平台、雲端聚合一次扛進來,而是先定義現場能派上用場的最小組合,再整理要讓這組設計真正值得信賴所需的整合測試觀點。

先下結論

第一版想守住的重點如下。

  • 格式使用 UTF-8JSON Lines
  • 一筆紀錄一行不動搖
  • 必要欄位是 時間levelcategorymessage結構化 fieldssessionIdprocessId
  • 基本是 一個行程一個檔案
  • 負載不高就同步寫入;量多時採 single writer + bounded queue
  • Error / Critical,以及 session 的開始與結束要做同步 flush
  • 輪轉與保留從 v1 起就內建
  • 儲存位置無法使用時,不要默默跑到別的地方寫

收斂到這個程度,實作面與運維面都比較不容易崩。

首先把範圍縮窄

自行實作 logger 會變得困難,多半是因為一開始就想全包。診斷日誌、稽核日誌、效能量測、分散追蹤、使用者行為分析想用同一套機制一次解決時,需求會一口氣膨脹。

本文的對象是用於切分應用程式故障的診斷日誌。也就是優先讓我們事後能回查「什麼時候」、「哪段處理」、「發生了什麼事」、「當時的上下文是什麼」。光是這樣縮小,第一階段的設計判斷就會輕鬆許多。

最低限度需要的要件

1. 格式使用 UTF-8 JSON Lines

就算用純文字串接也能留下日誌,但之後不容易以程式方式處理。反過來說,從一開始就做沉重的自訂二進位格式,運維時的可觀測性又會下降。

作為中間方案,UTF-8JSON Lines 好處理。一行等於一筆紀錄,當成文字讀也易於閱讀,之後用腳本或工具分析也方便。即使寫入中途被截斷,也容易辨識是哪一行壞掉,對實務相當合用。

2. 一開始就把必要欄位釘死

至少要先備齊的欄位,是以下 7 個。

  • timestamp
  • level
  • category
  • message
  • fields
  • sessionId
  • processId

如果只把 message 當成字串日誌,之後搜尋條件一增加就會頭痛。反之,欄位塞太多又會讓呼叫端的負擔突然飆高。一開始先固定在這個範圍,之後真的有需要再擴充比較保險。

3. 以「一個行程一個檔案」為基本

讓多個行程往同一個檔案追加寫入的設計,出事的成因比想像中多。互斥控制、部分寫入、輪轉時機、異常結束時的處理,會一口氣變得棘手。

先以 一個行程一個檔案 為基本原則。如果希望把多個行程聚合,在後段再聚合、或是明確地建一個專責聚合行程,會比較安全。

4. 寫入策略依負載分流

日誌量不多時,同步寫入比較直觀,調查障礙也輕鬆。硬是非同步化,反而容易遺失結束前的日誌,或讓例外時的 flush 條件模糊。

反之,當日誌量增加到同步 I/O 成為瓶頸時,就採用 single writer + bounded queue。這時重要的是要先決定佇列滿了之後的策略。要丟舊日誌、丟新日誌、還是出警告,不要留在模糊地帶。

5. 訂下 flush 條件

ErrorCritical,還有 session 開始與結束的日誌,同步 flush 對調查幫助很大。但如果連平常的 Info 都全部 flush 會拖慢效能,不把所有 level 一視同仁才實際。

6. 輪轉與保留從 v1 就納入

輪轉常被認為「之後再加就好」,但進入運維後就突然會讓人頭痛。大小、每日、每次啟動等方式都可以,至少要有「不會無限膨脹」與「要留幾份」的規格。

7. 儲存失敗時不要擅自改寫到其他位置

當日誌的儲存位置不能用時,默默改寫到別的地方的設計,之後會讓調查變困難。運維負責人在「該出現的地方」找不到日誌,第一時間反應就會延誤。

如果寫不了,就用應用端通知、事件日誌、標準錯誤等明確可識別的手段把失敗顯露出來。至少「不知道跑去哪裡」這種狀況要避免。

v1 的最小組合示意

第一版多半做到以下程度就夠。

  • UTF-8 JSON Lines
  • 一個行程一個檔案
  • 以 session 為單位的檔名
  • 以大小或每次啟動為單位的輪轉
  • 保留份數的上限
  • Error / Critical 的同步 flush
  • 能接受結構化 fields 的 API

超過這些的功能,等實際運維中「真的覺得困擾」才補上,反而更容易維護。

常見的 NG

把常見的反例也一起列出。

  • 把所有內容塞進 message 字串
  • 多個行程共用同一個檔案
  • 沒定 flush 條件就全面非同步化
  • 把輪轉與保留往後延
  • 儲存失敗時默默改寫到別的資料夾
  • 把網路傳輸或本地 DB 寫入都一次塞進 v1

這些乍看很方便,但都容易讓切分與運維變得更沉重。

整合測試以真實檔案、真實執行緒、真實行程為前提

logger 是單元測試單獨無法令人放心的元件。只驗證字串整形或 JSON 化並不夠,實際運維遇到的問題多半在 I/O、並行性、輪轉、結束時 flush、權限錯誤上。

因此整合測試時要使用真實檔案、真實執行緒,必要時甚至要用真實行程來確認。至少要避免「平常能過,但出事時不敢信」的狀態。

希望跑過的整合測試項目

單一寫入的完整性

  • 一行是否為一筆 JSON 紀錄
  • 能否以 UTF-8 重新讀取
  • 必要欄位是否每次都齊全
  • 有沒有混入換行導致拆成多行壞掉

同一行程內的並行執行

  • 多執行緒同時寫入是否會讓紀錄壞掉
  • 紀錄數量是否多或少
  • 使用 queue 時,順序與遺失策略是否符合規格

flush 與結束時的行為

  • Error / Critical 是否立即反映
  • 正常結束時 queue 是否清空
  • 接近例外結束的路徑下,必要的結束日誌是否仍留下

輪轉與保留

  • 達到輪轉條件時,是否切換到新檔案
  • 超過保留上限的舊檔,是否依規格刪除
  • 輪轉前後 JSON 行是否不會壞掉

異常系

  • 儲存位置資料夾不存在時的處理
  • 沒有寫入權限時的處理
  • 磁碟滿等相當情境下失敗時的通知或回傳值
  • queue 滿溢時的行為

多行程的情境

若規格是 一個行程一個檔案,那麼「另一個行程不會想寫入同一個檔案」這件事本身就是確認對象。反之若採聚合行程方式,則要連同轉交失敗的情境一起驗。

v1 最少想跑過幾條

一開始全部做會讓測試太沉。v1 最少想跑過的,是下面這 6 條左右。

  1. 單執行緒的正常寫入
  2. 多執行緒同時寫入
  3. Error / Critical 的 flush
  4. 輪轉與保留
  5. 儲存位置異常時的失敗通知
  6. 正常結束時的 drain 與最終 flush

光這 6 條都通過,就已經明顯遠離「字串是有出來,但運維時不敢信」的 logger 了。

總結

自行實作 logger 的第一個目標不是高功能化,而是「出事時能信得過」。為此,把格式固定成 UTF-8 JSON Lines、縮小必要欄位、以 一個行程一個檔案 為基本、早早定好 flush、輪轉、保留、失敗時行為,都是有效的。

而這套設計實際上能不能運作,必須以真實檔案、真實執行緒、真實行程進行整合測試來驗證。與其把實作做大,不如先把最小組合與最低限度的測試集固定好,之後成長起來也比較順。

相關文章

共用相同標籤的最新文章。能以相近的主題延伸理解。

相關主題

與本文相近的主題頁面。以本文為起點,可進一步連到相關服務與其他文章。

與本主題相關的服務

本文連結到以下服務頁面,歡迎從最接近的入口查看。

回到部落格一覽