MySQL效能分析之Profile

阿新 • • 發佈：2018-11-19

在MySQL資料庫中，可以通過配置profiling引數來啟用SQL剖析。該引數開啟後，後續執行的SQL語句都將記錄其資源開銷，諸如IO，上下文切換，CPU，Memory等，根據這些開銷分析當前SQL瓶頸從而進行優化與調整。

MySQL版本

mysql> show variables like 'version';
+---------------+--------+
| Variable_name | Value  |
+---------------+--------+
| version       | 5.7.22 |
+---------------+--------+ 

1 row in set (0.00 sec)

profile引數

mysql> show variables like '%profil%';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | ON    |
| profiling_history_size | 15    |
+------------------------+-------+ 

3 rows in set (0.01 sec)

have_profiling
have_profiling 是System Var 全域性引數，不支援動態修改。如果該引數為YES，表示支援profiling功能，如果為NO表示不支援profiling功能。如果支援profiling功能，profiling引數可以用來控制該功能是否啟用。(have_profiling引數在5.6.8中將被棄用，並且可能在以後的版本中可能被刪除)

profiling
profiling 是System Var 全域性引數，支援動態修改。如果設定為0或者OFF(該引數預設值即為OFF)，sql的profiling功能被禁用。如果設定為1或者ON，這之後執行語句會被profiling(除了show profiles, show profile)。

profiling_history_size
profiling_history_size是Cmd-Line,Option File,System Var 全域性引數，支援動態修改。該引數控制儲存的被profiling的sql數量,預設值為15。如果該值設為0則禁用profiling功能。

profile幫助

mysql> help profile;
Name: 'SHOW PROFILE'
Description:
Syntax:
SHOW PROFILE [type [, type] ... ]
    [FOR QUERY n]
    [LIMIT row_count [OFFSET offset]]

type:
    ALL
  | BLOCK IO
  | CONTEXT SWITCHES
  | CPU
  | IPC
  | MEMORY
  | PAGE FAULTS
  | SOURCE
  | SWAPS

The SHOW PROFILE and SHOW PROFILES statements display profiling information that indicates resource 
usage for statements executed during the course of the current session.

*Note*:

These statements are deprecated and will be removed in a future MySQL release. Use the Performance 
Schema instead; see http://dev.mysql.com/doc/refman/5.7/en/performance-schema-query-profiling.html.

Profiling is controlled by the profiling session variable, which has a default value of 0 (OFF). 
Profiling is enabled by setting profiling to 1 or ON:

mysql> SET profiling = 1;

SHOW PROFILES displays a list of the most recent statements sent to the server. 
The size of the list is controlled by the profiling_history_size session variable, which has a default value of 15. 
The maximum value is 100. Setting the value to 0 has the practical effect of disabling profiling.

All statements are profiled except SHOW PROFILE and SHOW PROFILES, so you will find neither of those statements in the profile list. 
Malformed statements are profiled. For example, SHOW PROFILING is an illegal statement, 
and a syntax error occurs if you try to execute it, but it will show up in the profiling list.

SHOW PROFILE displays detailed information about a single statement. Without the FOR QUERY n clause, 
the output pertains to the most recently executed statement. If FOR QUERY n is included, SHOW PROFILE displays information for statement n. 
The values of n correspond to the Query_ID values displayed by SHOW PROFILES.

The LIMIT row_count clause may be given to limit the output to row_count rows. 
If LIMIT is given, OFFSET offset may be added to begin the output offset rows into the full set of rows.

By default, SHOW PROFILE displays Status and Duration columns. 
The Status values are like the State values displayed by SHOW PROCESSLIST, 
although there might be some minor differences in interpretion for the two statements for some status values 
(see http://dev.mysql.com/doc/refman/5.7/en/thread-information.html).

Optional type values may be specified to display specific additional
types of information:
o ALL displays all information
o BLOCK IO displays counts for block input and output operations
o CONTEXT SWITCHES displays counts for voluntary and involuntary
  context switches
o CPU displays user and system CPU usage times
o IPC displays counts for messages sent and received
o MEMORY is not currently implemented
o PAGE FAULTS displays counts for major and minor page faults
o SOURCE displays the names of functions from the source code, together with the name and line number of the file in which the function occurs
o SWAPS displays swap counts

Profiling is enabled per session. When a session ends, its profiling information is lost.

URL: http://dev.mysql.com/doc/refman/5.7/en/show-profile.html

Examples:
mysql> SELECT @@profiling;
+-------------+
| @@profiling |
+-------------+
|           0 |
+-------------+
1 row in set (0.00 sec)

mysql> SET profiling = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> DROP TABLE IF EXISTS t1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> CREATE TABLE T1 (id INT);
Query OK, 0 rows affected (0.01 sec)

mysql> SHOW PROFILES;
+----------+----------+--------------------------+
| Query_ID | Duration | Query                    |
+----------+----------+--------------------------+
|        0 | 0.000088 | SET PROFILING = 1        |
|        1 | 0.000136 | DROP TABLE IF EXISTS t1  |
|        2 | 0.011947 | CREATE TABLE t1 (id INT) |
+----------+----------+--------------------------+
3 rows in set (0.00 sec)

mysql> SHOW PROFILE;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| checking permissions | 0.000040 |
| creating table       | 0.000056 |
| After create         | 0.011363 |
| query end            | 0.000375 |
| freeing items        | 0.000089 |
| logging slow query   | 0.000019 |
| cleaning up          | 0.000005 |
+----------------------+----------+
7 rows in set (0.00 sec)

mysql> SHOW PROFILE FOR QUERY 1;
+--------------------+----------+
| Status             | Duration |
+--------------------+----------+
| query end          | 0.000107 |
| freeing items      | 0.000008 |
| logging slow query | 0.000015 |
| cleaning up        | 0.000006 |
+--------------------+----------+
4 rows in set (0.00 sec)

mysql> SHOW PROFILE CPU FOR QUERY 2;
+----------------------+----------+----------+------------+
| Status               | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| checking permissions | 0.000040 | 0.000038 |   0.000002 |
| creating table       | 0.000056 | 0.000028 |   0.000028 |
| After create         | 0.011363 | 0.000217 |   0.001571 |
| query end            | 0.000375 | 0.000013 |   0.000028 |
| freeing items        | 0.000089 | 0.000010 |   0.000014 |
| logging slow query   | 0.000019 | 0.000009 |   0.000010 |
| cleaning up          | 0.000005 | 0.000003 |   0.000002 |
+----------------------+----------+----------+------------+
7 rows in set (0.00 sec)

profile示例

mysql> set profiling=1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
 
mysql> select count(1) from store;
+----------+
| count(1) |
+----------+
|      193 |
+----------+
1 row in set (0.06 sec)
 
mysql> show profiles;
+----------+------------+----------------------------+
| Query_ID | Duration   | Query                      |
+----------+------------+----------------------------+
|        1 | 0.05912400 | select count(1) from store |
+----------+------------+----------------------------+
1 row in set, 1 warning (0.00 sec)
 
mysql> select count(1) from store_bak;
+----------+
| count(1) |
+----------+
|  3162113 |
+----------+
1 row in set (5.81 sec)
 
mysql> show profiles;
+----------+------------+--------------------------------+
| Query_ID | Duration   | Query                          |
+----------+------------+--------------------------------+
|        1 | 0.05912400 | select count(1) from store     |
|        2 | 5.82553775 | select count(1) from store_bak |
+----------+------------+--------------------------------+
2 rows in set, 1 warning (0.00 sec)

檢視資源的消耗情況，如io，cpu

mysql> show profile cpu,block io for query 2;
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000095 | 0.000000 |   0.000000 |            0 |             0 |
| checking permissions | 0.000011 | 0.000000 |   0.000000 |            0 |             0 |
| Opening tables       | 0.017916 | 0.001000 |   0.000000 |           32 |             0 |
| init                 | 0.000028 | 0.000000 |   0.000000 |            0 |             0 |
| System lock          | 0.000018 | 0.000000 |   0.000000 |            0 |             0 |
| optimizing           | 0.000010 | 0.000000 |   0.000000 |            0 |             0 |
| statistics           | 0.000021 | 0.000000 |   0.000000 |            0 |             0 |
| preparing            | 0.000020 | 0.000000 |   0.000000 |            0 |             0 |
| executing            | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |
| Sending data         | 5.794340 | 5.794119 |   0.000000 |            0 |             0 |
| end                  | 0.000025 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000014 | 0.000000 |   0.000000 |            0 |             0 |
| closing tables       | 0.000026 | 0.000000 |   0.000000 |            0 |             0 |
| freeing items        | 0.000045 | 0.000000 |   0.000000 |            0 |             0 |
| logging slow query   | 0.012937 | 0.001000 |   0.000000 |          264 |             8 |
| cleaning up          | 0.000028 | 0.000000 |   0.000000 |            0 |             0 |
+----------------------+----------+----------+------------+--------------+---------------+
16 rows in set, 13 warnings (0.00 sec)

通過INFORMATION_SCHEMA.PROFILING表來查詢語句消耗情況

mysql> select min(seq) seq,state,count(*) num_ops,  
    -> round(sum(duration),5) sum_dur, round(avg(duration),5) avg_dur,  
    -> round(sum(cpu_user),5) sum_cpu, round(avg(cpu_user),5) avg_cpu  
    -> from information_schema.profiling  
    -> where query_id = 21 
    -> group by state  
    -> order by seq;
+------+--------------------+----------+----------+---------+---------+---------+
| seq  | state              | num_ops | sum_dur  | avg_dur | sum_cpu | avg_cpu |
+------+--------------------+---------+----------+---------+---------+---------+
| 2375 | Sending data       |      47 | 20.98920 | 0.44658 | 0.00000 | 0.00000 |
| 2376 | executing          |      46 |  0.00126 | 0.00003 | 0.00000 | 0.00000 |
| 2468 | updating           |       1 |  0.00003 | 0.00003 | 0.00000 | 0.00000 |
| 2469 | end                |       1 |  0.00002 | 0.00002 | 0.00000 | 0.00000 |
| 2470 | query end          |       1 |  0.00094 | 0.00094 | 0.00000 | 0.00000 |
| 2471 | closing tables     |       1 |  0.00005 | 0.00005 | 0.00000 | 0.00000 |
| 2472 | freeing items      |       1 |  0.00010 | 0.00010 | 0.00000 | 0.00000 |
| 2473 | logging slow query |       1 |  0.00012 | 0.00012 | 0.00000 | 0.00000 |
| 2474 | cleaning up        |       1 |  0.00012 | 0.00012 | 0.00000 | 0.00000 |
+------+--------------------+---------+----------+---------+---------+---------+
9 rows in set (0.00 sec)

MySQL效能分析之Profile

MySQL版本

profile引數

profile幫助

profile示例

MySQL效能分析之Profile

mysql效能分析show profile/show profiles

MySQL常用效能分析方法-profile，explain，索引

神奇的 SQL 之 MySQL 效能分析神器 → EXPLAIN，SQL 起飛的基石！

mysql狀態分析之show global status

mysql狀態分析之show global status（轉）

MySQL(三) —— MySQL效能優化之索引優化

MySQL(二) —— MySQL效能優化之 SQL語句優化

MySQL (一) —— MySQL效能優化之慢查詢日誌

mysql效能優化之建立高效能索引

Mysql效能優化之資料型別優化

MySQL效能分析和優化-part 1

MySQL效能優化之filesort

mysql效能分析利器 EXPALIN

java程式效能分析之thread dump和heap dump

Android 效能分析之TraceView使用(應用耗時分析)

MySQL(二) —— MySQL效能優化之 SQL語句優化

MySQL(三) —— MySQL效能優化之索引優化

mysql 效能優化之慢查詢

MYSQL效能優化之資料庫的分庫分表

MySQL效能分析之Profile

MySQL版本

profile引數

profile幫助

profile示例

相關推薦