當應用程式發生問題時,若有一份好的日誌可以追查,有助於有效地定位出問題所在,因此,幾乎每個程式語言的標準程式庫都會內建日誌程式庫,而且設計上都有一定的複雜度。

如果開發者從沒使用過日誌,從日誌程式庫的設計來探索,可以是個發掘自身日誌需求的起點。

日誌程式庫的組成

基本上,大多數的日誌程式庫,都會有Logger、Formatter、Handler這樣的功能元件。

Logger用來建立日誌訊息,具有名稱,在同一個名稱下只會有一個Logger實例,名稱具有階層性,這便於對應程式的套件或模組階層,在日誌的最佳實踐中往往也建議,依各個模組階層指定名稱建立Logger。同時,Logger物件的名稱也代表了Logger物件之間的繼承關係,子Logger物件可以繼承父Logger物件的組態,或進一步定義細部的日誌。

Formatter(或稱為Renderer)決定了日誌訊息最後呈現的方式,使用純文字是建議的方式,以便能在沒有任何日誌分析工具的情況下,也能直接開啟查看日誌。而且,一個Logger輸出訊息時,因應不同的目的可以有多個Formatter,格式可以採用一行一個訊息、XML、JSON等方式,使用哪種格式的考量之一,是日後打算使用哪種工具來分析日誌,如果使用的工具是以逐行處理訊息,例如grep,那麼每一個日誌就不應當跨行,另一種考量是閱讀的方便性,例如建立HTML或郵件格式來呈現訊息。

Handler(或稱為Appender)決定了日誌最後輸出的目的地,通常預設為系統標準錯誤(Standard error),除此之外,也常輸出至檔案。同時,一個Logger可以有多個Handler,像是在系統上儲存至檔案,並同時發送至另一臺主機。此外,Handler的主要考量是要易於分類與管理,以及考量讀取分析時的效率,例如,每個模組最好有自己的日誌檔案,日誌檔案最好能夠輪替(rotate),像是每隔多久建立新的日誌檔案,最多保留幾個日誌檔案等。

除了Logger、Formatter、Handler元件,日誌程式庫多半還會有Filter元件的存在,以便開發者在DEBUG、INFO、WARNING、ERROR等日誌層級(Level)之外,還能過濾更細部或自訂的日誌訊息。

日誌程式庫基本上都能透過組態檔案來變更日誌的行為,不只是在程式碼中進行組態。組態檔案的主要考量就是可讀性,或能否使用開發者熟悉的格式,像是有些程式庫能使用JSON、YAML,或甚至是組態檔案中撰寫程式碼來進行組態。

日誌的多種層級

不同的日誌程式庫,往往提供不同的日誌層級。基本上,各種程式庫都會有的層級,是DEBUG、INFO、WARNING、ERROR、CRITICAL等,低於設定層級的日誌訊息不會輸出,以便因應程式開發在不同時期下,可記錄不同粒度的日誌訊息,這也是經常被拿來跟只使用print之類方法,而不使用日誌程式庫的開發者說嘴的一個功能。因為,到處使用print顯示相關的訊息,最後若不想看訊息時,還得逐一找出、刪除或註解掉print程式碼,不是嗎?

不過,並非曾使用過print的地方,就適合改用日誌程式庫,有些開發者使用print,其實是在進行除錯時想逐一查看變數的值罷了,這時需要的也許是個Debugger,而不是將print替換為Logger。使用日誌的目的之一是:「事情發生時,開發者(或應用程式管理者)並不在現場」,我們可從這點來思考該記錄到日誌的部分,或是該設定的日誌層級。

有時在程式開發階段,確實會需要查看程式執行時某些變數的值,在許可的情況下,應儘量使用Debugger,不過,在無法使用Debugger的場合,只好採用插入程式碼的方式時,就可以使用日誌並採用DEBUG層級,這類訊息往往很瑣碎,因此層級低於INFO,而且通常與應用程式上線後無關。

如果在日誌時需要同時收集訊息的動作較耗資源,例如logger.debug(expensiveInfo()),我們可事先使用isDebugEnabled之類的方法檢查後再進行,以避expensiveInfo()執行時耗費不必要的運算資源。

INFO就是資訊(INFOrmation),乍看這層級,有點籠統,因為,有什麼資訊既不是為了Debug,也不是WARNING,或更高的ERROR,而該記錄下來的呢?

從「事情發生時人並不在現場」來想,就會比較知道該記錄的資訊了。例如,想知道應用程式進行的操作,以便事後追查時釐清責任歸屬,因此使用者操作時,引發的應用程式事件可以記錄,執行的SQL可以記錄,來自外部系統的資料可以記錄(像是HTTP請求,或從另一臺主機取回之資料)。

某些行為或流程不建議採用,但不致於影響應用程式的正常運行;某些時候收到的資料有錯誤,但仍能解讀或使用;某些功能已廢棄,未來可能移除,這類的情況可以使用WARNING等級,這類訊息主要是作為提示,建議開發者或使用者避免使用某些功能,或者考量採取進一步的動作。

ERROR大部份開發者比較熟悉,簡單說就是應用程式執行時期發生錯誤,例外的發生就是最容易理解的例子,也因此logger.error(ex)這類程式碼,最常出現在捕捉到例外之後的程式碼,ERROR雖然是個錯誤,但應用程式有可能繼續運行,如果某個錯誤的發生,嚴重性是使得應用程式無法繼續運行,就是使用比ERROR更高一級的日誌層級,這類層級往往就是CRITICAL、FATAL之類的名稱。

日誌層級的設定必須視不同的應用程式,作不同的思考,單就程式庫而言,也有不同的考量。舉例來說,有些程式庫提供比DEBUG更細的TRACE,而有些程式庫CRITICAL以上還有細分,而像Java的一個日誌框架slf4j,則認為ERROR與FATAL並沒有實質上的差別,因此沒有FATAL等級。

日誌訊息內容

當然,知道日誌時指定的訊息內容要記錄哪些,才是最重要的,畢竟,只是記錄了一個變數值,沒有包含時間,也沒指出哪個模組或哪個函式中發生的,這樣的日誌日後追查時根本毫無幫助。

以Python而論,Formatter可以設定LogRecord attributes(https://goo.gl/zPLIUz),查看它提供的屬性名稱,即能知道事情發生時能記錄的資訊,像是:時間、檔名、函式名稱、日誌層級、行數、模組名稱、Logger名稱、路徑名稱、行程名稱、執行緒名稱、執行時期資訊、堆疊資訊等。

這只是個基本清單,另一方面,也並不是說每個日誌訊息都要記錄這全部的東西,記得:「事情發生時人並不在現場」這個原則,想想事後追查時,哪些資訊出現在日誌訊息中,對於定位問題所在是有幫助的,而哪些是不必要的。

除了考量可記錄的資訊之外,每一筆日誌訊息要有固定的規則性,如果某個地方的格式記錄時是「時間-檔名-函式名稱-訊息」,另一個地方就不要有其他格式,像是「時間-訊息-函式名稱-檔名」,這會造成事後擷取或比對同類型日誌時的困擾。

日誌API的複雜性

無論是哪個日誌程式庫,若認真去探索API的設計與功能元件,都會發現有一定的複雜度,對於工程要求越高的程式語言,對日誌的需求也是越多樣化,像是Java除了本身提供的標準日誌程式庫之外,還有著log4j、logback、apache common logging、slf4j等日誌框架,後兩者其實提供的是一層介面,允許開發者在底層使用不同的日誌程式庫實作。

這反映出了日誌本身的必要性,以及需求的複雜。儘管有些文件宣稱九成的機會下,只會用到很少部份的API,然而,這比較像是一種鼓勵,希望開發者從文件中介紹的簡單API,開始採用日誌程式庫。在這之後,有機會的話,可以進一步深入所採用的日誌API,思考一下它們設計上何以複雜?這會讓開發者更加清楚自己對日誌的需求。

作者簡介


Advertisement

更多 iThome相關內容