MariaDB Slow Query Log Explained

Troubleshooting MariaDB Performance with Slow Query Log 



Introduction

How do be troubleshoot MariaDB for performance ? We get this question often and there is definitely no silver bullet to troubleshoot MariaDB performance like a magic so it’s always better to understand performance bottleneck in detail. Let us first explain how we define performance in MinervaDB – Performance is a combination of latency and throughput, is there a ratio in that computation ? Absolutely not, A very expensive SQL in a high performance server can never benefit from processing power and infrastructure investments, this equally applies when you execute a optimal SQL on undersized infrastructure, throughput is very important to increase the velocity of data retrieval and processing, So where do we start MariaDB performance audit / forensics in MinervaDB ? We strongly believe  performance is ” Response Time “, If we have identified the top 5 expensive SQLs  by response time and throughput then by tuning 4 out of 5 those SQLs solves 80% of the bottleneck so knowing what to optimize immediately by priority is very important than troubleshooting with no evidence. In this post we have explained how to use MariaDB slow query log to troubleshoot performance outage:

Enabling slow query log in MariaDB

By default slow query log is disabled in MariaDB for both performance and storage optimization. You can dynamically enable slow query log with SET GLOBAL:

SET GLOBAL slow_query_log=1;

You can set the same in server option group in an option file prior to starting up the server:

[mariadb]
...
slow_query_log

How to configure MariaDB slow query log to login slow queries by ” Response Time” ?

The time that defines a slow query can be configured by setting the long_query_time system variable.

Dynamically configuring long_query_time with SET GLOBAL:

SET GLOBAL long_query_time=1.0;

Configuring long_query_time in a server option group in an option file prior to starting up the server:

[mariadb]
...
log_output=FILE
slow_query_log
slow_query_log_file=slow-queries.log
long_query_time=1.0

Identify slow query log with a custom filename

By default, the slow query log is written to ${hostname}-slow.log in the datadir directory. But you can always change it to avoid possible confusion if you have several MariaDB instances.

Configuring slow query log file on my.cnf :

[mariadb]
...
slow_query_log
slow_query_log_file=mariadb-slow-mdb1.log

Configuring slow query log file dynamically with SET GLOBAL : 

SET GLOBAL slow_query_log_file='mariadb-slow-mdb1.log';

Note: 

  • Relative path for slow query log file in MariaDB is datadir directory
  • You can also configure absolute path for slow query log file in MariaDB
[mariadb]
...
slow_query_log
slow_query_log_file=/data3/slow-log/mariadb/mariadb-mdb1-slow.log

You can also set slow query log filename in MariaDB with log-basename option, which configures MariaDB to use a common prefix for all log files (e.g. slow query log, general query log, error log, binary logs, etc.). The slow query log filename will be built by adding -slow.log to this prefix. This option cannot be set dynamically. It can be set in a server option group in an option file prior to starting up the server. For example:

[mariadb]
...
log-basename=mariadb-mdb1
slow_query_log

P.S. The log-basename cannot be an absolute path. The log file name is relative to the datadir directory.

Configuring slow query log output destination in MariaDB

You can configure slow query log output destination in MariaDB, it can either be written to a file on disk, or it can be written to the slow_log table in the mysql database.

Writing slow query log to a file

You can set the slow query log to a file dynamically with SET GLOBAL option:

SET GLOBAL log_output='FILE';

You can set slow query log to a file in a server option group in an option file prior to starting up the server:

[mariadb]
...
log_output=FILE
slow_query_log
slow_query_log_file=slow-queries.log

Writing slow query log to a table 

You can set the slow query log to a table dynamically with SET GLOBAL option:

SET GLOBAL log_output='TABLE';

You can set slow query log to a table in a server option group in an option file prior to starting up the server:

[mariadb]
...
log_output=TABLE
slow_query_log

Querying MariaDB slow query log from mysql.slow_log table

SELECT * FROM mysql.slow_log\G
...
*************************** 2. row ***************************
    start_time: 2014-07-28 11:24:51.146181
     user_host: root[root] @ localhost []
    query_time: 00:00:37.002168
     lock_time: 00:00:00.000000
     rows_sent: 1
 rows_examined: 0
            db: mdbtest
last_insert_id: 0
     insert_id: 0
     server_id: 1
      sql_text: SELECT SLEEP(27)
     thread_id: 31

Disable slow query log for a session

In MariaDB 10.1 and later, a user can disable logging to the slow query log for a connection by setting the slow_query_log system variable to 0

SET SESSION slow_query_log=0;

P.S. Not always logging every statements to slow query log in MariaDB is required to troubleshoot performance so consider setting for leaner slow logs, In MariaDB 10.3.1 and later, it is possible to disable logging to the slow query log for specific types of statements by setting the log_slow_disabled_statements system variable. This option cannot be set dynamically. It can be set in a server option group in an option file prior to starting up the server.

[mariadb]
...
log_output=FILE
general_log
general_log_file=queries.log
log_slow_disabled_statements='admin,call,slave,sp'

Using MariaDB slow query log to identify queries that don’t use indexes

It’s quite obvious that READs on larger tables without indexes goes very expensive. So when you have a complex database architecture on MariaDB how do you find specific queries on tables taking a hit on performance due to missing indexes / not using indexes ? You can enable MariaDB system variable log_queries_not_using_indexes with slow query log enabled.

Enable log_queries_not_using_indexes dynamically with SET GLOBAL:

SET GLOBAL log_queries_not_using_indexes=ON;

Enable log_queries_not_using_indexes configuring server option group in an option file prior to starting up the server:

[mariadb]
...
log_output=FILE
slow_query_log
slow_query_log_file=slow-queries.log
long_query_time=1.0
log_queries_not_using_indexes=ON

Log queries that examine a minimum number of rows

You can configure slow query log to log queries that examine a minimum number of rows regardless of their execution time by setting the min_examined_row_limit system variable.

configure min_examined_row_limit dynamically with SET GLOBAL:

SET GLOBAL min_examined_row_limit=500000;

configure min_examined_row_limit with server option group in an option file prior to starting up the server:

[mariadb]
...
log_output=FILE
slow_query_log
slow_query_log_file=slow-queries.log
long_query_time=1.0
min_examined_row_limit=100000

Identifying slow administrative statements with slow query log

By default, the Slow Query Log only logs slow non-administrative statements. To log administrative statements, set the log_slow_admin_statements system variable.

Enable log_slow_admin_statements dynamically with SET GLOBAL:

SET GLOBAL log_slow_admin_statements=ON;

Enable log_slow_admin_statements with server option group in an option file prior to starting up the server:

[mariadb]
...
log_output=FILE
slow_query_log
slow_query_log_file=slow-queries.log
long_query_time=1.0
log_slow_admin_statements=ON

The slow query log considers following statements administrative:

  • ALTER TABLE
  • ANALYZE TABLE
  • CHECK TABLE
  • CREATE INDEX
  • DROP INDEX
  • OPTIMIZE TABLE
  • REPAIR TABLE.

Conclusion

MariaDB slow query log is very powerful system variable to troubleshoot performance bottleneck effectively. But over configuring is not always recommended as that causes extra load on the MariaDB server. If MariaDB slow query log is used conservatively with detailed understanding of related server options / system variables you can simplify MariaDB performance troubleshooting.

UA-155183614-1