1. Обзор
Поскольку Hibernate обрабатывает взаимодействие с базой данных вместо нас, мы можем быстро разрабатывать код, связанный с базой данных. Но это может затруднить отладку сбоев, связанных с базой данных.
Следовательно, может быть полезно просмотреть взаимодействие Hibernate с базой данных. Например, SQL, сгенерированный Hibernate для чтения данных из таблицы.
В этом руководстве мы увидим различные уровни ведения журнала в Hibernate, которые можно использовать для достижения этой цели .
2. Запись SQL
На самом базовом уровне мы можем регистрировать операторы SQL, сгенерированные Hibernate, без передачи ему фактических значений параметров.
Hibernate использует категорию org.hibernate.SQL для регистрации этой информации. Итак, все, что нам нужно сделать, это установить уровень ведения журнала этой категории на DEBUG.
В Log4J нам нужно будет добавить элемент логгера в XML конфигурации:
<logger name="org.hibernate.SQL">
<level value="debug"/>
</logger>
Точно так же в Log4J2 мы добавим элемент Logger :
<Logger name="org.hibernate.SQL" level="debug"/>
И в Logback мы добавим элемент логгера :
<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 регистрирует входные параметры и полученные результаты, используя категорию org.hibernate.type.descriptor.sql с уровнем журнала TRACE . Теперь давайте добавим эту категорию в наши файлы конфигурации.
В 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 для просмотра вышеуказанной информации. Мы можем включать и отключать две категории независимо друг от друга .
Но имеет смысл включить org.hibernate.SQL , чтобы мы знали, к какому оператору SQL относятся значения параметров .
4. Активируйте статистику гибернации
Помимо значений параметров SQL и JDBC, Hibernate также может регистрировать статистику для каждого оператора SQL. Это может быть полезно для выявления потенциальных проблем с производительностью.
Hibernate использует категорию org.hibernate.stat для регистрации этой информации. Но Hibernate не всегда генерирует эту статистику, потому что это может плохо повлиять на производительность.
Во- первых, мы должны сказать Hibernate сгенерировать эту статистику, установив для свойства конфигурации hibernate.generate_statistics значение true .
Например, мы можем установить это свойство в нашем файле hibernate.cfg.xml :
<property name="hibernate.generate_statistics">true</property>
Наряду с этим свойством установка для категории org.hibernate.stat значения DEBUG будет регистрировать оператор со статистикой для каждого выполненного запроса . В конце сеанса также будет записан один многострочный оператор журнала, который будет содержать сводную статистическую информацию:
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.foreach.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 .