mysql显示SQL语句执行时间

查看 mysql 語法 詳細執行時間 與 cpu/記憶體使用量: mysql query profiler

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 | +--------------------------------+----------+---------------+-------------------+

其它屬性列表

all - displays all information

block io - displays counts for block input and output operations

context switches - displays counts for voluntary and involuntary context switches

ipc - displays counts for messages sent and received

memory - is not currently implemented

page faults - displays counts for major and minor page faults

source - displays the names of functions from the source code, together with the name and line number of the file in which the function occurs

swaps - displays swap counts

設定 profiling 存的 size

mysql> show variables where variable_name='profiling_history_size'; # 預設是 15筆

關閉

mysql> set profiling=0;