Docela často se bavím s vývojáři, kteří používají Postgres (nicméně předpokládám, že situace bude podobná i u jiných databází), a všímám si, že stále nemají dobře vyřešený monitoring. Že jen reaktivně (nikoliv proaktivně) řeší výkon aplikací. Že ne vždy mají potřebnou zpětnou vazbu z produkce.
U trochu větších firem nemá vývojář co dělat na produkčních systémech. Ale životně nezbytně potřebuje zpětnou vazbu ohledně výkonu, zátěže a to z produkčních systémů. Žádný vývojář, zvlášť databázových aplikací, by neměl být bez informací o chování, o zátěži aplikací v produkčním prostředí.
Databáze jako úzké hrdlo
U větších než malých dat, u větší než malé zátěže je databáze přirozeným úzkým hrdlem výkonu aplikace. Musí to tak být – databáze pracuje s IO subsystémem, musí čekat až se data skutečně zapíší na disky, musí čekat na přečtení dat z disku. Snem mnoha vývojářů (a jejich nadřízených) je, pokud možno databázi neřešit. Mít subsystém, který zajistí dobrý výkon jak s malými daty, tak s miliardami záznamů. Nic takového neexistuje, a nemůže existovat (je rozdíl jestli pracuji s daty, které se mi dobře vejdou do paměti, nebo naopak nevejdou).
Nemůžete použít stejné materiály a stejnou konstrukci pro Čmeláka a pro Airbus. Při větších objemech dat, při větší intenzitě provozu je nutné rozumět databázím (ať už se použije Postgres, MySQL nebo Mongo). Jinak se vymýšlí a řeší hrozné blbosti, na kterých se pálí neskutečně času, a které pak vedou k problémům, které nejsou řešitelné (nebo řešitelné jsou, ale jen obtížně). Některé ty šílené koncepty mohou mít svůj prapůvod v licenční politice Oracle, s BSD licencí Postgresu lze navrhovat databázové systémy logicky (a prakticky).
Základem musí být kvalitní dlouhodobý monitoring databázového serveru – tj minimálně vizualizace zátěže CPU a IO. Nicméně neuškodí monitorovat i další metriky – iops, troughput, swap, tps, počet aktivních/neaktivních spojení, počet connectů/disconnectů za sec, … Bez kvalitního monitoringu jsou vývojáři slepí a dost často hledají performance problémy, tam kde nejsou. Nástrojů pro monitoring je celá řada (Zabbix, Munin, PgWatch2, …).
Další krok je monitorování pomalých dotazů. I v Postgresu platí Paretovo pravidlo. Totiž že 20 % dotazů vygeneruje 80 % zátěže, a o těchto 20 % dotazů by měl vývojář databázové aplikace vědět. Pokud jsou dotazy volané z uložených procedur, tak je pak potřeba profilovat uložené procedury, abych mohl získat tuto informaci. Jeden neoptimalizovaný dotaz na kritické cestě může působit opravdu vážné provozní problémy.
Místo správné detekce problémů vývojáři začnou řešit aplikační cache, přepis logiky, lepší škálování, zvýšení výkonu hw, … Většinou se jedná o dost práce. Přidání indexu, oprava dotazu je záležitost pěti minut. Nemám nic proti aplikační cache, nemám nic proti aplikacím, které mohou dobře horizontálně škálovat. Je dobré se napřed přesvědčit, jestli se nejedná o nějaký banální problém na úrovni databáze, který je možné opravit rychle bez zvyšování komplexity aplikace.
Postgres nabízí několik jednoduše uchopitelných nástrojů pro detekci potenciálně problémových dotazů nebo funkcí.
Pomalé dotazy
Nejjednodušším nástrojem je logování pomalých dotazů. V konfiguraci Postgresu nastavím limit – log_min_duration_statement. Dotazy, které trvají déle než tento limit se zapíší do logu Postgresu. Následně pomocí PgFouine nebo PgBadgeru log zpracuji a v reportu vidím přehledně nejčastější dotazy, nejpomalejší dotazy, případně dotazy, které spotřebovávají nejvíce strojového času.
Když jsem začínal s výkonnostními audity Postgresu, tak report vygenerovaný PgFouine byl pro mne absolutní základ, a většinou jsem nepotřeboval nic dalšího. Většina problémů je způsobena opomenutím, přehlédnutím, a opraví se snadno, pokud se je podaří zacílit. Většina, nikoliv všechny. Chyby v návrhu databáze, chyby v normalizaci opravitelné nejsou (bez radikální revize). Nicméně i o nich je dobré vědět – je dobré vědět, jak věci příště nedělat.
Doplňkem k logování pomalých dotazů je logování prováděcích plánů pomalých dotazů pomocí extenze auto_explain. Ze zalogovaného prováděcího plánu lze vyčíst důvod problémů, navíc je to určitý záznam historie – jinak vlastně zpětná analýza výkonnostních problémů v Postgresu není podporována. auto_explain lze použít i pro logování pomalých dotazů volaných z procedur a funkcí (nastavením log_nested_statements na on).
Problém nemusí způsobovat jen pomalé dotazy, ale i často volané funkce (např. triggery). Zde nám může pomoct EXPLAIN ANALYZE, který zobrazí režii triggerů a počet jejich volání
CREATE TABLE ff(a int); CREATE OR REPLACE FUNCTION public.slow_func(i integer) RETURNS integer LANGUAGE plpgsql AS $function$ BEGIN PERFORM pg_sleep(0.001); RETURN i; END; $function$ CREATE OR REPLACE FUNCTION public.trg_func() RETURNS TRIGGER LANGUAGE plpgsql AS $function$ BEGIN new.a := slow_func(new.a); RETURN new; END; $function$ CREATE TRIGGER trg BEFORE INSERT OR UPDATE ON ff FOR EACH ROW EXECUTE FUNCTION trg_func(); postgres=> EXPLAIN ANALYZE INSERT INTO ff SELECT * FROM generate_series(1,1000); ┌───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐ │ QUERY PLAN │ ╞═══════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════╡ │ Insert on ff (cost=0.00..10.00 rows=1000 width=4) (actual time=2104.062..2104.062 rows=0 loops=1) │ │ -> Function Scan on generate_series (cost=0.00..10.00 rows=1000 width=4) (actual time=0.313..2.851 rows=1000 loops=1) │ │ Planning Time: 0.118 ms │ │ Trigger trg: time=2067.810 calls=1000 │ │ Execution Time: 2104.200 ms │ └───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘ (5 rows)
Setkal jsem se s jedním problémovým dotazem v PostGISu. Trval několik minut, a během té doby naplno utilizoval CPU. PostGISu vůbec nerozumím, a stejně tak návrhu dotazů nad geo daty. Umím ale zapnout trasování externích funkcí v Postgresu.
SET track_functions to 'all';
Po opakovaném provedení dotazu se v pohledu pg_stat_user_functions ukázalo, že problémové bylo volání jedné PostGIS funkce, která byla během několika minut zavolána cca 40000krát. Pak již autoři dotazu začali tušit, v čem je problém a i uvažovat o nějakém workaroundu. Bez této informace uvažovali o více serverovém clusteru, cloudu, o signifikantním povýšení hardware a o dalších relativně drahých a ne zrovna jednoduchých řešeních.
Apriori nemám nic proti komplikovaným a drahým řešením, ale měl by být pro to jiný důvod než neznalost profilace a základních technik optimalizace. U těchto zákazníků jsem to akceptoval, protože byli experti na úplně jinou oblast než bylo IT. Smutné bylo, že jejich dodavatelé IT technologií jim žádné rozumné řešení nenabídli (to už mi bylo trochu stydno). I IT je řemeslo a mělo by mít nějakou úroveň.
Použití track_functions je jednoduché.
CREATE OR REPLACE FUNCTION public.fast_func(i integer)
RETURNS integer
LANGUAGE plpgsql
AS $function$
BEGIN
RETURN i;
END;
$function$
CREATE OR REPLACE FUNCTION public.test_func(i integer)
RETURNS integer
LANGUAGE plpgsql
AS $function$
DECLARE r int DEFAULT 0;
BEGIN
FOR i IN 1..i
LOOP
r := r + fast_func(i);
END LOOP;
FOR i IN 1..i
LOOP
r := r + slow_func(i);
END LOOP;
RETURN r;
END;
$function$
postgres=> SELECT test_func(1000);
┌───────────┐
│ test_func │
╞═══════════╡
│ 1001000 │
└───────────┘
(1 row)
postgres=> SELECT * FROM pg_stat_user_functions ;
┌────────┬────────────┬───────────┬───────┬────────────┬───────────┐
│ funcid │ schemaname │ funcname │ calls │ total_time │ self_time │
╞════════╪════════════╪═══════════╪═══════╪════════════╪═══════════╡
│ 16413 │ public │ fast_func │ 1000 │ 2.57 │ 2.57 │
│ 16414 │ public │ slow_func │ 1000 │ 2021.531 │ 2021.531 │
│ 16417 │ public │ test_func │ 1 │ 2042.871 │ 18.769 │
└────────┴────────────┴───────────┴───────┴────────────┴───────────┘
(3 rows)
Použití je velice jednoduché a pro vytvoření si představy, v čem a kde může být problém, to může stačit. Navíc nic nemusíte instalovat do Postgresu. Co může být problém, je nutnost mít práva superusera.
Detailní profil
Pro získání detailního profilu funkce můžeme použít extenze plProfiler nebo plpgsql_check. Prapředka extenze plpgsql_check jsem napsal cca před 10 roky, kdy jsem potřeboval statickou analýzu vložených SQL dotazů. Postupem času jsem do této extenze přidával další kontroly – nepoužívané parametry, nepoužívané proměnné, detekce mrtvého kódu, a předloni jsem integroval jednoduchý profiler. S Postgresem 12 a novější by režie profilace měla být minimální. Použití je opět jednoduché:
CREATE EXTENSION plpgsql_check; -- jednorázově
LOAD 'plpgsql_check'; -- po startu session
SET plpgsql_check.profiler TO on;
postgres=> SELECT test_func(1000);
┌───────────┐
│ test_func │
╞═══════════╡
│ 1001000 │
└───────────┘
(1 row)
postgres=> SELECT * FROM plpgsql_profiler_function_tb('test_func');
┌────────┬─────────────┬─────────────┬────────────┬────────────┬──────────┬──────────┬────────────────┬────────────────────────────┐
│ lineno │ stmt_lineno │ cmds_on_row │ exec_stmts │ total_time │ avg_time │ max_time │ processed_rows │ source │
╞════════╪═════════════╪═════════════╪════════════╪════════════╪══════════╪══════════╪════════════════╪════════════════════════════╡
│ 1 │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ DECLARE r int DEFAULT 0; │
│ 2 │ 2 │ 1 │ 1 │ 0.017 │ 0.017 │ {0.017} │ {0} │ BEGIN │
│ 3 │ 3 │ 1 │ 1 │ 0.355 │ 0.355 │ {0.355} │ {0} │ FOR i IN 1..i │
│ 4 │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ LOOP │
│ 5 │ 5 │ 1 │ 1000 │ 7.185 │ 0.008 │ {0.038} │ {0} │ r := r + fast_func(i); │
│ 6 │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ END LOOP; │
│ 7 │ 7 │ 1 │ 1 │ 0.798 │ 0.798 │ {0.798} │ {0} │ FOR i IN 1..i │
│ 8 │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ LOOP │
│ 9 │ 9 │ 1 │ 1000 │ 2063.58 │ 2.064 │ {2.662} │ {0} │ r := r + slow_func(i); │
│ 10 │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ END LOOP; │
│ 11 │ 11 │ 1 │ 1 │ 0 │ 0 │ {0} │ {0} │ RETURN r; │
│ 12 │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ ∅ │ END; │
└────────┴─────────────┴─────────────┴────────────┴────────────┴──────────┴──────────┴────────────────┴────────────────────────────┘
(12 rows)
plProfiler se skládá ze dvou částí – extenze do Postgresu (v C) a vizualizace do html (v Pythonu). Při zavolání z command line se spustí testovaná funkce, vytvoří profil a vygeneruje html report. Tento profiler je založený na vytvoření grafu volání.
Při překladu je nutné používat starší formu překladu extenzí:
make USE_PGXS=1 make USE_PGXS=1 install # pod rootem plprofiler run --command "select test_func(100)" --output test_func.html -h localhost
Další následnou otázkou je důvod, proč nějaký dotaz je pomalý. Mezi ty nejčastější důvody v Postgresu patří:
- chybějící indexy
- neaktuální sloupcové statistiky
- nafouklé tabulky nebo indexy
To, že chybí indexy nebo že nám nesedí statistiky snadno vyčteme z prováděcích plánů. Je hrozně důležité umět číst prováděcí plány dotazů. Bez nich se jakákoliv SQL databáze používá více-méně na amatérské úrovni. Naučit se číst prováděcí plány je záležitost hodiny nebo dvou (spíše méně). Detekci nafouklých (bloated) tabulek můžeme udělat několika způsoby.
Nejjednodušší – někde na jiném stroji obnovíme databázi z logické zálohy a porovnáme velikost. Pokud je obnovená databáze významně menší (desítky procent), tak můžeme mít problém s neoptimálním formátem tabulek nebo indexů. Také není na škodu nad databází pustit před jakoukoliv analýzou VACUUM ANALYZE.
postgres=> EXPLAIN ANALYZE SELECT * FROM obce WHERE okres_id = okres_code('Beroun');
┌──────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ QUERY PLAN │
╞══════════════════════════════════════════════════════════════════════════════════════════════════════╡
│ Seq Scan on obce (cost=0.00..1699.62 rows=85 width=41) (actual time=4.682..315.778 rows=85 loops=1) │
│ Filter: ((okres_id)::text = (okres_code('Beroun'::character varying))::text) │
│ Rows Removed by Filter: 6165 │
│ Planning Time: 2.900 ms │
│ Execution Time: 315.808 ms │
└──────────────────────────────────────────────────────────────────────────────────────────────────────┘
(5 rows)
postgres=> CREATE INDEX ON obce(okres_id);
postgres=> EXPLAIN ANALYZE SELECT * FROM obce WHERE okres_id = okres_code('Beroun');
┌────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ QUERY PLAN │
╞════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════╡
│ Index Scan using obce_okres_id_idx on obce (cost=0.53..12.79 rows=85 width=41) (actual time=0.289..0.357 rows=85 loops=1) │
│ Index Cond: ((okres_id)::text = (okres_code('Beroun'::character varying))::text) │
│ Planning Time: 1.043 ms │
│ Execution Time: 0.441 ms │
└────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘
(4 rows)
Znalosti databází, databázových systémů jsou, bohužel, dost často nedostatečné. Je to samozřejmě vidět i na aplikacích. Musí se pak řešit hromada zbytečných problémů, dělá se zbytečná práce.
ČLÁNKY DO MAILU