天天看點

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

作者:粥屋與包屋

本文我們讨論一些有價值的技術,這些技術在調查特定場景時可以更輕松。 開頭我們研究了一種識别Java應用程式和關系資料庫伺服器之間的連接配接問題的方法。 我們已經在《Java 故障診斷 - 使用 profiler 來識别應用程式執行的SQL查詢》中讨論了剖析SQL查詢,但有時問題會在應用程式與DBMS建立通信時出現。 這種情況甚至會導緻應用程式完全沒有響應,這就使得找到這種問題的原因變得非常重要。

接着,将向你展示我最喜歡的了解特定執行場景背後的代碼的方法之一—使用調用圖的簡單方法, 調用圖是應用程式對象之間依賴關系的可視化表示。 我發現調用圖很有幫助,特别是在處理我以前從未見過的混亂代碼時。 而且,我相信大多數開發者在他們的職業生涯中的某個階段都要處理混亂的代碼庫,了解這種方法會很有幫助。

前面的文章讨論了可視化應用程式執行的最常用方法之一—​執行stack。 你學會了如何在使用 VisualVM 進行采樣或分析時生成執行stack,以及如何使用它來識别執行延遲。 然後,我們将使用執行stack的不同表現形式:火焰圖。 火焰圖是一種可視化應用程式執行情況的方法,它同時關注執行的代碼和執行時間。 從一個額外的角度檢視相同的資料,有時可以幫助你更容易地找到你正在尋找的東西。火焰圖為你提供了應用程式執行的不同視角,這有助于你識别潛在的延遲和性能問題。 最後,我們将讨論分析應用程式的持久層在不使用關系型資料庫而使用我們稱之為 "NoSQL技術系列" 的不同持久化方法時如何工作的技術。

對于我們在本章中讨論的主題,VisualVM 是不夠的。 VisualVM 是一個優秀的免費工具,在我用 profiler 調查的90%以上的場景中都會用到它,但它有其局限性。

為了示範我們在本文中讨論的功能,我們将使用 JProfiler(http://mng.bz/RvVn),這是一個授權的 profiler。 JProfiler 提供了我們用VisualVM讨論的所有内容,但它也有VisualVM沒有的功能(價格不高)。 你可以利用該軟體提供的試用期,嘗試對我們在本文中使用的例子進行剖析,并對 VisualVM 和 JProfiler 之間的差異形成你自己的看法。

檢測JDBC連接配接的問題

我們在《Java 故障診斷 - 使用 profiler 來識别應用程式執行的SQL查詢》中讨論了很多關于調查SQL查詢問題的細節。 但是,應用程式需要與DBMS的連接配接來發送查詢的情況又是怎樣的呢? 對連接配接管理的疏忽會導緻問題,我們将讨論這些問題以及如何找到它們的根本原因。

有些人可能會争辯說,應用程式使用的架構和庫在大多數情況下負責連接配接管理,是以此類問題不再發生。 然而,經驗告訴我,這些問題仍然會發生,主要是因為開發者依賴于許多事情是自動的。 有時候,我們應該使用不太常見的、更低級的實作,而不是依賴于架構所提供的東西,這也是大多數這類問題發生的原因。

讓我告訴你一個我最近不得不處理的問題的故事。 在一個特定的服務中(用Spring實作), 開發人員必須實作一個不太常見的功能:取消存儲過程(在資料庫層面運作的過程)的執行。 這個實作并不複雜,但它需要直接通路連接配接對象。 在大多數情況下,讓 Spring 在幕後使用該連接配接就足夠了。 Spring 是一個健壯的架構,易于定制,你可以很容易地通路它所管理的連接配接 ,但在你通路這些連接配接之後,它還會管理這些連接配接嗎?答案是有時。 而這個 "有時" 正是讓事情變得有趣(也更有挑戰性)的原因。

開發人員發現,在Spring管理事務的标準方法執行中,架構也在最後關閉了連接配接。 該程式被取消了,采用了批處理的方式,從 Spring Batch 中實作。 在這種情況下,架構不會關閉連接配接,你必須管理它們。 開發人員在兩種情況下都使用了同樣的方法,沒有意識到在其中一種情況下沒有正确關閉連接配接,這可能會造成很大的問題。 幸運的是,這個開發錯誤被及時發現,沒有造成任何傷害。

這個故事說明了為什麼你在這所學的技術仍然适用。 你使用的架構的名字并不重要,你可能永遠不知道幕後發生的一切, 是以準備好以任何方式調查你的應用程式的執行情況将永遠是相關的。

我們将使用在 https://gitee.com/tunte/java-troubleshooting-sample.git 提供的項目 da-ch8-ex1。 這個項目定義了一個有巨大問題的簡單應用:它的一個方法 "忘記" 關閉它打開的JDBC連接配接。 一個應用程式建立了一個JDBC連接配接來向DBMS發送SQL查詢。 一旦應用程式不再需要它們,JDBC連接配接必須始終被關閉。 所有的DBMS都為用戶端(即應用程式)提供了獲得有限數量連接配接的能力(通常是一個小數量,如100)。 當一個應用程式打開所有這些連接配接但不關閉它們時,它就無法連接配接到資料庫伺服器。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 1

DBMS 并不總是提供精确的100個連接配接。這個數字在資料庫層面是可以配置的。 當使用一個資料庫時,最好找到(通常是通過詢問資料庫管理者)應用程式可以打開的最大連接配接數。

注意 為了簡化我們的示範,我們将使用一個持久化層,将連接配接數限制為10。

讓我們開始項目 da-ch8-ex1 并分析該應用程式的行為。 這個項目定義了一個簡單的應用程式,在資料庫中存儲有關産品的詳細資訊。 該應用在 /products 路徑上暴露了一個端點。 通過調用該端點,該應用程式根據其存儲在資料庫中的資料傳回詳細資訊。 當你第一次調用端點時,應用程式幾乎是即時響應的。 但是,當你向同一個端點發送第二個請求時,應用程式在30秒後回應了一個錯誤資訊,如圖 2 所示。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 2

這個應用程式的實際作用對于我們的示範來說并不重要,是以我不會去讨論它的功能細節, 但是想象一下,一個從事單獨項目的朋友打電話給你尋求幫助,并展示了這樣一個問題。 他們沒有給你很多關于他們的應用程式如何工作的細節(在現實世界的應用程式中,這可能是一個複雜的商業案例)。 你還能幫助他們嗎?我們從分析他們向我們展示的行為開始。

我們想找出導緻問題行為的原因。 你通路了日志,立即懷疑問題與JDBC連接配接有關。 在下面的片段中顯示的異常資訊告訴你,應用程式無法建立連接配接,很可能是因為DBMS不允許打開其他連接配接。 但讓我們假設我們不能總是依賴日志。 最後,我們無法确定你的應用程式使用的另一個架構或庫沒有産生直接的異常資訊:

java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30014ms.
     at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696)
     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197)
     at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162)
     at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
     at com.example.repositories.PurchaseRepository.findAll(PurchaseRepository.java:31)
     at com.example.repositories.PurchaseRepository$FastClassBySpringCGLIB$d661c9a0.invoke(<generated>)           

正如我在第7章中所建議的,每一次剖析調查都應該從抽樣開始,這可以讓你對執行情況有一個概覽, 以及繼續研究所需的細節。如果你使用 VisualVM,采樣結果會像圖 3 一樣。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 3

經過采樣和觀察日志中的異常stack跟蹤,我們知道我們的應用程式在連接配接到DBMS時出現了問題。 但是,是什麼導緻了這個問題呢?這可能是兩件事中的一件:

  • 由于一些基礎設施或網絡問題,應用程式和DBMS之間的通信失敗。
  • DBMS 不想為我們的應用程式提供一個連接配接:
    • 因為有一個認證問題
    • 因為應用程式已經消耗了DBMS能夠提供的所有連接配接。

由于在我們的案例中,問題總是在第二次發送請求時發生(有一個确定的模式來重制它),我們可以排除通信問題。 這一定是DMBS沒有提供連接配接。但這不可能是一個認證問題,因為第一次調用工作得很好。 不太可能是憑證發生了變化,是以最合理的原因是我們的應用程式有時沒有關閉連接配接。 現在我們隻需要找到發生這種情況的地方。記住,遇到問題的方法不一定是導緻問題的方法。 可能這個方法是 "不走運" 的,在别人 "吃掉" 所有的連接配接後,它還試圖獲得一個連接配接。

但是在VisualVM中,你不能明确地調查JDBC連接配接,是以我們不能用它來确定哪個連接配接保持開放。 相反,我們将使用 JProfiler 繼續我們的調查。 将 JProfiler 附加到一個正在運作的Java程序上,與使用 VisualVM 非常相似。 讓我們按照這個方法一步一步來。

首先,選擇 JProfiler 主視窗左上角的 Start Center,如圖 4 所示。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 4

出現一個彈出視窗(圖 5),你可以選擇左邊的快速附件,以獲得本地運作的所有Java程序的清單。 選擇你要剖析的程序,然後選擇啟動。 就像VisualVM一樣,你可以通過主類的名稱或程序ID(PID)來識别該程序。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 5

JProfiler 會問你是否要使用抽樣或工具(工具相當于我們在VisualVM中所說的剖析),如圖6 所示。 我們選擇 instrumentation,因為我們正在使用 profiler 來擷取JDBC連接配接的細節,進而希望更深入地分析執行情況。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 6

在左邊菜單的資料庫下,選擇 JDBC。然後啟動JDBC分析,如圖 7 所示。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 7

一旦剖析開始,我們對兩個頁籤最感興趣: Connections 和 Connection Leaks(圖 8)。 這些頁籤向我們展示了應用程式打開的DBMS的連接配接細節,我們将利用它們來确定問題的根源。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 8

現在是時候重制這個問題并剖析執行情況了。 向 /products 端點發送一個請求,讓我們看看會發生什麼。 Connections 頁籤顯示許多連接配接被建立,如 圖 9所示。 由于我們不知道這個應用程式是做什麼的,許多連接配接不一定意味着問題。 但我們期望應用程式關閉這些連接配接,以便在需要時可以獲得其他連接配接。 我們需要弄清楚的是,該應用程式是否正确地關閉了這些連接配接。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 9

Connection Leaks 頁籤證明了我們的猜測(圖 10);該應用程式不僅打開了許多連接配接,而且在端點響應之後,這些連接配接仍然沒有關閉。 這是連接配接洩漏的一個明顯迹象。如果我們不明确地啟動CPU分析(我一會兒會告訴你如何做),你隻會看到建立連接配接的線程的名字。 有時線程的名字就足夠了,在這種情況下,你根本不需要啟動CPU剖析。 然而,在像這樣的情況下,它并沒有告訴我們足夠的資訊來識别建立連接配接的代碼。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 10

但這還不夠,不是嗎?我們曾懷疑應用程式在獲得與DBMS的連接配接時出現了問題。 現在我們需要使用 profiler 的CPU剖析功能來識别代碼庫中建立連接配接并忘記關閉的部分。

我們仍然需要一種方法來識别建立洩漏連接配接的代碼。 幸運的是,JProfiler 也能幫助我們做到這一點,但我們需要在啟用CPU剖析功能後重新進行練習。 在激活CPU剖析的情況下,JProfiler 将為每個洩漏的連接配接顯示建立該連接配接的方法的stack跟蹤。

圖 11 顯示了如何啟用CPU剖析以及如何找到每個洩漏連接配接的stack跟蹤。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 11

讓我們直接進入我們的例子 da-ch8-ex1 中的代碼。 我們觀察到,該方法确實建立了一個似乎沒有被關閉的連接配接。 我們找到了根本原因!

清單 1 識别問題的根源

public Product findProduct(int id) throws SQLException {
    String sql = "SELECT * FROM product WHERE id = ?";

    Connection con = dataSource.getConnection(); // his line creates a connection that is never closed.
    try (PreparedStatement statement = con.prepareStatement(sql)) {
      statement.setInt(1, id);
      ResultSet result = statement.executeQuery();

      if (result.next()) {
        Product p = new Product();
        p.setId(result.getInt("id"));
        p.setName(result.getString("name"));
        return p;
      }
    }
    return null;
  }           

項目 da-ch8-ex2 糾正了代碼。 通過在 try-with-resources 塊中加入連接配接,當不再需要連接配接時,應用程式将在 try 塊的末尾關閉連接配接。

清單 2 通過關閉連接配接來解決問題

public Product findProduct(int id) throws SQLException {
    String sql = "SELECT * FROM product WHERE id = ?";


    try (Connection con = dataSource.getConnection();  // The connection is declared in the try-with-resources block, closing the connection at the end of the try block.
         PreparedStatement statement = con.prepareStatement(sql)) {
      statement.setInt(1, id);
      ResultSet result = statement.executeQuery();

      if (result.next()) {
        Product p = new Product();
        p.setId(result.getInt("id"));
        p.setName(result.getString("name"));
        return p;
      }
    }
    return null;
  }           

在應用修正後,我們可以再次對該應用程式進行剖析。 現在 JProfiler 中的 Connection 頁籤顯示我們隻建立了一個連接配接,而 Connection Leaks 頁籤是空的,這證明問題确實得到了解決(圖 12)。 當你測試該應用程式時,你也看到你可以向 /products 端點發送多個請求。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 12

你是否想知道是否有一個最佳實踐來避免現實世界場景中的此類問題? 我建議開發人員在每次實作或修複錯誤後,花10分鐘左右的時間,用剖析器測試他們所做的能力。 這種做法可以幫助在開發的早期階段就發現由錯誤的查詢或錯誤的連接配接管理造成的延遲問題。

使用調用圖了解應用程式的代碼設計

我們将讨論我最喜歡的了解應用程式類設計的技術之一:将執行情況可視化為一個調用圖。 這種技術在處理混亂的代碼時特别有幫助,這是處理新應用程式的一個必然結果。

到目前為止,我們已經使用堆棧痕迹來了解執行。 執行stack記錄是很有價值的工具,我們已經看到我們可以用它們做多少事情。 它們很有幫助,因為它們以文本的方式直接表示,這使得它們可以被列印在日志中(通常作為異常stack痕迹)。 但從視覺角度來看,它們在快速識别對象和方法調用之間的關系方面并不出色。 調用圖是表示 profiler 收集的資料的不同方式,它更注重對象和方法調用之間的關系。

為了示範如何獲得調用圖,我們将使用提供的例子 da-ch8-ex2 來示範如何使用調用圖來快速了解哪些對象和方法在執行過程中起作用,而無需分析代碼。 當然,我們的想法并不是要完全避開代碼;你最終還是會對代碼進行挖掘,但通過首先使用調用圖, 你會對前面發生的事情有一個更好的了解。

我們将繼續使用 JProfiler 進行示範。 由于調用圖是表示 CPU profiler 資料的一種方式,我們首先需要開始CPU剖析。 圖 13 顯示了如何啟動CPU剖析,其結果是堆棧跟蹤(在 JProfiler 中被稱為調用樹)。 我們将調查在調用應用程式所暴露的 /products 端點時發生了什麼。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 13

右鍵單擊stack跟蹤中的一行,選擇 Show Call Graph,将收集到的關于執行的資料以調用圖的形式可視化(圖 14)。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 14

JProfiler 将生成一個調用圖表示,重點是你在生成調用圖時選擇的那一行所定義的方法。 你最初隻知道這個方法是從哪裡調用的,以及這個方法調用了什麼。 你可以進一步浏覽并觀察整個調用鍊(圖 15)。 調用圖還提供了關于執行時間和調用次數的細節,但其重點主要是對象和方法調用之間的關系。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 15

使用火焰圖來發現性能問題

另一種可視化剖析執行的方法是使用火焰圖。 如果說調用圖側重于對象和方法調用之間的關系,那麼火焰圖對于識别潛在的延遲最有幫助。 它們隻是以不同的方式看到方法執行stack提供的相同細節,但是,正如本章介紹中提到的, 相同資料的其他表現形式可能有助于識别特定資訊。

我們将繼續使用例子 da-ch8-ex2 進行示範。 我們将使用 JProfiler 将執行stack表示法改為火焰圖,并讨論新表示法的優勢。

如前面所讨論的,在生成了一個調用樹之後, 你可以使用頂部菜單欄中的 Analyze 項将其改為火焰圖,如圖 16 所示。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 16

火焰圖是一種将執行樹表示為stack的方法。 之是以取這個花哨的名字,是因為該圖通常看起來像一個火焰。 這個棧的第一層是線程執行的第一個方法。 然後,上面的每一層都被下面的層所調用的方法所共享。 圖17向你展示了為圖16中的執行樹建立的火焰圖。

一個方法可以調用多個其他方法。 在火焰圖中,被調用的方法将出現在同一層上。 在這種情況下,每個的長度是相對于調用它的方法(下面那一層)所花費的時間。 在圖17中,你可以看到 ProductRepository 類中的方法 findById() 和 PurchaseRepository 類中的方法 findAll() 都是由 ProductService 類中的 getProductNamesForPurchases() 調用。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 17

在圖 18 中,我們觀察到 ProductService 類中的 getProductNamesForPurchases() 是 ProductRepository 類中 findById() 方法和 PurchaseRepository 類中 findAll() 方法的底層。 此外,findById() 和 findAll() 共享同一個層。 但是請注意,它們的長度并不相同。 長度是相對于調用者的執行而言的,是以在這種情況下,findById() 的執行時間要比 findAll() 的執行時間短。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 18

你可能已經注意到,這個圖很容易讓人迷失。 而且這隻是一個用于學習的簡單例子;在真實世界的應用中,火焰可能要複雜得多。 為了減輕這種複雜性,你可以使用 JProfiler 根據方法、類或包的名稱來給各層着色。 圖19顯示了如何使用着色來标記火焰圖中的特定層。 你使用頂部菜單中的 Colorize 項來添加着色規則。 你可以添加多個着色規則來指定哪些層應該被着色以及你喜歡的顔色。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖19

在圖 20 中,你可以看到我是如何突出顯示名稱中含有 “Purchase” 一詞的方法的級别,并将其染成藍色。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 20

分析 NoSQL 資料庫的查詢

應用程式通常使用關系型資料庫,但在許多情況下,某些實作需要不同的持久化技術。 我們稱這些為NoSQL技術,而我們實作的應用程式可以從大量的此類實作中進行選擇。 一些最知名的例子是 MongoDB、Cassandra、Redis和Neo4J。 一些 profiler,如 JProfiler,可以攔截應用程式發送至特定NoSQL伺服器的查詢,以與資料庫合作。

JProfiler 可以攔截發送到MongoDB和Cassandra的事件, 當你在調查使用這種持久化實作的應用程式的行為時,這些細節可能有助于節省時間。 出于這個原因,我們将使用一個小應用程式來示範使用JProfiler來觀察應用程式與MongoDB資料庫的互動。 項目da-ch8-ex3與MongoDB一起工作。 該應用實作了幾個端點:一個是在資料庫中存儲産品的詳細資訊,另一個是傳回所有先前添加的産品的清單。 為了簡單起見,一個産品隻用一個名字和一個唯一的ID來表示。

你首先需要在本地安裝一個MongoDB伺服器,項目 da-ch8-ex3 将連接配接到該伺服器。 你可以從官方頁面下載下傳并安裝MongoDB社群伺服器:https://www.mongodb.com/try/download/community。 一旦你安裝了伺服器,你就可以啟動項目 da-ch8-ex3。 我們還将把JProfiler附在這個過程中。 要開始監控MongoDB事件,在左側菜單中選擇資料庫下的MongoDB部分并開始記錄。 為了觀察JProfiler如何呈現事件,我們将調用該應用程式暴露的兩個端點。 你可以使用cURL指令(如下面的片段)或Postman等工具來調用這兩個端點:

# Adds a product named “Beer” to the database
curl -XPOST http://localhost:8080/product/Beer

# Gets all the products in the database
curl http://localhost:8080/product           

圖 21顯示了被JProfiler攔截的兩個事件。 該工具顯示了與每個事件相關的stack痕迹(調用樹)。我們可以得到關于調用次數和執行時間的詳細資訊。

Java 故障診斷 - 使用先進的可視化工具進行剖析資料

圖 21

結語

像VisualVM這樣的免費工具提供了大量的小工具,可以幫助任何調查。 但是像JProfiler這樣的授權工具可以通過不同的方式來表現調查資料,使調查更加有效。

有時應用程式在連接配接到DBMS時遇到問題。 通過使用JProfiler,你可以更容易地調查與關系型資料庫伺服器的JDBC連接配接問題。 你可以評估連接配接是否保持打開,并确定代碼中 "忘記 "關閉連接配接的部分。

調用圖是可視化執行stack的一種不同方式,主要關注對象和方法調用之間的關系。 由于這個原因,調用圖是一個很好的工具,你可以用來更容易地了解應用程式執行背後的類設計。

火焰圖為可視化剖析資料提供了一個不同的視角。 你可以使用火焰圖來更容易地發現造成執行延遲的區域和長stack痕迹。 你可以給火焰圖中的特定層着色,以更好地可視化執行。

一些授權工具提供了擴充功能,如調查應用程式之間或你的應用程式和NoSQL資料庫伺服器之間的通信。

繼續閱讀