PostgreSQLには多数の構成オプションが付属していますが、これらのオプションの一部のデフォルト設定を変更すると、PostgreSQLサーバーの可観測性が大幅に向上します。これらのオプションは、これらの問題を理解して解決するために不可欠な情報を提供できるため、本番環境で問題が発生する前に設定および構成することをお勧めします。
PostgreSQLサーバーの内部動作に関するメトリックと情報を公開する設定と拡張機能の詳細については、以下をお読みください。
log_line_prefix 構成オプションは、PostgreSQLが各ログ行の先頭に書き込む内容を決定します。デフォルトは、使用している特定のLinuxディストリビューションまたはマネージドソリューションによって異なりますが、多くの場合、不正なクライアントの追跡に非常に役立ついくつかの項目が含まれていません。このlog_line_prefixをお試しください :
log_line_prefix = '%m [%p] %a %u %d %h '
タイムスタンプ(%m )が含まれます )、バックエンドプロセスのPID(%p )、アプリケーション名(%a )クライアントの、クライアントが接続しているユーザー名(%u )、クライアントが接続しているデータベース(%d )および接続元のホスト名またはIP(%h )。これにより、次のようなログラインが作成されます。
2021-01-30 05:06:03.675 UTC [73] psql postgres bench 172.17.0.1 ERROR: relation "pgbench_akkounts" does not exist at character 15
2021-01-30 05:06:03.675 UTC [73] psql postgres bench 172.17.0.1 STATEMENT: select * from pgbench_akkounts;
これはデフォルトよりもはるかに便利です。クライアントが172.17.0.1から接続していることがわかります ユーザーとしてpostgres データベースベンチへ 、およびアプリケーションは psql 。これだけを表示するデフォルトオプションよりも明らかに改善されています:
2021-01-30 05:13:22.630 UTC [63] ERROR: relation "pgbench_akkounts" does not exist at character 15
2021-01-30 05:13:22.630 UTC [63] STATEMENT: select * from pgbench_akkounts;
PostgreSQLは、実行に設定された時間以上かかるクエリをログに記録するように構成できます。これらは同じログファイルに入ります。 MySQLのような個別の低速クエリログファイルはありません。
実行に1秒以上かかるステートメントをログに記録するには、 log_min_duration_statementを使用します。 このようなオプション:
log_min_duration_statement = 1s
log_min_duration_statement すべてのステートメント(たとえば、 REINDEX TABLE のような長時間実行されるadminステートメントを含む)を考慮します )であり、クエリではありません( SELECT )。このオプションによって生成されるログエントリは次のとおりです。
2021-01-30 08:42:57.473 UTC [62] psql postgres postgres 172.17.0.1 LOG: duration: 1016.283 ms statement: select pg_sleep(1);
2021-01-30 08:52:00.541 UTC [62] psql postgres postgres 172.17.0.1 LOG: duration: 1118.277 ms statement: select pg_sleep(1.1);
これにより、同様のステートメントのログが多すぎる場合は、次を使用して、Postgresにその一部のみをログに記録するように指示できます。
log_min_duration_statement = -1
log_min_duration_sample = 1s
log_statement_sample_rate = 0.25
これにより、ロギングの対象となるステートメント(実行に1秒以上かかったステートメント)の25%のみがログに記録されます。ログ出力は以前と同じです。ログに記録されなかった適格なステートメントの数を知る方法はありません。
すべてのステートメントを、それらの実行にかかった時間とともにログに記録するには、 log_statementを使用します。 代わりにオプション:
log_statement = mod
log_duration = on
「mod」オプションは、PostgresにDDLとデータ変更ステートメントをログに記録するように指示します。これにより、次のようなログが作成されます:
2021-01-30 08:35:08.985 UTC [64] pgbench postgres bench 172.17.0.1 LOG: statement: insert into pgbench_tellers(tid,bid,tbalance) values (10,1,0)
2021-01-30 08:35:08.985 UTC [64] pgbench postgres bench 172.17.0.1 LOG: duration: 0.241 ms
そうではないことに注意してください この方法で有効にされたステートメントログのサンプルを作成することができます。すべてのステートメントがログに記録され、大量のログエントリが作成されます。
クエリは、ロックを取得するのに時間がかかりすぎる可能性があります。通常、待機時間の上限は、オプション lock_timeoutを使用して設定されます。 、通常はクライアント側で。クエリがロックを取得するのをこれだけ長く待機している場合、Postgresはこのクエリの実行をキャンセルしてエラーをログに記録します:
2021-01-30 09:35:52.415 UTC [67] psql postgres testdb 172.17.0.1 ERROR: canceling statement due to lock timeout
2021-01-30 09:35:52.415 UTC [67] psql postgres testdb 172.17.0.1 STATEMENT: cluster t;
たとえば、ロックタイムアウトを1分に設定したいが、ロックを30秒以上待機するクエリをログに記録するとします。これは、次を使用して行うことができます:
log_lock_waits = on
deadlock_timeout = 30s
これにより、次のようなログが作成されます:
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 LOG: process 70 still waiting for ShareLock on transaction 493 after 30009.004 ms
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 DETAIL: Process holding the lock: 68. Wait queue: 70.
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 CONTEXT: while locking tuple (0,3) in relation "t"
2021-01-30 09:49:22.331 UTC [70] psql postgres testdb 172.17.0.1 STATEMENT: select * from t for update;
deadlock_timeoutの使用 タイプミスではありません。これは、ロック待機ログメカニズムが使用する値です。理想的には、 log_min_duration_lock_waitのようなものがあったはずです。 、しかし残念ながら、そうではありません。
実際のデッドロックの場合、Postgresは deadlock_timeoutの後にデッドロックされたトランザクションを中止します 期間、および問題のあるステートメントをログに記録します。明示的な構成は必要ありません。
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 LOG: process 68 detected deadlock while waiting for ShareLock on transaction 496 after 30007.633 ms
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 DETAIL: Process holding the lock: 70. Wait queue: .
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 CONTEXT: while locking tuple (0,3) in relation "t"
2021-01-30 09:55:37.724 UTC [68] psql postgres testdb 172.17.0.1 STATEMENT: select * from t where a=4 for update;
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 ERROR: deadlock detected
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 DETAIL: Process 68 waits for ShareLock on transaction 496; blocked by process 70.
Process 70 waits for ShareLock on transaction 495; blocked by process 68.
Process 68: select * from t where a=4 for update;
Process 70: select * from t where a=0 for update;
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 HINT: See server log for query details.
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 CONTEXT: while locking tuple (0,3) in relation "t"
2021-01-30 09:55:37.725 UTC [68] psql postgres testdb 172.17.0.1 STATEMENT: select * from t where a=4 for update;
自動バキュームプロセスは、Postgresがテーブル内のデータがバキュームを保証して分析するのに十分に変更されたと判断したときに開始されます。このプロセスを監視するには、自動真空実行のログを有効にします。
log_autovacuum_min_duration = 250ms
1つのテーブルに過度の変更を加えたために発生したエントリの例を次に示します。
2021-01-30 10:23:33.201 UTC [63] LOG: automatic vacuum of table "postgres.public.t": index scans: 0
pages: 0 removed, 95 remain, 0 skipped due to pins, 0 skipped frozen
tuples: 8991 removed, 10000 remain, 0 are dead but not yet removable, oldest xmin: 492
buffer usage: 215 hits, 4 misses, 4 dirtied
avg read rate: 1.885 MB/s, avg write rate: 1.885 MB/s
system usage: CPU: user: 0.01 s, system: 0.00 s, elapsed: 0.01 s
WAL usage: 244 records, 1 full page images, 67984 bytes
2021-01-30 10:23:33.222 UTC [63] LOG: automatic analyze of table "postgres.public.t" system usage: CPU: user: 0.01 s, system: 0.00 s, elapsed: 0.01 s
自動バキュームは通常、バキューム後に分析をトリガーし、これもログに記録されることに注意してください。
これらのログは、自動真空パラメータを調整する最善の方法を理解するのに役立ち、自動真空が思ったほど効果的でないかどうか、いつ効果がないかを調査するのに役立ちます。
チェックポインティングは、WALログに記録された変更をテーブルをバックアップする実際のファイルにプッシュするプロセスです。理想的には、チェックポイントはCPUとディスクを集中的に使用するプロセスであるため、定期的であまり頻繁ではない間隔で発生する必要があります。さまざまな理由から、チェックポイントも次のスケジュールされた時間より前に発生するように強制され、その結果、クエリのパフォーマンスが低下します。
チェックポイントの頻度と効率を監視するには、チェックポイントのログ記録を有効にします。
log_checkpoints = on
これにより、チェックポイントが発生するたびに以下をログに記録するようにPostgreSQLに指示します。
2021-01-30 10:05:57.085 UTC [56] LOG: checkpoint starting: immediate force wait
2021-01-30 10:05:57.159 UTC [56] LOG: checkpoint complete: wrote 0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.000 s, sync=0.000 s, total=0.074 s; sync files=0, longest=0.000 s, average=0.000 s; distance=0 kB, estimate=0 kB
最初の行には、バックエンドがチェックポインターに渡したフラグが含まれています。チェックポイントに保留中の変更がなかったにもかかわらず、「力」がチェックポイントを引き起こしたことがわかります。 「即時」が指定されていない場合、チェックポインターは checkpoint_completion_targetまでチェックポイントを設定します。 。
問題の診断に役立つ、PostgreSQL構成でオンにできる他の設定がいくつかあります。
- track_io_timing -これをonに設定します 各クエリのディスクI/Oで費やされた時間を確認できます(以下で説明するpg_stat_statements拡張機能と組み合わせて)。これをオンにする際の警告についてのドキュメントを参照してください。ただし、ほとんどすべてのmodernLinuxで安全です。これをオンにしないと、クエリのディスクI/Oコストを確認することはできません。
- track_commit_timestamp -これをonに設定します レプリケーションの遅延やその他のレプリケーション関連の問題のデバッグに役立ちます。
pg_stat_statementsを介した統計のクエリ
拡張機能pg_stat_statements PostgreSQLの展開に不可欠なアクセサリです。実行された各クエリの統計を収集して記録し、「pg_stat_statements」と呼ばれるビューとして表示します。これは拡張機能です。つまり、次のコマンドを使用して、データが必要な各データベースに明示的にインストールする必要があります。
CREATE EXTENSION pg_stat_statements;
拡張子は.soに依存しているため 、 shared_preload_librariesを使用してロードする必要があります :
shared_preload_libraries = 'pg_stat_statements'
残念ながら、これにはPostgreSQLサーバーの再起動が必要です。したがって、ライブに移行する前に必ずこれを行ってください。
以前のバージョンのPostgreSQLからアップグレードした場合は、次を使用してpg_stat_statement拡張機能もアップグレードしてください。
ALTER EXTENSION pg_stat_statements UPDATE;
pg_stat_statements拡張機能は何もログに記録せず、同じ名前のビューを照会することで使用されます。詳細については、公式ドキュメントを参照してください。
auto_explainを介したクエリ実行計画
auto_explain コアPostgreSQLに存在するもう1つの拡張機能です。遅いクエリの実行計画をログに記録できます。 shared_preload_librariesに追加する必要があるだけです。 、および拡張機能としてインストールする必要はありません。また、通常はデフォルト以外の値に設定する必要がある他のオプションもいくつかあります。
shared_preload_libraries = 'pg_stat_statements,auto_explain'
auto_explain.log_min_duration = 1s
auto_explain.log_analyze = on
auto_explain.log_buffers = on
auto_explain.log_triggers = on
auto_explain.log_timing = on
auto_explain.log_verbose = on
auto_explain.log_format = json
上記は、完了するのに1秒以上かかるクエリの実行プランをログに記録します。出力例は次のとおりです。
2021-01-30 11:28:25.977 UTC [64] psql postgres postgres 172.17.0.1 LOG: duration: 1.305 ms plan:
{
"Query Text": "SELECT n.nspname as \"Schema\",\n c.relname as \"Name\",\n CASE c.relkind WHEN 'r' THEN 'table' WHEN 'v' THEN 'view' WHEN 'm' THEN 'materialized view' WHEN 'i' THEN 'index' WHEN 'S' TH
EN 'sequence' WHEN 's' THEN 'special' WHEN 'f' THEN 'foreign table' WHEN 'p' THEN 'table' WHEN 'I' THEN 'index' END as \"Type\",\n pg_catalog.pg_get_userbyid(c.relowner) as \"Owner\"\nFROM pg_catalog.pg_class c
\n LEFT JOIN pg_catalog.pg_namespace n ON n.oid = c.relnamespace\nWHERE c.relkind IN ('r','p','v','m','S','f','')\n AND n.nspname <> 'pg_catalog'\n AND n.nspname <> 'information_schema'\n AND
n.nspname !~ '^pg_toast'\n AND pg_catalog.pg_table_is_visible(c.oid)\nORDER BY 1,2;",
"Plan": {
"Node Type": "Sort",
"Parallel Aware": false,
"Startup Cost": 32.93,
"Total Cost": 33.01,
"Plan Rows": 32,
"Plan Width": 224,
"Actual Startup Time": 1.292,
"Actual Total Time": 1.298,
"Actual Rows": 0,
[... lots of text snipped ...]
auto_explainの詳細については、公式ドキュメントをご覧ください。
拡張機能pg_stat_statements およびauto_explain PostgreSQLがクエリパフォーマンス管理とクエリプラン管理のために持っている唯一の2つの広くサポートされているオプションです。これらの2つの機能を理解し、本番環境での使用を事前に計画することは有益です。
アプリケーション名はクライアント側のパラメータであり、通常、アプリケーションが接続情報に使用するDSNまたはlibpqスタイルの接続文字列で設定できます。 PostgreSQLエコシステムの多くのツールとユーティリティはアプリケーション名を理解しており、これを意味のある値に設定するのに役立ちます。例:
application_name = weekly-revenue-report
これは、PostgreSQLサーバーに接続するクライアントアプリケーションごとに設定されます。