Reading the Slow Query Log: When the Database Is the Brake

A shop rarely turns slow overnight. It happens in steps: the catalogue grows, filters are added, a reporting view in the back office pulls figures across twelve months, and one additional field gets no index. At some point the category page takes a second longer than it did last year, and nobody can say why. This article shows how to make the database tell you itself: with the slow query log, a defensible evaluation and indexes that match the actual query. Our Shopware agency works through exactly this order whenever a shop turns sluggish for no visible reason.

Why the database slows things down unseen

The database is the layer in a shop that produces a visible error message least often. A template with a syntax error breaks off, a missing image leaves a gap, an expired certificate blocks the request. A query, by contrast, returns a correct result even when it needs 1.8 seconds and two million rows read to do so. It is not broken, it is merely expensive. That is precisely why this problem travels through every stage of a shop's growth without anyone writing it down. Anyone who has their hosting and maintenance professionally supervised sees the curve of these costs earlier than through complaints reaching customer service.

The commercial backdrop is stable: 4 percent of internet users in Germany buy online every day, and another 28 percent do so at least once a week (Bitkom). This group already knows your shop. It arrives with an expectation of speed that is shaped by online retail as a whole and not by your server configuration. A category page that waits two seconds for the database is far more noticeable to a weekly visitor than to someone who orders twice a year.

How quickly technical problems lead to an abandoned purchase was surveyed by Bitkom back in 2017: as reasons for cancelled orders, 49 percent named a poor internet connection, 43 percent difficulties during payment, 42 percent a website that was not user-friendly and 32 percent an error on the website (Bitkom 2017). The figures come from a 2017 survey and describe the ranking, not today's state. The order is remarkable all the same: four of the most frequently named reasons are technical, and three of them are within the shop operator's reach.

Switching on the slow query log

The first step costs nothing and is skipped anyway: the log of slow queries is switched off out of the box. The documentation states it in a single sentence - the slow query log is disabled by default (MariaDB). Without that switch there is no evidence base, and every discussion about indexes remains a matter of opinion. If you are planning a version change anyway, our article on the end of life of MySQL 8.0 is worth a look - logging and migration fit into the same maintenance window.

The second point is the threshold. By default a query is only logged once it takes longer than a certain amount of time, and the preset is ten seconds (MariaDB). For a shop that is useless: a single query hardly ever reaches ten seconds in normal operation, while the actual problem is made up of four hundred queries at 40 milliseconds each. The minimum and default values of long_query_time are 0 and 10 respectively (MySQL), and the value can be specified to a resolution of microseconds (MySQL). In practice, starting at 0.2 seconds and lowering later has proven itself.

[mysqld]
slow_query_log = 1
slow_query_log_file = /var/log/mysql/slow.log
long_query_time = 0.2
log_queries_not_using_indexes = 1
min_examined_row_limit = 1000
log_slow_rate_limit = 1
log_slow_verbosity = query_plan,explain

The log_queries_not_using_indexes switch adds a second class of candidates to the log. The slow query log can be configured to log queries that do not use indexes regardless of their execution time, either through the not_using_index option in log_slow_filter or by setting the log_queries_not_using_indexes system variable to 1 (MariaDB). This is the switch that reveals the fast but structurally wrong queries - the ones that run through 50,000 rows in 30 milliseconds today and through 900,000 in eighteen months.

So that this second switch does not flood the log, a lower bound belongs with it. It can be beneficial to exclude queries that examine fewer than a minimum number of rows from the log (MariaDB). A query that reads ten rows without an index is not a case for optimisation, it is a lookup in a configuration table. With min_examined_row_limit you define the order of magnitude at which you want to look at all.

• slow_query_log - the main switch. Without it nothing is written.
• long_query_time - the threshold in seconds, decimal places down to microseconds are permitted.
• log_queries_not_using_indexes - logs queries without index usage regardless of duration.
• min_examined_row_limit - raises the triviality bound so that small lookups stay out.
• log_slow_rate_limit - records only every nth matching query when the log grows too fast.
• log_slow_verbosity - adds the query plan and the explanation so the evaluation needs no re-staging.

On a shop with high traffic, even a cleanly bounded log can grow too large. There is a throttle for that: the slow query log can be throttled by configuring the log_slow_rate_limit system variable (MariaDB). Instead of every matching query, only every tenth or hundredth is then written. For a ranking by frequency that is sufficient, as long as you factor the sample into the evaluation.

From the raw log to a ranking

In its raw state a slow query log is a text file with thousands of nearly identical entries. Anyone reading it by hand finds the most conspicuous query and overlooks the most expensive one. The server vendor ships a tool for the summary: to make this easier, you can use the mysqldumpslow command to process a slow query log file and summarise its contents (MySQL). The tool replaces literals with placeholders and thereby groups all variants of the same query into one line.

The decisive column is not the single duration but the product of duration and count - in the example above, the figure in brackets after the time. A query at 0.04 seconds looks harmless, yet at 96,140 calls a day it consumes more compute time than the spectacular query at 0.31 seconds. Anyone sorting only by the longest runtime optimises the wrong place and then wonders why the load time stays the same.

1. Sort by total time (-s t), not by peak value - that shows where the compute time actually goes.
2. Sort by count (-s c) and check whether a query is executed several times per page view.
3. Look at the ratio of rows read to rows returned: 1,153,680 read for 96,140 calls is a different finding than 12 read per call.
4. Write out the three most expensive patterns and follow them up individually instead of working the list from top to bottom.

EXPLAIN estimates, ANALYZE measures

Once an expensive query has been identified, the execution plan comes next. EXPLAIN shows the route the optimiser would take: which table is read first, which index comes into question, how many rows it expects. The most important caveat sits in the word expects. The rows column is an estimate drawn from the table statistics, not a measurement. And it describes the rows the plan intends to read before a LIMIT takes effect - a query with LIMIT 20 can carry a six-digit figure in that column and still stop after twenty hits. Conversely, a low estimate can hide an expensive query when the statistics are stale.

Both widespread server branches therefore offer a measuring variant. In one of them, EXPLAIN ANALYZE runs a statement and produces EXPLAIN output along with timing and additional, iterator-based, information about how the optimiser's expectations matched the actual execution (MySQL). That puts the measured value next to every estimated one. If you want to build such runs into your development environment, our programming and development service provides the framework.

In the other branch the command is simply called ANALYZE: the statement invokes the optimiser, executes the statement, and then produces EXPLAIN output instead of the result set (MariaDB). The difference from an estimate sits in two additional columns. r_rows is an observation-based counterpart of the rows column and shows how many rows were actually read from the table (MariaDB). Where rows says 1,200 and r_rows shows 486,000, the statistics are the problem, not the index.

-- Estimate: what the optimiser expects
EXPLAIN
SELECT p.id, p.product_number
FROM `order` o
JOIN order_line_item p ON p.order_id = o.id
WHERE o.order_date_time >= '2026-08-01'
  AND o.state_id = 0x9F2C
ORDER BY o.order_date_time DESC
LIMIT 20;

-- Measurement: what actually happened
ANALYZE
SELECT p.id, p.product_number
FROM `order` o
JOIN order_line_item p ON p.order_id = o.id
WHERE o.order_date_time >= '2026-08-01'
  AND o.state_id = 0x9F2C
ORDER BY o.order_date_time DESC
LIMIT 20;

These two columns are not available only in the interactive call. The r_rows and r_filtered columns are also included in the EXPLAIN output written to the slow query log from version 10.1.0 onwards (MariaDB). With log_slow_verbosity set to query_plan,explain you therefore get the measurement directly in the log - without re-staging the query and without artificially reproducing the production load. This is the point at which a diagnosis switches from reconstruction to observation.

For the assessment there is a usable rule of thumb straight from the documentation. On the worked example it notes that the optimiser somewhat overestimated the number of matching records, and continues: when you have a full scan and r_filtered is less than 15 percent, it is time to consider adding an appropriate index (MariaDB). That threshold is no law of nature, but it replaces gut feeling with a figure a team can discuss.

The literal in the wrong type

There is one mistake that switches off an existing, correctly built index entirely without producing a warning: the literal in the wrong data type. The rule is stated briefly in the documentation: for comparisons of a string column with a number, the server cannot use an index on the column to look up the value quickly (MySQL). The reason is the implicit conversion: the server has to convert every single row into a number before it can compare - and an index over the strings does not help with that arithmetic.

-- customer_number is VARCHAR(32) with an index

-- switches the index off: number against string
SELECT id FROM customer WHERE customer_number = 10042;

-- uses the index: string against string
SELECT id FROM customer WHERE customer_number = '10042';

-- same effect with a function around the column
SELECT id FROM `order` WHERE DATE(order_date_time) = '2026-08-01';
SELECT id FROM `order`
 WHERE order_date_time >= '2026-08-01 00:00:00'
   AND order_date_time < '2026-08-02 00:00:00';

In day-to-day shop operation this mainly affects three fields: order numbers, customer numbers and article numbers. All three look like numbers but are stored as strings for good reason, because leading zeros, prefixes or letter blocks occur. As soon as an interface passes the value as a number - an import run, a report, a link to the merchandise management system - an indexed lookup turns into a full table scan. Automated checks catch this early; what such a test framework looks like is described in our article on E2E test automation for online shops.

Composite indexes and their order

Most shop queries filter on several columns at once: sales channel and active flag, category and sort position, customer and order date. Composite indexes exist for that, and their capacity is generous - an index may consist of up to 16 columns (MySQL). That figure tempts people to pack every filter column into one index. It only helps when the order is right, because a composite index is a sorted list over the column sequence and not a collection of independent lookup tables.

The governing rule is the prefix rule, and the documentation puts it like this: the server can use multiple-column indexes for queries that test all the columns in the index, or queries that test just the first column, the first two columns, the first three columns, and so on (MySQL). An index over (sales_channel_id, active, created_at) therefore also serves a query that filters on sales_channel_id alone. A query that filters exclusively on created_at it does not serve - that would need its own index or a different column order.

-- Equality filters first, range and sorting last
CREATE INDEX idx_order_channel_state_date
  ON `order` (sales_channel_id, state_id, order_date_time);

-- uses the index fully
SELECT id FROM `order`
 WHERE sales_channel_id = 0x1A AND state_id = 0x9F
 ORDER BY order_date_time DESC LIMIT 20;

-- uses only the first pair of columns
SELECT id FROM `order`
 WHERE sales_channel_id = 0x1A AND state_id = 0x9F;

-- does not use the index: the first column is missing from the filter
SELECT id FROM `order`
 WHERE order_date_time >= '2026-08-01';

• Columns with equality comparisons belong at the front, columns with range comparisons behind them - after a range the usable prefix chain ends.
• The sort column belongs at the end, then the server reads the order from the index instead of producing it afterwards.
• Selective columns before unselective ones: a column with two possible values narrows less than one with ten thousand.
• Before every new index, check whether an existing one already contains it as a prefix - then the new one is redundant.
• With every change to the column order, verify the affected queries with a measurement, not with an assumption.

Between index maintenance and caching there is a division of labour worth knowing: a cache lowers the number of calls, an index lowers the cost per call. Both work together, but only one of them helps with the first call after an update. How caching can be set up in a shop is covered in the article on Redis caching for Shopware.

When an index does harm

An index is not a free accelerant. It occupies space, it has to be maintained on every write, and it lengthens import runs. Above all, it does not help in every situation. The documentation is unusually clear here: indexes are less important for queries on small tables, or big tables where report queries process most or all of the rows (MySQL). The reason follows immediately: when a query needs to access most of the rows, reading sequentially is faster than working through an index (MySQL).

In practice that means a nightly revenue report across all orders of a month needs no additional index but a different time window or a precomputed table. An index on a status table with twelve rows changes nothing, because the table sits in memory anyway. Anyone who creates both regardless pays on every write and gains nothing.

There is a figure for the borderline case too. On an example with a filter that leaves just under a third of the rows, the documentation notes: 30 percent is typically not selective enough to warrant adding new indexes (MariaDB). Together with the 15 percent mark from the previous section this yields a usable corridor: below 15 percent an index is generally worthwhile, from 30 percent it rarely is, and in between the measurement decides. How much the application layer itself contributes to the load time is shown in the article on OPcache and JIT under PHP 8.5.

A diagnostic routine for everyday shop work

The individual building blocks only become useful once they are worked through in a fixed order. The following routine can be started in a maintenance window and carried out over two to four weeks. It ends with a list of changes that are each measurable on their own - and not with a bundle where it stays unclear afterwards which step had the effect.

1. Switch on the log, threshold at 0.2 seconds, index filter on, triviality bound at 1,000 examined rows.
2. Let it run for seven days so that the weekly rhythm, newsletter dispatch and import runs appear in the log.
3. Evaluate with mysqldumpslow by total time and by count, and write out the ten most expensive patterns.
4. Measure the execution plan per pattern instead of estimating it: ANALYZE or EXPLAIN ANALYZE.
5. Fix type errors and functions around columns first - these corrections cost nothing and take effect immediately.
6. Only then create indexes, one at a time, with the row count and runtime measured before and after.
7. Verify the write load: measure the import run and the order completion again after every index change.
8. Lower the threshold and repeat the run until the most expensive entry falls below the relevance bound.

The seventh step is the one most often skipped and the most expensive to pay for. An index that speeds up the category page by 400 milliseconds and lengthens the nightly import run by twenty minutes is a bad deal if the import falls into a window with store pickups. How closely such processes are linked is shown in the article on click and collect as a well-designed process.

What this means for shop operators

Database diagnosis is not a specialist discipline for exceptional cases but a recurring maintenance task like applying updates. A shop whose catalogue grows by thirty percent has different query profiles afterwards, and an index that fitted two years ago may be redundant today. Experience puts the effort for a full pass at two to three person-days spread over a few weeks of runtime - considerably less than a server upgrade, which merely postpones the same symptom. In our consulting and conception we set this effort against the alternatives.

If you are planning a larger project, the topic belongs in the requirements early: recording in advance which queries should answer how fast under which load saves renegotiation during operation. Wording aids for this are in the article on the requirements specification for a shop project. And anyone who merely wants to know whether the effort is worth it at all switches the log on for a week and looks at the total column - that answer costs one configuration line.