MySQL中使用SHOW PROFILE命令分析性能的用法整理
showprofile是由JeremyCole捐献给MySQL社区版本的。默认的是关闭的，但是会话级别可以开启这个功能。开启它可以让MySQL收集在执行语句的时候所使用的资源。为了统计报表,把profiling设为1
mysql>SETprofiling=1;
之后在运行一个查询
mysql>SELECTCOUNT(DISTINCTactor.first_name)AScnt_name,COUNT(*)AScnt ->FROMsakila.film_actor ->INNERJOINsakila.actorUSING(actor_id) ->GROUPBYsakila.film_actor.film_id ->ORDERBYcnt_nameDESC; ... 997rowsinset(0.03sec)
这个执行语句的剖析信息存储在这个会话中。使用SHOWPROFILES进行查看。
mysql>SHOWPROFILES\G
***************************1.row*************************** Query_ID:1 Duration:0.02596900 Query:SELECTCOUNT(DISTINCTactor.first_name)AScnt_name,...
你可以使用SHOWPROFILE语句来获取已经存储的剖析数据。如果不加参数，会显示状态以及它们持续的时间。
mysql>SHOWPROFILE;
+------------------------+-----------+ |Status|Duration| +------------------------+-----------+ |(initialization)|0.000005| |Openingtables|0.000033| |Systemlock|0.000037| |Tablelock|0.000024| |init|0.000079| |optimizing|0.000024| |statistics|0.000079| |preparing|0.00003| |Creatingtmptable|0.000124| |executing|0.000008| |Copyingtotmptable|0.010048| |Creatingsortindex|0.004769| |Copyingtogrouptable|0.0084880| |Sortingresult|0.001136| |Sendingdata|0.000925| |end|0.00001| |removingtmptable|0.00004| |end|0.000005| |removingtmptable|0.00001| |end|0.000011| |queryend|0.00001| |freeingitems|0.000025| |removingtmptable|0.00001| |freeingitems|0.000016| |closingtables|0.000017| |loggingslowquery|0.000006| +------------------------+-----------+
每行都是状态变化的过程以及它们持续的时间。Status那一列和SHOWFULLPROCESSLIST的State应该是一致的。
这个值是来自于thd->proc_info变量。因此你所查看的这个值是直接来自MySQL内部的。尽管这些数值是比较直接易懂的，你也可以查看MySQL手册。
你可以给SHOWPROFILES指定一个Query_ID来查看指定的语句，还可以给输出添加新的列。如，查看用户和CPU使用。可以用如下命令。
mysql>SHOWPROFILECPUFORQUERY1;
SHOWPROFILE可以深入的查看服务器执行语句的工作情况。以及也能帮助你理解执行语句消耗时间的情况。一些限制是它没有实现的功能，不能查看和剖析其他连接的语句，以及剖析时所引起的消耗。
SHOWPROFILES显示最近发给服务器的多条语句，条数根据会话变量profiling_history_size定义，默认是15，最大值为100。设为0等价于关闭分析功能。
SHOWPROFILEFORQUERYn，这里的n就是对应SHOWPROFILES输出中的Query_ID。
例如：
mysql>showprofiles;
+----------+-------------+---------------------------------------+ |Query_ID|Duration|Query| +----------+-------------+---------------------------------------+ |1|0.00037700|altertabletable1dropcolumnc3int| |2|70.37123800|altertabletable1dropcolumnc3| |3|0.00124500|showtables| |4|0.00569800|select*fromtable1whereid=2| |5|0.00068500|selectcount(1)fromtables1| |6|0.00197900|selectcount(1)fromtable1| |7|0.00105900|altertabletables1dropc1| |8|0.00800200|altertabletable1dropc1| +----------+-------------+---------------------------------------+ 8rowsinset(0.00sec)
mysql>SHOWPROFILEFORQUERY2;#查看altertabletable1dropcolumnc3的分析
+------------------------------+-----------+ |Status|Duration| +------------------------------+-----------+ |starting|0.000183| |checkingpermissions|0.000057| |checkingpermissions|0.000059| |init|0.000060| |Openingtables|0.000071| |Systemlock|0.000062| |setup|0.000080| |creatingtable|0.005052| |Aftercreate|0.000220| |copytotmptable|0.000244| |renameresulttable|70.364027| |end|0.000575| |Waitingforquerycachelock|0.000062| |end|0.000075| |queryend|0.000057| |closingtables|0.000061| |freeingitems|0.000080| |loggingslowquery|0.000056| |loggingslowquery|0.000098| |cleaningup|0.000059| +------------------------------+-----------+ 20rowsinset(0.00sec)
如果没有指定FORQUERY，那么输出最近一条语句的信息。
LIMIT部分的用法与SELECT中LIMIT子句一致，不赘述。
type是可选的，取值范围可以如下：
- ALL显示所有性能信息
- BLOCKIO显示块IO操作的次数
- CONTEXTSWITCHES显示上下文切换次数，不管是主动还是被动
- CPU显示用户CPU时间、系统CPU时间
- IPC显示发送和接收的消息数量
- MEMORY[暂未实现]
- PAGEFAULTS显示页错误数量
- SOURCE显示源码中的函数名称与位置
- SWAPS显示SWAP的次数
例：
mysql>showprofilecpuforquery2;
+------------------------------+-----------+----------+------------+ |Status|Duration|CPU_user|CPU_system| +------------------------------+-----------+----------+------------+ |starting|0.000183|0.000000|0.000000| |checkingpermissions|0.000057|0.000000|0.000000| |checkingpermissions|0.000059|0.000000|0.000000| |init|0.000060|0.000000|0.000000| |Openingtables|0.000071|0.000000|0.000000| |Systemlock|0.000062|0.000000|0.000000| |setup|0.000080|0.000000|0.001000| |creatingtable|0.005052|0.003000|0.001000| |Aftercreate|0.000220|0.000000|0.000000| |copytotmptable|0.000244|0.000000|0.000000| |renameresulttable|70.364027|7.470864|41.612674| |end|0.000575|0.000000|0.001000| |Waitingforquerycachelock|0.000062|0.000000|0.000000| |end|0.000075|0.000000|0.000000| |queryend|0.000057|0.000000|0.000000| |closingtables|0.000061|0.000000|0.000000| |freeingitems|0.000080|0.000000|0.000000| |loggingslowquery|0.000056|0.000000|0.000000| |loggingslowquery|0.000098|0.000000|0.000000| |cleaningup|0.000059|0.000000|0.000000| +------------------------------+-----------+----------+------------+ 20rowsinset(0.00sec)
ps:
SHOWPROFILEALLFORQUERY2;的信息还可以通过SELECT*FROMinformation_schema.profilingWHEREquery_id=2ORDERBYseq;获取。
作用范围
这个命令只是在本会话内起作用，即无法分析本会话外的语句。
开启分析功能后，所有本会话中的语句都被分析（甚至包括执行错误的语句），除了SHOWPROFILE和SHOWPROFILES两句本身。
应用示例：使用SHOWPROFILE分析查询缓存命中的性能优势。
mysql>setprofiling=1;
QueryOK,0rowsaffected(0.00sec)
mysql>selectcount(1)ascntfromtran_excution;
+-------+ |cnt| +-------+ |14225| +-------+ 1rowinset(0.00sec)
由于已经启用了查询缓存，相同查询（非分区表）可以直接在查询缓存中命中。
mysql>selectcount(1)ascntfromtran_excution;
我们仔细看下两个同样的语句的分析。
mysql>showprofilesourceforquery1;
+--------------------------------+----------+-----------------------+---------------+-------------+ |Status|Duration|Source_function|Source_file|Source_line| +--------------------------------+----------+-----------------------+---------------+-------------+ |starting|0.000048|NULL|NULL|NULL| |Waitingforquerycachelock|0.000013|try_lock|sql_cache.cc|454| |checkingquerycacheforquery|0.000040|send_result_to_client|sql_cache.cc|1561| |checkingpermissions|0.000023|check_access|sql_parse.cc|4751| |Openingtables|0.000040|open_tables|sql_base.cc|4831| |Systemlock|0.000020|mysql_lock_tables|lock.cc|299| |Waitingforquerycachelock|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| |Sendingdata|0.003875|exec|sql_select.cc|2380| |end|0.000018|mysql_select|sql_select.cc|2615| |queryend|0.000015|mysql_execute_command|sql_parse.cc|4440| |closingtables|0.000016|mysql_execute_command|sql_parse.cc|4492| |freeingitems|0.000016|mysql_parse|sql_parse.cc|5640| |Waitingforquerycachelock|0.000012|try_lock|sql_cache.cc|454| |freeingitems|0.000032|NULL|NULL|NULL| |Waitingforquerycachelock|0.000017|try_lock|sql_cache.cc|454| |freeingitems|0.000016|NULL|NULL|NULL| |storingresultinquerycache|0.000017|end_of_result|sql_cache.cc|1020| |loggingslowquery|0.000018|log_slow_statement|sql_parse.cc|1461| |loggingslowquery|0.000050|log_slow_statement|sql_parse.cc|1470| |cleaningup|0.000018|dispatch_command|sql_parse.cc|1417| +--------------------------------+----------+-----------------------+---------------+-------------+ 25rowsinset(0.00sec)
mysql>showprofilesourceforquery2;
+--------------------------------+----------+-----------------------+--------------+-------------+ |Status|Duration|Source_function|Source_file|Source_line| +--------------------------------+----------+-----------------------+--------------+-------------+ |starting|0.000051|NULL|NULL|NULL| |Waitingforquerycachelock|0.000014|try_lock|sql_cache.cc|454| |checkingquerycacheforquery|0.000016|send_result_to_client|sql_cache.cc|1561| |checkingprivilegesoncached|0.000013|send_result_to_client|sql_cache.cc|1652| |checkingpermissions|0.000015|check_access|sql_parse.cc|4751| |sendingcachedresulttoclien|0.000036|send_result_to_client|sql_cache.cc|1749| |loggingslowquery|0.000017|log_slow_statement|sql_parse.cc|1461| |cleaningup|0.000018|dispatch_command|sql_parse.cc|1417| +--------------------------------+----------+-----------------------+--------------+-------------+ 8rowsinset(0.00sec)
可以清晰地看到缓存中命中时，大大节省了后台的开销。当然缓存的使用也需要根据各种场景（表的数据规模，更新频率等）考察使用，并不是启用缓存就一定能够提高查询效率。这里仅仅作为SHOWPROFILE的一个应用示例。