《高效能MySQL》學習筆記——第三章 伺服器效能剖析
第三章 伺服器效能剖析
(1)效能剖析(profiling):用於測試伺服器的時間花費在哪裡。
本書對資料庫效能的定義:是指完成某件任務所需要的時間度量,即響應時間,每個SQL語句的查詢話費的時間。
完成一項任務所需要的時間可以分成兩部分:執行時間和等待時間(如IO等待)。
(2)效能剖析有兩個步驟:
-
測量任務所花費的時間;
-
對結果進行統計分析,均值、方差、分佈、計算特定的指標分析等。
(3)效能剖析本身會導致伺服器變慢嗎?
當然會,因為要做額外的工作付出額外的開銷。但是如果效能剖析可以幫助應用程式執行得更快,那麼效能剖析就使值得的。
(4)慢查詢日誌和通用日誌
慢查詢日誌是指捕獲所有查詢時間超過long_query_time的查詢,將其SQL語句和消耗時間記錄到日誌中。可以設定long_query_time = 0來捕獲所有SQL。慢查詢日誌是開銷最低、精度最高的測量查詢時間的工具。
通用日誌是指查詢請求到伺服器時記錄,不包含響應時間和執行計劃等重要資訊。
將慢查詢日誌生成剖析報告的工具:pt-query-digest(十年前給力,2020年需根據實際情況使用更好的工具)。
(5)SHOW PROFILES
SHOW PROFILES 命令可以對每條SQL進行效能剖析,預設是禁用的,使用set profiling = 1開啟對當前執行緒的SQL進行剖析。
SHOW PROFILE FOR QUERY N 命令可以展示記錄的id為N的查詢每個執行步驟的詳細時間記錄。
也可以查詢每個查詢的所有詳細步驟資訊:SELECT * FROM INFORMATION_SCHEMA.FROFILING;
mysql> set profiling = 1; Query OK, 0 rows affected, 1 warning (0.00 sec) mysql> select 1; +---+ | 1 | +---+ | 1 | +---+ 1 row in set (0.00 sec) mysql> show profiles; +----------+------------+----------+ | Query_ID | Duration | Query | +----------+------------+----------+ | 1 | 0.00043725 | select 1 | +----------+------------+----------+ 1 row in set, 1 warning (0.00 sec) mysql> select 2; +---+ | 2 | +---+ | 2 | +---+ 1 row in set (0.00 sec) mysql> show profiles; +----------+------------+----------+ | Query_ID | Duration | Query | +----------+------------+----------+ | 1 | 0.00043725 | select 1 | | 2 | 0.00042800 | select 2 | +----------+------------+----------+ 2 rows in set, 1 warning (0.00 sec) mysql> set profiling = 0; Query OK, 0 rows affected, 1 warning (0.00 sec) mysql> select 3; +---+ | 3 | +---+ | 3 | +---+ 1 row in set (0.00 sec) mysql> show profiles; +----------+------------+----------+ | Query_ID | Duration | Query | +----------+------------+----------+ | 1 | 0.00043725 | select 1 | | 2 | 0.00042800 | select 2 | +----------+------------+----------+ 2 rows in set, 1 warning (0.00 sec) mysql> show profile for query 1; +----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000116 | | checking permissions | 0.000007 | | Opening tables | 0.000013 | | init | 0.000005 | | optimizing | 0.000008 | | executing | 0.000051 | | end | 0.000004 | | query end | 0.000005 | | closing tables | 0.000002 | | freeing items | 0.000043 | | cleaning up | 0.000186 | +----------------------+----------+ 11 rows in set, 1 warning (0.00 sec) mysql> select * from information_schema.profiling; +----------+-----+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+ | QUERY_ID | SEQ | STATE | DURATION | CPU_USER | CPU_SYSTEM | CONTEXT_VOLUNTARY | CONTEXT_INVOLUNTARY | BLOCK_OPS_IN | BLOCK_OPS_OUT | MESSAGES_SENT | MESSAGES_RECEIVED | PAGE_FAULTS_MAJOR | PAGE_FAULTS_MINOR | SWAPS | SOURCE_FUNCTION | SOURCE_FILE | SOURCE_LINE | +----------+-----+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+ | 1 | 2 | starting | 0.000116 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | | 1 | 3 | checking permissions | 0.000007 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | check_access | sql_authorization.cc | 2203 | | 1 | 4 | Opening tables | 0.000013 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | open_tables | sql_base.cc | 5590 | | 1 | 5 | init | 0.000005 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | Sql_cmd_dml::execute | sql_select.cc | 662 | | 1 | 6 | optimizing | 0.000008 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | JOIN::optimize | sql_optimizer.cc | 217 | | 1 | 7 | executing | 0.000051 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | JOIN::exec | sql_executor.cc | 227 | | 1 | 8 | end | 0.000004 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | Sql_cmd_dml::execute | sql_select.cc | 715 | | 1 | 9 | query end | 0.000005 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | mysql_execute_command | sql_parse.cc | 4547 | | 1 | 10 | closing tables | 0.000002 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | mysql_execute_command | sql_parse.cc | 4593 | | 1 | 11 | freeing items | 0.000043 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | mysql_parse | sql_parse.cc | 5264 | | 1 | 12 | cleaning up | 0.000186 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | dispatch_command | sql_parse.cc | 2159 | | 2 | 2 | starting | 0.000130 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | | 2 | 3 | checking permissions | 0.000011 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | check_access | sql_authorization.cc | 2203 | | 2 | 4 | Opening tables | 0.000023 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | open_tables | sql_base.cc | 5590 | | 2 | 5 | init | 0.000009 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | Sql_cmd_dml::execute | sql_select.cc | 662 | | 2 | 6 | optimizing | 0.000009 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | JOIN::optimize | sql_optimizer.cc | 217 | | 2 | 7 | executing | 0.000012 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | JOIN::exec | sql_executor.cc | 227 | | 2 | 8 | end | 0.000004 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | Sql_cmd_dml::execute | sql_select.cc | 715 | | 2 | 9 | query end | 0.000006 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | mysql_execute_command | sql_parse.cc | 4547 | | 2 | 10 | closing tables | 0.000094 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | mysql_execute_command | sql_parse.cc | 4593 | | 2 | 11 | freeing items | 0.000112 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | mysql_parse | sql_parse.cc | 5264 | | 2 | 12 | cleaning up | 0.000019 | 0.000000 | 0.000000 | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | NULL | dispatch_command | sql_parse.cc | 2159 | +----------+-----+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+-----------------------+----------------------+-------------+ 22 rows in set, 1 warning (0.00 sec)
(6)SHOW STATUS
SHOW STATUS 命令可以檢視計數器統計到的值,如統計了查詢的次數、使用某個索引的次數。雖然無法展示使用時間,但還是可以通過觀察哪些操作執行的更頻繁。最有用的計數器有:控制代碼計數器(handler counter)、臨時檔案和表計數器等。
mysql> SHOW STATUS WHERE VARIABLE_NAME LIKE 'Handler%' OR VARIABLE_NAME LIKE 'Created%';
+----------------------------+-------+
| Variable_name | Value |
+----------------------------+-------+
| Created_tmp_disk_tables | 0 |
| Created_tmp_files | 5 |
| Created_tmp_tables | 3 |
| Handler_commit | 3 |
| Handler_delete | 0 |
| Handler_discover | 0 |
| Handler_external_lock | 90 |
| Handler_mrr_init | 0 |
| Handler_prepare | 0 |
| Handler_read_first | 0 |
| Handler_read_key | 3 |
| Handler_read_last | 0 |
| Handler_read_next | 0 |
| Handler_read_prev | 0 |
| Handler_read_rnd | 0 |
| Handler_read_rnd_next | 58 |
| Handler_rollback | 0 |
| Handler_savepoint | 0 |
| Handler_savepoint_rollback | 0 |
| Handler_update | 0 |
| Handler_write | 55 |
+----------------------------+-------+
21 rows in set (0.00 sec)
FLASH STATUS; -- 該命令作用是重置計數器
通過重置計數器,並測試一條SQL,就可以獲取這條SQL的執行時各個計數器的值。EXPLAIN 得到的是估計的結果,而通過 SHOW STATUS 統計計數器的值測量到的是實際發生的結果。
(7)間歇性問題
舉例:一個SQL查詢正常情況下很快,但是有幾次不合理的特別慢,手工執行下也很快,EXPLAIN 和 SHOW STATUS 中都正確使用了索引,嘗試修改WHERE 條件排除快取命中的可能,也沒有什麼問題,這種情況下很難查出來是什麼原因導致這幾次SQL執行很慢,可能是正在備份,或某種型別的鎖,或爭用阻塞了SQL的進度等,這種問題就使間歇性問題。書中對間歇性問題的建議是不要花費太多時間去找出問題所在,更不能用試錯的方式來解決問題,可以通過以下思路進行嘗試:
-
先確定到底是伺服器問題還是單條SQL的問題
-
使用SHOW GLOBAL STATUS
-
使用SHOW PROCESSLIST
-
使用慢查詢日誌
以上兩個方法都是通過不停的捕獲命令的輸出,觀察異常值等其他特徵,來進行診斷。第三個方法是檢視慢查詢日誌中吞吐量突然下降時間段結束後的那一部分日誌,再具體分析哪個SQL導致緩慢。以上三個方法在書中都有具體例子,有需要可以自行看書。書中建議從第1、2兩種方法開始查詢問題,這兩個方法開銷最低。
-
-
有必要再捕獲診斷資料
- 觸發器:根據實際情況設計觸發指標和觸發條件,使用合理工具(如pt-talk和pt-collect)收集資料給觸發器去判斷。
(8)一個診斷案例
略,有需要可以自行看書。
(9)使用information_schema
稍後整理一個information_schema庫的專題講解。