Какие знаешь способы обнаружения проблем медленного запроса к БД?

Обнаружение медленных запросов к БД: методы и инструменты

Медленные запросы — это одна из главных причин деградации производительности web-приложений. Обнаружение и оптимизация таких запросов требует системного подхода и набора инструментов.

Способ 1: Логирование на уровне БД (Slow Query Log)

PostgreSQL: log_min_duration_statement

-- postgresql.conf
log_min_duration_statement = 100  -- логировать запросы > 100ms
log_statement = all
log_duration = on

-- Результат в логах:
LOG:  duration: 245.630 ms  execute <unnamed>: SELECT * FROM users WHERE email = $1
LOG:  duration: 1234.560 ms  execute <unnamed>: SELECT * FROM orders o JOIN items oi ON o.id = oi.order_id

MySQL: slow_query_log

-- my.cnf
[mysqld]
slow_query_log = 1
long_query_time = 0.1  -- 100ms

-- Просмотр медленных запросов
mysqldumpslow -s t -t 10 /var/log/mysql/slow.log

Преимущества:

• Видны реальные запросы в production
• Показывает количество examined rows
• Работает для всех приложений

# Time: 2024-03-22 15:30:45.123456 +00:00
# User@Host: app@[192.168.1.100]
# Query_time: 2.456789  Lock_time: 0.000123  Rows_sent: 100  Rows_examined: 1000000
SELECT * FROM users WHERE country = US ORDER BY created_at DESC LIMIT 100;

Способ 2: Application-level logging (Spring/Hibernate)

Hibernate SQL logging:

# application.properties
spring.jpa.show-sql=true
spring.jpa.properties.hibernate.format_sql=true
spring.jpa.properties.hibernate.use_sql_comments=true

# Логирование времени выполнения
logging.level.org.hibernate.SQL=DEBUG
logging.level.org.hibernate.stat.Statistics=DEBUG

Результат:

Hibernate: select user0_.id, user0_.email, user0_.name from users user0_ where user0_.email=?
time to load: 145ms

Custom logging с метриками:

@Component
public class QueryPerformanceInterceptor extends EmptyInterceptor {
    private long start;
    
    @Override
    public String onPrepareStatement(String sql) {
        this.start = System.currentTimeMillis();
        return sql;
    }
    
    @Override
    public void afterTransactionCompletion(Transaction tx) {
        long duration = System.currentTimeMillis() - start;
        if (duration > 100) {
            log.warn("Slow query detected: {}ms", duration);
        }
    }
}

Способ 3: EXPLAIN / EXPLAIN ANALYZE

PostgreSQL:

-- План исполнения
EXPLAIN SELECT * FROM users WHERE email = test@example.com;

/* Результат:
Seq Scan on users  (cost=0.00..35.50 rows=1 width=500)
  Filter: (email = test@example.com)
*/

-- С реальными числами и временем
EXPLAIN ANALYZE SELECT * FROM users WHERE email = test@example.com;

/* Результат:
Seq Scan on users  (cost=0.00..35.50 rows=1 width=500) (actual time=145.230..145.230 rows=1)
  Filter: (email = test@example.com)
Planning Time: 0.125 ms
Execution Time: 145.380 ms
*/

Признаки медленного запроса в EXPLAIN:

-- BAD: Sequential Scan на большой таблице
Seq Scan on huge_table  (cost=0.00..50000.00 rows=1000000)
-- GOOD: Index Scan
Index Scan using idx_email on users  (cost=0.29..8.30 rows=1)

-- BAD: Join с высокой стоимостью
Nested Loop  (cost=0.00..50000.00)
-- GOOD: Hash Join
Hash Join  (cost=10.00..150.00)

MySQL:

EXPLAIN SELECT * FROM users u JOIN orders o ON u.id = o.user_id WHERE u.email = test@example.com\G

/* Результат показывает:
- table: какая таблица
- type: ALL (плохо!), range (хорошо), const (отлично)
- possible_keys: какие индексы могут использоваться
- key: какой индекс использовался
- rows: примерное количество строк
- filtered: процент отфильтрованных строк
*/

Способ 4: Database profilers и monitoring

pgBadger (PostgreSQL log analyzer):

# Анализ slow query логов
pgbadger /var/log/postgresql/postgresql.log -o report.html

# Генерирует HTML отчет с:
# - Топ медленных запросов
# - Количество ошибок
# - Временная шкала проблем

MySQL Workbench Performance Schema:

-- Какие запросы самые медленные?
SELECT * FROM performance_schema.events_statements_summary_by_digest
ORDER BY SUM_TIMER_WAIT DESC
LIMIT 10;

-- Какие таблицы часто сканируются полностью?
SELECT object_schema, object_name, count_read, count_write
FROM performance_schema.table_io_waits_summary_by_table
WHERE count_read > 1000
ORDER BY count_read DESC;

Способ 5: APM (Application Performance Monitoring)

New Relic / DataDog / Dynatrace:

// Автоматическое отслеживание медленных запросов
@Service
public class UserService {
    @Transactional(readOnly = true)
    public List<User> findByCountry(String country) {
        // APM инструмент видит:
        // - SQL: SELECT * FROM users WHERE country = $1
        // - Время: 234ms
        // - Database server: db-prod-1
        // - Затронуто строк: 10000
        return userRepository.findByCountry(country);
    }
}

// Dashboard покажет:
// 1. Топ медленных endpoints
// 2. Топ медленных SQL запросов
// 3. Горячие точки в коде
// 4. Тренды производительности

Способ 6: Custom profiling в коде

Spring StopWatch:

@Service
public class OrderService {
    private static final Logger log = LoggerFactory.getLogger(OrderService.class);
    
    public List<Order> getAllOrders() {
        StopWatch stopWatch = new StopWatch("getAllOrders");
        
        stopWatch.start("fetch_orders");
        List<Order> orders = orderRepository.findAll();
        stopWatch.stop();
        
        stopWatch.start("enrich_with_items");
        orders.forEach(order -> {
            order.setItems(itemRepository.findByOrderId(order.getId()));
        });
        stopWatch.stop();
        
        if (stopWatch.getTotalTimeMillis() > 1000) {
            log.warn("Slow operation: {}ms\n{}", 
                stopWatch.getTotalTimeMillis(), 
                stopWatch.prettyPrint());
        }
        
        return orders;
    }
}

/* Результат:
StopWatch getAllOrders: running time = 1234 ms
---------------------------------------------
ms     %     Task name
---------------------------------------------
234    19%   fetch_orders
1000   81%   enrich_with_items
*/

Метрики Micrometer:

@Service
public class UserService {
    private final MeterRegistry meterRegistry;
    
    public UserService(MeterRegistry meterRegistry) {
        this.meterRegistry = meterRegistry;
    }
    
    public User getUser(Long id) {
        Timer.Sample sample = Timer.start(meterRegistry);
        try {
            return userRepository.findById(id).orElse(null);
        } finally {
            // Автоматически запишет время в metrics
            sample.stop(Timer.builder("user.get.time")
                .description("User retrieval time")
                .publishPercentiles(0.5, 0.95, 0.99)
                .minimumExpectedValue(Duration.ofMillis(1))
                .maximumExpectedValue(Duration.ofSeconds(5))
                .register(meterRegistry));
        }
    }
}

Способ 7: Query result set profiling

Определение N+1 проблемы:

// Включи Hibernate statistics
Session session = sessionFactory.openSession();
statistics.setStatisticsEnabled(true);

List<User> users = session.createQuery("from User").getResultList();

for (User user : users) {
    user.getOrders().size(); // N дополнительных запросов!
}

Statistics stats = statistics.getStatistics();
log.info("Loaded objects: {}", stats.getEntityLoadCount());
log.info("Entity fetch count: {}", stats.getEntityFetchCount());
log.info("Collection load count: {}", stats.getCollectionLoadCount());
log.info("Collection fetch count: {}", stats.getCollectionFetchCount());

/* Результат:
Loaded objects: 100
Entity fetch count: 100
Collection load count: 100  <- N+1 проблема!
Collection fetch count: 100
*/

Решение:

// Использование fetch join
List<User> users = session.createQuery(
    "from User u left join fetch u.orders",
    User.class
).getResultList();

// Или @EntityGraph
@Repository
public interface UserRepository extends JpaRepository<User, Long> {
    @EntityGraph(attributePaths = "orders")
    List<User> findAll();
}

Способ 8: Index анализ

Проверка неиспользуемых индексов:

-- PostgreSQL
SELECT schemaname, tablename, indexname, idx_scan, idx_tup_read, idx_tup_fetch
FROM pg_stat_user_indexes
WHERE idx_scan = 0  -- Индекс никогда не использовался
ORDER BY pg_relation_size(indexrelid) DESC;

-- MySQL
SELECT object_schema, object_name, count_read, count_write
FROM performance_schema.table_io_waits_summary_by_index_usage
WHERE index_name != PRIMARY AND count_read = 0
ORDER BY count_write DESC;

Чеклист диагностики медленного запроса

1. EXPLAIN / EXPLAIN ANALYZE
   - [ ] Используется ли индекс?
   - [ ] Есть ли Sequential Scan на большой таблице?
   - [ ] Количество examined rows vs returned rows

2. Логи
   - [ ] Включены ли slow query logs на БД?
   - [ ] Логируются ли SQL в приложении?
   - [ ] Есть ли паттерны?

3. Код
   - [ ] Есть ли N+1 проблема?
   - [ ] Используется ли fetch join / EntityGraph?
   - [ ] Есть ли ненужные LEFT JOIN?

4. Индексы
   - [ ] Есть ли индекс на WHERE колонке?
   - [ ] Составной индекс в правильном порядке?
   - [ ] Нет ли функций в WHERE (LOWER(), SUBSTRING и т.д.)?

5. Статистика
   - [ ] Свежа ли статистика в БД?
   - [ ] Нужно ли VACUUM / ANALYZE?

Заключение

Оптимальный стек инструментов для обнаружения медленных запросов:

1. Slow query logs (PostgreSQL/MySQL) — для production
2. EXPLAIN ANALYZE — для анализа плана исполнения
3. APM инструменты (New Relic/DataDog) — для мониторинга
4. Custom logging (StopWatch/Micrometer) — для приложения
5. pgBadger — для анализа тренда медленных запросов

Регулярный мониторинг производительности запросов предотвращает критические проблемы в production.