Hibernateのさまざまなロギングレベル

投稿日: 2022-10-25 2022-10-25
タグ: Hibernate, Logging, Persistence, sql

1. 概要

Hibernateがデータベースとの対話を処理するため、データベース関連のコードを迅速に開発できます。ただし、これにより、データベース関連の障害のデバッグが困難になる可能性があります。

したがって、Hibernateとデータベースの相互作用を表示すると便利な場合があります。たとえば、テーブルからデータを読み取るためにHibernateによって生成されたSQL。

このチュートリアルでは、これを実現するために使用できるHibernateのさまざまなレベルのロギングを確認します。

2. SQLのロギング

最も基本的なレベルでは、実際のパラメーター値が渡されることなく、Hibernateによって生成されたSQLステートメントをログに記録できます。

Hibernateはカテゴリorg.hibernate.SQLを使用してこの情報をログに記録します。したがって、このカテゴリのログレベルをDEBUGに設定するだけです。

Log4Jでは、構成XMLにlogger要素を追加する必要があります。

<logger name="org.hibernate.SQL">
     <level value="debug"/>
</logger>

同様に、Log4J2では、Logger要素を追加します。

<Logger name="org.hibernate.SQL" level="debug"/>

そして、Logbackに、logger要素を追加します。

<logger name="org.hibernate.SQL" level="DEBUG" />

これで、生成されたSQLがログに表示されます。

2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - insert into Employee 
(employeeNumber, name, title, id) values (?, ?, ?, ?)
2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - select employee0_.id as id1_0_, 
employee0_.employeeNumber as employee2_0_, employee0_.name as name3_0_, 
employee0_.title as title4_0_ from Employee employee0_

3. ロギングパラメータ値

通常、生成されたSQLで問題を特定できますが、SQLステートメントに渡されるパラメーターも表示したい場合があります。

Hibernateは、ログレベルがTRACE のorg.hibernate.type.descriptor.sqlカテゴリを使用して、入力パラメーターと取得した結果をログに記録します。それでは、このカテゴリを構成ファイルに追加しましょう。

Log4Jでは、次のことを行います。

<logger name="org.hibernate.type.descriptor.sql"> 
    <level value="trace"/> 
</logger>

Log4J2の場合：

<Logger name="org.hibernate.type.descriptor.sql" level="trace"/>

そして最後に、Logbackで：

<logger name="org.hibernate.type.descriptor.sql" level="TRACE" />

したがって、SQLステートメントに渡されたパラメーター値と実行結果を確認する必要があります。

2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - insert into Employee (employeeNumber, name, title, id) 
values (?, ?, ?, ?)
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [1] 
as [VARCHAR] - [001]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [2] 
as [VARCHAR] - [John Smith]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:52 - binding parameter [3] 
as [VARCHAR] - [null]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicBinder:64 - binding parameter [4] 
as [BIGINT] - [1]
2019-12-07 23:04:23 | DEBUG | [main] o.h.SQL:127 - select employee0_.id as id1_0_, 
employee0_.employeeNumber as employee2_0_, employee0_.name as name3_0_, 
employee0_.title as title4_0_ from Employee employee0_
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([id1_0_] :
 [BIGINT]) - [1]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([employee2_0_] :
 [VARCHAR]) - [001]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:60 - extracted value ([name3_0_] :
 [VARCHAR]) - [John Smith]
2019-12-07 23:04:23 | TRACE | [main] o.h.t.d.s.BasicExtractor:50 - extracted value ([title4_0_] :
 [VARCHAR]) - [null]

上記の情報を表示するためにorg.hibernate.SQLカテゴリを有効にする必要がないことに注意してください。 2つのカテゴリを個別に有効または無効にできます。

ただし、 org.hibernate.SQLを有効にして、パラメーター値がに関連するSQLステートメントを認識できるようにすることは理にかなっています。

4. HibernateStatisticsをアクティブ化する

SQLおよびJDBCパラメーター値とは別に、Hibernateは各SQLステートメントの統計をログに記録することもできます。これは、潜在的なパフォーマンスの問題を特定するのに役立ちます。

Hibernateはカテゴリorg.hibernate.statを使用してこの情報をログに記録します。ただし、Hibernateはパフォーマンスに悪影響を与える可能性があるため、これらの統計を常に生成するとは限りません。

まず、構成プロパティhibernate.generate_statisticsをtrue に設定して、これらの統計を生成するようにHibernateに指示する必要があります。

たとえば、hibernate.cfg.xmlファイルでこのプロパティを設定できます。

<property name="hibernate.generate_statistics">true</property>

このプロパティに加えて、カテゴリorg.hibernate.statをDEBUGに設定すると、実行された各クエリの統計を含むステートメントがログに記録されます。また、セッションの最後に、統計情報を要約した1つの複数行のログステートメントをログに記録します。

2019-12-07 23:25:18 | DEBUG | [main] o.h.s.i.StatisticsInitiator:101 - Statistics initialized 
[enabled=true]
2019-12-07 23:25:19 | DEBUG | [main] o.h.s.i.StatisticsImpl:729 - HHH000117: HQL: 
from com.baeldung.hibernate.logging.Employee, time: 22ms, rows: 1
2019-12-07 23:25:19 | INFO  | [main] o.h.e.i.StatisticalLoggingSessionEventListener:258 - 
Session Metrics {
    55600 nanoseconds spent acquiring 1 JDBC connections;
    178600 nanoseconds spent releasing 1 JDBC connections;
    2167200 nanoseconds spent preparing 2 JDBC statements;
    2426800 nanoseconds spent executing 2 JDBC statements;
    0 nanoseconds spent executing 0 JDBC batches;
    0 nanoseconds spent performing 0 L2C puts;
    0 nanoseconds spent performing 0 L2C hits;
    0 nanoseconds spent performing 0 L2C misses;
    47098900 nanoseconds spent executing 1 flushes (flushing a total of 1 entities 
    and 0 collections);
    0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities 
    and 0 collections)
}

統計が有効になっていることを示すログの最初の行に注意してください。

5. すべてのアクティビティをログに記録

データベースとのHibernateの相互作用をさらに深く掘り下げるには、カテゴリorg.hibernateのロギングを有効にする必要があります。このカテゴリには、Hibernateによってログに記録されたすべてのメッセージが含まれます。

ただし、このカテゴリは大量のログ出力を作成する可能性があるため、注意して使用する必要があります。

6. 結論

このチュートリアルでは、Hibernateでのさまざまなレベルのロギングを見ました。ログに記録された情報は、開発中に非常に役立ちます。ただし、アプリケーションのパフォーマンスに悪影響を与える可能性があるため、本番環境でこれを有効にする場合は注意が必要です。

そしてもちろん、このチュートリアルに付属するコードは、GitHubのにあります。

getdocs

13036