Azure Database for MySQL - フレキシブル サーバーのクエリ パフォーマンスのトラブルシューティング

  • [アーティクル]

適用対象: Azure Database for MySQL - 単一サーバー Azure Database for MySQL - フレキシブル サーバー

重要

Azure Database for MySQL の単一サーバーは提供終了パスにあります。 Azure Database for MySQL フレキシブル サーバーにアップグレードすることを強くお勧めします。 Azure Database for MySQL フレキシブル サーバーへの移行の詳細については、「Azure Database for MySQL 単一サーバーの動作」を参照してください 。

クエリのパフォーマンスは複数の要因によって影響を受ける可能性があるため、まず、Azure Database for MySQL フレキシブル サーバー インスタンスで発生している症状の範囲を確認することが重要です。 たとえば、以下についてクエリのパフォーマンスが低下していますか?

  • Azure Database for MySQL フレキシブル サーバー インスタンスで実行されているすべてのクエリ
  • クエリの特定のセット
  • 特定のクエリ

また、クエリを実行しているテーブルの構造または基になるデータに対する最近の変更がパフォーマンスに影響を与える可能性があることにも注意してください。

ログ機能の有効化

個々のクエリを分析する前に、クエリ ベンチマークを定義する必要があります。 この情報を使用すると、データベース サーバーにログ機能を実装して、アプリケーションのニーズに基づいて指定したしきい値を超えるクエリをトレースできます。

Azure Database for MySQL フレキシブル サーバーでは、低速クエリ ログ機能を使用して、実行に N 秒より長い時間がかかるクエリを特定することをお勧めします。 低速クエリ ログでクエリを特定したら、MySQL 診断を使用してそれらのクエリをトラブルシューティングできます。

実行時間の長いクエリのトレースを開始するには、Azure portalまたは Azure CLI を使用して slow_query_log パラメーターを有効にしておく必要があります。 また、このパラメーターを有効にすると、"低速実行" クエリとして識別されるまでにクエリを実行できる秒数を指定する long_query_time パラメーターの値も構成する必要があります。 パラメーターの既定値は 10 秒ですが、アプリケーションの SLA のニーズに対応するように値を調整できます。

Azure Database for MySQL flexible server slow query log interface.

低速クエリ ログは実行時間の長いクエリをトレースするための優れたツールですが、効果がない可能性のあるシナリオもあります。 たとえば、低速クエリ ログは次のようになります。

  • クエリの数が非常に多い場合やクエリ ステートメントがきわめて大きい場合は、パフォーマンスに悪影響を与えます。 long_query_time パラメーターの値を適宜調整してください。
  • すべての行を取得することが予想されるクエリをログに記録するように指定する log_queries_not_using_index パラメーターも有効にしている場合は、役に立たない可能性があります。 インデックスのフル スキャンを実行するクエリはインデックスを利用しますが、インデックスでは返される行数が制限されないため、それらはログに記録されます。

ログからの情報の取得

ログは、作成日から最大 7 日間使用できます。 Azure portal または Azure CLI を介して低速クエリ ログをリストおよびダウンロードできます。 Azure portalで、サーバーに移動し、[監視] で [サーバー ログ] を選択してから、エントリの横にある下向き矢印を選択して、調査中の日時に関連するログをダウンロードします。

Azure Database for MySQL flexible server retrieving data from the logs.

また、低速クエリ ログが診断ログを介して Azure Monitor ログと統合されている場合は、エディターでクエリを実行してそれらをさらに分析できます。

AzureDiagnostics
| where Resource == '<your server name>'
| where Category == 'MySqlSlowLogs'
| project TimeGenerated, Resource , event_class_s, start_time_t , query_time_d, sql_text_s
| where query_time_d > 10

注意

診断ログを使用した低速クエリ ログの診断を開始するその他の例については、「Azure Monitor ログのログを分析する」を参照してください。

次のスナップショットは、低速クエリのサンプルを示しています。

# Time: 2021-11-13T10:07:52.610719Z
# User@Host: root[root] @  [172.30.209.6]  Id: 735026
# Query_time: 25.314811  Lock_time: 0.000000 Rows_sent: 126  Rows_examined: 443308
use employees;
SET timestamp=1596448847;
select * from titles where DATE(from_date) > DATE('1994-04-05') AND title like '%senior%';;

クエリが 26 秒で実行され、443,000 個を超える行が検査され、126 行の結果が返されていることに注意してください。

通常は、Query_time と Rows_examined の値が高いクエリに焦点を当てる必要があります。 ただし、クエリの Query_time は高いが、Rows_examined がわずかしかない場合は、多くの場合、リソースのボトルネックが存在することを示しています。 このような場合は、IO スロットルがあるかどうかや CPU 使用率を確認する必要があります。

クエリのプロファイリング

実行速度が遅い特定のクエリを特定したら、EXPLAIN コマンドとプロファイリングを使用して詳細を収集できます。

クエリ プランを確認するには、次のコマンドを実行します。

EXPLAIN <QUERY>

Note

EXPLAIN ステートメントの使用方法の詳細については、「EXPLAIN を使用して Azure Database for MySQL フレキシブル サーバーのクエリ パフォーマンスをプロファイリングする方法」を参照してください。

クエリの EXPLAIN プランの作成に加えて、SHOW PROFILE コマンドを使用して、現在のセッション内で実行されたステートメントの実行を診断できます。

プロファイリングを有効にして、セッションで特定のクエリをプロファイリングするには、次の一連のコマンドを実行します。

SET profiling = 1;
<QUERY>;
SHOW PROFILES;
SHOW PROFILE FOR QUERY <X>;

注意

個々のクエリのプロファイリングはセッションでのみ使用でき、履歴ステートメントはプロファイリングできません。

これらのコマンドを使用してクエリをプロファイリングする方法を詳しく見てみましょう。 まず、現在のセッションのプロファイリングを有効にして、SET PROFILING = 1 コマンドを次のように実行します。

mysql> SET PROFILING = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

次に、完全なテーブル スキャンを実行する準最適のクエリを実行します。

mysql> select * from sbtest8 where c like '%99098187165%';
+----+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+
| id | k       | c                                                                                                                       | pad                                                         |
+----+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+
| 10 | 5035785 | 81674956652-89815953173-84507133182-62502329576-99098187165-62672357237-37910808188-52047270287-89115790749-78840418590 | 91637025586-81807791530-84338237594-90990131533-07427691758 |
+----+---------+-------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------+
1 row in set (27.60 sec)

次に、SHOW PROFILES コマンドを実行して、使用可能なすべてのクエリ プロファイルの一覧を表示します。

mysql> SHOW PROFILES;
+----------+-------------+----------------------------------------------------+
| Query_ID | Duration    | Query                                              |
+----------+-------------+----------------------------------------------------+
|        1 | 27.59450000 | select * from sbtest8 where c like '%99098187165%' |
+----------+-------------+----------------------------------------------------+
1 row in set, 1 warning (0.00 sec)

最後に、クエリ 1 のプロファイルを表示するには、コマンド SHOW PROFILE FOR QUERY 1 を実行します。

mysql> SHOW PROFILE FOR QUERY 1;
+----------------------+-----------+
| Status               | Duration  |
+----------------------+-----------+
| starting             |  0.000102 |
| checking permissions |  0.000028 |
| Opening tables       |  0.000033 |
| init                 |  0.000035 |
| System lock          |  0.000018 |
| optimizing           |  0.000017 |
| statistics           |  0.000025 |
| preparing            |  0.000019 |
| executing            |  0.000011 |
| Sending data         | 27.594038 |
| end                  |  0.000041 |
| query end            |  0.000014 |
| closing tables       |  0.000013 |
| freeing items        |  0.000088 |
| cleaning up          |  0.000020 |
+----------------------+-----------+
15 rows in set, 1 warning (0.00 sec)

データベース サーバーで最もよく使用されるクエリを一覧表示する

クエリのパフォーマンスをトラブルシューティングするときは常に、Azure Database for MySQL フレキシブル サーバー インスタンスで最も頻繁に実行されるクエリを理解すると便利です。 この情報を使用して、上位のいずれかのクエリで実行に通常よりも時間がかかっているかどうかを判断できます。 さらに、開発者または DBA は、この情報を使用して、クエリの実行回数と期間が急激に増加したクエリがあるかどうかを確認できます。

Azure Database for MySQL フレキシブル サーバー インスタンスに対して最も実行された上位 10 個のクエリを一覧表示するには、次のクエリを実行します。

SELECT digest_text AS normalized_query,
 count_star AS all_occurrences,
 Concat(Round(sum_timer_wait / 1000000000000, 3), ' s') AS total_time,
 Concat(Round(min_timer_wait / 1000000000000, 3), ' s') AS min_time,
 Concat(Round(max_timer_wait / 1000000000000, 3), ' s') AS max_time,
 Concat(Round(avg_timer_wait / 1000000000000, 3), ' s') AS avg_time,
 Concat(Round(sum_lock_time / 1000000000000, 3), ' s') AS total_locktime,
 sum_rows_affected AS sum_rows_changed,
 sum_rows_sent AS sum_rows_selected,
 sum_rows_examined AS sum_rows_scanned,
 sum_created_tmp_tables,
 sum_select_scan,
 sum_no_index_used,
 sum_no_good_index_used
FROM performance_schema.events_statements_summary_by_digest
ORDER BY sum_timer_wait DESC LIMIT 10;

Note

このクエリを使用して、データベース サーバーで実行された上位のクエリをベンチマークし、上位クエリに変更があったかどうかや、初期ベンチマークの既存のクエリの実行時間が長くなったかどうかを判断します。

合計実行時間別に最も負荷の高い 10 個のクエリを一覧表示する

次のクエリの出力では、データベース サーバーに対して実行されている上位 10 個のクエリとそれらのデータベース サーバーでの実行回数に関する情報が提供されます。 さらに、クエリの待機時間、ロック時間、クエリ ランタイムの一部として作成された一時テーブルの数など、他の有用な情報も提供されます。このクエリ出力を使用して、データベースへの上位のクエリと待機時間などの要因の変化を追跡します。これは、将来のリスクを回避するためにクエリをさらに微調整する機会を示している可能性があります。

SELECT REPLACE(event_name, 'statement/sql/', '') AS statement, 
 count_star AS all_occurrences , 
 Concat(Round(sum_timer_wait / 1000000000000, 2), ' s') AS total_latency, 
 Concat(Round(avg_timer_wait / 1000000000000, 2), ' s') AS avg_latency, 
 Concat(Round(sum_lock_time / 1000000000000, 2), ' s') AS total_lock_time  , 
 sum_rows_affected AS sum_rows_changed, 
 sum_rows_sent AS  sum_rows_selected, 
 sum_rows_examined AS  sum_rows_scanned, 
 sum_created_tmp_tables,  sum_created_tmp_disk_tables, 
 IF(sum_created_tmp_tables = 0, 0, Concat( Truncate(sum_created_tmp_disk_tables / 
 sum_created_tmp_tables * 100, 0))) AS 
 tmp_disk_tables_percent, 
 sum_select_scan, 
 sum_no_index_used, 
 sum_no_good_index_used 
FROM performance_schema.events_statements_summary_global_by_event_name 
WHERE event_name LIKE 'statement/sql/%' 
 AND count_star > 0 
ORDER BY sum_timer_wait DESC 
LIMIT 10;

InnoDB ガベージ コレクションの監視

InnoDB ガベージ コレクションがブロックされたり遅延したりすると、データベースで大幅なパージ ラグが発生し、ストレージの使用率とクエリのパフォーマンスに悪影響を及ぼす可能性があります。

InnoDB ロールバック セグメントの履歴リストの長さ (HLL) は、undo (元に戻す) ログに保存されている変更レコードの数を測定します。 HLL 値の増加は、InnoDB のガベージ コレクション スレッド (パージ スレッド) が書き込みワークロードに追いついていないか、実行時間の長いクエリまたはトランザクションによってパージがブロックされていることを示します。

ガベージ コレクションの過度の遅延は、次のような重大な悪影響を及ぼす可能性があります。

  • InnoDB システムのテーブルスペースが拡大するため、基になるストレージ ボリュームの増加が加速します。 場合によっては、システム テーブルスペースは、パージがブロックされた結果、数テラバイトまで膨れ上がる可能性があります。
  • 削除のマークが付けられたレコードが、タイムリーに削除されません。 これにより、InnoDB テーブルスペースが拡大する可能性があり、これらのレコードによって占有されているストレージをエンジンで再利用できなくなります。
  • InnoDB ストレージ構造の拡大により、すべてのクエリのパフォーマンスが低下し、CPU 使用率が増加する可能性があります。

そのため、HLL の値、パターン、傾向を監視することが重要です。

HLL 値の検索

HLL 値を検索するには、show engine innodb status コマンドを実行します。 この値は、TRANSACTIONS 見出しの下の出力にリストされます。

mysql> show engine innodb status\G 
*************************** 1. row *************************** 
 
(...) 
 
------------ 
TRANSACTIONS 
------------ 
Trx id counter 52685768 
Purge done for trx's n:o < 52680802 undo n:o < 0 state: running but idle 
History list length 2964300 
 
(...)

HLL 値は、information_schema.innodb_metrics テーブルに対してクエリを実行して確認することもできます。

mysql> select count from information_schema.innodb_metrics  
    -> where name = 'trx_rseg_history_len'; 
+---------+ 
|  count  | 
+---------+ 
| 2964300 | 
+---------+ 
1 row in set (0.00 sec)

HLL 値の解釈

HLL 値を解釈するときは、次の表に示すガイドラインを考慮してください。

値 注
10,000 未満 通常の値。ガベージ コレクションが遅れていないことを示します。
10,000 から 1,000,000 の間 これらの値は、ガベージ コレクションがわずかに遅れていることを示します。 これらの値は、安定した状態が続き、増加しない場合は許容できます。
1,000,000 より大きい これらの値は調査する必要があり、是正措置が必要になる場合があります

過剰な HLL 値への対処

HLL が大きなスパイクを示したり、定期的な増加のパターンを示したりする場合は、Azure Database for MySQL フレキシブル サーバー インスタンスで実行されているクエリとトランザクションを直ちに調査します。 その後、ガベージ コレクション プロセスの進行を妨げている可能性があるワークロードの問題を解決できます。 データベースでパージ ラグが発生しないことは想定されていませんが、無制限に遅延を拡大させないようにする必要があります。

たとえば、information_schema.innodb_trx テーブルからトランザクション情報を取得するには、次のコマンドを実行します。

select * from information_schema.innodb_trx  
order by trx_started asc\G

trx_started 列の詳細は、トランザクションの経過時間を計算するのに役立ちます。

mysql> select * from information_schema.innodb_trx  
    -> order by trx_started asc\G 
*************************** 1. row *************************** 
                    trx_id: 8150550 
                 trx_state: RUNNING 
               trx_started: 2021-11-13 20:50:11 
     trx_requested_lock_id: NULL 
          trx_wait_started: NULL 
                trx_weight: 0 
       trx_mysql_thread_id: 19 
                 trx_query: select * from employees where DATE(hire_date) > DATE('1998-04-05') AND first_name like '%geo%';
(…)

セッションの現在の状態で費やされた時間など、現在のデータベース セッションの詳細については、information_schema.processlist テーブルを確認してください。 たとえば、次の出力は、過去 1462 秒間クエリをアクティブに実行しているセッションを示しています。

mysql> select user, host, db, command, time, info  
    -> from information_schema.processlist  
    -> order by time desc\G 
*************************** 1. row *************************** 
   user: test 
   host: 172.31.19.159:38004 
     db: employees 
command: Query 
   time: 1462 
   info: select * from employees where DATE(hire_date) > DATE('1998-04-05') AND first_name like '%geo%';
 
(...)

Recommendations

  • クエリを実行するのに十分なリソースがデータベースに割り当てられていることを確認します。 場合によっては、ワークロードに合わせて、インスタンス サイズをスケールアップして、CPU コアとメモリをさらに取得する必要が生じることもあります。

  • 小さいトランザクションに分割することにより、大規模または実行時間の長いトランザクションを回避します。

  • ワークロードに応じて innodb_purge_threads を構成し、バックグラウンドのパージ操作の効率を向上させます。

    注意

    環境ごとにこのサーバー変数に対する変更をテストして、エンジン動作の変化を確認します。

  • システムが指定されたしきい値のいずれかを超えた場合に通知を受け取るように、"ホストの CPU 使用率"、"ホストのメモリ使用率"、"合計接続数" のアラートを使用します。

  • Query Performance Insights または Azure Workbooks を使用して、問題が発生していたり実行に時間がかかったりするクエリを特定し、それらを最適化します。

  • 運用データベース サーバーの場合は、診断を定期的に収集して、すべてがスムーズに実行されていることを確認します。 そうでない場合は、特定した問題をトラブルシューティングして解決します。

次の手順

重要度の高い質問に対する回答を見つける、質問を投稿する、または回答するには、Stack Overflow にアクセスしてください。