När man arbetar med OLTP-databaser (OnLine Transaction Processing) är frågeprestanda avgörande eftersom det direkt påverkar användarupplevelsen. Långsamma frågor betyder att applikationen inte svarar och är långsam och detta resulterar i dåliga konverteringsfrekvenser, missnöjda användare och alla typer av problem.
OLTP är ett av de vanligaste användningsfallen för PostgreSQL, därför vill du att dina frågor ska köras så smidigt som möjligt. I den här bloggen vill vi prata om hur du kan identifiera problem med långsamma frågor i PostgreSQL.
Förstå den långsamma loggen
Generellt sett är det vanligaste sättet att identifiera prestandaproblem med PostgreSQL att samla in långsamma frågor. Det finns ett par sätt du kan göra det på. Först kan du aktivera det på en enda databas:
pgbench=# ALTER DATABASE pgbench SET log_min_duration_statement=0;
ALTER DATABASEEfter detta kommer alla nya anslutningar till 'pgbench'-databasen att loggas in i PostgreSQL-loggen.
Det är också möjligt att aktivera detta globalt genom att lägga till:
log_min_duration_statement = 0till PostgreSQL-konfigurationen och ladda sedan om config:
pgbench=# SELECT pg_reload_conf();
pg_reload_conf
----------------
t
(1 row)Detta möjliggör loggning av alla frågor i alla databaser i din PostgreSQL. Om du inte ser några loggar, kanske du vill aktivera logging_collector =på också. Loggarna kommer att inkludera all trafik som kommer till PostgreSQL-systemtabeller, vilket gör det mer bullrigt. Låt oss för våra syften hålla oss till loggning på databasnivå.
Det du ser i loggen är poster enligt nedan:
2020-02-21 09:45:39.022 UTC [13542] LOG: duration: 0.145 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 29817899;
2020-02-21 09:45:39.022 UTC [13544] LOG: duration: 0.107 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 11782597;
2020-02-21 09:45:39.022 UTC [13529] LOG: duration: 0.065 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 16318529;
2020-02-21 09:45:39.022 UTC [13529] LOG: duration: 0.082 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + 3063 WHERE tid = 3244;
2020-02-21 09:45:39.022 UTC [13526] LOG: duration: 16.450 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + 1359 WHERE bid = 195;
2020-02-21 09:45:39.023 UTC [13523] LOG: duration: 15.824 ms statement: UPDATE pgbench_accounts SET abalance = abalance + -3726 WHERE aid = 5290358;
2020-02-21 09:45:39.023 UTC [13542] LOG: duration: 0.107 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -2716 WHERE tid = 1794;
2020-02-21 09:45:39.024 UTC [13544] LOG: duration: 0.112 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -3814 WHERE tid = 278;
2020-02-21 09:45:39.024 UTC [13526] LOG: duration: 0.060 ms statement: INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (4876, 195, 39955137, 1359, CURRENT_TIMESTAMP);
2020-02-21 09:45:39.024 UTC [13529] LOG: duration: 0.081 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + 3063 WHERE bid = 369;
2020-02-21 09:45:39.024 UTC [13523] LOG: duration: 0.063 ms statement: SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
2020-02-21 09:45:39.024 UTC [13542] LOG: duration: 0.100 ms statement: UPDATE pgbench_branches SET bbalance = bbalance + -2716 WHERE bid = 210;
2020-02-21 09:45:39.026 UTC [13523] LOG: duration: 0.092 ms statement: UPDATE pgbench_tellers SET tbalance = tbalance + -3726 WHERE tid = 67;
2020-02-21 09:45:39.026 UTC [13529] LOG: duration: 0.090 ms statement: INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (3244, 369, 16318529, 3063, CURRENT_TIMESTAMP);Du kan se information om frågan och dess varaktighet. Inte mycket annat men det är definitivt ett bra ställe att börja. Det viktigaste att komma ihåg är att inte varje långsam fråga är ett problem. Ibland måste frågor få tillgång till en betydande mängd data och det förväntas ta längre tid för dem att komma åt och analysera all information som användaren efterfrågar. En annan fråga är vad "långsamt" betyder? Detta beror mest på applikationen. Om vi pratar om interaktiva applikationer märks med största sannolikhet något långsammare än en sekund. Helst exekveras allt inom 100 - 200 millisekunders gräns.
Utveckla en frågeexekveringsplan
När vi har fastställt att en given fråga verkligen är något vi vill förbättra, bör vi ta en titt på exekveringsplanen. Först och främst kan det hända att det inte finns något vi kan göra åt det och vi måste acceptera att en given fråga bara är långsam. För det andra kan exekveringsplanerna för frågor ändras. Optimerare försöker alltid välja den mest optimala exekveringsplanen men de fattar sina beslut baserat på bara ett urval av data, därför kan det hända att exekveringsplanen för frågor ändras med tiden. I PostgreSQL kan du kontrollera exekveringsplanen på två sätt. Först den beräknade genomförandeplanen, med hjälp av EXPLAIN:
pgbench=# EXPLAIN SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
QUERY PLAN
----------------------------------------------------------------------------------------------
Index Scan using pgbench_accounts_pkey on pgbench_accounts (cost=0.56..8.58 rows=1 width=4)
Index Cond: (aid = 5290358)Som du kan se förväntas vi komma åt data med hjälp av primärnyckelsökning. Om vi vill dubbelkolla hur exakt frågan kommer att köras kan vi använda EXPLAIN ANALYZE:
pgbench=# EXPLAIN ANALYZE SELECT abalance FROM pgbench_accounts WHERE aid = 5290358;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------
Index Scan using pgbench_accounts_pkey on pgbench_accounts (cost=0.56..8.58 rows=1 width=4) (actual time=0.046..0.065 rows=1 loops=1)
Index Cond: (aid = 5290358)
Planning time: 0.053 ms
Execution time: 0.084 ms
(4 rows)Nu har PostgreSQL kört den här frågan och den kan berätta för oss inte bara uppskattningarna utan exakta siffror när det kommer till exekveringsplanen, antalet rader som nås och så vidare. Tänk på att loggning av alla frågor kan bli en allvarlig omkostnad på ditt system. Du bör också hålla ett öga på stockarna och se till att de roteras ordentligt.
Pg_stat_statements
Pg_stat_statements är tillägget som samlar in körningsstatistik för olika frågetyper.
pgbench=# select query, calls, total_time, min_time, max_time, mean_time, stddev_time, rows from public.pg_stat_statements order by calls desc LIMIT 10;
query | calls | total_time | min_time | max_time | mean_time | stddev_time | rows
------------------------------------------------------------------------------------------------------+-------+------------------+----------+------------+---------------------+---------------------+-------
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 30437 | 6636.83641200002 | 0.006533 | 83.832148 | 0.218051595492329 | 1.84977058799388 | 30437
BEGIN | 30437 | 231.095600000001 | 0.000205 | 20.260355 | 0.00759258796859083 | 0.26671126085716 | 0
END | 30437 | 229.483213999999 | 0.000211 | 16.980678 | 0.0075396134310215 | 0.223837608828596 | 0
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 30437 | 290021.784321001 | 0.019568 | 805.171845 | 9.52859297305914 | 13.6632712046825 | 30437
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 30437 | 6667.27243200002 | 0.00732 | 212.479269 | 0.219051563294674 | 2.13585110968012 | 30437
SELECT abalance FROM pgbench_accounts WHERE aid = $1 | 30437 | 3702.19730600006 | 0.00627 | 38.860846 | 0.121634763807208 | 1.07735927551245 | 30437
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4, CURRENT_TIMESTAMP) | 30437 | 2349.22475800002 | 0.003218 | 61.372127 | 0.0771831901304325 | 0.971590327400244 | 30437
SELECT $1 | 6847 | 60.785467 | 0.002321 | 7.882384 | 0.00887767883744706 | 0.105198744982906 | 6847
insert into pgbench_tellers(tid,bid,tbalance) values ($1,$2,$3) | 5000 | 18.592042 | 0.001572 | 0.741427 | 0.0037184084 | 0.0137660355678027 | 5000
insert into pgbench_tellers(tid,bid,tbalance) values ($1,$2,$3) | 3000 | 7.323788 | 0.001598 | 0.40152 | 0.00244126266666667 | 0.00834442591085048 | 3000
(10 rows)Som du kan se på data ovan har vi en lista med olika frågor och information om deras exekveringstider - detta är bara en del av data som du kan se i pg_stat_statements men det räcker för oss att förstå att vår primärnyckelsökning ibland tar nästan 39 sekunder att slutföra - det här ser inte bra ut och det är definitivt något vi vill undersöka.
Om du inte har aktiverat pg_stat_statements kan du göra det på ett standardsätt. Antingen via konfigurationsfil och
shared_preload_libraries = 'pg_stat_statements'Eller så kan du aktivera det via PostgreSQL-kommandoraden:
pgbench=# CREATE EXTENSION pg_stat_statements;
CREATE EXTENSIONAnvända ClusterControl för att eliminera långsamma frågor
Om du råkar använda ClusterControl för att hantera din PostgreSQL-databas kan du använda den för att samla in data om långsamma frågor.
Som du kan se samlar den in data om körning av frågor - rader skickade och undersökt, körtidsstatistik och så vidare. Med den kan du enkelt peka ut de dyraste frågorna och se hur de genomsnittliga och maximala körtiderna ser ut. Som standard samlar ClusterControl in frågor som tog längre tid än 0,5 sekunder att slutföra, du kan ändra detta i inställningarna:
Slutsats
Den här korta bloggen täcker inte på något sätt alla aspekter och verktyg som är användbara för att identifiera och lösa frågeprestandaproblem i PostgreSQL. Vi hoppas att det är en bra början och att det kommer att hjälpa dig att förstå vad du kan göra för att lokalisera grundorsaken till de långsamma frågorna.