負荷試験や本番稼働中のデータベースサーバでは、通常さまざまな種類のSQLが実行されています。
昨日紹介したpg_stat_statmentsシステムビューは、PostgreSQLの内部でSQLの実行状況を積算することのできるモジュールでしたが、「pg_stat_statementsを使うには制約が・・・」というケースもあるでしょう。
PostgreSQLには実行しているSQL文をサーバログに出力する機能があります。SQL文だけでなく実行時間なども出力することができるため、このサーバログを集計することによって、どのようなSQLがどれくらい実行されていて、どのSQLにパフォーマンス上の問題がありそうなのか、といったことを絞り込んでいくことができます。
■SQLログ解析ツール「pgBadger」
サーバログを集計するツールとしてはいくつかあるのですが、今日は「pgBadger」というツールを紹介します。
pgBadger
http://dalibo.github.com/pgbadger/
pgBadgerはPerlで作成されたスクリプトで、一昔前にPHPスクリプトで開発されていたpgFouineというプログラムと同様の機能を持っています。コマンドラインでサーバログを指定して実行すると、サーバログを分析したレポートをHTMLファイルで作成してくれます。
また、SQLだけではなく、サーバログに出ているエラーログなども集計してくれます。
■pgBadgerのインストール
それでは、pgBadgerをインストールしてみます。
「インストール」とは言うものの、単一のPerlスクリプトですので、ソースコードのtar.gzアーカイブを取得して展開するだけです。
[snaga@devsv02 pgsql]$ tar zxf pgbadger-2.2-1.tar.gz [snaga@devsv02 pgsql]$ cd pgbadger-2.2 [snaga@devsv02 pgbadger-2.2]$ ls ChangeLog doc/ LICENSE Makefile.PL MANIFEST META.yml pgbadger* README [snaga@devsv02 pgbadger-2.2]$
■サーバログの設定
PostgreSQLはサーバログの設定によって出力される内容や形式が変わってきます。pgBadgerを使うためには、分析に必要な内容がサーバログに出力されている必要がありますので、まずはサーバログの設定を確認します。
pgBadgerでは以下の設定を推奨しています。（出力先にstderrを使う場合）
log_line_prefix = '%t [%p]: [%l-1] ' log_line_prefix = '%t [%p]: [%l-1] db=%d,user=%u 'また、サーバログの出力にsyslogを使う場合には、以下のいずれかの設定が推奨されています。
log_line_prefix = 'user=%u,db=%d ' log_line_prefix = 'db=%d,user=%u 'この辺りの詳細についてはpgBadgerのマニュアルを参照してください。
今回のログ関連の設定は以下の通りです。
testdb1=# SELECT name,setting FROM pg_settings WHERE name LIKE 'log%';
name | setting
-----------------------------+----------------------
log_autovacuum_min_duration | -1
log_checkpoints | off
log_connections | on
log_destination | stderr
log_directory | pg_log
log_disconnections | on
log_duration | off
log_error_verbosity | default
log_executor_stats | off
log_file_mode | 0600
log_filename | postgresql-%Y-%m.log
log_hostname | off
log_line_prefix | %t [%p]: [%l-1] db=%d,user=%u
log_lock_waits | off
log_min_duration_statement | 0
log_min_error_statement | error
log_min_messages | warning
log_parser_stats | off
log_planner_stats | off
log_rotation_age | 1440
log_rotation_size | 0
log_statement | none
log_statement_stats | off
log_temp_files | 0
log_timezone | Japan
log_truncate_on_rotation | on
logging_collector | on
(27 rows)
testdb1=#
■サーバログ解析の実施
それでは、実際にSQLログの解析をしてみます。
pgbadgerコマンドを実行する際、log_line_prefixの値を--prefixオプションで指定し、サーバログのファイル（ここでは/tmp/postgresql-2012-11.log）を引数として与えます。
[snaga@devsv02 pgbadger-2.2]$ ./pgbadger --prefix '%t [%p]: [%l-1] db=%d,user=%u ' /tmp/postgresql-2012-11.log [========================>] Parsed 100810441 bytes of 100810441 (100.00%), queries: 486277, events: 1 [snaga@devsv02 pgbadger-2.2]$ ls ChangeLog LICENSE MANIFEST out.html postgresql-2012-11.log doc/ Makefile.PL META.yml pgbadger* README [snaga@devsv02 pgbadger-2.2]$ログの集計が完了すると、上記のように out.html というレポートファイルが作成されます。 今回のレポートのサンプルは以下の通りです。
pgBadgerサンプルレポート
■レポートの読み方
レポートには、以下のセクションがあります。
- Overall statistics （概要）
- Hourly statistics （日付/時間帯別統計）
- Queries by type （クエリ種別統計）
- Sessions per database （データベース別セッション統計）
- Sessions per user （ユーザ別セッション統計）
- Sessions per host （接続元ホスト別セッション統計）
- Connections per database （データベース別接続統計）
- Connections per user （ユーザ別接続統計）
- Connections per host （接続元ホスト別接続統計）
- Slowest queries （遅いクエリランキング）
- Queries that took up the most time (N) （総実行時間が長いクエリランキング）
- Most frequent queries (N) （実行回数の多いクエリランキング）
- Slowest queries (N) （平均実行時間が長いクエリランキング）
- Most frequent events (N) （もっともよく発生したエラーランキング）
- Logs per type （サーバログ種別統計）
・突出して遅いクエリを探す場合
Slowest queries を確認しましょう。実行時間が特に遅かったクエリを表示してくれます。
Slowest queriesには(N)が付いている統計と付いていない統計がありますが、ここで見るのは(N)が付いていない統計です。
・全体的に実行時間の遅いクエリを探す場合
Slowest queries(N) を見ましょう。こちらは(N)の付いている統計です。
(N)というのは、Day3のpg_stat_statementsシステムビューの時にも出てきたように、クエリのパラメータの値を「?」で置き換えた "normalize" した集計、という意味です。（"normanlize" の詳細ついては、Day3のエントリを参照ください。）
・実行回数の多いクエリを探す場合
Most frequent queries(N) を見ましょう。似たようなクエリが何回実行されているか、多い順にランキングされます。
■まとめ
今日は、PostgreSQLのサーバログを集計してパフォーマンス分析をするツール「pgBadger」の使い方を紹介しました。
pgBadgerのようなツールは、あくまでもパフォーマンス分析を支援してくれる、楽にしてくれるツールです。作成されたレポートをどのように読むか、どのように解釈して改善につなげるかがDBAの腕の見せ所になります。
こういったツールを使って手間を省きつつ、ピンポイントで素早くパフォーマンスのボトルネックを特定して改善できるように、日頃から腕を磨いておきましょう。
ではまた。
0 件のコメント:
コメントを投稿