Het kan soms een uitdaging zijn om erachter te komen waarom een query die goed presteert in ontwikkeling en testen de productie opblaast. Lees verder voor meer informatie over enkele functies die inzicht kunnen geven in hoe uw zoekopdrachten in productie gaan.
Momenteel actieve zoekopdrachten
Wanneer een client verbinding maakt met een PostgreSQL-server, wordt het belangrijkste Postgres-serverproces (van oudsher de postmaster genoemd) ) spawnt een nieuw proces (genaamd debackend ) om de vragen van de klant te beantwoorden. Elke backend wacht daarom tot de client een query verzendt, of probeert er een uit te voeren.
De systeemweergave pg_stat_activity toont informatie over elke backend die momenteel wordt uitgevoerd. Het toont met name de query die de back-end momenteel uitvoert als deze actief is, of de laatste query die hij heeft uitgevoerd als hij wacht tot de client een andere query verzendt.
Hier zijn twee backends die clients bedienen die zijn verbonden met de database testdb , waarbij ze allebei actief hun zoekopdrachten uitvoeren:
testdb=# select usename,datname,state,query from pg_stat_activity where datname='testdb';
-[ RECORD 1 ]-----------------------------------------------------------------------------
usename | postgres
datname | testdb
state | active
query | SELECT pg_sleep(10);
-[ RECORD 2 ]-----------------------------------------------------------------------------
usename | postgres
datname | testdb
state | active
query | select usename,datname,state,query from pg_stat_activity where datname='testdb';Soms wacht de query mogelijk op een vergrendeling, en ook dit verschijnt inpg_stat_activity. U kunt hier een INSERT zien die wacht op een relatievergrendeling:
testdb=# select wait_event_type, wait_event, left(query, 60) from pg_stat_activity where datname='testdb';
-[ RECORD 1 ]---+-------------------------------------------------------------
wait_event_type | Client
wait_event | ClientRead
left | lock table t in access exclusive mode;
-[ RECORD 2 ]---+-------------------------------------------------------------
wait_event_type |
wait_event |
left | select wait_event_type, wait_event, left(query, 60) from pg_
-[ RECORD 3 ]---+-------------------------------------------------------------
wait_event_type | Lock
wait_event | relation
left | insert into t values (1);Zie de documenten voor meer informatie over pg_stat_activity.
Hoewel deze weergave nuttig is om te begrijpen wat Postgres momenteel aan het doen is, biedt het geen informatie over de uitvoeringsstatistieken van query's of informatie over query's die zijn uitgevoerd.
Alle zoekopdrachten die in het verleden zijn uitgevoerd
Daarvoor is de extensie pg_stat_statements is van onschatbare waarde. Deze extensie is opgenomen in de kerndistributie van PostgreSQL en is ook beschikbaar op beheerde services zoals AWS RDS en GCP SQL.
pg_stat_statements (PSS) is een "extensie" in PostgreSQL-termen en moet eerst worden geïnstalleerd:
- Raadpleeg de documentatie van uw Linux-distro om te zien of de extensie vooraf is geïnstalleerd of dat er een ander pakket voor moet worden geïnstalleerd. Op Centos 7 moet je bijvoorbeeld
sudo yum install postgresql-contrib. - Bewerk het hoofdconfiguratiebestand postgresql.conf (meestal onder
/etc, zoals/etc/postgresql/10/main/postgresql.confop Debian) en wijzig de waarde vanshared_preload_librariesnaar "pg_stat_statements". Dit is een door komma's gescheiden lijst met waarden, dus als er al iets staat, voeg dan een komma toe en dan "pg_stat_statements". - Voor AWS RDS moet u uw actieve parametergroep wijzigen en de waarde instellen.
- Na het bewerken van "shared_preload_libraries", moet je de PostgreSQL-daemon opnieuw starten. Hier is helaas geen weg omheen. Op AWS RDS moet u de RDS-instantie opnieuw opstarten.
- Na een herstart zou de PostgreSQL-server de gedeelde bibliotheek hebben geladen, en we kunnen de extensie installeren door
CREATE EXTENSION pg_stat_statementsuit te voeren . Je moet een superuser zijn om deze opdracht uit te voeren. - U kunt de extensie in elke database installeren en toch de query's in alle databases zien.
Nadat de extensie is geïnstalleerd, kunt u de weergave opvragen met de naam pg_stat_statements om informatie te krijgen over elke uitgevoerde query sinds de extensie is geïnstalleerd.
De getallen, zoals de tijd die nodig is om de query uit te voeren, worden opgeteld als een som. Alleen al voor de uitvoeringstijd van de query worden enkele statistieken (gemiddelde, min, max, standaarddeviatie) gepresenteerd. Deze waarden kunnen worden gewist met de functiepg_stat_statements_reset .
Hier is hoe een rij van pg_stat_statements ziet eruit als:
testdb=# select * from pg_stat_statements where query like '%pg_sleep%' and dbid=42548;
-[ RECORD 1 ]-------+--------------------
userid | 10
dbid | 42548
queryid | 2649515222348904837
query | SELECT pg_sleep($1)
calls | 1
total_time | 10016.782625
min_time | 10016.782625
max_time | 10016.782625
mean_time | 10016.782625
stddev_time | 0
rows | 1
shared_blks_hit | 0
shared_blks_read | 0
shared_blks_dirtied | 0
shared_blks_written | 0
local_blks_hit | 0
local_blks_read | 0
local_blks_dirtied | 0
local_blks_written | 0
temp_blks_read | 0
temp_blks_written | 0
blk_read_time | 0
blk_write_time | 0Afgezien van de identificerende parameters (gebruiker, database, zoekopdracht), kunt u veel interessante dingen over uw zoekopdracht achterhalen:
- Hoe lang het normaal duurt om uit te voeren (
mean_time) - Hoeveel rijen het gemiddeld retourneert (
rows/calls) - De hoeveelheid gegevens die van de gedeelde buffercache wordt gelezen en de hoeveelheid gegevens die van de schijf wordt gelezen (de
shared_blks_readtoont de totale hoeveelheid gegevens die de query heeft gelezen, waarvanshared_blks_hitkwam uit de cache) - De hoeveelheid gegevens die synchroon naar de schijf moest worden geschreven vanwege cachedruk (
shared_blks_written) - De hoeveelheid gegevens die is geschreven, als het aantal aangeraakte blokken (
shared_blks_dirtied) - De hoeveelheid tijd besteed aan het lezen en schrijven van de schijf (
blk_{read,write}_time) - Tijdelijke bestanden geschreven naar en gelezen van (
temp_blks_{read,written}) - Tijdelijke tabellen geschreven naar en gelezen uit (
local_*)
De lees- en schrijftijden van de schijf zijn alleen beschikbaar als de configuratieparametertrack_io_timing is ingeschakeld. Standaard is dat niet het geval. Op de meeste moderne Linux-systemen zou het ok moeten zijn om deze parameter aan te zetten. Lees meer.
Het is de moeite waard om een snapshot te maken van de pg_stat_statements gegevens continu met regelmatige tussenpozen om te zien hoe deze parameters trending zijn per query. De open source tool pgmetrics kan de pg_stat_statements extraheren en blootleggen data als JSON voor eenvoudigere automatisering.
Query's die tijdens een tijdsbereik worden uitgevoerd
Als u eenmaal zo'n systeem heeft, wordt het gemakkelijk om de uitgevoerde query's in een bepaald tijdsbestek te volgen. Dit maakt het gemakkelijk om problemen op te lossen, zoals waarom een nachtelijke batchtaak langer duurde dan verwacht.
Door de tellers tussen twee gegeven tijdstempels af te trekken, kunt u de meeste getallen vinden zoals voorheen, met uitzondering van min, max en standaarddeviatie. Dit is voldoende om de zoekopdrachten te identificeren die binnen het tijdbereik zijn uitgevoerd en de bronnen die ze hebben verbruikt.
Trage zoekopdrachten loggen
Een andere manier om snel query's te identificeren die meer tijd in beslag nemen dan verwacht, is door het loggen van instructies in te schakelen. U kunt een drempelduur specificeren, en als de query langer duurt om te voltooien, wordt deze gelogd. (In het normale PostgreSQL-logbestand is er geen apart logbestand voor langzame zoekopdrachten.)
Bewerk de configuratie zoals hieronder om deze functie in te schakelen:
log_min_duration_statement = 1000 # in milliseconds
en herlaad Postgres. Je kunt ook ALTER SYSTEM . gebruiken :
ALTER SYSTEM SET log_min_duration_statement = 1000; -- in millisecondsHiermee wordt elke instructie (inclusief niet-DML) die meer dan een seconde duurt om te voltooien gelogd:
2019-12-02 16:57:05.727 UTC [8040] postgres@testdb LOG: duration: 10017.862 ms statement: SELECT pg_sleep(10);De werkelijke tijd die de query in beslag neemt, evenals de volledige SQL-tekst, wordt gelogd.
Als u een logboekbewakingssysteem heeft en het aantal langzame zoekopdrachten per uur / per dag kunt volgen, kan dit een goede indicator zijn voor de prestaties van de applicatie.
Plannen voor het uitvoeren van query's
Als u eenmaal een zoekopdracht heeft gevonden waarvan u denkt dat deze sneller zou moeten worden uitgevoerd, is de volgende stap om het queryplan te bekijken. Om mee te werken hebt u doorgaans het actuelequeryplan van productieservers nodig. Als je EXPLAIN zo goed kunt uitvoeren op productieservers, moet je anders vertrouwen opauto_explain .
auto_explain is een andere kernuitbreiding van PostgreSQL, ofwel al geïnstalleerd of beschikbaar als een "contrib" -pakket voor uw distro. Het is ook beschikbaar op AWSRDS. auto_explain is een beetje eenvoudiger te installeren dan pg_stat_statements :
- Bewerk de postgres-configuratie (of de RDS-parametergroep)
shared_preload_librariesomauto_explainop te nemen . - Je hoeft Postgres echter niet opnieuw te starten, je kunt in plaats daarvan gewoon uitvoeren:
LOAD 'auto_explain';. - U wilt de instellingen configureren, in ieder geval deze:
auto_explain.log_min_duration = 1000 # seconds
In wezen, wanneer een zoekopdracht langer duurt danauto_explain.log_min_duration aantal seconden om te voltooien, auto_explainlogs de query en het uitvoeringsplan voor de query in het logbestand, als volgt:
2019-12-04 09:23:05.130 UTC [12823] postgres@testdb LOG: duration: 11025.765 ms plan:
Query Text: select pg_sleep(11);
Result (cost=0.00..0.01 rows=1 width=4) (actual time=11025.716..11025.718 rows=1 loops=1)
Output: pg_sleep('11'::double precision)Het kan het plan ook in JSON-formaat loggen, als je scripts hebt die het kunnen verwerken:
2019-12-02 17:30:53.676 UTC [8040] postgres@testdb LOG: duration: 10000.230 ms plan:
{
"Query Text": "SELECT pg_sleep(10);",
"Plan": {
"Node Type": "Result",
"Parallel Aware": false,
"Startup Cost": 0.00,
"Total Cost": 0.01,
"Plan Rows": 1,
"Plan Width": 4,
"Actual Startup Time": 10000.205,
"Actual Total Time": 10000.206,
"Actual Rows": 1,
"Actual Loops": 1,
"Output": ["pg_sleep('10'::double precision)"],
"Shared Hit Blocks": 0,
"Shared Read Blocks": 0,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"I/O Read Time": 0.000,
"I/O Write Time": 0.000
},
"Triggers": [
]
}In Postgres is er geen andere manier dan auto_explain om naar het uitvoeringsplan te kijken van een query die al is uitgevoerd, waardoor auto_explain een belangrijk hulpmiddel in uw gereedschapskist is.