mysqldにおけるスロークエリログ判定実装

MySQL

スロークエリログはどのように計測され、出力されているのかをまとめてみました。

測定方法

THDクラスのset_time関数で計測開始、end_time関数で計測終了。

計測開始ポイント

  • mysqld --bootstrapを使用している場合はmysql_parse関数の直前
  • ネットワーク経由の場合はネットワークコマンド(COM_XXX)の種別判定直前
    • ただしQUERYコマンド(COM_QUERY、SQLCOM_XXX)の場合はmysql_parse関数の直前で再設定

というわけでまとめるとSQL文のparse直前に計測を開始

計測終了ポイント

  • thd->end_time関数自体はlog_slow_statement関数の中で呼ばれるのみ
  • log_slow_statement関数はSQL文の結果返却を含む全ての処理が終わった後、終了処理(お掃除)が走る直前で呼ばれる。
  • セミコロンによる複数行ステートメントの場合は各ステートメント終了時。

スロークエリログの出力

log_slow_statement関数はクエリ単位で必ず呼ばれ、その中でオプションの有無、設定した閾値、計測した値に基づいて出力する。

まとめ・補足

  • ネットワーク経由でコマンドを受け取った後の「parse」「optimize」「execution」「結果返却」全て処理時間の合算である。
  • mysqlコマンドラインクライアントで表示される実行時間はmysqlコマンド自身が計測した値で、mysqldサーバで計測したものとは別。

ついでに一般クエリログは？

  • 各ネットワークコマンドの処理の初期処理に相当するタイミング
    • COM_QUERY(SQL文)ならparse前

ということです。