tom__bo’s Blog

えんじにゃ〜

MySQLで実行された全てのクエリを取得する

MySQLで実行された全てのクエリを把握する方法を挙げてみる。 いくつか方法はあるが、負荷の高い環境でクエリをとるにはうするのが良いだろうか?

パフォーマンスチューニングが主たる目的なので、Restoreからロールフォワードすることは考えない。 SELECT文が取れないので、SBR形式でbinary_logを書くことも除く。 version, 5.6, 5.7あたりを想定。

general_log

標準的なクエリ取得方法。 general_log = 'ON' に設定することで取得する。

標準的なやり方だが、全てのクエリがgeneral_log_fileに書き込まれるのでパフォーマンスの悪化が大きい。 ここに書き込まれる順番はmysqldがクエリを受け取った順番なので、実行順序とは異なる。

MySQL :: MySQL 5.7 Reference Manual :: 5.4.3 The General Query Log

再起動不要。

2018-06-23T17:27:52.827345Z      6 Query select * from t1

slow_query_log, long_query_time = 0

閾値を0にしてスロークエリ(すべてのクエリ)をロギングする。 general_logと同じようにファイルに書くのでパフォーマンスへの影響は大きい。 ファイル書き込みで遅くなる分と比べれば大した違いではないと思うが、閾値との比較が入る分微妙に遅くなるんじゃないかと思う。

Administrative statementsやインデックスを使わないクエリはデフォルトでは出力されないので注意が必用
これらを取得するには、それぞれlog_slow_admin_statements, log_queries_not_using_indexesをONにする必用がある。

Administrative statements include ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE, and REPAIR TABLE. 参照

2つのオプション含め再起動不要

# Time: 2018-06-23T17:27:52.827545Z
# User@Host: tombo[tombo] @  [192.168.1.9]  Id:     6
# Query_time: 0.000240  Lock_time: 0.000128 Rows_sent: 0  Rows_examined: 0
SET timestamp=1529774872;
select * from t1;

events_statements_history テーブルを使う

performance_schemaのstatement event tableを使う。

MySQL :: MySQL 5.7 Reference Manual :: 24.11.6 Performance Schema Statement Event Tables

current, history, history_longと保持してくれている量に違いがあるので、欠損しない間隔でpollingして取得すればすべてのクエリが取れる。 DIGEST_STATEMENTである程度パラメータを抽象化したクエリが取れるほか、Instrumentsからの計測結果も取得できる。 currentを除くhistory系の保持件数performance_schema_events_stages_history(long)sizeの変更は再起動が必用

mysql> select * from  performance_schema.events_statements_history\G
...略
*************************** 15. row ***************************
              THREAD_ID: 31
               EVENT_ID: 5
           END_EVENT_ID: 5
             EVENT_NAME: statement/sql/select
                 SOURCE: socket_connection.cc:101
            TIMER_START: 488005568226000
              TIMER_END: 488005868363000
             TIMER_WAIT: 300137000
              LOCK_TIME: 128000000
               SQL_TEXT: select * from t1
                 DIGEST: 23a2bd5d5f00f61920a837cbec0340c8
            DIGEST_TEXT: SELECT * FROM `t1`
         CURRENT_SCHEMA: sample
            OBJECT_TYPE: NULL
          OBJECT_SCHEMA: NULL
            OBJECT_NAME: NULL
  OBJECT_INSTANCE_BEGIN: NULL
            MYSQL_ERRNO: 0
      RETURNED_SQLSTATE: NULL
           MESSAGE_TEXT: NULL
                 ERRORS: 0
               WARNINGS: 0
          ROWS_AFFECTED: 0
              ROWS_SENT: 0
          ROWS_EXAMINED: 0
CREATED_TMP_DISK_TABLES: 0
     CREATED_TMP_TABLES: 0
       SELECT_FULL_JOIN: 0
 SELECT_FULL_RANGE_JOIN: 0
           SELECT_RANGE: 0
     SELECT_RANGE_CHECK: 0
            SELECT_SCAN: 1
      SORT_MERGE_PASSES: 0
             SORT_RANGE: 0
              SORT_ROWS: 0
              SORT_SCAN: 0
          NO_INDEX_USED: 1
     NO_GOOD_INDEX_USED: 0
       NESTING_EVENT_ID: NULL
     NESTING_EVENT_TYPE: NULL
    NESTING_EVENT_LEVEL: 0
15 rows in set (0.00 sec)

MySQLへのパッケットをキャプチャする

tcpdumpwiresharkMySQLが使うportでフィルタしてパケットをキャプチャする。 デコードする必用があるのと、SSLで通信されているとdecryptしないといけない。

MySQLが動作している端末でキャプチャする方法とルーター等でポートミラーリングして他の端末でキャプチャする方法があり、後者のほうがMySQLのパフォーマンスには影響しにくいと思うが、ポートミラーリングによるネットワーク機器への負荷はどのくらい問題になるのかわからない。

f:id:tom__bo:20180624113502p:plain

感想

event_statements_historytcpdumpのどちらかでやるのがよさそうだけど、それぞれがどのくらいIO, Memory, CPUを圧迫するかは実験してみよう。 そもそもこういうのってコンプライアンス的に難しいのか?サービスによるのか?