Аудит продуктивності повільного read-case

1. Аудит продуктивності як сценарій

Коли розробник каже «у нас гальмує каталог», це звучить приблизно як «у мене болить… ну, десь там». Наче й правда, але лікувати такий опис можна хіба що подорожником, прикладеним до ноутбука. Аудит продуктивності в шарі збереження починається з дуже приземленої думки: ми оптимізуємо не абстрактну систему, а конкретний read-case, який можна двічі поспіль повторити однаково й отримати зіставний результат.

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

Щоб цю думку втримати, корисно запам’ятати просту формулу дня:

Сценарій → baseline → симптом SQL → підтвердження статистикою → EXPLAIN (за потреби) → одна зміна

І тепер уже можна говорити про «схему аудиту» як про справжню процедуру, а не про натхнення.

2. Крок 0: фіксуємо один read-case і параметри

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

У Commerce Persistence Lab зручні кандидати на такий read-case — це, наприклад, «сторінка активних товарів в адмінці» або «список нових замовлень для обробки». Важливо, що це саме читання, без бізнес-ефектів, і воно має запускатися однаково: той самий статус, той самий pageSize, одне й те саме сортування.

Часто я пропоную студентам подумки підписати read-case як тест-кейс, навіть якщо ви поки що не пишете тест:

«CatalogPage: status=ACTIVE, sort=name, pageSize=50»

Це допомагає не розпливатися.

Технічно нам також корисно забезпечити однакове середовище: один і той самий профіль логів (sql-trace, stats), один і той самий набір даних (бажано не з даними, засіяними вчора, а сьогодні — з іншими), і бажано одна й та сама логіка транзакції. У проєкті в нас open-in-view=false, тому read-case має жити в сервісі або квері-сервісі (а не бути випадковим обходом сутностей десь «після транзакції»).

Невеликий приклад «фіксуємо вхід» у коді (без філософії, просто щоб показати стиль):

import java.util.UUID;

/**
 * Параметри зафіксованого read-case: так сценарій стає відтворюваним.
 * Ідея: однаковий вхід → порівнювані вимірювання «до/після».
 */
public record CatalogPageRequest(
    UUID auditRunId, // Ідентифікатор прогону: зручно для кореляції логів і метрик
    int pageSize,    // Розмір сторінки фіксуємо, щоб не "покращити" час випадково
    String sort      // Сортування часто впливає на план запиту та вартість ORDER BY
) {}

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

3. Крок 1: baseline (час, Statistics, SQL)

Коли базовий сценарій обрано, дуже хочеться відразу полізти в JOIN FETCH або індекси. Але baseline — це якір, без якого ви потім не зрозумієте, стало краще чи вам просто пощастило з прогрівом. Тут важливо визнати неприємну істину: час сам по собі — поганий діагноз, бо він не пояснює причину. Тому baseline ми знімаємо «трійкою»: мінімальна тривалість, статистика й форма SQL.

На рівні коду зручно мати невелику утиліту, яка запускає сценарій, знімає час і читає один і той самий набір метрик. Тоді baseline, перевірка гіпотези й повторний прогін говорять однією мовою: elapsedMs, queryCount, prepareStatementCount, entityLoadCount, collectionFetchCount, flushCount.

Приклад простого «знімка» (без фанатизму, 8–9 рядків — щоб було видно ідею):

import org.hibernate.stat.Statistics;

/**
 * Знімок ключових метрик, щоб порівнювати прогони «до/після» не на рівні відчуттів.
 */
public record AuditSnapshot(
    long elapsedMs,              // Час виконання сценарію (грубий, але потрібний орієнтир)
    long queryCount,             // Скільки виконань запитів пройшло через Hibernate
    long prepareStatementCount,  // Скільки JDBC PreparedStatement реально знадобилося
    long entityLoadCount,        // Скільки сутностей було завантажено (може виявляти надмірне підвантаження)
    long collectionFetchCount,   // Скільки разів підвантажувалися колекції (часто ознака N+1)
    long flushCount              // Скільки flush сталося в «читанні» (підозріло для read-case)
) {
    public static AuditSnapshot from(Statistics st, long elapsedMs) {
        // Забираємо один і той самий набір лічильників для baseline і повторного прогону.
        return new AuditSnapshot(
            elapsedMs,
            st.getQueryExecutionCount(),
            st.getPrepareStatementCount(),
            st.getEntityLoadCount(),
            st.getCollectionFetchCount(),
            st.getFlushCount()
        );
    }
}

Тепер можна зробити один прогін сценарію. Зверніть увагу: тут немає спроби стати JMH. Нам не потрібен ідеальний мікробенчмарк — нам потрібна відтворювана діагностика.

import org.hibernate.stat.Statistics;

public AuditSnapshot run(Statistics st, Runnable useCase) {
    // Важливо скинути лічильники, інакше прогони будуть "накопичуватися" і брехатимуть.
    st.clear();

    long started = System.nanoTime();
    // Тут запускається зафіксований read-case (один і той самий вхід).
    useCase.run();
    long elapsedMs = (System.nanoTime() - started) / 1_000_000;

    // Знімаємо snapshot одразу після виконання, щоб baseline і after порівнювалися за тими самими полями.
    return AuditSnapshot.from(st, elapsedMs);
}

Паралельно з цим ви вмикаєте SQL trace (як ми обговорювали в лекції 1), щоб бачити форму запитів. І от у вас з’являється baseline виду: «240 мс, 18 запитів, 120 entity loads, 30 collection fetches, flushCount=0». Це вже не «повільно», це конкретика.

4. Крок 2: класифікуємо проблему за SQL

Коли ви відкриваєте SQL-лог, мозок розробника часто поводиться як кіт на лазерній указці: увага стрибає по рядках, погляд чіпляється за страшні left outer join, рука тягнеться змінювати анотації. На цьому кроці ми робимо навпаки: читаємо лог структурно, щоб визначити тип проблеми. І лише після цього обираємо інструмент виправлення, а не навпаки.

У реальності в нас зазвичай трапляються чотири характерні сюжети.

Перший сюжет — повторювані SELECT однакової форми з різними параметрами. Це виглядає як один root query, а потім багато запитів виду select ... from product_details where product_id=? або select ... from order_item where order_id=?. Часто це або N+1, або ліниве підвантаження по циклу, або маленький @BatchSize міг би допомогти, або потрібен fetch-plan для конкретного сценарію.

Другий сюжет — один запит, але він дуже широкий: багато JOIN, багато колонок, багато рядків через to-many. У логах він виглядає як «ніби один запит», але фактично ви тягнете величезний result set, дублюєте дані в рядках і робите дороге читання для простого списку. Це типовий випадок, коли треба подумати про projection/read-model, а не радіти: «О, лише один запит».

Третій сюжет — у read-case раптово з’являються UPDATE або flush перед запитом. Це означає, що ви десь мутували managed-entity (можливо, навіть випадково: trim(), зміна поля, зміна embeddable або setter із побічним ефектом). Такий сценарій ламає ідею «читання має бути читанням», а заодно часто псує час і створює зайве навантаження на базу.

Четвертий сюжет — запитів мало, але конкретний запит важкий: фільтри й сортування змушують PostgreSQL робити дороге сканування, сортування й обирати невдалий план виконання. Це той момент, коли EXPLAIN із лекції 3 стає справді корисним, і розмова про індекс перестає бути абстрактною.

Щоб це втримати в голові, зручно мати маленьку «таблицю симптомів» — не як догму, а як шпаргалку для думки:

Зверніть увагу: у цій таблиці немає пункту «винен Hibernate». Hibernate, звісно, може бути чудовим цапом-відбувайлом, але в реальності він лише чесно виконує те, що ми попросили (іноді навіть занадто чесно).

5. Крок 3: перевіряємо гіпотезу за Statistics

SQL-лог показує форму проблеми, але інколи ми легко самі себе обманюємо. Наприклад, здається, що запитів не так уже й багато, а фактично їх 60, просто вони перемішані. Або здається, що N+1 зник, але колекції все ще підвантажуються. На цьому кроці ми використовуємо Statistics як «сухий звіт бухгалтера»: він не сперечається, він просто фіксує кількість подій.

Ідея проста: після того як ви очима класифікували проблему, ви дивитеся на відповідні лічильники. Якщо ви підозрювали повторювані secondary selects, то prepareStatementCount зазвичай швидко повзе вгору, а collectionFetchCount та/або entityLoadCount часто злітають разом із ним. queryExecutionCount тут теж корисний як швидкий сигнал, але він не замінює ці лічильники й сам SQL trace. Якщо ви підозрювали широкий SELECT, то запитів може бути мало, але entityLoadCount буде несподівано великим (ви завантажили купу сутностей, які вам узагалі не потрібні), а інколи ви побачите, що під капотом матеріалізувалися колекції.

Якщо ви підозрювали, що десь був flush, то flushCount раптово стане більшим за нуль, хоча ви «просто читали». Це дуже корисний лічильник саме для read-case, бо він швидко витягує назовні брудне читання з побічними ефектами.

Міні-приклад «читаємо лічильники як діагноз», без довгого коду:

import org.hibernate.stat.Statistics;

public String quickDiagnosis(Statistics st) {
    // Короткий рядок для логу/консолі: дисциплінує, бо це «цифри», а не відчуття.
    return "queryCount=" + st.getQueryExecutionCount()
        + ", prepareStatementCount=" + st.getPrepareStatementCount()
        + ", entityLoadCount=" + st.getEntityLoadCount()
        + ", collectionFetchCount=" + st.getCollectionFetchCount()
        + ", flushCount=" + st.getFlushCount();
}

У реальному audit-циклі ви не обмежуєтеся одним рядком, але навіть такий «згорнутий звіт» уже дисциплінує: замість «здається, стало краще» з’являється «queries впали з 18 до 2, collections — з 30 до 0».

6. Крок 4: знаходимо домінуючий запит

Дуже поширена помилка в оптимізації — виправляти перше, що трапилося на очі. Це як лікувати застуду вимірюванням температури в лікті: цифри є, користі мало. У performance audit нам потрібне домінуюче джерело вартості: запит або шаблон запитів, який справді визначає навантаження та час сценарію. Цей крок часто економить найбільше часу — тому що ви перестаєте оптимізувати «все потроху» і починаєте оптимізувати «найдорожче».

Для пошуку домінуючого SQL зазвичай достатньо двох прийомів. Перший — коментар до запиту (якщо ви використовуєте Hibernate API через Session), щоб легко знайти SQL-блок у логах. Другий — просто дисципліна: ви берете root query вашого сценарію і дивитеся, що йде після нього.

Приклад із коментарем (зараз це саме діагностика, не архітектура):

import org.hibernate.Session;

// Дістаємо Hibernate Session, щоб додати SQL-коментар і легше знаходити запит у trace.
Session session = entityManager.unwrap(Session.class);

return session.createQuery("from Product p where p.status = :s", Product.class)
    .setComment("аудит: catalog-page") // Цей коментар зʼявиться в SQL як /* ... */.
    .setParameter("s", ProductStatus.ACTIVE) // Фіксуємо параметр: статус — частина сценарію.
    .setMaxResults(50) // Фіксуємо розмір сторінки: інакше порівняння "до/після" невалідне.
    .getResultList();

Далі ви в SQL trace знаходите блок із /* аудит: catalog-page */ й аналізуєте його цілком: root query, secondary selects, підвантаження колекцій, неочікувані записи. На цьому кроці важливо не розпорошуватися: якщо у вас у сценарії 18 запитів, часто 15 із них будуть «однієї родини», і саме це сімейство є головною ціллю.

Якщо ж запит один, але важкий, то «домінуючий запит» очевидний — це він. Тоді ви переходите до EXPLAIN (як обговорювали в минулій лекції) уже для конкретного SQL, а не «для ідеї запиту».

7. Крок 5: обираємо один важіль

На цьому етапі в новачка зазвичай виникає бажання зробити все одразу: і JOIN FETCH, і projection, і індекс, і @BatchSize, і «давайте ще кешування увімкнемо». Це нормально, бо мозок любить відчуття діяльності. Але інженерний audit улаштований інакше: в одному циклі ми змінюємо один фактор, інакше ви не зрозумієте, що саме спрацювало (і чи спрацювало взагалі).

Щоб обрати важіль, достатньо поставити собі дуже практичне питання: «Де саме народжується вартість?» Якщо вартість народжується від кількості запитів, першим важелем зазвичай буде fetch-plan або звуження read-model. Якщо вартість народжується від ширини даних (надмірного підвантаження), першим важелем часто буде projection. Якщо вартість народжується від плану БД (сканування, сортування), тоді вже має сенс говорити про індекс або переписування фільтра чи сортування.

Покажу кілька мініприкладів «один важіль — один крок», без заглиблення в тему fetching (вона вже була раніше), але щоб було видно, як це виглядає в коді.

Якщо проблема виглядає як N+1 на зв’язках to-one/to-many, то першим важелем може бути окремий read-method із EntityGraph:

import org.springframework.data.jpa.repository.EntityGraph;
import org.springframework.data.jpa.repository.JpaRepository;

public interface PurchaseOrderRepository extends JpaRepository<PurchaseOrder, Long> {

    // EntityGraph задає fetch-plan під конкретний read-case:
    //     підтягнемо customer і items одним способом, щоб не ловити N+1 на лінивих звʼязках.
    @EntityGraph(attributePaths = {"customer", "items"})
    java.util.List<PurchaseOrder> findTop20ByStatusOrderByCreatedAtDesc(OrderStatus status);
}

Якщо проблема в тому, що ви тягнете entity-граф заради списку, то першим важелем часто стає projection: звужуємо read-model.

import java.util.List;

// Projection замість сутностей: беремо лише те, що потрібно списку (id/sku/name).
//     Це знижує надмірне підвантаження і часто зменшує вартість матеріалізації.
List<ProductRow> rows = entityManager.createQuery("""
    select new com.example.commerce.catalog.dto.ProductRow(p.id, p.sku, p.name)
    from Product p
    where p.status = :status
    order by p.name
    """, ProductRow.class)
    .setParameter("status", ProductStatus.ACTIVE) // Параметр фіксує сценарій, тож baseline буде зіставним.
    .getResultList();

Якщо проблема в тому, що read-case раптово «пише», важелем буде не fetch і не індекс, а усунення мутації або переведення читання в read-only режим — для чистоти експерименту:

import java.util.List;

// Read-only hint допомагає не витрачати час на dirty checking і зменшує ризик flush у читанні.
List<Product> products = entityManager.createQuery("""
    select p from Product p where p.status = :status
    """, Product.class)
    .setParameter("status", ProductStatus.ACTIVE) // Ті самі параметри — та сама точка порівняння.
    .setHint("org.hibernate.readOnly", true) // Підкреслюємо, що цей сценарій має бути чистим read.
    .getResultList();

А якщо ви бачите, що запит сам по собі важкий (мало запитів, але довго), то важелем стає EXPLAIN (а вже потім — індекси). Тут важливо: ми не «оптимізуємо індексами у вакуумі», ми пов’язуємо індекс із конкретним SQL:

explain
select p.id, p.sku, p.name
from product p
where p.status = 'ACTIVE'
order by p.name

Ці приклади спеціально короткі, бо ключова думка не в синтаксисі. Ключова думка: спочатку ви діагностували тип проблеми, потім обрали один важіль, і лише потім зробили одну зміну.

8. Крок 6: повторний прогін

Після однієї зміни дуже хочеться переможно написати в чат команди: «Я прискорив каталог на 73 %». Стримайтеся. На цьому кроці наше завдання — підготувати коректний повторний прогін: той самий вхід, той самий набір даних, той самий порядок дій, ті самі увімкнені профілі логів. Зараз важливо не гарно оголосити перемогу, а забезпечити, щоб порівняння взагалі мало сенс.

Технічно це означає кілька нудних, але обов’язкових речей: знову statistics.clear(), той самий pageSize, те саме сортування, той самий статус. Якщо ви вимірювали «список NEW замовлень», то ви знову вимірюєте NEW, а не раптом PAID. Якщо ви знімали SQL trace на одному сценарії, ви знову знаходите в логах саме цей сценарій (і дуже корисно, якщо в нього є коментар). Якщо ви робили EXPLAIN, ви робите його для того самого SQL-шаблону, а не «приблизно схожого».

І ще один важливий момент для психіки розробника: якщо після зміни метрики не покращилися, це не провал. Це просто означає, що гіпотеза була слабкою або ви лікували не домінуюче джерело вартості. У performance audit це нормальна частина процесу: «перевірили → не спрацювало → повернулися на крок 4».

9. Типові помилки в аудиті read-case

Наприкінці хочеться зібрати найчастіші «граблі» саме навколо процедури аудиту, а не навколо конкретних інструментів. Ці помилки неприємні тим, що ви можете зробити правильний EntityGraph або правильну projection — і все одно не зрозуміти, чи допомогло це, бо сам експеримент був поставлений погано. Тому цей блок — про дисципліну й відтворюваність, а не про анотації.

Помилка № 1: аудит без baseline.
Якщо ви не зафіксували «до», то «після» перетворюється на літературний твір. Здається швидше, здається повільніше, «у мене на машині так було». Hibernate Statistics і мінімальний замір часу потрібні не для краси, а щоб будь-яку зміну можна було порівняти з вихідним станом в однакових умовах.

Помилка № 2: змінювати відразу три речі й радіти одній.
Дуже спокусливо одночасно переписати запит, додати JOIN FETCH і накотити індекс. А потім ви не знаєте, що саме дало ефект і що з цього можна безпечно залишити. У навчальному audit-циклі ми принципово змінюємо один фактор, щоб зв’язок «зміна → ефект» був доведеним, а не інтуїтивним.

Помилка № 3: оптимізувати «найкрасивіший запит», а не найдорожчий.
Іноді розробник лагодить root query, бо він великий і страшний, а реальна вартість сидить у 50 повторюваних secondary selects. Або навпаки: він героїчно бореться з N+1, а насправді один монстр-запит із широким SELECT і сортуванням за неіндексованим полем з’їдає 95 % часу. Домінуюче джерело вартості важливіше за естетику.

Помилка № 4: ігнорувати flushCount у read-case.
Read-case, який раптово робить flush, часто означає, що ви мутуєте managed-entity всередині читання. Це може бути майже непомітно в коді, але дуже помітно в SQL. Якщо ви не дивитеся на flushCount, ви можете шукати «погані індекси» там, де проблема — у випадковому оновленні.

Помилка № 5: сперечатися з базою даних без EXPLAIN.
Буває й навпаки: ви впевнені, що запит «має літати», бо «він же простий», але PostgreSQL обирає план, де робить seq scan і сортування в пам’ять або на диск. У цей момент будь-які розмови «давайте додамо анотацію» закінчуються. Потрібен план виконання, бо він пояснює ціну конкретного SQL у конкретній БД.