Як доводити N + 1: trace та statistics

1. «Здається, гальмує»

У початківця-розробника є природна звичка: якщо щось гальмує, значить, «треба оптимізувати». Проблема в тому, що без вимірювання ви не знаєте, що саме оптимізувати. Це як лікувати температуру, не вимірявши її: можна, звісно, «про всяк випадок» випити все з аптечки, але це не медицина — це квест «вгадай таблетку». Hibernate в цьому сенсі особливо підступний, бо вміє виконувати SQL не лише там, де ви цього очікуєте, а й «по дорозі»: під час обходу колекції, під час логування, під час виклику toString(), під час size() колекції тощо.

Тому нам потрібен baseline — відправна точка, з якою порівнюють зміни. Baseline відповідає на запитання: «Скільки SQL реально пішло в базу, коли я виконав ось цей сценарій читання, на ось цих даних, у межах ось такої транзакції». І тут ключове слово — «той самий». Якщо ви один раз запускали на 5 замовленнях, а вдруге на 50, ви вже не порівнюєте: ви просто дивитеся два різні фільми й намагаєтеся зрозуміти, чому фінал у них різний.

Тому діємо як у лабораторії: спочатку фіксуємо сценарій читання як метод, який можна викликати повторно; потім фіксуємо інструменти спостереження (SQL trace та statistics); далі робимо вимірювання; і лише потім обговорюємо, що змінювати. Ми поки що не лікуємо N+1 — ми вчимося його доводити.

Щоб далі не розпорошуватися на різні демо, зафіксуємо один і той самий сценарій: список замовлень плюс доступ до customer.email. Він стане baseline на кілька лекцій поспіль, і далі ми змінюватимемо не предмет вимірювання, а лише те, як сам сценарій читає дані.

2. Два мікроскопи: SQL trace та Statistics

Коли кажуть «подивіться SQL», зазвичай мають на увазі логи org.hibernate.SQL. Це вже дуже корисно: ви бачите, які SELECT реально пішли в PostgreSQL. Але логи схожі на відеозапис з місця злочину: усе видно, та якщо ви не вмієте швидко рахувати й порівнювати, можна втопитися в деталях. Саме тому нам потрібен другий мікроскоп — Hibernate Statistics. Він не показує текст запитів, зате показує цифри: скільки statementʼів підготовлено, скільки сутностей завантажено, скільки колекцій ініціалізовано. Це схоже на приладову панель автомобіля: вона не розповість, як улаштований двигун, але за стрілками ви розумієте, що машина реально робить.

Щоб не плутатися, зафіксуємо порівняння в таблиці — це той рідкісний випадок, коли таблиця краща за будь-який художній абзац:

І важлива ремарка: query count можна отримати різними способами, але в межах курсу найпряміший і найчесніший шлях — брати його з Hibernate Statistics, бо це вбудований інструмент. Пізніше можна обговорювати DataSource-proxy та інші штуки, але ми зараз не на виставці «який інструмент модніший». Ми працюємо в лабораторії: чим простіше й відтворюваніше, тим краще.

4. Увімкнюємо SQL trace та statistics

SQL trace та statistics не обов’язково мають бути увімкнені завжди. Ба більше, якщо увімкнути все і скрізь, логи стануть такими шумними, що ви почнете мріяти про життя лісника без інтернету (там теж є N+1, але це комарі). У нашому курсі для цього й вигадані профілі: sql-trace вмикає детальний SQL, а stats — статистику.

Нижче — мінімальні фрагменти конфігурації, які дають нам видимість без перетворення застосунку на генератор логів. Зверніть увагу: ми не використовуємо hibernate.show_sql як «println для SQL», а використовуємо нормальний logging — так простіше контролювати рівень і формат.

# application-sql-trace.yml
logging:
  level:
    org.hibernate.SQL: DEBUG         # Друкуємо сам SQL
    org.hibernate.orm.jdbc.bind: TRACE # Друкуємо bind-параметри (значення ?)

spring:
  jpa:
    properties:
      hibernate:
        format_sql: true             # Робимо SQL у логах читабельнішим

Якщо ви ввімкнете такий профіль, ви побачите сам SQL (org.hibernate.SQL) і bind-параметри (org.hibernate.orm.jdbc.bind). Іноді параметрів забагато — але для діагностики N+1 це дуже корисно, бо ви побачите, що повторюється один і той самий запит, тільки id щоразу інший.

А статистика вмикається ще простіше:

# application-stats.yml
spring:
  jpa:
    properties:
      hibernate:
        generate_statistics: true # Увімкнюємо Hibernate Statistics (за замовчуванням вимкнено)

Запускаємо застосунок із профілями (приблизно так, спосіб залежить від вашого запуску):

./gradlew bootRun --args='--spring.profiles.active=local,sql-trace,stats' # Важливо: профілі мають збігатися під час порівняння

Якщо ви не любите команди, можна вмикати профілі в IDE. Головне — щоб умови експерименту були однакові для порівняння.

5. query count: лічильник запитів vs час

Найпростіша, але дуже потужна метрика — це кількість SQL-операцій за один сценарій читання. Для N+1 вона особливо показова, бо N+1 майже завжди проявляється як лінійне зростання: було 20 замовлень — стало 21 запит; стало 200 замовлень — стало 201 запит. Іноді навіть гірше: якщо в циклі ви чіпаєте дві lazy-зв’язки, то отримаєте приблизно 1 + N + N, тобто 1 + 2N. І ось це «2N» — уже той момент, коли база починає нервово кашляти.

Чому не треба починати з вимірювання часу? Бо час дуже шумний. Сьогодні ваш ноутбук вирішив оновити IDE, завтра в PostgreSQL прогрівся кеш, післязавтра ви запускали це після міграцій, і все було гірше. А query count — це майже завжди чітка структурна метрика: або запит пішов, або ні. Вона не пояснює все (один важкий запит може бути гіршим за десять легких), але чудово ловить N+1, бо N+1 — саме структурна проблема.

У нашому курсі ми будемо брати query count через Hibernate Statistics, використовуючи getPrepareStatementCount(). Це не абсолютний універсальний лічильник усього, що могло статися навколо бази, а практичний proxy для query count в одному лабораторному сценарії. Для ловлі N+1 цього більш ніж достатньо: патерн лінійного зростання він показує дуже надійно.

6. Hibernate Statistics: вимірювання query count

Коли ви вперше бачите Statistics API, є спокуса або «не чіпати, бо страшно», або навпаки «рахувати все підряд і втопитися». Ми зробимо акуратно: нам потрібні лише три операції. Перша — отримати об’єкт Statistics. Друга — clear() перед запуском сценарію, щоб вимірювання не було накопичувальним. Третя — взяти getPrepareStatementCount() після сценарію і надрукувати.

І тримаємо один baseline без стрибків: список замовлень і доступ до customer.email. На ньому легко спершу побачити N+1, а потім перевірити, як змінюється поведінка, коли список поводиться стабільно.

Зробимо невеликий helper у пакеті labsupport. Він житиме рівно там, де йому місце — у навчальній інфраструктурі, а не в домені замовлень (бо замовлення не мають знати, скільки SQL вони породили… інакше почнуть цим пишатися).

package com.example.commerce.labsupport;

import jakarta.persistence.EntityManagerFactory;
import org.hibernate.SessionFactory;
import org.hibernate.stat.Statistics;
import org.springframework.stereotype.Component;

@Component
public class HibernateStats {
    private final Statistics stats;

    public HibernateStats(EntityManagerFactory emf) {
        // Отримуємо Hibernate-специфічний SessionFactory з JPA-фабрики
        this.stats = emf.unwrap(SessionFactory.class).getStatistics();
    }

    public Statistics stats() {
        // Повертаємо Statistics, щоб у runnerʼі можна було викликати clear() і читати лічильники
        return stats;
    }
}

Зверніть увагу на важливу деталь: ми «розгортаємо» EntityManagerFactory до SessionFactory через unwrap(). Це нормальний, офіційний шлях, коли ви хочете отримати доступ до Hibernate-специфічного API в межах курсу. Ми не робимо цього «в бізнесі» на кожне завдання, але в лабораторії — цілком доречно.

Тепер нам потрібен відтворюваний read-сценарій. Нехай це буде наш базовий сценарій: читаємо список замовлень і друкуємо orderNumber + customer.email. Саме цей getCustomer().getEmail() і буде потенційним тригером N+1 (залежно від fetch-налаштувань і поточного контексту).

package com.example.commerce.orders.query;

import com.example.commerce.orders.entity.PurchaseOrder;
import jakarta.persistence.EntityManager;
import org.springframework.stereotype.Service;
import org.springframework.transaction.annotation.Transactional;

@Service
public class OrderReadService {
    private final EntityManager em;

    public OrderReadService(EntityManager em) {
        this.em = em;
    }

    @Transactional(readOnly = true)
    public void printOrdersWithCustomerEmail() {
        // Важливо: один фіксований запит до root entity (те саме "1" у N+1)
        var orders = em.createQuery("select o from PurchaseOrder o", PurchaseOrder.class)
                .getResultList();

        for (var o : orders) {
            // Доступ до o.getCustomer() потенційно може тригерити lazy-завантаження (те саме "N")
            System.out.println(o.getOrderNumber() + " " + o.getCustomer().getEmail());
        }
    }
}

Так, метод виглядає іграшковим. Це нормально. Лабораторний метод має бути простим, інакше ви не зрозумієте, що саме викликало SQL. У реальному проєкті замість println() буде збирання DTO, але з погляду ORM-поведінки різниці майже немає: доступ до поля — це доступ до поля.

Важливо: це і є baseline-сценарій. Далі ми не вигадаємо новий read-метод заради нового експерименту, а розбиратимемо саме цей.

І тепер — сам вимір. Нам потрібен маленький runner, який виконає сценарій і надрукує proxy-лічильник запитів. Щоб не тягнути сюди тестові анотації (про тести у нас буде окремий модуль), зробимо CommandLineRunner під профіль, наприклад lab.

package com.example.commerce.labsupport;

import com.example.commerce.orders.query.OrderReadService;
import org.springframework.boot.CommandLineRunner;
import org.springframework.context.annotation.Profile;
import org.springframework.stereotype.Component;

@Profile("lab")
@Component
public class NPlusOneLabRunner implements CommandLineRunner {
    private final OrderReadService service;
    private final HibernateStats hStats;

    public NPlusOneLabRunner(OrderReadService service, HibernateStats hStats) {
        this.service = service;
        this.hStats = hStats;
    }

    @Override
    public void run(String... args) {
        // 1) Очищуємо лічильники, щоб вимірювання було «за один запуск»
        hStats.stats().clear();

        // 2) Запускаємо відтворюваний read-сценарій
        service.printOrdersWithCustomerEmail();

        // 3) Друкуємо кількість prepared statements як практичний proxy для query count
        System.out.println("кількість SQL-запитів (proxy) = " + hStats.stats().getPrepareStatementCount()); // кількість SQL-запитів (proxy) = 21
    }
}

Рівно три важливі рядки: clear(), виклик сценарію, друк лічильника. Усе. Якщо ви бачите, що query proxy підозріло зростає разом із кількістю замовлень — у вас є перший залізобетонний сигнал.

Тепер у нас є чесне вимірювання. Наступне інженерне запитання — вже не «яку анотацію смикнути», а які дані цей сценарій узагалі зобов’язаний читати, а які ми тягнемо за звичкою.

7. SQL trace: як у журналі побачити повторюваний патерн N+1

Цифри важливі, але цифри без змісту — це як чек із магазину без списку товарів: зрозуміло, що дорого, але незрозуміло, хто винен. SQL trace якраз відповідає на запитання «які саме запити повторюються». Для N+1 ми шукаємо дуже характерну картину: один запит на список кореневих сутностей, а потім серію однакових SELECT по пов’язаних даних із різними параметрами.

Припустімо, наш сценарій читає замовлення, а потім чіпає order.getCustomer().getEmail(). Часто лог виглядає приблизно так (приклад спрощений, щоб ви не втонули в aliasʼах і зайвих колонках):

-- 1) основний запит
select o.id, o.order_number, o.status, o.customer_id
from purchase_order o;

-- 2) повторюваний запит (N разів)
select c.id, c.email, c.first_name, c.last_name
from customer c
where c.id = ?;

Якщо у вас 20 замовлень, ви побачите один основний запит і приблизно 20 однакових запитів до customer (а bind-параметри будуть різні). Ось це і є повторюваний SQL-патерн. Сама форма запиту не зобов’язана збігатися буква в букву, але структура буде впізнаваною: where c.id = ? повторюється багато разів.

А якщо ви чіпаєте колекцію order.getItems().size(), то повторюваний патерн буде іншим, але ідея та сама:

-- 1) основний запит
select o.id, o.order_number
from purchase_order o;

-- 2) повторюваний запит (N разів)
select oi.order_id, oi.id, oi.product_id, oi.quantity
from order_item oi
where oi.order_id = ?;

І тут є тонкий момент, який часто дивує початківців: навіть size() може ініціалізувати колекцію (залежить від реалізації та умов), і ви раптово платите окремим SELECT на кожне замовлення. Тому ми й казали в попередній лекції: N+1 приносить не лише «явний обхід items», а й «невинне звернення».

Щоб спростити собі життя під час читання SQL trace, корисно дотримуватися дуже простого алгоритму мислення. Спочатку ви шукаєте, який запит був першим (root list). Потім дивитеся нижче: чи є серія запитів з однаковою формою. І якщо є — перевіряєте, чи справді їхня кількість приблизно дорівнює кількості елементів у root list. Це і буде ваш N у N+1.

8. Діагностичний workflow: відтворити → виміряти → порівняти

Поки ми розглядали інструменти окремо, усе виглядає доволі просто. На практиці люди ламають діагностику не складністю Hibernate, а власною неакуратністю експерименту. Тому важливо мати короткий, повторюваний робочий процес. Він виглядає майже як шкільна лабораторна робота (і це добре, бо шкільні лабораторні — один із небагатьох видів мистецтва, де люди справді щось вимірюють).

Ось схема процесу, яку корисно тримати в голові:

flowchart TD
    A[Обираємо один read-сценарій] --> B[Фіксуємо однакові умови запуску]
    B --> C[Увімкнюємо sql-trace та stats]
    C --> D[Очищуємо статистику]
    D --> E[Запускаємо сценарій]
    E --> F[Дивимося на кількість запитів]
    E --> G[Читаємо SQL trace і шукаємо повторюваний шаблон]
    F --> H[Фіксуємо baseline]
    G --> H[Фіксуємо baseline]

Зверніть увагу: у цій лекції ми свідомо зупиняємося на етапі baseline. Якщо ви спробуєте «лагодити» до того, як зафіксували baseline, ви опинитеся в типовій пастці: «мені здається, стало краще» — і ніхто (включно з вами самими через тиждень) не зможе це довести.

І ще одне правило: сценарій має виконуватися в межах стабільної транзакції. У нашому прикладі це гарантує @Transactional(readOnly = true) на методі printOrdersWithCustomerEmail(). Це не лише про LazyInitializationException. Це ще й про те, що ви хочете вимірювати поведінку в нормальних умовах одиниці роботи, а не в напіврозірваному контексті.

9. Типові помилки під час діагностики N+1

Помилка №1: порівнювати різні сценарії й називати це «до/після».
Дуже поширена пастка: ви спочатку виміряли метод, який друкує лише orderNumber, а потім виміряли метод, який друкує orderNumber + customer.email + items.size(), і зробили висновок, що «стало гірше». Це не «гірше», це просто інший сценарій з іншими вимогами. Для чесного порівняння змінюйте один фактор за раз: або код, або дані, або набір доступів до зв’язків, але не все одночасно.

Помилка №2: забути очистити статистику й отримати накопичувальні цифри.
Hibernate Statistics за замовчуванням накопичує значення, і якщо ви не зробите clear(), то ваш «SQL count» буде сумою за кілька запусків. Це призводить до найприкрішого виду помилок: коли ви впевнені, що знайшли N+1, а насправді просто двічі запустили сценарій і склали результати. Дисципліна тут простіша, ніж здається: clear() завжди має бути безпосередньо перед вимірюваним викликом.

Помилка №3: намагатися довести N+1 лише часом виконання.
Час — шумна метрика: прогрів кешів, паралельні процеси, випадкові фонові задачі й навіть те, що ви відкрили 40 вкладок у браузері, можуть змінити результат. N+1 — структурна проблема, її треба ловити структурними сигналами: кількістю запитів і повторюваними шаблонами в SQL. Час можна дивитися потім, але починати краще з «скільки запитів і які».

Помилка №4: запускати вимірювання на надто малому датасеті й робити далекосяжні висновки.
N+1 на 2–3 рядках може виглядати «нормально»: ну так, 1 + 3 запити — не кінець світу. Але саме тому N+1 так часто живе в продакшені: на малих даних воно не лякає. Для діагностики обирайте сценарії, де список має хоча б десятки елементів. У лабораторному проєкті це зазвичай вирішується seed-даними: якщо у вас є 30–50 замовлень, ви вже побачите характер проблеми.

Помилка №5: змішувати запис і читання в одному вимірюваному сценарії.
Якщо всередині методу ви випадково робите зміни (навіть якщо «трохи»), Hibernate може зробити flush, зʼявляться UPDATE, додаткові SELECT, і ви перестанете розуміти, що саме вимірюєте. Для діагностики N+1 виділяйте чистий read-path і робіть метод @Transactional(readOnly = true). Це не магія оптимізації — це спосіб не зіпсувати експеримент.