show profile是由Jeremy Cole捐獻(xiàn)給MySQL社區(qū)版本的。默認(rèn)的是關(guān)閉的，但是會(huì)話級(jí)別可以開(kāi)啟這個(gè)功能。開(kāi)啟它可以讓MySQL收集在執(zhí)行語(yǔ)句的時(shí)候所使用的資源。為了統(tǒng)計(jì)報(bào)表,把profiling設(shè)為1

mysql> SET profiling = 1;

之后在運(yùn)行一個(gè)查詢

mysql> SELECT COUNT(DISTINCT actor.first_name) AS cnt_name, COUNT(*) AS cnt

-> FROM sakila.film_actor

-> INNER JOIN sakila.actor USING(actor_id)

-> GROUP BY sakila.film_actor.film_id

-> ORDER BY cnt_name DESC;

...

997 rows in set (0.03 sec)

這個(gè)執(zhí)行語(yǔ)句的剖析信息存儲(chǔ)在這個(gè)會(huì)話中。使用SHOW PROFILES進(jìn)行查看。

*************************** 1. row ***************************

Query_ID: 1

Duration: 0.02596900

Query: SELECT COUNT(DISTINCT actor.first_name) AS cnt_name,...

你可以使用SHOW PROFILE語(yǔ)句來(lái)獲取已經(jīng)存儲(chǔ)的剖析數(shù)據(jù)。如果不加參數(shù)，會(huì)顯示狀態(tài)以及它們持續(xù)的時(shí)間。

+------------------------+-----------+

| Status | Duration |

+------------------------+-----------+

| (initialization) | 0.000005 |

| Opening tables | 0.000033 |

| System lock | 0.000037 |

| Table lock | 0.000024 |

| init | 0.000079 |

| optimizing | 0.000024 |

| statistics | 0.000079 |

| preparing | 0.00003 |

| Creating tmp table | 0.000124 |

| executing | 0.000008 |

| Copying to tmp table | 0.010048 |

| Creating sort index | 0.004769 |

| Copying to group table | 0.0084880 |

| Sorting result | 0.001136 |

| Sending data | 0.000925 |

| end | 0.00001 |

| removing tmp table | 0.00004 |

| end | 0.000005 |

| removing tmp table | 0.00001 |

| end | 0.000011 |

| query end | 0.00001 |

| freeing items | 0.000025 |

| removing tmp table | 0.00001 |

| freeing items | 0.000016 |

| closing tables | 0.000017 |

| logging slow query | 0.000006 |

+------------------------+-----------+

每行都是狀態(tài)變化的過(guò)程以及它們持續(xù)的時(shí)間。Status那一列和SHOW FULL PROCESSLIST的State應(yīng)該是一致的。

這個(gè)值是來(lái)自于thd->proc_info變量。因此你所查看的這個(gè)值是直接來(lái)自MySQL內(nèi)部的。盡管這些數(shù)值是比較直接易懂的，你也可以查看MySQL手冊(cè)。

你可以給SHOW PROFILES指定一個(gè)Query_ID來(lái)查看指定的語(yǔ)句，還可以給輸出添加新的列。如，查看用戶和CPU使用。可以用如下命令。

mysql> SHOW PROFILE CPU FOR QUERY 1;

SHOW PROFILE可以深入的查看服務(wù)器執(zhí)行語(yǔ)句的工作情況。以及也能幫助你理解執(zhí)行語(yǔ)句消耗時(shí)間的情況。一些限制是它沒(méi)有實(shí)現(xiàn)的功能，不能查看和剖析其他連接的語(yǔ)句，以及剖析時(shí)所引起的消耗。

SHOW PROFILES顯示最近發(fā)給服務(wù)器的多條語(yǔ)句，條數(shù)根據(jù)會(huì)話變量profiling_history_size定義，默認(rèn)是15，最大值為100。設(shè)為0等價(jià)于關(guān)閉分析功能。

SHOW PROFILE FOR QUERY n，這里的n就是對(duì)應(yīng)SHOW PROFILES輸出中的Query_ID。

例如：

+----------+-------------+---------------------------------------+

| Query_ID | Duration | Query |

+----------+-------------+---------------------------------------+

| 1 | 0.00037700 | alter table table1 drop column c3 int |

| 2 | 70.37123800 | alter table table1 drop column c3 |

| 3 | 0.00124500 | show tables |

| 4 | 0.00569800 | select * from table1 where id=2 |

| 5 | 0.00068500 | select count(1) from tables1 |

| 6 | 0.00197900 | select count(1) from table1 |

| 7 | 0.00105900 | alter table tables1 drop c1 |

| 8 | 0.00800200 | alter table table1 drop c1 |

+----------+-------------+---------------------------------------+

8 rows in set (0.00 sec)

mysql> SHOW PROFILE FOR QUERY 2; #查看alter table table1 drop column c3的分析

+------------------------------+-----------+

| Status | Duration |

+------------------------------+-----------+

| starting | 0.000183 |

| checking permissions | 0.000057 |

| checking permissions | 0.000059 |

| init | 0.000060 |

| Opening tables | 0.000071 |

| System lock | 0.000062 |

| setup | 0.000080 |

| creating table | 0.005052 |

| After create | 0.000220 |

| copy to tmp table | 0.000244 |

| rename result table | 70.364027 |

| end | 0.000575 |

| Waiting for query cache lock | 0.000062 |

| end | 0.000075 |

| query end | 0.000057 |

| closing tables | 0.000061 |

| freeing items | 0.000080 |

| logging slow query | 0.000056 |

| logging slow query | 0.000098 |

| cleaning up | 0.000059 |

+------------------------------+-----------+

20 rows in set (0.00 sec)

如果沒(méi)有指定FOR QUERY，那么輸出最近一條語(yǔ)句的信息。

LIMIT部分的用法與SELECT中LIMIT子句一致，不贅述。

type是可選的，取值范圍可以如下：

ALL 顯示所有性能信息

BLOCK IO 顯示塊IO操作的次數(shù)

CONTEXT SWITCHES 顯示上下文切換次數(shù)，不管是主動(dòng)還是被動(dòng)

CPU 顯示用戶CPU時(shí)間、系統(tǒng)CPU時(shí)間

IPC 顯示發(fā)送和接收的消息數(shù)量

MEMORY [暫未實(shí)現(xiàn)]

PAGE FAULTS 顯示頁(yè)錯(cuò)誤數(shù)量

SOURCE 顯示源碼中的函數(shù)名稱與位置

SWAPS 顯示SWAP的次數(shù)

例：

mysql> show profile cpu for query 2;

+------------------------------+-----------+----------+------------+

| Status | Duration | CPU_user | CPU_system |

+------------------------------+-----------+----------+------------+

| starting | 0.000183 | 0.000000 | 0.000000 |

| checking permissions | 0.000057 | 0.000000 | 0.000000 |

| checking permissions | 0.000059 | 0.000000 | 0.000000 |

| init | 0.000060 | 0.000000 | 0.000000 |

| Opening tables | 0.000071 | 0.000000 | 0.000000 |

| System lock | 0.000062 | 0.000000 | 0.000000 |

| setup | 0.000080 | 0.000000 | 0.001000 |

| creating table | 0.005052 | 0.003000 | 0.001000 |

| After create | 0.000220 | 0.000000 | 0.000000 |

| copy to tmp table | 0.000244 | 0.000000 | 0.000000 |

| rename result table | 70.364027 | 7.470864 | 41.612674 |

| end | 0.000575 | 0.000000 | 0.001000 |

| Waiting for query cache lock | 0.000062 | 0.000000 | 0.000000 |

| end | 0.000075 | 0.000000 | 0.000000 |

| query end | 0.000057 | 0.000000 | 0.000000 |

| closing tables | 0.000061 | 0.000000 | 0.000000 |

| freeing items | 0.000080 | 0.000000 | 0.000000 |

| logging slow query | 0.000056 | 0.000000 | 0.000000 |

| logging slow query | 0.000098 | 0.000000 | 0.000000 |

| cleaning up | 0.000059 | 0.000000 | 0.000000 |

+------------------------------+-----------+----------+------------+

20 rows in set (0.00 sec)

ps:

SHOW PROFILE ALL FOR QUERY 2;的信息還可以通過(guò)SELECT * FROM information_schema.profiling WHERE query_id = 2 ORDER BY seq;獲取。

作用范圍

這個(gè)命令只是在本會(huì)話內(nèi)起作用，即無(wú)法分析本會(huì)話外的語(yǔ)句。

開(kāi)啟分析功能后，所有本會(huì)話中的語(yǔ)句都被分析(甚至包括執(zhí)行錯(cuò)誤的語(yǔ)句)，除了SHOW PROFILE和SHOW PROFILES兩句本身。

應(yīng)用示例：使用SHOW PROFILE分析查詢緩存命中的性能優(yōu)勢(shì)。

Query OK, 0 rows affected (0.00 sec)

mysql> select count(1) as cnt from tran_excution;

+-------+

| cnt |

+-------+

| 14225 |

+-------+

1 row in set (0.00 sec)

由于已經(jīng)啟用了查詢緩存，相同查詢(非分區(qū)表)可以直接在查詢緩存中命中。

mysql> select count(1) as cnt from tran_excution;

我們仔細(xì)看下兩個(gè)同樣的語(yǔ)句的分析。

mysql> show profile source for query 1;

+--------------------------------+----------+-----------------------+---------------+-------------+

| Status | Duration | Source_function | Source_file | Source_line |

+--------------------------------+----------+-----------------------+---------------+-------------+

| starting | 0.000048 | NULL | NULL | NULL |

| Waiting for query cache lock | 0.000013 | try_lock | sql_cache.cc | 454 |

| checking query cache for query | 0.000040 | send_result_to_client | sql_cache.cc | 1561 |

| checking permissions | 0.000023 | check_access | sql_parse.cc | 4751 |

| Opening tables | 0.000040 | open_tables | sql_base.cc | 4831 |

| System lock | 0.000020 | mysql_lock_tables | lock.cc | 299 |

| Waiting for query cache lock | 0.000037 | try_lock | sql_cache.cc | 454 |

| init | 0.000020 | mysql_select | sql_select.cc | 2579 |

| optimizing | 0.000015 | optimize | sql_select.cc | 865 |

| statistics | 0.000017 | optimize | sql_select.cc | 1056 |

| preparing | 0.000016 | optimize | sql_select.cc | 1078 |

| executing | 0.000015 | exec | sql_select.cc | 1836 |

| Sending data | 0.003875 | exec | sql_select.cc | 2380 |

| end | 0.000018 | mysql_select | sql_select.cc | 2615 |

| query end | 0.000015 | mysql_execute_command | sql_parse.cc | 4440 |

| closing tables | 0.000016 | mysql_execute_command | sql_parse.cc | 4492 |

| freeing items | 0.000016 | mysql_parse | sql_parse.cc | 5640 |

| Waiting for query cache lock | 0.000012 | try_lock | sql_cache.cc | 454 |

| freeing items | 0.000032 | NULL | NULL | NULL |

| Waiting for query cache lock | 0.000017 | try_lock | sql_cache.cc | 454 |

| freeing items | 0.000016 | NULL | NULL | NULL |

| storing result in query cache | 0.000017 | end_of_result | sql_cache.cc | 1020 |

| logging slow query | 0.000018 | log_slow_statement | sql_parse.cc | 1461 |

| logging slow query | 0.000050 | log_slow_statement | sql_parse.cc | 1470 |

| cleaning up | 0.000018 | dispatch_command | sql_parse.cc | 1417 |

+--------------------------------+----------+-----------------------+---------------+-------------+

25 rows in set (0.00 sec)

mysql> show profile source for query 2;

+--------------------------------+----------+-----------------------+--------------+-------------+

| Status | Duration | Source_function | Source_file | Source_line |

+--------------------------------+----------+-----------------------+--------------+-------------+

| starting | 0.000051 | NULL | NULL | NULL |

| Waiting for query cache lock | 0.000014 | try_lock | sql_cache.cc | 454 |

| checking query cache for query | 0.000016 | send_result_to_client | sql_cache.cc | 1561 |

| checking privileges on cached | 0.000013 | send_result_to_client | sql_cache.cc | 1652 |

| checking permissions | 0.000015 | check_access | sql_parse.cc | 4751 |

| sending cached result to clien | 0.000036 | send_result_to_client | sql_cache.cc | 1749 |

| logging slow query | 0.000017 | log_slow_statement | sql_parse.cc | 1461 |

| cleaning up | 0.000018 | dispatch_command | sql_parse.cc | 1417 |

+--------------------------------+----------+-----------------------+--------------+-------------+

8 rows in set (0.00 sec)

可以清晰地看到緩存中命中時(shí)，大大節(jié)省了后臺(tái)的開(kāi)銷。當(dāng)然緩存的使用也需要根據(jù)各種場(chǎng)景(表的數(shù)據(jù)規(guī)模，更新頻率等)考察使用，并不是啟用緩存就一定能夠提高查詢效率。這里僅僅作為SHOW PROFILE的一個(gè)應(yīng)用示例。

總結(jié)

以上是生活随笔為你收集整理的mysql 性能分析 命令_MySQL中使用SHOW PROFILE命令分析性能的用法整理的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。