PostgreSQL hadir dengan banyak opsi konfigurasi, tetapi mengubah pengaturan default dari beberapa opsi ini secara drastis meningkatkan kemampuan pengamatan server PostgreSQL Anda. Anda sebaiknya menyetel dan mengonfigurasi opsi ini sebelum masalah muncul dalam produksi, karena opsi tersebut dapat memberikan informasi penting untuk memahami dan menyelesaikan masalah tersebut.
Baca terus untuk mempelajari lebih lanjut tentang setelan dan ekstensi yang memaparkan metrik dan informasi tentang cara kerja dalam server PostgreSQL Anda.
Awalan Baris Log
log_line_prefix opsi konfigurasi menentukan apa yang ditulis PostgreSQL di awal setiap baris log. Defaultnya tergantung pada distribusi Linux tertentu atau solusi terkelola yang Anda gunakan, tetapi lebih sering daripada tidak, itu tidak menyertakan beberapa item yang terbukti sangat berguna dalam melacak klien yang berperilaku buruk. Coba log_line_prefix ini :
log_line_prefix = '%m [%p] %a %u %d %h '
Ini termasuk stempel waktu (%m ), PID proses backend (%p ), nama aplikasi (%a ) klien, nama pengguna yang terhubung dengan klien (%u ), database tempat klien telah terhubung (%d ) dan nama host atau IP asal koneksi (%h ). Ini menghasilkan logline seperti ini:
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;
yang jauh lebih berguna daripada default. Anda dapat melihat bahwa klien terhubung dari 172.17.0.1 sebagai pengguna postgres ke database bangku , dan aplikasinya adalah psql . Jelas merupakan peningkatan dari opsi default, yang hanya menunjukkan ini:
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;
Mencatat Kueri Lambat
PostgreSQL dapat dikonfigurasi untuk mencatat kueri yang membutuhkan lebih dari jumlah waktu yang ditentukan untuk dieksekusi. Ini masuk ke file log yang sama; tidak ada file log kueri lambat yang terpisah seperti di MySQL.
Untuk mencatat pernyataan yang membutuhkan waktu lebih dari 1 detik untuk dieksekusi, gunakanlog_min_duration_statement pilihan seperti ini:
log_min_duration_statement = 1s
Perhatikan bahwa log_min_duration_statement akan mempertimbangkan semua pernyataan (termasuk, misalnya, pernyataan admin yang sudah berjalan lama seperti REINDEX TABLE ) dan bukan hanya pertanyaan (PILIH ). Berikut adalah beberapa entri log yang dihasilkan oleh opsi ini:
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);
Jika ini menghasilkan terlalu banyak log dari pernyataan serupa, Anda dapat memberi tahu Postgres tolog hanya sebagian saja, menggunakan:
log_min_duration_statement = -1
log_min_duration_sample = 1s
log_statement_sample_rate = 0.25
Ini mencatat hanya 25% dari pernyataan yang memenuhi syarat untuk dicatat (yang membutuhkan waktu lebih dari 1 detik untuk dieksekusi). Keluaran log sama seperti sebelumnya. Tidak ada cara untuk mengetahui berapa banyak pernyataan yang memenuhi syarat yang tidak dicatat.
Untuk mencatat semua pernyataan, bersama dengan waktu yang dibutuhkan untuk mengeksekusinya, gunakanlog_statement sebagai gantinya:
log_statement = mod
log_duration = on
Opsi 'mod' memberi tahu Postgres untuk mencatat DDL dan pernyataan modifikasi data. Ini menghasilkan log seperti ini:
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
Berhati-hatilah karena tidak memungkinkan pengambilan sampel pernyataan log diaktifkan dengan cara ini, semua pernyataan akan dicatat, dan Anda akan mendapatkan banyak entri log.
Mencatat Kunci dan Kebuntuan
Kueri bisa menunggu terlalu lama untuk mendapatkan kunci. Biasanya, batas atas berapa lama menunggu diatur menggunakan opsi lock_timeout , biasanya di sisi klien. Jika kueri telah menunggu selama ini untuk mendapatkan kunci, Postgres akan membatalkan eksekusi kueri ini dan mencatat kesalahan:
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;
Katakanlah Anda ingin menyetel batas waktu penguncian 1 menit, tetapi log kueri yang menunggu penguncian lebih dari, katakanlah 30 detik. Anda dapat melakukannya menggunakan:
log_lock_waits = on
deadlock_timeout = 30s
Ini akan membuat log seperti ini:
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;
Penggunaan deadlock_timeout bukan salah ketik:ini adalah nilai yang digunakan oleh mekanisme lock waitlogging. Idealnya, seharusnya ada sesuatu seperti log_min_duration_lock_wait ,tapi sayangnya, tidak demikian.
Dalam kasus kebuntuan yang sebenarnya, Postgres akan membatalkan transaksi yang menemui jalan buntu setelah deadlock_timeout durasi, dan akan mencatat pernyataan yang menyinggung. Tidak diperlukan konfigurasi eksplisit.
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;
Mencatat Autovacuums
Proses autovacuum dimulai ketika Postgres menentukan bahwa data dalam tabel telah cukup berubah untuk menjamin kekosongan dan analisis. Untuk mengawasi proses ini, aktifkan logging dari autovacuum run:
log_autovacuum_min_duration = 250ms
Berikut adalah contoh entri yang disebabkan oleh perubahan berlebihan pada satu tabel:
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
Perhatikan bahwa autovacuum biasanya akan memicu analisis setelah vakum, dan ini juga akan dicatat.
Log ini akan membantu Anda mengetahui cara terbaik untuk menyetel parameter autovacuum, dan akan membantu dalam menyelidiki apakah dan kapan autovacuum tidak seefektif yang Anda kira.
Logging Checkpoints
Checkpointing adalah proses mendorong perubahan yang dicatat WAL ke dalam file aktual yang kembali ke tabel. Idealnya pos pemeriksaan harus terjadi pada interval reguler dan tidak terlalu sering, karena ini adalah proses intensif CPU dan disk. Karena berbagai alasan, pos pemeriksaan juga terpaksa dilakukan sebelum waktu yang dijadwalkan berikutnya, dan ini mengakibatkan penurunan kinerja kueri.
Untuk mengawasi frekuensi dan efisiensi pos pemeriksaan, aktifkan pencatatan pos pemeriksaan:
log_checkpoints = on
Ini memberitahu PostgreSQL untuk mencatat hal berikut setiap kali pos pemeriksaan terjadi:
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
Baris pertama berisi flag yang backend diteruskan ke checkpointer. Anda dapat melihat bahwa "kekuatan" menyebabkan pos pemeriksaan meskipun tidak ada perubahan yang tertunda pada pos pemeriksaan. Jika "segera" tidak ditentukan, pos pemeriksaan akan memiliki pos pemeriksaan hingga checkpoint_completion_target .
Pengaturan Sisi Server Lainnya
Ada beberapa setelan lain yang dapat Anda aktifkan di konfigurasi PostgreSQL yang akan membantu mendiagnosis masalah:
- track_io_timing - menyetel ini ke aktif memungkinkan Anda melihat waktu yang dihabiskan I/O indisk untuk setiap kueri (dikombinasikan dengan ekstensi pg_stat_statements yang dijelaskan di bawah). Lihat dokumen tentang peringatan untuk mengaktifkan ini, tetapi harus aman di hampir semua Linux modern. Tidak mungkin melihat biaya I/O disk kueri tanpa mengaktifkannya.
- track_commit_timestamp - menyetel ini ke aktif dapat berguna dalam men-debug kelambatan replikasi dan masalah terkait replikasi lainnya.
Statistik Kueri melalui pg_stat_statements
Ekstensi pg_stat_statements adalah aksesori penting untuk penerapan PostgreSQL apa pun. Ini mengumpulkan dan mencatat statistik untuk setiap kueri yang dieksekusi, dan menampilkannya sebagai tampilan yang disebut "pg_stat_statements". Ini adalah ekstensi, yang berarti Anda harus menginstalnya secara eksplisit di setiap database yang Anda inginkan datanya, dengan menggunakan perintah:
CREATE EXTENSION pg_stat_statements;
Karena ekstensi bergantung pada .so , Anda harus memuatnya menggunakanshared_preload_libraries :
shared_preload_libraries = 'pg_stat_statements'
Sayangnya ini membutuhkan restart server PostgreSQL; jadi pastikan Anda melakukan ini sebelum melakukan siaran langsung.
Jika Anda telah mengupgrade dari PostgreSQL versi sebelumnya, pastikan untuk mengupgrade juga ekstensi pg_stat_statement Anda, menggunakan:
ALTER EXTENSION pg_stat_statements UPDATE;
Ekstensi pg_stat_statements tidak mencatat apa pun, ini digunakan melalui kueri tampilan dengan nama yang sama. Untuk detail lebih lanjut, lihat dokumentasi resmi.
Rencana Eksekusi Kueri melalui auto_explain
penjelasan_otomatis adalah ekstensi lain yang ada di inti PostgreSQL. Itu dapat mencatat rencana eksekusi kueri lambat. Itu hanya perlu ditambahkan keshared_preload_libraries , dan tidak perlu diinstal sebagai ekstensi. Ini juga memiliki beberapa opsi lain yang biasanya perlu disetel ke nilai non-default:
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
Di atas mencatat rencana eksekusi untuk setiap kueri yang membutuhkan waktu lebih dari 1 detik untuk diselesaikan. Berikut adalah contoh keluarannya:
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 ...]
Untuk mempelajari lebih lanjut tentang auto_explain, lihat dokumen resmi.
Ekstensi pg_stat_statements dan jelaskan_otomatis adalah satu-satunya dua opsi yang didukung secara luas yang dimiliki PostgreSQL untuk manajemen kinerja kueri dan manajemen rencana kueri. Membayar untuk mengetahui dua fitur ini, dan merencanakan ke depan untuk menggunakannya dalam produksi.
Nama Aplikasi
Nama aplikasi adalah parameter sisi klien, dan biasanya dapat diatur dalam DSN atau string koneksi bergaya libpq yang digunakan aplikasi Anda untuk informasi koneksi. Banyak alat dan utilitas dalam sistem ekologi PostgreSQL memahami nama aplikasi, dan ini membantu untuk menyetelnya ke nilai yang berarti, misalnya:
application_name = weekly-revenue-report
Ini akan disetel untuk setiap aplikasi klien yang terhubung ke server PostgreSQL Anda.