show profiles mysql查詢優化之profile

時間 2019-11-12

標籤 profiles mysql 查詢優化 profile 欄目 MySQL 简体版

原文原文鏈接

當mysql遇到性能瓶頸時，從mysql自己出發去優化大體分爲兩個方面。一個是調整mysql的配置參數，另外一個是優化查詢sql了。mysql

查看sql運行時間是必不可少的，這時候profile就至關重要了。linux

一、查看profile是否打開，如下三種方法都的能夠的。sql

mysql> show profiles;
Empty set, 1 warning (0.00 sec)

mysql> show variables like "profiling%";
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| profiling              | OFF   |
| profiling_history_size | 15    |
+------------------------+-------+
2 rows in set (0.00 sec)

mysql>

mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
|           0 |
+-------------+
1 row in set, 1 warning (0.00 sec)

mysql>

以上結果能夠看出，profile沒有打開。咱們在當前Session會話狀態打開profile；函數

二、當前Session會話狀態打開profile工具

開啓 Query Profiler 功能以後，MySQL 就會自動記錄全部執行的 Query 的 profile 信息了。性能

mysql> set profiling=1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show variables like "profiling";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling     | ON    |
+---------------+-------+
1 row in set (0.00 sec)

mysql>

三、查看sql運行時間優化

獲取系統中保存的全部 Query 的 profile 概要信息spa

mysql> show databases;
+---------------------+
| Database            |
+---------------------+
| yw_mdmall           |
+---------------------+
1 rows in set (0.00 sec)

mysql> use yw_mdmall;
Database changed
mysql> select id from yw_order limit 10;
+----+
| id |
+----+
|  2 |
|  3 |
|  4 |
|  5 |
|  6 |
|  7 |
|  8 |
|  9 |
| 10 |
| 11 |
+----+
10 rows in set (0.00 sec)

mysql> show profiles;
+----------+------------+----------------------------------+
| Query_ID | Duration   | Query                            |
+----------+------------+----------------------------------+
|        1 | 0.00036950 | show databases                   |
|        2 | 0.00010925 | SELECT DATABASE()                |
|        3 | 0.00021900 | select id from yw_order limit 10 |
+----------+------------+----------------------------------+
3 rows in set, 1 warning (0.00 sec)

mysql>

查看最後一條sql的執行詳細信息.net

經過執行「SHOW PROFILE」命令獲取當前系統中保存的多個 Query 的 profile 的概要信息。htm

mysql> show profile;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000055 |
| checking permissions | 0.000009 |
| Opening tables       | 0.000023 |
| init                 | 0.000017 |
| System lock          | 0.000008 |
| optimizing           | 0.000006 |
| statistics           | 0.000013 |
| preparing            | 0.000012 |
| executing            | 0.000003 |
| Sending data         | 0.000038 |
| end                  | 0.000005 |
| query end            | 0.000007 |
| closing tables       | 0.000008 |
| freeing items        | 0.000012 |
| cleaning up          | 0.000005 |
+----------------------+----------+
15 rows in set, 1 warning (0.00 sec)

mysql>

查看指定 Query_ID 對應sql的執行詳細信息

mysql> show profile for query 3;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000055 |
| checking permissions | 0.000009 |
| Opening tables       | 0.000023 |
| init                 | 0.000017 |
| System lock          | 0.000008 |
| optimizing           | 0.000006 |
| statistics           | 0.000013 |
| preparing            | 0.000012 |
| executing            | 0.000003 |
| Sending data         | 0.000038 |
| end                  | 0.000005 |
| query end            | 0.000007 |
| closing tables       | 0.000008 |
| freeing items        | 0.000012 |
| cleaning up          | 0.000005 |
+----------------------+----------+
15 rows in set, 1 warning (0.00 sec)

mysql> show profile for query 2;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000041 |
| checking permissions | 0.000008 |
| Opening tables       | 0.000007 |
| init                 | 0.000012 |
| optimizing           | 0.000006 |
| executing            | 0.000008 |
| end                  | 0.000005 |
| query end            | 0.000004 |
| closing tables       | 0.000004 |
| freeing items        | 0.000011 |
| cleaning up          | 0.000005 |
+----------------------+----------+
11 rows in set, 1 warning (0.00 sec)

mysql> 
mysql> show profile for query 1;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000032 |
| checking permissions | 0.000006 |
| Opening tables       | 0.000042 |
| init                 | 0.000008 |
| System lock          | 0.000005 |
| optimizing           | 0.000004 |
| statistics           | 0.000010 |
| preparing            | 0.000011 |
| executing            | 0.000185 |
| Sending data         | 0.000023 |
| end                  | 0.000005 |
| query end            | 0.000004 |
| closing tables       | 0.000003 |
| removing tmp table   | 0.000013 |
| closing tables       | 0.000004 |
| freeing items        | 0.000011 |
| cleaning up          | 0.000005 |
+----------------------+----------+
17 rows in set, 1 warning (0.00 sec)

查看最後一條sql的執行 cpu、io、內存、交換內存等信息

mysql> show profile cpu,block io,memory,swaps,context switches,source for query 3;
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+-----------------------+------------------+-------------+
| Status               | Duration | CPU_user | CPU_system | Context_voluntary | Context_involuntary | Block_ops_in | Block_ops_out | Swaps | Source_function       | Source_file      | Source_line |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+-----------------------+------------------+-------------+
| starting             | 0.000055 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | NULL                  | NULL             |        NULL |
| checking permissions | 0.000009 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | check_access          | sql_parse.cc     |        5268 |
| Opening tables       | 0.000023 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | open_tables           | sql_base.cc      |        4934 |
| init                 | 0.000017 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | mysql_prepare_select  | sql_select.cc    |        1050 |
| System lock          | 0.000008 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | mysql_lock_tables     | lock.cc          |         304 |
| optimizing           | 0.000006 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | optimize              | sql_optimizer.cc |         138 |
| statistics           | 0.000013 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | optimize              | sql_optimizer.cc |         362 |
| preparing            | 0.000012 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | optimize              | sql_optimizer.cc |         485 |
| executing            | 0.000003 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | exec                  | sql_executor.cc  |         110 |
| Sending data         | 0.000038 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | exec                  | sql_executor.cc  |         190 |
| end                  | 0.000005 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | mysql_execute_select  | sql_select.cc    |        1105 |
| query end            | 0.000007 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | mysql_execute_command | sql_parse.cc     |        4967 |
| closing tables       | 0.000008 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | mysql_execute_command | sql_parse.cc     |        5015 |
| freeing items        | 0.000012 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | mysql_parse           | sql_parse.cc     |        6294 |
| cleaning up          | 0.000005 | 0.000000 |   0.000000 |                 0 |                   0 |            0 |             0 |     0 | dispatch_command      | sql_parse.cc     |        1774 |
+----------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+-------+-----------------------+------------------+-------------+
15 rows in set, 1 warning (0.00 sec)

mysql>

mysql> show profile block io,cpu for query 3;
+----------------------+----------+----------+------------+--------------+---------------+
| Status               | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+----------------------+----------+----------+------------+--------------+---------------+
| starting             | 0.000056 | 0.000000 |   0.000000 |            0 |             0 |
| checking permissions | 0.000009 | 0.000000 |   0.000000 |            0 |             0 |
| Opening tables       | 0.000023 | 0.000000 |   0.000000 |            0 |             0 |
| init                 | 0.000017 | 0.000000 |   0.000000 |            0 |             0 |
| System lock          | 0.000008 | 0.000000 |   0.000000 |            0 |             0 |
| optimizing           | 0.000006 | 0.000000 |   0.000000 |            0 |             0 |
| statistics           | 0.000012 | 0.000000 |   0.000000 |            0 |             0 |
| preparing            | 0.000012 | 0.000000 |   0.000000 |            0 |             0 |
| executing            | 0.000003 | 0.000000 |   0.000000 |            0 |             0 |
| Sending data         | 0.000039 | 0.000000 |   0.000000 |            0 |             0 |
| end                  | 0.000005 | 0.000000 |   0.000000 |            0 |             0 |
| query end            | 0.000007 | 0.000000 |   0.000000 |            0 |             0 |
| closing tables       | 0.000009 | 0.000000 |   0.000000 |            0 |             0 |
| freeing items        | 0.000012 | 0.000000 |   0.000000 |            0 |             0 |
| cleaning up          | 0.000004 | 0.000000 |   0.000000 |            0 |             0 |
+----------------------+----------+----------+------------+--------------+---------------+
15 rows in set, 1 warning (0.00 sec)

mysql>

小結：要想優化一條 Query，咱們就須要清楚的知道這條 Query 的性能瓶頸到底在哪裏，是消耗的 CPU計算太多，仍是須要的的 IO 操做太多？要想可以清楚的瞭解這些信息，在 MySQL 5.0 和 MySQL 5.1正式版中已經能夠很是容易作到了（Mysql 5.0.37 以後，自帶SHOW PROFILES and SHOW PROFILE 功能模塊），那就是經過 Query Profiler 功能。

MySQL 的 Query Profiler 是一個使用很是方便的 Query 診斷分析工具，經過該工具能夠獲取一條Query 在整個執行過程當中多種資源的消耗狀況，如 CPU，IO，IPC，SWAP 等，以及發生的 PAGE FAULTS，CONTEXT SWITCHE 等等，同時還能獲得該 Query 執行過程當中 MySQL 所調用的各個函數在源文件中的位置。

另外一文：http://linuxgeek.blog.51cto.com/6014609/995243

在mysql的表鎖定機制中，select語句的優先級比update低。因此此select語句一直在鎖隊列中等待，後來的update操做會插隊到select語句前面。致使Sending data時間很長

解決方法最簡單的：

select HIGH_PRIORITY * from searchzh where modified_date > '2009-09-02 14:45:22';指定該select語句具備高優先級。

另外一文：http://www.jb51.net/article/82739.htm

問題出如今字段屬性上，改表結構