mita2 database life

主にMySQLに関するメモです

MySQL 8.0でレスポンスタイムのヒストグラムが見れるようになった

このエントリーはMySQL Casual Advent Calendar 2018の7日目です。
自分は筆が遅く、11月から準備しようしよう、と思ってたにも関わらず、結局、直前になって書いてます。。。

さて、MySQL 8.0になって、performance_schemaが15個増えてました。

5.7では、87個。

mysql> select count(*) from information_schema.TABLES where TABLE_SCHEMA = 'performance_schema';
+----------+
| count(*) |
+----------+
| 87 |
+----------+
1 row in set (0.02 sec)

8.0では102個。

mysql> select count(*) from information_schema.TABLES where TABLE_SCHEMA = 'performance_schema';
+----------+
| count(*) |
+----------+
| 102 |
+----------+
1 row in set (0.04 sec)

一番気になったのが events_statements_histogram_globalです。 このテーブルはクエリのレスポンスタイムの分布(ヒストグラム)を確認することができます。

mysql> SELECT * FROM events_statements_histogram_global;
+---------------+------------------+-------------------+--------------+------------------------+-----------------+
| BUCKET_NUMBER | BUCKET_TIMER_LOW | BUCKET_TIMER_HIGH | COUNT_BUCKET | COUNT_BUCKET_AND_LOWER | BUCKET_QUANTILE |
+---------------+------------------+-------------------+--------------+------------------------+-----------------+
| 0 | 0 | 10000000 | 0 | 0 | 0.000000 |
| 1 | 10000000 | 10471285 | 0 | 0 | 0.000000 |
| 2 | 10471285 | 10964781 | 0 | 0 | 0.000000 |
| 3 | 10964781 | 11481536 | 0 | 0 | 0.000000 |
| 4 | 11481536 | 12022644 | 0 | 0 | 0.000000 |
---省略---
| 80 | 380189396 | 398107170 | 0 | 17 | 0.127820 |
| 81 | 398107170 | 416869383 | 0 | 17 | 0.127820 |
| 82 | 416869383 | 436515832 | 5 | 22 | 0.165414 |
| 83 | 436515832 | 457088189 | 4 | 26 | 0.195489 |
| 84 | 457088189 | 478630092 | 4 | 30 | 0.225564 |
| 85 | 478630092 | 501187233 | 5 | 35 | 0.263158 |
| 86 | 501187233 | 524807460 | 8 | 43 | 0.323308 |
| 87 | 524807460 | 549540873 | 6 | 49 | 0.368421 |
| 88 | 549540873 | 575439937 | 11 | 60 | 0.451128 |
| 89 | 575439937 | 602559586 | 6 | 66 | 0.496241 |
---省略---

例えば、この結果の下から2行目のBUCKET_NUMERが88の行だと、実行時間が、549540873 ピコ秒より大きく、575439937 ピコ秒以下のクエリが11回あったことがわかります。
COUNT_BUCKET_AND_LOWERは該当のバケットより実行時間が短かったクエリの合計。
549540873以下の実行時間だったクエリが60回ということ。

このテーブルをモニタリングしていくと、こういうグラフを作れる。

※PMMの同じ機能のグラフを拝借。グラフを作るのが面倒だったので・・・


べんり!!

バケットの間隔(factor)はソースコードにハードコードされています。

/**
Bucket factor.
histogram_timer[i+1] = BUCKET_BASE_FACTOR * histogram_timer[i]
The value is chosen so that BUCKET_BASE_FACTOR ^ 50 = 10,
which corresponds to a 4.7 percent increase for each bucket,
or a power of 10 increase for 50 buckets.
*/
#define BUCKET_BASE_FACTOR 1.0471285480508996

コメントに書いてあるように、50バケットごとに約10倍になるようなfactorになっている。
人間が見るときは、キリの良い50バケット目ずつを取り出してみるのが良さそうです。

mysql> select BUCKET_NUMBER, BUCKET_TIMER_LOW / 1000 / 1000 / 1000 as BUCKET_TIMER_LOW_MS,
BUCKET_TIMER_HIGH / 1000 / 1000 / 1000 as BUCKET_TIMER_HIGH_MS, COUNT_BUCKET_AND_LOWER
FROM events_statements_histogram_global where BUCKET_NUMBER % 50 = 1;
+---------------+----------------------+----------------------+------------------------+
| BUCKET_NUMBER | BUCKET_TIMER_LOW_MS | BUCKET_TIMER_HIGH_MS | COUNT_BUCKET_AND_LOWER |
+---------------+----------------------+----------------------+------------------------+
| 1 | 0.010000000000 | 0.010471285000 | 0 |
| 51 | 0.100000000000 | 0.104712854000 | 0 |
| 101 | 1.000000000000 | 1.047128548000 | 109 |
| 151 | 10.000000000000 | 10.471285480000 | 134 |
| 201 | 100.000000000000 | 104.712854805000 | 140 |
| 251 | 1000.000000000000 | 1047.128548050000 | 141 |
| 301 | 10000.000000000000 | 10471.285480509000 | 141 |
| 351 | 100000.000000002000 | 104712.854805092000 | 141 |
| 401 | 1000000.000000030000 | 1047128.548050931000 | 141 |
+---------------+----------------------+----------------------+------------------------+
9 rows in set (0.00 sec)