MySQL :: MySQL 5.6 Reference Manual :: 22 MySQL Performance Schema
5.6以降「よくなったよ!」「確かにね! でもメモリー」「」みたいな感じで扱われて結局まだONにしているインスタンスの少ないPerformance Schemaなのでちょっと練習中。
tpcc-mysqlとかでやると割と綺麗なクエリーをしているので面白い情報が出ない(ibdata1のfsyncに時間がかかってることなんて知ってるよ! って感じになる)ので、isucon2のアプリで試してみることにしますた。
モリスさん++
livedoor Techブログ : 自家製 #isucon2 のつくりかた
MySQLは5.6がいいので
MySQL :: Download MySQL Yum Repositoryで入れる。
$ sudo yum localinstall -y http://dev.mysql.com/get/mysql-community-release-el6-5.noarch.rpm
$ sudo yum install -y mysql-community-*
らくちん。
吊るしでPerformance Schemaはいくらか有効になっているので(中の人いわく、「よく使いそうなものはデフォルトでONになっている」)まずはそのまま見てみる。めぼしそうなもの(とりあえずcount_starカラムが0じゃないレコードを含むテーブル)を探してみるとこんなのがあった。
↓にずらーと出力結果ばかり並べているので先に結論。
events_statements_summary_by_digest マジ優秀。
これを見るためだけに(メモリーが許すなら)performance_schemaをONにしておく価値はある。
* events_statements_summary_by_account_by_event_name
* events_statements_summary_by_host_by_event_name
* events_statements_summary_by_thread_by_event_name
* events_statements_summary_by_user_by_event_name
* events_statements_summary_global_by_event_name
mysql> SELECT * FROM events_statements_summary_by_account_by_event_name WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 3;
+------------+-----------+----------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+
| USER | HOST | EVENT_NAME | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | SUM_LOCK_TIME | SUM_ERRORS | SUM_WARNINGS | SUM_ROWS_AFFECTED | SUM_ROWS_SENT | SUM_ROWS_EXAMINED | SUM_CREATED_TMP_DISK_TABLES | SUM_CREATED_TMP_TABLES | SUM_SELECT_FULL_JOIN | SUM_SELECT_FULL_RANGE_JOIN | SUM_SELECT_RANGE | SUM_SELECT_RANGE_CHECK | SUM_SELECT_SCAN | SUM_SORT_MERGE_PASSES | SUM_SORT_RANGE | SUM_SORT_ROWS | SUM_SORT_SCAN | SUM_NO_INDEX_USED | SUM_NO_GOOD_INDEX_USED |
+------------+-----------+----------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+
| isucon2app | localhost | statement/sql/select | 2738 | 35991922775000 | 83997000 | 13145333000 | 160056655000 | 195344000000 | 0 | 0 | 0 | 1653914 | 29363625 | 0 | 557 | 556 | 0 | 0 | 0 | 1558 | 0 | 0 | 4986 | 557 | 1558 | 0 |
| isucon2app | localhost | statement/sql/insert | 148 | 3698267239000 | 81107000 | 24988292000 | 1354468459000 | 113248000000 | 0 | 0 | 82048 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| isucon2app | localhost | statement/sql/update | 94 | 1648364786000 | 5976157000 | 17535795000 | 42219182000 | 5534000000 | 0 | 0 | 94 | 0 | 385118 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 94 | 94 | 0 | 0 | 0 |
+------------+-----------+----------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM events_statements_summary_by_account_by_event_name WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
USER: isucon2app
HOST: localhost
EVENT_NAME: statement/sql/select
COUNT_STAR: 2738
SUM_TIMER_WAIT: 35991922775000
MIN_TIMER_WAIT: 83997000
AVG_TIMER_WAIT: 13145333000
MAX_TIMER_WAIT: 160056655000
SUM_LOCK_TIME: 195344000000
SUM_ERRORS: 0
SUM_WARNINGS: 0
SUM_ROWS_AFFECTED: 0
SUM_ROWS_SENT: 1653914
SUM_ROWS_EXAMINED: 29363625
SUM_CREATED_TMP_DISK_TABLES: 0
SUM_CREATED_TMP_TABLES: 557
SUM_SELECT_FULL_JOIN: 556
SUM_SELECT_FULL_RANGE_JOIN: 0
SUM_SELECT_RANGE: 0
SUM_SELECT_RANGE_CHECK: 0
SUM_SELECT_SCAN: 1558
SUM_SORT_MERGE_PASSES: 0
SUM_SORT_RANGE: 0
SUM_SORT_ROWS: 4986
SUM_SORT_SCAN: 557
SUM_NO_INDEX_USED: 1558
SUM_NO_GOOD_INDEX_USED: 0
1 row in set (0.00 sec)
うーん、ちょっと大まかすぎるかな。。sum_sort_scanとかsum_sort_merge_passesとかは出てるから、どちらかというと全体の傾向をグラフにした方がいいような気がする(や、それならinformation_schemaで今のところ足りてるけど、こっちはupdateかselectか分けて見られるってことだよね)
* events_statements_summary_by_digest
mysql> SELECT * FROM events_statements_summary_by_digest WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 3;
+-------------+----------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+---------------------+---------------------+
| SCHEMA_NAME | DIGEST | DIGEST_TEXT | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | SUM_LOCK_TIME | SUM_ERRORS | SUM_WARNINGS | SUM_ROWS_AFFECTED | SUM_ROWS_SENT | SUM_ROWS_EXAMINED | SUM_CREATED_TMP_DISK_TABLES | SUM_CREATED_TMP_TABLES | SUM_SELECT_FULL_JOIN | SUM_SELECT_FULL_RANGE_JOIN | SUM_SELECT_RANGE | SUM_SELECT_RANGE_CHECK | SUM_SELECT_SCAN | SUM_SORT_MERGE_PASSES | SUM_SORT_RANGE | SUM_SORT_ROWS | SUM_SORT_SCAN | SUM_NO_INDEX_USED | SUM_NO_GOOD_INDEX_USED | FIRST_SEEN | LAST_SEEN |
+-------------+----------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+---------------------+---------------------+
| isucon2 | 68ff5779415a5d171d700f4a20fd47d0 | SELECT `stock` . `seat_id` , `variation` . `name` AS `v_name` , `ticket` . `name` AS `t_name` , `artist` . `name` AS `a_name` FROM `stock` JOIN `variation` ON `stock` . `variation_id` = `variation` . `id` JOIN `ticket` ON `variation` . `ticket_id` = `ticket` . `id` JOIN `artist` ON `ticket` . `artist_id` = `artist` . `id` WHERE `order_id` IS NOT NULL ORDER BY `order_id` DESC LIMIT ? | 556 | 19618662892000 | 12253383000 | 35285364000 | 160056655000 | 62943000000 | 0 | 0 | 0 | 4931 | 22848064 | 0 | 556 | 556 | 0 | 0 | 0 | 556 | 0 | 0 | 4931 | 556 | 556 | 0 | 2015-03-31 14:50:03 | 2015-03-31 14:50:21 |
| isucon2 | 32f72c3a9a23b6bdf3847bbdddeb16c7 | SELECT COUNT ( * ) FROM `variation` INNER JOIN `stock` ON `stock` . `variation_id` = `variation` . `id` WHERE `variation` . `ticket_id` = ? AND `stock` . `order_id` IS NULL | 351 | 8184198181000 | 6442619000 | 23316803000 | 50954069000 | 27705000000 | 0 | 0 | 0 | 351 | 2878902 | 0 | 0 | 0 | 0 | 0 | 0 | 351 | 0 | 0 | 0 | 0 | 351 | 0 | 2015-03-31 14:50:03 | 2015-03-31 14:50:21 |
| isucon2 | 886e82ad6d641a9be797d0b5b1f2bf73 | SELECT `seat_id` , `order_id` FROM `stock` WHERE `variation_id` = ? | 402 | 5404182832000 | 3303525000 | 13443240000 | 38198522000 | 13646000000 | 0 | 0 | 0 | 1646592 | 1646592 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 2015-03-31 14:50:06 | 2015-03-31 14:50:21 |
+-------------+----------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+----------------+----------------+----------------+----------------+---------------+------------+--------------+-------------------+---------------+-------------------+-----------------------------+------------------------+----------------------+----------------------------+------------------+------------------------+-----------------+-----------------------+----------------+---------------+---------------+-------------------+------------------------+---------------------+---------------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM events_statements_summary_by_digest WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
SCHEMA_NAME: isucon2
DIGEST: 68ff5779415a5d171d700f4a20fd47d0
DIGEST_TEXT: SELECT `stock` . `seat_id` , `variation` . `name` AS `v_name` , `ticket` . `name` AS `t_name` , `artist` . `name` AS `a_name` FROM `stock` JOIN `variation` ON `stock` . `variation_id` = `variation` . `id` JOIN `ticket` ON `variation` . `ticket_id` = `ticket` . `id` JOIN `artist` ON `ticket` . `artist_id` = `artist` . `id` WHERE `order_id` IS NOT NULL ORDER BY `order_id` DESC LIMIT ?
COUNT_STAR: 556
SUM_TIMER_WAIT: 19618662892000
MIN_TIMER_WAIT: 12253383000
AVG_TIMER_WAIT: 35285364000
MAX_TIMER_WAIT: 160056655000
SUM_LOCK_TIME: 62943000000
SUM_ERRORS: 0
SUM_WARNINGS: 0
SUM_ROWS_AFFECTED: 0
SUM_ROWS_SENT: 4931
SUM_ROWS_EXAMINED: 22848064
SUM_CREATED_TMP_DISK_TABLES: 0
SUM_CREATED_TMP_TABLES: 556
SUM_SELECT_FULL_JOIN: 556
SUM_SELECT_FULL_RANGE_JOIN: 0
SUM_SELECT_RANGE: 0
SUM_SELECT_RANGE_CHECK: 0
SUM_SELECT_SCAN: 556
SUM_SORT_MERGE_PASSES: 0
SUM_SORT_RANGE: 0
SUM_SORT_ROWS: 4931
SUM_SORT_SCAN: 556
SUM_NO_INDEX_USED: 556
SUM_NO_GOOD_INDEX_USED: 0
FIRST_SEEN: 2015-03-31 14:50:03
LAST_SEEN: 2015-03-31 14:50:21
1 row in set (0.00 sec)
これは判りやすい。ステートメント(pt-query-digestみたいに可変部分は握りつぶしてくれる)単位でSelect_scanやSum_rows_examinedが見られる。ステキ。
Percona Serverのスローログ + pt-query-digest並みの情報量な気がする。パーセンタイルな情報はないけどまあいいや。
* events_waits_summary_by_account_by_event_name
* events_waits_summary_by_host_by_event_name
* events_waits_summary_by_instance
* events_waits_summary_by_thread_by_event_name
* events_waits_summary_by_user_by_event_name
* events_waits_summary_global_by_event_name
mysql> SELECT * FROM events_waits_summary_by_account_by_event_name WHERE count_star <> 0 AND event_name <> 'idle' ORDER BY sum_timer_wait DESC LIMIT 3;
+------------+-----------+--------------------------------------+------------+----------------+----------------+----------------+----------------+
| USER | HOST | EVENT_NAME | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT |
+------------+-----------+--------------------------------------+------------+----------------+----------------+----------------+----------------+
| isucon2app | localhost | wait/io/table/sql/handler | 29763732 | 28437697326885 | 48125 | 955185 | 1355498746525 |
| isucon2app | localhost | wait/io/file/innodb/innodb_data_file | 417 | 2104885627075 | 2718100 | 5047687260 | 1191383874065 |
| isucon2app | localhost | wait/io/file/innodb/innodb_log_file | 350 | 865270214655 | 7838215 | 2472200500 | 58576612710 |
+------------+-----------+--------------------------------------+------------+----------------+----------------+----------------+----------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM events_waits_summary_by_account_by_event_name WHERE count_star <> 0 AND event_name <> 'idle' ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
USER: isucon2app
HOST: localhost
EVENT_NAME: wait/io/table/sql/handler
COUNT_STAR: 29763732
SUM_TIMER_WAIT: 28437697326885
MIN_TIMER_WAIT: 48125
AVG_TIMER_WAIT: 955185
MAX_TIMER_WAIT: 1355498746525
1 row in set (0.00 sec)
どこのイベントで待ちが発生したかの情報なんだけど、なんかやっぱりちょっと粒度が荒い。
ibdata1で待ってるのは知ってるよ! でもdouble write切れないんだよ! って感じ。
* file_summary_by_event_name
mysql> SELECT * FROM file_summary_by_event_name WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 3;
+--------------------------------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+--------------------------+-------------+-----------------+-----------------+-----------------+-----------------+---------------------------+------------+----------------+----------------+----------------+----------------+
| EVENT_NAME | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | COUNT_READ | SUM_TIMER_READ | MIN_TIMER_READ | AVG_TIMER_READ | MAX_TIMER_READ | SUM_NUMBER_OF_BYTES_READ | COUNT_WRITE | SUM_TIMER_WRITE | MIN_TIMER_WRITE | AVG_TIMER_WRITE | MAX_TIMER_WRITE | SUM_NUMBER_OF_BYTES_WRITE | COUNT_MISC | SUM_TIMER_MISC | MIN_TIMER_MISC | AVG_TIMER_MISC | MAX_TIMER_MISC |
+--------------------------------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+--------------------------+-------------+-----------------+-----------------+-----------------+-----------------+---------------------------+------------+----------------+----------------+----------------+----------------+
| wait/io/file/innodb/innodb_data_file | 1519 | 2481586224040 | 0 | 1633697065 | 1191383874065 | 163 | 3469540305 | 0 | 21285495 | 896338905 | 4734976 | 1029 | 206577099575 | 0 | 200755170 | 20881438270 | 119422976 | 327 | 2271539584160 | 0 | 6946603895 | 1191383874065 |
| wait/io/file/innodb/innodb_log_file | 434 | 1022073887450 | 0 | 2355008810 | 58576612710 | 6 | 27545210 | 0 | 4590740 | 22502480 | 69632 | 211 | 262934620795 | 0 | 1246135275 | 58576612710 | 7907840 | 217 | 759111721445 | 0 | 3498210485 | 41712168190 |
| wait/io/file/sql/FRM | 1663 | 374523815050 | 0 | 225209600 | 205524644710 | 739 | 124995936065 | 0 | 169141665 | 29619563050 | 167156 | 105 | 176487850 | 0 | 1680525 | 15076215 | 26609 | 819 | 249351391135 | 0 | 304458000 | 205524644710 |
+--------------------------------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+--------------------------+-------------+-----------------+-----------------+-----------------+-----------------+---------------------------+------------+----------------+----------------+----------------+----------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM file_summary_by_event_name WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
EVENT_NAME: wait/io/file/innodb/innodb_data_file
COUNT_STAR: 1519
SUM_TIMER_WAIT: 2481586224040
MIN_TIMER_WAIT: 0
AVG_TIMER_WAIT: 1633697065
MAX_TIMER_WAIT: 1191383874065
COUNT_READ: 163
SUM_TIMER_READ: 3469540305
MIN_TIMER_READ: 0
AVG_TIMER_READ: 21285495
MAX_TIMER_READ: 896338905
SUM_NUMBER_OF_BYTES_READ: 4734976
COUNT_WRITE: 1029
SUM_TIMER_WRITE: 206577099575
MIN_TIMER_WRITE: 0
AVG_TIMER_WRITE: 200755170
MAX_TIMER_WRITE: 20881438270
SUM_NUMBER_OF_BYTES_WRITE: 119422976
COUNT_MISC: 327
SUM_TIMER_MISC: 2271539584160
MIN_TIMER_MISC: 0
AVG_TIMER_MISC: 6946603895
MAX_TIMER_MISC: 1191383874065
1 row in set (0.00 sec)
WAIT, READ, WRITE, MISCに分かれているので多少見やすそうだけど、粒度が荒くてちょっとつらい。
対して、↓の
* file_summary_by_instance
mysql> SELECT * FROM file_summary_by_instance WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 3;
+----------------------------------+--------------------------------------+-----------------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+--------------------------+-------------+-----------------+-----------------+-----------------+-----------------+---------------------------+------------+----------------+----------------+----------------+----------------+
| FILE_NAME | EVENT_NAME | OBJECT_INSTANCE_BEGIN | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | COUNT_READ | SUM_TIMER_READ | MIN_TIMER_READ | AVG_TIMER_READ | MAX_TIMER_READ | SUM_NUMBER_OF_BYTES_READ | COUNT_WRITE | SUM_TIMER_WRITE | MIN_TIMER_WRITE | AVG_TIMER_WRITE | MAX_TIMER_WRITE | SUM_NUMBER_OF_BYTES_WRITE | COUNT_MISC | SUM_TIMER_MISC | MIN_TIMER_MISC | AVG_TIMER_MISC | MAX_TIMER_MISC |
+----------------------------------+--------------------------------------+-----------------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+--------------------------+-------------+-----------------+-----------------+-----------------+-----------------+---------------------------+------------+----------------+----------------+----------------+----------------+
| /var/lib/mysql/ibdata1 | wait/io/file/innodb/innodb_data_file | 140132153275264 | 819 | 1604593676840 | 2331560 | 1959210715 | 1191383874065 | 157 | 3398451980 | 3504655 | 21645855 | 896338905 | 4636672 | 626 | 181296946215 | 7489790 | 289611630 | 20881438270 | 88735744 | 36 | 1419898278645 | 2331560 | 39441618755 | 1191383874065 |
| /var/lib/mysql/ib_logfile0 | wait/io/file/innodb/innodb_log_file | 140132153275968 | 431 | 1022063454720 | 382690 | 2371376700 | 58576612710 | 6 | 27545210 | 382690 | 4590740 | 22502480 | 69632 | 211 | 262934620795 | 7044730 | 1246135275 | 58576612710 | 7907840 | 214 | 759101288715 | 934780 | 3547202120 | 41712168190 |
| /var/lib/mysql/isucon2/stock.ibd | wait/io/file/innodb/innodb_data_file | 140132153361152 | 310 | 273430299835 | 3560095 | 882033075 | 9891016520 | 0 | 0 | 0 | 0 | 0 | 0 | 239 | 12590424770 | 8717170 | 52679550 | 827383095 | 15532032 | 71 | 260839875065 | 3560095 | 3673800900 | 9891016520 |
+----------------------------------+--------------------------------------+-----------------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+--------------------------+-------------+-----------------+-----------------+-----------------+-----------------+---------------------------+------------+----------------+----------------+----------------+----------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM file_summary_by_instance WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
FILE_NAME: /var/lib/mysql/ibdata1
EVENT_NAME: wait/io/file/innodb/innodb_data_file
OBJECT_INSTANCE_BEGIN: 140132153275264
COUNT_STAR: 819
SUM_TIMER_WAIT: 1604593676840
MIN_TIMER_WAIT: 2331560
AVG_TIMER_WAIT: 1959210715
MAX_TIMER_WAIT: 1191383874065
COUNT_READ: 157
SUM_TIMER_READ: 3398451980
MIN_TIMER_READ: 3504655
AVG_TIMER_READ: 21645855
MAX_TIMER_READ: 896338905
SUM_NUMBER_OF_BYTES_READ: 4636672
COUNT_WRITE: 626
SUM_TIMER_WRITE: 181296946215
MIN_TIMER_WRITE: 7489790
AVG_TIMER_WRITE: 289611630
MAX_TIMER_WRITE: 20881438270
SUM_NUMBER_OF_BYTES_WRITE: 88735744
COUNT_MISC: 36
SUM_TIMER_MISC: 1419898278645
MIN_TIMER_MISC: 2331560
AVG_TIMER_MISC: 39441618755
MAX_TIMER_MISC: 1191383874065
1 row in set (0.00 sec)
こっちはファイル名まで見られるのでいくらか良い感じ。更新が集中しているテーブルとか見られる。グラフ化したい。
* objects_summary_global_by_type
mysql> SELECT * FROM objects_summary_global_by_type WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 3;
+-------------+---------------+---------------+------------+----------------+----------------+----------------+----------------+
| OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT |
+-------------+---------------+---------------+------------+----------------+----------------+----------------+----------------+
| TABLE | isucon2 | stock | 29755167 | 25975000162265 | 38885 | 872795 | 60737987310 |
| TABLE | isucon2 | order_request | 343 | 2256830278395 | 177870 | 6579680030 | 1355498746525 |
| TABLE | isucon2 | artist | 3653 | 139255591860 | 25795 | 38120775 | 14495216505 |
+-------------+---------------+---------------+------------+----------------+----------------+----------------+----------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM objects_summary_global_by_type WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
OBJECT_TYPE: TABLE
OBJECT_SCHEMA: isucon2
OBJECT_NAME: stock
COUNT_STAR: 29755167
SUM_TIMER_WAIT: 25975000162265
MIN_TIMER_WAIT: 38885
AVG_TIMER_WAIT: 872795
MAX_TIMER_WAIT: 60737987310
1 row in set (0.00 sec)
こっちはファイルに触れる触れないに関わらずテーブル単位で待ちが発生した回数と時間の累計。
バッファプールだけで完結するSELECTならundoのためにibdata1とib_logfileに触ることはあっても.ibdファイルには触らないだろうから、とかそんなところが違うんだと思う。
* table_io_waits_summary_by_index_usage
* table_io_waits_summary_by_table
mysql> SELECT * FROM table_io_waits_summary_by_index_usage WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 3;
+-------------+---------------+---------------+----------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------+-----------------+-----------------+-----------------+-----------------+--------------+------------------+------------------+------------------+------------------+--------------+------------------+------------------+------------------+------------------+--------------+------------------+------------------+------------------+------------------+
| OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | INDEX_NAME | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | COUNT_READ | SUM_TIMER_READ | MIN_TIMER_READ | AVG_TIMER_READ | MAX_TIMER_READ | COUNT_WRITE | SUM_TIMER_WRITE | MIN_TIMER_WRITE | AVG_TIMER_WRITE | MAX_TIMER_WRITE | COUNT_FETCH | SUM_TIMER_FETCH | MIN_TIMER_FETCH | AVG_TIMER_FETCH | MAX_TIMER_FETCH | COUNT_INSERT | SUM_TIMER_INSERT | MIN_TIMER_INSERT | AVG_TIMER_INSERT | MAX_TIMER_INSERT | COUNT_UPDATE | SUM_TIMER_UPDATE | MIN_TIMER_UPDATE | AVG_TIMER_UPDATE | MAX_TIMER_UPDATE | COUNT_DELETE | SUM_TIMER_DELETE | MIN_TIMER_DELETE | AVG_TIMER_DELETE | MAX_TIMER_DELETE |
+-------------+---------------+---------------+----------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------+-----------------+-----------------+-----------------+-----------------+--------------+------------------+------------------+------------------+------------------+--------------+------------------+------------------+------------------+------------------+--------------+------------------+------------------+------------------+------------------+
| TABLE | isucon2 | stock | NULL | 23155059 | 15405691875035 | 51590 | 665280 | 60737987310 | 23073139 | 14505802679445 | 51590 | 628320 | 29693793745 | 81920 | 899889195590 | 3240930 | 10984820 | 60737987310 | 23073139 | 14505802679445 | 51590 | 628320 | 29693793745 | 81920 | 899889195590 | 3240930 | 10984820 | 60737987310 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| TABLE | isucon2 | stock | variation_seat | 6596170 | 10556789714240 | 48125 | 1600060 | 35806416030 | 6596170 | 10556789714240 | 48125 | 1600060 | 35806416030 | 0 | 0 | 0 | 0 | 0 | 6596170 | 10556789714240 | 48125 | 1600060 | 35806416030 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
| TABLE | isucon2 | order_request | NULL | 94 | 2256572540145 | 24644620 | 24006090570 | 1355498746525 | 0 | 0 | 0 | 0 | 0 | 94 | 2256572540145 | 24644620 | 24006090570 | 1355498746525 | 0 | 0 | 0 | 0 | 0 | 94 | 2256572540145 | 24644620 | 24006090570 | 1355498746525 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 |
+-------------+---------------+---------------+----------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------+-----------------+-----------------+-----------------+-----------------+--------------+------------------+------------------+------------------+------------------+--------------+------------------+------------------+------------------+------------------+--------------+------------------+------------------+------------------+------------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM table_io_waits_summary_by_index_usage WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
OBJECT_TYPE: TABLE
OBJECT_SCHEMA: isucon2
OBJECT_NAME: stock
INDEX_NAME: NULL
COUNT_STAR: 23155059
SUM_TIMER_WAIT: 15405691875035
MIN_TIMER_WAIT: 51590
AVG_TIMER_WAIT: 665280
MAX_TIMER_WAIT: 60737987310
COUNT_READ: 23073139
SUM_TIMER_READ: 14505802679445
MIN_TIMER_READ: 51590
AVG_TIMER_READ: 628320
MAX_TIMER_READ: 29693793745
COUNT_WRITE: 81920
SUM_TIMER_WRITE: 899889195590
MIN_TIMER_WRITE: 3240930
AVG_TIMER_WRITE: 10984820
MAX_TIMER_WRITE: 60737987310
COUNT_FETCH: 23073139
SUM_TIMER_FETCH: 14505802679445
MIN_TIMER_FETCH: 51590
AVG_TIMER_FETCH: 628320
MAX_TIMER_FETCH: 29693793745
COUNT_INSERT: 81920
SUM_TIMER_INSERT: 899889195590
MIN_TIMER_INSERT: 3240930
AVG_TIMER_INSERT: 10984820
MAX_TIMER_INSERT: 60737987310
COUNT_UPDATE: 0
SUM_TIMER_UPDATE: 0
MIN_TIMER_UPDATE: 0
AVG_TIMER_UPDATE: 0
MAX_TIMER_UPDATE: 0
COUNT_DELETE: 0
SUM_TIMER_DELETE: 0
MIN_TIMER_DELETE: 0
AVG_TIMER_DELETE: 0
MAX_TIMER_DELETE: 0
1 row in set (0.01 sec)
更に細かく、インデックス単位でのWAIT, READ, WRITE, FETCH, INSERT, UPDATE, DELETE(table_io_waits_summary_by_tableの方はテーブル単位)
INDEX_NAME = 'NULL'ってWITH ROLLUP的な感じで合算なのかと思ったけどどうもそうではなさげ。。なんだろう。
使われてないインデックス(writeばっかりでfetchが少ないとかになるのかな)とか算出するsysスキーマがあったような気がする。これ使ってるのかな。
* table_lock_waits_summary_by_table
mysql> SELECT * FROM table_lock_waits_summary_by_table WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 3;
+-------------+---------------+-------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------------+-----------------------+-----------------------+-----------------------+-----------------------+------------------------------+----------------------------------+----------------------------------+----------------------------------+----------------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+-------------------------+-----------------------------+-----------------------------+-----------------------------+-----------------------------+-------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+--------------------+------------------------+------------------------+------------------------+------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+
| OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | COUNT_STAR | SUM_TIMER_WAIT | MIN_TIMER_WAIT | AVG_TIMER_WAIT | MAX_TIMER_WAIT | COUNT_READ | SUM_TIMER_READ | MIN_TIMER_READ | AVG_TIMER_READ | MAX_TIMER_READ | COUNT_WRITE | SUM_TIMER_WRITE | MIN_TIMER_WRITE | AVG_TIMER_WRITE | MAX_TIMER_WRITE | COUNT_READ_NORMAL | SUM_TIMER_READ_NORMAL | MIN_TIMER_READ_NORMAL | AVG_TIMER_READ_NORMAL | MAX_TIMER_READ_NORMAL | COUNT_READ_WITH_SHARED_LOCKS | SUM_TIMER_READ_WITH_SHARED_LOCKS | MIN_TIMER_READ_WITH_SHARED_LOCKS | AVG_TIMER_READ_WITH_SHARED_LOCKS | MAX_TIMER_READ_WITH_SHARED_LOCKS | COUNT_READ_HIGH_PRIORITY | SUM_TIMER_READ_HIGH_PRIORITY | MIN_TIMER_READ_HIGH_PRIORITY | AVG_TIMER_READ_HIGH_PRIORITY | MAX_TIMER_READ_HIGH_PRIORITY | COUNT_READ_NO_INSERT | SUM_TIMER_READ_NO_INSERT | MIN_TIMER_READ_NO_INSERT | AVG_TIMER_READ_NO_INSERT | MAX_TIMER_READ_NO_INSERT | COUNT_READ_EXTERNAL | SUM_TIMER_READ_EXTERNAL | MIN_TIMER_READ_EXTERNAL | AVG_TIMER_READ_EXTERNAL | MAX_TIMER_READ_EXTERNAL | COUNT_WRITE_ALLOW_WRITE | SUM_TIMER_WRITE_ALLOW_WRITE | MIN_TIMER_WRITE_ALLOW_WRITE | AVG_TIMER_WRITE_ALLOW_WRITE | MAX_TIMER_WRITE_ALLOW_WRITE | COUNT_WRITE_CONCURRENT_INSERT | SUM_TIMER_WRITE_CONCURRENT_INSERT | MIN_TIMER_WRITE_CONCURRENT_INSERT | AVG_TIMER_WRITE_CONCURRENT_INSERT | MAX_TIMER_WRITE_CONCURRENT_INSERT | COUNT_WRITE_DELAYED | SUM_TIMER_WRITE_DELAYED | MIN_TIMER_WRITE_DELAYED | AVG_TIMER_WRITE_DELAYED | MAX_TIMER_WRITE_DELAYED | COUNT_WRITE_LOW_PRIORITY | SUM_TIMER_WRITE_LOW_PRIORITY | MIN_TIMER_WRITE_LOW_PRIORITY | AVG_TIMER_WRITE_LOW_PRIORITY | MAX_TIMER_WRITE_LOW_PRIORITY | COUNT_WRITE_NORMAL | SUM_TIMER_WRITE_NORMAL | MIN_TIMER_WRITE_NORMAL | AVG_TIMER_WRITE_NORMAL | MAX_TIMER_WRITE_NORMAL | COUNT_WRITE_EXTERNAL | SUM_TIMER_WRITE_EXTERNAL | MIN_TIMER_WRITE_EXTERNAL | AVG_TIMER_WRITE_EXTERNAL | MAX_TIMER_WRITE_EXTERNAL |
+-------------+---------------+-------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------------+-----------------------+-----------------------+-----------------------+-----------------------+------------------------------+----------------------------------+----------------------------------+----------------------------------+----------------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+-------------------------+-----------------------------+-----------------------------+-----------------------------+-----------------------------+-------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+--------------------+------------------------+------------------------+------------------------+------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+
| TABLE | isucon2 | stock | 3844 | 1580755330 | 38885 | 411180 | 84922530 | 3612 | 1451608235 | 38885 | 401555 | 84922530 | 232 | 129147095 | 192885 | 556325 | 9873325 | 1806 | 503861820 | 48125 | 278740 | 84922530 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1806 | 947746415 | 38885 | 524755 | 13140050 | 114 | 40675635 | 192885 | 356510 | 1143450 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 2 | 1497265 | 525525 | 748440 | 971740 | 116 | 86974195 | 418110 | 749595 | 9873325 |
| TABLE | isucon2 | variation | 2260 | 722340080 | 58905 | 319550 | 9551850 | 2216 | 705739265 | 58905 | 318395 | 9551850 | 44 | 16600815 | 180180 | 376915 | 656040 | 1108 | 360249120 | 114345 | 324940 | 9551850 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1108 | 345490145 | 58905 | 311465 | 1170785 | 20 | 5014625 | 180180 | 250635 | 358050 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 2 | 860860 | 338030 | 430430 | 522830 | 22 | 10725330 | 423885 | 487410 | 656040 |
| TABLE | isucon2 | artist | 2236 | 466900280 | 25795 | 208670 | 3642485 | 2224 | 455622090 | 25795 | 204820 | 3642485 | 12 | 11278190 | 210595 | 939785 | 2962960 | 1112 | 224735280 | 44660 | 201740 | 1176560 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1112 | 230886810 | 25795 | 207515 | 3642485 | 4 | 2527140 | 210595 | 631785 | 1158850 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 2 | 1629705 | 699545 | 814660 | 930160 | 6 | 7121345 | 438130 | 1186570 | 2962960 |
+-------------+---------------+-------------+------------+----------------+----------------+----------------+----------------+------------+----------------+----------------+----------------+----------------+-------------+-----------------+-----------------+-----------------+-----------------+-------------------+-----------------------+-----------------------+-----------------------+-----------------------+------------------------------+----------------------------------+----------------------------------+----------------------------------+----------------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+-------------------------+-----------------------------+-----------------------------+-----------------------------+-----------------------------+-------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+-----------------------------------+---------------------+-------------------------+-------------------------+-------------------------+-------------------------+--------------------------+------------------------------+------------------------------+------------------------------+------------------------------+--------------------+------------------------+------------------------+------------------------+------------------------+----------------------+--------------------------+--------------------------+--------------------------+--------------------------+
3 rows in set (0.00 sec)
mysql> SELECT * FROM table_lock_waits_summary_by_table WHERE count_star <> 0 ORDER BY sum_timer_wait DESC LIMIT 1\G
*************************** 1. row ***************************
OBJECT_TYPE: TABLE
OBJECT_SCHEMA: isucon2
OBJECT_NAME: stock
COUNT_STAR: 3844
SUM_TIMER_WAIT: 1580755330
MIN_TIMER_WAIT: 38885
AVG_TIMER_WAIT: 411180
MAX_TIMER_WAIT: 84922530
COUNT_READ: 3612
SUM_TIMER_READ: 1451608235
MIN_TIMER_READ: 38885
AVG_TIMER_READ: 401555
MAX_TIMER_READ: 84922530
COUNT_WRITE: 232
SUM_TIMER_WRITE: 129147095
MIN_TIMER_WRITE: 192885
AVG_TIMER_WRITE: 556325
MAX_TIMER_WRITE: 9873325
COUNT_READ_NORMAL: 1806
SUM_TIMER_READ_NORMAL: 503861820
MIN_TIMER_READ_NORMAL: 48125
AVG_TIMER_READ_NORMAL: 278740
MAX_TIMER_READ_NORMAL: 84922530
COUNT_READ_WITH_SHARED_LOCKS: 0
SUM_TIMER_READ_WITH_SHARED_LOCKS: 0
MIN_TIMER_READ_WITH_SHARED_LOCKS: 0
AVG_TIMER_READ_WITH_SHARED_LOCKS: 0
MAX_TIMER_READ_WITH_SHARED_LOCKS: 0
COUNT_READ_HIGH_PRIORITY: 0
SUM_TIMER_READ_HIGH_PRIORITY: 0
MIN_TIMER_READ_HIGH_PRIORITY: 0
AVG_TIMER_READ_HIGH_PRIORITY: 0
MAX_TIMER_READ_HIGH_PRIORITY: 0
COUNT_READ_NO_INSERT: 0
SUM_TIMER_READ_NO_INSERT: 0
MIN_TIMER_READ_NO_INSERT: 0
AVG_TIMER_READ_NO_INSERT: 0
MAX_TIMER_READ_NO_INSERT: 0
COUNT_READ_EXTERNAL: 1806
SUM_TIMER_READ_EXTERNAL: 947746415
MIN_TIMER_READ_EXTERNAL: 38885
AVG_TIMER_READ_EXTERNAL: 524755
MAX_TIMER_READ_EXTERNAL: 13140050
COUNT_WRITE_ALLOW_WRITE: 114
SUM_TIMER_WRITE_ALLOW_WRITE: 40675635
MIN_TIMER_WRITE_ALLOW_WRITE: 192885
AVG_TIMER_WRITE_ALLOW_WRITE: 356510
MAX_TIMER_WRITE_ALLOW_WRITE: 1143450
COUNT_WRITE_CONCURRENT_INSERT: 0
SUM_TIMER_WRITE_CONCURRENT_INSERT: 0
MIN_TIMER_WRITE_CONCURRENT_INSERT: 0
AVG_TIMER_WRITE_CONCURRENT_INSERT: 0
MAX_TIMER_WRITE_CONCURRENT_INSERT: 0
COUNT_WRITE_DELAYED: 0
SUM_TIMER_WRITE_DELAYED: 0
MIN_TIMER_WRITE_DELAYED: 0
AVG_TIMER_WRITE_DELAYED: 0
MAX_TIMER_WRITE_DELAYED: 0
COUNT_WRITE_LOW_PRIORITY: 0
SUM_TIMER_WRITE_LOW_PRIORITY: 0
MIN_TIMER_WRITE_LOW_PRIORITY: 0
AVG_TIMER_WRITE_LOW_PRIORITY: 0
MAX_TIMER_WRITE_LOW_PRIORITY: 0
COUNT_WRITE_NORMAL: 2
SUM_TIMER_WRITE_NORMAL: 1497265
MIN_TIMER_WRITE_NORMAL: 525525
AVG_TIMER_WRITE_NORMAL: 748440
MAX_TIMER_WRITE_NORMAL: 971740
COUNT_WRITE_EXTERNAL: 116
SUM_TIMER_WRITE_EXTERNAL: 86974195
MIN_TIMER_WRITE_EXTERNAL: 418110
AVG_TIMER_WRITE_EXTERNAL: 749595
MAX_TIMER_WRITE_EXTERNAL: 9873325
1 row in set (0.00 sec)
テーブルごとのロック待ちの統計…なんだけど、i_sで確認するステータスとは違う変数名がならんでてどこがどう対応してるんだろう。
ブロックしてるクエリーとかも見られるi_sの方が優秀かなここは。
もういちど。
events_statements_summary_by_digest マジ優秀。
【2015/03/31 17:28】
フルパワーにしたらこんな感じだった。
日々の覚書: MySQLのperformance_schemaをフルパワーにするとどんな情報が見られるのか