Shulou(Shulou.com)05/31 Report--

This article will explain in detail the example analysis of online problems and optimization of slow logs in MySQL. The editor thinks it is very practical, so I share it with you for reference. I hope you can get something after reading this article.

MySQL slow log (slow log) is a kind of information that MySQL DBA and other developers, operators and maintenance personnel need to pay attention to frequently. Slow logs can be used to find out SQL statements such as long execution time or missing indexes, which provides a basis for system tuning.

Combined with an online case, this article will analyze how to correctly set MySQL slow log parameters and use slow log feature, and introduce the enhancement of MySQL slow log feature by off-net easy Cloud RDS.

MySQL parameter group function

NetEase Cloud RDS instance provides parameter group management feature. You can view most of the commonly used MySQL system parameters through the parameter management interface, and users can know the current running values and recommended values:

Users can also modify the listed parameters through the parameter management page, click the "modify parameters" button to set them online, and click "Save changes" to complete the parameter modification of the MySQL master-slave node:

Looking at the parameter management interface, it is not difficult to find that there are many parameters related to slow query, so how do these parameters work, how do they relate to each other, and what conditions do SQL statements meet before they are recorded in the slow log? Only by understanding these can we make better use of slow logs for system tuning and problem location.

Next, based on this online case, we introduce how to correctly configure slow log parameters:

Some users reported that several instances of RDS version 5.7 they used were abnormal in the slow log. The SQL statement was executed for more than one minute, but it was not recorded in the slow log. SQL statements for reproduction are also provided.

The slow log parameter is configured correctly.

First, we need to confirm whether slow logging is enabled for this instance. By default, MySQL slow logging is turned off. The slow log switch parameter is slow_query_log, which can be explicitly specified in the mysqld startup command line or configuration file. If you specify slow_query_log=1 or no value, slow log is enabled, and a value of 0 means off. The user can turn it on and off dynamically at run time.

The slow log feature is enabled by default for NetEase Cloud RDS instance. We confirm that the user has not disabled the slow log switch of the instance.

Next, you need to confirm the slow log location, and MySQL uses the log_output parameter to specify whether the slow log is saved as a file (FILE) or as a table (TABLE). It is important to emphasize that specifying only log_output and setting slow_query_log to 0 does not record slow logs, which means that slow_query_log is the slow log switch. If slow logs are recorded as files, you can specify the file name through slow_query_log_file. If the user does not explicitly specify slow_query_log_file, MySQL initializes it to host_name-slow.log,host_name, which is the hostname of running mysqld, and the slow log file is located in the MySQL data directory by default.

NetEase Cloud RDS instance does not allow users to modify the log file path, but you can configure the log_output parameter. Through query, confirm that the instance records slow logs as files, and check the log files to confirm that there is no SQL statement described by users.

Because the user provided a recurrence statement, we executed its SQL statement, and it took more than a minute to return. Through the explain command, we found that it did not leave the index, scanned a large number of records, and checked the slow log again and still did not record the SQL statement.

MySQL records SQL statements that meet the execution time of more than long_query_time seconds and scan records that exceed min_examined_row_limit rows.

The minimum and default values of the long_query_time parameter are 1 and 10s, respectively, which can be accurate to microseconds (ms). If you choose to record the slow log to a file, the recording time is accurate to microseconds, and if recorded in the slow log table (mysql.slow_log), it is only accurate to seconds, and the microsecond part is ignored.

NetEase Cloud RDS instance allows users to set these two parameter values, so is it because the user has adjusted the above two thresholds that the recording conditions cannot be met? further query is not the cause of the problem.

We notice that MySQL also has a parameter called log_queries_not_using_indexes that controls whether SQL queries that are not indexed are recorded, as follows:

Focus on the content indicated by the arrow. If the query does not leave the index or the index is invalid, and the relevant parameter is enabled, then warn_no_index is set to true, and if the number of scanned records exceeds the threshold, it will also be recorded like a slow query. Is this parameter not enabled? The result is still negative.

The cause of the problem

Since there may be more SQL statements not indexed in the database instance, if log_queries_not_using_indexes is enabled, there is a risk that the log file or table capacity will grow too fast. You can limit the number of SQL statements written to slow logs without indexing per minute by setting log_throttle_queries_not_using_indexes. This parameter defaults to 0, which means that the number of SQL statements written is not enabled, that is, the number of SQL statements written is not controlled.

When enabled, the system opens a window of 60s after the execution of the first query without an index, in which only a maximum of log_throttle_queries_not_using_indexes SQL statements are recorded. The excess is suppressed, and at the end of the time window, the number of suppressed slow queries in the window and the total time spent on these slow queries are printed. The next statistical time window is not created immediately, but opens after the execution of the next query that does not index.

Corresponding to this online problem, log_throttle_queries_not_using_indexes is set to 10, and the following is periodically printed in the log file:

Indeed in line with the phenomenon described above, users' slow logs should be suppressed and summarized into 359. We tried to set log_throttle_queries_not_using_indexes to 0, and then executed the corresponding SQL statement, and sure enough, the corresponding SQL statement was recorded in the log file.

This online problem seems to have been located, that is, the system generates too many slow logs without indexing, and the log_throttle_queries_not_using_indexes set is too small to record users' slow logs without indexing properly. However, there is still one doubt that has not been solved, that is, when log_throttle_queries_not_using_indexes is 0, no more than 10 slow logs are printed per minute, let alone 359 prompted by throttle. Then the SQL statement provided by the user should be recorded in the slow log when it is set to 10. Why is it not recorded? In fact, if you take a closer look at the code logic of MySQL logs that are not indexed, you can find the answer:

The figure above is the main logic for recording slow logs. Whether or not to record logs is controlled by the function log_slow_applicable, which has been analyzed previously. Let's take a closer look at other relevant contents of the function, as shown in the red box below:

Suppress_logging is a decisive variable, and the SQL statement can only be recorded if it is false. The result is related to log_throttle_queries_not_using_indexes. Let's take a closer look at the related implementation of log_throttle_qni.log, as shown below:

Eligible means that when the total number of statements not indexed by the warn_no_index,inc_log_count () function exceeds log_throttle_queries_not_using_indexes in 1 minute, the return value is true. Only warn_no_index and inc_log_count () return values of true,suppress_current are true, and suppress_current is suppress_logging.

Through the analysis of the above two screenshots, we can answer the previous doubts:

Log_throttle_queries_not_using_indexes counts all statements that do not walk through the index, some of which are not recorded in the slow log because they do not meet the constraint on the number of scanned records, which is why there are no 10 records in the slow log file when the value is 10. Because 8 of the 10 SQL statements were not recorded due to the small number of scan records.

This also explains the number 359 in the figure above, which is the total number of SQL statements that do not index in this time window. Therefore, log_throttle_queries_not_using_indexes is a very critical parameter, and if it is not properly set, it will not be able to record the slow query without moving the index, resulting in the failure of the slow log function. Therefore, first of all, users need to avoid a large number of SQL statements that do not index as much as possible, which can be optimized through the RDS health check function. Thirdly, if there is the above hint in the slow log, you should increase the value of log_throttle_queries_not_using_indexes in order to further analyze the problem.

InnoSQL slow Log feature enhanced

Some RDS instance users asked us why the execution time of my SQL statement did not exceed the set long_query_time and went through the index, but it was still recorded in the slow log. Is it out of Bug? In fact, this is not Bug, but because the version of InnoSQL (open source branch of MySQL maintained by NetEase) used by NetEase Cloud RDS optimizes the slow log. In addition to examining the execution time of the SQL statement, it is also concerned about the number of disk pages (Disk Page) required for the query, because too many pages are required, which may also have a greater impact on the system load. In order to quantify statistics, we collect the total number of pages that need to be read by SQL queries and the actual number of IO in these pages, which are recorded as logical_reads and physical_reads, respectively. The former includes page requests that hit InnoDB Buffer Pool and miss pages that require IO.

This function is provided to users by introducing two parameters, slow_query_type and long_query_io. "1" enables slow logging based on execution time, "2" means slow logging is based on the total number of pages searched, and "3" is a collection of "1" and "2". So in InnoSQL, SQL queries can be recorded in slow logs only if the execution time is long enough or the total number of pages required is enough. The code implementation snippet is as follows:

The threshold of the number of pages is measured by the long_query_io parameter, and the user can set it dynamically. If the total number of pages m_logical_reads exceeds this value, it will be recorded even if the execution time does not exceed the limit. Accordingly, new fields have been added to the slow log table structure and slow log file output of the RDS instance.

The above figure shows the slow_log table structure of InnoSQL version, in which logical_reads and physical_reads add fields to InnoSQL. Similarly, two fields are added to the output of the slow log file, as follows:

In addition to the details described above, the MySQL slow log module has the following features to pay attention to:

○ does slow log statistics and the time recorded in the slow log does not include the time it takes to acquire a lock before the SQL statement starts execution.

○ MySQL writes SQL statements to the slow log only after they have been executed and the locks they hold have been released, so the recording order of SQL statements in the slow log does not accurately reflect the actual execution order of these SQL statements.

○ each slow log contains a timestamp. If it is written to a file, the log_timestamps parameter is used to convert the slow log timestamp to the time of the specified time zone. However, this parameter does not work for slow logs in the mysql.slow_log table

○ can enable the slow log function of MySQL slave library by setting log_slow_slave_statements.

○ ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE and other table management operations can also be recorded in slow logs and can be enabled through the log_slow_admin_statements option.

This is the end of this article on "example Analysis of slow Log online problems and Optimization in MySQL". I hope the above content can be helpful to you, so that you can learn more knowledge. if you think the article is good, please share it for more people to see.

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.