Статьи

Вход в спящий режим: советы и решения общих проблем

Ноябрь 19, 2018

Как решить некоторые из наиболее распространенных проблем Hibernate при правильной регистрации?

Конфигурация журналирования Hibernate является важной, но редко обсуждаемой темой. Правильная конфигурация может помочь вам обнаружить потенциальные проблемы во время разработки, а неправильная конфигурация может вызвать серьезные проблемы с производительностью. Это одна из причин, по которой я объясняю различные варианты конфигурации в моей новой книге Hibernate Советы: более 70 решений распространенных проблем Hibernate .

В этом посте мы поделимся двумя наиболее полезными советами по ведению журнала Hibernate из книги. Давайте начнем.

1. Решение наиболее распространенной проблемы производительности Hibernate

Давайте посмотрим на один из рецептов, включенных в книгу. Это поможет вам найти n + 1 выбор проблем в процессе разработки. Эта проблема производительности часто возникает, когда Hibernate должен инициализировать лениво извлеченные ассоциации между сущностями. К сожалению, эту проблему трудно найти в исходном коде, потому что вы просто вызываете метод get для атрибута, который отображает ассоциацию, например author.getBooks () . Если вы делаете это в цикле, который повторяет объекты списка авторов , Hibernate должен выполнить 1 запрос, чтобы загрузить n объектов Author и n дополнительных запросов для инициализации ассоциации. Это называется проблемой выбора n + 1, и это одна из самых распространенных проблем с производительностью.

Вы можете найти его, активировав компонент Статистика Hibernate, который обеспечивает простой способ подсчета всех выполненных запросов в вашей сессии Hibernate. Посмотрим, как это делается.

Как посчитать выполненные запросы в сеансе

проблема

Некоторые из моих вариантов использования медленные и, кажется, выполняют слишком много запросов.

Как подсчитать все запросы, выполненные в Hibernate Session ?

Решение

Самый простой способ подсчитать все выполненные запросы — активировать компонент статистики Hibernate. Затем Hibernate собирает много внутренней статистики и предоставляет ее в виде сообщения журнала и через API статистики.

ВНИМАНИЕ: не используйте это в производстве! Сбор статистической информации создает накладные расходы, которые замедляют работу вашего приложения.

По умолчанию компонент статистики Hibernate отключен. Вы можете активировать его, установив для параметра hibernate.generate_statistics значение true . Вы можете сделать это, предоставив системное свойство с тем же именем или установив параметр в файле persistence.xml .

01
02
03
04
05
06
07
08
09
10
<persistence>
    <persistence-unit name="my-persistence-unit">
        <description>Hibernate Tips</description>
        <provider>org.hibernate.jpa.HibernatePersistenceProvider</provider>
        <properties>
            <property name="hibernate.generate_statistics" value="true" />
            …
        </properties>
    </persistence-unit>
</persistence>

У вас есть два варианта доступа к статистике. Hibernate может записать подмножество с наиболее важной информацией каждого сеанса в файл журнала, или вы можете получить к ним доступ через API статистики.

Давайте сначала посмотрим на сообщения журнала. Hibernate записывает сообщение журнала, похожее на следующее, в конце каждого сеанса. Он показывает количество операторов SQL, время, затраченное на их подготовку и выполнение, а также взаимодействие с кешем второго уровня.

01
02
03
04
05
06
07
08
09
10
11
16:24:55,318 INFO [org.hibernate.engine.internal.StatisticalLoggingSessionEventListener] – Session Metrics {
  25659 nanoseconds spent acquiring 1 JDBC connections;
  22394 nanoseconds spent releasing 1 JDBC connections;
  1091216 nanoseconds spent preparing 12 JDBC statements;
  11118842 nanoseconds spent executing 12 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;
  16999942 nanoseconds spent executing 1 flushes (flushing a total of 17 entities and 17 collections);
  63915 nanoseconds spent executing 1 partial-flushes (flushing a total of 0 entities and 0 collections)

Вы также можете получить доступ к API статистики через интерфейс статистики Hibernate. Вы можете получить его из SessionFactory . Он предоставляет несколько методов получения, которые дают вам доступ к более подробной информации, чем вывод журнала.

1
2
3
Statistics stats = sessionFactory.getStatistics();
long queryCount = stats.getQueryExecutionCount();
long collectionFetchCount = stats.getCollectionFetchCount();

Исходный код

Вы можете найти ссылку на скачивание проекта с исполняемыми тестовыми примерами для этой подсказки Hibernate в книге .

Учить больше

Если вы хотите узнать больше о функциях журналирования Hibernate, вам следует взглянуть на главы:

  • Как регистрировать операторы SQL и их параметры
  • Как использовать комментарии к запросу для идентификации запроса

=============

Подсчет выполненных запросов может помочь найти недостатки и избежать проблем с производительностью. Но этого недостаточно. Вам также необходимо знать, какие запросы выполняет Hibernate и какие значения параметров он использует. При правильной конфигурации ведения журнала Hibernate запишет всю эту информацию в журнал.

=============

2. Как регистрировать операторы SQL и их параметры

проблема

Как настроить Hibernate таким образом, чтобы он записывал выполненные операторы SQL и использовал параметры связывания в файл журнала?

Решение

Hibernate использует две разные категории журналов и уровни журналов для записи выполненных операторов SQL и их параметров связывания:

  • Операторы SQL записываются как сообщения DEBUG в категорию org.hibernate.SQL .
  • Значения параметров привязки записываются в категорию org.hibernate.type.descriptor.sql с уровнем журнала TRACE .

Вы можете активировать и деактивировать их независимо друг от друга в конфигурации вашего журнала.

ПРЕДУПРЕЖДЕНИЕ. Регистрация всех запросов SQL и их привязок параметров привязки может замедлить работу вашего приложения и создать огромные файлы журналов.

Вы не должны активировать эти сообщения журнала в производстве.

Следующий фрагмент кода показывает пример конфигурации log4j, которая активирует их обоих.

01
02
03
04
05
06
07
08
09
10
11
12
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{HH:mm:ss,SSS} %-5p [%c] - %m%n
 
log4j.rootLogger=info, stdout
# basic log level for all messages
log4j.logger.org.hibernate=info
 
# SQL statements and parameters
log4j.logger.org.hibernate.SQL=debug
log4j.logger.org.hibernate.type.descriptor.sql=trace

Затем Hibernate записывает сообщения журнала, подобные следующим, в ваш файл журнала.

1
2
3
4
5
17:34:50,353 DEBUG [org.hibernate.SQL] - select author0_.id as id1_0_, author0_.firstName as firstNam2_0_, author0_.lastName as lastName3_0_, author0_.version as version4_0_ from Author author0_ where author0_.id=1
17:34:50,362 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([id1_0_] : [BIGINT]) - [1]
17:34:50,373 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([firstNam2_0_] : [VARCHAR]) - [Thorben]
17:34:50,373 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([lastName3_0_] : [VARCHAR]) - [Janssen]
17:34:50,374 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([version4_0_] : [INTEGER]) - [0]

Оператор SQL в фрагменте кода не так легко прочитать. Это станет намного лучше, если вы скажете Hibernate отформатировать его.

Вы можете сделать это, установив для параметра конфигурации hibernate.format_sql значение true . Вы можете предоставить его как системное свойство или установить его в файле persistence.xml , как в следующем фрагменте кода, или в файле hibernate.cfg.xml .

01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<persistence>
   <persistence-unit name="my-persistence-unit">
       <description>Hibernate Tips</description>
       <provider>
           org.hibernate.jpa.HibernatePersistenceProvider
       </provider>
       <exclude-unlisted-classes>false</exclude-unlisted-classes>
 
       <properties>
           <property name="hibernate.format_sql" value="true" />
 
           ...
       </properties>
   </persistence-unit>
</persistence>

В следующем фрагменте кода показан форматированный оператор SQL, который гораздо лучше читать, чем предыдущее сообщение.

01
02
03
04
05
06
07
08
09
10
11
12
13
14
15
16:42:56,873 DEBUG [org.hibernate.SQL] -
   select
       author0_.id as id1_0_,
       author0_.firstName as firstNam2_0_,
       author0_.lastName as lastName3_0_,
       author0_.version as version4_0_
   from
       Author author0_
   where
       author0_.id=?
16:42:56,926 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] - binding parameter [1] as [BIGINT] - [1]
16:42:56,950 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([id1_0_] : [BIGINT]) - [1]
16:42:56,965 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([firstNam2_0_] : [VARCHAR]) - [Thorben]
16:42:56,965 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([lastName3_0_] : [VARCHAR]) - [Janssen]
16:42:56,966 TRACE [org.hibernate.type.descriptor.sql.BasicExtractor] - extracted value ([version4_0_] : [INTEGER]) - [0]

Исходный код

Вы можете найти ссылку на скачивание проекта с исполняемыми тестовыми примерами для этой подсказки Hibernate в книге .

Делая ваши журналы лучше

Как уже упоминалось, активация сообщений уровня TRACE и DEBUG и отправка их в ваш журнал может привести к огромным файлам и даже замедлить работу вашего приложения. Однако они могут содержать фрагменты информации, которые важны для процесса отладки и могут помочь выявить критические ошибки, прежде чем они попадут в производство.

OverOps показывает вам последние 250 операторов уровня DEBUG, TRACE и INFO, которые были зарегистрированы до ошибки в работе, даже если они были отключены и не достигли файла журнала. Он также показывает состояние переменной за любым исключением, зарегистрированной ошибкой или предупреждением, не полагаясь на фактически зарегистрированную информацию. Вы можете увидеть полный исходный код и состояние переменной во всем стеке вызовов ошибки, даже на микросервисах и машинах.

Откройте для себя новый способ устранения ошибок в производстве. Посмотрите живую демоверсию OverOps .

Вывод

Чтобы получить больше подобных рецептов, ознакомьтесь с моей новой книгой « Советы по гибернации»: более 70 решений общих проблем Hibernate . Он дает вам более 70 готовых к использованию рецептов для таких тем, как базовые и расширенные сопоставления, ведение журналов, поддержка Java 8, кэширование и статически и динамически определяемые запросы. Всего за несколько дней вы можете получить электронную книгу за 2,99 долл. США и мягкую обложку за 12,99 долл. США на hibernate-tips.com .

Ссылка: Ведение журнала гибернации: советы и решения общих проблем от нашего партнера по JCG Торбена Янссена в блоге OverOps .
31
Share: