В продолжение темы о решении проблемы N+1 в Hibernate.
Профайлинг показал, что FilterBoth+Lim в три раза быстрее, чем FilterBothSmart, хотя должно быть с точностью до наоборот, при этом скорость работы отличается от ожидаемой в десятки раз. Производились следующие замеры:
1-2. LJ+Order и LJ+Distinct+Order просто для демонстрации необходимости Distinct
3. Fetch+Limit демонстрирует ворнинг HHH000104
4. LJ+Distinct+Order+Lim просто выборка с окном без фильтрации, этого запроса было достаточно для демонстрации фуллскана
5. Filter+Lim выборка с окном и фильтрацией по родителю
6. FilterBoth+Lim выборка с окном и фильтрацией по родителю и потомку
7. FilterBothSmart сабжевая оптимизация
7.1 Prefetch предвыборка первичных ключей с окном
7.2 Fetch выборка данных
У H2 выводит план в совершенно вырвиглазном формате, но понять, в принципе, можно. Хитрожопая база догадывается, что ей достаточно индекса. При этом она и для остальных запросов использовала только индекс. Пришлось в в родителя добавить поле nonIndex, чтобы данные таки были прочитаны с диска - это сильно просадило запросы.
Итог: странная ситуация и в песочнице не хватает какого-то ключевого фактора либо методические ошибки: может мешает кэш, но как его просто отключить я не вкурил.
Постановка задачи
Нужно сформировать отчет, содержащий 100к строк и фильтрацию по нескольким полям. Выборка объективно не укладывается в отведенные рамки: годовая выборка - 30 секунд. Приходится грузить данные на клиента маленькими чанками по сто записей. При этом мы столкнулись с тем, что один чанк загружается в течении 2 секунд, помножив на 1000 чанков получаем более получаса на получение отчета. Вся выборка ведется по двум таблицам в отношении One-to-Many, причем Many часть почти на 100% состоит из 1 записи, но СЦУКО могут встречаться > 1.
Оптимизация выборки окна
Мы оптимизировали выборку предзагрузив необходимые данные и у нас нет коррелированных подзапросов. Но при добавлении в запрос содержащий LEFT JOIN FETCH окна query.setFirstResult(start).setMaxResults(100); Hibernate плевался ворнигом HHH000104: firstResult/maxResults specified with collection fetch; applying in memory! что, в общем-то, логично: из-за OUTER JOIN он не может рассчитать ни начало выборки, ни необходимое количество записей, поэтому он выбирал все данные, и только потом ограничивал окно.
На StackOverflow предложили оригинальное решение проблемы: так как окно небольшое, то сначала выбираем первичные ключи SELECT DISTINCT p.id FROM Parent p LEFT JOIN p.child c WHERE p = ... and c = ... ORDER BY p.timestamp, а затем выбираем данные фильтруя по полученным идентификаторам SELECT DISTINCT p FROM Parent p LEFT JOIN FETCH p.child c WHERE p.id IN (?) ORDER BY p.timestamp.
Bottleneck
Хак с выборкой первичных ключей помог, но все равно производительности сильно не хватало. Мы начали искать затык и, спустя какое-то время, удалось изолировать момент проседания производительности. Время запроса SELECT p.* FROM parent p LEFT JOIN child c on p.id = c.id WHERE p.timestamp BETWEEN ? AND ? ORDER BY p.timestamp отличался от аналогичного с DISTINCT более чем в 100 раз. Оптимизатор MariaDB во втором запросе терял индекс, начиная яростно фуллсканить.
Оптимизации
После серьезного мозгового штурма мы нашли способ укорить запрос еще в пять раз, отказавшись от небольшого допущения. Клиент останавливал загрузку, получив пустой чанк, но если бы он знал размер ожидаемой выборки, то он бы сам знал, когда остановиться. А это было просто, поскольку для отрисовки прогресса мы и так сначала запрашивали размер выборки.
Сначала мы выбираем только родителей фильтруя по признакам, содержащимся в родителях и ограничивая окном в сто записей: SELECT DISTINCT p.id FROM Parent p WHERE p = ... ORDER BY p.timestamp. Затем полученные идентификаторы м используем во втором запросе никак не ограничивая окно и используя FETCH: SELECT DISTINCT p FROM Parent p LEFT JOIN FETCH p.child c WHERE p.id IN (?) AND c = ... ORDER BY p.timestamp. Это дало нам прирост производительности в пять раз, сократив время формирования отчета до приемлимого уровня.
Песочница
А теперь началось самое интересное: я не смог воспроизвести bottleneck в песочнице и H2 вместо MariaDB. Для бенчмаркинга попробовал использовать профайлер от SLF4J. Исходники находятся в модуле paging. Там запускабельны два класса: PagingApp, замеряющая время выборки с ипользованием Hibernate и Explain выводящую план запроса с аналитикой. Модель состоит из родителя и потомка в отношении One-to-Many. База заполняется случайными данными в 100к родителей и 0-10 потомков у каждого.
1-2. LJ+Order и LJ+Distinct+Order просто для демонстрации необходимости Distinct
3. Fetch+Limit демонстрирует ворнинг HHH000104
4. LJ+Distinct+Order+Lim просто выборка с окном без фильтрации, этого запроса было достаточно для демонстрации фуллскана
5. Filter+Lim выборка с окном и фильтрацией по родителю
6. FilterBoth+Lim выборка с окном и фильтрацией по родителю и потомку
7. FilterBothSmart сабжевая оптимизация
7.1 Prefetch предвыборка первичных ключей с окном
7.2 Fetch выборка данных
+ Profiler [Paging]
|-- elapsed time [init] 78,769 seconds.
|-- elapsed time [LJ+Order] 7,554 seconds.
|-- elapsed time [LJ+Distinct+Order] 12,422 seconds.
|-- elapsed time [Fetch+Limit] 42,375 seconds.
|-- elapsed time [LJ+Distinct+Order+Lim] 0,003 seconds.
|-- elapsed time [Filter+Lim] 0,017 seconds.
|-- elapsed time [FilterBoth+Lim] 0,011 seconds.
|---+ Profiler [FilterBothSmart]
|-- elapsed time [Prefetch] 0,008 seconds.
|-- elapsed time [Fetch] 0,024 seconds.
|-- Subtotal [FilterBothSmart] 0,032 seconds.
|-- elapsed time [FilterBothSmart] 0,032 seconds.
|-- Total [Paging] 141,194 seconds.
У H2 выводит план в совершенно вырвиглазном формате, но понять, в принципе, можно. Хитрожопая база догадывается, что ей достаточно индекса. При этом она и для остальных запросов использовала только индекс. Пришлось в в родителя добавить поле nonIndex, чтобы данные таки были прочитаны с диска - это сильно просадило запросы.
03:01:19,708 DEBUG [main] com.blazer.paging.Explain:16 - LJ+Distinct+Order+Lim
03:01:19,725 DEBUG [main] com.blazer.paging.Explain:43 - [SELECT DISTINCT
PARENTFILT0_.ID AS ID1_9_,
PARENTFILT0_.NONINDEX AS NONINDEX2_9_,
PARENTFILT0_.VALUE AS VALUE3_9_
FROM PUBLIC.PARENT_FILTER PARENTFILT0_
/* PUBLIC.PARENT_FILTER_VALUE_IDX */
/* scanCount: 10 */
LEFT OUTER JOIN PUBLIC.CHILD_FILTER CHILD1_
/* PUBLIC.FK_MXDQ9TND71UF79IQSE2I11ML5_INDEX_4: PARENT_ID = PARENTFILT0_.ID */
ON PARENTFILT0_.ID = CHILD1_.PARENT_ID
/* scanCount: 34 */
ORDER BY 3
LIMIT ?1
/* index sorted */
/*
total: 21
CHILD_FILTER.FK_MXDQ9TND71UF79IQSE2I11ML5_INDEX_4 read: 10 (47%)
PARENT_FILTER.PARENT_FILTER_DATA read: 10 (47%)
PARENT_FILTER.PARENT_FILTER_VALUE_IDX read: 1 (4%)
*/]
03:01:19,725 DEBUG [main] com.blazer.paging.Explain:18 - Filter+Lim
03:01:19,728 DEBUG [main] com.blazer.paging.Explain:43 - [SELECT DISTINCT
PARENTFILT0_.ID AS ID1_9_,
PARENTFILT0_.NONINDEX AS NONINDEX2_9_,
PARENTFILT0_.VALUE AS VALUE3_9_
FROM PUBLIC.PARENT_FILTER PARENTFILT0_
/* PUBLIC.PARENT_FILTER_VALUE_IDX: VALUE >= ?2
AND VALUE <= ?3
*/
/* WHERE (PARENTFILT0_.VALUE >= ?2)
AND (PARENTFILT0_.VALUE <= ?3)
*/
/* scanCount: 10 */
LEFT OUTER JOIN PUBLIC.CHILD_FILTER CHILD1_
/* PUBLIC.FK_MXDQ9TND71UF79IQSE2I11ML5_INDEX_4: PARENT_ID = PARENTFILT0_.ID */
ON PARENTFILT0_.ID = CHILD1_.PARENT_ID
/* scanCount: 34 */
WHERE (PARENTFILT0_.VALUE >= ?2)
AND (PARENTFILT0_.VALUE <= ?3)
ORDER BY 3
LIMIT ?1
/* index sorted */]
03:01:19,728 DEBUG [main] com.blazer.paging.Explain:20 - FilterBoth+Lim
03:01:19,732 DEBUG [main] com.blazer.paging.Explain:43 - [SELECT DISTINCT
PARENTFILT0_.ID AS ID1_9_,
PARENTFILT0_.NONINDEX AS NONINDEX2_9_,
PARENTFILT0_.VALUE AS VALUE3_9_
FROM PUBLIC.PARENT_FILTER PARENTFILT0_
/* PUBLIC.PARENT_FILTER_VALUE_IDX: VALUE >= ?2
AND VALUE <= ?3
*/
/* WHERE (PARENTFILT0_.VALUE >= ?2)
AND (PARENTFILT0_.VALUE <= ?3)
*/
/* scanCount: 10 */
LEFT OUTER JOIN PUBLIC.CHILD_FILTER CHILD1_
/* PUBLIC.FK_MXDQ9TND71UF79IQSE2I11ML5_INDEX_4: PARENT_ID = PARENTFILT0_.ID */
ON PARENTFILT0_.ID = CHILD1_.PARENT_ID
/* scanCount: 34 */
WHERE ((PARENTFILT0_.VALUE >= ?2)
AND (PARENTFILT0_.VALUE <= ?3))
AND ((CHILD1_.VALUE >= ?4)
AND (CHILD1_.VALUE <= ?5))
ORDER BY 3
LIMIT ?1
/* index sorted */
/*
total: 11
CHILD_FILTER.CHILD_FILTER_DATA read: 11 (100%)
*/]
03:01:19,732 DEBUG [main] com.blazer.paging.Explain:22 - FilterBothSmart Prefetch
03:01:19,736 DEBUG [main] com.blazer.paging.Explain:43 - [SELECT
PARENTFILT0_.ID AS COL_0_0_,
PARENTFILT0_.VALUE AS COL_1_0_
FROM PUBLIC.PARENT_FILTER PARENTFILT0_
/* PUBLIC.PARENT_FILTER_VALUE_IDX: VALUE >= ?2
AND VALUE <= ?3
*/
/* scanCount: 10 */
WHERE (PARENTFILT0_.VALUE >= ?2)
AND (PARENTFILT0_.VALUE <= ?3)
ORDER BY 2
LIMIT ?1
/* index sorted */]
03:01:19,736 DEBUG [main] com.blazer.paging.Explain:24 - FilterBothSmart Fetch
03:01:19,740 DEBUG [main] com.blazer.paging.Explain:43 - [SELECT DISTINCT
PARENTFILT0_.ID AS ID1_9_,
PARENTFILT0_.NONINDEX AS NONINDEX2_9_,
PARENTFILT0_.VALUE AS VALUE3_9_
FROM PUBLIC.PARENT_FILTER PARENTFILT0_
/* PUBLIC.PRIMARY_KEY_6: ID IN(?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10) */
/* WHERE PARENTFILT0_.ID IN(?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10)
*/
/* scanCount: 11 */
LEFT OUTER JOIN PUBLIC.CHILD_FILTER CHILD1_
/* PUBLIC.FK_MXDQ9TND71UF79IQSE2I11ML5_INDEX_4: PARENT_ID = PARENTFILT0_.ID */
ON PARENTFILT0_.ID = CHILD1_.PARENT_ID
/* scanCount: 35 */
WHERE (PARENTFILT0_.ID IN(?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9, ?10))
AND ((CHILD1_.VALUE >= ?11)
AND (CHILD1_.VALUE <= ?12))
ORDER BY 3
/*
total: 1
PARENT_FILTER.PARENT_FILTER_DATA read: 1 (100%)
*/]
Итог: странная ситуация и в песочнице не хватает какого-то ключевого фактора либо методические ошибки: может мешает кэш, но как его просто отключить я не вкурил.
