Serverside Prepare Statementの統計情報を見る
この記事は MySQL Casual Advent Calendar 2018 の12日目の記事です。
さて、MySQLでSQLステートメントの統計情報を見る時ってどうしますか? 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 について軽い感じで書きます」です。楽しみですね。