При всяко внедряване винаги има няколко заявки, които се изпълняват твърде бавно.
Прочетете, за да видите как да откривате заявки, чието изпълнение отнема твърде много време, и как да разберете защо са бавни.
Просто да използвате pg_stat_statements?
pg_stat_statements е популярно разширение, което е включено в основната дистрибуция на PostgreSQL и е достъпно по подразбиране за почти всички доставчици на DBaaS. Това е безценно и е горе-долу единственият начин да получите статистически данни за заявките, без да инсталирате персонализирани разширения.
Той обаче има няколко ограничения, когато става въпрос за откриване на бавни заявки.
Кумулативна статистика
Разширението pg_stat_statements предоставя кумулативно статистика за всяка заявка, изпълнявана някога от сървъра. За всяка заявка тя показва, наред с други показатели, общия брой изпълнения, както и общото време, необходимо за всички изпълнения.
За да „улавяте“ бавни заявки, когато се случат, трябва периодично да извличате цялото съдържание на pg_stat_statements прегледайте, съхранете го в база данни от времеви серии и сравнете броя на изпълнението. Например, ако имате съдържанието на pg_stat_statements в 10.00 ч. и 10.10 ч., можете да изберете онези заявки, които имат по-голям брой изпълнения в 10.10 ч., отколкото в 10.00 ч. За тези заявки можете да изчислите средното време за изпълнение през този интервал, като използвате:
(total time at 10.10 AM - total time at 10.00 AM) ÷ (total count at 10.10 AM - total count at 10.00 AM)
Ако това средно време за изпълнение надвиши горен праг, можете да задействате сигнал, за да предприемете действие.
Това работи сравнително добре на практика, но ще ви е необходима добра инфраструктура за наблюдение или специална услуга като pgDash.
Параметри на заявката
pg_stat_statements не улавя стойностите на параметрите за свързване, предадени на заявки.
Едно от нещата, които плановникът на заявки на Postgres оценява за избор на план за изпълнение, е броят на редовете, които условието вероятно ще филтрира. Например, ако повечето редове на таблица имат стойността на индексирана колона country като „САЩ“, специалистът по планиране може да реши да направи последователно сканиране от цялата таблица за къде клауза country = "US" , и може да реши да използва сканиране на индекс за country = "UK" от първото къде Очаква се клаузата да съответства на повечето редове в таблицата.
Познаването на действителната стойност на параметрите, за които изпълнението на заявката е било бавно, може да помогне за по-бързо диагностициране на проблеми с бавните заявки.
Бавно регистриране на заявки
По-простата алтернатива е да регистрирате бавни заявки. За разлика от определена друга СУБД, която улеснява това, PostgreSQL ни представя куп подобни конфигурационни настройки:
log_statementlog_min_duration_statementlog_min_duration_samplelog_statement_sample_ratelog_parameter_max_lengthlog_parameter_max_length_on_errorlog_duration
Те са описани подробно в документацията на Postgres. Ето една разумна отправна точка:
# next line says only log queries that take longer 5 seconds
log_min_duration_statement = 5s
log_parameter_max_length = 1024
log_parameter_max_length_on_error = 1024
Което води до регистрационни файлове като тези:
2022-04-14 06:17:11.462 UTC [369399] LOG: duration: 5.060 ms statement: select i.*, t."Name" as track, ar."Name" as artist
from "InvoiceLine" as i
join "Track" as t on i."TrackId" = t."TrackId"
join "Album" as al on al."AlbumId" = t."AlbumId"
join "Artist" as ar on ar."ArtistId" = al."ArtistId";
Ако има твърде много регистрационни файлове, можете да помолите Postgres да регистрира само (да речем) 50% от заявките, които се изпълняват повече от 5 секунди:
log_min_duration_sample = 5s
log_statement_sample_rate = 0.5 # 0..1 => 0%..100%
Разбира се, трябва да прочетете документите за това какво означават и предполагат тези параметри, преди да ги добавите във вашата конфигурация на Postgres. Бъдете предупредени, че настройките са странни и не интуитивни.
Планове за изпълнение на бавни заявки
Обикновено не е достатъчно да знаете, че е възникнала бавна заявка, също така ще трябва да разберете защо беше бавно. За това обикновено първо проверявате плана за изпълнение на заявката.
auto_explain е друго основно разширение на PostgreSQL (отново налично и в повечето DBaaS), което може да регистрира плановете за изпълнение на заявки, които току-що са приключили изпълнението. Това е документирано тук.
За да активирате auto_explain, обикновено го добавяте към shared_preload_libraries и рестартирайте Postgres. Ето примерна начална конфигурация:
# logs execution plans of queries that take 10s or more to run
auto_explain.log_min_duration = 10s
auto_explain.log_verbose = on
auto_explain.log_settings = on
auto_explain.log_format = json
auto_explain.log_nested_statements = on
# enabling these provide more information, but have a performance cost
#auto_explain.log_analyze = on
#auto_explain.log_buffers = on
#auto_explain.log_wal = on
#auto_explain.log_timing = on
#auto_explain.log_triggers = on
Това ще доведе до записване на планове като JSON формат, който след това може да се визуализира в инструменти като тези.
Все още изпълняващи се заявки
Всички изброени по-горе техники имат едно общо нещо:те произвеждат изходен резултат само след една заявка е завършила изпълнението. Те не могат да се използват за обработка на заявки, които този път са толкова бавни, че все още не са приключили с изпълнението.
Всяка връзка със сървър на PostgreSQL се обработва от бекенд , по-специално клиентски бекенд . Когато такъв бекенд изпълнява заявка, състоянието му е активно . Може също да е започнал транзакция, но след това е неактивен, наречен неактивен в транзакция състояние.
pg_stat_activity документираният тук системен изглед предоставя списък на всички работещи Postgres backends. Можете да направите заявка за този изглед, за да получите заявки, които все още се изпълняват:
SELECT client_addr, query_start, query
FROM pg_stat_activity
WHERE state IN ('active', 'idle in transaction')
AND backend_type = 'client backend';
Между другото, без да използвате разширения на трети страни, няма начин да знаете плана за изпълнение на заявка, която в момента се изпълнява от бекенд.
Ключи
Ако планът за изпълнение на бавна заявка не показва никакви очевидни проблеми, бекендът, изпълняващ заявката, може да е бил забавен поради спорни заключвания.
Заключванията се получават изрично или имплицитно по време на изпълнение на заявка по различни причини. Има цяла глава в документацията на Postgres, посветена на това.
Заключване на регистрация
Обикновено се задава горна граница за това колко време да се чака с помощта на опцията lock_timeout , обикновено от страна на клиента. Ако заявка е чакала толкова дълго, за да получи заключване, Postgres ще отмени изпълнението на тази заявка и ще регистрира грешка:
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;
Да приемем, че искате да зададете време за изчакване на заключване от 1 минута, но регистрирайте заявки, които чакат заключване повече от, да речем, 30 секунди. Можете да направите това с помощта на:
log_lock_waits = on
deadlock_timeout = 30s
Това ще създаде логове като този:
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;
Използването на deadlock_timeout не е печатна грешка:това е стойността, която използва механизмът за регистриране на изчакване на заключване. В идеалния случай трябваше да има нещо като log_min_duration_lock_wait , но за съжаление не е така.
В случай на действителни блокирания, Postgres ще прекъсне блокираните транзакции след deadlock_timeout продължителност и ще регистрира обидните изявления. Не е необходима изрична конфигурация.
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;
Откриване на текущи ключалки
Целият списък с предоставени в момента заключвания е достъпен от системния изглед pg_locks. Обикновено обаче е по-лесно да използвате функцията pg_blocking_pids , заедно с pg_stat_activity , като това:
SELECT state, pid, pg_blocking_pids(pid), query
FROM pg_stat_activity
WHERE backend_type='client backend';
който може да покаже изход като този:
state | pid | pg_blocking_pids | query
---------------------+--------+------------------+-------------------------------------------------
active | 378170 | {} | SELECT state, pid, pg_blocking_pids(pid), query+
| | | FROM pg_stat_activity +
| | | WHERE backend_type='client backend';
active | 369399 | {378068} | cluster "Track";
idle in transaction | 378068 | {} | select * from "Track" for update;
(3 rows)
което показва, че има един бекенд, който е блокиран (този, който изпълнява оператора CLUSTER) и че е блокиран от PID 378068 (който е изпълнил SELECT..FOR UPDATE, но след това е на празен ход в рамките на транзакцията).
