Журнал SQL и производительность

Любая проблема производительности в Hibernate видна в том SQL, который он отправляет. До сих пор запросы печатал hibernate.show_sql, но у него есть недостатки: он пишет прямо в консоль в обход системы журналирования, поэтому его вывод нельзя отфильтровать или направить в файл, и он не показывает значения параметров. В настоящем проекте SQL идёт через систему журналирования (logging), а запросы за вас считает статистика Hibernate.

Журнал через Logback

Hibernate пишет сообщения через библиотеку JBoss Logging, которая подхватывает Logback, если он есть. Добавьте зависимость:

<!-- pom.xml -->
<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
  <version>1.5.38</version>
</dependency>

Создайте src/main/resources/logback.xml:

<!-- src/main/resources/logback.xml -->
<configuration>
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%-5level %logger{20} - %msg%n</pattern>
    </encoder>
  </appender>
 
  <logger name="org.hibernate.SQL" level="DEBUG"/>
  <logger name="org.hibernate.orm.jdbc.bind" level="TRACE"/>
 
  <root level="WARN">
    <appender-ref ref="CONSOLE"/>
  </root>
</configuration>

Уберите hibernate.show_sql из persistence.xml. Сохранение автора и статьи теперь выводит:

DEBUG org.hibernate.SQL - insert into Author (name,id) values (?,?)
TRACE o.h.orm.jdbc.bind - binding parameter (1:VARCHAR) <- [Анна]
TRACE o.h.orm.jdbc.bind - binding parameter (2:BIGINT) <- [1]
DEBUG org.hibernate.SQL - insert into Post (author_id,title,views,id) values (?,?,?,?)
TRACE o.h.orm.jdbc.bind - binding parameter (1:BIGINT) <- [1]
TRACE o.h.orm.jdbc.bind - binding parameter (2:VARCHAR) <- [Статья 1]
TRACE o.h.orm.jdbc.bind - binding parameter (3:INTEGER) <- [0]
TRACE o.h.orm.jdbc.bind - binding parameter (4:BIGINT) <- [1]

Журнал	Уровень	Что показывает
`org.hibernate.SQL`	`DEBUG`	Каждый SQL-запрос
`org.hibernate.orm.jdbc.bind`	`TRACE`	Значения параметров

В значениях параметров бывают персональные данные, поэтому журнал bind — только для разработки. Spring Boot тоже использует Logback; там те же журналы настраиваются строкой logging.level.org.hibernate.SQL=debug.

Подсчёт запросов

Включите статистику в persistence.xml:

<!-- src/main/resources/META-INF/persistence.xml -->
<property name="hibernate.generate_statistics" value="true"/>

и читайте её из фабрики:

// src/main/java/com/example/blog/Stats.java
Statistics stats = emf.unwrap(SessionFactory.class).getStatistics();
stats.clear();
 
emf.runInTransaction(em -> em.createQuery("select p from Post p", Post.class)
        .getResultList()
        .forEach(p -> p.getAuthor().getName()));
IO.println("Без join fetch, запросов: " + stats.getPrepareStatementCount());
 
stats.clear();
emf.runInTransaction(em -> em.createQuery("select p from Post p join fetch p.author", Post.class)
        .getResultList()
        .forEach(p -> p.getAuthor().getName()));
IO.println("С join fetch, запросов: " + stats.getPrepareStatementCount());

Без join fetch, запросов: 4
С join fetch, запросов: 1

На данных Seed это проблема N+1, выраженная числом. Такая проверка хорошо подходит для теста.

Пакетная вставка

Hibernate умеет отправлять много команд insert за одно обращение к базе. Добавьте <property name="hibernate.jdbc.batch_size" value="20"/> и сохраните 100 статей:

Вставлено: 100, запросов: 4

Без этого свойства тому же коду нужно 103 запроса. Пакеты не работают с GenerationType.IDENTITY: там каждый insert должен выполниться сразу, чтобы получить id.

Привычки, которые сохраняют скорость

делайте @ManyToOne и @OneToOne ленивыми, а связанные данные загружайте через join fetch или графы сущностей;
задайте hibernate.default_batch_fetch_size как страховку от N+1;
для списков и отчётов выбирайте в запись только нужные поля, а не целые сущности;
разбивайте на страницы всё, что может расти;
используйте настоящий пул соединений (HikariCP) вместо встроенного.

Частая ошибка

Если включить журнал org.hibernate.SQL, но забыть убрать hibernate.show_sql, каждый запрос печатается дважды:

DEBUG org.hibernate.SQL - select p1_0.id,p1_0.author_id,p1_0.title,p1_0.views from Post p1_0 where p1_0.views>=?
Hibernate: select p1_0.id,p1_0.author_id,p1_0.title,p1_0.views from Post p1_0 where p1_0.views>=?

Используйте что-то одно, а в рабочей среде — журнал, уровень которого можно поменять без пересборки.

Спасибо, что читаете!