Profiling MySQL queries in 1C-Bitrix

MySQL Query Profiling for 1C-Bitrix

Bitrix makes heavy use of the database: the catalog module (b_catalog_price, b_iblock_element, b_iblock_element_prop_s*), search (b_search_content), and sessions (b_user_session). With 20–50 thousand products and enabled iblock properties, a typical catalog page generates 50–200 SQL queries. Some execute in 1–2 ms, but a handful may take 500 ms each — and those are what determine the page response time.

Enabling the Slow Query Log

The first tool is MySQL's slow query log. It can be enabled without restarting the server:

-- Dynamically, without reloading 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;       -- queries longer than 500 ms
SET GLOBAL log_queries_not_using_indexes = 1;  -- queries not using indexes

In /etc/mysql/conf.d/slow.cnf for a permanent effect:

[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 filters out noise from fast primary-key lookups that technically "don't use an index."

Analysis with pt-query-digest

Percona Toolkit is the standard for slow log analysis:

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

The report groups queries by normalized pattern (replacing values with ?) and shows:

• Calls — how many times the query was executed
• R/Call — average time per call
• R/t — total time over the period

On Bitrix projects, the top 5 problematic queries typically look like this:

1. SELECT ... FROM b_iblock_element_prop_s5 WHERE IBLOCK_ELEMENT_ID IN (...) — N+1 when fetching element properties
2. SELECT ... FROM b_catalog_price WHERE PRODUCT_ID = ? — per-item price fetching
3. SELECT COUNT(*) FROM b_iblock_element WHERE ... — COUNT without an index on a composite filter
4. SELECT ... FROM b_search_content WHERE ... — full-text search on a large table
5. UPDATE b_user_session SET ... — contention on session updates

EXPLAIN and Query Plan Analysis

For each slow query from the report, run 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;

What to look for in EXPLAIN output:

• type = ALL (full table scan) — no index present, critical issue
• type = ref or range — index is used, acceptable
• rows — estimated number of rows examined; if a 100k-row table shows rows = 95000, the index is not effective
• Extra: Using filesort — in-memory or on-disk sort, can be expensive
• Extra: Using temporary — a temporary table is created

-- EXPLAIN ANALYZE (MySQL 8.0+) shows actual runtime
EXPLAIN ANALYZE SELECT ...;

Creating Indexes for Typical Bitrix Queries

Several indexes that are regularly missing from a standard installation or disappear after updates:

-- Composite index for filtering active elements by iblock with sorting
CREATE INDEX idx_iblock_element_active_sort
ON b_iblock_element (IBLOCK_ID, ACTIVE, WF_STATUS_ID, SORT);

-- Index for price lookup by product and group
CREATE INDEX idx_catalog_price_product_group
ON b_catalog_price (PRODUCT_ID, CATALOG_GROUP_ID);

-- Index for session lookups (if b_user_session has no cache)
CREATE INDEX idx_user_session_timestamp
ON b_user_session (TIMESTAMP_X);

After creating an index, re-run EXPLAIN — the type should change from ALL to ref or range.

Bitrix ORM and N+1

The D7 ORM (\Bitrix\Main\ORM) frequently generates N+1 queries when working with related entities. Diagnose it via the built-in debugger or by intercepting SQL:

// Log all queries in the dev environment
\Bitrix\Main\Application::getConnection()->setTracker(
    new \Bitrix\Main\DB\SqlTracker(50)
);

// At the end of the request:
$tracker = \Bitrix\Main\Application::getConnection()->getTracker();
foreach ($tracker->getQueries() as $query) {
    if ($query->getTime() > 0.1) {
        error_log($query->getSql() . ' [' . $query->getTime() . 's]');
    }
}

A typical N+1 pattern in ORM code:

// BAD: query to b_catalog_price on every iteration
$elements = ElementTable::getList(['filter' => ['IBLOCK_ID' => 12]]);
while ($el = $elements->fetch()) {
    $price = PriceTable::getRow(['filter' => ['PRODUCT_ID' => $el['ID']]]); // N queries
}

// GOOD: batch fetch
$ids = array_column($elements->fetchAll(), 'ID');
$prices = PriceTable::getList(['filter' => ['PRODUCT_ID' => $ids]])->fetchAll();
$priceMap = array_column($prices, null, 'PRODUCT_ID');

Case Study: Wholesale Distributor

A Bitrix Small Business site, 28,000-item catalog, 3,000 unique visitors per day. Server: 4 CPU, 8 GB RAM. MySQL load: 85–90% CPU during peak hours, periodic timeouts.

pt-query-digest over 24 hours showed: 92% of total MySQL time was spent on queries against b_iblock_element_prop_s8 (the string properties table). EXPLAIN showed type = ALL across 280,000 rows — the index on IBLOCK_ELEMENT_ID was missing.

-- One index fixed the problem
CREATE INDEX idx_prop_s8_element_id ON b_iblock_element_prop_s8 (IBLOCK_ELEMENT_ID);

MySQL CPU load dropped from 85–90% to 15–20% with no changes to application code.

Monitoring Tools

• Percona Monitoring and Management (PMM) — full-featured stack with QPS graphs, latency, and top queries in real time
• MySQL Workbench → Performance Schema — built-in GUI, convenient for one-off diagnostics
• Grafana + mysql_exporter — for integration with an existing monitoring setup

Timelines