記錄日誌有哪些好的技巧？
一、簡介
在軟體開發中，我們出於各種目的，需要將程式執行中的一些狀態記錄在日誌中。
日誌記錄，並不是越多越好，也不是記錄的越頻繁越好，而是需要我們精心設計記錄日誌的時機、內容、格式（以方便後續解析、查詢日誌）等等。
本文簡單介紹了記錄日誌的一些基本原則和注意事項，更具體的記日誌的技巧、最佳實踐、日誌框架等請參考子文件ofollow,noindex">Go如何記錄日誌 。
二、記錄日誌的目的（why）
開發除錯
目的是開發期除錯程式使用，這種日誌量比較大，且沒有什麼實質性的意義，只應該出現在開發期，而不應該在專案上線之後輸出。
記錄使用者行為
這種型別的日誌，記錄使用者的操作行為，用於大資料分析，比如監控、風控、推薦等等。這種日誌，一般是給其他團隊分析使用，而且可能是多個團隊，因此一般會有一定的格式要求，開發者應該按照這個格式來記錄，便於其他團隊的使用。當然，要記錄哪些行為、操作，一般也是約定好的，因此，開發者主要是執行的角色。
程式執行狀況
記錄程式的執行狀況，特別是非預期的行為、異常情況，這種日誌，主要是給開發、維護人員使用。什麼時候記錄，記錄什麼內容，完全取決於開發人員，開發者具有高度自主性。本文討論的主要也是指這種型別的日誌，因為作為一個服務端開發、運維人員，程式執行日誌往往是解決線上問題的救命稻草。
系統、機器狀況
比如網路請求、系統CPU、記憶體、IO使用情況等等，這種日誌主要是給運維人員使用，生成各種更直觀的展現形式，在系統出問題的時候報警。
三、日誌的要素（what）
每條日誌都可以被當作一個事件（event），紀錄了該事件發生時各個資訊：
時間
日誌的時間可以包含多種含義，不同含義的時間傳遞不同的資訊：
- 指事件發生的時間，而不是日誌被列印的時間。該時間附近範圍內，結合該事件及伺服器的網路、CPU、IO等狀況，可以瞭解他們之間的相關性，有助於分析事件發生的原因。
- 持續時間。例如網路請求的耗時、處理請求的各個階段的耗時等。
- 事件發生的順序。通過時間戳的順序，瞭解到一系列事件的發生順序。對多程序、多執行緒、分散式系統有幫助。
位置
事件發生在哪個模組、哪個檔案、哪個函式、哪一行程式碼裡。
級別
日誌的重要程度。用於：
- 不同的環境（測試、生產）下，列印不同級別的日誌
- 不同級別的日誌產生不同級別的監控報警
內容
簡明扼要的描述發生了什麼樣的事情。目的是通過日誌本身，而不是重新閱讀相關程式碼來搞清楚發生了什麼事情。
例如：logger.warn('user_login failed due to unvalid_username')
唯一標識
不管是面向使用者的服務、面向機器叢集的服務，都需要一個唯一標識作為日誌的主體，以方便查詢該事件主體的其他資訊。（很多元資料是不會記在日誌裡的，只會記一個唯一標識）
例如：logger.warn('user_login failed due to password, username %s', username)
事件上下文
除了時間、位置、級別、內容，其他的一些有用的資訊。
例如：
- logger.warn('user_login failed due to wrong password, username %s', username)
- logger.warn('user_login failed due to invalid password, username %s', username)
-
logger.warn('user_login failed due to
empty
password, username %s', username)
為了獲取更豐富的上下文，有些資料需要從 Nginx 那裡獲取並傳給本服務，然後列印。參考：和日誌相關的Nginx設定
格式化
將上述的各個資訊按照固定的順序打印出來，不僅方便查詢（例如使用grep，sed，awk等），也方便收集日誌的程式（ES）解析日誌。
其他
根據各自的業務特點，還可以在日誌中記錄（包括、不限於）：
- 錯誤次數
- 當前正在處理的請求數
- 處理的進度（33%，50%，78%。。。）
- IP
- 問題出現時的請求連結
四、記錄日誌的一些原則和技巧
使用框架或模組
Java :Log4j 、Log4j2 、Commons Logging 、Slf4j 、Logback
Python 內建的 logging 模組
beego 框架裡的 github.com/astaxie/beego/logs 模組
其他的一些Go的框架：
- Logrus:github.com/Sirupsen/logrus (Docker use this)
- github.com/op/go-logging
- github.com/golang/glog (from Google, implementation of their C++ glog library in Go)
- github.com/cihub/seelog
不能出錯
記錄日誌的目的是為了方便發現問題，解決問題，那麼就需要保證記錄日誌本身不能出錯。
尤其是對於 Error、Fatal級別的日誌，出現的概率低，所以要做好單元測試，以保證記錄日誌本身是沒問題的，是不會影響正常業務的。
避免敏感資訊
- 避免記錄使用者密碼。
- 避免記錄使用者個人資訊，如身份證號、手機號等。應該只在日誌裡記錄該使用者的唯一標識，然後根據該唯一標識去其他的系統（例如資料庫）檢視詳細資訊。
記錄“不可能發生”的事件
雖然正常邏輯下，某些情況是永遠都不可能發生的，但是還是需要給這些不可能發生的情況列印一條日誌。
例如 條件語句裡的 else，switch 裡的 default，都需要進行防禦式的程式設計，同時記錄日誌。
Lazy logging
日誌本身是一個字串，可以通過多種方式拼接而成。如果根據log level，該條日誌不應被列印，那麼就應該 避免 拼接這個操作，也應該 避免 字串拼接裡的函式的呼叫。
例如：
#coding=utf-8 import logging logger = logging.getLogger('LazyLogging') logger.setLevel(logging.DEBUG) hander = logging.StreamHandler() formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') hander.setFormatter(formatter) logger.addHandler(hander) def getUserCount(): logger.info('getUserCount is called') return 1 logger.debug("There are " + str(getUserCount()) + " users logged in now.")
- log level 設定為 DEBUG（第5行），那麼會先列印第12行，再列印第15行
-
log level 設定為 INFO，依然會列印第12行，說明：
- 問題1: 即便沒有列印第15行，依然生成了一個字串
- 問題2: 而且呼叫了 getUserCount 這個函式
- 解決上述的問題1，可以把第15行修改為：
logger.debug("There are %s users logged in now.", getUserCount())
- 為了解決上述的問題2，一個辦法是：
class lazyEval: def __init__(self, f, *args): self.func = f self.args = args def __str__(self): return str(self.func(*self.args)) logger.debug("There are %s users logged in now.", lazyEval(getUserCount))
Java裡的方式：
logger.debug(``"There are {} users logged in now."``, () -> getUserCount());
目前Golang裡也存在這樣的問題，但是還沒找到怎麼做到 lazyLogging。
但是，可以看出上面的方式也不優雅，所以應當 避免 在列印日誌時呼叫函式。
非同步列印日誌
網際網路應用程式中，高併發下的寫日誌會帶來大量的IO操作，從而影響正常服務的效能。這時候的記日誌就需要專門的服務去做，例如把日誌打到訊息佇列裡，然後再寫到磁碟上。
設定快取
預設的日誌是隨時 flush 到console、檔案裡的，通過設定快取進行批量操作，可以一定程度上優化服務效能。
對日誌歸檔、分類
列印到一個檔案裡，會使得該檔案越來越大，不方便查詢。
按日誌屬性分類：access log，error log，
按日期歸檔：lathspell-api.2018-01-17.log，lathspell-api.2018-01-18.log
按大小切分：lathspell-api.2018-01-17.log.1，lathspell-api.2018-01-17.log.2，lathspell-api.2018-01-17.log.3 （避免檔案太大）