Java 小應用日誌級別異常處理最佳實踐

（點選上方公眾號，可快速關註）

來源：南角影 ，

blog.csdn.net/reaper1022/article/details/78875087

編者按：做了很多年IT工作，突然又對日誌級別有些迷茫，哈哈，為什麼要有又字。是的，人們都在實踐中不停的學習並增進自己。寫了好久的字，盯住看3分鐘，然後你會想，哦？寫錯了吧 ^_^

原文在： https://stackify.com/java-logging-best-practices/ 。是官方的內容，至於 ELKB，也是類似的東西。

日誌：我們應該做的更好了

我在說什麼？現在有大量的Java日誌框架和庫，大多數開發人員每天都在使用。兩個最常用的是 log4j 和 logback。他們使用起來非常簡單，並且表現很不錯。基本的 Java 日誌檔案還不夠，這裡我們會給出一些Java最佳實踐或者建議來幫助你去使用！

你曾經脫離開發部門去檢視過日誌檔案嗎？如果你做過這些事情，你很快會意識到一些問題。

• 有大量的資料

• 你需要訪問資料

• 分佈在多個伺服器

• 一個具體的操作可能是跨應用的，因此你需要檢視多個日誌

• 日誌都是流水性的，很難查詢。就算你要把資料放在SQL裡面，你也需要對文字資料做全索引以便查詢。

• 很難閱讀。訊息就像義大利麵似的雜亂難以閱讀

• 你通常沒有任何使用者的背景關係等資訊

• 你可能缺少一些有用的細節（你的意思是說“log.Info(‘In the method’)沒用？？？）

• 你需要管理日誌檔案迴圈和保留

另外，你有你應用生成的大量資料，卻不能有效的工作起來。

是時候嚴肅對待日誌了

一旦你的應用不是執行在你的桌面系統，那麼當你的應用不能正確執行的時候，日誌（包括錯誤資訊）就是你的救命稻草。當然，AMP（效能管理平臺）工具會對記憶體上限溢位、效能閥值出現問題的時候發出警告資訊，但這些資訊確並不能幫你解決問題，例如為什麼這個使用者不能登入，或者為什麼這條記錄沒有處理

在 Stackify，我們構建了一個日誌文化“culture of logging” ，來達到如下標的

1. 輸出所有的事情。盡可能多的記錄你所能記錄的，總是有相關的背景關係日誌，這些日誌並不會增加開銷。 

2. 要智慧工作，不要死工作。在固定位置整合所有的日誌（約定，比如 d:/someapplogs/），這個位置對所有的開發人員都是透明的，並可以訪問的。從日誌裡面發現異常有助於提升我們的產品。

本文我們將分享這些最佳實踐，並分享我們是如何達到以上標的，其中大部分已經在 Stackify’s 日誌管理系統中實現了。如果你使用了 字首式檢視系統（Prefix to view your logs,），一定要去看看。

開始記錄所有的事情

我在很多商店工作過，那裡的資訊是這樣的

} catcha(Exception e){

    LOGGER.error(e.getMessage(),e);

}

我給這個開發人員點贊，至少使用了 try/catch 來處理異常。異常裡面會包含堆疊資訊讓我大概知道從那裡來的這個異常，但沒有記錄更多的背景關係資訊。

有時，他們也做了一些前置的日誌

public void processResultes(final List results){

    LOGGER.debug(“Processing resultes”);

}

但是，通常這樣的陳述句並不能告訴你應用裡面到底發生了什麼。如果你負責生產應用的問題解決，那麼這樣的日誌並不能給你什麼指示，尤其還是像大海撈針似的找到這些日誌。

就像之前提及的一樣。當生產出現問題的時候，你不能檢視物力伺服器上的內容，日誌是解決問題最常用的幾個手段之一。你想要有大量的關聯資訊及背景關係資訊。下麵我給出指導性原則。

Walk the Code

讓我們假設你有個想要處理的 try/catch 的地方，但是之前並沒有告訴你關於請求的更多資訊，樣例程式碼是這樣的

public class Foo {

 

    private int id;

 

    private double value;

 

    public Foo(int id, double value) {

     this.id = id;

     this.value = value;

    }

 

    public int getId() {

     return id;

    }

 

    public double getValue() {

     return value;

    }

}

按照下麵工廠樣式建立 Foo 物件，註意，我留了一個可能產生錯誤的地方，方法裡面呼叫 value.doubleValue()，但沒有檢查 null。

public class FooFactory {

 

    public static Foo createFoo(int id, Double value) {

     return new Foo(id, value.doubleValue());

    } 

}

這是簡單有用的場景。假設這是我應用的一個關鍵場景（不允許有任何失敗），讓我們嘗試加一些日誌資訊。

public class FooFactory {

 

    private static Logger LOGGER = LoggerFactory.getLogger(FooFactory.class);

 

    public static Foo createFoo(int id, Double value) {

 

     LOGGER.debug(“Creating a Foo”);

 

     try {

         Foo foo = new Foo(id, value.doubleValue());

 

         LOGGER.debug(“{}”, foo);

 

         return foo;

 

     } catch (Exception e) {

         LOGGER.error(e.getMessage(), e);

     }

 

     return null;

    }

}

現在我們建立兩個 foo 物件，一個有效，一個無效。

FooFactory.createFoo(1, Double.valueOf(33.0));

   FooFactory.createFoo(2, null);

日誌看起來是這樣的

2017-02-15 17:01:04,842 [main] DEBUG com.stackifytest.logging.FooFactory: Creating a Foo

2017-02-15 17:01:04,848 [main] DEBUG com.stackifytest.logging.FooFactory: com.stackifytest.logging.Foo@5d22bbb7

2017-02-15 17:01:04,849 [main] DEBUG com.stackifytest.logging.FooFactory: Creating a Foo

2017-02-15 17:01:04,851 [main] ERROR com.stackifytest.logging.FooFactory:

java.lang.NullPointerException

    at com.stackifytest.logging.FooFactory.createFoo(FooFactory.java:15)

    at com.stackifytest.logging.FooFactoryTest.test(FooFactoryTest.java:11)

現在我們知道了一些資訊，當 FooFactory.createFoo() 方法時候出錯了，但沒有背景關係。預設的 debug 資訊列印物件 toString 不可讀，可以修改 toString。

@Override

public String toString() {

    return “Foo [id=” + id + “, value=” + value + “]”;

}

修改後執行

2017-02-15 17:13:06,032 [main] DEBUG com.stackifytest.logging.FooFactory: Creating a Foo

2017-02-15 17:13:06,041 [main] DEBUG com.stackifytest.logging.FooFactory: Foo [id=1, value=33.0]

2017-02-15 17:13:06,041 [main] DEBUG com.stackifytest.logging.FooFactory: Creating a Foo

2017-02-15 17:13:06,043 [main] ERROR com.stackifytest.logging.FooFactory:

java.lang.NullPointerException

    at com.stackifytest.logging.FooFactory.createFoo(FooFactory.java:15)

    at com.stackifytest.logging.FooFactoryTest.test(FooFactoryTest.java:11)

好多了！現在我們可以看到 [id=, value=]。另一個可選項是你可以透過java反射來獲取對應的屬性。最主要的好處就是當你增加修改成員的時候，你不要修改 toString 方法了。下麵是使用了 Google 的 Gson 庫的輸出。

2017-02-15 17:22:55,584 [main] DEBUG com.stackifytest.logging.FooFactory: Creating a Foo

2017-02-15 17:22:55,751 [main] DEBUG com.stackifytest.logging.FooFactory: {“id”:1,”value”:33.0}

2017-02-15 17:22:55,754 [main] DEBUG com.stackifytest.logging.FooFactory: Creating a Foo

2017-02-15 17:22:55,760 [main] ERROR com.stackifytest.logging.FooFactory:

java.lang.NullPointerException

    at com.stackifytest.logging.FooFactory.createFoo(FooFactory.java:15)

    at com.stackifytest.logging.FooFactoryTest.test(FooFactoryTest.java:11)

當你在 Stackify 的回溯工具中用 JSON 來輸出物件後，可以看到 JSON  格式化的物件。

圖略，差不多就是移動到輸出位置，可以更方便檢視物件內容。

{

  variable : value,

  variable : value

}

輸出更多的診斷背景關係詳細資訊

這就給我們帶來了關於記錄更多細節的最後一點:診斷背景關係日誌。在除錯生產問題時，您可能在日誌中有上千次“建立一個 Foo”訊息，但是不知道是誰建立的。知道使用者是誰是一種非常珍貴的背景關係，能夠快速解決問題。考慮其他的細節可能是有用的——例如，HttpWebRequest 細節。但是誰想要記住每次都記錄下來呢？如何對映診斷背景關係資訊可以參考 SLF4J’s MDC https://logback.qos.ch/manual/mdc.html。

最簡單的增加背景關係選項通常在 servlet filter 中。下麵這個例子建立了一個 servlet filter 生成事務 id 並關聯到 MDC。

public class LogContextFilter implements Filter {

 

    public void init(FilterConfig config) {

    }

 

    public void destroy() {

    }

 

    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws ServletException, IOException {

 

     String transactionId = UUID.randomUUID().toString();

 

     MDC.put(“TRANS_ID”, transactionId);

現在我們可以看到如下類似日誌

19:49:36.350 eric-ubuntu DEBUG Create a Foo {“TRANS_ID”:”d91lxxxxx2ffjjlslf03jf9j;a;j8g3g”}

19:49:36.406 eric-ubuntu DEBUG {“id”:1,”value”:33.0}{“TRANS_ID”:”d91lxxxxx2ffjjlslf03jf9j;a;j8g3g”}

更多的背景關係。現在，我們可以從單個請求中跟蹤所有日誌陳述句。

這就引出了下一個話題，那就是什麼僅僅是努力工作，而不是更聰明地工作（Work Harder, Not Smarter）。但在此之前，我將回答一個我肯定會在評論中聽到的問題:“但是如果我記錄了所有東西，那就產生更多的開銷和巨大的日誌檔案了嗎？我的回答有幾個部分，首先使用日誌冗餘。你可以使用 LOGGER.debug() 輸出任何你需要的資訊，而在生產上你可以輸出警告級別之上的資訊。當你使用 debug 時，只需要修改屬性檔案而不需要重新部署程式碼。其次，日誌輸出應該非同步非阻塞的，開銷非常低，如果你擔心日誌檔案空間，下節會介紹幾個更聰明的方法去處理。

更聰明地工作，不僅僅是努力

既然我們已經記錄了所有內容，它提供了更多的背景關係資料，我們將會討論下一部分內容。正如我所提到並演示了的，將所有這些輸出到平面檔案中仍然不能在很大的複雜的應用程式和環境中幫助您很多。在數千個請求中，跨越數天、數周或更長時間、跨多個伺服器的檔案，您必須考慮如何快速找到所需的資料。

我們真的需要提供一個解決方案：

– 在一個地方聚合所有的 Log 和 Exception；

– 這些日誌對團隊中所有成員可見、實時；

– 在整個堆疊/基礎結構中提供日誌記錄的時間線；

– 是以結構化的格式並高度索引的儲存，利於搜尋。

這是我告訴你們的關於 Stackfy Retrace的部分。當我們試圖提高自己的能力以快速有效地處理我們的日誌資料時，我們決定將它作為我們產品的核心部分（是的，我們使用 Stackify 來監控 Stackify）並與我們的客戶共享，因為我們認為這是應用程式故障排除的核心問題。

首先，我們認識到許多開發人員已經登入了，並且不打算花大量的時間來將程式碼取出並放入新的程式碼。這就是為什麼我們為最常見的 Java 日誌框架建立了日誌應用程式。

• log4j 1.2 (https://github.com/stackify/stackify-log-log4j12)

• log4j 2.x (https://github.com/stackify/stackify-log-log4j2)

• logback (https://github.com/stackify/stackify-log-logback)

繼續使用 log4j 作為樣例，設定非常簡單，在 pom 檔案中加入

   com.stackify

   stackify-log-log4j12

   1.1.9

   runtime

當然，在 logging.properties 檔案中需要加入

log4j.rootLogger=DEBUG, CONSOLE, STACKIFY

log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender

log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout

log4j.appender.CONSOLE.layout.ConversionPattern=%d [%t] %-5p %c: %m%n

 

log4j.appender.STACKIFY=com.stackify.log.log4j12.StackifyLogAppender

log4j.appender.STACKIFY.apiKey=[HIDDEN]

log4j.appender.STACKIFY.application=test-logging

log4j.appender.STACKIFY.environment=test

正如您所看到的，如果您已經使用了不同的 appender，您可以將它放在適當的位置，並將它們放在一起。現在您已經將日誌流到 Stackfy，我們可以檢視一下日誌記錄看板。（順便說一下，如果我們的監控代理安裝了，你也可以把 Syslog 項傳送到 stackfy！）

這個指示板顯示了一個整合的日誌資料流，來自您的所有伺服器和應用程式，呈現在時間軸上。從這裡，你可以快速地

• 檢視基於時間範圍的日誌

• 對特定的伺服器、應用程式或環境進行篩選

另外還有一些非常好的可用性。你會註意到的第一件事就是頂部的圖表。這是快速“分流”你的應用程式的好方法。藍色的線表示日誌訊息的速率，紅色條表示記錄的異常。

明顯，幾分鐘前，我的web應用程式開始有了更穩定的活動，但更重要的是，在同一時間我們開始發現很多異常。異常不會開銷CPU和記憶體，但會對使用者的滿意度產生直接影響，這就是錢啊。

過放大到這個時間段的圖表，我可以快速地將我的日誌細節過濾到那個時間範圍，並檢視那段時間的日誌。

查詢你的日誌

您是否看到下麵的藍色文字看起來像一個 JSON 物件？

它是一個 JSON 物件。這是日誌物件的結果，併在前面添加了背景關係屬性。它看起來比平面檔案中的純文字要好得多，不是嗎？它變得更棒了。看到頁面頂部的搜尋框了嗎？我可以輸入任何我能想到的搜尋字串，它會查詢我所有的日誌，就像它是一個普通文字（Plain File）一樣。但是，正如我們前面討論的那樣，這並不好，因為您最終可能會得到比您想要的更多的匹配。假設我要搜尋所有帶 id 為 5 的物件。幸運的是，我們的日誌聚合器非常聰明，可以在這個位置上提供幫助。

json.idNumber:5.0

搜尋結果如下

想知道你還能搜尋什麼？當滑鼠懸停在日誌記錄上時，只需單擊檔案圖示，就可以看到 Stackify 索引的所有欄位。能夠從日誌中獲得更多的價值，併在所有欄位中搜索，稱為結構化日誌。

發現 Java 異常詳情

您可能也註意到了這個紅色的 bug 圖示。這是因為我們透過自動顯示更多的背景關係來區別對待異常。點選它，我們會給出一個更深刻的觀點。

我們的庫不僅可以獲取完整的堆疊跟蹤，還可以獲取所有的 Web 請求細節，包括 essay-header、查詢字串和伺服器變數。在這個樣式中，有一個 “Logs” 選項卡，它提供了一個預先過濾的從應用程式中記錄日誌的檢視，在它發生的伺服器上，在異常之前和之後的一個很窄的時間視窗中，為異常提供更多的背景關係。想知道這個錯誤是多麼常見或頻繁，或者想檢視其他事件的詳細資訊？點選“檢視所有事件”按鈕，就可以看到！

我可以很快看到這個錯誤在最後一個小時發生了60次。錯誤和日誌是緊密相關的，在一個應用程式中可以發生大量的日誌記錄，異常有時會在噪聲中丟失。這就是為什麼我們也構建了一個錯誤指示板，給您同樣的統一檢視，但僅限於異常。

在這裡，我可以看到一些很棒的資料

• 在過去的幾分鐘裡，我的異常率有所上升；

• 我的大部分錯誤都來自於我的“測試”環境——大約每小時84次；

• 我有幾個新的錯誤剛剛開始出現（如紅色三角形所示）。

你是否曾經將你的應用程式釋出到生產中，並想知道 QA 漏掉了什麼？（不，我說的是 QA 會錯過一個錯誤……）錯誤指示板來救援。你可以實時看到一個趨勢——大量的紅色三角形，很多新的錯誤。圖上的大峰值?也許你的使用增加了，所以以前已知的錯誤被更多地擊中；可能有一些錯誤的程式碼（比如一個洩漏的SQL連線池），導致了比正常情況下更高的 SQL 超時錯誤率。

不難想象有很多不同的場景可以提供早期預警和檢測。嗯。早期預警和檢測。這引出了另一個很大的話題。

監控

如果能在某些時候得到提醒不是很好嗎

• 特定應用程式或環境的錯誤率突然增加？

• 一個特別解決的錯誤再次發生？

• 你記錄的某個動作不夠頻繁，等等？

Stackify 可以做上面所有的事情，下麵逐個看下

錯誤率

當我們檢視錯誤指示板時，我註意到我的“測試”環境每小時有大量的錯誤。從錯誤指示板中，單擊“出錯率”，然後選擇您希望為其配置警報的應用程式/環境

我可以為“錯誤/分鐘”和“完全錯誤”配置監視器，然後選擇“通知”選項卡來指定應該通知誰，以及如何通知。隨後，如果使用 Stackify 監控，我還可以在這裡配置其他警報:應用程式執行狀態、記憶體使用、效能計數器、自定義度量、ping檢查等等。

解決的錯誤和新的錯誤

早些時候，我在建立 Foo 物件時不檢查 null 值，從而引入了一個新的錯誤。我已經修正了這個錯誤，並透過觀察那個特定錯誤的細節來確認它。你們可以看到，上次發生在12分鐘前：

這是一個愚蠢的錯誤，但卻是一個容易犯的錯誤。我將把這個標記為“解析”，讓我做一些非常酷的事情:如果它回來了，請保持警惕。通知選單將允許我檢查我的配置，預設情況下，我將為所有的應用程式和環境同時接收新的和倒退的錯誤通知。

現在，如果同樣的錯誤在將來再次發生，我將會收到關於回歸的電子郵件它會顯示在儀錶盤上。當你“認為”你已經解決了這個問題並且想要確定的時候，這是一個很好的自動幫助。

日誌監控

有些東西不太容易監測。也許您有一個非同步執行的關鍵流程，它成功(或失敗)的惟一記錄是日誌記錄。在這篇文章的前面，我展示了針對您的結構化日誌資料進行深度查詢的能力，任何查詢都可以被儲存和監視。這裡有一個非常簡單的場景:我的查詢每分鐘執行一次，我們可以監視我們有多少匹配的記錄。

這是檢查系統健康的一個很簡單的方法，如果日誌檔案是唯一的指標。

Java 日誌最佳實踐

所有這些錯誤和日誌資料都是無價之寶，特別是當你退一步看一幅更大的圖片時。下麵是一個Java Web 應用程式的應用程式指示板，它包含所有的監視:

正如您所看到的，您在一瞥中得到了一些很好的背景關係資料，這些錯誤和日誌有助於：滿意度和 HTTP 錯誤率。您可以看到，使用者滿意度很高，而且 HTTP 錯誤率也很低。您可以快速開始向下挖掘，以檢視哪些頁面可能表現不好，以及出現了哪些錯誤:

在這篇文章中有很多內容要講，我覺得我只是觸及了錶面。如果你再挖深一點，甚至把手放在上面，你就可以!我希望這些Java日誌記錄最佳實踐能夠幫助您編寫更好的日誌，並節省時間故障排除。

我們所有的 Java 日誌應用程式都可以在 GitHub 上使用，您可以 註冊一個免費試用，以開始今天的 Stackify！

https://github.com/stackify

【關於投稿】

如果大家有原創好文投稿，請直接給公號傳送留言。

① 留言格式：
【投稿】+《 文章標題》+ 文章連結

② 示例：
【投稿】《不要自稱是程式員，我十多年的 IT 職場總結》：http://blog.jobbole.com/94148/

③ 最後請附上您的個人簡介哈~

看完本文有收穫？請轉發分享給更多人

關註「ImportNew」，提升Java技能