歡迎在新的一年來到我的部落格。在一個巴黎devops maillist上回復了一個關於監控和日誌監控之後，我想起了很久以前我的一個部落格計劃。
儘管在寫這篇博文的時候，我是在負責運維工作，不過本文主要是寫給開發者的。
對我來說，明白如何記錄日誌和記錄什麼，是軟體工程師必須明瞭的最艱鉅的任務之一。之所以這麼說，是因為這項任務與預測（divination）類似，你不知道當你要除錯的時候需要些什麼資訊……我希望這10個建議能幫助你更好地在應用程式中記錄日誌，讓運維工程師們受益。:)
1. 你不應自己寫log
絕對不要，即便是用printf或者是自己寫入到log檔案，又或自己處理logrotate。請給你的運維同志們省省心，呼叫標準庫或者系統API來完成它。
這樣，你可以保證程式的執行與其他系統元件好好相處，把log寫到正確的位置或者網路服務上，而不需要專門的系統配置。
假如你要使用系統API，也就是syslog(3)，學習好怎麼用它。
如果你更喜歡用logging庫，在Java裡面你有很多選擇，例如Log4j，JCL，slf4j和logback。我最喜歡用slf4j和logback的組合，因為它們特別給力，而且相對地容易配置(還允許使用JMX進行配置或者過載配置檔案)。
slf4j最好的是你可以修改logging控制檯的位置。如果你在編寫一個庫，這會變得非常重要，因為這可以讓庫的使用者使用自己的logging控制檯而不需要修改你的庫。
其他語言當然也有多種logging庫，例如ruby的Log4r，stdlib logger，和幾近完美的Jordan Sissel’s Ruby-cabin。
如果你想糾結CPU佔用問題，那麼你不用看這篇文章了。還有，不要把log語句放在緊內部迴圈體內，否則你永遠看不出區別來。
2. 你應在適當級別上進行log
如果你遵循了上述第一點的做法，接下來你要對你程式中每一個log語句使用不同的log級別。其中最困難的一個任務是找出這個log應該是什麼級別
以下是我的一些建議:
- TRACE level: 如果使用在生產環境中，這是一個程式碼異味(code smell)。它可以用於開發過程中追蹤bug，但不要提交到你的版本控制系統
- DEBUG level: 把一切東西都記錄在這裡。這在debug過程中最常用到。我主張在進入生產階段前減少debug語句的數量，只留下最有意義的部分，在除錯(troubleshooting)的時候啟用。
- INFO level: 把使用者行為(user-driven)和系統的特定行為(例如計劃任務…)
- NOTICE level: 這是生產環境中使用的級別。把一切不認為是錯誤的，可以記錄的事件都log起來
- WARN level: 記錄在這個級別的事件都有可能成為一個error。例如，一次呼叫資料庫使用的時間超過了預設時間，或者記憶體快取即將到達容量上限。這可以讓你適當地發出警報，或者在除錯時更好地理解系統在failure之前做了些什麼
- ERROR level: 把每一個錯誤條件都記錄在這。例如API呼叫返回了錯誤，或是內部錯誤條件
- FATAL level: 末日來了。它極少被用到，在實際程式中也不應該出現多少。在這個級別上進行log意味著程式要結束了。例如一個網路守護程式無法bind到socket上，那麼它唯一能做的就只有log到這裡，然後退出執行。
記住，在你的程式中，預設的執行級別是高度可變的。例如我通常用INFO執行我的服務端程式碼，但是我的桌面程式用的是DEBUG。這是因為你很難在一臺你沒有接入許可權的機器上進行除錯，但你在做使用者服務時，比起教他們怎麼修改log level再把生成的log發給你，我的做法可以讓你輕鬆得多。當然你可以有其他的做法:)
3. honor the log category
我在第一點中提到的大部分logging庫允許指定一個logging類別。它可以分類log資訊，並基於logging框架的配置，在最後以某一形式進行log或是不進行。
通常，Java開發者在log語句處使用完整，合格的類名作為類別名。如果你的程式遵循單一職責原則(Single responsibility principle，原文有誤)，這種模式還不錯。
在Java的logging庫中，Log類別是按等級劃分的，例如在com.daysofwonder.ranking.ELORankingComputation會匹配到頂級的com.daysofwonder.ranking。這可以讓運營工程師配置一個對此類別下指定的所有ranking子系統作用的logging。如果需要的話，還可以同時生成子類別的logging配置。
擴充開來，我們講解一下特定情況下的除錯。假設你在做一個應答使用者請求的服務端軟體(如REST API)。它正在對my.service.api.<apitoken>進行log(其中apitoken用於識別使用者)。那麼你可以選擇對my.service.api類別進行log，記錄所有的api，或是對某違規API使用者的my.service.api.<bad-user-api-token>進行log。當然這需要系統允許你在執行中修改logging配置。
4. 你應該寫有意義的log
這可能是最重要的建議了。沒有什麼比你深刻理解程式內部，卻寫出含糊的log更糟了。
在你寫日誌資訊之前，總要提醒自己，有突發事件的時候，你唯一擁有的只有來自log檔案，你必須從中明白髮生了什麼。這可能就是被開除和升職之間的微妙的差距。
當開發者寫log的時候，它(log語句)是直接寫在程式碼環境中的，在各種條件中我們應該寫入基於當前環境的資訊。不幸的是，在log檔案中並沒有這些環境，這可能導致這些資訊無法被理解。
解決這個情況(在寫warn和error level時尤為重要)的一個方法是，新增輔助資訊到log資訊中，如果做不到，那麼改為把這個操作的作用寫下。
還有，不要讓一個log資訊的內容基於上一個。這是因為前面的資訊可能由於(與當前資訊)處於不同的類別或者level而沒被寫入。更壞的情況是，它因多執行緒或非同步操作，在另一個地方(或是以另一方式)出現。
5. 日誌資訊應該用英語
這個建議可能有點奇怪，尤其是對法國佬(French guy)來說。我還是認為英語遠比法語更簡煉，更適應技術語言。如果一個資訊裡面包含超過50%的英語單詞，你有什麼理由去用法語寫log呢
把英法之爭丟一邊，下面是這個建議背後的原因：
- 英語意味著你的log是用ASCII編碼的。這非常重要，因為你不會真正知道log資訊會發生什麼，或是它被歸檔前經過何種軟體層和介質。如果你的資訊裡面使用了特殊字符集，乃至UTF-8，它可能並不會被正確地顯示(render)，更糟的是，它可能在傳輸過程中被損壞，變得不可讀。不過這還有個問題，log使用者輸入時，可能有各種字符集或者編碼。
- 如果你的程式被大多數人使用，而你又沒有足夠的資源做國際化，英語會成為你的不二之選。如果你有國際化，那麼讓介面與終端使用者更親近(closer)(這通常不會是你的log)
- 如果你國際化了你的log(例如所有的warning和error level資訊)，給他們一個特定的有意義的錯誤碼。這樣，使用者做與語言無關的搜尋，找到相關資訊。這種良好的模式已經在虛擬記憶體(VMS)作業系統中應用了很久，而我必須承認它非常有用。如果你曾經設計過這種模式，你還可以試試這種模式: APP-S-CODE 或者 APP-S-SUB-CODE，它們分別代表:
APP: 應用程式的3字縮寫
S: 嚴重程度的1字縮寫(例如D代表debug，I代表info)
SUB: 這個code所從屬的應用程式的子部分
CODE: 一個數字代號，指定這個問題中的錯誤
6. 你應該給log帶上上下文
沒有什麼比這樣的log資訊更糟的了
|
1 |
Transaction failed |
或是
|
1 |
User operation succeeds |
又或是API異常時:
|
1 |
java.lang.IndexOutOfBoundsException |
沒有相應的上下文，這些資訊不過是噪音，它們不會對除錯過程中有意義的數值或是空間起作用(add value and consume space)。
帶上上下文的資訊要有價值得多，例如:
|
1 |
Transaction 234632 failed: cc number checksum incorrect |
或是
|
1 |
User 54543 successfully registered e-mail<a href="mailto:user@domain.com">user@domain.com</a> |
又或是
|
1 |
IndexOutOfBoundsException: index 12 is greater than collection size 10 |
在上面這一例子中的異常，如果你想把它傳播開， 確保在處理的時候帶上與當前level相應的上下文，讓除錯更簡單，如下一個java的例子:
|
1 2 3 4 5 6 7 |
public void storeUserRank(int userId，int rank，String game) { try { ...deal database ... } catch (DatabaseException de) { throw new RankingException("Can't store ranking for user "+userId+" in game "+ game + " because " + de.getMessage() ); } } |
這樣，rank API的上層客戶端就可以有足夠的上下文資訊log這個error。更好的做法是讓上下文成為exception的引數，而不是資訊，如果需要的話，上層可以對它進行修正(use remediation)。
保留上下文的一個簡單方法是使用一些java logging庫的MDC實現。MDC是一個每執行緒關聯陣列(per thread associative array)。可以修改logger設定，讓每一行log總是輸出MDC內容。如果你的程式使用每執行緒模式，這可以幫助解決保留上下文的問題。這個java的例子對給定的請求，使用MDC記錄每使用者的資訊:
|
1 2 3 4 5 6 7 8 9 10 11 12 |
class UserRequest { ... public void execute(int userid) { MDC.put("user"，userid); // ... all logged message now will display the user=<userid> for this thread context ... log.info("Successful execution of request"); // user request processing is now finished，no need to log our current user anymore MDC.remote("user"); } } |
提示，MDC系統在非同步logging模式中的表現並不好，例如Akka的logging系統。因為MDC是儲存在一個每執行緒儲存區域的，而且在非同步系統中你無法保證在寫入log的執行緒是有MDC的那一個。在這種情況下，你需要手動地使用每一個log語句來log這些上下文。
7. 你應該用機器可解析的格式來打日誌
Log資訊對人很友善，但是對機器就慘了。有時人工地讀這些log檔案並不足夠，你需要進行一些自動化過程(例如通過警報和審查)。或是你想集中儲存你的log，以進行搜尋。
如下，如果你把log的上下文嵌在string中會發生什麼:
|
1 |
log.info("User {} plays {} in game {}",userId,card，gameId); |
這會生成這樣的文字:
|
1 |
2013-01-1217:49:37,656[T1]INFOc.d.g.UserRequestUser1334563plays4ofspadesingame23425656 |
現在，如果你想使它可解析，你需要下面這個(未測試過的)正規表示式:
|
1 |
/User(\d+)plays(.+)ingame(\d+)$/ |
好了，這並不輕鬆而且容易出錯，把它接入到你程式碼中已有的string引數中。
這個方法怎麼樣，我相信Jordan Sissel在他的ruby-cabin庫中第一次介紹的: 在你的log裡面加入機器可解析格式的上下文。我們上述的例子中這樣可以使用JSON:
|
1 |
2013-01-1217:49:37,656[T1]INFOc.d.g.UserRequestUserplays{'user':1334563,'card':'4ofspade','game':23425656} |
現在你的log分析器可以更容易地寫入，更直接地索引，而且你可以釋放logstash所有的威力。
8. 日誌不宜太多或太少
這聽著貌似很愚蠢。log的數量是有一個合適的平衡的。
太多的log會使從中獲得有價值的東西變得困難。當人工地瀏覽這種十分混亂的log，嘗試除錯產品在早上3點的一個問題可不是一個好事。
太少的log，你可能無法除錯問題: 除錯就像在拼一個困難的拼圖，你需要得到足夠的拼塊。
不幸的是，這沒有魔法般的規則去知道應該log些什麼。所以需要嚴格地遵從第一第二點，程式可以變得很靈活，輕鬆地增減log的長度(verbosity)。
解決這個問題的一個方法是，在開發過程中儘可能多地進行log(不要被加入用於程式除錯的log所迷惑)。當應用程式進入生產過程時，對生成的log進行一次分析，根據所發現的問題增減log語句。尤其是在除錯時，在你需要的部分，你可以有更多的上下文或logging，確保在下一個版本中加入這些語句(可以的話，同時解決它來讓這個問題在記憶中保持新鮮)。當然，這需要運維人員和開發者之間大量的交流。
這是一個複雜的任務，但是我推薦你重構logging語句，如你重構程式碼一樣多。這樣可以在產品的log和它的log語句的修改中有一個緊密的反饋迴圈。如果你的組織有一個連續的交付程式的話，它會十分有效，正如持續的重構。
Logging語句是與程式碼註釋同級的程式碼後設資料。保持logging語句與程式碼相同步是很重要的。沒什麼比除錯時獲得與所執行的程式碼毫無關係的資訊更糟了。
9. 你應該考慮閱讀者
為什麼要對應用程式做log
唯一的答案是，在某一天會有人去讀它(或是它的意義)。更重要的是，猜猜誰會讀它，這是很有趣的事。對於不同的”誰”，你將要寫下的log資訊的內容，上下文，類別和level會大不同。
這些”誰”包括:
- 一個嘗試自己解決問題的終端使用者(想象一個客戶端或桌面程式)
- 一個在除錯產品問題的系統管理員或者運維工程師
- 一個在開發中debug，或者在解決產品問題的開發者
開發者瞭解程式內部，所以給他的log資訊可以比給終端使用者的複雜得多。為你的目標閱讀者調整你的表達方式，乃至為此加入額外的類別(dedicate separate catagories)。
10. 你不應該只為除錯而log
正如log會有不同的閱讀者，它也有不同的使用理由。即便除錯是最顯而易見的閱讀log的目的，你同樣可以有效地把log用在:
- 審查: 有時商業上會有需求。這可以獲取與管理或者合法使用者的有意義的事件。通常會有一些語句描述這個系統中的使用者在做些什麼(例如誰登入了，誰在編輯……)
- 建檔: log是打上了時間戳的(有時是微妙級的)，可以成為一個為程式各部分建檔的好工具。例如記錄一個操作的開始和結束，你可以自動化(通過解析log)或是在除錯中，進行效能度量，而不需要把這些度量加到程式中。
- 統計: 如果你每次對一個特定事件(例如特定的錯誤或事件)進行log，你可以對執行中的程式(或使用者行為)進行有趣的統計。這可以新增(hook)到一個警報系統中去連續地發現大量error。
總結
我希望這可以幫助你生成更多有用的log。如果我忘記了一些必須的(對你而言)建議，請諒解。對了，如果你看了這篇部落格之後並不能更好地進行log，我並不負責 :)
如果這10個建議還不夠的話，儘管在評論中補充更多有用的建議。