"MySQL" High performance MySQL learning notes, chapter III, server performance profiling

Chapter III: Analysis of server performance

? This chapter will answer the following three questions:

? How to confirm that the server is in the best performing state

? Find out why a statement isn't performing fast enough

? Diagnostics are described by the user as "paused", "stacked", "stuck" for some intermittent troubleshooting

1. Introduction to Performance Optimization:

? For performance issues, 1000 DBAs have 1000 answers. such as, "QPS", "CPU Load", "extensibility" and the like.

Principle One: We define performance as the measure of time required to complete a task. That is, "performance is response time."

? Use tasks and time to measure performance, not resources. The purpose of the database is to execute the SQL statement, the "task" in the sentence is a query or SQL statement (SELECT UPDATE Delete, etc.), the performance of the database server is measured by the response time of the query, the unit is the time spent per query. Here we first assume that performance optimization is to reduce the response time as much as possible with a certain workload.

? CPU utilization is only a symptom, not a good measurable goal.

? The increase in throughput can be seen as a byproduct of performance optimizations that allow the server to execute more queries per second. Because the query execution takes less time per second. (Throughput is the inverse of performance: number of queries per unit of time, QPS,QPM, etc.)

Principle two: Unable to measure can not be effectively optimized. The first step should be to measure where the time is spent.

? The time required to complete a task can be divided into two parts: execution time and wait time.

? If you want to optimize the execution time of a task, the best way is to measure the time spent by locating different subtasks, then optimize the removal of some subtasks, reduce the frequency of child tasks, or improve the execution efficiency of subtasks.

? If you want to optimize the wait time for a task, it is relatively complex, and the wait may be caused by other system indirect effects.

1.1. Optimize by profiling.

? Profiling (Profiling) is a two-step process: Measuring the time spent on a task, then counting and sorting the results, and telling the important tasks to go ahead.

? The Profiling report lists all the task lists. Each row records a task, including the task name, the execution time of the task, the time spent on the task, the average time of the task, and the percentage of time that the task was executed.

? The execution time-based analysis studies what tasks take the longest time to execute.

? Wait-based analysis is the longest time a task is judged to be blocked at what stage.

? In fact, when analysis based on execution time finds that a task takes time to spend too much time, it should be analyzed in depth and may find that some "execution time" is actually waiting.

1.2. Understanding Performance Profiling

? Although profiling outputs rankings, totals, and averages, there is still a lot of important information missing.

? Queries that are optimized: Some queries that account for only a small percentage of the total response time are not worth optimizing. If you spend 1000 of dollars to optimize a task, the revenue of a single business does not increase any more, then it can be said to be wasted. If the cost of optimization is greater than the benefit, you should stop optimizing.

? Exception condition: Some tasks need to be optimized even if they do not appear in front of the profiling output. For example, some tasks are executed infrequently, and each execution is very slow, seriously impacting the user experience.

? Hidden details: Profiling could not show all of the response time of the Von Department, only believe that the average is very dangerous. Just as the average body temperature of all the patients in the hospital is meaningless.

2. Performance profiling of the application system

? In fact, profiling an application is generally easier than dissecting a database server and has a higher rate of return. It is recommended that you perform a top-down performance analysis of the system so that you can track the entire process from user initiated to server response, although performance issues are mostly related to the database, but there are many problems with the application.

# 应该尽可能地测量一切可以测量的地方，并且接受这些测量带来的额外开销。# Oracle 的性能优化大师Tom Kyte 曾被问到Oracle中的测量点开销，他的回答是，测量点至少为性能优化共享10%# 大多数应用并不需要每天都运行详尽的性能测量，所以实际上贡献至少超过10%

3. Anatomy of MySQL Query 3.1 profiling server load

? Each new version of MySQL adds more measurable points. But if you just need to dissect and find the expensive queries, the slow query log should be able to meet our needs. All queries can be captured by setting "Long_query_time" to zero, and the response time of the query can be microsecond. In the current version, slow log is the most cost-effective tool to measure query time with the highest accuracy. If the slow query log is turned on for a long time, it is mainly used with the Logrotate tool (

）。 The Percona branch of MySQL records more valuable information than the official Community version. such as query plan, lock, I/O activity, etc. In general, slow logging is a lightweight and comprehensive profiling tool.

? You can use Pt-query-digest to parse slow query logs, such as:

Pt-query-digest slow.log >slow_log_analyze.log/data/mysql/3109/slow.log:53% 00:25 remain/data/mysql/3109/slow . log:98% 00:00 remaincat slow_log_analyze.log# 75.3s user time, 2s system time, 41.28M RSS, 235.76M vsz# current date:s Un Feb 15:43:11 2018# hostname:mysql-cent7-ip001109# Files:/data/mysql/3109/slow.log# overall:445.27k Total, Uniq UE, 0.03 QPS, 0.04x concurrency _________# time range:2017-09-28t16:00:25 to 2018-02-25t07:27:18# Attribute Tota L min Max avg 95% stddev median# ============ ======= ======= ======= ======= ======= ======= ======     =# Exec time 461284s 100ms 150s 1s 3s 1s 740ms# Lock time 1154s 0 10s 3MS 57us 83ms 21us# rows sent 426.70M 0 9.54M 1004.84 97.36 76.26k 0.99# Rows examine 46   5.04M 0 9.54M 1.07k 299.03 76.26k 0.99# Query size 4.55G 6 1022.79k 10.71k 76.28 73.23k 36.69# profile# Rank Query ID Response time Calls r/call v/m item# = ================== ================= ====== ======= = = = = = =========# 1 0x558caef5f387e929 238431.3966 51.7% 294383 0.8099 0.62 SELECT sbtest?# 2 0x84d1dee77fa8d4c3 5363 8.8398 11.6% 33446 1.6037 1.14 Select sbtest?# 3 0x3821ae1f716d5205 53362.1845 11.6% 33504 1.5927 1.11 SELECT SB test?# 4 0x737f39f04b198ef6 53244.4816 11.5% 33378 1.5952 1.14 SELECT sbtest?# 5 0X6EEB1BFDCCF4EBCD 53036.2877 11.5% 33539 1.5813 1.10 Select sbtest?# 6 0x67a347a2812914df 2619.2344 0.6% $13.0962 67.98 SELECT TPCC?.    order_line# 7 0x28fc5b5d583e2da6 2377.9580 0.5% 215 11.0603 11.53 SHOW GLOBAL status# 0xe730a9f41a4ab139 259.9002 0.1% 355 0.7321 0.42 SHOW INNODB status# one 0x88901a51719cb50b 131.1035 0.0% all 3.3616 21.74 SEL ECT information_schema.tables# 0x16f46891a99f2c89 127.1865 0.0%, 1.4453 1.15 SELECT Performance_schema.ev   ents_statements_history#0x153f1ce7d660ae82 79.2867 0.0% 1.7236 1.47 SELECT information_schema.processlist# MISC 0xMISC 3976.0946 0.9% 16077 0.2473 0.0 <47 items># Query 1:0.17 QPS, 0.14x concurrency, ID 0x558caef5f387e929 at BYTE 4877477857# This item was included in the because it matches--limit.# scores:v/m = 0.62# time range:2018-02- 03t11:26:24 to 2018-02-23t13:03:23# Attribute pct Total min max avg 95% StdDev median:

?

? In addition to the slow log, the Pt-query-digest tool in the Percona Toolkit Toolkit can be profiled, and the output of show processlist can be analyzed continuously using the--processlist parameter. But the output of "show processlist" is changing rapidly. This is not highly recommended, even though there is still a lot of useful information missing from the collection once per second. Another way is to use the--TYPE=TCPDUMP option to analyze network packet capture data.

3.2 Profiling a single query using show profile

? Disabled by default, but it is a session-level parameter. set profiling=1, and then sends all the statements on the server, it will measure the time it takes and some other data related to the state change of the query execution.

? When a query is submitted to the server, the tool logs the profiling information to a temporary table and assigns the query an integer identifier starting at 1.

? Such as:

Set Profiling=1select * from T_order;select * from T_productshow profiles+----------+------------+-------------------- -----+| query_id | Duration | Query |+----------+------------+-------------------------+| 1 | 9.75e-05 | SHOW WARNINGS | | 2 | 0.00052075 | SELECT * FROM T_order | | 3 | 0.000511 | SELECT * FROM T_product | | 4 | 5.3e-05 | SHOW WARNINGS |+----------+------------+-------------------------+show profile for query--------------------- -+----------+| Status | Duration |+----------------------+----------+| Starting | 0.000065 | | Checking Permissions | 0.000009 | | Opening Tables | 0.000142 | | init | 0.000022 | | System Lock | 0.000010 | | Optimizing | 0.000008 | | Statistics | 0.000013 | | Preparing | 0.000012 | | Executing | 0.000007 | | Sending Data | 0.000154 | | End | 0.000010 | | QueRy End | 0.000011 | | Closing Tables | 0.000010 | | Freeing items | 0.000016 | | Cleaning Up | 0.000012 |+----------------------+----------+

The

? Profiling report gives each step of the query execution and the time it takes to see if the result is difficult to determine quickly which step takes the most time. The output is sorted in order of execution, not by the time spent. Here's how to query the profiling report using Information_shcema:

Set @query_id =1select state,sum (DURATION) as Total_r, ROUND (100*sum (DURATION)/(SELECT SUM (DURATION) from Informati On_schema. PROFILING WHERE query_id = @query_id), 2) as Pct_r,count (*) as Calls,sum (DURATION)/count (*) as "R/call" from INFORM Ation_schema. Profilingwhere [Email protected]_idgroup by Stateorder by Total_r desc# output is as follows: +----------------------+----------+ -------+-------+--------------+| State | Total_r | Pct_r | Calls | R/call |+----------------------+----------+-------+-------+--------------+| Starting | 0.000072 | 20.45 | 1 | 0.0000720000 | | Sending Data | 0.000047 | 13.35 | 1 | 0.0000470000 | | init | 0.000030 | 8.52 | 1 | 0.0000300000 | | Opening Tables | 0.000026 | 7.39 | 1 | 0.0000260000 | | Checking Permissions | 0.000025 | 7.10 | 1 | 0.0000250000 | | Cleaning Up | 0.000023 | 6.53 | 1 | 0.0000230000 | | System Lock | 0.000019 | 5.40 | 1 | 0.0000190000 | | Statistics | 0.000018 | 5.11 | 1 | 0.0000180000 | | Preparing | 0.000016 | 4.55 | 1 | 0.0000160000 | | Optimizing | 0.000015 | 4.26 | 1 | 0.0000150000 | | Freeing items | 0.000014 | 3.98 | 1 | 0.0000140000 | | Query End | 0.000013 | 3.69 | 1 | 0.0000130000 | | Closing Tables | 0.000012 | 3.41 | 1 | 0.0000120000 | | Executing | 0.000011 | 3.13 | 1 | 0.0000110000 | | End | 0.000011 | 3.13 | 1 | 0.0000110000 |+----------------------+----------+-------+-------+--------------+# With this result it is easy to see that the query time is long mainly because it takes a lot of time to sending data # This state is represented by a very large number of reasons, possibly a variety of server activities, including searching for matching Row records at the time of association, which is hard to say to optimize the amount of time saved. #若Sorting result takes more time, you might consider increasing the sort buffer size

Use Show status

? The MySQL show status command returns a number of counters, both server-level global technology and session-level counters based on a connection. The official MySQL manual provides a detailed description of whether all variables are global or session-level.

? show statusMost of the results are a counter that shows how frequently certain activities, such as read indexes, can be, but not how much time is consumed. show statusonly one of the results of Innodb_row_lock_time refers to the operation time, and this is global, or it is not possible to measure session-level work. The most useful counters include handle counters, temporary files, and table counters. Reset the session-level counter to 0, then query the previously mentioned view and check the results of the counter:

Flush Status;select * from sakila.nicer_but_slower_film_list;#...............show status where Variable_name like " handler% "or variable_name like" created% "+----------------------------+-------+| variable_name | Value |+----------------------------+-------+| Created_tmp_disk_tables | 2 | | Created_tmp_files | 2 | | Created_tmp_tables | 3 | | Handler_commit | 1 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_external_lock | 10 | | Handler_mrr_init | 0 | | Handler_prepare | 0 | | Handler_read_first | 3 | | Handler_read_key | 12942 | | Handler_read_last | 0 | | Handler_read_next | 6462 | | Handler_read_prev | 0 | | Handler_read_rnd | 5462 | | Handler_read_rnd_next | 6478 | | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | HandLer_update | 0 | | Handler_write | 0 |+----------------------------+-------+

From the results you can see that the query uses three temporary tables, two of which are disk staging tables, and there are many read operations (Handler_read_rnd_next) that are not indexed. Suppose we do not know the specific definition of this view, only from the result to speculate that the query may have done a multi-table association query, and there is no appropriate index, perhaps one of the sub-query created a temporary table, and then make a union query with other tables, and the temporary table used to hold the results of the subquery is not indexed.

? Note, however, that using show status itself creates a temporary table and also accesses the temporary table through a handle operation, which also affects the show status corresponding number in the result, and the different versions may behave differently, comparing the results of the execution plan of the previously show profiles obtained query. At least the counter for the temp table is 2 extra.
? explainthe query execution plan that you see can also get the show status same information as most, but the result of the estimate is the explain show status actual measurement. For example, explain you cannot tell if a temporary table is a disk table.

"MySQL" High performance MySQL learning notes, chapter III, server performance profiling