#意識
ASAP (As Soon As Possible)原則
當線上出現詭異問題,
當你意識到靠現有的日志無法定位問題時,
當現象難以在你的開發環境重現時,
請不要執著于枯坐肉眼看代碼,因為:一)不一定是你代碼邏輯問題,可能是臟數據造成的,是老業務數據造成的,是分布式環境造成的,是其他子系統造成的;二)線上業務處于不穩定中,條件不允許問題定位無限期。
此時,請立即在問題相關的調用鏈條上,一次性:
- 在函數的入口和出口打印日志,同時打印輸入、輸出參數
- catch(){……}里打印stacktrace,同時打印try塊中關鍵變量的值(避免你發現某個異常是問題第一原因,卻不知道是什么變量傳入導致的)
- 與其他模塊交互的接口入口處打印輸入參數,
即,
解決線上問題歸根結底要靠log、a lot of log output! 在logging的力度上切勿猶猶豫豫,我們的工程師習慣于吝嗇地找兩個函數打印日志、打包部署一把、沒看出來、再找幾個函數打印、再部署、等著現象重現再觀察、……,一來二去時間流逝,閑庭信步,從客服知道的小事故變成了全國皆知的大事故。
所以,再強調一遍:在你的調用鏈條上,逐層調用的函數入口和出口都打印詳細日志,不怕多只怕少,然后部署,等待現象重現,畢其功于一役!
通過它可以跟蹤為什么系統響應變慢或者太快
- 處理完一個incoming request所耗費的時間,精確到毫秒
- 執行數據庫查詢的時間
- 從磁盤或者存儲介質獲取數據的時間
- 等等
2)異常和堆棧跟蹤
3)Sessions
知道一個問題是由誰引起的非常重要,因此在日志中使用會話標識符就變得必不可少。它可以簡單到是一個 IP 地址或者是一個更復雜的 UUID,只要能區分不同的請求者就足夠。
4)版本號
#工具
推薦的Java Logging框架
1)log4j:我們的配置是,log4j.appender.CONSOLE.layout.ConversionPattern= [%-d{yyyy-MM-dd HH\:mm\:ss.SSS}] [%p] [%c] [%m]%n;%p是日志優先級,%c是類目名,%m是輸出信息,%n是回車換行符。
2)logback:log4j創建人Ceki Gülcü后續推出了SLF4J+logback。SLF4J(Simple Logging Facade for Java)作為commons-logging的替代,為各種logging APIs提供了一個簡單的統一接口,使得最終用戶能夠在部署的時候配置所希望的logging APIs的實現。logback勝在性能,據稱“某些關鍵操作,比如判定是否記錄一條日志語句的操作,其性能得到了顯著的提高。這個操作在logback 中需要3納秒,而在 log4j 中則需要30納 秒。 logback 創建記錄器(logger)的速度也更快:13毫秒,而在 log4j 中需要23毫秒。更重要的是,它獲取已存在的記錄器只需94納秒, 而 log4j 需要2234納秒,時間減少到了1/23。跟java.util.logging(JUL)相比性能提高也是顯著的”。
#配置
不要隨便從網上找一個log4j的配置文件,請確認你理解每一個配置項
我們既然輸出日志,自然期望在面對“這個問題是否從過去幾天開始出現?”這樣的疑問時,不至于發現你的rollingPolicy錯誤設置導致只能看到最近幾小時的日志,或者日志發生時間沒有精確到毫秒。
#理念
可用grep抽取的日志:獨立的行!
我們總是希望能用grep處理日志文件。這意味著:一個日志條目永遠不應該跨多行,除非你是堆棧打印。
我們會用grep問日志什么問題呢?如:
- 用手機號13910******下單的顧客最近三天內都來自于哪些IP?
- 瀏覽地址是****?from=kfapi的顧客,但referral卻是搜索引擎域名,最近三天有多少次?
- 最近一周內,訂單中心執行的所有事務,耗時最長的一次是多長時間?
- ××××的接口是否真的于18:00發送了一個請求,我們收到的參數是什么?
確保你的日志能回答這樣的問題。
不同關注領域寫不同的日志文件
當訪問和調用極其頻繁,有時候你會發現把你的工程里什么信息都打印到一個日志文件里,會讓你看得頭昏腦脹。
最簡單的示范就是Apache的訪問日志和錯誤日志是分開的。
同樣,你也可以把更加安靜的事件(偶爾出現)與更加喧鬧的事件分開存儲。
如,對外的開放平臺可以打印三種日志文件:connection log(建立鏈接和關閉鏈接,附帶接入參數),message log(內部調用鏈),stacktrace log(異常的堆棧打印)。
#具體實現
至少精確到毫秒
日志必須包含時間戳,精確到至少毫秒級。
如果只是記錄到秒級,我們曾明知代碼因缺乏并發控制而產生BUG,卻只能郁悶地看著精確到秒級的日志。
對Java來說,最好配置為:yyyy-MM-dd/HH:mm:ss.SSS。
請盡可能打印明確的會話標識
日志條目里打印一個會話標識(A certain session identifier),當有許多并發請求打過來時,你就能基于此字段過濾 client 了。比如,我們日志會補充打印一個瀏覽器 cookies 里種下的 UUID 。
log4j的isDebugEnabled判斷
如果打印信息是常量字符串或簡單字符串拼接,那么不需要if ( log.isDebugEnabled() )。
如果你拼裝的動作比較耗資源,請用if ( log.isDebugEnabled() )。
如有可能,請將性能數據標準化輸出
這樣更方便grep或hadoop做性能數據抽取和挖掘,從而能很輕松地轉換為圖形監控。
比如,訂單中心的性能數據格式為:樹枝標志 當前節點起始時間 [當前節點持續時間, 當前節點自身消耗時間, 在父節點中所占的時間比例]
哪些位置需要部署性能檢測點
(1)訪問數據庫的dao層;
(2)訪問外部資源的ext層;
(3)訪問mq的方法;
(4)等等,一切不在你自己負責的工程掌握的部分(外部),或一切你認為自己工程的性能危險點,都需要加入性能監控日志。
#Sample
打印了應用的版本號,客戶端的會話標識,關鍵步驟的執行時長。
一個好的堆棧跟蹤日志