Профилирование MySQL-запросов 1С-Битрикс

Профилирование MySQL-запросов 1С-Битрикс

Битрикс активно работает с базой данных: модуль каталога (b_catalog_price, b_iblock_element, b_iblock_element_prop_s*), поиск (b_search_content), сессии (b_user_session). При 20–50 тысячах товаров и включённых свойствах инфоблока типичная страница каталога генерирует 50–200 SQL-запросов. Часть из них выполняется за 1–2 мс, но несколько могут занимать по 500 мс — и именно они определяют время ответа страницы.

Включение slow query log

Первый инструмент — журнал медленных запросов MySQL. Включается без перезапуска сервера:

-- Динамически, без перезагрузки MySQL
SET GLOBAL slow_query_log = 'ON';
SET GLOBAL slow_query_log_file = '/var/log/mysql/slow.log';
SET GLOBAL long_query_time = 0.5;       -- запросы дольше 500 мс
SET GLOBAL log_queries_not_using_indexes = 1;  -- запросы без индексов

В /etc/mysql/conf.d/slow.cnf для постоянного эффекта:

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 0.5
log_queries_not_using_indexes = 1
min_examined_row_limit = 100

min_examined_row_limit = 100 убирает шум от быстрых запросов по первичному ключу, которые «не используют индекс» формально.

Анализ через pt-query-digest

Percona Toolkit — стандарт анализа slow log:

pt-query-digest /var/log/mysql/slow.log \
    --limit 20 \
    --report-format query_report \
    > /tmp/slow_report.txt

Отчёт группирует запросы по нормализованному шаблону (заменяет значения на ?), показывает:

• Calls — сколько раз выполнялся
• R/Call — среднее время на вызов
• R/t — суммарное время за период

На Битрикс-проектах топ-5 проблемных запросов обычно выглядит так:

1. SELECT ... FROM b_iblock_element_prop_s5 WHERE IBLOCK_ELEMENT_ID IN (...) — N+1 при выборке свойств
2. SELECT ... FROM b_catalog_price WHERE PRODUCT_ID = ? — поштучная выборка цен
3. SELECT COUNT(*) FROM b_iblock_element WHERE ... — COUNT без индекса по составному фильтру
4. SELECT ... FROM b_search_content WHERE ... — полнотекстовый поиск по большой таблице
5. UPDATE b_user_session SET ... — конкуренция за обновление сессий

EXPLAIN и анализ плана запроса

Для каждого медленного запроса из отчёта запускаем EXPLAIN:

EXPLAIN SELECT be.ID, be.NAME, bp.VALUE
FROM b_iblock_element be
LEFT JOIN b_iblock_element_prop_s5 bp ON bp.IBLOCK_ELEMENT_ID = be.ID
WHERE be.IBLOCK_ID = 12
  AND be.ACTIVE = 'Y'
  AND be.WF_STATUS_ID = 1
ORDER BY be.SORT ASC
LIMIT 48 OFFSET 0;

На что смотреть в выводе EXPLAIN:

• type = ALL (full table scan) — отсутствует индекс, критично
• type = ref или range — используется индекс, нормально
• rows — оценка числа проверяемых строк; если на таблице с 100k записей rows = 95000 — индекс не работает
• Extra: Using filesort — сортировка в памяти/на диске, может быть дорогой
• Extra: Using temporary — создаётся временная таблица

-- EXPLAIN ANALYZE (MySQL 8.0+) показывает реальное время
EXPLAIN ANALYZE SELECT ...;

Создание индексов для типичных запросов Битрикс

Несколько индексов, которые регулярно отсутствуют в стандартной установке или исчезают после обновлений:

-- Составной индекс для фильтрации активных элементов по инфоблоку с сортировкой
CREATE INDEX idx_iblock_element_active_sort
ON b_iblock_element (IBLOCK_ID, ACTIVE, WF_STATUS_ID, SORT);

-- Индекс для выборки цен по продуктам и группам
CREATE INDEX idx_catalog_price_product_group
ON b_catalog_price (PRODUCT_ID, CATALOG_GROUP_ID);

-- Индекс для поиска по сессиям (если b_user_session без кэша)
CREATE INDEX idx_user_session_timestamp
ON b_user_session (TIMESTAMP_X);

После создания индекса перезапускаем EXPLAIN — тип должен измениться с ALL на ref или range.

Битрикс ORM и N+1

D7 ORM (\Bitrix\Main\ORM) часто генерирует N+1 при работе со связанными сущностями. Диагностика — через встроенный дебаггер или перехват SQL:

// Логируем все запросы в dev-окружении
\Bitrix\Main\Application::getConnection()->setTracker(
    new \Bitrix\Main\DB\SqlTracker(50)
);

// В конце запроса:
$tracker = \Bitrix\Main\Application::getConnection()->getTracker();
foreach ($tracker->getQueries() as $query) {
    if ($query->getTime() > 0.1) {
        error_log($query->getSql() . ' [' . $query->getTime() . 's]');
    }
}

Типичный N+1 в ORM-коде:

// ПЛОХО: запрос к b_catalog_price на каждой итерации
$elements = ElementTable::getList(['filter' => ['IBLOCK_ID' => 12]]);
while ($el = $elements->fetch()) {
    $price = PriceTable::getRow(['filter' => ['PRODUCT_ID' => $el['ID']]]); // N запросов
}

// ХОРОШО: batch-выборка
$ids = array_column($elements->fetchAll(), 'ID');
$prices = PriceTable::getList(['filter' => ['PRODUCT_ID' => $ids]])->fetchAll();
$priceMap = array_column($prices, null, 'PRODUCT_ID');

Кейс: оптовый дистрибьютор

Сайт на Битрикс «Малый бизнес», каталог 28 000 позиций, 3 000 уникальных посетителей в день. Сервер: 4 CPU, 8 GB RAM. Нагрузка на MySQL — 85–90% CPU в пиковые часы, периодические таймауты.

pt-query-digest за сутки показал: 92% суммарного времени MySQL — запросы к b_iblock_element_prop_s8 (таблица строковых свойств). EXPLAIN показал type = ALL на 280 000 строк — индекс по IBLOCK_ELEMENT_ID отсутствовал.

-- Один индекс закрыл проблему
CREATE INDEX idx_prop_s8_element_id ON b_iblock_element_prop_s8 (IBLOCK_ELEMENT_ID);

Нагрузка на MySQL упала с 85–90% до 15–20% CPU без каких-либо изменений в коде приложения.

Инструменты мониторинга

• Percona Monitoring and Management (PMM) — полнофункциональный стек, графики QPS, latency, топ запросов в реальном времени
• MySQL Workbench → Performance Schema — встроенный GUI, удобен для разовой диагностики
• Grafana + mysql_exporter — для интеграции в существующий мониторинг

Сроки