スマートスタイル TECH BLOG

データベース&クラウド技術情報

pt-query-digest と Metabase でスロークエリログを可視化してみる

はじめに

MySQL のスロークエリチューニングを行っていると、スロークエリの情報を分析するためにデータを可視化したいというニーズが少なからず発生するのではと思います。

弊社では、スロークエリログの分析ツールとして Percona Toolkit の pt-query-digest を主に使用しています。

pt-query-digest の出力レポート(以降、ダイジェストレポートと呼ぶことにします)では、各クエリごとの詳細レポートが表示されます。

たとえば、このスロークエリの発生状況を知りたい場合、以下の情報は読み取ることができます。

  • Time range から、最初と最後に発生した日時の範囲
  • Count から、スロークエリログの総発生回数

ただし、このスロークエリが時間帯ごとに何回発生しているか、発生間隔はどの程度かを知りたい時はこの情報のみでは不明です。

スロークエリとして出現しているが、チューニング対象とすべきか精査したい場合(夜間帯にのみ集中していて、バッチ処理であることを推定したり)や、
長期的な観察視点で、いつ時点から発生したか(またはチューニングや改修により収束したか)を把握したいというケースが想定されます。

MySQL のスロークエリログを可視化するツールとしては、Anemometer(およびyoku0825氏によるラッパーツールanemoeater) が著名です。

GitHub – box/Anemometer: Box SQL Slow Query Monitor
GitHub – yoku0825/anemoeater: Wrapper-script for box/Anemometer

ただ、本家(Anemometer)は開発が止まってしまっている状況であること、また、yoku0825氏が anemoeater で言及している通り、Percona Toolkit 3.0.11 以降の pt-query-digest では動かないという問題があります。
※詳しくはこちらをご一読ください。

特にこれらを気にする必要がなければ、Anemometer を使用する、という選択で問題ありません。

また、昨今では、Datadog や Splank を使ってスロークエリログを(ある程度パースした上で)データ投入し、分析を行っているというユーザも多いのではないかと思います。

本記事では、これからスロークエリの分析を行いたく、まずは可視化を手軽に行ってみたいユーザであったり、他の仕組みを使ってみようと考えているユーザに向けて、pt-query-digest と、OSS の BI ツール Metabase を使った方法を紹介します。

  • ※ちなみに、Percona Monitoring and Management 2 (PMM2) であれば、Query Analytics(QAN) という機能が使用可能ですので、細やかなクエリ分析が可能です。
    ただし、今回紹介している時系列発生状況はQPSであれば確認できるようですが、細かくドリルダウンすることができないようです。

    • PMM2 はDemoが公開されていますので、ぜひ一度操作を体感してみてください。

用意する動作環境

今回ご紹介する内容は、Linux OS で以下のソフトウェアがインストール・使用可能であることを前提としています。

  • docker, docker-compose
  • pt-query-digest

なお、本記事での使用バージョンは以下の通りでした。

pt-query-digest による時系列レポートの出力

ダイジェストレポートでは、デフォルトで fingerprint (リテラルが削除され、ホワイトスペースが折りたたまれた、抽象化されたクエリテキスト) 単位で集約化されます。

ただし、前述の通り発生日時や回数もまとめられてしまうため、その内訳を知ることができません。

そこで、--timeline オプションを使います。

pt-query-digest | –timeline

この機能は、入力されたスロークエリログの全エントリを対象に、発生日時と回数を集計して時系列でレポート出力してくれます。

以下は、fingerprint 単位でグルーピングして、時系列レポートのみを別ファイルに出力するコマンド例です。
--no-report を付けなければ、ダイジェストレポートの最後尾に時系列レポートが追記されます。

出力内容はこのようになります。

タイムスタンプの次のカラムは、そのクエリグループから最初に出現したクエリと最後に出現したクエリの時間差を表しています。
上のサンプルにはありませんが、1+00:00:16 という表現の場合、「前回発生から1日と16秒経過して再度発生した」という意味合いになります。

その隣のカラムは発生回数を表しています。

この時点で、時系列レポートを csv や tsv に編集し直して、Excel や スプレッドシートといったソフトウェアにインポートして、ピボットテーブル/グラフでデータ分析してしまっても、それはそれでありだと思います。(一過性の問題対応時など)

ただし、スロークエリログの入力量が多かったり、日々の運用プロセスにおいて継続的な確認を行っていきたい場合は、データベースでのデータ管理と BI ツールでデータ可視化を効率よく行っていきたいニーズは高まると思いますし、チームや組織といった関係者間での共有も容易になるメリットがありますので、そうしたほうがおすすめです。

時系列レポートのTSV化

ここでもうひと手間、後述する DB(MySQL) へのデータロード用に、先ほどの時系列レポートデータを TSV 化する awk スクリプトを作成しておきましょう。

以下のコードを query_timeline_to_tsv.awk というファイル名で保存し、実行権限を付与しておきます。

この awk スクリプトを先ほどの時系列レポートに噛ませ、最後にタイムスタンプでソートします。

このスクリプトのポイントは、クエリの fingerprint を MD5 チェックサム値に変換して出力しているところです。

これにより、ダイジェストレポートとの紐付けが容易に行えるようになります。

試しに、ダイジェストレポートをチェックサム値で grep すると、レポート内の各クエリの ID と合致することが確認できます。

ダイジェストレポートにおけるクエリ ID は 0x が先頭に付与されていますが、これは pt-query-digest がレポート出力時に MD5 チェックサム値に後付けしたものになります。

今回の時系列レポートのほうは、0x を付与しないでそのままの形式で出力しておきます。(理由は後述します)

なお、元の時系列レポートデータに含まれていた「前回発生時からの時間差」データは、今回不要だったため DB にロードする対象外としました。(TSVには含めておいて、LOAD DATA コマンドで対象カラムを落とすのでも構いません)

Metabase + MySQL 環境を Docker で構築する

Metabase についてはこちらもメジャーなソフトウェアですので、説明は割愛させていただきます。

Metabase | Business Intelligence, Dashboards, and Data Visualization

手軽に利用開始できるのが嬉しいですね。
今回は Docker コンテナ版で環境構築してみます。

Metabase Documentation | Running Metabase on Docker

work ディレクトリ配下で docker-compose.yml を作成します。

以下は docker-compose.yml の設定例です。(簡易的にパスワード等をベタで指定していますのでご注意ください)

注意点としては、MySQL の起動オプションの2つの指定です。

それ以外の設定については、お好みに併せて変更いただいて構いません。

Metabase と MySQL コンテナを起動します。

Metabase は以下URLでアクセスできます。(localhostは環境に合わせて適宜変更)

http://localhost:13000/

画面上のガイドに沿って初期設定を済ませておきましょう。(説明は割愛します)

ちなみに、本記事ではローカライゼーションは英語にしています。 (少し違和感がある日本語表記のため)
また、日時表記に関しては、以下のように設定を変更しています。

クエリ分析用テーブルの作成

時系列レポートデータ用のテーブルを作成しておきます。
※スキーマはコンテナ作成時に自動作成済み

時系列レポートデータのロード

時系列レポート出力 --> awk スクリプトでチェックサム変換・TSV 化 --> MySQL へデータロード という処理を行っています。

Metabase でデータを可視化してみる

ここからは Metabase の画面に遷り、ロードしたデータを可視化して眺めてみましょう。

初期設定時に DB への接続設定が済んでいるはずですので、Browse data > query_analyze > Query Timeline と遷移するとデータがテーブル形式で表示されます。

画面下部の Visualization をクリックし、Bar(棒グラフ)を選択してみると、簡単にグラフ化されました。

チェックサムが凡例となっています。ここで凡例上の特定のチェックサムをクリックすると、フィルタされたデータが表示されます。


テーブル形式の状態から、フィルタをかけることも可能です。


他の BI ツールでも備わっているのか、細かい比較はできていませんが、Metabase では細やかなフィルタリング機能が備わっている点が、非常に使いやすくおすすめなポイントです。

たとえば、日中(サービス提供時間帯)のみのデータに絞りたい場合はこのようなフィルタが可能です。

特定の一週間のみのデータに絞ったグラフはこのようになります。

画面右上の + New ボタンから、独自のクエリ(画面操作・SQLなど)を作成し、保存することができます。

クエリ結果は、csv/xlsx/json 形式でダウンロードもできますので、データの2次利用が可能です。

そして、特定のグループでダッシュボードを作成し、クエリ結果のグラフをまとめて表示することで、ユーザが柔軟にカスタマイズできる点は、他の BI ツール同様かと思います。

Dashboard Examples | Metabase

なによりも、UIの見やすさや操作のしやすさは Metabase を選ぶ大きなポイントではないかと思います。

pt-query-digest のクエリヒストリ, クエリレビューデータDB保存機能を併用する

pt-query-digest には、ダイジェストレポートの出力を DB に保存する機能が備わっています。

pt-query-digest | DESCRIPTION

Query analysis is a best-practice that should be done frequently. To make this easier, pt-query-digest has two features: query review (–review) and query history (–history). When the –review option is used, all unique queries are saved to a database. When the tool is ran again with –review, queries marked as reviewed in the database are not printed in the report. This highlights new queries that need to be reviewed. When the –history option is used, query metrics (query time, lock time, etc.) for each unique query are saved to database. Each time the tool is ran with –history, the more historical data is saved which can be used to trend and analyze query performance over time.

pt-query-digest | –review
pt-query-digest | –history

この機能を併用して、先ほどロードした時系列レポートデータとダイジェストレポートの分析データを関連付けて更なるデータ分析も可能になります。

ここで、それぞれのテーブルは MD5 チェックサム値で繋げることができます。(時系列レポートデータ側のチェックサム先頭に 0x を付けなかったのはこのためです)

クエリヒストリ、クエリレビューデータの格納テーブルのDDLは以下になります。

マニュアル を見ていただくと気付くかと思いますが、Percona Server for MySQL を使用する場合、スロークエリログ拡張が実装されているため、より多くの Attribute と Metrics データを格納することが可能です。

— Percona extended slowlog attributes
http://www.percona.com/docs/wiki/patches:slow_extended

Percona Server for MySQL 8.0 のスロークエリログ拡張について詳細は以下のドキュメントをご参照ください。

また、fingerprintsample のデータ型を TEXT(マニュアルデフォルト) から MEDIUMTEXT に変更していますが、長大なクエリを格納する場合に文字列長不足によるインポートエラーを回避するためです。

横道に逸れてしまいましたが、先ほどの DDL を実行してテーブルを作成します。

クエリヒストリ、レビューのテーブルへデータをロードするコマンドは以下のようになります。
(同時にダイジェストレポートも作成可能です)

Metabase に反映されない場合は、データベース設定画面から Sync database schema now ボタンをクリックして同期してみましょう。

無事、Query HistoryQuery Review が追加されました。

Query History を覗いてみると、ダイジェストレポートで出力されるデータと同一の内容が格納されていることが確認できます。

自動探索機能 (X-rays)

今回使用(pull)した Metabase は v0.43 (Latest) ですが、データの自動探索 (X-rays) という機能が実装されていました。

Metabase Documentation | 14 X Rays

X-rays are a fast and easy way to get automatic insights and explorations of your data.

Welcome 画面のイナズマアイコンの箇所をクリックしてみます。

すると、テーブルに格納されたデータを元に、Metabase が自動でデータ集約して作成されたグラフが纏まったページに遷移しました。

タイムスタンプフィールドに焦点を当てた X-rays はこちらのように作成されました。
まさに今回求めていたスロークエリの時系列発生状況をサマライズしてくれています。(日毎、曜日毎など)


BI ツールが未経験だったり、どのようにデータを可視化すればわからないといった不安があるユーザも、まずはこの機能を使って触り始めるには良いのではと思いました。

おわりに

後半はほとんど Metabase の紹介になってしまいましたが、pt-query-digestdocker が使用できる環境があれば、手軽にスロークエリの可視化が行えます。

また、もし SHOW GLOBAL STATUS の定期的なデータもあるようでしたら、併せて Metabase でデータ可視化することで、スロークエリとの相関関係を調査したり、といった活用方法も考えられます。
(既に MySQL の監視を行っている場合は冗長かもしれませんが)

データの分析方法はユーザ次第ですが、スロークエリチューニング活動における精査がより効率的に行え、さらに新しい洞察が得られるかもしれません。

興味がありましたらぜひ一度お試しください。

Return Top