MySQL使用profile查询性能的操作教程
MYSQL的profiling功能要在Mysql版本5.0.37以上才能使用。
查看profile是否开启
mysql>showvariableslike'%profil%';
+------------------------+-------+ |Variable_name|Value| +------------------------+-------+ |profiling|OFF|--开启SQL语句剖析功能 |profiling_history_size|15|--设置保留profiling的数目，缺省为15，范围为0至100，为0时将禁用profiling +------------------------+-------+ 2rowsinset(0.00sec)
基于会话级别开启
mysql>setprofiling=1;--关闭则用setprofiling=off
QueryOK,0rowsaffected(0.00sec)
mysql>selectdistinctd.account,a.server_idfromtab_appserver_usera ->innerjointab_department_parentbona.key_id=b.parent_id ->innerjointab_department_memberconb.department_id=c.department_idandc.state=1 ->andc.isdefault=1innerjointab_user_infodonc.user_id=d.user_idandd.state=1 ->wherea.type=1 ->union ->selectdistinctb.account,a.server_idfromtab_appserver_usera ->innerjointab_user_infobona.key_id=b.user_idandb.state=1 ->wherea.type=0;
查看是否设置生效：
select@@profiling;
默认是0，设置成功是1
运行SQL语句：
mysql>select*FROMhx_lineWHEREid='1455023';
查看profiles
mysql>showprofiles;
+----------+------------+---------------------------------------------+ |Query_ID|Duration|Query| +----------+------------+---------------------------------------------+ |1|0.00036150|select*FROMhx_lineWHEREid='1455023'| +----------+------------+---------------------------------------------+
查看具体某条的profile
mysql>showprofileFORQUERY1;
+--------------------------------+----------+ |Status|Duration| +--------------------------------+----------+ |starting|0.000013| |Waitingforquerycachelock|0.000014| |checkingquerycacheforquery|0.000038| |checkingpermissions|0.000006| |Openingtables|0.000013| |Systemlock|0.000009| |Waitingforquerycachelock|0.000024| |init|0.000060| |optimizing|0.000014| |statistics|0.000046| |preparing|0.000017| |executing|0.000004| |Sendingdata|0.000081| |end|0.000005| |queryend|0.000004| |closingtables|0.000008| |freeingitems|0.000009| |Waitingforquerycachelock|0.000003| |freeingitems|0.000013| |Waitingforquerycachelock|0.000003| |freeingitems|0.000003| |storingresultinquerycache|0.000005| |loggingslowquery|0.000003| |cleaningup|0.000004| +--------------------------------+----------+ 24rows
我们看到了一个简单的查询，MYSQL内部做了24次操作。
另外，看到了一堆querycache的操作，试着把query_cache_size=0，把query_cache关闭，再次测试：
mysql>showprofileFORQUERY1;
+----------------------+----------+ |Status|Duration| +----------------------+----------+ |starting|0.000040| |checkingpermissions|0.000007| |Openingtables|0.000015| |Systemlock|0.000010| |init|0.000061| |optimizing|0.000013| |statistics|0.000059| |preparing|0.000018| |executing|0.000004| |Sendingdata|0.000092| |end|0.000006| |queryend|0.000004| |closingtables|0.000008| |freeingitems|0.000020| |loggingslowquery|0.000003| |cleaningup|0.000004| +----------------------+----------+ 16rowsinset(0.00sec)
当开启了query_cache的情况下，需要多操作6次，在这个示例里面多化了0.000087s。
查询这条语句对CPU的使用情况：
mysql>showprofilecpuFORQUERY1;
+----------------------+----------+----------+------------+ |Status|Duration|CPU_user|CPU_system| +----------------------+----------+----------+------------+ |starting|0.000037|0.000000|0.000000| |checkingpermissions|0.000009|0.000000|0.000000| |Openingtables|0.000014|0.000000|0.000000| |Systemlock|0.000009|0.000000|0.000000| |init|0.000059|0.000000|0.000000| |optimizing|0.000009|0.000000|0.000000| |statistics|0.000044|0.000000|0.000000| |preparing|0.000015|0.000000|0.000000| |executing|0.000004|0.000000|0.000000| |Sendingdata|0.000081|0.000000|0.000000| |end|0.000006|0.000000|0.000000| |queryend|0.000004|0.000000|0.000000| |closingtables|0.000008|0.000000|0.000000| |freeingitems|0.000021|0.000000|0.000000| |loggingslowquery|0.000004|0.000000|0.000000| |cleaningup|0.000004|0.000000|0.000000| +----------------------+----------+----------+------------+
查看io及cpu的消耗
mysql>showprofileblockio,cpuforquery1;
+--------------------------------+----------+----------+------------+--------------+---------------+ |Status|Duration|CPU_user|CPU_system|Block_ops_in|Block_ops_out| +--------------------------------+----------+----------+------------+--------------+---------------+ |starting|0.000018|NULL|NULL|NULL|NULL| |checkingquerycacheforquery|0.000099|NULL|NULL|NULL|NULL| |Openingtables|0.000963|NULL|NULL|NULL|NULL| |Systemlock|0.000015|NULL|NULL|NULL|NULL| |Tablelock|0.000169|NULL|NULL|NULL|NULL| |optimizing|0.000020|NULL|NULL|NULL|NULL| |statistics|0.000027|NULL|NULL|NULL|NULL| |preparing|0.000018|NULL|NULL|NULL|NULL| |Creatingtmptable|0.000055|NULL|NULL|NULL|NULL| |executing|0.000003|NULL|NULL|NULL|NULL| |Copyingtotmptable|0.704845|NULL|NULL|NULL|NULL| |Sendingdata|0.130039|NULL|NULL|NULL|NULL| |optimizing|0.000029|NULL|NULL|NULL|NULL| |statistics|0.000029|NULL|NULL|NULL|NULL| |preparing|0.000020|NULL|NULL|NULL|NULL| |Creatingtmptable|0.000142|NULL|NULL|NULL|NULL| |executing|0.000003|NULL|NULL|NULL|NULL| |Copyingtotmptable|0.000086|NULL|NULL|NULL|NULL| |Sendingdata|0.000067|NULL|NULL|NULL|NULL| |optimizing|0.000004|NULL|NULL|NULL|NULL| |statistics|0.000005|NULL|NULL|NULL|NULL| |preparing|0.000005|NULL|NULL|NULL|NULL| |executing|0.000002|NULL|NULL|NULL|NULL| |Sendingdata|0.023963|NULL|NULL|NULL|NULL| |removingtmptable|0.003420|NULL|NULL|NULL|NULL| |Sendingdata|0.000005|NULL|NULL|NULL|NULL| |removingtmptable|0.003308|NULL|NULL|NULL|NULL| |Sendingdata|0.000006|NULL|NULL|NULL|NULL| |removingtmptable|0.000007|NULL|NULL|NULL|NULL| |Sendingdata|0.000009|NULL|NULL|NULL|NULL| |queryend|0.000003|NULL|NULL|NULL|NULL| |freeingitems|0.000144|NULL|NULL|NULL|NULL| |storingresultinquerycache|0.000011|NULL|NULL|NULL|NULL| |loggingslowquery|0.000003|NULL|NULL|NULL|NULL| |cleaningup|0.000006|NULL|NULL|NULL|NULL| +--------------------------------+----------+----------+------------+--------------+---------------+ 35rowsinset(0.00sec)
使用查询语句对消耗进行排序
mysql>SELECTSTATE,SUM(DURATION)ASTotal_R,ROUND(100*SUM(DURATION)/(SE CTSUM(DURATION) ->FROMINFORMATION_SCHEMA.PROFILINGWHEREQUERY_ID=1),2)ASPct_R,CO T(*)ASCalls,SUM(DURATION)/COUNT(*)AS"R/Call" ->FROMINFORMATION_SCHEMA.PROFILINGWHEREQUERY_ID=1GROUPBYSTATEO ERBYTotal_RDESC;
+--------------------------------+----------+-------+-------+--------------+ |STATE|Total_R|Pct_R|Calls|R/Call| +--------------------------------+----------+-------+-------+--------------+ |Copyingtotmptable|0.704931|81.26|2|0.3524655000| |Sendingdata|0.154089|17.76|6|0.0256815000| |removingtmptable|0.006735|0.78|3|0.0022450000| |Openingtables|0.000963|0.11|1|0.0009630000| |Creatingtmptable|0.000197|0.02|2|0.0000985000| |Tablelock|0.000169|0.02|1|0.0001690000| |freeingitems|0.000144|0.02|1|0.0001440000| |checkingquerycacheforquery|0.000099|0.01|1|0.0000990000| |statistics|0.000061|0.01|3|0.0000203333| |optimizing|0.000053|0.01|3|0.0000176667| |preparing|0.000043|0.00|3|0.0000143333| |starting|0.000018|0.00|1|0.0000180000| |Systemlock|0.000015|0.00|1|0.0000150000| |storingresultinquerycache|0.000011|0.00|1|0.0000110000| |executing|0.000008|0.00|3|0.0000026667| |cleaningup|0.000006|0.00|1|0.0000060000| |loggingslowquery|0.000003|0.00|1|0.0000030000| |queryend|0.000003|0.00|1|0.0000030000| +--------------------------------+----------+-------+-------+--------------+ 18rowsinset(0.01sec)
showprofile额外一些命令：
*ALL-displaysallinformation
*BLOCKIO-displayscountsforblockinputandoutputOperations
*CONTEXTSWITCHES-displayscountsforvoluntaryandinvoluntarycontextswitches
*ipC-displayscountsformessagessentandreceived
*MEMORY-isnotcurrentlyimplemented
*PAGEFAULTS-displayscountsformajorandminorpagefaults
*SOURCE-displaysthenamesoffunctionsfromthesourcecode,togetherwiththenameandlinenumberofthefileinwhichthefunctionoccurs
*SWAPS-displaysswapcounts
最后说明：profile是一个非常量化的子标，可以根据这些量化指标来比较各项资源的消耗，有利于我们对该语句的整体把控！