Как посмотреть план и время выполнения запроса в SQL

Просмотр плана выполнения (EXPLAIN) и времени запроса в SQL

Для оптимизации запросов важно понимать, как база данных их выполняет. Для этого используются команды EXPLAIN и инструменты анализа времени.

1. EXPLAIN PLAN (план выполнения запроса)

EXPLAIN показывает, как SQL engine планирует выполнить запрос, БЕЗ его фактического выполнения.

PostgreSQL:

-- Базовое использование
EXPLAIN SELECT * FROM users WHERE id = 1;

-- Результат показывает:
-- RESULT:
-- Seq Scan on users  (cost=0.00..35.50 rows=1 width=100)
--   Filter: (id = 1)

-- С ANALYZE (фактическое выполнение + статистика)
EXPLAIN ANALYZE SELECT * FROM users WHERE id = 1;

-- Результат:
-- Seq Scan on users  (cost=0.00..35.50 rows=1 width=100) (actual time=0.05..0.10 rows=1 loops=1)
--   Filter: (id = 1)
-- Planning Time: 0.05 ms
-- Execution Time: 0.15 ms

-- С подробностью (всю информацию)
EXPLAIN (ANALYZE, VERBOSE, COSTS, BUFFERS) 
SELECT * FROM users WHERE id = 1;

MySQL:

-- EXPLAIN в MySQL
EXPLAIN SELECT * FROM users WHERE id = 1;

-- Результат (таблица):
-- id | select_type | table | type  | possible_keys | key     | key_len | ref   | rows | Extra
-- 1  | SIMPLE      | users | const | PRIMARY       | PRIMARY | 8       | const | 1    |

-- С FORMAT JSON для понятности
EXPLAIN FORMAT=JSON 
SELECT * FROM users WHERE id = 1;

2. Понимание плана выполнения

Главные параметры EXPLAIN ANALYZE:

EXPLAIN ANALYZE 
SELECT u.id, u.name, COUNT(o.id) as order_count
FROM users u
LEFT JOIN orders o ON u.id = o.user_id
WHERE u.created_at > '2024-01-01'
GROUP BY u.id, u.name;

-- РЕЗУЛЬТАТ:
-- Hash Aggregate  (cost=1000.50..1050.75 rows=500 width=40) (actual time=10.20..15.30 rows=500 loops=1)
--   ->  Hash Left Join  (cost=500.25..900.50 rows=5000 width=50) (actual time=2.10..8.50 rows=5000 loops=1)
--         Hash Cond: (o.user_id = u.id)
--         ->  Seq Scan on orders o  (cost=0.00..400.00 rows=10000 width=16) (actual time=0.05..3.20 rows=10000 loops=1)
--         ->  Hash  (cost=450.25..450.25 rows=500 width=40) (actual time=1.50..1.50 rows=500 loops=1)
--               ->  Seq Scan on users u  (cost=0.00..450.25 rows=500 width=40) (actual time=0.02..0.50 rows=500 loops=1)
--                     Filter: (created_at > '2024-01-01')
--                     Rows Removed by Filter: 500
-- Planning Time: 0.25 ms
-- Execution Time: 15.60 ms

/* Разбираем результат:

1. EXECUTION ORDER (как выполняется, снизу вверх):
   a) Seq Scan на users: reads all users, filters by created_at
      -> 500 rows (after filter)
   
   b) Seq Scan на orders: reads all orders
      -> 10000 rows
   
   c) Hash Join: объединяет users и orders
      -> 5000 rows
   
   d) Hash Aggregate: группирует и считает
      -> 500 rows итоговых

2. COST vs ACTUAL:
   - cost=1000.50..1050.75: ПЛАНИРУЕМОЕ время (в условных единицах)
   - actual time=10.20..15.30: РЕАЛЬНОЕ время (в миллисекундах)
   - Если actual > cost: план был слишком оптимистичен
   - Если actual < cost: хорошо, оценка была консервативной

3. ROWS:
   - rows=500 (estimated): сколько рядов ожидается
   - rows=500 (actual): сколько рядов было на самом деле
   - Если отличаются: проблема со статистикой, нужен ANALYZE TABLE

4. LOOPS:
   - loops=1: алгоритм запущен 1 раз (хорошо)
   - loops > 1: вложенные циклы (может быть неоптимально)
*/

3. Типы операций в плане выполнения

-- Seq Scan — полное сканирование таблицы (BAD для больших таблиц)
SELECT * FROM users;
-- Index Scan или Index Only Scan — использование индекса (GOOD)
SELECT * FROM users WHERE id = 5;
-- Bitmap Index Scan — гибридный подход (MEDIUM)
SELECT * FROM users WHERE age > 30 AND status = 'active';

-- Nested Loop Join — вложенные циклы (может быть медленно)
SELECT * FROM users u 
JOIN orders o ON u.id = o.user_id;

-- Hash Join — создает хеш-таблицу (часто быстро)
SELECT * FROM users u 
JOIN orders o ON u.id = o.user_id;

-- Sort — сортировка (может быть медленно для больших наборов)
SELECT * FROM users ORDER BY created_at DESC;

4. Команды для измерения времени

PostgreSQL:

-- Включить timing
\timing on

-- Выполнить запрос (будет показано время)
SELECT * FROM users WHERE id = 1;
-- Timing: 0.45 ms

-- Отключить timing
\timing off

-- Кроме того, EXPLAIN ANALYZE показывает:
-- Planning Time: 0.25 ms
-- Execution Time: 0.45 ms

MySQL:

-- Включить профилирование
SET profiling = 1;

-- Выполнить запрос
SELECT * FROM users WHERE id = 1;

-- Просмотреть последние запросы
SHOW PROFILES;

-- Подробная информация о последнем запросе
SHOW PROFILE FOR QUERY 1;

-- Результат:
-- Status             | Duration
-- starting           | 0.000015
-- checking query cache | 0.000010
-- Opening tables     | 0.000025
-- init               | 0.000035
-- System lock        | 0.000008
-- Waiting for query cache lock | 0.000005
-- Query body parse   | 0.000015
-- Query cache hit    | 0.000008
-- Query cache insert | 0.000020
-- System unlock      | 0.000010
-- Sending data       | 0.000095
-- end                | 0.000010

Отключить профилирование:
SET profiling = 0;

JAVA с JDBC:

import java.sql.*;
import java.time.Instant;

public class QueryPerformanceAnalyzer {
    public void analyzeQuery(String sql) throws SQLException {
        Connection conn = DriverManager.getConnection(
            "jdbc:postgresql://localhost:5432/mydb", 
            "user", 
            "password"
        );
        
        // Способ 1: Простое измерение времени
        long startTime = System.nanoTime();
        
        try (Statement stmt = conn.createStatement()) {
            ResultSet rs = stmt.executeQuery(sql);
            while (rs.next()) {
                // Process results
            }
        }
        
        long endTime = System.nanoTime();
        double duration = (endTime - startTime) / 1_000_000.0; // в миллисекундах
        System.out.println("Query execution time: " + duration + " ms");
        
        // Способ 2: EXPLAIN ANALYZE через Java
        String explainQuery = "EXPLAIN ANALYZE " + sql;
        try (Statement stmt = conn.createStatement()) {
            ResultSet rs = stmt.executeQuery(explainQuery);
            System.out.println("\nExecution Plan:");
            while (rs.next()) {
                System.out.println(rs.getString(1));
            }
        }
        
        conn.close();
    }
    
    // Более точное измерение с несколькими прогонами
    public void benchmarkQuery(String sql, int iterations) throws SQLException {
        Connection conn = DriverManager.getConnection(
            "jdbc:postgresql://localhost:5432/mydb", 
            "user", 
            "password"
        );
        
        long totalTime = 0;
        long minTime = Long.MAX_VALUE;
        long maxTime = 0;
        
        for (int i = 0; i < iterations; i++) {
            long start = System.nanoTime();
            
            try (Statement stmt = conn.createStatement()) {
                ResultSet rs = stmt.executeQuery(sql);
                while (rs.next()) {
                    // Process results
                }
            }
            
            long duration = System.nanoTime() - start;
            totalTime += duration;
            minTime = Math.min(minTime, duration);
            maxTime = Math.max(maxTime, duration);
        }
        
        System.out.println("\nBenchmark Results (" + iterations + " iterations):");
        System.out.println("Average: " + (totalTime / iterations / 1_000_000.0) + " ms");
        System.out.println("Min: " + (minTime / 1_000_000.0) + " ms");
        System.out.println("Max: " + (maxTime / 1_000_000.0) + " ms");
    }
}

5. Практический пример оптимизации

Плохой запрос:

EXPLAIN ANALYZE
SELECT * FROM orders WHERE user_id = 42;

-- РЕЗУЛЬТАТ:
-- Seq Scan on orders  (cost=0.00..500.00 rows=10000 width=50)
-- Planning Time: 0.05 ms
-- Execution Time: 45.32 ms  <- МЕДЛЕННО!

-- Проблема: Seq Scan — полное сканирование таблицы

Решение: создание индекса

CREATE INDEX idx_orders_user_id ON orders(user_id);

EXPLAIN ANALYZE
SELECT * FROM orders WHERE user_id = 42;

-- РЕЗУЛЬТАТ:
-- Index Scan using idx_orders_user_id on orders  (cost=0.29..8.30 rows=10 width=50)
-- Index Cond: (user_id = 42)
-- Planning Time: 0.10 ms
-- Execution Time: 0.42 ms  <- НАМНОГО БЫСТРЕЕ!

-- Улучшение: 45.32 ms -> 0.42 ms = 107x ускорение!

6. Инструменты анализа

PGADMIN (для PostgreSQL):

1. Подключиться к базе
2. Tools -> Query Tool
3. Написать запрос
4. Explain -> Explain или Explain Analyze
5. Видеть план визуально с цветовой схемой

MySQL Workbench:

1. Подключиться к БД
2. Написать запрос
3. Query -> Explain Current Statement
4. Видеть таблицу с параметрами

DBeaver (универсальный инструмент):

1. SQL запрос
2. Ctrl+E (Explain)
3. Видеть план

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

1. EXPLAIN ANALYZE — посмотреть план
2. Проверить costs — планируемое vs реальное время
3. Найти Seq Scans — полные сканирования таблиц (BAD)
4. Проверить индексы — есть ли нужные индексы?
5. Проверить статистику — ANALYZE TABLE
6. Измерить время — \timing on в PostgreSQL
7. Профилировать — SHOW PROFILE в MySQL
8. Прочитать execution plan — понять порядок операций
9. Оптимизировать — индексы, JOIN order, WHERE условия
10. Переизмерить — убедиться, что улучшилось

Пример анализа в Spring Boot приложении

@Service
public class OrderService {
    @Autowired
    private JdbcTemplate jdbcTemplate;
    
    public List<Order> findOrdersByUserId(Long userId) {
        String sql = "SELECT * FROM orders WHERE user_id = ?";
        
        // Добавить logging времени
        long startTime = System.currentTimeMillis();
        
        List<Order> orders = jdbcTemplate.query(
            sql,
            new OrderRowMapper(),
            userId
        );
        
        long duration = System.currentTimeMillis() - startTime;
        logger.info("Query executed in {} ms", duration);
        
        if (duration > 1000) {
            logger.warn("Slow query detected! Running EXPLAIN ANALYZE...");
            explainQuery(sql);
        }
        
        return orders;
    }
    
    private void explainQuery(String sql) {
        String explainSql = "EXPLAIN ANALYZE " + sql;
        jdbcTemplate.query(explainSql, rs -> {
            while (rs.next()) {
                logger.info(rs.getString(1));
            }
        });
    }
}

Заключение

Для анализа SQL запросов используй:

1. EXPLAIN — для плана выполнения (БЕЗ выполнения)
2. EXPLAIN ANALYZE — для плана + реального времени (С выполнением)
3. \timing on (PostgreSQL) — для быстрого измерения времени
4. SET profiling = 1 (MySQL) — для детальной профилизации
5. DBeaver/PGADMIN — для визуализации плана
6. Java System.nanoTime() — для точного измерения в приложении

Оптимальный запрос: планируемое время близко к реальному и использует индексы вместо full table scans.