Mysql優化_內建profiling效能分析工具

OldBoy~發表於2017-05-17

如果要進行SQL的調優優化和排查,第一步是先讓故障重現,但是這個並不是這一分鐘有問題,下一秒就OK。
一般的企業一般是DBA資料庫工程師從監控裡找到問題。DBA會告訴我們讓我們來排查問題,那麼可能很多種原因,也許是程式記憶體洩漏、也許是網路、也許是死鎖、也許是SQL寫的爛。假設是SQL問題我們需要把SQL抓出,一般就是在測試環境跑一下SQL,重現故障。首先開啟我們的慢查詢日誌,這樣把有問題的SQL排查出來,然後用EXPLAIN分析一下,一般到了這一步應該會找到相應問題所在。但是如果還是沒有解決,SQL在傳輸網路、連結、是否是死鎖等各方面都再有一個更加詳細的排查,那麼show profile就可以幫忙解決了。
差不多到了這,基本上95%的問題解決了,那麼最後如果通過前面問題的分析,解決的問題還是一般般,那麼就需要配合DBA看看mysql配置檔案各方面的引數節點配置進行調優了。

show profile是什麼?是Mysql提供可以用來分析當前會話中語句執行的資源消耗情況。可以用於SQL的調優測量。
預設情況下引數處於關閉狀態,開啟後儲存最近15次的執行結果。
假設一條SQL執行完成之後,10秒鐘,這麼慢,那麼能不能有一張清單告訴你你到底是多少個步驟,比如第一步花了1.34秒,第二步花了2.44秒...累積達到10秒,show profile就有這樣的功能。

SQL導致伺服器慢要麼就是CPU運算複雜要麼就是頻繁IO。
MySQL 的 Query Profiler 是一個使用非常方便的 Query 診斷分析工具,通過該工具可以獲取一條Query 在整個執行過程中多種資源的消耗情況,如 CPU,IO,IPC,SWAP 等,以及發生的 PAGE FAULTS,CONTEXT SWITCHE 等等,同時還能得到該 Query 執行過程中 MySQL 所呼叫的各個函式在原始檔中的位置。

MySQL [test_db]> show variables like '%profiling%';  //檢視是否開啟
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| have_profiling         | YES   |
| profiling              | ON    |
| profiling_history_size | 15    |
+------------------------+-------+
MySQL [test_db]> set profiling=on;  //開啟show profiling
Query OK, 0 rows affected, 1 warning (0.00 sec)
reset cache query; //清空SQL快取
select * from table where... order by desc limit 0,100;  //執行SQL
show profiles;    //獲取系統中儲存的所有query的profile概要資訊
MySQL [test_db]> show profiles;
+----------+------------+-------------------------------------------------+
| Query_ID | Duration   | Query                                           |
+----------+------------+-------------------------------------------------+
|        5 | 0.00099825 | select * from emp order by id desc limit 0,60   |
|        6 | 0.00004150 | select * from emp order by id desc limit 0,60   |
|        7 | 0.00007300 | select * from emp order by id desc limit 0,60   |
|        8 | 0.00010325 | select * from emp order by id desc limit 0,60   |
|        9 | 0.00011000 | select * from emp order by id desc limit 0,60   |
|       10 | 0.00007025 | select * from emp order by id desc limit 0,60   |
|       11 | 0.00005275 | select * from emp order by id desc limit 0,60   |
|       12 | 0.00004050 | select * from emp order by id desc limit 0,60   |
|       13 | 0.00009000 | select * from emp order by id desc limit 0,60   |
|       14 | 0.10676625 | select * from emp order by id desc limit 0,50   |
|       15 | 7.02310450 | select * from emp order by id desc limit 150000 |
|       16 | 3.90775625 | select * from emp order by id desc limit 150000 |
|       17 | 2.96361950 | select * from emp order by id desc limit 150000 |
|       18 | 0.19119000 | set profiling=1                                 |
|       19 | 0.10549050 | select count(*) from emp                        |
+----------+------------+-------------------------------------------------+

三列分別是查詢ID,執行時間,執行SQL

在獲取到概要資訊之後,就可以根據概要資訊中的 Query_ID 來獲取某個 Query 在執行過程中,以19為例

MySQL [test_db]> show profile cpu,block io for query 19;
MySQL [test_db]> MySQL [test_db]> show profile cpu,block io for query 19;
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status                         | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| starting                       | 0.000037 | 0.000000 |   0.000000 |            0 |             0 |  //開始連線
| Waiting for query cache lock   | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |  //找快取
| starting                       | 0.000001 | 0.000000 |   0.000000 |            0 |             0 |
| checking query cache for query | 0.104519 | 0.000000 |   0.001000 |          232 |             0 |
| checking permissions           | 0.000011 | 0.000000 |   0.000000 |            0 |             0 |  //驗證許可權
| Opening tables                 | 0.000014 | 0.000000 |   0.000000 |            0 |             0 |
| init                           | 0.000787 | 0.000000 |   0.000000 |          168 |             0 |
| System lock                    | 0.000017 | 0.000000 |   0.000000 |            0 |             0 |
| Waiting for query cache lock   | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |
| System lock                    | 0.000013 | 0.000000 |   0.000000 |            0 |             0 |
| optimizing                     | 0.000010 | 0.000000 |   0.000000 |            0 |             0 |
| executing                      | 0.000009 | 0.000000 |   0.000000 |            0 |             0 |
| end                            | 0.000003 | 0.000000 |   0.000000 |            0 |             0 |
| query end                      | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |
| closing tables                 | 0.000031 | 0.000000 |   0.000000 |            0 |             0 |
| freeing items                  | 0.000010 | 0.000000 |   0.000000 |            0 |             0 |
| Waiting for query cache lock   | 0.000001 | 0.000000 |   0.000000 |            0 |             0 |  
| freeing items                  | 0.000013 | 0.000000 |   0.000000 |            0 |             0 |
| Waiting for query cache lock   | 0.000001 | 0.000000 |   0.000000 |            0 |             0 |
| freeing items                  | 0.000001 | 0.000000 |   0.000000 |            0 |             0 |
| storing result in query cache  | 0.000003 | 0.000000 |   0.000000 |            0 |             0 |
| cleaning up                    | 0.000002 | 0.000000 |   0.000000 |            0 |             0 |
+--------------------------------+----------+----------+------------+--------------+---------------+

上面結果顯示了完整的生命週期過程。

如果出現以下四種情況之一,那麼就有問題!

converting HEAP to MyISAM查詢結果太大,記憶體不夠用了往磁碟上搬了。
Creating tmp table 建立了臨時表,拷貝資料到臨時表,用完再刪除
Copying to tmp table on disk ,把記憶體中臨時表複製到磁碟,很危險!
locked,鎖了。

相關文章