1. 程式人生 > >Java 寫 Log

Java 寫 Log

處理 .html strac exp group 類型 開啟 添加 track

. 一個最基本的例子

使用Logging框架寫Log基本上就三個步驟
  1. 引入loggerg類和logger工廠類
  2. 聲明logger
  3. 記錄日誌

下面看一個例子

技術分享圖片
//1. 引入slf4j接口的Logger和LoggerFactory
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class UserService {
  //2. 聲明一個Logger,這個是static的方式,我比較習慣這麽寫。
  private final static Logger logger = LoggerFactory.getLogger(UserService.class);

  public boolean verifyLoginInfo(String userName, String password) {
    //3. log it,輸出的log信息將會是:"Start to verify User [Justfly]
    logger.info("Start to verify User [{}]", userName);
    return false;
  }
}
技術分享圖片

其中的第二步,關於Logger對象是否要聲明為靜態的業界有過一些討論,Logback的作者最早是推薦使用對象變量的方式來聲明,後來他自己也改變了想法。想詳細了解的同學可以去看一下: http://slf4j.org/faq.html#declared_static 兩種方式的優劣概述如下:
  • 靜態Logger對象相對來說更符合語義,節省CPU,節省內存,不支持註入
  • 對象變量Logger支持註入,對於一個JVM中運行的多個引用了同一個類庫的應用程序,可以在不同的應用程序中對同個類的Logger進行不同的配置。比如Tomcat上部署了倆個應用,他們都引用了同一個lib。

2. Logger接口的方法

Logger接口分為倆個版本,一個帶Marker版本和一個沒帶Marker版本的。帶Marker版本的我沒用過就不介紹了。沒帶Marker版本的接口方法可以分為以下兩組:

2.1 判斷Logger級別是否開啟的方法

  • public boolean isTraceEnabled();
  • public boolean isDebugEnabled();
  • public boolean isInfoEnabled();
  • public boolean isWarnEnabled();
  • public boolean isErrorEnabled();

這 組方法的作用主要是避免沒必要的log信息對象的產生,尤其是對於不支持參數化信息的Log框架(Log4j 1, commons-logging)。如下面的例子所示,如果沒有加debug級別判斷,在Debug級別被禁用的環境(生產環境)中,第二行的代碼將沒有 必要的產生多個String對象。

if(logger.isDebugEnabled()){
   logger.debug("["+resultCount+"]/["+totalCount+"] of users are returned");
}

如果使用了參數信息的方法,在如下代碼中,即使沒有添加debug級別(第一行)判斷,在生產環境中,第二行代碼只會生成一個String對象。

if(logger.isDebugEnabled()){
   logger.debug("[{}]/[{}] of users in group are returned", resultCount,totalCount);
 }

因此,為了代碼的可讀性,我一般情況下使用參數化信息的方法,並且不做Logger級別是否開啟的判斷,換句話說,這組方法我一般情況下不會用。

2.2 log信息的方法

2.2.1 方法說明

Logger中有五個級別:track,debug,info,warn,error。對於每個級別,分別有五個log方法,以info級別為例子:
  • public void info(String msg);

無參數的log方法,例子:

logger.info("開始初始化配置文件讀取模塊");

輸出

2014-08-11 23:36:17,783 [main] INFO c.j.training.logging.service.UserService - 開始初始化配置文件讀取模塊

  • public void info(String format, Object arg);
支持一個參數的參數化log方法,例子:
logger.info("開始導入配置文件[{}]","/somePath/config.properties");

輸出

2014-08-11 23:36:17,787 [main] INFO c.j.training.logging.service.UserService - 開始導入配置文件[/somePath/config.properties]
  • public void info(String format, Object arg1, Object arg2);

支持倆個參數的參數化log方法,例子:

logger.info("開始從配置文件[{}]中讀取配置項[{}]的值","/somePath/config.properties","maxSize");

輸出 2014-08-11 23:36:17,789 [main] INFO c.j.training.logging.service.UserService - 開始從配置文件[/somePath/config.properties]中讀取配置項[maxSize]的值
  • public void info(String format, Object... arguments);

支持多個參數的參數化log方法,對比上面的倆個方法來說,會多增加構造一個Object[]的開銷。例子:

logger.info("在配置文件[{}]中讀取到配置項[{}]的值為[{}]","/somePath/config.properties","maxSize", 5);

輸出
2014-08-11 23:36:17,789 [main] INFO c.j.training.logging.service.UserService - 在配置文件[/somePath/config.properties]中讀取到配置項[maxSize]的值為[5]
  • public void info(String msg, Throwable t);
無參數化記錄log異常信息
logger.info("讀取配置文件時出現異常",new FileNotFoundException("File not exists"));

輸出

2014-08-11 23:36:17,794 [main] INFO c.j.training.logging.service.UserService - 讀取配置文件時出現異常
java.io.FileNotFoundException: File not exists
at cn.justfly.training.logging.service.UserServiceTest.testLogResult(UserServiceTest.java:31) ~[test-classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_45]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_45]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_45]
at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_45]
參數化說明
在上面的例子中,我們可以看到log信息中的{}將會按照順序被後面的參數所替換。這樣帶來了一個好處:如果在運行時不需要打印該Log,則不會重復產生String對象。

2.2.2 如何Log Exception

2.2.2.1 把Exception作為Log方法的最後一個參數

上面講的參數化Log方法的中的最後一個參數如果是一個Exception類型的對象的時候,logback將會打印該Exception的StackTrace信息。看下面的這個例子:

logger.info("讀取配置文件[{}]時出錯。","/somePath/config.properties",new FileNotFoundException("File not exists"));
上面的代碼在執行的時候會輸出如下內容:
2014-08-12 00:22:49,167 [main] INFO c.j.training.logging.service.UserService - 讀取配置文件[/somePath/config.properties]時出錯。
java.io.FileNotFoundException: File not exists
at cn.justfly.training.logging.service.UserServiceTest.testLogResult(UserServiceTest.java:30) [test-classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_45]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_45]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_45]
at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_45]
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit.jar:na]
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit.jar:na]
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit.jar:na]
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit.jar:na]
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit.jar:na]

2.2.2.2 Exception不會替換log信息中的參數

另外需要註意的時,該Exception不會作為參數化內容中的參數進行替換。比如下面的代碼:

logger.info("讀取配置文件[{}]時出錯。異常為[{}]","/somePath/config.properties",new FileNotFoundException("File not exists"));

其執行結果如下所示,第二個參數沒有進行替換 2014-08-12 00:25:37,994 [main] INFO c.j.training.logging.service.UserService - 讀取配置文件[/somePath/config.properties]時出錯。異常為[{}]
java.io.FileNotFoundException: File not exists
at cn.justfly.training.logging.service.UserServiceTest.testLogResult(UserServiceTest.java:30) [test-classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_45]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_45]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_45]
at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_45]

2.2.2.3 參數化Exception

如果你就是不想要打印StackTrace,就是要將其參數化的話怎麽弄?一般情況下不建議這麽做,因為你把Exception中有用的東西吃掉了。但是如果你非要這麽做的話,也不是不可以,有倆個方法:
  • 把Exception的toString()方法的返回值作為參數
例子如下所示,註意我們不用ex.getMessage()而是用toString()方法,原因在於不是每個Message實例都有Message,但是默認的toString()方法裏面包括有Message
logger.info("讀取配置文件[{}]時出錯。異常為[{}]","/somePath/config.properties",new FileNotFoundException("File not exists").toString());

執行結果為: 2014-08-12 00:29:24,018 [main] INFO c.j.training.logging.service.UserService - 讀取配置文件[/somePath/config.properties]時出錯。異常為[java.io.FileNotFoundException: File not exists]
  • 不要讓Exception成為最後一個參數
例子如下:
logger.info("讀取參數[{}]的時候出錯:[{}], 請檢查你的配置文件[{}]","maxSize",new FileNotFoundException("File not exists"),"/somePath/config.properties");

執行結果為: 2014-08-12 00:35:11,125 [main] INFO c.j.training.logging.service.UserService - 讀取參數[maxSize]的時候出錯:[java.io.FileNotFoundException: File not exists], 請檢查你的配置文件[/somePath/config.properties]

3. Log什麽

前面講了怎麽使用Loggger的方法log日誌,下面繼續講講在什麽地方需要記錄什麽級別的log,以及需要記錄什麽內容。

3.1 如何使用不同級別的Log

SLF4J把Log分成了Error,Warn,Info,Debug和Trace五個級別。我們可以把這倆個級別分成兩組

3.1.1 用戶級別

Error、Warn和Info這三個級別的Log會出現在生產環境上,他們必須是運維人員能閱讀明白的

3.1.1.1 Error

  • 影響到程序正常運行、當前請求正常運行的異常情況,例如:
    • 打開配置文件失敗
    • 第三方應用網絡連接異常
    • SQLException
  • 不應該出現的情況,例如:
    • 某個Service方法返回的List裏面應該有元素的時候缺獲得一個空List
    • 做字符轉換的時候居然報錯說沒有GBK字符集

3.1.1.2 Warn

  • 不應該出現但是不影響程序、當前請求正常運行的異常情況,例如:
    • 有容錯機制的時候出現的錯誤情況
    • 找不到配置文件,但是系統能自動創建配置文件
  • 即將接近臨界值的時候,例如:
    • 緩存池占用達到警告線

3.1.1.3 Info

  • 系統運行信息
    • Service方法的出入口
    • 主要邏輯中的分步驟
  • 外部接口部分
    • 客戶端請求參數和返回給客戶端的結果
    • 調用第三方時的調用參數和調用結果

3.1.2 開發級別

Debug和Trace這倆個級別主要是在開發期間使用或者當系統出現問題後開發人員介入調試的時候用的,需要有助於提供詳細的信息。

3.1.2.1 Debug

  • 用於記錄程序變量,例如:
    • 多次叠代中的變量
  • 用於替代代碼中的註釋
如果你習慣在代碼實現中寫: //1. 獲取用戶基本薪資
技術分享圖片
//2. 獲取用戶休假情況
技術分享圖片
//3. 計算用戶應得薪資
技術分享圖片 不妨這麽寫試試 技術分享圖片
logger.debug("開始獲取員工[{}] [{}]年基本薪資",employee,year);

logger.debug("獲取員工[{}] [{}]年的基本薪資為[{}]",employee,year,basicSalary);
logger.debug("開始獲取員工[{}] [{}]年[{}]月休假情況",employee,year,month);

logger.debug("員工[{}][{}]年[{}]月年假/病假/事假為[{}]/[{}]/[{}]",employee,year,month,annualLeaveDays,sickLeaveDays,noPayLeaveDays);
logger.debug("開始計算員工[{}][{}]年[{}]月應得薪資",employee,year,month);

logger.debug("員工[{}] [{}]年[{}]月應得薪資為[{}]",employee,year,month,actualSalary);
技術分享圖片

3.1.2.2 Trace

主要用於記錄系統運行中的完整信息,比如完整的HTTP Request和Http Response

3.2 Log中的要點

3.2.1 Log上下文

在Log中必須盡量帶入上下文的信息,對比以下倆個Log信息,後者比前者更有作用
  • "開始導入配置文件"
  • "開始導入配置文件[/etc/myService/config.properties]"

3.2.2 考慮Log的讀者

對於用戶級別的Log,它的讀者可能是使用了你的框架的其他開發者,可能是運維人員,可能是普通用戶。你需要盡量以他們可以理解的語言來組織Log信息,如果你的Log能對他們的使用提供有用的幫助就更好了。 下面的兩條Log中,前者對於非代碼維護人員的幫助不大,後者更容易理解。
  • "開始執行getUserInfo 方法,用戶名[jimmy]"
  • "開始獲取用戶信息,用戶名[jimmy]"
下面的這個Log對於框架的使用者提供了極大的幫助
  • "無法解析參數[12 03, 2013],birthDay參數需要符合格式[yyyy-MM-dd]"

3.2.3 Log中的變量用[]與普通文本區分開來

把變量和普通文本隔離有這麽幾個作用
  • 在你閱讀Log的時候容易捕捉到有用的信息
  • 在使用工具分析Log的時候可以更方便抓取
  • 在一些情況下不容易混淆
對比以下下面的兩條Log,前者發生了混淆:
  • "獲取用戶lj12月份發郵件記錄數"
  • "獲取用戶[lj1][2]月份發郵件記錄數"

3.2.4 Error或者Warn級別中碰到Exception的情況盡量log 完整的異常信息

Error和Warn級別是比較嚴重的情況,意味著系統出錯或者危險,我們需要更多的信息來幫助分析原因,這個時候越多的信息越有幫助。這個時候最好的做法是Log以下全部內容:
  • 你是在做什麽事情的時候出錯了
  • 你是在用什麽數據做這個事情的時候出錯了
  • 出錯的信息是什麽
對比下面三個Log語句,第一個提供了詳盡的信息,第二個只提供了部分信息,Exception的Message不一定包含有用的信息,第三個只告訴你出錯了,其他的你一無所知。
  • log.error("獲取用戶[{}]的用戶信息時出錯",userName,ex);
  • log.error("獲取用戶[{}]的用戶信息時報錯,錯誤信息:[{}]",userName,ex.getMessage());
  • log.error("獲取用戶信息時出錯");

3.2.5 對於Exception,要每次都Log StackTrace嗎?

在一些Exception處理機制中,我們會每層或者每個Service對應一個RuntimeException類,並把他們拋出去,留給最外層的異常處理層處理。典型代碼如下:

技術分享圖片
try{
  
}catch(Exception ex){
  String errorMessage=String.format("Error while reading information of user [%s]",userName);
  logger.error(errorMessage,ex);
  throw new UserServiceException(errorMessage,ex);
}
技術分享圖片

這個時候問題來了,在最底層出錯的地方Log了異常的StackTrace,在你把這個異常外上層拋的過程中,在最外層的異常處理層的時候,還會再Log一次異常的StackTrace,這樣子你的Log中會有大篇的重復信息。 我碰到這種情況一般是這麽處理的:Log之!原因有以下這幾個方面:
  • 這個信息很重要,我不確認再往上的異常處理層中是否會正常的把它的StackTrace打印出來。
  • 如果這個異常信息在往上傳遞的過程中被多次包裝,到了最外層打印StackTrace的時候最底層的真正有用的出錯原因有可能不會被打印出來。
  • 如果有人改變了LogbackException打印的配置,使得不能完全打印的時候,這個信息可能就丟了。
  • 就算重復了又怎麽樣?都Error了都Warning了還省那麽一點空間嗎?

Java 寫 Log