Chapter 3. Optimizing Queries

This chapter explains the basics of how to improve the performance of the queries that are executed on a MariaDB server. First, the important tools required to find slow queries are described. Once we find such queries, we will need to find out why they are slow. Thus, a description of how MariaDB uses indexes follows. Then, we will discuss the EXPLAIN command, which shows how MariaDB executes a query. Contextually, we will also discuss the main execution strategy.

The topics covered in this chapter are:

  • The slow query log
  • The pt-query-digest command from Percona Toolkit
  • Indexes
  • Table statistics
  • The EXPLAIN statement
  • Important MariaDB optimizations

The slow query log

The slow query log (or simply slow log) stores SQL statements that take too long to execute. To enable it, the slow_query_log variable or the --slow-query-log startup option can be set to 1. To explicitly disable the log, the --slow-query-log startup option must be set to 0. Without passing any arguments, the --slow-query-log startup option enables this log. As the slow_query_log variable is dynamic, the slow query log can be enabled or disabled at runtime.

The default filename of the slow query log is the server's hostname followed by the -slow.log suffix.

Just like the general query log, the slow query log can be a file, table, or both. The log output server variable can be used to specify if the log is a table or file. The allowed values to be set are FILE, TABLE, and NONE (which disables both the slow query log and the general query log). A combination of these values (separated by a comma) is allowed. The NONE value overrides other values.

For example, if the hostname is hal, hal-slow.log will be the default name for the slow query log. A different name can be specified using the slow_query_log_file server variable, or using the --slow-query-file option. In a replication environment, using the same file name for all logs is a good practice, because it may be necessary to execute the same scripts on all the servers.

If the slow query log is written into a table, the table is called slow_log and it can be found in the mysql database. In The general query log section in Chapter 2, Debugging, we have described in detail what can or cannot be done with the general_log table. These sections also apply to the slow_log table. As explained previously, in the slow query log we can find the queries that were executed too slowly. But what does this depend on? This depends on our workload, of course. For this reason, the rules that determine what queries are written in the slow query log depend on some of the server's system variables.

First, we may want to log queries that do not use indexes at all. To do this, we can set the log_queries_not_using_indexes variable (or the --log-queries-not-using-indexes startup option) to 1, as its default value is 0. This variable is dynamic, but only exists at the global level.

Even if a query uses indexes, we may want to log it if it exceeds a time-out. This can be done via the long_query_time variable, or the --long_query_time startup option. If the value is 0, there is no time-out and the slow queries are not logged. This value is expressed in seconds. Decimal values are allowed with a precision of microseconds (up to six decimal digits); however, for table-based logs, the decimal part is ignored. The query execution time is counted from the time the thread acquires the necessary locks. This means that, if a query takes too much time just because it is blocked by a slow query, it is not logged. This variable is dynamic and exists at both the global and session levels. This allows connections that execute more complex queries to set a greater time-out.

A query can also have other problems that we may want to log. The classes of problems that must be logged are listed in the log_slow_filter variable, separated by a comma. The allowed values are described as follows:

  • full_scan: This value means that the query has performed a full table scan (same as log_queries_not_using_indexes)
  • full_join: This value means that the query performed a join operation, which does not use indexes
  • filesort: This value means that the query performed a sorting operation, which requires an internal, temporary in-memory table
  • filesort_on_disk: This value means that the query performed a sorting operation, which requires a temporary on-disk file
  • tmp_table: This value means that the query created an implicit temporary table
  • tmp_table_on_disk: This value means that the query created an implicit temporary table written on the disk
  • query_cache_miss: This value means that a query search was performed but the query was not found in the query cache

By default, the log_slow_filter variable contains all these values. It is dynamic and exists at both the session and global levels.

Even if a query matches the criteria defined by the log_queries_not_using_indexes and long_query_time system variables, the min_examined_row_limit variable can prevent it from being logged. Queries that examined fewer than the described number of rows are never written into the slow query log. A value of 0 allows all queries to be logged. The maximum value is platform-dependent, but is always very high. This variable is dynamic and exists at both the global and session levels. This setting is usually useful because, if a query examines only a few rows, it would not benefit from the use of an index in any case (and the optimizer takes this into account). If the query exceeds the time-out, it is still possible that it does not examine many rows, for example, if the query requires complex ordering or grouping operations, or if it calls slow functions (including stored functions).

Sometimes, logging all the queries that do not use indexes can be a heavy task for a busy server. For this reason, it is possible to limit the logging of such queries using the log_throttle_queries_not_using_indexes system variable. If the value of the system variable is 0 (the default), there is no limit. If its value is higher than 0, it will determine the number of queries that do not use indexes and that can be logged in a minute. When this limit is reached, further queries will not be logged. A minute after the last query that does not use indexes is logged, a summary of the suppressed queries is written into the log.

By default, administrative queries (such as CHECK TABLE or ANALYZE TABLE) are not written to the slow query log. To change this behavior, the log_slow_admin_statements variable can be set to 1. This variable is dynamic, but only exists at the global level.

In a replication environment, usually, slaves do not log replicated slow queries, because such queries can be found in the master's slow query log. Normally, a slow query is logged only if it was directly sent to the slave. However, this behavior can be changed by setting the log_slow_slave_statements variable to 1. This variable is dynamic, but only exists at the global level. If the workload on the master is heavy and the workload on the slaves is light, using the slow query log on a slave instead of the master could be an optimization. Of course, it will still be necessary to explicitly enable the slow query on a slave and disable it on the master.

To produce a less verbose slow query logfile, the --log-short-format startup option can be used. In the configuration files, it can be specified as log-short-format. This option also affects the binary log.

The counterpart of the --log-short-format startup option is log_slow_verbosity, which can be used to add information to the slow query logfile. It is a comma-separated list of values, where each value adds some information. The allowed values are described as follows:

  • microtime: This value means that the variable uses microtime precision
  • query_plan: This value means that the variable logs information about the query execution plan
  • innodb: This value means that the variable logs the InnoDB statistics
  • profiling: This value means that the variable enables query profiling
  • profiling_use_getrusage: This value means that the variable logs the results of the getrusage function
  • explain: This value means that the variable prints the output of the EXPLAIN statement (discussed in the next section)

To enable profiling and profiling_use_getrusage, it is necessary to use XtraDB. The default value is 'query_plan'. Both log_short_format and log_slow_verbosity affect the file-based slow query log but not the table.

To summarize, the following variables determine the queries that should be written in the slow query log:

  • log_queries_not_using_indexes
  • log_throttle_queries_not_using_indexes
  • long_query_time
  • log_slow_filter

The following variables can filter out the variables that match the previous criteria:

  • min_examined_row_limit
  • log_slow_admin_statements

The following variables determine what information is logged (and the overhead caused by the slow query log):

  • log-short-format
  • log_slow_verbosity

Queries that examine tables with no rows or a single row are always excluded from the slow query log.

The file format of the slow query log

When the server starts, lines similar to the following command are written into the slow query log:

/usr/local/mysql/bin/mysqld, Version: 10.0.7-MariaDB-log (MariaDB Server). started with:
Tcp port: 0  Unix socket: (null)
Time                 Id Command    Argument.

Now, let's see an entry made into a slow query log. The following example shows how a query is written in the slow query log, with a default configuration:

# Time: 140116 11:19:05
# User@Host: root[root] @ localhost []
# Thread_id: 4  Schema: test  QC_hit: No
# Query_time: 0.059419  Lock_time: 0.000340  Rows_sent: 1  Rows_examined: 66620
SET timestamp=1389867545;
SELECT COUNT(*) FROM t
 WHERE a > b;

The commented lines provide general information about the cost of the query, discussed as follows:

  • Time: This is the date and time the query execution was started. It follows the same format used by the logs, as we have already discussed, with a human-readable time.
  • User@Host: This is the account that executed the query.
  • Thread_id: This is the ID of the connection, and is the same value that is displayed in the information_schema and performance_schema tables, or returned by the CONNECTION_ID() function. On the same line, we also see Schema, which is the default database that was selected (as a result of the USE statement). It is written even if the default database is not used by the query.
  • QC_hit: This informs us if the query is found in the query cache.

The last commented line is the most important. The Query_time value is the execution time in seconds. If the slow query log is written to a file, the Query_time value is a floating point number with a microsecond precision. If the log is written to a table, this value is an integer. The Lock_time value is the amount of time that the query had to wait before relevant locks were released by other sessions. If a statement takes a lot of time because of long-running queries executed in concurrent sessions, we probably will not need to optimize it. The Rows_sent value is the quantity of data sent by the server to the client, that is, the number of rows in the result set. The Rows_examined value is the number of lines read by the query. The server must examine the number of rows before deciding if they must be included in the result set or used to join tables. If the used indexes are not selective enough, or no indexes are used, this value is higher than necessary. This is usually the most expensive part of the query cost.

Then, we find the statements to be executed to repeat the procedure. First, we can find a SET timestamp statement, which is sometimes necessary (for example, if functions such as CURRENT_TIMESTAMP() are used in a WHERE clause). A USE statement can only be found for the first slow query issued by the connection. Of course, despite these lines, it may be impossible to repeat the procedure with a copy and paste operation; for example, if a query involves temporary tables or user-defined variables, or it may be nondeterministic. Finally, we find the slow query, as it was received from the client.

If the log-short-format startup option is active, a much shorter format is used by the slow query log, shown as follows:

# Thread_id: 5  Schema: test  QC_hit: No
# Query_time: 0.230296  Lock_time: 0.000302  Rows_sent: 1  Rows_examined: 263337
SET timestamp=1389869887;
SELECT COUNT(*) FROM t WHERE a > b;

These lines are a subset of the former example; thus, they do not need any further explanation.

Depending on the log_slow_verbosity variable, more information can be added to the slow query log. The output of EXPLAIN is the most useful information we may need to find out the reason why a query is slow, but we usually prefer to execute this statement manually.

The slow_log table

The slow_log table contains information that is very similar, but not identical, to the information contained in a default slow query logfile. This table contains the following columns:

  • The start_time column matches the Time column
  • The user_host column matches the User@Host column
  • The query_time column matches the Query_time column
  • The lock_time column matches the Lock_time column
  • The rows_sent column matches the Rows_sent column
  • The rows_examined column matches the Rows_examined column
  • The db column matches the Schema column
  • The last_insert_id and insert_id, columns that contain information about the AUTO_INCREMENT columns in the future
  • The server_id column gives the server's server_id variable, which is always set in a replication environment
  • The sql_text column, which is the original query
  • The thread_id column matches the Thread_id column
..................Content has been hidden....................

You can't read the all page of ebook, please click here login for view all page.
Reset
3.21.100.62