Podczas pracy z bazami danych OLTP (OnLine Transaction Processing) wydajność zapytań jest najważniejsza, ponieważ bezpośrednio wpływa na wrażenia użytkownika. Powolne zapytania oznaczają, że aplikacja nie reaguje i jest powolna, co skutkuje złymi współczynnikami konwersji, niezadowoleniem użytkowników i wszystkimi zestawami problemów.
OLTP jest jednym z najczęstszych przypadków użycia PostgreSQL, dlatego chcesz, aby Twoje zapytania działały tak płynnie, jak to tylko możliwe. W tym blogu chcielibyśmy porozmawiać o tym, jak można zidentyfikować problemy z wolnymi zapytaniami w PostgreSQL.
Zrozumienie powolnego dziennika
Ogólnie rzecz biorąc, najbardziej typowym sposobem identyfikowania problemów z wydajnością w PostgreSQL jest zbieranie powolnych zapytań. Możesz to zrobić na kilka sposobów. Po pierwsze, możesz włączyć to w jednej bazie danych:
pgbench=# ALTER DATABASE pgbench SET log_min_duration_statement=0;
ALTER DATABASEPo tym wszystkie nowe połączenia z bazą danych „pgbench” będą rejestrowane w dzienniku PostgreSQL.
Można również włączyć to globalnie, dodając:
log_min_duration_statement = 0do konfiguracji PostgreSQL, a następnie przeładuj konfigurację:
pgbench=# SELECT pg_reload_conf();
pg_reload_conf
----------------
t
(1 row)Umożliwia to rejestrowanie wszystkich zapytań we wszystkich bazach danych w PostgreSQL. Jeśli nie widzisz żadnych dzienników, możesz również włączyć logging_collector =on. Dzienniki będą zawierały cały ruch przychodzący do tabel systemowych PostgreSQL, co sprawi, że będzie on bardziej zaszumiony. Dla naszych celów pozostańmy przy logowaniu na poziomie bazy danych.
W dzienniku zobaczysz wpisy jak poniżej:
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);Możesz zobaczyć informacje o zapytaniu i czasie jego trwania. Niewiele więcej, ale zdecydowanie jest to dobre miejsce na rozpoczęcie. Najważniejszą rzeczą, o której należy pamiętać, jest to, że nie każde wolne zapytanie stanowi problem. Czasami zapytania muszą uzyskiwać dostęp do znacznej ilości danych i oczekuje się, że uzyskanie dostępu i przeanalizowanie wszystkich informacji, o które prosił użytkownik, zajmie im więcej czasu. Kolejne pytanie brzmi, co oznacza „wolno”? Zależy to głównie od aplikacji. Jeśli mówimy o aplikacjach interaktywnych, najprawdopodobniej zauważalne jest coś wolniejszego niż sekunda. Idealnie wszystko jest wykonywane w granicach 100 - 200 milisekund.
Opracowywanie planu wykonywania zapytań
Gdy ustalimy, że dane zapytanie rzeczywiście jest czymś, co chcemy poprawić, powinniśmy przyjrzeć się planowi wykonania zapytania. Przede wszystkim może się zdarzyć, że nic nie da się z tym zrobić i będziemy musieli zaakceptować, że dane zapytanie jest po prostu powolne. Po drugie, plany wykonywania zapytań mogą ulec zmianie. Optymalizatorzy zawsze starają się wybrać najbardziej optymalny plan wykonania, ale podejmują decyzje na podstawie tylko próbki danych, dlatego może się zdarzyć, że plan wykonania zapytania zmieni się w czasie. W PostgreSQL możesz sprawdzić plan wykonania na dwa sposoby. Najpierw szacunkowy plan wykonania, używając 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)Jak widać, oczekuje się od nas dostępu do danych za pomocą wyszukiwania klucza podstawowego. Jeśli chcemy dokładnie sprawdzić, jak dokładnie zostanie wykonane zapytanie, możemy użyć WYJAŚNIJ ANALIZĘ:
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)Teraz PostgreSQL wykonał to zapytanie i może nam podać nie tylko szacunki, ale dokładne liczby, jeśli chodzi o plan wykonania, liczbę dostępnych wierszy i tak dalej. Należy pamiętać, że rejestrowanie wszystkich zapytań może spowodować poważne obciążenie systemu. Powinieneś także mieć oko na kłody i upewnić się, że są prawidłowo obracane.
Pg_stat_statements
Pg_stat_statements to rozszerzenie, które gromadzi statystyki wykonania dla różnych typów zapytań.
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)Jak widać na powyższych danych, mamy listę różnych zapytań i informacje o czasie ich wykonania - to tylko część danych, które widzisz w pg_stat_statements, ale to wystarczy do abyśmy zrozumieli, że nasze wyszukiwanie klucza podstawowego zajmuje czasami prawie 39 sekund - to nie wygląda dobrze i zdecydowanie jest to coś, co chcemy zbadać.
Jeśli nie masz włączonej funkcji pg_stat_statements, możesz to zrobić w standardowy sposób. Albo za pomocą pliku konfiguracyjnego i
shared_preload_libraries = 'pg_stat_statements'Lub możesz to włączyć za pomocą wiersza poleceń PostgreSQL:
pgbench=# CREATE EXTENSION pg_stat_statements;
CREATE EXTENSIONKorzystanie z ClusterControl do eliminowania powolnych zapytań
Jeśli używasz ClusterControl do zarządzania bazą danych PostgreSQL, możesz go użyć do zbierania danych o wolnych zapytaniach.
Jak widać zbiera dane o wykonaniu zapytania - wysłane wiersze i zbadane, statystyki czasu wykonania i tak dalej. Dzięki niemu możesz łatwo wskazać najdroższe zapytania i zobaczyć, jak wygląda średni i maksymalny czas wykonania. Domyślnie ClusterControl zbiera zapytania, których wykonanie trwało dłużej niż 0,5 sekundy, możesz to zmienić w ustawieniach:
Wnioski
Ten krótki blog w żaden sposób nie obejmuje wszystkich aspektów i narzędzi pomocnych w identyfikowaniu i rozwiązywaniu problemów z wydajnością zapytań w PostgreSQL. Mamy nadzieję, że to dobry początek i że pomoże Ci zrozumieć, co możesz zrobić, aby wskazać główną przyczynę powolnych zapytań.
