查看mysql语句运行时间的2种方法

网站运行很慢的时候，我就特别起知道为什么这么慢，所以我查啊查,数据库绝对是很重要的一部分，里面运行的sql是绝对不能放过的。平时做项目的时候，我也会注意sql语句的书写，写出一些高效的sql来，所以我会经常测试自己写的sql语句。我把我知道的二个方法，总结一下发出来。

一，show profiles 之类的语句来查看

1，查一下profile是不是打开了，默认是不打开的。

mysql> show profiles;

Empty set (0.02 sec)

mysql> show variables like "%pro%";

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

| Variable_name | Value |

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

| profiling | OFF |

| profiling_history_size | 15 |

| protocol_version | 10 |

| slave_compressed_protocol | OFF |

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

4 rows in set (0.00 sec)

我查看一下profiles里面没有东西，所以公司的电脑里面profile是没有打开的，我查看了一下mysql变量，果然是OFF的。

2，开启profile，然后测试

开启profile

mysql> set profiling=1;

Query OK, 0 rows affected (0.00 sec)

测试如下：

mysql> show tables;

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

| Tables_in_test |

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

| aa |

| bb |

| comment |

| string_test |

| user |

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

5 rows in set (0.00 sec)

mysql> select * from aa;

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

| id | name | nname | sex |

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

| 2 | tank | bbbb,4bbbb | NULL |

| 3 | zhang| 3,c,u | NULL |

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

2 rows in set (0.00 sec)

mysql> update aa set name='d';

Query OK, 2 rows affected (0.00 sec)

Rows matched: 2 Changed: 2 Warnings: 0

mysql> delete from bb;

Query OK, 2 rows affected (0.00 sec)

mysql> show profiles;

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

| Query_ID | Duration | Query |

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

| 1 | 0.00054775 | show tables |

| 2 | 0.00022400 | select * from aa |

| 3 | 0.00026275 | update aa set name='d' |

| 4 | 0.00043000 | delete from bb |

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

4 rows in set (0.00 sec)

mysql> show profile;

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

| Status | Duration |

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

| (initialization) | 0.0000247 |

| checking permissions | 0.0000077 |

| Opening tables | 0.0000099 |

| System lock | 0.000004 |

| Table lock | 0.000005 |

| init | 0.0003057 |

| query end | 0.0000062 |

| freeing items | 0.000057 |

| closing tables | 0.000008 |

| logging slow query | 0.0000015 |

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

10 rows in set (0.00 sec)

mysql> show profile for query 1;

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

| Status | Duration |

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

| (initialization) | 0.000028 |

| checking permissions | 0.000007 |

| Opening tables | 0.0000939 |

| System lock | 0.0000017 |

| Table lock | 0.0000055 |

| init | 0.000009 |

| optimizing | 0.0000027 |

| statistics | 0.0000085 |

| preparing | 0.0000065 |

| executing | 0.000004 |

| checking permissions | 0.000258 |

| Sending data | 0.000049 |

| end | 0.0000037 |

| query end | 0.0000027 |

| freeing items | 0.0000307 |

| closing tables | 0.0000032 |

| removing tmp table | 0.0000275 |

| closing tables | 0.0000037 |

| logging slow query | 0.000002 |

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

19 rows in set (0.00 sec)

mysql> show profile for query 3;

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

| Status | Duration |

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

| (initialization) | 0.0000475 |

| checking permissions | 0.0000077 |

| Opening tables | 0.000026 |

| System lock | 0.0000042 |

| Table lock | 0.0000045 |

| init | 0.0000205 |

| Updating | 0.0000787 |

| end | 0.0000567 |

| query end | 0.000004 |

| freeing items | 0.0000067 |

| closing tables | 0.000004 |

| logging slow query | 0.000002 |

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

12 rows in set (0.00 sec)

二，timestampdiff来查看测试时间

mysql> set @d=now();

Query OK, 0 rows affected (0.00 sec)

mysql> select * from comment;

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

| c_id | mid | name | content | datetime |

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

| 1 | 1 | ?? | 2222222211 | 2010-05-12 00:00:00 |

| 2 | 1 | ?? | ????(??) | 2010-05-13 00:00:00 |

| 3 | 2 | tank | ?????? | 0000-00-00 00:00:00 |

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

3 rows in set (0.00 sec)

mysql> select timestampdiff(second,@d,now());

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

| timestampdiff(second,@d,now()) |

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

| 0 |

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

1 row in set (0.00 sec)

这种方法有一点要注意，就是三条sql语句要尽量连一起执行，不然误差太大，根本不准

set @d=now();

select * from comment;

select timestampdiff(second,@d,now());

如果是用命令行来执行的话，有一点要注意，就是在select timestampdiff(second,@d,now());后面，一定要多copy一个空行，不然最后一个sql要你自己按回车执行，这样就不准了。

其实我觉得吧，真正要我们关心的是，那些查询慢的sql,因为真正影响速度的是他们，关于慢查询的东西，有空写一下。

----------------------------------------------------------------------------------------

查看mysql sql 执行时间和资源占用

MySQL 的 SQL 語法調整主要都是使用 EXPLAIN, 但是這個並沒辦法知道詳細的 Ram(Memory)/CPU 等使用量.

於 MySQL 5.0.37 以上開始支援 MySQL Query Profiler, 可以查詢到此 SQL 會執行多少時間, 並看出 CPU/Memory 使用量, 執行過程中 System lock, Table lock 花多少時間等等.

MySQL Query Profile 詳細介紹可見: Using the New MySQL Query Profiler(2007.04.05 發表)

效能分析主要分下述三種(轉載自上篇):

Bottleneck analysis - focuses on answering the questions: What is my database server waiting on; what is a user connection waiting on; what is a piece of SQL code waiting on?

Workload analysis - examines the server and who is logged on to determine the resource usage and activity of each.

Ratio-based analysis - utilizes a number of rule-of-thumb ratios to gauge performance of a database, user connection, or piece of code.

MySQL Query Profile 使用方法

啟動

mysql> set profiling=1; # 此命令於 MySQL 會於 information_schema 的 database 建立一個 PROFILING 的 table 來紀錄.

SQL profiles show

mysql> show profiles; # 從啟動之後所有語法及使用時間, 含錯誤語法都會紀錄.

ex: (root@localhost) [test]> show profiles; # 注意 Query_ID, 下面執行時間統計等, 都是依 Query_ID 在紀錄

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

| Query_ID | Duration | Query |

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

| 1 | 0.00090400 | show profile for query 1 |

| 2 | 0.00008700 | select * from users |

| 3 | 0.00183800 | show tables |

| 4 | 0.00027600 | mysql> show profiles |

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

查詢所有花費時間加總

mysql> select sum(duration) from information_schema.profiling where query_id=1; # Query ID = 1

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

| sum(duration) |

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

| 0.000447 |

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

查詢各執行階段花費多少時間

mysql> show profile for query 1; # Query ID = 1

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

| Status | Duration |

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

| (initialization) | 0.00006300 |

| Opening tables | 0.00001400 |

| System lock | 0.00000600 |

| Table lock | 0.00001000 |

| init | 0.00002200 |

| optimizing | 0.00001100 |

| statistics | 0.00009300 |

| preparing | 0.00001700 |

| executing | 0.00000700 |

| Sending data | 0.00016800 |

| end | 0.00000700 |

| query end | 0.00000500 |

| freeing items | 0.00001200 |

| closing tables | 0.00000800 |

| logging slow query | 0.00000400 |

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

查詢各執行階段花費的各種資源列表

mysql> show profile cpu for query 1; # Query ID = 1

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

| Status | Duration | CPU_user | CPU_system |

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

| (initialization) | 0.000007 | 0 | 0 |

| checking query cache for query | 0.000071 | 0 | 0 |

| Opening tables | 0.000024 | 0 | 0 |

| System lock | 0.000014 | 0 | 0 |

| Table lock | 0.000055 | 0.001 | 0 |

| init | 0.000036 | 0 | 0 |

| optimizing | 0.000013 | 0 | 0 |

| statistics | 0.000021 | 0 | 0 |

| preparing | 0.00002 | 0 | 0 |

| executing | 0.00001 | 0 | 0 |

| Sending data | 0.015072 | 0.011998 | 0 |

| end | 0.000021 | 0 | 0 |

| query end | 0.000011 | 0 | 0 |

| storing result in query cache | 0.00001 | 0 | 0 |

| freeing items | 0.000018 | 0 | 0 |

| closing tables | 0.000019 | 0 | 0 |

| logging slow query | 0.000009 | 0 | 0 |

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

mysql> show profile IPC for query 1;

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

| Status | Duration | Messages_sent | Messages_received |

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

| (initialization) | 0.000007 | 0 | 0 |

| checking query cache for query | 0.000071 | 0 | 0 |

| Opening tables | 0.000024 | 0 | 0 |

| System lock | 0.000014 | 0 | 0 |

| Table lock | 0.000055 | 0 | 0 |

| init | 0.000036 | 0 | 0 |

| optimizing | 0.000013 | 0 | 0 |

| statistics | 0.000021 | 0 | 0 |

| preparing | 0.00002 | 0 | 0 |

| executing | 0.00001 | 0 | 0 |

| Sending data | 0.015072 | 0 | 0 |

| end | 0.000021 | 0 | 0 |

| query end | 0.000011 | 0 | 0 |

| storing result in query cache | 0.00001 | 0 | 0 |

| freeing items | 0.000018 | 0 | 0 |

| closing tables | 0.000019 | 0 | 0 |

| logging slow query | 0.000009 | 0 | 0 |

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

---------------------------------------------------------------------------------------

show processlist;

找出你要停止的语句

然后找出你要终止的语句的id

在系统下mysqladmin -uroot -ppassword kill 要杀的ID