使用 Java Flight Recorder 監控 Hibernate 事件
1. 概述
在本教程中,我們將研究使用 Java Flight Recorder 在 Hibernate 生命週期執行期間記錄事件的過程。之後,我們將使用 Oracle 的JDK Mission Control工具來檢查記錄的事件並深入了解 Hibernate 的內部執行情況。
2. Java Flight Recorder和JDK Mission Control簡介
Java Flight Recorder (JFR) 是 Oracle、OpenJDK 和 Oracle JDK 的 Hotspot 虛擬機器提供的低階代理。它對於監視 Java 應用程式很有用。
Java Flight Recorder 代理程式記錄應用程式執行期間從 Java 虛擬機器和支援的框架(如 Hibernate)產生的事件。 JFR 將產生的事件記錄到一個檔案中,可以使用 Oracle 的 JDK Mission Control 工具對此檔案進行分析和視覺化。
3. 設定應用程式以發出 Hibernate-JFR 事件
Hibernate ORM 不會立即發出任何 Java Flight Recorder 事件。為了能夠從 Hibernate 產生事件,我們必須將hibernate-jfr
依賴項加入pom.xml
檔中:
<dependency>
<groupId>org.hibernate.orm</groupId>
<artifactId>hibernate-jfr</artifactId>
<version>6.4.4.Final</version>
</dependency>
值得注意的是, hibernate-jfr
jar 僅自 Hibernate 6.4 起可用。
3.1.配置範例 Spring Boot 應用程式
現在讓我們建立一個範例 Spring Boot 應用程序,使用spring-data-jpa
和ehcache
作為 Hibernate L2 快取來示範 Hibernate JFR 事件。我們將在本範例中使用的 Spring Boot 版本是 3.1.5。
範例應用程式使用 H2 資料庫。我們可以使用下面的 Spring 配置來為此類用例配置 Hibernate:
spring:
h2:
console.enabled: true
datasource:
url: jdbc:h2:mem:hibernatejfr
username: sa
password: password
driverClassName: org.h2.Driver
jpa:
database-platform: org.hibernate.dialect.H2Dialect
defer-datasource-initialization: true
show-sql: true # Print SQL statements
properties:
hibernate:
format_sql: true
generate_statistics: true
## Enable jdbc batch inserts
jdbc.batch_size: 4
order_inserts: true
javax.cache.provider: org.ehcache.jsr107.EhcacheCachingProvider
## Enable L2 cache
cache:
region.factory_class: org.hibernate.cache.jcache.JCacheRegionFactory
use_second_level_cache: true
use_query_cache: true
jakarta.persistence.sharedCache.mode: ENABLE_SELECTIVE
我們將使用 Spring JPA 和 Hibernate 6 作為 ORM 層建立一個簡單的 Spring Boot 應用程式來示範 JFR 事件。為簡潔起見,我們僅提供演示應用程式的類別圖:
配置應用程式後,讓我們在啟動應用程式時傳遞-XX:StartFlightRecording
作為 VM 參數,以飛行記錄模式啟動應用程式:
java -XX:StartFlightRecording=filename=myrecordingL2Cache.jfr -jar hibernatejfr-0.0.1-SNAPSHOT.jar
如果我們使用 IntelliJ Idea 啟動應用程序,我們可以透過 IDE Run/Debug Configurations
添加-XX:StartFlightRecording
VM 參數:
現在應用程式已準備好運行。首先,我們將啟動演示應用程式並使用 cURL 或 PostMan 存取一些 REST 端點。然後,我們將停止應用程式並驗證錄音是否保存在指定的檔案中。
或者,如果我們想在運行單元測試案例時捕獲事件,可以使用maven-surefire-plugin
應用 VM 參數在測試案例執行期間啟動飛行記錄。
3.2.配置日誌
我們可以啟用 Hibernate 配置屬性hibernate.generate_statistics
來產生日誌,列印 L2C 快取命中和 JDBC 連線等操作的統計資料。我們可以使用這些日誌來驗證二級快取是否設定正確。
啟用記錄時,飛行記錄器會在應用程式啟動時列印日誌。因此,我們應該留意確認 JFR 記錄正在運行的日誌行:
[0.444s][info][jfr,startup] Started recording 1. No limit specified, using maxsize=250MB as default.
[0.444s][info][jfr,startup]
[0.444s][info][jfr,startup] Use jcmd 27465 JFR.dump name=1 to copy recording data to file.
4. Hibernate JFR 事件的類型
hibernate-jfr
jar 定義了 Hibernate 在飛行記錄期間產生的事件,並且它遵循 SPI 機制將自身插入 Hibernate 生命週期中。 Java 中的服務提供者介面 (SPI) 架構提供了一種促進可擴展性、鬆散耦合、模組化和外掛程式架構的好方法。
hibernate-core
jar 聲明了 JFR jar 實作的服務提供者介面 (SPI) org.hibernate.event.spi.EventManager
。因此,當 Hibernate 偵測到類別路徑中存在hibernate-jfr
jar 時,Hibernate 會註冊它並在執行期間發出 JFR 事件。
hibernate-jfr
jar 中定義了以下事件:
-
CacheGetEvent
-
CachePutEvent
-
DirtyCalculationEvent
-
FlushEvent
-
JdbcBatchExecutionEvent
-
JdbcConnectionAcquisitionEvent
-
JdbcConnectionReleaseEvent
-
JdbcPreparedStatementCreationEvent
-
JdbcPreparedStatementExecutionEvent
-
PartialFlushEvent
-
SessionClosedEvent
-
SessionOpenEvent
我們可以看到這些事件的名稱是不言自明的。但是,某些事件(例如CacheGetEvent
和CachePutEvent
)僅在配置了 2 級快取時才會發布。同樣,以批次模式執行 JDBC 查詢時,會發布JdbcBatchExecutionEvent
。
此外,上述每個 Hibernate JFR 事件都具有描述所發出事件的詳細資訊的屬性。例如, SessionOpenEvent
具有以下屬性:
Hibernate 為不同類型的事件收集不同的屬性。對分析至關重要的一些重要屬性包括Start Time
、 Duration
、 End Time
和Event Thread
。 Session Identifier
是另一個重要的屬性,但 hibernate 並未收集所有事件類型的它。
5. 使用 JDK Mission Control 分析 JFR 事件
現在我們已經有了可供分析的 JFR 文件,讓我們深入 JDK Mission Control 來分析 JFR 文件。
5.1.在 Java Mission Control 中尋找 Hibernate ORM 事件
讓我們啟動 Java Mission Control 並透過導航到File
> Open File
選單項目來開啟 JFR 檔案。
載入文件後,我們會看到一個包含Automated Analysis Results
的登入頁面。此頁面提供了了解應用程式行為的窗口,並允許快速查看。但是,要查看 Hibernate 引發的事件,我們導航到「 Outline
」窗格中的「 Event Browser”
,並在Event Types Tree
部分下尋找「 Hibernate ORM”
:
5.2.在 JDK Mission Control 中對相關 Hibernate ORM 事件進行分組
現在,我們右鍵單擊Event Types Tree
下的Hibernate ORM
標題,然後按一下「 Create New Page Based on the Selected Event Types
」上下文功能表。 此操作會在Outline
側邊欄上建立一個名為「 Filtered Events
」的新頁面,其中顯示所有 Hibernate 事件。我們可以根據需要重命名Filtered Events
頁面。
現在,我們可以開啟新的Filtered Events
頁面,右鍵單擊表中的任何行,然後選擇Group By > Event Thread.
此操作根據Event Thread
屬性對表中的所有事件進行分組。按Event Thread
分組是在命令式程式設計範例中聚合相關事件的一種非常有效的方法:
在反應式或多執行緒範例中,我們在按Event Thread,
因為這可能會產生不連貫的結果,因為不同的執行緒可能計算了相關的應用程式邏輯。
5.3. JDK Mission Control中Hibernate ORM事件的基本分析
依事件執行緒將事件分組會在表格上方顯示一個新部分,顯示分組的事件。接下來,我們透過右鍵點擊標題並選擇Visible Columns > Total Duration
向該表新增另一列。 Total Duration
列有助於識別執行時間較長的執行緒:
選擇具有最大「 Total Duration
」的Event Thread
現在會顯示貢獻該時間的所有事件。如果我們按「 Start Time”,
我們可以視覺化 Hibernate 中的事件順序。
在上面的案例中,我們可以看到,在所有捕獲的事件中,JDBC 語句的執行和創建貢獻了「 Total Duration
」的大部分,其次是「 Cache Put Events
」。我們也可以看到執行的 JDBC 查詢。
六,結論
在本文中,我們簡要回顧了 Oracle 的 Java Flight Recorder 代理,並了解了從 Spring Boot 應用程式發出 Hibernate JFR 事件的過程。我們還使用 JDK Mission Control 工具對從應用程式捕獲的飛行記錄檔案進行了基本分析,並視覺化了 Hibernate ORM 的哪些部分花費了更長的時間。我們記錄了 ORM 層中發生的事件的順序以及執行的 JDBC 查詢。
範例應用程式的原始程式碼和 JFR 檔案可在 GitHub 上取得。