PostgreSQL zawiera mnóstwo opcji konfiguracyjnych, ale zmiana domyślnych ustawień niektórych z tych opcji drastycznie poprawia obserwowalność serwera PostgreSQL. Będziesz chciał ustawić i skonfigurować te opcje, zanim problemy pojawią się w produkcji, ponieważ mogą one dostarczyć informacji niezbędnych do zrozumienia i rozwiązania tych problemów.
Czytaj dalej, aby dowiedzieć się więcej o ustawieniach i rozszerzeniach, które ujawniają metryki i informacje o wewnętrznym działaniu Twojego serwera PostgreSQL.
Prefiks wiersza dziennika
log_line_prefix opcja konfiguracji określa, co PostgreSQL zapisuje na początku każdego wiersza dziennika. Wartość domyślna zależy od konkretnej dystrybucji Linuksa lub rozwiązania zarządzanego, którego używasz, ale najczęściej nie zawiera kilku elementów, które mogą okazać się bardzo przydatne w śledzeniu niewłaściwie zachowujących się klientów. Wypróbuj ten log_line_prefix :
log_line_prefix = '%m [%p] %a %u %d %h '
Zawiera znacznik czasu (%m ), PID procesu zaplecza (%p ), nazwa aplikacji (%a ) klienta, nazwa użytkownika, z którym połączył się klient (%u ), baza danych, z którą połączył się klient (%d ) oraz nazwę hosta lub adres IP, z którego pochodzi połączenie (%h ). Daje to takie logiki:
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;
które są znacznie bardziej przydatne niż domyślne. Widać, że klient połączył się z 172.17.0.1 jako użytkownik postgres do bazy danych stół , a aplikacja to psql . Zdecydowanie ulepszenie w stosunku do opcji domyślnej, która pokazuje tylko to:
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;
Rejestrowanie powolnych zapytań
PostgreSQL można skonfigurować do rejestrowania zapytań, których wykonanie zajmuje więcej niż określony czas. Znajdują się one w tym samym pliku dziennika; nie ma oddzielnego pliku dziennika zapytań, jak w MySQL.
Aby rejestrować instrukcje, których wykonanie trwa dłużej niż 1 sekundę, użyj log_min_duration_statement opcja taka:
log_min_duration_statement = 1s
Pamiętaj, że log_min_duration_statement weźmie pod uwagę wszystkie instrukcje (w tym na przykład długotrwałe instrukcje administratora, takie jak TABELA REINDEKSU ), a nie tylko zapytania (SELECT ). Oto kilka wpisów dziennika utworzonych przez tę opcję:
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);
Jeśli spowoduje to powstanie zbyt wielu dzienników podobnych instrukcji, możesz powiedzieć Postgresowi, aby logował tylko ich procent, używając:
log_min_duration_statement = -1
log_min_duration_sample = 1s
log_statement_sample_rate = 0.25
W ten sposób rejestrowane jest tylko 25% instrukcji, które kwalifikują się do zarejestrowania (tych, których wykonanie zajęło ponad 1 sekundę). Dane wyjściowe dziennika są takie same jak poprzednio. Nie ma sposobu, aby dowiedzieć się, ile kwalifikujących się wyciągów nie zostało zarejestrowanych.
Aby zarejestrować wszystkie instrukcje wraz z czasem ich wykonania, użyj log_statement zamiast tego opcja:
log_statement = mod
log_duration = on
Opcja „mod” nakazuje Postgresowi rejestrowanie DDL i instrukcji modyfikujących dane. Wynikiem tego są logi takie jak:
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
Ostrzegamy, że nie w ten sposób możliwe jest włączenie rejestrowania próbkowania wyciągów, wszystkie wyciągi zostaną zarejestrowane, a otrzymasz mnóstwo wpisów w dzienniku.
Logowanie blokad i zakleszczeń
Zapytania mogą czekać zbyt długo, aby uzyskać blokadę. Zazwyczaj górny limit czasu oczekiwania jest ustawiany za pomocą opcji lock_timeout , zwykle po stronie klienta. Jeśli zapytanie czekało tak długo na uzyskanie blokady, Postgres anuluje wykonanie tego zapytania i zarejestruje błąd:
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;
Załóżmy, że chcesz ustawić limit czasu blokady na 1 minutę, ale rejestruj zapytania, które oczekują na blokady dłużej niż, powiedzmy, 30 sekund. Możesz to zrobić za pomocą:
log_lock_waits = on
deadlock_timeout = 30s
Spowoduje to utworzenie takich dzienników:
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;
Korzystanie z deadlock_timeout nie jest literówką:jest to wartość, której używa mechanizm lock waitloging. Idealnie powinno być coś takiego jak log_min_duration_lock_wait , ale niestety tak nie jest.
W przypadku rzeczywistych zakleszczeń Postgres przerwie te transakcje po deadlock_timeout czas trwania i zarejestruje obraźliwe oświadczenia. Żadna wyraźna konfiguracja nie jest konieczna.
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;
Rejestrowanie autoodkurzania
Proces automatycznego odkurzania rozpoczyna się, gdy Postgres stwierdzi, że dane w tabeli zmieniły się wystarczająco, aby zapewnić próżnię i analizę. Aby mieć oko na ten proces, włącz rejestrowanie przebiegów autoodkurzania:
log_autovacuum_min_duration = 250ms
Oto przykładowy wpis spowodowany nadmiernymi zmianami w jednej tabeli:
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
Zwróć uwagę, że automatyczne podciśnienie zazwyczaj uruchamia analizę po podciśnieniu i zostanie to również zarejestrowane.
Te dzienniki pomogą Ci dowiedzieć się, jak najlepiej dostroić parametry automatycznego odkurzania, a także pomogą zbadać, czy i kiedy automatyczna próżnia nie jest tak skuteczna, jak myślałeś.
Rejestrowanie punktów kontrolnych
Tworzenie punktów kontrolnych to proces wpychania zmian zarejestrowanych przez WAL do rzeczywistych plików, które obsługują tabele. Idealnie, punkty kontrolne powinny pojawiać się w regularnych i niezbyt częstych odstępach czasu, ponieważ jest to proces intensywnie wykorzystujący procesor i dysk. Z różnych powodów punkty kontrolne są również wymuszone przed następnym zaplanowanym czasem, co skutkuje zmniejszoną wydajnością zapytań.
Aby mieć oko na częstotliwość i wydajność punktów kontrolnych, włącz rejestrowanie punktów kontrolnych:
log_checkpoints = on
Dzięki temu PostgreSQL ma rejestrować następujące informacje za każdym razem, gdy wystąpi punkt kontrolny:
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
Pierwsza linia zawiera flagi, które backend przekazał do wskaźnika kontrolnego. Widać, że „siła” spowodowała punkt kontrolny, mimo że nie było żadnych oczekujących zmian w punkcie kontrolnym. Jeśli „natychmiastowy” nie został określony, punkt kontrolny wskazywałby na checkpoint_completion_target .
Inne ustawienia po stronie serwera
Istnieje kilka innych ustawień, które możesz włączyć w konfiguracji PostgreSQL, które pomogą w diagnozowaniu problemów:
- track_io_timing - ustawienie tego na włączone pozwala zobaczyć czas spędzony na indisk I/O dla każdego zapytania (w połączeniu z rozszerzeniem pg_stat_statements opisanym poniżej). Zapoznaj się z dokumentacją na temat ostrzeżenia przed włączeniem tego, ale powinno być bezpieczne na prawie każdym nowoczesnym Linuksie. Widzenie kosztu operacji we/wy zapytania jest niemożliwe bez włączenia tej opcji.
- track_commit_timestamp - ustawienie tego na włączone może być przydatny w debugowaniu opóźnień replikacji i innych problemów związanych z replikacją.
Statystyki zapytań za pomocą pg_stat_statements
Rozszerzenie pg_stat_statements jest niezbędnym dodatkiem do każdego wdrożenia PostgreSQL. Gromadzi i rejestruje statystyki dla każdego wykonanego zapytania i przedstawia je jako widok o nazwie „pg_stat_statements”. Jest to rozszerzenie, co oznacza, że musisz je jawnie zainstalować w każdej bazie danych, dla której chcesz uzyskać dane, używając polecenia:
CREATE EXTENSION pg_stat_statements;
Ponieważ rozszerzenie opiera się na .so , musisz to załadować za pomocąshared_preload_libraries :
shared_preload_libraries = 'pg_stat_statements'
Niestety wymaga to ponownego uruchomienia serwera PostgreSQL; więc upewnij się, że zrobiłeś to przed transmisją na żywo.
Jeśli zaktualizowałeś poprzednią wersję PostgreSQL, pamiętaj o uaktualnieniu rozszerzenia pg_stat_statement, używając:
ALTER EXTENSION pg_stat_statements UPDATE;
Rozszerzenie pg_stat_statements nie rejestruje niczego, jest używane poprzez odpytywanie widoku o tej samej nazwie. Więcej informacji można znaleźć w oficjalnej dokumentacji.
Plany wykonywania zapytań przez auto_explain
automatyczne wyjaśnienie to kolejne rozszerzenie obecne w rdzeniu PostgreSQL. Może rejestrować plany wykonania powolnych zapytań. Wystarczy go dodać doshared_preload_libraries , i nie musi być instalowany jako rozszerzenie. Posiada również kilka innych opcji, które zazwyczaj muszą być ustawione na wartości inne niż domyślne:
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
Powyższe rejestruje plan wykonania dla każdego zapytania, którego wykonanie trwa dłużej niż 1 sekundę. Oto przykładowe wyjście:
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 ...]
Aby dowiedzieć się więcej o auto_explain, zapoznaj się z oficjalnymi dokumentami.
Rozszerzenia pg_stat_statements i automatyczne wyjaśnienie są jedynymi dwoma szeroko wspieranymi opcjami PostgreSQL do zarządzania wydajnością zapytań i zarządzania planami zapytań. Warto poznać te dwie funkcje i zaplanować z wyprzedzeniem ich wykorzystanie w produkcji.
Nazwa aplikacji
Nazwa aplikacji jest parametrem po stronie klienta i zwykle można ją ustawić w ciągach połączenia w stylu DSN lub libpq, których aplikacja używa do informacji o połączeniu. Wiele narzędzi i narzędzi w ekosystemie PostgreSQL rozumie nazwę aplikacji i pomaga ustawić ją na znaczącą wartość, na przykład:
application_name = weekly-revenue-report
Byłoby to ustawione dla każdej aplikacji klienckiej, która łączy się z twoim serwerem PostgreSQL.