PostgreSQL wordt geleverd met een overvloed aan configuratie-opties, maar het wijzigen van de standaardinstellingen van sommige van deze opties verbetert de zichtbaarheid van uw PostgreSQL-server drastisch. U wilt deze opties instellen en configureren voordat er zich problemen voordoen in de productie, omdat ze informatie kunnen verschaffen die essentieel is om deze problemen te begrijpen en op te lossen.
Lees verder voor meer informatie over de instellingen en extensies die statistieken en informatie over de interne werking van uw PostgreSQL-server blootleggen.
Logregelvoorvoegsel
De log_line_prefix configuratieoptie bepaalt wat PostgreSQL aan het begin van elke logregel schrijft. De standaard is afhankelijk van de specifieke Linuxdistributie of beheerde oplossing die je gebruikt, maar vaker wel dan niet bevat het niet een paar items die erg handig kunnen zijn bij het opsporen van misdragende clients. Probeer deze log_line_prefix :
log_line_prefix = '%m [%p] %a %u %d %h 'Het bevat het tijdstempel (%m ), de PID van het backend-proces (%p ), de applicatienaam (%a ) van de klant, de gebruikersnaam waarmee de klant is verbonden (%u ), de database waarmee de client verbinding heeft gemaakt (%d ) en de hostnaam of IP waar de verbinding vandaan komt (%h ). Dit resulteert in loglines als deze:
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;die veel nuttiger zijn dan de standaard. U kunt zien dat een client verbonden is vanaf 172.17.0.1 als gebruiker postgres naar database bank , en de applicatie was psql . Absoluut een verbetering ten opzichte van de standaardoptie, die alleen dit laat zien:
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;Trage zoekopdrachten loggen
PostgreSQL kan worden geconfigureerd om query's te loggen die meer dan een bepaalde tijd nodig hebben om uit te voeren. Deze gaan in hetzelfde logbestand; er is geen apart logbestand voor langzame zoekopdrachten zoals in MySQL.
Gebruik delog_min_duration_statement om instructies te loggen die meer dan 1 seconde duren om uit te voeren. optie als deze:
log_min_duration_statement = 1sMerk op dat log_min_duration_statement zal alle instructies in overweging nemen (inclusief bijvoorbeeld langlopende admin-instructies zoals REINDEX TABLE ) en niet alleen vragen (SELECT ). Hier zijn enkele logboekvermeldingen die door deze optie worden geproduceerd:
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);Als dit resulteert in te veel logboeken van vergelijkbare uitspraken, kunt u Postgres vertellen om er slechts een percentage van te loggen, met behulp van:
log_min_duration_statement = -1
log_min_duration_sample = 1s
log_statement_sample_rate = 0.25Dit registreert slechts 25% van de instructies die in aanmerking komen voor logboekregistratie (die meer dan 1 seconde duurden om uit te voeren). De logoutput is hetzelfde als voorheen. Er is geen manier om te weten hoeveel geldige verklaringen niet zijn gelogd.
Om alle instructies te loggen, samen met de tijd die nodig is om ze uit te voeren, gebruikt u delog_statement optie in plaats daarvan:
log_statement = mod
log_duration = onDe 'mod'-optie vertelt Postgres om DDL's en gegevensmodificerende verklaringen te loggen. Dit resulteert in logs zoals deze:
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 msWees gewaarschuwd:het is niet het is mogelijk om voorbeeldregistratie van verklaringen op deze manier te gebruiken, alle verklaringen worden gelogd en je zult eindigen met tonnen logboekvermeldingen.
Loggingsloten en impasses
Query's kunnen te lang wachten om een slot te verkrijgen. Meestal wordt een bovengrens voor hoe lang te wachten ingesteld met behulp van de optie lock_timeout , meestal aan de kant van de klant. Als een vraag zo lang heeft gewacht om een slot te verkrijgen, zal Postgres de uitvoering van deze vraag annuleren en een fout loggen:
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;Stel dat u een vergrendelingstime-out van 1 minuut wilt instellen, maar logquery's in die langer dan bijvoorbeeld 30 seconden op vergrendelingen wachten. U kunt dit doen met:
log_lock_waits = on
deadlock_timeout = 30sDit maakt logs als volgt:
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;Het gebruik van deadlock_timeout is geen typfout:het is de waarde die het lock-wachtlogmechanisme gebruikt. Idealiter had er zoiets als log_min_duration_lock_wait . moeten zijn ,maar helaas is dat niet het geval.
In het geval van daadwerkelijke deadlocks, zal Postgres de deadlock-transacties afbreken na deadlock_timeout duur, en zal de beledigende verklaringen loggen. Er is geen expliciete configuratie nodig.
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;Autovacuüms registreren
Het autovacuümproces treedt in werking wanneer Postgres vaststelt dat de gegevens in een tabel voldoende zijn gewijzigd om een vacuüm en analyse te rechtvaardigen. Om dit proces in de gaten te houden, schakelt u het loggen van autovacuum runs in:
log_autovacuum_min_duration = 250msHier is een voorbeelditem dat werd veroorzaakt door buitensporige wijzigingen in éé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 sMerk op dat autovacuüm doorgaans een analyse activeert na het vacuüm, en dit zal ook worden vastgelegd.
Deze logboeken helpen u erachter te komen hoe u de autovacuümparameters het beste kunt afstemmen en helpen bij het onderzoeken of en wanneer autovacuüm niet zo effectief is als u had verwacht.
Checkpoints loggen
Checkpointing is het proces van het pushen van WAL-gelogde wijzigingen in de daadwerkelijke bestanden die achter tabellen staan. Idealiter zouden controlepunten met regelmatige en niet al te frequente intervallen moeten plaatsvinden, aangezien het een CPU- en schijfintensief proces is. Om verschillende redenen worden controlepunten ook gedwongen om vóór de volgende geplande tijd te gebeuren, en dit resulteert in verminderde queryprestaties.
Schakel het loggen van checkpoints in om de frequentie en efficiëntie van checkpoints in de gaten te houden:
log_checkpoints = onDit vertelt PostgreSQL om het volgende te loggen wanneer een controlepunt plaatsvindt:
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 kBDe eerste regel bevat de vlaggen die door de backend aan de checkpointer zijn doorgegeven. U kunt zien dat de "kracht" een controlepunt veroorzaakte, ook al waren er geen wijzigingen in het controlepunt in behandeling. Als "onmiddellijk" niet was opgegeven, zou de checkpointer tot aan checkpoint_completion_target zijn geweest .
Andere server-side-instellingen
Er zijn een aantal andere instellingen die u kunt inschakelen in uw PostgreSQL-configuratie die u kunnen helpen bij het diagnosticeren van problemen:
- track_io_timing - dit instellen op aan laat u de tijd zien die indisk I/O is besteed aan elke query (gecombineerd met de extensie pg_stat_statements die hieronder wordt beschreven). Zie de documentatie over een waarschuwing om dit in te schakelen, maar zou veilig moeten zijn op bijna elke moderne Linux. Het is onmogelijk om de schijf-I/O-kosten van een query te zien zonder dit aan te zetten.
- track_commit_timestamp - dit instellen op aan kan handig zijn bij het debuggen van replicatievertragingen en andere replicatiegerelateerde problemen.
Querystatistieken via pg_stat_statements
De extensie pg_stat_statements is een essentieel accessoire voor elke PostgreSQL-implementatie. Het verzamelt en registreert statistieken voor elke uitgevoerde query en presenteert deze als een weergave genaamd "pg_stat_statements". Dit is een extensie, wat betekent dat u deze expliciet moet installeren in elke database waarvoor u gegevens wilt, met behulp van het commando:
CREATE EXTENSION pg_stat_statements;Omdat de extensie afhankelijk is van een .so , moet u dat laden metshared_preload_libraries :
shared_preload_libraries = 'pg_stat_statements'Dit vereist helaas een herstart van de PostgreSQL-server; dus zorg ervoor dat je dit doet voordat je live gaat.
Als u een upgrade hebt uitgevoerd vanaf een eerdere versie van PostgreSQL, moet u ook uw pg_stat_statement-extensie upgraden met:
ALTER EXTENSION pg_stat_statements UPDATE;De extensie pg_stat_statements logt niets, het wordt gebruikt via het opvragen van de weergave met dezelfde naam. Zie de officiële documentatie voor meer details.
Query-uitvoeringsplannen via auto_explain
auto_explain is een andere extensie die aanwezig is in de kern van PostgreSQL. Het kan de uitvoeringsplannen van langzame query's loggen. Het hoeft alleen te worden toegevoegd aanshared_preload_libraries , en hoeft niet als extensie te worden geïnstalleerd. Het heeft ook een aantal andere opties die normaal gesproken moeten worden ingesteld op niet-standaardwaarden:
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 = jsonHet bovenstaande registreert het uitvoeringsplan voor elke query die meer dan 1 seconde duurt om te voltooien. Hier is een voorbeelduitvoer:
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 ...]Zie de officiële documenten voor meer informatie over auto_explain.
De extensies pg_stat_statements en auto_explain zijn de enige twee breed ondersteunde opties die PostgreSQL heeft voor het beheer van queryprestaties en het beheer van queryplannen. Het loont de moeite om deze twee functies te leren kennen en vooruit te plannen voor het gebruik ervan in productie.
Applicatienaam
De toepassingsnaam is een parameter aan de clientzijde en kan meestal worden ingesteld in DSN's of libpq-achtige verbindingsreeksen die uw toepassing gebruikt voor verbindingsinformatie. Veel hulpprogramma's en hulpprogramma's in het PostgreSQL-ecosysteem begrijpen de toepassingsnaam en het helpt om deze op een zinvolle waarde in te stellen, bijvoorbeeld:
application_name = weekly-revenue-reportDit wordt ingesteld voor elke clienttoepassing die verbinding maakt met uw PostgreSQLserver.