show profile在mysql5.7之後過時
show profile命令用於跟蹤執行過的sql語句的資源消耗資訊,可以幫助檢視sql語句的執行情況,可以在做效能分析或者問題診斷的時候作為參考。在MySQL5.7中, show profile命令已經開始不推薦使用,MySQL使用performance_schema 中系統表的資訊來替代show profile命令,這兒主要是研究資源效能監控的思路。
SHOW PROFILE [type [, type] ... ]
[FOR QUERY n]
[LIMIT row_count [OFFSET offset]]
type:
ALL
| BLOCK IO
| CONTEXT SWITCHES
| CPU
| IPC
| MEMORY
| PAGE FAULTS
| SOURCE
| SWAPS
此工具預設是禁用的,首先開啟show profile跟蹤記錄SQL執行情況的配置,可以通過伺服器變數在會話級別動態的修改:
mysql> set profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)
當設定完成之後,在伺服器上執行的所有語句,都會測量其耗費的時間和其他一些查詢執行狀態變更相關的資料。
以下面查詢語句舉例:
mysql> select * from emp;
+-------+--------+-----------+------+------------+---------+---------+--------+
| empno | ename | job | mgr | hiredate | sal | comm | deptno |
+-------+--------+-----------+------+------------+---------+---------+--------+
| 7369 | SMITH | CLERK | 7902 | 1980-12-17 | 800.00 | NULL | 20 |
| 7499 | ALLEN | SALESMAN | 7698 | 1981-02-20 | 1600.00 | 300.00 | 30 |
| 7521 | WARD | SALESMAN | 7698 | 1981-02-22 | 1250.00 | 500.00 | 30 |
| 7566 | JONES | MANAGER | 7839 | 1981-04-02 | 2975.00 | NULL | 20 |
| 7654 | MARTIN | SALESMAN | 7698 | 1981-09-28 | 1250.00 | 1400.00 | 30 |
| 7698 | BLAKE | MANAGER | 7839 | 1981-05-01 | 2850.00 | NULL | 30 |
| 7782 | CLARK | MANAGER | 7839 | 1981-06-09 | 2450.00 | NULL | 10 |
| 7788 | SCOTT | ANALYST | 7566 | 1987-07-13 | 3000.00 | NULL | 20 |
| 7839 | KING | PRESIDENT | NULL | 1981-11-17 | 5000.00 | NULL | 10 |
| 7844 | TURNER | SALESMAN | 7698 | 1981-09-08 | 1500.00 | 0.00 | 30 |
| 7876 | ADAMS | CLERK | 7788 | 1987-07-13 | 1100.00 | NULL | 20 |
| 7900 | JAMES | CLERK | 7698 | 1981-12-03 | 950.00 | NULL | 30 |
| 7902 | FORD | ANALYST | 7566 | 1981-12-03 | 3000.00 | NULL | 20 |
| 7934 | MILLER | CLERK | 7782 | 1982-01-23 | 1300.00 | NULL | 10 |
+-------+--------+-----------+------+------------+---------+---------+--------+
14 rows in set (0.01 sec)
在mysql的命令列模式下只能顯示兩位小數的時間,可以使用如下命令檢視具體的執行時間
mysql> show profiles;
+----------+------------+-------------------+
| Query_ID | Duration | Query |
+----------+------------+-------------------+
| 1 | 0.00130500 | show databases |
| 2 | 0.00010250 | SELECT DATABASE() |
| 3 | 0.00027500 | show databases |
| 4 | 0.00023075 | show tables |
| 5 | 0.00041800 | show databases |
| 6 | 0.00018925 | show tables |
| 7 | 0.00376825 | select * from emp |
+----------+------------+-------------------+
7 rows in set, 1 warning (0.00 sec)
上面一共有7條sql語句操作,執行如下命令可以檢視詳細的每個步驟的時間,這兒以Query_ID = 1的語句舉例子:
mysql> show profile for query 1 ;
+----------------------+----------+
| Status | Duration |
+----------------------+----------+
| starting | 0.000089 |
| checking permissions | 0.000025 |
| Opening tables | 0.000062 |
| init | 0.000036 |
| System lock | 0.000007 |
| optimizing | 0.000004 |
| statistics | 0.000023 |
| preparing | 0.000039 |
| executing | 0.000910 |
| Sending data | 0.000019 |
| end | 0.000016 |
| query end | 0.000006 |
| closing tables | 0.000002 |
| removing tmp table | 0.000004 |
| closing tables | 0.000016 |
| freeing items | 0.000013 |
| cleaning up | 0.000036 |
+----------------------+----------+
17 rows in set, 1 warning (0.00 sec)
除了query n指定Query_ID外,還可以設定Type檢視MYSQL語句執行的其他資訊,type主要引數如下:
all:顯示所有效能資訊
block io:顯示塊io操作的次數
context switches:顯示上下文切換次數,被動和主動
cpu:顯示使用者cpu時間、系統cpu時間
IPC:顯示傳送和接受的訊息數量
Memory:暫未實現
page faults:顯示頁錯誤數量
source:顯示原始碼中的函式名稱與位置
swaps:顯示swap的次數
##all顯示內容太寬,這兒暫不顯示
mysql> show profile all for query 7;
block io
mysql> mysql> show profile block io fo 7;
+----------------------+----------+--------------+---------------+
| Status | Duration | Block_ops_in | Block_ops_out |
+----------------------+----------+--------------+---------------+
| starting | 0.000053 | 0 | 0 |
| checking permissions | 0.000006 | 0 | 0 |
| Opening tables | 0.000014 | 0 | 0 |
| init | 0.000056 | 0 | 0 |
| System lock | 0.000055 | 0 | 0 |
| optimizing | 0.000006 | 0 | 0 |
| statistics | 0.000008 | 0 | 0 |
| preparing | 0.000007 | 0 | 0 |
| executing | 0.000002 | 0 | 0 |
| Sending data | 0.003099 | 0 | 0 |
| end | 0.000006 | 0 | 0 |
| query end | 0.000007 | 0 | 0 |
| closing tables | 0.000006 | 0 | 0 |
| freeing items | 0.000396 | 0 | 0 |
| cleaning up | 0.000050 | 0 | 0 |
+----------------------+----------+--------------+---------------+
15 rows in set, 1 warning (0.00 sec)
context switches
mysql> show profile context switches for query 1;
+----------------------+----------+-------------------+---------------------+
| Status | Duration | Context_voluntary | Context_involuntary |
+----------------------+----------+-------------------+---------------------+
| starting | 0.000089 | 0 | 0 |
| checking permissions | 0.000025 | 0 | 0 |
| Opening tables | 0.000062 | 0 | 0 |
| init | 0.000036 | 0 | 0 |
| System lock | 0.000007 | 0 | 0 |
| optimizing | 0.000004 | 0 | 0 |
| statistics | 0.000023 | 0 | 0 |
| preparing | 0.000039 | 0 | 0 |
| executing | 0.000910 | 0 | 0 |
| Sending data | 0.000019 | 0 | 0 |
| end | 0.000016 | 0 | 0 |
| query end | 0.000006 | 0 | 0 |
| closing tables | 0.000002 | 0 | 0 |
| removing tmp table | 0.000004 | 0 | 0 |
| closing tables | 0.000016 | 0 | 0 |
| freeing items | 0.000013 | 0 | 0 |
| cleaning up | 0.000036 | 0 | 0 |
+----------------------+----------+-------------------+---------------------+
17 rows in set, 1 warning (0.00 sec)
cpu
mysql> show profile cpu for query 7;
+----------------------+----------+----------+------------+
| Status | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| starting | 0.000053 | 0.000000 | 0.000000 |
| checking permissions | 0.000006 | 0.000000 | 0.000000 |
| Opening tables | 0.000014 | 0.000000 | 0.000000 |
| init | 0.000056 | 0.000000 | 0.000000 |
| System lock | 0.000055 | 0.000000 | 0.000000 |
| optimizing | 0.000006 | 0.000000 | 0.000000 |
| statistics | 0.000008 | 0.000000 | 0.000000 |
| preparing | 0.000007 | 0.000000 | 0.000000 |
| executing | 0.000002 | 0.000000 | 0.000000 |
| Sending data | 0.003099 | 0.002000 | 0.000000 |
| end | 0.000006 | 0.000000 | 0.000000 |
| query end | 0.000007 | 0.000000 | 0.000000 |
| closing tables | 0.000006 | 0.000000 | 0.000000 |
| freeing items | 0.000396 | 0.001000 | 0.000000 |
| cleaning up | 0.000050 | 0.000000 | 0.000000 |
+----------------------+----------+----------+------------+
15 rows in set, 1 warning (0.00 sec)
ipc
mysql> show profile ipc for query 1;
+----------------------+----------+---------------+-------------------+
| Status | Duration | Messages_sent | Messages_received |
+----------------------+----------+---------------+-------------------+
| starting | 0.000089 | 0 | 0 |
| checking permissions | 0.000025 | 0 | 0 |
| Opening tables | 0.000062 | 0 | 0 |
| init | 0.000036 | 0 | 0 |
| System lock | 0.000007 | 0 | 0 |
| optimizing | 0.000004 | 0 | 0 |
| statistics | 0.000023 | 0 | 0 |
| preparing | 0.000039 | 0 | 0 |
| executing | 0.000910 | 0 | 0 |
| Sending data | 0.000019 | 0 | 0 |
| end | 0.000016 | 0 | 0 |
| query end | 0.000006 | 0 | 0 |
| closing tables | 0.000002 | 0 | 0 |
| removing tmp table | 0.000004 | 0 | 0 |
| closing tables | 0.000016 | 0 | 0 |
| freeing items | 0.000013 | 0 | 0 |
| cleaning up | 0.000036 | 0 | 0 |
+----------------------+----------+---------------+-------------------+
17 rows in set, 1 warning (0.00 sec)
page faults
mysql> show profile page faults for query 1;
+----------------------+----------+-------------------+-------------------+
| Status | Duration | Page_faults_major | Page_faults_minor |
+----------------------+----------+-------------------+-------------------+
| starting | 0.000089 | 0 | 0 |
| checking permissions | 0.000025 | 0 | 0 |
| Opening tables | 0.000062 | 0 | 0 |
| init | 0.000036 | 0 | 0 |
| System lock | 0.000007 | 0 | 0 |
| optimizing | 0.000004 | 0 | 0 |
| statistics | 0.000023 | 0 | 0 |
| preparing | 0.000039 | 0 | 0 |
| executing | 0.000910 | 0 | 1 |
| Sending data | 0.000019 | 0 | 0 |
| end | 0.000016 | 0 | 0 |
| query end | 0.000006 | 0 | 0 |
| closing tables | 0.000002 | 0 | 0 |
| removing tmp table | 0.000004 | 0 | 0 |
| closing tables | 0.000016 | 0 | 0 |
| freeing items | 0.000013 | 0 | 0 |
| cleaning up | 0.000036 | 0 | 0 |
+----------------------+----------+-------------------+-------------------+
17 rows in set, 1 warning (0.00 sec)
source
swaps
# swaps
mysql> show profile swaps for query 7;
+----------------------+----------+-------+
| Status | Duration | Swaps |
+----------------------+----------+-------+
| starting | 0.000053 | 0 |
| checking permissions | 0.000006 | 0 |
| Opening tables | 0.000014 | 0 |
| init | 0.000056 | 0 |
| System lock | 0.000055 | 0 |
| optimizing | 0.000006 | 0 |
| statistics | 0.000008 | 0 |
| preparing | 0.000007 | 0 |
| executing | 0.000002 | 0 |
| Sending data | 0.003099 | 0 |
| end | 0.000006 | 0 |
| query end | 0.000007 | 0 |
| closing tables | 0.000006 | 0 |
| freeing items | 0.000396 | 0 |
| cleaning up | 0.000050 | 0 |
+----------------------+----------+-------+
15 rows in set, 1 warning (0.00 sec)
來源:www.cnblogs.com/Courage129/p/14187...
本作品採用《CC 協議》,轉載必須註明作者和本文連結