kenken0807_DBメモ

つば九郎が好きなDBAです。Oracle Standard Editionでの運用やツールとかとかの備忘録。特に記載がない場合はoracle11gR2です。時々MySQL

Serverside Prepare Statementの統計情報を見る

この記事は MySQL Casual Advent Calendar 2018 の12日目の記事です。

さて、MySQLSQLステートメントの統計情報を見る時ってどうしますか? performance_schema.events_statements_summary_by_digest テーブルであったり、sys.statement_analysis ビューを見ますよね。少なくとも私は見ます。

しかし、残念ながら events_statements_summary_by_digest には serverside prepare statement の情報は収集されないのです。

MySQL5.7以降からは performance_schema に prepared_statements_instances テーブルがあり、 ここから serverside prepare statement のキャッシュされたステートメントや統計情報が確認できるようになりました。

mysql > show create table prepared_statements_instances\G
*************************** 1. row ***************************
       Table: prepared_statements_instances
Create Table: CREATE TABLE `prepared_statements_instances` (
  `OBJECT_INSTANCE_BEGIN` bigint(20) unsigned NOT NULL,
  `STATEMENT_ID` bigint(20) unsigned NOT NULL,
  `STATEMENT_NAME` varchar(64) DEFAULT NULL,
  `SQL_TEXT` longtext NOT NULL,
  `OWNER_THREAD_ID` bigint(20) unsigned NOT NULL,
  `OWNER_EVENT_ID` bigint(20) unsigned NOT NULL,
  `OWNER_OBJECT_TYPE` enum('EVENT','FUNCTION','PROCEDURE','TABLE','TRIGGER') DEFAULT NULL,
  `OWNER_OBJECT_SCHEMA` varchar(64) DEFAULT NULL,
  `OWNER_OBJECT_NAME` varchar(64) DEFAULT NULL,
  `TIMER_PREPARE` bigint(20) unsigned NOT NULL,
  `COUNT_REPREPARE` bigint(20) unsigned NOT NULL,
  `COUNT_EXECUTE` bigint(20) unsigned NOT NULL,
  `SUM_TIMER_EXECUTE` bigint(20) unsigned NOT NULL,
  `MIN_TIMER_EXECUTE` bigint(20) unsigned NOT NULL,
  `AVG_TIMER_EXECUTE` bigint(20) unsigned NOT NULL,
  `MAX_TIMER_EXECUTE` bigint(20) unsigned NOT NULL,
  `SUM_LOCK_TIME` bigint(20) unsigned NOT NULL,
  `SUM_ERRORS` bigint(20) unsigned NOT NULL,
  `SUM_WARNINGS` bigint(20) unsigned NOT NULL,
  `SUM_ROWS_AFFECTED` bigint(20) unsigned NOT NULL,
  `SUM_ROWS_SENT` bigint(20) unsigned NOT NULL,
  `SUM_ROWS_EXAMINED` bigint(20) unsigned NOT NULL,
  `SUM_CREATED_TMP_DISK_TABLES` bigint(20) unsigned NOT NULL,
  `SUM_CREATED_TMP_TABLES` bigint(20) unsigned NOT NULL,
  `SUM_SELECT_FULL_JOIN` bigint(20) unsigned NOT NULL,
  `SUM_SELECT_FULL_RANGE_JOIN` bigint(20) unsigned NOT NULL,
  `SUM_SELECT_RANGE` bigint(20) unsigned NOT NULL,
  `SUM_SELECT_RANGE_CHECK` bigint(20) unsigned NOT NULL,
  `SUM_SELECT_SCAN` bigint(20) unsigned NOT NULL,
  `SUM_SORT_MERGE_PASSES` bigint(20) unsigned NOT NULL,
  `SUM_SORT_RANGE` bigint(20) unsigned NOT NULL,
  `SUM_SORT_ROWS` bigint(20) unsigned NOT NULL,
  `SUM_SORT_SCAN` bigint(20) unsigned NOT NULL,
  `SUM_NO_INDEX_USED` bigint(20) unsigned NOT NULL,
  `SUM_NO_GOOD_INDEX_USED` bigint(20) unsigned NOT NULL,
  PRIMARY KEY (`OBJECT_INSTANCE_BEGIN`),
  UNIQUE KEY `OWNER_THREAD_ID` (`OWNER_THREAD_ID`,`OWNER_EVENT_ID`),
  KEY `STATEMENT_ID` (`STATEMENT_ID`),
  KEY `STATEMENT_NAME` (`STATEMENT_NAME`),
  KEY `OWNER_OBJECT_TYPE` (`OWNER_OBJECT_TYPE`,`OWNER_OBJECT_SCHEMA`,`OWNER_OBJECT_NAME`)
) ENGINE=PERFORMANCE_SCHEMA DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
1 row in set (0.00 sec)

(MySQL8.0.13を使ってます。)

このテーブルにはevents_statements_summary_by_digestと同じように、そのステートメントのトータルレイテンシーや実行回数などが格納されます。 セッション単位でprepareされたタイミングでレコードを確認することができて、同一のステートメントであったとしても集約せずにそれぞれ作成されます。

Session 1
mysql> PREPARE s1_statement FROM 'select sleep(?)';
Query OK, 0 rows affected (0.00 sec)
Statement prepared

Session 2
mysql> PREPARE s2_statement FROM 'select sleep(?)';
Query OK, 0 rows affected (0.00 sec)
Statement prepared

mysql> SELECT STATEMENT_NAME,SQL_TEXT  FROM performance_schema.prepared_statements_instances;
+----------------+-----------------+
| STATEMENT_NAME | SQL_TEXT        |
+----------------+-----------------+
| s1_statement   | select sleep(?) |
| s2_statement   | select sleep(?) |
+----------------+-----------------+

実行すると、それぞれのステートメント統計情報がカウントされます。

Session 1
mysql> SET @t=1;
Query OK, 0 rows affected (0.00 sec)

mysql> EXECUTE s1_statement USING @t;
+----------+
| sleep(?) |
+----------+
|        0 |
+----------+
1 row in set (1.00 sec)

mysql> SET @t=10;
Query OK, 0 rows affected (0.00 sec)

mysql> EXECUTE s1_statement USING @t;
+----------+
| sleep(?) |
+----------+
|        0 |
+----------+
1 row in set (10.00 sec)

Session 2
mysql> SET @t=5;
Query OK, 0 rows affected (0.00 sec)

mysql> EXECUTE s2_statement USING @t;
+----------+
| sleep(?) |
+----------+
|        0 |
+----------+
1 row in set (5.00 sec)

mysql> SELECT STATEMENT_NAME,SQL_TEXT,COUNT_EXECUTE,SUM_TIMER_EXECUTE,SUM_ROWS_EXAMINED  FROM performance_schema.prepared_statements_instances;
+----------------+-----------------+---------------+-------------------+-------------------+
| STATEMENT_NAME | SQL_TEXT        | COUNT_EXECUTE | SUM_TIMER_EXECUTE | SUM_ROWS_EXAMINED |
+----------------+-----------------+---------------+-------------------+-------------------+
| s1_statement   | select sleep(?) |             2 |    11001261779000 |                 0 |
| s2_statement   | select sleep(?) |             1 |     5000721345000 |                 0 |
+----------------+-----------------+---------------+-------------------+-------------------+

そして、これを同一ステートメントを集計してsys.statement_analysis ビューっぽく人間が理解しやすいように見たいときは、こんな感じ(ビューのSQLは拝借)で実行します。

mysql>    SELECT 
        `sys`.`format_statement`(ps_psi.`SQL_TEXT`) AS `query`,
        IF(((SUM(ps_psi.`SUM_NO_GOOD_INDEX_USED`) > 0)
                OR (SUM(ps_psi.`SUM_NO_INDEX_USED`) > 0)),
            '*',
            '') AS `full_scan`,
       SUM(ps_psi.`COUNT_EXECUTE`) AS `exec_count`,
       SUM(ps_psi.`SUM_ERRORS`) AS `err_count`,
       SUM(ps_psi.`SUM_WARNINGS`) AS `warn_count`,
        `sys`.`format_time`(SUM(ps_psi.`SUM_TIMER_EXECUTE`)) AS `total_latency`,
        `sys`.`format_time`(SUM(ps_psi.`MAX_TIMER_EXECUTE`)) AS `max_latency`,
        `sys`.`format_time`(SUM(ps_psi.`AVG_TIMER_EXECUTE`)) AS `avg_latency`,
        `sys`.`format_time`(SUM(ps_psi.`SUM_LOCK_TIME`)) AS `lock_latency`,
       SUM(ps_psi.`SUM_ROWS_SENT`) AS `rows_sent`,
        ROUND(IFNULL((SUM(ps_psi.`SUM_ROWS_SENT`) / NULLIF(SUM(ps_psi.`COUNT_EXECUTE`),
                                0)),
                        0),
                0) AS `rows_sent_avg`,
       SUM(ps_psi.`SUM_ROWS_EXAMINED`) AS `rows_examined`,
        ROUND(IFNULL((SUM(ps_psi.`SUM_ROWS_EXAMINED`) / NULLIF(SUM(ps_psi.`COUNT_EXECUTE`),
                                0)),
                        0),
                0) AS `rows_examined_avg`,
       SUM(ps_psi.`SUM_ROWS_AFFECTED`) AS `rows_affected`,
        ROUND(IFNULL((SUM(ps_psi.`SUM_ROWS_AFFECTED`) / NULLIF(SUM(ps_psi.`COUNT_EXECUTE`),
                                0)),
                        0),
                0) AS `rows_affected_avg`,
       SUM(ps_psi.`SUM_CREATED_TMP_TABLES`) AS `tmp_tables`,
       SUM(ps_psi.`SUM_CREATED_TMP_DISK_TABLES`) AS `tmp_disk_tables`,
       SUM(ps_psi.`SUM_SORT_ROWS`) AS `rows_sorted`,
       SUM(ps_psi.`SUM_SORT_MERGE_PASSES`) AS `sort_merge_passes`,
       ps_psi.`SQL_TEXT`
    FROM
        `performance_schema`.`prepared_statements_instances` ps_psi GROUP BY ps_psi.`SQL_TEXT`
    ORDER BY SUM(ps_psi.`SUM_TIMER_EXECUTE`) DESC\G

*************************** 1. row ***************************
            query: select sleep(?)
        full_scan:
       exec_count: 3
        err_count: 0
       warn_count: 0
    total_latency: 16.00 s
      max_latency: 15.00 s
      avg_latency: 10.50 s
     lock_latency: 0 ps
        rows_sent: 3
    rows_sent_avg: 1
    rows_examined: 0
rows_examined_avg: 0
    rows_affected: 0
rows_affected_avg: 0
       tmp_tables: 0
  tmp_disk_tables: 0
      rows_sorted: 0
sort_merge_passes: 0
         SQL_TEXT: select sleep(?)
1 row in set (0.00 sec)

これでserverside prepare statementを使用したアプリがあったとしても、ステートメントの統計情報が見れてめでたしめでたし。
と思ったのですが、これdeallocateすると消えます

Session 1
mysql> DEALLOCATE  PREPARE s1_statement;
Query OK, 0 rows affected (0.00 sec)

Session 2
mysql> DEALLOCATE PREPARE s2_statement;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT STATEMENT_NAME,SQL_TEXT  FROM performance_schema.prepared_statements_instances;
Empty set (0.00 sec)

以上です。

明日は@taka_yuki_04さんで「zerofill について軽い感じで書きます」です。楽しみですね。