為了系統(tǒng)的整理MySQL 性能優(yōu)化方面的知識，這里收集部分好文章，方便自己學(xué)習(xí)。

performance-schema （三）

前一篇文章我們分析了Performance-Schema中每個表的用途，以及主要字段的含義，比較側(cè)重于理論的介紹。這篇文章我主要從DBA的角度出發(fā)，詳細(xì)介紹如何通過Performance-Schema得到DBA關(guān)心的數(shù)據(jù)，比如哪個SQL執(zhí)行次數(shù)最多，哪個表訪問最頻繁，哪個鎖最熱等信息。通過充分利用Performance-Schema表的數(shù)據(jù)，讓DBA更了解DB的運(yùn)行狀態(tài)，也更有助于排查定位問題。本文主要從兩方面展開討論，第一方面是統(tǒng)計信息維度，包括SQL維度，對象維度和等待事件維度三小點；第二方面是定位分析問題維度，結(jié)合實際應(yīng)用場景，利用Performance-Schema搜集的數(shù)據(jù)進(jìn)行分析。

統(tǒng)計信息(SQL維度)
? ? ?關(guān)于SQL維度的統(tǒng)計信息主要集中在events_statements_summary_by_digest表中，通過將SQL語句抽象出digest，可以統(tǒng)計某類SQL語句在各個維度的統(tǒng)計信息(比如：執(zhí)行次數(shù)，排序次數(shù)，使用臨時表等)
(1).哪類SQL執(zhí)行最多？

SELECT DIGEST_TEXT,COUNT_STAR,FIRST_SEEN,LAST_SEEN FROM events_statements_summary_by_digest ORDER BY COUNT_STAR DESC limit 1\G *************************** 1. row *************************** DIGEST_TEXT: SELECT `pay_order_id` , `total_fee` , `pay_seller_id` , `pay_buyer_id` , `buyer_id` , `seller_id` FROM `pay_order` WHERE `pay_order_id` = ? COUNT_STAR: 5282893 FIRST_SEEN: 2015-12-15 18:25:38 LAST_SEEN: 2015-12-18 16:20:59

可以看到執(zhí)行次數(shù)最多的SQL是“SELECT `pay_order_id` , `total_fee` , `pay_seller_id` , pay_buyer_id , buyer_id , seller_id FROM tc_pay_order WHERE pay_order_id = ?”，FIRST_SEEN和LAST_SEEN分別顯示了語句第一次執(zhí)行和最后一次執(zhí)行的時間點。
(2).哪類SQL的平均響應(yīng)時間最多？
AVG_TIMER_WAIT
(3).哪類SQL排序記錄數(shù)最多？
SUM_SORT_ROWS
(4).哪類SQL掃描記錄數(shù)最多？
SUM_ROWS_EXAMINED
(5).哪類SQL使用臨時表最多？
SUM_CREATED_TMP_TABLES,SUM_CREATED_TMP_DISK_TABLES
(6).哪類SQL返回結(jié)果集最多？
SUM_ROWS_SENT
? ? ?通過上述指標(biāo)我們可以間接獲得某類SQL的邏輯IO(SUM_ROWS_EXAMINED)，CPU消耗(SUM_SORT_ROWS)，網(wǎng)絡(luò)帶寬(SUM_ROWS_SENT)的對比，但還無法得到某類SQL的物理IO消耗，以及某類SQL訪問數(shù)據(jù)的buffer命中率。

統(tǒng)計信息(對象維度)
(1).哪個表物理IO最多？

SELECT file_name,event_name,SUM_NUMBER_OF_BYTES_READ,SUM_NUMBER_OF_BYTES_WRITE FROM file_summary_by_instance ORDER BY SUM_NUMBER_OF_BYTES_READ + SUM_NUMBER_OF_BYTES_WRITE DESC LIMIT 1\G *************************** 1. row *************************** file_name: /u01/my3306/data/chuck/test_01.ibd event_name: wait/io/file/innodb/innodb_data_file SUM_NUMBER_OF_BYTES_READ: 2168078336 SUM_NUMBER_OF_BYTES_WRITE: 1390761934848

通過file_summary_by_instance表，可以獲得系統(tǒng)運(yùn)行到現(xiàn)在，哪個文件(表)物理IO最多，這可能意味著這個表經(jīng)常需要訪問磁盤IO，從結(jié)果來看chuck庫里面的test_01的數(shù)據(jù)文件訪問最多。

(2).哪個表邏輯IO最多?

SELECT object_name,COUNT_READ,COUNT_WRITE,COUNT_FETCH,SUM_TIMER_WAIT FROM table_io_waits_summary_by_table ORDER BY sum_timer_wait DESC limit 1\G *************************** 1. row *************************** object_name: test_slow COUNT_READ: 1986130 COUNT_WRITE: 393222 COUNT_FETCH: 1986130 SUM_TIMER_WAIT: 925309746633072

通過table_io_waits_summary_by_table表，可以獲得系統(tǒng)運(yùn)行到現(xiàn)在，哪個表邏輯IO最多，亦即最“熱”的表，從結(jié)果來看chuck庫里面的test_slow表訪問次數(shù)最多。

(3).哪個索引訪問最多？

SELECT OBJECT_NAME,INDEX_NAME,COUNT_FETCH,COUNT_INSERT,COUNT_UPDATE,COUNT_DELETE FROM table_io_waits_summary_by_index_usage ORDER BY SUM_TIMER_WAIT DESC limit 1\G *************************** 1. row *************************** OBJECT_NAME: test_slow INDEX_NAME: PRIMARY COUNT_FETCH: 393247 COUNT_INSERT: 0 COUNT_UPDATE: 393222 COUNT_DELETE: 0

通過table_io_waits_summary_by_index_usage表，可以獲得系統(tǒng)運(yùn)行到現(xiàn)在，哪個表的具體哪個索引(包括主鍵索引，二級索引)使用最多，從結(jié)果來看，我們知道test_slow表訪問最多，并且都是通過主鍵訪問。

(4).哪個索引從來沒有使用過？

SELECT OBJECT_SCHEMA,OBJECT_NAME,INDEX_NAME FROM table_io_waits_summary_by_index_usage WHERE INDEX_NAME IS NOT NULL AND COUNT_STAR = 0 AND OBJECT_SCHEMA <> 'mysql' ORDER BY OBJECT_SCHEMA,OBJECT_NAME; *************************** 1. row *************************** OBJECT_SCHEMA: chuck OBJECT_NAME: test_icp INDEX_NAME: idx_y_z

通過table_io_waits_summary_by_index_usage表，我們還可以獲得系統(tǒng)運(yùn)行到現(xiàn)在，哪些索引從來沒有被用過。由于索引也會占用大量的空間，我們可以利用這個統(tǒng)計信息，結(jié)合一定的時間策略將無用的索引刪除。上面的結(jié)果顯示，chuck庫test_icp表的idx_y_z從來沒有被使用過。

統(tǒng)計信息(等待事件維度)
(1).哪個等待事件消耗的時間最多？

SELECT EVENT_NAME,COUNT_STAR,SUM_TIMER_WAIT,AVG_TIMER_WAIT FROM events_waits_summary_global_by_event_name WHERE event_name != 'idle' ORDER BY SUM_TIMER_WAIT DESC LIMIT 1; *************************** 1. row *************************** EVENT_NAME: wait/synch/cond/threadpool/worker_cond COUNT_STAR: 26369820 SUM_TIMER_WAIT: 1604134685750586132 AVG_TIMER_WAIT: 60832219664

通過events_waits_summary_global_by_event_name表，可以獲取到系統(tǒng)運(yùn)行到現(xiàn)在，消耗時間最多的事件，當(dāng)然還可以根據(jù)其它維度排序，比如平均等待時間，從結(jié)果來看wait/synch/cond/threadpool/worker_cond這個事件消耗的累計時間最長。

具體場景分析
? ? ? 前面我們討論的基本都是匯總信息，有點類似與ORACLE-AWR(Automatic?Workload?Repository)的味道，那么我們?nèi)绾卫胮eformance schema來定位問題呢？或者對于的發(fā)生的問題，比如抖動，我們是否有辦法知道當(dāng)時發(fā)生了什么？
(1).剖析某條SQL的執(zhí)行情況，包括statement信息，stage信息和wait信息。
? ? ?有時候我們需要分析具體某條SQL，該SQL在執(zhí)行各個階段的時間消耗，通過events_statements_xxx表和events_stages_xxx表，就可以達(dá)到目的。兩個表通過event_id與nesting_event_id關(guān)聯(lián)，stages表的nesting_event_id為對應(yīng)statements表的event_id。比如分析包含count(*)的某條SQL語句，具體如下：

SELECT EVENT_ID,sql_text FROM events_statements_history WHERE sql_text LIKE '%count(*)%'; +----------+--------------------------------------+ | EVENT_ID | sql_text | +----------+--------------------------------------+ | 1690 | select count(*) from chuck.test_slow | +----------+--------------------------------------+

首先得到了語句的event_id為1690，通過查找events_stages_xxx中nesting_event_id為1690的記錄，可以達(dá)到目的。
a.查看每個階段的時間消耗

SELECT event_id,EVENT_NAME,SOURCE,TIMER_END - TIMER_START FROM events_stages_history_long WHERE NESTING_EVENT_ID = 1690; +----------+--------------------------------+----------------------+-----------------------+ | event_id | EVENT_NAME | SOURCE | TIMER_END-TIMER_START | +----------+--------------------------------+----------------------+-----------------------+ | 1691 | stage/sql/init | mysqld.cc:990 | 316945000 | | 1693 | stage/sql/checking permissions | sql_parse.cc:5776 | 26774000 | | 1695 | stage/sql/Opening tables | sql_base.cc:4970 | 41436934000 | | 2638 | stage/sql/init | sql_select.cc:1050 | 85757000 | | 2639 | stage/sql/System lock | lock.cc:303 | 40017000 | | 2643 | stage/sql/optimizing | sql_optimizer.cc:138 | 38562000 | | 2644 | stage/sql/statistics | sql_optimizer.cc:362 | 52845000 | | 2645 | stage/sql/preparing | sql_optimizer.cc:485 | 53196000 | | 2646 | stage/sql/executing | sql_executor.cc:112 | 3153000 | | 2647 | stage/sql/Sending data | sql_executor.cc:192 | 7369072089000 | | 4304138 | stage/sql/end | sql_select.cc:1105 | 19920000 | | 4304139 | stage/sql/query end | sql_parse.cc:5463 | 44721000 | | 4304145 | stage/sql/closing tables | sql_parse.cc:5524 | 61723000 | | 4304152 | stage/sql/freeing items | sql_parse.cc:6838 | 455678000 | | 4304155 | stage/sql/logging slow query | sql_parse.cc:2258 | 83348000 | | 4304159 | stage/sql/cleaning up | sql_parse.cc:2163 | 4433000 | +----------+--------------------------------+----------------------+-----------------------+

通過間接關(guān)聯(lián)，我們能分析得到SQL語句在每個階段的時間消耗，時間單位以皮秒表示。這里展示的結(jié)果很類似profiling功能，有了performance schema，就不再需要profiling這個功能了。另外需要注意的是，由于默認(rèn)情況下events_stages_history表中只為每個連接記錄了最近10條記錄，為了確保獲取所有記錄，需要訪問events_stages_history_long表。

b.查看某個階段的鎖等待情況
? ? ? 針對每個stage可能出現(xiàn)的鎖等待，一個stage會對應(yīng)一個或多個wait，events_waits_history_long這個表容易爆滿[默認(rèn)閥值10000]。由于select count(*)需要IO(邏輯IO或者物理IO)，所以在stage/sql/Sending data階段會有io等待的統(tǒng)計。通過stage_xxx表的event_id字段與waits_xxx表的nesting_event_id進(jìn)行關(guān)聯(lián)。

SELECT event_id,event_name,source,timer_wait,object_name,index_name,operation,nesting_event_id FROM events_waits_history_long WHERE nesting_event_id = 2647; +----------+---------------------------+-----------------+------------+-------------+------------+-----------+------------------+ | event_id | event_name | source | timer_wait | object_name | index_name | operation | nesting_event_id | +----------+---------------------------+-----------------+------------+-------------+------------+-----------+------------------+ | 190607 | wait/io/table/sql/handler | handler.cc:2842 | 1845888 | test_slow | idx_c1 | fetch | 2647 | | 190608 | wait/io/table/sql/handler | handler.cc:2842 | 1955328 | test_slow | idx_c1 | fetch | 2647 | | 190609 | wait/io/table/sql/handler | handler.cc:2842 | 1929792 | test_slow | idx_c1 | fetch | 2647 | | 190610 | wait/io/table/sql/handler | handler.cc:2842 | 1869600 | test_slow | idx_c1 | fetch | 2647 | | 190611 | wait/io/table/sql/handler | handler.cc:2842 | 1922496 | test_slow | idx_c1 | fetch | 2647 | +----------+---------------------------+-----------------+------------+-------------+------------+-----------+------------------+

通過上面的實驗，我們知道了statement,stage,wait的三級結(jié)構(gòu)，通過nesting_event_id進(jìn)行關(guān)聯(lián)，它表示某個事件的父event_id。

(2).模擬innodb行鎖等待的例子
? ? ? 會話A執(zhí)行語句update test_icp set y=y+1 where x=1(x為primary key)，不commit；會話B執(zhí)行同樣的語句update test_icp set y=y+1 where x=1，會話B堵塞，并最終報錯。通過連接連接查詢events_statements_history_long和events_stages_history_long，可以看到在updating階段花了大約60s的時間。這主要因為實例上的innodb_lock_wait_timeout設(shè)置為60，等待60s后超時報錯了。

SELECT statement.EVENT_ID,stages.event_id,statement.sql_text,stages.event_name,stages.timer_wait FROM events_statements_history_long statement join events_stages_history_long stages on statement.event_id=stages.nesting_event_id WHERE statement.sql_text = 'update test_icp set y=y+1 where x=1'; +----------+----------+-------------------------------------+--------------------------------+----------------+ | EVENT_ID | event_id | sql_text | event_name | timer_wait | +----------+----------+-------------------------------------+--------------------------------+----------------+ | 5816 | 5817 | update test_icp set y=y+1 where x=1 | stage/sql/init | 195543000 | | 5816 | 5819 | update test_icp set y=y+1 where x=1 | stage/sql/checking permissions | 22730000 | | 5816 | 5821 | update test_icp set y=y+1 where x=1 | stage/sql/Opening tables | 66079000 | | 5816 | 5827 | update test_icp set y=y+1 where x=1 | stage/sql/init | 89116000 | | 5816 | 5828 | update test_icp set y=y+1 where x=1 | stage/sql/System lock | 218744000 | | 5816 | 5832 | update test_icp set y=y+1 where x=1 | stage/sql/updating | 6001362045000 | | 5816 | 5968 | update test_icp set y=y+1 where x=1 | stage/sql/end | 10435000 | | 5816 | 5969 | update test_icp set y=y+1 where x=1 | stage/sql/query end | 85979000 | | 5816 | 5983 | update test_icp set y=y+1 where x=1 | stage/sql/closing tables | 56562000 | | 5816 | 5990 | update test_icp set y=y+1 where x=1 | stage/sql/freeing items | 83563000 | | 5816 | 5992 | update test_icp set y=y+1 where x=1 | stage/sql/cleaning up | 4589000 | +----------+----------+-------------------------------------+--------------------------------+----------------+

查看wait事件

SELECT event_id,event_name,source,timer_wait,object_name,index_name,operation,nesting_event_id FROM events_waits_history_long WHERE nesting_event_id = 5832; *************************** 1. row *************************** event_id: 5832 event_name: wait/io/table/sql/handler source: handler.cc:2782 timer_wait: 6005946156624 object_name: test_icp index_name: PRIMARY operation: fetch

從結(jié)果來看，waits表中記錄了一個fetch等待事件，但并沒有更細(xì)的innodb行鎖等待事件統(tǒng)計。

(3).模擬MDL鎖等待的例子
? ? ? 會話A執(zhí)行一個大查詢select count(*) from test_slow，會話B執(zhí)行表結(jié)構(gòu)變更alter table test_slow modify c2 varchar(152);通過如下語句可以得到alter語句的執(zhí)行過程，重點關(guān)注“stage/sql/Waiting for table metadata lock”階段。

SELECT statement.EVENT_ID,stages.event_id,statement.sql_text,stages.event_name as stage_name,stages.timer_wait as stage_time FROM events_statements_history_long statement left join events_stages_history_long stages on statement.event_id=stages.nesting_event_id WHERE statement.sql_text = 'alter table test_slow modify c2 varchar(152)'; +-----------+-----------+----------------------------------------------+----------------------------------------------------+---------------+ | EVENT_ID | event_id | sql_text | stage_name | stage_time | +-----------+-----------+----------------------------------------------+----------------------------------------------------+---------------+ | 326526744 | 326526745 | alter table test_slow modify c2 varchar(152) | stage/sql/init | 216662000 | | 326526744 | 326526747 | alter table test_slow modify c2 varchar(152) | stage/sql/checking permissions | 18183000 | | 326526744 | 326526748 | alter table test_slow modify c2 varchar(152) | stage/sql/checking permissions | 10294000 | | 326526744 | 326526750 | alter table test_slow modify c2 varchar(152) | stage/sql/init | 4783000 | | 326526744 | 326526751 | alter table test_slow modify c2 varchar(152) | stage/sql/Opening tables | 140172000 | | 326526744 | 326526760 | alter table test_slow modify c2 varchar(152) | stage/sql/setup | 157643000 | | 326526744 | 326526769 | alter table test_slow modify c2 varchar(152) | stage/sql/creating table | 8723217000 | | 326526744 | 326526803 | alter table test_slow modify c2 varchar(152) | stage/sql/After create | 257332000 | | 326526744 | 326526832 | alter table test_slow modify c2 varchar(152) | stage/sql/Waiting for table metadata lock | 1000181831000 | | 326526744 | 326526835 | alter table test_slow modify c2 varchar(152) | stage/sql/After create | 33483000 | | 326526744 | 326526838 | alter table test_slow modify c2 varchar(152) | stage/sql/Waiting for table metadata lock | 1000091810000 | | 326526744 | 326526841 | alter table test_slow modify c2 varchar(152) | stage/sql/After create | 17187000 | | 326526744 | 326526844 | alter table test_slow modify c2 varchar(152) | stage/sql/Waiting for table metadata lock | 1000126464000 | | 326526744 | 326526847 | alter table test_slow modify c2 varchar(152) | stage/sql/After create | 27472000 | | 326526744 | 326526850 | alter table test_slow modify c2 varchar(152) | stage/sql/Waiting for table metadata lock | 561996133000 | | 326526744 | 326526853 | alter table test_slow modify c2 varchar(152) | stage/sql/After create | 124876000 | | 326526744 | 326526877 | alter table test_slow modify c2 varchar(152) | stage/sql/System lock | 30659000 | | 326526744 | 326526881 | alter table test_slow modify c2 varchar(152) | stage/sql/preparing for alter table | 40246000 | | 326526744 | 326526889 | alter table test_slow modify c2 varchar(152) | stage/sql/altering table | 36628000 | | 326526744 | 326526912 | alter table test_slow modify c2 varchar(152) | stage/sql/committing alter table to storage engine | 11846511000 | | 326526744 | 326528280 | alter table test_slow modify c2 varchar(152) | stage/sql/end | 43824000 | | 326526744 | 326528281 | alter table test_slow modify c2 varchar(152) | stage/sql/query end | 112557000 | | 326526744 | 326528299 | alter table test_slow modify c2 varchar(152) | stage/sql/closing tables | 27707000 | | 326526744 | 326528305 | alter table test_slow modify c2 varchar(152) | stage/sql/freeing items | 201614000 | | 326526744 | 326528308 | alter table test_slow modify c2 varchar(152) | stage/sql/cleaning up | 3584000 | +-----------+-----------+----------------------------------------------+----------------------------------------------------+---------------+

從結(jié)果可以看到，出現(xiàn)了多次stage/sql/Waiting for table metadata lock階段，并且間隔1s，說明每隔1s鐘會重試判斷。找一個該階段的event_id,通過nesting_event_id關(guān)聯(lián)，確定到底在等待哪個wait事件。

SELECT event_id,event_name,source,timer_wait,object_name,index_name,operation,nesting_event_id FROM events_waits_history_long WHERE nesting_event_id = 326526850; +-----------+---------------------------------------------------+------------------+--------------+-------------+------------+------------+------------------+ | event_id | event_name | source | timer_wait | object_name | index_name | operation | nesting_event_id | +-----------+---------------------------------------------------+------------------+--------------+-------------+------------+------------+------------------+ | 326526851 | wait/synch/cond/sql/MDL_context::COND_wait_status | mdl.cc:1327 | 562417991328 | NULL | NULL | timed_wait | 326526850 | | 326526852 | wait/synch/mutex/mysys/my_thread_var::mutex | sql_class.h:3481 | 733248 | NULL | NULL | lock | 326526850 | +-----------+---------------------------------------------------+------------------+--------------+-------------+------------+------------+------------------+

通過結(jié)果可以知道，產(chǎn)生阻塞的是條件變量MDL_context::COND_wait_status，并且顯示了代碼的位置。

小結(jié)
? ? ?本文簡單舉例說明了如何通過Performance Schema得到數(shù)據(jù)庫運(yùn)行的統(tǒng)計信息，以及如何利用這些統(tǒng)計信息分析定位問題。通過Performance Schema，DBA可以能深入的理解系統(tǒng)，也能進(jìn)一步定位問題的源頭和本質(zhì)。

轉(zhuǎn)載自：http://www.cnblogs.com/cchust/p/5061131.html

總結(jié)

以上是生活随笔為你收集整理的MySQL Performance-Schema(三) 实践篇的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯，歡迎將生活随笔推薦給好友。