好久以前,有個朋友問我,若是一個老項目讓你接手去進行後續維護,你會先從哪裏入手、讓本身更快地上手項目?當時我沒有特別正面去回答這個朋友的問題,我說:一個老項目是否容易上手,一個很是關鍵的地方就是這個項目的日誌是否打得足夠好。由於一般來講,一個老項目相對比較穩定了,後續大機率不會有比較大的變動和改動,那麼對於這樣的項目,核心就是「維穩」。可是任何人都沒法保證項目在線上運行時不會出線上故障,在出現線上問題或者故障時,如何快速止損就是第一要義,而日誌在止損過程當中就扮演着很是重要的角色。日誌打的足夠明瞭清晰,能夠幫助開發和運維人員快速定位問題,繼而決定採起何種方案進行止損。html
今天就讓咱們一塊兒來聊一聊如何把項目程序日誌打「好」。如下是本文大綱目錄:java
一.爲什麼須要規範地打印程序日誌?nginx
二.如何規範地打印程序日誌? git
如有不正之處請多多諒解,並歡迎批評指正。web
請尊重做者勞動成果,轉載請標明原文連接:算法
https://www.cnblogs.com/dolphin0520/p/10396894.htmlsql
咱們平時在寫程序代碼過程當中,通常會把主要精力集中在功能實現上,每每會忽視日誌的重要性,然而日誌在系統上線後是極其重要的,由於系統上線後,只有經過日誌才能瞭解當前系統的運行狀態,在出現線上故障時,日誌是否足夠清晰明瞭決定了是否可以快速找到止損方案。咱們能夠看一下下面這段代碼:數據庫
public class HttpClient {
private static final Logger LOG = LoggerFactory.getLogger(HttpClient.class);
private static int CONNECT_TIMEOUT = 5000; // unit ms
private static int READ_TIMEOUT = 10000; // unit ms
public static String sendPost(String url, String param) {
OutputStream out = null;
BufferedReader in = null;
String result = "";
try {
URL realUrl = new URL(url);
URLConnection conn = realUrl.openConnection();
conn.setDoInput(true);
conn.setDoOutput(true);
conn.setConnectTimeout(CONNECT_TIMEOUT);
conn.setReadTimeout(READ_TIMEOUT);
conn.setRequestProperty("charset", "UTF-8");
out = new PrintWriter(conn.getOutputStream());
out.print(parm);
out.flush();
in = new BufferedReader(new InputStreamReader(conn.getInputStream()));
String line;
while ((line = in.readLine()) != null) {
result += line;
}
} catch (Exception ex) {
LOG.error("post request error!!!");
} finally {
try {
if (out != null) {
out.close();
}
if (in != null) {
in.close();
}
} catch (IOException ex) {
LOG.error("close stream error!!!");
}
return result;
}
}
}複製代碼
某一天線上忽然大量http請求失敗,而後查看日誌,發現了大量的「post request error!!!」錯誤,此時假如看到這樣的日誌你可能徹底不知道到底是什麼緣由致使的,還得繼續經過一些其餘的手段來定位具體緣由。bash
假如打印的錯誤日誌是這樣的:服務器
post request error!!!, url:[http://www.123.test.com], param:[name=jack]
java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:579)複製代碼
那麼便能很快地判定是下游http服務問題致使的,且下游http服務域名爲www.123.test.com(Connection refused一般是因爲下游服務端口未啓動引發的),能夠迅速找相應的人員進行止損,避免在故障定位階段耗費大量的時間。
上面舉的例子只是一個很是小的例子,實際平常開發中可能碰到的線上問題比這個更加複雜和棘手,總結來看,日誌的主要做用有如下幾點:
1)日誌是系統運行的「照妖鏡」,經過它可以實時反映系統的運行狀態;
如上圖所示,系統A中producer不斷產生數據放入到data queue中,sender不斷從data queue中取數據發送給下游系統B的receiver,那麼對於系統A來講,data queue中的待發送數據量即是一個很是關鍵的指標,它可以從側面真實反應當前系統的運行情況,若是data queue中的element個數超過容量的90%了,那麼標誌着此時系統可能運行不正常了,會有隊列堵塞的風險;若是data queue中的element個數不到容量的10%,那麼標誌着此時系統運行比較正常,出現隊列堵塞的風險較低。
若是這個指標沒有輸出到日誌中,開發和運維人員是沒法確切知道當前系統A的運行狀態的(固然也有其餘的方式來獲取這個指標,好比經過http接口暴露出來也是一種方式之一)。
2)良好的日誌便於後期運維和開發人員迅速定位線上問題,加快止損速度,減小系統故障帶來的損失;
3)日誌還有另一個做用即是可以無縫與監控系統結合,經過監控系統進行日誌採集,拿到系統運行的相關性能指標,有利於分析系統的性能瓶頸、提早規避風險;
舉例說明:
假若有一個商城系統,在初期,數據庫經過2臺服務器提供服務(1臺master,1臺slave),此時大部分接口能在秒級內響應用戶請求。隨着時間的推移,商城系統的用戶量逐漸增多,併發查詢和寫入量都出現了必定的增加,數據庫中的數據量也慢慢增多,致使部分sql語句查詢愈來愈慢,忽然有一天,數據庫的slave機器因爲過多的慢查詢致使被拖垮,完全宕機了,致使商城服務不可用。
若是商城系統在日誌中記錄了每一個http請求的耗時狀況,經過監控系統配置日誌採集,同時配置相應的報警,那麼便能提早發現因爲業務增加帶來的系統性能瓶頸,提早進行系統優化(如機器擴容、sql語句優化、分庫分表等),規避風險。
4)便於統計與業務相關的指標數據,進行相關業務分析和功能優化。
舉例說明:
好比一個搜索系統,想統計過去一週不一樣地域(如南北地域)的搜索使用佔比,若是日誌中自己打印了每一個搜索query請求的ip,則很容易統計,不然須要從新上線加日誌才能統計。
所以,你們在平常編寫代碼過程當中要注重日誌書寫的規範性,讓它發揮出它應有的價值,在輔助保障咱們服務穩定運行的同時,可以有效提高後期系統維護效率。
接下來,咱們從如下幾個方面來談談如何規範地打印日誌。
一般來講日誌文件的命名可包括如下幾個關鍵信息:
類型標識(logTypeName)
日誌級別(logLevel)
日誌生成時間(logCreateTime)
日誌備份編號(logBackupNum)複製代碼
類型標識:指此日誌文件的功能或者用途,好比一個web服務,記錄http請求的日誌一般命名爲request.log或者access.log,request、access就是類型標識,而java的gc日誌一般命名爲gc.log,這樣看一目瞭然;而一般用來記錄服務的總體運行的日誌通常用服務名稱(serviceName、appKey)或者機器名(hostName)來命名,如 nginx.log;
日誌級別:打印日誌的時候直接經過文件來區分級別是一種比較推薦的方式,若是把全部級別的日誌打到同一個日誌文件中,在定位問題時,還須要去文件中進行查找操做,相對繁瑣。日誌級別通常包括DEBUG、INFO、WARN、ERROR、FATAL這五個級別,在實際編寫代碼中,能夠採起嚴格匹配模式或者非嚴格匹配模式,嚴格匹配模式即INFO日誌文件中只打印INFO日誌,ERROR日誌文件只打印ERROR日誌;非嚴格匹配模式即INFO日誌文件能夠打印INFO日誌、WARN日誌、ERROR日誌、FATAL日誌,WARN日誌文件能夠打印WARN日誌、ERROR日誌、FATAL日誌,以此類推。
日誌生成時間:即在日誌文件名稱中附帶上日誌文件建立的時間,方便在查找日誌文件時進行排序;
日誌備份編號:當進行日誌切割時,若是是以文件大小進行滾動,此時能夠在日誌文件名稱末尾加上編號;
雖然日誌中可以保存系統運行時的關鍵信息,可是因爲磁盤空間有限,因此咱們不能無限制地保留日誌,所以必須有日誌滾動策略。日誌滾動一般有如下幾種模式:
第一種:按照時間滾動
第二種:按照單個日誌文件大小滾動
第三種:同時按照時間和單個日誌文件大小滾動。
對於日誌滾動策略來講,有2個比較關鍵的參數:最大保留日誌數量和最大磁盤佔用空間。這2個參數切記必定要設置,若是沒有設置,則頗有可能會出現把線上機器磁盤打滿的狀況。
日誌的級別一般有如下幾種:
debug/trace、info、warning、error、fatal
這幾種日誌級別的嚴重程序依次遞增:
debug/trace:debug和trace級別的日誌因爲打印內容較多,因此一般狀況下不適用於線上生產環境使用,通常使用於前期線下環境調試。即便線上環境要使用,也須要經過開關來控制,只在定位追蹤線上問題時纔開啓;
info:info日誌通常用來記錄系統運行的關鍵狀態、關鍵業務邏輯或者關鍵執行節點。但切記一點,info日誌毫不可濫用,若是info日誌濫用,則和debug/trace日誌沒有太大區別了。
warning:warning日誌通常用來記錄系統運行時的一些非預期狀況,顧名思義,是做爲一種警示,提醒開發和運維人員須要關注,可是不用人爲介入馬上去處理的。
error:error日誌通常用來記錄系統運行時的一些普通錯誤,這些錯誤一旦出現,則表示已經影響了用戶的正常訪問或者使用,一般意味着須要人爲介入處理。但不少時候在生產環境中,也不必定是出現error日誌就須要人工當即介入處理的,一般會結合error日誌的數量以及持續時間來進行綜合判斷。
fatal:屬於系統致命錯誤,通常出現意味着系統基本等於掛掉了,須要人工當即介入處理。
下面舉個簡單的例子來講明,假如咱們有這樣一個場景,咱們有一個工資計算系統,每隔月1號須要從員工考勤系統獲取公司全部員工的考勤數據,而後根據考勤數據來計算上月應發工資,那麼須要有一個函數從考勤系統獲取員工考勤數據:
public Map<Long, Double> getEmployeeWorkDaysFromAttendance(int year, int month, Set<Long> employeeList) throws BusiessException {
// 入口關鍵日誌,須要打印關鍵的參數,由於employeeList可能數量較大,因此次數沒有直接打印employeeList列表內容,只打印了size
logger.info("get employee work days, year:{}, month:{}, employeeList.size:{}", year, month, employeeList.size());
// 若是須要臨時檢驗員工列表,能夠把debug日誌開關打開
if (debugOpen()) {
logger.debug("employ list content:{}", JSON.toJsonString(employeeList));
}
int retry = 1;
while (retry <= MAX_RETRY_TIMES) {
try {
Map<Long, Double> employeeWorkDays = employeeAttendanceRPC.getEmployeeWorkDays(year, month, employeeList);
logger.info("get employee work days success, year:{}, month:{}, employeeList.size:{}, employeeWorkDays.size:{}", year, month, employeeList.size(), employeeWorkDays.size());
return employeeWorkDays;
} catch (Exception ex) {
logger.warning("rpc invoke failed(employeeAttendanceRPC.getEmployeeWorkDays), retry times:{}, year:{}, month:{}, employeeList.size:{}", retry, year, month, employeeList.size(), ex);
// 連續重試失敗以後,向上跑出異常
// 對於沒有異常機制的語言,此處應該打印error日誌
if (retry == MAX_RETRY_TIMES) {
throw new BusiessException(ex, "rpc invoke failed(employeeAttendanceRPC.getEmployeeWorkDays)");
}
}
retry++;
}
}複製代碼
因爲日誌是爲了方便咱們瞭解系統當前的運行情況以及定位線上問題,因此日誌打印的時機很是重要,若是濫用日誌,則會致使日誌內容過多,影響問題定位的效率;若是日誌打印過少,則容易致使缺乏關鍵日誌,致使在線上定位問題時找不到問題根音。所以把握日誌打印的時機相當重要,如下是常見的適合打印日誌的時機:
1)http調用或者rpc接口調用
在程序調用其餘服務或者系統的時候,須要打印接口調用參數和調用結果(成功/失敗)。
2)程序異常
在程序出現exception的時候,要麼選擇向上拋出異常,要麼必須在catch塊中打印異常堆棧信息。不過須要注意的是,最好不要重複打印異常日誌,好比在catch塊裏既向上拋出了異常,又去打印錯誤日誌(對外rpc接口函數入口處除外)。
3)特殊的條件分支
程序進入到一些特殊的條件分支時,好比特殊的else或者switch分支。好比咱們根據工齡計算薪資:
public double calSalaryByWorkingAge(int age) {
if (age < 0) {
logger.error("wrong age value, age:{}", age);
return 0;
}
// ..
}複製代碼
理論上工齡不可能小於0,因此須要打印出這種非預期狀況,固然經過拋出異常的方式也是可行的。
4)關鍵執行路徑及中間狀態
在一些關鍵的執行路徑以及中間狀態也須要記錄下關鍵日誌信息,好比一個算法可能分爲不少步驟,每隔步驟的中間輸出結果是什麼,須要記錄下來,以方便後續定位跟蹤算法執行狀態。
5)請求入口和出口
在函數或者對外接口的入口/出口處須要打印入口/出口日誌,一來方便後續進行日誌統計,同時也更加方便進行系統運行狀態的監控。
日誌打印時機決定了可以根據日誌去進行問題定位,而日誌的內容決定了是否可以根據日誌快速找出問題緣由,所以日誌內容也是相當重要的。一般來講,一行日誌應該至少包括如下幾個組成部分:
logTag、param、exceptionStacktrace
logTag爲日誌標識,用來標識此日誌輸出的場景或者緣由,param爲函數調用參數,exceptionStacktrace爲異常堆棧。舉例說明:
public class HttpClient {
private static final Logger LOG = LoggerFactory.getLogger(HttpClient.class);
private static int CONNECT_TIMEOUT = 5000; // unit ms
private static int READ_TIMEOUT = 10000; // unit ms
public static String sendPost(String url, String param) {
OutputStream out = null;
BufferedReader in = null;
String result = "";
try {
URL realUrl = new URL(url);
URLConnection conn = realUrl.openConnection();
conn.setDoInput(true);
conn.setDoOutput(true);
conn.setConnectTimeout(CONNECT_TIMEOUT);
conn.setReadTimeout(READ_TIMEOUT);
conn.setRequestProperty("charset", "UTF-8");
out = new PrintWriter(conn.getOutputStream());
out.print(parm);
out.flush();
in = new BufferedReader(new InputStreamReader(conn.getInputStream()));
String line;
while ((line = in.readLine()) != null) {
result += line;
}
} catch (Exception ex) {
// 有關鍵logTag,有參數信息,有錯誤堆棧
LOG.error("post request error!!!, url:[[}], param:[{}]", url, param, ex);
} finally {
try {
if (out != null) {
out.close();
}
if (in != null) {
in.close();
}
} catch (IOException ex) {
LOG.error("close stream error!!!, url:[[}], param:[{}]", url, param, ex);
}
return result;
}
}
}
複製代碼
public class HttpClient {
private static final Logger LOG = LoggerFactory.getLogger(HttpClient.class);
private static int CONNECT_TIMEOUT = 5000; // unit ms
private static int READ_TIMEOUT = 10000; // unit ms
public static String sendPost(String url, String param) {
OutputStream out = null;
BufferedReader in = null;
String result = "";
try {
URL realUrl = new URL(url);
URLConnection conn = realUrl.openConnection();
conn.setDoInput(true);
conn.setDoOutput(true);
conn.setConnectTimeout(CONNECT_TIMEOUT);
conn.setReadTimeout(READ_TIMEOUT);
conn.setRequestProperty("charset", "UTF-8");
out = new PrintWriter(conn.getOutputStream());
out.print(parm);
out.flush();
in = new BufferedReader(new InputStreamReader(conn.getInputStream()));
String line;
while ((line = in.readLine()) != null) {
result += line;
}
} catch (Exception ex) {
// 沒有任何錯誤信息
LOG.error("post request error!!!");
} finally {
try {
if (out != null) {
out.close();
}
if (in != null) {
in.close();
}
} catch (IOException ex) {
LOG.error("close stream error!!!");
}
return result;
}
}
}
複製代碼
另外,對於對外http接口或者rpc接口,最好對於每一個請求都有requestId,以便跟蹤每一個請求後續全部的執行路徑。
參考文章: