分析sql執(zhí)行帶來(lái)的開(kāi)銷(xiāo)是優(yōu)化sql的重要手段。在mysql數(shù)據(jù)庫(kù)中，可以通過(guò)配置profiling參數(shù)來(lái)啟用sql剖析。該參數(shù)可以在全局和session級(jí)別來(lái)設(shè)置。對(duì)于全局級(jí)別則作用于整個(gè)mysql實(shí)例，而session級(jí)別緊影響當(dāng)前session。該參數(shù)開(kāi)啟后，后續(xù)執(zhí)行的sql語(yǔ)句都將記錄其資源開(kāi)銷(xiāo)，諸如io，上下文切換，cpu，memory等等。根據(jù)這些開(kāi)銷(xiāo)進(jìn)一步分析當(dāng)前sql瓶頸從而進(jìn)行優(yōu)化與調(diào)整。本文描述了如何使用mysql profile，不涉及具體的樣例分析。

1、有關(guān)profile的描述

代碼如下:

--當(dāng)前版本

]> show variables like 'version';

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

| variable_name | value |

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

| version | 5.6.17-enterprise-commercial-advanced |

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

--查看profiling系統(tǒng)變量

]> show variables like '%profil%';

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

| variable_name | value |

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

| have_profiling | yes | --只讀變量，用于控制是否由系統(tǒng)變量開(kāi)啟或禁用profiling

| profiling | off | --開(kāi)啟sql語(yǔ)句剖析功能

| profiling_history_size | 15 | --設(shè)置保留profiling的數(shù)目，缺省為15，范圍為0至100，為0時(shí)將禁用profiling

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

profiling [539]

if set to 0 or off (the default), statement profiling is disabled. if set to 1 or on, statement prof

is enabled and the show profile and show profiles statements provide access to prof

information. see section 13.7.5.32, “show profiles syntax”.

this variable is deprecated in mysql 5.6.8 and will be removed in a future mysql release.

profiling_history_size [539]

the number of statements for which to maintain profiling information if profiling [539] is

enabled. the default value is 15. the maximum value is 100. setting the value to 0 effectively

disables profiling. see section 13.7.5.32, “show profiles syntax”.

this variable is deprecated in mysql 5.6.8 and will be removed in a future mysql release.

--獲取profile的幫助

]> help profile;

name: 'show profile'

description:

syntax:

show profile [type [, type] ... ]

[for query n]

[limit row_count [offset offset]]

type:

all --顯示所有的開(kāi)銷(xiāo)信息

| block io --顯示塊io相關(guān)開(kāi)銷(xiāo)

| context switches --上下文切換相關(guān)開(kāi)銷(xiāo)

| cpu --顯示cpu相關(guān)開(kāi)銷(xiāo)信息

| ipc --顯示發(fā)送和接收相關(guān)開(kāi)銷(xiāo)信息

| memory --顯示內(nèi)存相關(guān)開(kāi)銷(xiāo)信息

| page faults --顯示頁(yè)面錯(cuò)誤相關(guān)開(kāi)銷(xiāo)信息

| source --顯示和source_function，source_file，source_line相關(guān)的開(kāi)銷(xiāo)信息

| swaps --顯示交換次數(shù)相關(guān)開(kāi)銷(xiāo)的信息

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 as of mysql 5.6.7 and will be

removed in a future mysql release. use the performance schema instead;

see.

--上面描述從5.6.7開(kāi)始該命令將會(huì)被移除，用performance schema instead代替

--在oracle數(shù)據(jù)庫(kù)中，是通過(guò)autotrace來(lái)剖析單條sql并獲取真實(shí)的執(zhí)行計(jì)劃以及其開(kāi)銷(xiāo)信息

2、開(kāi)啟porfiling

代碼如下:

--啟用session級(jí)別的profiling

]> set profiling=1;

query ok, 0 rows affected, 1 warning (0.00 sec)

--驗(yàn)證修改后的結(jié)果

]> show variables like '%profil%';

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

| variable_name | value |

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

| have_profiling | yes |

| profiling | on |

| profiling_history_size | 15 |

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

--發(fā)布sql查詢(xún)

]> select count(*) from customer;

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

| count(*) |

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

| 599 |

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

--查看當(dāng)前session所有已產(chǎn)生的profile

]> show profiles;

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

| query_id | duration | query |

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

| 1 | 0.00253600 | show variables like '%profil%' |

| 2 | 0.00138150 | select count(*) from customer |

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

2 rows in set, 1 warning (0.01 sec)

--我們看到有2個(gè)warning，之前一個(gè)，現(xiàn)在一個(gè)

]> show warnings; --下面的結(jié)果表明show profiles將來(lái)會(huì)被performance schema替換掉

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

| level | code | message |

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

| warning | 1287 | 'show profiles' is deprecated and will be removed in a future release. please use performance schema instead |

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

3、獲取sql語(yǔ)句的開(kāi)銷(xiāo)信息

代碼如下:

--可以直接使用show profile來(lái)查看上一條sql語(yǔ)句的開(kāi)銷(xiāo)信息

--注，show profile之類(lèi)的語(yǔ)句不會(huì)被profiling，即自身不會(huì)產(chǎn)生profiling

--我們下面的這個(gè)show profile查看的是show warnings產(chǎn)生的相應(yīng)開(kāi)銷(xiāo)

]> show profile;

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

| status | duration |

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

| starting | 0.000141 |

| query end | 0.000058 |

| closing tables | 0.000014 |

| freeing items | 0.001802 |

| cleaning up | 0.000272 |

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

--如下面的查詢(xún)show warnings被添加到profiles

]> show profiles;

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

| query_id | duration | query |

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

| 1 | 0.00253600 | show variables like '%profil%' |

| 2 | 0.00138150 | select count(*) from customer |

| 3 | 0.00228600 | show warnings |

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

--獲取指定查詢(xún)的開(kāi)銷(xiāo)

]> show profile for query 2;

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

| status | duration |

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

| starting | 0.000148 |

| checking permissions | 0.000014 |

| opening tables | 0.000047 |

| init | 0.000023 |

| system lock | 0.000035 |

| optimizing | 0.000012 |

| statistics | 0.000019 |

| preparing | 0.000014 |

| executing | 0.000006 |

| sending data | 0.000990 |

| end | 0.000010 |

| query end | 0.000011 |

| closing tables | 0.000010 |

| freeing items | 0.000016 |

| cleaning up | 0.000029 |

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

--查看特定部分的開(kāi)銷(xiāo)，如下為cpu部分的開(kāi)銷(xiāo)

]> show profile cpu for query 2 ;

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

| status | duration | cpu_user | cpu_system |

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

| starting | 0.000148 | 0.000000 | 0.000000 |

| checking permissions | 0.000014 | 0.000000 | 0.000000 |

| opening tables | 0.000047 | 0.000000 | 0.000000 |

| init | 0.000023 | 0.000000 | 0.000000 |

| system lock | 0.000035 | 0.000000 | 0.000000 |

| optimizing | 0.000012 | 0.000000 | 0.000000 |

| statistics | 0.000019 | 0.000000 | 0.000000 |

| preparing | 0.000014 | 0.000000 | 0.000000 |

| executing | 0.000006 | 0.000000 | 0.000000 |

| sending data | 0.000990 | 0.001000 | 0.000000 |

| end | 0.000010 | 0.000000 | 0.000000 |

| query end | 0.000011 | 0.000000 | 0.000000 |

| closing tables | 0.000010 | 0.000000 | 0.000000 |

| freeing items | 0.000016 | 0.000000 | 0.000000 |

| cleaning up | 0.000029 | 0.000000 | 0.000000 |

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

--如下為memory部分的開(kāi)銷(xiāo)

]> show profile memory for query 2 ;

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

| status | duration |

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

| starting | 0.000148 |

| checking permissions | 0.000014 |

| opening tables | 0.000047 |

| init | 0.000023 |

| system lock | 0.000035 |

| optimizing | 0.000012 |

| statistics | 0.000019 |

| preparing | 0.000014 |

| executing | 0.000006 |

| sending data | 0.000990 |

| end | 0.000010 |

| query end | 0.000011 |

| closing tables | 0.000010 |

| freeing items | 0.000016 |

| cleaning up | 0.000029 |

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

--同時(shí)查看不同資源開(kāi)銷(xiāo)

]> show profile block io,cpu for query 2;

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

| status | duration | cpu_user | cpu_system | block_ops_in | block_ops_out |

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

| starting | 0.000148 | 0.000000 | 0.000000 | 0 | 0 |

| checking permissions | 0.000014 | 0.000000 | 0.000000 | 0 | 0 |

| opening tables | 0.000047 | 0.000000 | 0.000000 | 0 | 0 |

| init | 0.000023 | 0.000000 | 0.000000 | 0 | 0 |

| system lock | 0.000035 | 0.000000 | 0.000000 | 0 | 0 |

| optimizing | 0.000012 | 0.000000 | 0.000000 | 0 | 0 |

| statistics | 0.000019 | 0.000000 | 0.000000 | 0 | 0 |

| preparing | 0.000014 | 0.000000 | 0.000000 | 0 | 0 |

| executing | 0.000006 | 0.000000 | 0.000000 | 0 | 0 |

| sending data | 0.000990 | 0.001000 | 0.000000 | 0 | 0 |

| end | 0.000010 | 0.000000 | 0.000000 | 0 | 0 |

| query end | 0.000011 | 0.000000 | 0.000000 | 0 | 0 |

| closing tables | 0.000010 | 0.000000 | 0.000000 | 0 | 0 |

| freeing items | 0.000016 | 0.000000 | 0.000000 | 0 | 0 |

| cleaning up | 0.000029 | 0.000000 | 0.000000 | 0 | 0 |

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

--下面的sql語(yǔ)句用于查詢(xún)query_id為2的sql開(kāi)銷(xiāo)，且按最大耗用時(shí)間倒序排列

]> set @query_id=2;

]> select state, sum(duration) as total_r,

-> round(

-> 100 * sum(duration) /

-> (select sum(duration)

-> from information_schema.profiling

-> where query_id = @query_id

-> ), 2) as pct_r,

-> count(*) as calls,

-> sum(duration) / count(*) as r/call

-> from information_schema.profiling

-> where query_id = @query_id

-> group by state

-> order by total_r desc;

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

| state | total_r | pct_r | calls | r/call |

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

| sending data | 0.000990 | 71.53 | 1 | 0.0009900000 |--最大耗用時(shí)間部分為發(fā)送數(shù)據(jù)

| starting | 0.000148 | 10.69 | 1 | 0.0001480000 |

| opening tables | 0.000047 | 3.40 | 1 | 0.0000470000 |

| system lock | 0.000035 | 2.53 | 1 | 0.0000350000 |

| cleaning up | 0.000029 | 2.10 | 1 | 0.0000290000 |

| init | 0.000023 | 1.66 | 1 | 0.0000230000 |

| statistics | 0.000019 | 1.37 | 1 | 0.0000190000 |

| freeing items | 0.000016 | 1.16 | 1 | 0.0000160000 |

| preparing | 0.000014 | 1.01 | 1 | 0.0000140000 |

| checking permissions | 0.000014 | 1.01 | 1 | 0.0000140000 |

| optimizing | 0.000012 | 0.87 | 1 | 0.0000120000 |

| query end | 0.000011 | 0.79 | 1 | 0.0000110000 |

| end | 0.000010 | 0.72 | 1 | 0.0000100000 |

| closing tables | 0.000010 | 0.72 | 1 | 0.0000100000 |

| executing | 0.000006 | 0.43 | 1 | 0.0000060000 |

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

--開(kāi)啟profiling后，我們可以通過(guò)show profile等方式查看，其實(shí)質(zhì)是這些開(kāi)銷(xiāo)信息被記錄到information_schema.profiling表

--如下面的查詢(xún)，部分信息省略

profiling

]> select * from profiling limit 3,3\g;

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

query_id: 1

seq: 5

state: init

duration: 0.000020

cpu_user: 0.000000

cpu_system: 0.000000

context_voluntary: 0

context_involuntary: 0

block_ops_in: 0

block_ops_out: 0

messages_sent: 0

messages_received: 0

page_faults_major: 0

page_faults_minor: 0

swaps: 0

source_function: mysql_prepare_select

source_file: sql_select.cc

source_line: 1050

--停止profile,可以設(shè)置profiling參數(shù)，或者在session退出之后,profiling會(huì)被自動(dòng)關(guān)閉

]> set profiling=off;

query ok, 0 rows affected, 1 warning (0.00 sec)

更多信息請(qǐng)查看IT技術(shù)專(zhuān)欄