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