![[初心者向け] PostgreSQL on EC2 でスロークエリログを出してみた](https://devio2024-media.developers.io/image/upload/f_auto,q_auto,w_3840/v1770879158/user-gen-eyecatch/oqsycotdvm9tgrca2lgz.webp)
[初心者向け] PostgreSQL on EC2 でスロークエリログを出してみた
今回は、EC2(AL2023) にインストールした PostgreSQL に対して、スロークエリログを設定してみたいと思います。
ログ出力には pg_stat_statements などを用いた方法もあるかと思いますが、今回は log_min_duration_statement パラメータによるログ記録をやってみます。
なお、EC2 はパブリックサブネットに配置しており、PostgreSQL は下記手順等でインストール済みとします。
今回 PostgreSQL のバージョンは 17 を使います。
[ec2-user@ip-10-0-14-158 ~]$ sudo -u postgres psql
psql (17.7)
Type "help" for help.
postgres=# select * from version();
version
--------------------------------------------------------------------------------------------------------------
PostgreSQL 17.7 on x86_64-amazon-linux-gnu, compiled by gcc (GCC) 11.5.0 20240719 (Red Hat 11.5.0-5), 64-bit
(1 row)
やってみた
EC2 にアクセスし、PostgreSQL サーバーが起動できているか確認。Active: active (running) なので OK。起動していない場合は sudo systemctl start postgresql を実行してください。
# PostgreSQL サーバーが起動しているか確認
$ sudo systemctl status postgresql
● postgresql.service - PostgreSQL database server
...
Active: active (running) since Thu 2026-02-12 04:22:42 UTC; 2h 43min ago
...
log_min_duration_statement とログの出力場所
スロークエリログは、log_min_duration_statement パラメータで制御できます。
デフォルトは -1(無効)で、値を 0 以上に設定した場合は、その時間以上のクエリを記録する動きになります。
例えば 2000[ms] を指定すると、実行に 2 秒以上かかったクエリがログに記録されます。
log_min_duration_statement (integer)
文の実行に少なくとも指定した時間かかった場合、それぞれの文の実行に要した時間をログに記録します。 例えば、250msと設定した場合、250msもしくはそれ以上長くかかった全てのSQL文がログとして残ります。 ... この値が単位なしで指定された場合は、ミリ秒単位であるとみなします。 0に設定すれば、すべての文の実行時間が出力されます。 -1（デフォルト）は、文実行時間の記録を無効にします。https://www.postgresql.jp/document/17/html/runtime-config-logging.html
現在の log_min_duration_statement の値を確認。-1 なので無効になっています。
# PostgreSQL サーバーに接続
$ sudo -u postgres psql
psql (17.7)
Type "help" for help.
-- スロークエリログの設定値を確認。-> -1 なので、設定されていない。
postgres=# SHOW log_min_duration_statement;
log_min_duration_statement
----------------------------
-1
(1 row)
設定変更前の before の動きを見るために、今現在のスロークエリログ無効の状態で、処理時間が 2 秒以上かかる遅いクエリ（pg_sleep 関数）を実行してみます。
-- クエリの実行時間を表示するため、メタコマンド \timing を実行
postgres=# \timing
Timing is on.
-- 2秒待つクエリを実行
postgres=# SELECT pg_sleep(2);
pg_sleep
----------
(1 row)
Time: 2002.307 ms (00:02.002)
上記で実行している \timing と pg_sleep については以下ドキュメントを参照。
\timing を実行することで、Time: 2002.307 ms (00:02.002) のようにクエリの実行時間を表示してくれます。
\timing [ on | off ]
パラメータがある場合、各SQL文にかかる時間の表示の有無をonまたはoffに設定します。 ... 表示はミリセカンド単位です。
以下の関数は、サーバプロセスの実行を遅延させるために使用可能です。
pg_sleep ( double precision )
前述の通り、今はスロークエリログが無効なので、ログには何も記録されないはずです。確認してみましょう。
の前に、ログがどこに出力されているのかがわからないので、そこから確認していきます。
まず、PostgreSQL ログに関連する各種パラメータの値を表示します。
postgres=# SELECT name, setting, short_desc
FROM pg_settings
WHERE name IN (
'logging_collector',
'log_destination',
'data_directory',
'log_directory',
'log_filename'
)
ORDER BY name;
name | setting | short_desc
-------------------+---------------------+-----------------------------------------------------------------------------
data_directory | /var/lib/pgsql/data | Sets the server's data directory.
log_destination | stderr | Sets the destination for server log output.
log_directory | log | Sets the destination directory for log files.
log_filename | postgresql-%a.log | Sets the file name pattern for log files.
logging_collector | on | Start a subprocess to capture stderr, csvlog and/or jsonlog into log files.
(5 rows)
(日本語訳ver)
data_directory | /var/lib/pgsql/data | サーバーのデータディレクトリを設定します。
log_destination | stderr | サーバーログ出力の出力先を設定します。
log_directory | log | ログファイルの出力先ディレクトリを設定します。
log_filename | postgresql-%a.log | ログファイルのファイル名パターンを設定します。
logging_collector | on | stderr、csvlog、および/またはjsonlogをログファイルにキャプチャするサブプロセスを開始します。
(5行)
上記より、logging_collector が on なので、log_destination（stderr） に出力されたログが log_filename（postgresql-%a.log）の形式で保存されることがわかりました。
logging_collector (boolean)
このパラメータはログ収集機構を有効にします。 それはstderrに送られたログメッセージを捕捉し、ログファイルにリダイレクトするバックグラウンドプロセスです。
...
log_filename (string)
logging_collectorが有効な場合、このパラメータは作成されたログファイルのファイル名を設定します。
...
log_destination (string)
このパラメータを設定するには、コンマ区切りでお好みのログ出力先を記載します。 デフォルトでは、ログはstderrのみに出力されます。https://www.postgresql.jp/document/17/html/runtime-config-logging.html
また、その出力されたファイルの場所は、以下ドキュメントより、data_directory + log_directory、上記のパラメータからその場所を示すと、/var/lib/pgsql/data/log の位置にあることがわかります。
log_directory (string)
When logging_collector is enabled, this parameter determines the directory in which log files will be created. It can be specified as an absolute path, or relative to the cluster data directory. This parameter can only be set in the postgresql.conf file or on the server command line. The default is log.(日本語訳)
logging_collector が有効な場合、このパラメータはログファイルが作成されるディレクトリを決定します。絶対パスとして指定することも、クラスタの data directory からの相対パスとして指定することもできます。このパラメータはpostgresql.confファイル内またはサーバーコマンドラインでのみ設定できます。デフォルトはlogです。https://www.postgresql.org/docs/17/runtime-config-logging.html
/var/lib/pgsql/data/log にログファイルがあるか確認します。postgresql-%a.log 形式のファイルがありますね。
-- PostgreSQL サーバーから抜ける
postgres=# exit
# ログファイルが存在するか確認
[ec2-user@ip-10-0-14-158 ~]$ sudo ls /var/lib/pgsql/data/log/
postgresql-Thu.log postgresql-Tue.log postgresql-Wed.log
ログの中身を確認します。
# 最新のログの末尾 5 行を表示
[ec2-user@ip-10-0-14-158 ~]$ sudo tail -5 /var/lib/pgsql/data/log/postgresql-Thu.log
2026-02-12 04:22:42.495 UTC [1771] LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2026-02-12 04:22:42.504 UTC [1775] LOG: database system was shut down at 2026-02-12 01:45:12 UTC
2026-02-12 04:22:42.516 UTC [1771] LOG: database system is ready to accept connections
2026-02-12 04:27:42.603 UTC [1773] LOG: checkpoint starting: time
2026-02-12 04:27:42.614 UTC [1773] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; ...
PostgreSQL サーバーが起動した際に出力される「database system is ready to accept connections」などはありますが、スロークエリログは記録されていません。(後述の結果と比べるとよくわかります。)
スロークエリログの設定を行う
スロークエリログを記録するために log_min_duration_statement パラメータの値を変更します。
同パラメータは、postgresql.conf にて設定変更できます。
# postgresql.conf にて log_min_duration_statement の設定値を変更する
[ec2-user@ip-10-0-14-158 ~]$ sudo vi /var/lib/pgsql/data/postgresql.conf
<以下は vim の使い方>
/log_min_duration ← 検索（/ + 文字列 + Enter）
i ← 編集モード開始
（編集する）
Esc ← 編集モード終了
:wq ← 保存して終了
:q! ← （保存したくない場合は、）保存せず終了
# 変更できたか確認 -> 2000[ms] になっている。OK。
[ec2-user@ip-10-0-14-158 ~]$ sudo cat /var/lib/pgsql/data/postgresql.conf
...
log_min_duration_statement = 2000 # -1 is disabled, 0 logs all statements
# and their durations, > 0 logs only
# statements running at least this number
# of milliseconds
...
# PostgreSQL サーバーに設定変更を反映させるためにリロード
[ec2-user@ip-10-0-14-158 ~]$ sudo systemctl reload postgresql
# 実際に PostgreSQL サーバーに反映されているか確認 -> 値が 2s になっているので OK
[ec2-user@ip-10-0-14-158 ~]$ sudo -u postgres psql
psql (17.7)
Type "help" for help.
postgres=# show log_min_duration_statement;
log_min_duration_statement
----------------------------
2s
(1 row)
スロークエリログが記録されるか確認
設定変更できたので、実際に遅いクエリ（今回は 2 秒以上）がログに記録されるか確認します。
まず before として現在のログを見ます。
最新のログが parameter "log_min_duration_statement" changed to "2000" となっていて、パラメータ変更時のログになっています。
# before ログ
[ec2-user@ip-10-0-14-158 ~]$ sudo tail -5 /var/lib/pgsql/data/log/postgresql-Thu.log
2026-02-12 04:22:42.516 UTC [1771] LOG: database system is ready to accept connections
2026-02-12 04:27:42.603 UTC [1773] LOG: checkpoint starting: time
2026-02-12 04:27:42.614 UTC [1773] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, ...
2026-02-12 05:28:09.986 UTC [1771] LOG: received SIGHUP, reloading configuration files
2026-02-12 05:28:09.986 UTC [1771] LOG: parameter "log_min_duration_statement" changed to "2000"
2秒以上かかる処理時間の長いクエリを実行します。また対照群として、処理時間が 1 秒のクエリも実行します。
# PostgreSQL サーバーへアクセス
[ec2-user@ip-10-0-14-158 ~]$ sudo -u postgres psql
psql (17.7)
Type "help" for help.
-- 処理時間表示されるように有効化
postgres=# \timing
Timing is on.
-- 2秒以上かかる処理を実行
postgres=# SELECT pg_sleep(2);
pg_sleep
----------
(1 row)
Time: 2002.636 ms (00:02.003)
-- 対照群として 2 秒未満の処理も実行しておく
postgres=# SELECT pg_sleep(1);
pg_sleep
----------
(1 row)
Time: 1001.313 ms (00:01.001)
-- PostgreSQL サーバーから抜ける
postgres=# exit;
上記実行したクエリのログが確認されているか見てみましょう。
以下より、LOG: duration: 2002.437 ms statement: SELECT pg_sleep(2);の形で実行時間とその時のクエリが記録されていますね。うまくスロークエリログを記録できました。
# after ログ
[ec2-user@ip-10-0-14-158 ~]$ sudo tail -5 /var/lib/pgsql/data/log/postgresql-Thu.log
2026-02-12 04:27:42.603 UTC [1773] LOG: checkpoint starting: time
2026-02-12 04:27:42.614 UTC [1773] LOG: checkpoint complete: wrote 3 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 ...
2026-02-12 05:28:09.986 UTC [1771] LOG: received SIGHUP, reloading configuration files
2026-02-12 05:28:09.986 UTC [1771] LOG: parameter "log_min_duration_statement" changed to "2000"
2026-02-12 05:33:15.320 UTC [4221] LOG: duration: 2002.437 ms statement: SELECT pg_sleep(2);
また上記を見ると、対照群として実施した pg_sleep(1); のクエリに関しては、2秒以上のクエリではないのでそちらは記録されてないですね。こちらも想定通りの動きとなりました。
ちなみに複数回、スロークエリとなるステートメントを実行すると、以下のように複数のログがどんどん増えていく挙動になります。
[ec2-user@ip-10-0-14-158 ~]$ sudo tail -5 /var/lib/pgsql/data/log/postgresql-Thu.log
2026-02-12 05:28:09.986 UTC [1771] LOG: received SIGHUP, reloading configuration files
2026-02-12 05:28:09.986 UTC [1771] LOG: parameter "log_min_duration_statement" changed to "2000"
2026-02-12 05:33:15.320 UTC [4221] LOG: duration: 2002.437 ms statement: SELECT pg_sleep(2);
2026-02-12 05:36:10.440 UTC [4333] LOG: duration: 2002.170 ms statement: SELECT pg_sleep(2);
2026-02-12 05:36:33.520 UTC [4333] LOG: duration: 2002.168 ms statement: SELECT pg_sleep(2);
検証は以上です。
終わりに
今回は、EC2(AL2023)にインストールした PostgreSQL にスロークエリログ記録ができるように設定変更してみました。log_min_duration_statementパラメータの変更のみで記録ができるのでとても簡易的で便利だなと感じました。
また、今回のように実際に設定変更してみることで、PostgreSQL ログの場所など基本的なことも理解することができたので有意義な検証でした。
本ブログが自分と同じく PostgreSQL 初学者の方の参考になれば幸いです。
参考情報
