Hibernate 6 で slf4j-simple を使って binding parameters を表示する

Hibernate 6 で slf4j-simple で binding parameters を表示しようとした場合、2つの罠があります。抜け出し方を解説します。

# 罠1: slf4j-simple の設定が読まれない

simplelogger.properties を配置しても読んでくれないので悩んでいたのですが、以下の Q&A を見て解決することができました。

https://stackoverflow.com/questions/11639997/how-do-you-configure-logging-in-hibernate-4-to-use-slf4j

なぜかシステム プロパティを設定しなくても SLF4J が読み込まれるのは Logback が使われるときだけというコードになっているため、システム プロパティの `org.jboss.logging.provider` に `slf4j` を設定する必要があるそうです。コマンドラインで

```
java -Dorg.jboss.logging.provider=slf4j
```

のようにしても良いですが、メイン クラス冒頭に以下の static イニシャライザーを加えてしまうのが、IDE から実行する場合にはお手軽かと思います。

```java
    static {
        System.setProperty("org.jboss.logging.provider", "slf4j");
    }
```

Hibernate のチュートリアルの場合、TestCase を拡張している EntityManagerIllustrationTest などのクラスがメイン クラス相当になりますが、この場合は `setUp()` への追加で大丈夫です。

```java
	protected void setUp() throws Exception {
        System.setProperty("org.jboss.logging.provider", "slf4j");
```

# 罠2: binding parameters を表示するログ カテゴリーが変更されている

Hibernate 6 から binding parameters を表示するログ カテゴリーが `log4j.logger.org.hibernate.type.descriptor.sql` から以下の2つに変更になったようです。

* `org.hibernate.orm.jdbc.bind` - INSERT 時のパラメーター
* `org.hibernate.orm.jdbc.extract` - SELECT などで返ってきた値

なお、公式の文書 [27.2. Logging](https://docs.jboss.org/hibernate/orm/6.0/userguide/html_single/Hibernate_User_Guide.html#best-practices-logging) によれば `log4j.logger.org.hibernate.type.descriptor.jdbc` を設定することになっているのですが、これは機能しませんでした。

したがって、罠1を回避した上で [SimpleLogger の JavaDoc](https://www.slf4j.org/api/org/slf4j/impl/SimpleLogger.html) に従って simplelogger.properties を以下のように設定すると、binding parameter を表示することができます。

```simplelogger.properties
org.slf4j.simpleLogger.log.org.hibernate.orm.jdbc.bind=trace
org.slf4j.simpleLogger.log.org.hibernate.orm.jdbc.extract=trace
```

persistence.xml で以下のように show_sql と format_sql を指定してある場合、

```xml
            <property name="hibernate.show_sql" value="true" />
            <property name="hibernate.format_sql" value="true" />
```

以下のように、binding parameters や抽出された値がログに出力されます。

```
Hibernate: 
    insert 
    into
        EVENTS
[main] DEBUG org.hibernate.orm.jdbc.bind - binding parameter [1] as [TIMESTAMP] - [2022-04-25 00:26:19.433]
        (EVENT_DATE, title, id) 
    values
        (?, ?, ?)
[main] DEBUG org.hibernate.orm.jdbc.bind - binding parameter [2] as [VARCHAR] - [A follow up event]
[main] DEBUG org.hibernate.orm.jdbc.bind - binding parameter [3] as [BIGINT] - [2]
[main] WARN org.hibernate.orm.deprecation - HHH90000021: Encountered deprecated setting [javax.persistence.lock.timeout], use [jakarta.persistence.lock.timeout] instead
Hibernate: 
    select
        e1_0.id,
        e1_0.EVENT_DATE,
        e1_0.title 
    from
        EVENTS e1_0
[main] DEBUG org.hibernate.orm.jdbc.extract - extracted value ([1] : [BIGINT]) - [1]
[main] DEBUG org.hibernate.orm.jdbc.extract - extracted value ([2] : [TIMESTAMP]) - [2022-04-25 00:26:19.377]
[main] DEBUG org.hibernate.orm.jdbc.extract - extracted value ([3] : [VARCHAR]) - [Our very first event!]
[main] DEBUG org.hibernate.orm.jdbc.extract - extracted value ([1] : [BIGINT]) - [2]
[main] DEBUG org.hibernate.orm.jdbc.extract - extracted value ([2] : [TIMESTAMP]) - [2022-04-25 00:26:19.433]
[main] DEBUG org.hibernate.orm.jdbc.extract - extracted value ([3] : [VARCHAR]) - [A follow up event]
```