Началось все с желания посчитать, сколько запросов в БД улетает на каждый rest запрос при использовании spring data jpa + hibernate.
Гугл выдал интересное видео про xrebel, но так же сообщил, что xrebel платный.
Дальнейший поиск привел к статье Counting Queries per Request with Hibernate and Spring
Её и взял за основу для своего счетчика. Какого-то ещё примера не нашел, поэтому решил оставить эту заметку
Первое, что нужно создать - класс счетчик:
package ru.counter.utils.querycounter
import org.hibernate.EmptyInterceptor
import org.springframework.stereotype.Component
@Component
class HibernateStatisticsInterceptor : EmptyInterceptor() {
private val queryCount = ThreadLocal<Long>()
fun startCounter() {
queryCount.set(0L)
}
fun getQueryCount(): Long {
return queryCount.get()
}
fun clearCounter() {
queryCount.remove()
}
override fun onPrepareStatement(sql: String?): String? {
val count = queryCount.get()
if (count != null) {
queryCount.set(count + 1)
}
return super.onPrepareStatement(sql)
}
}
Т.к. используется обычный mvc а не асинхронный, ThreadLocal будет достаточно.
Далее понадобится фильтр http запросов, который будет обнулять счетчик в начале запроса и выводить данные по завершению:
package ru.counter.utils.querycounter
import org.slf4j.Logger
import org.slf4j.LoggerFactory
import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty
import org.springframework.core.Ordered
import org.springframework.core.annotation.Order
import org.springframework.stereotype.Component
import javax.servlet.FilterChain
import javax.servlet.http.HttpFilter
import javax.servlet.http.HttpServletRequest
import javax.servlet.http.HttpServletResponse
@Component
@ConditionalOnProperty(name = ["sql.query.count.per.request.log.enable"], havingValue = true.toString())
@Order(Ordered.HIGHEST_PRECEDENCE) // максимальный приоритет, чтобы фильтр был первым
// на случай, если другие фильтры тоже кидают запросы в БД
class RequestStatisticsSqlQueryCountFilter(
private val statisticsInterceptor: HibernateStatisticsInterceptor
) : HttpFilter() {
private val log: Logger = LoggerFactory.getLogger(javaClass)
init {
log.warn(
"http фильтр для подсчета количества sql запросов на 1 http запрос включен," +
" негативно для производительности"
)
}
private val time = ThreadLocal<Long>()
override fun doFilter(request: HttpServletRequest?, response: HttpServletResponse?, chain: FilterChain?) {
if (request?.requestURI?.startsWith("/api") != true) { // мне были важны только запросы к api
chain?.doFilter(request, response)
} else {
time.set(System.currentTimeMillis())
statisticsInterceptor.startCounter()
chain?.doFilter(request, response)
val duration = System.currentTimeMillis() - time.get()
val queryCount: Long = statisticsInterceptor.getQueryCount()
log.info("[Time: {} ms] [Queries: {}] {} {}", duration, queryCount, request.method, request.requestURI)
statisticsInterceptor.clearCounter()
time.remove()
}
}
}
Важное тут:
ConditionalOnProperty, считать количество запросов в проме мне не надо, это информация нужна только во время разработки, поэтому добавлена возможность управлять наличием этого фильтра через spring property
На всякий случай вывод в консоль при создании бина о, том что он может негативно влиять на производительность
Третий элемент это регистрация перехватчика запросов для hibernate, который и будет инкрементировать счетчик:
package ru.counter.configuration
import org.slf4j.LoggerFactory
import org.springframework.beans.factory.annotation.Autowired
import org.springframework.beans.factory.annotation.Value
import org.springframework.boot.autoconfigure.orm.jpa.HibernatePropertiesCustomizer
import org.springframework.context.annotation.Configuration
import ru.counter.utils.querycounter.HibernateStatisticsInterceptor
@Configuration
class HibernateInterceptorRegistration : HibernatePropertiesCustomizer {
private val log = LoggerFactory.getLogger(javaClass)
@Value("\${sql.query.count.per.request.log.enable:false}")
private var statisticsInterceptorEnabled: Boolean = false
@Autowired
private lateinit var statisticsInterceptor: HibernateStatisticsInterceptor
override fun customize(hibernateProperties: MutableMap<String, Any>) {
if (statisticsInterceptorEnabled) {
log.warn("Счетчик sql запросов на 1 http запрос включен, негативно для производительности")
hibernateProperties["hibernate.session_factory.interceptor"] = statisticsInterceptor
}
}
}
Здесь так же он регистрируется, только если при запуске sql.query.count.per.request.log.enable указана и имеет значение true, наверно можно переделать так же под ConditionalOnProperty
И точно так же вывод предупреждения в лог.
В итоге запустив приложение со счетчиком можно увидеть данные в логе
INFO RequestStatisticsSqlQueryCountFilter : [Time: 154 ms] [Queries: 18] GET /api/private/v1/auth/check
INFO RequestStatisticsSqlQueryCountFilter : [Time: 149 ms] [Queries: 4] GET /api/private/v1/organisation/employee
INFO RequestStatisticsSqlQueryCountFilter : [Time: 0 ms] [Queries: 0] GET /api/private/v1/auth/check
INFO RequestStatisticsSqlQueryCountFilter : [Time: 62 ms] [Queries: 16] GET /api/private/v1/organisation
INFO RequestStatisticsSqlQueryCountFilter : [Time: 30 ms] [Queries: 1] GET /api/public/v1/image/1001
INFO RequestStatisticsSqlQueryCountFilter : [Time: 30 ms] [Queries: 1] GET /api/public/v1/image/1000
Spring data jpa дает очень удобные интерфейс для работы с БД, но одна ошибка, может стоит 100 или 1000 запросов. Главное, что jpa дает, это скорость разработки.
Возможность быстро сделать прототип и потом его немного допилить, когда интеграции уже зафиксированы и каждая сторона отлаживает и улучшает свою часть.
Про импорты
В коде специально оставил все импорты, некоторые моменты могут быть очевидны, но не все.
Комментарии (9)
aleksandy
12.05.2022 07:13Для простого подсчёта запросов проще использовать специально созданный инспектор.
sergeevik Автор
12.05.2022 10:14Да, но общая идея была посчитать количество запросов на отображение одного экрана. Увидеть сколько сервисов он вызывает и сколько суммарно они делают запросов, чтобы в нагруженных местах попробовать оптимизировать
vooft
Что?! Скорость первичной разработки только если, а потом долго и мучительно пытаться выразить нужный тебе sql через всякие NamedGraph. Ваш счетчик настолько ничтожен по оверхеду по сравнению с JPA, что даже смешно писать об этом.
Код у вас выглядит будто вы сконвертировали через Intellij из Java в Kotlin. Зачем у вас все параметры nullable в doFilter?
sergeevik Автор
Да, это я и хотел написать, спасибо, поправил
Есть много разных вариантов как можно получить данные из БД, на мой взгляд выбирать нужно тот, который нужен сейчас и тот который можно сейчас использовать с учетом временных ограничений.
Да, но зачем тащить в пром, то что там не будет никогда использоваться? Так можно сотню небольших сервисов набрать, каждый из которых ничтожен, но вместе дадут просадку.
прям так и сделал с нужными мне правками
hello_my_name_is_dany
А почему было не оставить код на Java?
vooft
В проде тоже нужны метрики :)
Еще замечу, что time в RequestStatisticsSqlQueryCountFilter совершенно не нужен в ThreadLocal, это может быть просто локальная переменная.
sergeevik Автор
Ну это не совсем метрика)
Тут задача в том, чтобы понять нагрузку в плане количества запросов на 1 вызов и оптимизировать запрос. В прозе он будет таким же и там полезнее метрики самой бд
Да, согласен)
aleksandy
Согласен, что JPA даёт нехилый оверхед особенно на простых структурах. Но, чтобы не заниматься
Кто мешает написать через HQL или, если он не позволяет выразить полёт мысли, native sql?
vooft
Даже native sql не гарантирует, что хибернейт не решит сгонять в базу еще пару-тройку раз, особенно если есть пара уровней вложенности. При маленькой нагрузке это не важно, но при большой это это становится критично.
Особенно это проблематично когда в проект могут добавлять новые сущности, я в свое время сильно обжегся, что на простом вызове save и findById он делал 10 запросов.
К слову, с этим бороться мне в свое время помогла вот эта библиотечка, которая позволяет сделать тест на количество запросов https://github.com/quick-perf/quickperf