お知らせ
2023.12.5(Tue)
技術
2018.2.14(Wed)
作業効率UP！ Spring + log4jdbcで実行したSQLのログを出力する方法
目次
こんにちは、飯塚です。
実行したSQLを再現するために「？」を埋める作業が、面倒くさいことこの上ないと思ったことはありませんか？ 特に、条件に日付や時間を含んでいる場合の精神的ストレスは、無視できません。プログラマーとして、こういう面倒な作業の存在とは、闘っていかなくてはなりません！
ということで、今回はlog4jdbcで、実行したSQLのログを出力してみようと思います。
log4jdbcで、実行したSQLのログを出力
今回やりたいことは、こんな感じです。
ログ出力(設定前)
[main] DEBUG org.hibernate.SQL - select * from MyData where t_chara like ?
ログ出力(設定後)
[main] DEBUG jdbc.sqlonly - 1. select * from MyData where t_chara like '%テスト%'
log4jdbcというJDBCドライバーを使うことで、実行したSQLをログ出力できます。実行したSQLを即座に確認できれば、開発でも障害対応でも便利なこと間違いなしです。
参考ページ
環境
- PostgreSQL
- 9.3
※なお後述しますが、MySQLなど他のDBでも応用できるはずです。
pom.xmlの設定
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<version>${slf4j.version}</version>
<scope>compile</scope>
</dependency>
<dependency>
<groupId>org.bgee.log4jdbc-log4j2</groupId>
<artifactId>log4jdbc-log4j2-jdbc4</artifactId>
<version>1.16</version>
</dependency>log4jdbcはログファザードにSLF4jを使っているので、pomにいなければ追加します。
log4jdbc-log4j2の仲間にlog4jdbc-remixがありますが、log4jdbc-remixはもう開発が終了しているので非推奨です。時代はlog4jdbc-log4j2です！
persistence.xmlの設定
(変更前)
<property name="javax.persistence.jdbc.driver" value="org.postgresql.Driver" /> <property name="hibernate.connection.url" value="jdbc:postgresql://localhost:5432/testdb" />
(変更後)
<property name="javax.persistence.jdbc.driver" value="net.sf.log4jdbc.DriverSpy" /> <property name="hibernate.connection.url" value="jdbc:log4jdbc:postgresql://localhost:5432/testdb" />
log4jdbcを使うために、ドライバーとURLの2つだけ変更をします。※database.propertiesでDB接続の設定していても、変更内容は同じです。
DriverSpyは、log4jdbc用のドライバーです。JDBC URLに「:log4jdbc」を追加するだけで、有名なドライバー(postgresql.Driver, mysql.jdbc.Driver, OracleDriver…etc)であれば、勝手に読み込んでくれます！
ちなみにDriverSpy.javaのソースを見てみると、URLが「jdbc:log4」で始まっていることが確認できた後に、先頭の9文字を切り取っています。(「jdbc:log4jdbc:postgresql」→ 「jdbc:postgresql」)
log4jdbc.log4j2.propertiesの設定
以下の内容で src/main/resources/log4jdbc.log4j2.properties を作成します。
log4jdbc.spylogdelegator.name=net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator
Delegatorは和訳すると「委任者」という意味で、デザインパターンの1つです。他のクラスに処理を任せることで、処理を任せる先を意識することなく、何回も使えるという考え方のようです。
今回の場合はJDBC SpyのログイベントをSLF4J(Simple Logging Facade for Java) に任せるという意味のようです。
logback.xmlの設定
<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE logback>
<configuration scan="true" scanPeriod="30 seconds">
<contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator">
<resetJUL>true</resetJUL>
</contextListener>
<jmxConfigurator/>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<!-- ログ内の日付をSQL実行可能なフォーマットに変換する -->
<!-- 'MM/dd/yyyy' → 'yyyy/MM/dd' -->
<!-- 'HH:mm:ss.SSS' → 'HH:mm:ss' -->
<pattern>
%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36}- %replace(%replace(%msg){'(\d{2})/(\d{2})/(\d{4})' ,'$3/$1/$2'}){'(\d{2}):(\d{2}):(\d{2})\.(\d{3})', '$1:$2:$3'}%n
</pattern>
</encoder>
</appender>
<!-- log4jdbc-log4j2 -->
<logger name="jdbc.sqlonly" level="OFF"/>
<logger name="jdbc.sqltiming" level="DEBUG"/>
<logger name="jdbc.audit" level="OFF"/>
<logger name="jdbc.resultset" level="OFF"/>
<logger name="jdbc.resultsettable" level="OFF"/>
<logger name="jdbc.connection" level="OFF"/>
<root level="info">
<appender-ref ref="STDOUT"/>
</root>
</configuration>SLF4J からLogback (ログ出力ライブラリ) を使用するための設定です。Lo4j → Logging → Logbackという変遷により、Logbackが現在のスタンダードです。
また、ログ出力ライブラリの併用 (Log4j + Logbackなど) は推奨されていないので、Logback一択に切り替えたほうがよさそうです。
ログの出力パターンは、実行したSQLと実行時間を出力する「sqltiming」のみDEBUGにしました。大量のログによって処理が遅くなるのを防ぐためです。それぞれの出力パターンの例は補足として下にまとめました。
参考ページ
ログのレイアウトについて
通常のレイアウトの場合、時間が条件に指定されているSQLは以下のようになります。
23:06:21.866 [main] DEBUG jdbc.sqltiming - org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:56)
1. select * from MyData where t_date = '01/13/2018 00:00:00.000'
{executed in 1 msec}
この日付と時刻の書式では、SQLをそのまま実行できません。仕方ないので、 上記のlogback.xmlのように正規表現で書式を変換することにしました。
23:19:04.182 [main] DEBUG jdbc.sqltiming- org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:56)
1. select * from MyData where t_date = '2018/01/13 00:00:00'
{executed in 2 msec}
【補足】logback.xml jdbcログ出力例一覧
jdbc.sqlonly
23:51:54.422 [main] DEBUG jdbc.sqlonly - 1. select * from MyData where t_chara like '%テスト%'
jdbc.sqltiming
23:51:54.443 [main] DEBUG jdbc.sqltiming -
1. select * from MyData where t_chara like '%テスト%' {executed in 2 msec}
jdbc.audit
23:51:54.451 [main] DEBUG jdbc.audit - 1. Connection.new Connection returned org.hibernate.service.jdbc.connections.internal.DriverManagerConnectionProviderImpl.getConnection(DriverManagerConnectionProviderImpl.java:204) 23:51:54.452 [main] DEBUG jdbc.audit - 1. Connection.getAutoCommit() returned true org.hibernate.service.jdbc.connections.internal.DriverManagerConnectionProviderImpl.getConnection(DriverManagerConnectionProviderImpl.java:214) 23:51:54.457 [main] DEBUG jdbc.audit - 1. Connection.getMetaData() returned org.postgresql.jdbc4.Jdbc4DatabaseMetaData@1bb266b3 org.hibernate.engine.jdbc.internal.JdbcServicesImpl.configure(JdbcServicesImpl.java:119) 23:51:54.570 [main] INFO org.hibernate.dialect.Dialect - HHH000400: Using dialect: org.hibernate.dialect.PostgreSQLDialect 23:51:54.577 [main] DEBUG jdbc.audit - 1. Connection.getCatalog() returned testdb org.hibernate.engine.jdbc.internal.JdbcServicesImpl.configure(JdbcServicesImpl.java:148) 23:51:54.997 [main] DEBUG jdbc.audit - 1. Connection.getAutoCommit() returned true org.hibernate.service.jdbc.connections.internal.DriverManagerConnectionProviderImpl.getConnection(DriverManagerConnectionProviderImpl.java:186) 23:51:55.003 [main] DEBUG jdbc.audit - 1. PreparedStatement.new PreparedStatement returned org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:161) 23:51:55.003 [main] DEBUG jdbc.audit - 1. Connection.prepareStatement(select * from MyData where t_chara like ?) returned net.sf.log4jdbc.sql.jdbcapi.PreparedStatementSpy@7862f56 org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:161) 23:51:55.006 [main] DEBUG jdbc.audit - 1. PreparedStatement.setString(1, "%テスト%") returned org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$1.doBind(VarcharTypeDescriptor.java:57) 23:51:55.015 [main] DEBUG jdbc.audit - 1. PreparedStatement.executeQuery() returned net.sf.log4jdbc.sql.jdbcapi.ResultSetSpy@22295ec4 org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:56) 23:51:55.026 [main] DEBUG jdbc.audit - 1. PreparedStatement.getMaxRows() returned 0 org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:485) 23:51:55.027 [main] DEBUG jdbc.audit - 1. PreparedStatement.getQueryTimeout() returned 0 org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:488) 23:51:55.027 [main] DEBUG jdbc.audit - 1. PreparedStatement.close() returned org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:499) 23:51:55.028 [main] DEBUG jdbc.audit - 1. Connection.getAutoCommit() returned true org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.isAutoCommit(LogicalConnectionImpl.java:308) 23:51:55.028 [main] DEBUG jdbc.audit - 1. Connection.isClosed() returned false org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.releaseConnection(LogicalConnectionImpl.java:237) 23:51:55.028 [main] DEBUG jdbc.audit - 1. Connection.getWarnings() returned null org.hibernate.engine.jdbc.spi.SqlExceptionHelper.handleAndClearWarnings(SqlExceptionHelper.java:261) 23:51:55.028 [main] DEBUG jdbc.audit - 1. Connection.clearWarnings() returned org.hibernate.engine.jdbc.spi.SqlExceptionHelper.handleAndClearWarnings(SqlExceptionHelper.java:268)
jdbc.resultset
※単純なSELECT文でも170行ものログが出力されるので、基本的に使わなそうです。
23:52:56.891 [main] DEBUG jdbc.resultset - 1. ResultSet.new ResultSet returned org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:56) 23:52:56.893 [main] DEBUG jdbc.resultset - 1. ResultSet.getMetaData() returned org.postgresql.jdbc4.Jdbc4ResultSetMetaData@142269f2 org.hibernate.loader.custom.CustomLoader$Metadata.<init>(CustomLoader.java:654) 23:52:56.895 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.897 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.897 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.898 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト1 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.898 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.898 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.898 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.899 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 88 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.899 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.900 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 77 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.900 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.901 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.901 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.903 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-01 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.903 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.903 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 15:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 2 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト2 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.904 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.905 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 77 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.905 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.905 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 66 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.905 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.905 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.905 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.906 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-02 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.906 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.906 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 10:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.906 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.906 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.906 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 4 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.906 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.907 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト4 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.907 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.909 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.909 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.909 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 55 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.909 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.909 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 44 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.909 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.909 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.910 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.910 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-04 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.910 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.910 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 00:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.910 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.910 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 5 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト5 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 44 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.911 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.912 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 33 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.912 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.912 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.912 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.912 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-05 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.912 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 19:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 7 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト7 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.913 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 22 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 11 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-07 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.914 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 09:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 8 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト8 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.915 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 11 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.916 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.916 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 0 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.916 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.916 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.916 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.916 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-08 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.916 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.917 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 04:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.917 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.917 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.917 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 9 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.917 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.917 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト9 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.918 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.918 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.918 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.918 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 0 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.918 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.918 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned -11 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.918 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-09 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 23:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.919 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 10 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト10 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned -11 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned -22 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.920 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned false org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-10 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 18:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.921 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 3 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.922 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.922 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト3 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.922 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.922 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.922 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.922 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 66 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.922 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.923 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 55 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.923 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.923 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned true org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.923 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.923 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-03 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.923 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 05:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned true org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(id) returned 6 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.getString(t_chara) returned テスト6 org.hibernate.type.descriptor.sql.VarcharTypeDescriptor$2.doExtract(VarcharTypeDescriptor.java:66) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.924 [main] DEBUG jdbc.resultset - 1. ResultSet.getInt(t_int) returned 1 org.hibernate.type.descriptor.sql.IntegerTypeDescriptor$2.doExtract(IntegerTypeDescriptor.java:66) 23:52:56.925 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.925 [main] DEBUG jdbc.resultset - 1. ResultSet.getShort(t_small) returned 33 org.hibernate.type.descriptor.sql.SmallIntTypeDescriptor$2.doExtract(SmallIntTypeDescriptor.java:66) 23:52:56.925 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.925 [main] DEBUG jdbc.resultset - 1. ResultSet.getBigDecimal(t_big) returned 22 org.hibernate.type.descriptor.sql.DecimalTypeDescriptor$2.doExtract(DecimalTypeDescriptor.java:67) 23:52:56.925 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.925 [main] DEBUG jdbc.resultset - 1. ResultSet.getBoolean(t_bool) returned true org.hibernate.type.descriptor.sql.BooleanTypeDescriptor$2.doExtract(BooleanTypeDescriptor.java:66) 23:52:56.925 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.926 [main] DEBUG jdbc.resultset - 1. ResultSet.getDate(t_date) returned 2018-01-06 org.hibernate.type.descriptor.sql.DateTypeDescriptor$2.doExtract(DateTypeDescriptor.java:67) 23:52:56.926 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.926 [main] DEBUG jdbc.resultset - 1. ResultSet.getTime(t_time) returned 14:00:00 org.hibernate.type.descriptor.sql.TimeTypeDescriptor$2.doExtract(TimeTypeDescriptor.java:67) 23:52:56.926 [main] DEBUG jdbc.resultset - 1. ResultSet.wasNull() returned false org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:66) 23:52:56.926 [main] DEBUG jdbc.resultset - 1. ResultSet.next() returned false org.hibernate.loader.Loader.processResultSet(Loader.java:939) 23:52:56.928 [main] DEBUG jdbc.resultset - 1. ResultSet.close() returned void org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:525)
jdbc.resultsettable
※jdbc.sqlonlyやjdbc.sqlonlyと併用しないとログに表示されないようです。
00:00:22.146 [main] DEBUG jdbc.sqltiming - org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:56)
1. select * from MyData where t_chara like '%テスト%'
{executed in 2 msec}
00:00:22.167 [main] INFO jdbc.resultsettable -
|---|--------|------|--------|------|-------|-----------|---------|
|id |t_chara |t_int |t_small |t_big |t_bool |t_date |t_time |
|---|--------|------|--------|------|-------|-----------|---------|
|1 |テスト1 |1 |88 |77 |false |2018-01-01 |15:00:00 |
|2 |テスト2 |1 |77 |66 |false |2018-01-02 |10:00:00 |
|4 |テスト4 |1 |55 |44 |false |2018-01-04 |00:00:00 |
|5 |テスト5 |1 |44 |33 |false |2018-01-05 |19:00:00 |
|7 |テスト7 |1 |22 |11 |false |2018-01-07 |09:00:00 |
|8 |テスト8 |1 |11 |0 |false |2018-01-08 |04:00:00 |
|9 |テスト9 |1 |0 |-11 |false |2018-01-09 |23:00:00 |
|10 |テスト10 |1 |-11 |-22 |false |2018-01-10 |18:00:00 |
|3 |テスト3 |1 |66 |55 |true |2018-01-03 |05:00:00 |
|6 |テスト6 |1 |33 |22 |true |2018-01-06 |14:00:00 |
|---|--------|------|--------|------|-------|-----------|---------|jdbc.connection
23:55:06.869 [main] DEBUG jdbc.connection - open connections: 1 (1)
hibernate.propertiesの設定
以上の設定だけでもSQLのログは確認できますが、以下のエラーが出力されてしまいます。
22:59:11.984 [main] ERROR jdbc.sqltiming - 1. Connection.createClob() org.postgresql.util.PSQLException: 方法 org.postgresql.jdbc4.Jdbc4Connection.createClob() はまだ装備されていません。
まだ実装していないメソッドがあることを教えてくれているだけなので、出力させないようにしたいと思います。
以下の内容で src/main/resources/hibernate.properties を作成します。
hibernate.jdbc.lob.non_contextual_creation=true
まとめ
以上で設定完了です。これで地道かつ非生産的な作業から解放されました！
今回はじめてログ関連の設定を触ってみましたが、INFOレベルであっても読まないログは出力のする必要がない気がしました。もっと必要な情報だけをピンポイントで出力できるようにカスタマイズしたいです。
ITエンジニアリング事業部 チーフ
A.Iizuka
技術の入門・まとめ系を中心に書いてます。あとで読み返したいと感じていただける記事を目指しています。
MOST VIEWED ARTICLES
よく見られている記事
