コストの高いクエリを特定する
TiDBを使用すると、SQL実行中に高負荷なクエリを特定できるため、SQL実行のパフォーマンスを診断・改善できます。具体的には、実行時間がtidb_expensive_query_time_threshold (デフォルトでは60秒)を超える、またはメモリ使用量がtidb_mem_quota_query (デフォルトでは1GB)を超えるステートメントに関する情報が、 tidb-server ログファイル (デフォルトでは「tidb.log」)に出力されます。
注記:
高価なクエリ ログは、次の点でスロークエリログと異なります。TiDB は、ステートメントがリソース使用量 (実行時間またはメモリ使用量) のしきい値を超えるとすぐにステートメント情報を高価なクエリ ログに出力出力。一方、TiDB は、ステートメントの実行後にステートメント情報を低速クエリ ログに出力。
高価なクエリログの例
[expensivequery.go:145] [expensive_query] [cost_time=60.021998785s] [cop_time=0.022540151s] [process_time=28.448316643s] [wait_time=0.045507163s] [request_count=430] [total_keys=3538276] [process_keys=3537846] [num_cop_tasks=430] [process_avg_time=0.066158875s] [process_p90_time=0.140427865s] [process_max_time=0.27903656s] [process_max_addr=tikv-1-peer:20160] [wait_avg_time=0.00010583s] [wait_p90_time=0.000358794s] [wait_max_time=0.001218721s] [wait_max_addr=tikv-1-peer:20160] [stats=usertable:451469035823955972] [conn=1621098504] [user=root] [database=test] [table_ids="[104]"] [txn_start_ts=451469037501677571] [mem_max="621043469 Bytes (592.3 MB)"] [sql="insert /*+ SET_VAR(tidb_dml_type=bulk) */ into usertable_2 select * from usertable limit 5000000"] [session_alias=] ["affected rows"=3505282]]
フィールドの説明
基本フィールド:
cost_time: ログが印刷されるときのステートメントの実行時間。stats: 文に関係するテーブルまたはインデックスで使用される統計情報のバージョン。値がpseudo場合、利用可能な統計情報がないことを意味します。この場合、テーブルまたはインデックスを分析する必要があります。table_ids: ステートメントに関係するテーブルの ID。txn_start_ts: トランザクションの開始タイムスタンプと一意のID。この値を使用して、トランザクション関連のログを検索できます。sql: SQL ステートメント。session_alias: 現在のセッションのエイリアス。affected rows: 現在ステートメントによって影響を受けている行数。
メモリ使用量関連のフィールド:
mem_max: ログ出力時のステートメントのメモリ使用量。このフィールドには、メモリ使用量を測定するための単位として、バイトと、その他の読みやすく適応性の高い単位(MBやGBなど)の2種類があります。
ユーザー関連フィールド:
user: ステートメントを実行するユーザーの名前。conn_id: 接続ID(セッションID)。例えば、キーワードcon:60026を使用すると、セッションIDが60026ログを検索できます。database: ステートメントが実行されるデータベース。
TiKVコプロセッサータスク関連フィールド:
wait_time: TiKV 内のステートメントにおけるすべてのコプロセッサー要求の合計待機時間。TiKV のコプロセッサーは限られた数のスレッドを実行するため、コプロセッサーのすべてのスレッドが動作している場合でも、要求がキューイングされる可能性があります。キュー内の要求の処理に時間がかかる場合、後続の要求の待機時間が増加します。request_count: ステートメントが送信するコプロセッサー要求の数。total_keys:コプロセッサーがスキャンしたキーの数。processed_keys:コプロセッサーが処理したキーの数。2 と比較すると、total_keysprocessed_keys古いバージョンの MVCC は含まれません。6 とprocessed_keystotal_keys差が大きいことから、古いバージョンが多数存在することがわかります。num_cop_tasks: ステートメントが送信するコプロセッサー要求の数。process_avg_time:コプロセッサータスクの平均実行時間。process_p90_time:コプロセッサータスクの P90 実行時間。process_max_time:コプロセッサータスクの最大実行時間。process_max_addr: 実行時間が最も長いコプロセッサータスクのアドレス。wait_avg_time:コプロセッサータスクの平均待機時間。wait_p90_time:コプロセッサータスクの P90 待機時間。wait_max_time:コプロセッサータスクの最大待機時間。wait_max_addr: 待機時間が最も長いコプロセッサータスクのアドレス。