PostgreSQL kommer med et væld af konfigurationsmuligheder, men ændring af standardindstillingerne for nogle af disse muligheder forbedrer drastisk observerbarheden af din PostgreSQL-server. Du skal indstille og konfigurere disse muligheder, før der dukker problemer op i produktionen, da de kan give oplysninger, der er vigtige for at forstå og løse disse problemer.
Læs videre for at lære mere om de indstillinger og udvidelser, der afslører metrics og information om din PostgreSQL-servers indre funktion.
Loglinjepræfiks
log_line_prefix konfigurationsindstillingen bestemmer, hvad PostgreSQL skriver i begyndelsen af hver loglinje. Standarden afhænger af den specifikke Linuxdistribution eller administrerede løsning, som du bruger, men som oftest inkluderer den ikke nogle få elementer, der kan vise sig at være meget nyttige til at spore klienter, der ikke opfører sig forkert. Prøv dette log_line_prefix :
log_line_prefix = '%m [%p] %a %u %d %h '
Det inkluderer tidsstemplet (%m ), PID for backend-processen (%p ), applikationsnavnet (%a ) af klienten, det brugernavn, som klienten har forbundet med (%u ), den database, som klienten har oprettet forbindelse til (%d ) og værtsnavnet eller IP-adressen, hvor forbindelsen kommer fra (%h ). Dette resulterer i loglines som denne:
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;
som er meget mere nyttige end standarden. Du kan se, at en klient er tilsluttet fra 172.17.0.1 som bruger postgres til database bench , og applikationen var psql . Absolut en forbedring i forhold til standardindstillingen, som kun viser dette:
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;
Logning af langsomme forespørgsler
PostgreSQL kan konfigureres til at logge forespørgsler, der tager mere end en bestemt mængde tid at udføre. Disse går ind i den samme logfil; der er ingen separat langsom forespørgselslogfil som i MySQL.
For at logge udsagn, der tager mere end 1 sekund at udføre, skal du bruge log_min_duration_statement mulighed som denne:
log_min_duration_statement = 1s
Bemærk at log_min_duration_statement vil overveje alle udsagn (inklusive f.eks. langvarige admin-udsagn som REINDEX TABLE ) og ikke bare forespørgsler (SELECT ). Her er nogle logposter, der er produceret af denne mulighed:
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);
Hvis dette resulterer i for mange logfiler med lignende udsagn, kan du kun fortælle Postgres tolog en procentdel af det ved at bruge:
log_min_duration_statement = -1
log_min_duration_sample = 1s
log_statement_sample_rate = 0.25
Dette logger kun 25 % af de udsagn, der bliver kvalificerede til logning (dem, der tog mere end 1 sekund at udføre). Log-outputtet er det samme som før. Der er ingen måde at vide, hvor mange berettigede udsagn der ikke blev logget.
For at logge alle udsagn sammen med den tid, det tager at udføre dem, skal du brugelog_statement mulighed i stedet for:
log_statement = mod
log_duration = on
Muligheden 'mod' fortæller Postgres at logge DDL'er og datamodificerende erklæringer. Dette resulterer i logfiler som disse:
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
Vær advaret om, at det ikke er muligt at prøve erklæringslogning aktiveret på denne måde, vil alle erklæringer blive logget, og du vil ende med tonsvis af logposter.
Logning af låse og blokerede låse
Forespørgsler kan vente for længe med at få en lås. Typisk indstilles en øvre grænse for, hvor længe man skal vente ved at bruge muligheden lock_timeout , normalt på klientsiden. Hvis en forespørgsel har ventet så længe på at få en lås, vil Postgres annullere udførelsen af denne forespørgsel og logge en fejl:
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;
Lad os sige, at du vil indstille en låsetimeout på 1 minut, men logforespørgsler, der venter på låsning i mere end f.eks. 30 sekunder. Du kan gøre dette ved at bruge:
log_lock_waits = on
deadlock_timeout = 30s
Dette vil oprette logfiler som denne:
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;
Brugen af deadlock_timeout er ikke en tastefejl:det er den værdi, som låsens ventelogningsmekanisme bruger. Ideelt set skulle der have været noget som log_min_duration_lock_wait ,men det er desværre ikke tilfældet.
I tilfælde af faktiske deadlocks vil Postgres afbryde den fastlåste transaktion efter deadlock_timeout varighed, og vil logge de stødende udtalelser. Ingen eksplicit konfiguration er nødvendig.
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;
Logning af autostøvsugere
Autovakuumprocessen starter, når Postgres fastslår, at dataene i en tabel er ændret tilstrækkeligt til at berettige et vakuum og analysere. For at holde øje med denne proces skal du aktivere logning af autovakuumkørsler:
log_autovacuum_min_duration = 250ms
Her er et eksempel på indtastning, der blev forårsaget af overdrevne ændringer i én 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
Bemærk, at autovakuum typisk vil udløse en analyse efter vakuumet, og dette vil også blive logget.
Disse logfiler hjælper dig med at finde ud af, hvordan du bedst justerer autovakuumparametrene, og hjælper dig med at undersøge, om og hvornår autovakuum ikke er så effektivt, som du troede det ville være.
Logning af kontrolpunkter
Checkpointing er processen med at skubbe WAL-loggede ændringer ind i de faktiske filer, der bager tabeller. Ideelt set bør kontrolpunkter forekomme med regelmæssige og ikke for hyppige intervaller, da det er en CPU- og diskintensiv proces. Af forskellige årsager er kontrolpunkter også tvunget til at ske inden det næste planlagte tidspunkt, og dette resulterer i reduceret forespørgselsydeevne.
For at holde øje med kontrolpunkters frekvens og effektivitet, aktiver logning af kontrolpunkter:
log_checkpoints = on
Dette fortæller PostgreSQL at logge følgende, når der opstår et kontrolpunkt:
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
Den første linje indeholder de flag, som backend sendte til checkpointeren. Du kan se, at "styrken" forårsagede et kontrolpunkt, selvom der ikke var nogen afventende ændringer til kontrolpunktet. Hvis "umiddelbar" ikke var blevet specificeret, ville checkpointeren have checkpointet op til checkpoint_completion_target .
Andre indstillinger på serversiden
Der er et par andre indstillinger, som du kan aktivere i din PostgreSQL-konfiguration, som vil hjælpe med at diagnosticere problemer:
- track_io_timing - indstille dette til til lader dig se den tid brugt på indisk I/O for hver forespørgsel (kombineret med pg_stat_statements-udvidelsen beskrevet nedenfor). Se dokumentet om en advarsel til at slå dette til, men det burde være sikkert på næsten alle moderne Linux. Det er umuligt at se en forespørgsels disk I/O-omkostninger uden at slå dette til.
- track_commit_timestamp - indstille dette til til kan være nyttig ved fejlfinding af replikeringsforsinkelser og andre replikeringsrelaterede problemer.
Forespørgselsstatistik via pg_stat_statements
Udvidelsen pg_stat_statements er et vigtigt tilbehør til enhver PostgreSQL-implementering. Den indsamler og registrerer statistik for hver forespørgsel, der udføres, og præsenterer dem som en visning kaldet "pg_stat_statements". Dette er en udvidelse, hvilket betyder, at du skal installere den eksplicit i hver database, du vil have data til, ved hjælp af kommandoen:
CREATE EXTENSION pg_stat_statements;
Da udvidelsen er afhængig af en .so , skal du indlæse det ved hjælp af shared_preload_libraries :
shared_preload_libraries = 'pg_stat_statements'
Dette kræver desværre en genstart af PostgreSQL-serveren; så sørg for at gøre dette, før du går live.
Hvis du har opgraderet fra en tidligere version af PostgreSQL, skal du også sørge for at opgradere din pg_stat_statement-udvidelse ved at bruge:
ALTER EXTENSION pg_stat_statements UPDATE;
Udvidelsen pg_stat_statements logger ikke noget, den bruges via querying i visningen af samme navn. For flere detaljer, se den officielle dokumentation.
Forespørgselsudførelsesplaner via auto_explain
auto_explain er en anden udvidelse til stede i kerne PostgreSQL. Det kan logge udførelsesplanerne for langsomme forespørgsler. Det skal kun føjes tilshared_preload_libraries , og behøver ikke at blive installeret som en udvidelse. Den har også et par andre muligheder, der typisk skal indstilles til ikke-standardværdier:
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
Ovenstående logger udførelsesplanen for enhver forespørgsel, der tager mere end 1 sekund at fuldføre. Her er et eksempel på output:
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 ...]
For at lære mere om auto_explain, se de officielle dokumenter.
Udvidelserne pg_stat_statements og auto_explain er de eneste to bredt understøttede muligheder, som PostgreSQL har til styring af forespørgselsydelse og styring af forespørgselsplaner. Det kan betale sig at lære disse to funktioner at kende og planlægge fremad med at bruge dem i produktionen.
Applikationsnavn
Applikationsnavnet er en parameter på klientsiden og kan normalt indstilles i DSN'er eller forbindelsesstrenge i libpq-stil, som din applikation bruger til forbindelsesoplysninger. Mange værktøjer og hjælpeprogrammer i PostgreSQL eco-systemet forstår applikationsnavnet, og det hjælper med at sætte dette til en meningsfuld værdi, for eksempel:
application_name = weekly-revenue-report
Dette ville blive indstillet for hver klientapplikation, der opretter forbindelse til din PostgreSQLserver.