show profile分析SQL · Mysql高級

# show profile分析SQL Mysql從5.0.37版本開始增加了對 show profiles 和 show profile 語句的支持。show profiles 能夠在做SQL優化時幫助我們了解時間都耗費到哪里去了。 ## 開啟show profile ```sql set profiling=1; //開啟profiling 開關； ``` ## 通過profile，我們能夠更清楚地了解SQL執行的過程。 **示例1：** ~~~ mysql> select * from t_user; +----+----------+--------------------------------------------------------------+--------+ | id | username | password | name | +----+----------+--------------------------------------------------------------+--------+ | 1 | super | $2a$10$TJ4TmCdK.X4wv/tCqHW14.w70U3CC33CeVncD3SLmyMXMknstqKRe | ????? | | 2 | admin | $2a$10$TJ4TmCdK.X4wv/tCqHW14.w70U3CC33CeVncD3SLmyMXMknstqKRe | ????? | | 3 | itcast | $2a$10$8qmaHgUFUAmPR5pOuWhYWOr291WJYjHelUlYn07k5ELF8ZCrW0Cui | test02 | | 4 | stu1 | $2a$10$pLtt2KDAFpwTWLjNsmTEi.oU1yOZyIn9XkziK/y/spH5rftCpUMZa | ??1 | | 5 | stu2 | $2a$10$nxPKkYSez7uz2YQYUnwhR.z57km3yqKn3Hr/p1FR6ZKgc18u.Tvqm | ??2 | | 6 | t1 | $2a$10$TJ4TmCdK.X4wv/tCqHW14.w70U3CC33CeVncD3SLmyMXMknstqKRe | ??1 | +----+----------+--------------------------------------------------------------+--------+ 6 rows in set (0.00 sec) mysql> show profiles; +----------+------------+------------------------------------+ | Query_ID | Duration | Query | +----------+------------+------------------------------------+ | 1 | 0.00422300 | select * from tb_item where id < 5 | | 2 | 0.00370000 | show tables | | 3 | 0.00065000 | select * from t_user | +----------+------------+------------------------------------+ 3 rows in set, 1 warning (0.00 sec) ~~~ **示例2：** **通過show profile for query query_id 語句可以查看到該SQL執行過程中每個線程的狀態和消耗的時間：** ~~~ mysql> show profile for query 3; +--------------------------------+----------+ | Status | Duration | +--------------------------------+----------+ | starting | 0.000103 | | Executing hook on transaction | 0.000014 | | starting | 0.000007 | | checking permissions | 0.000017 | | Opening tables | 0.000106 | | init | 0.000021 | | System lock | 0.000027 | | optimizing | 0.000023 | | statistics | 0.000092 | | preparing | 0.000028 | | executing | 0.000003 | | Sending data | 0.000073 | | end | 0.000004 | | query end | 0.000003 | | waiting for handler commit | 0.000007 | | closing tables | 0.000007 | | freeing items | 0.000012 | | cleaning up | 0.000103 | +--------------------------------+----------+ 18 rows in set, 1 warning (0.00 sec) ~~~ ~~~ TIP ： Sending data 狀態表示MySQL線程開始訪問數據行并把結果返回給客戶端，而不僅僅是返回個客戶端。由于在Sending data狀態下，MySQL線程往往需要做大量的磁盤讀取操作，所以經常是整各查詢中耗時最長的狀態。 ~~~ 在獲取到最消耗時間的線程狀態后，MySQL支持進一步選擇all、cpu、block io 、context switch、page faults等明細類型類查看MySQL在使用什么資源上耗費了過高的時間。例如，選擇查看CPU的耗費時間： ~~~ mysql> show profile cpu for query 3; +--------------------------------+----------+----------+------------+ | Status | Duration | CPU_user | CPU_system | +--------------------------------+----------+----------+------------+ | starting | 0.000103 | 0.000052 | 0.000051 | | Executing hook on transaction | 0.000014 | 0.000003 | 0.000010 | | starting | 0.000007 | 0.000006 | 0.000002 | | checking permissions | 0.000017 | 0.000005 | 0.000012 | | Opening tables | 0.000106 | 0.000037 | 0.000069 | | init | 0.000021 | 0.000007 | 0.000014 | | System lock | 0.000027 | 0.000009 | 0.000017 | | optimizing | 0.000023 | 0.000005 | 0.000018 | | statistics | 0.000092 | 0.000021 | 0.000071 | | preparing | 0.000028 | 0.000012 | 0.000016 | | executing | 0.000003 | 0.000002 | 0.000002 | | Sending data | 0.000073 | 0.000043 | 0.000030 | | end | 0.000004 | 0.000003 | 0.000001 | | query end | 0.000003 | 0.000002 | 0.000001 | | waiting for handler commit | 0.000007 | 0.000005 | 0.000001 | | closing tables | 0.000007 | 0.000006 | 0.000001 | | freeing items | 0.000012 | 0.000006 | 0.000007 | | cleaning up | 0.000103 | 0.000021 | 0.000082 | +--------------------------------+----------+----------+------------+ 18 rows in set, 1 warning (0.00 sec) ~~~ | 字段 | 含義 | | ---------- | ------------------------------ | | Status | sql 語句執行的狀態 | | Duration | sql 執行過程中每一個步驟的耗時 | | CPU_user | 當前用戶占有的cpu | | CPU_system | 系統占有的cpu |