🥇Hvad EXPLAIN tier om, og hvordan man får det til at tale

Det klassiske spørgsmål, som en udvikler stiller sin databaseadministrator, eller en virksomhedsejer stiller en PostgreSQL-konsulent, er næsten altid det samme: "Hvorfor tager det så lang tid for forespørgsler at køre i databasen?"

Traditionelt sæt af årsager:

ineffektiv algoritme
når du beslutter dig for at TILMELDE dig flere CTE'er over et par titusindvis af poster
forældede statistikker
hvis den faktiske fordeling af data i tabellen allerede er meget forskellig fra den, der blev indsamlet af ANALYZE sidste gang
"tilslut" ressourcer
og der er ikke længere nok dedikeret CPU-computerkraft, der konstant pumpes gigabyte hukommelse, eller disken kan ikke følge med alle databasens "ønsker".
blokering fra konkurrerende processer

Og hvis blokeringer er svære nok at fange og analysere, så behøver vi kun at bruge alt andet forespørgselsplan, som kan opnås ved hjælp af EXPLAIN-operatoren (Det er selvfølgelig bedre at FORKLARE (ANALYSERE, BUFFRE) med det samme ...) eller auto_explain-modulet.

Men som anført i samme dokumentation,

"At forstå en plan er en kunst, og at mestre den kræver en vis mængde erfaring, ..."

Men du kan undvære det, hvis du bruger det rigtige værktøj!

Hvordan ser en forespørgselsplan typisk ud? Noget i retning af dette:

Index Scan using pg_class_relname_nsp_index on pg_class (actual time=0.049..0.050 rows=1 loops=1)
  Index Cond: (relname = $1)
  Filter: (oid = $0)
  Buffers: shared hit=4
  InitPlan 1 (returns $0,$1)
    ->  Limit (actual time=0.019..0.020 rows=1 loops=1)
          Buffers: shared hit=1
          ->  Seq Scan on pg_class pg_class_1 (actual time=0.015..0.015 rows=1 loops=1)
                Filter: (relkind = 'r'::"char")
                Rows Removed by Filter: 5
                Buffers: shared hit=1

eller sådan her:

"Append  (cost=868.60..878.95 rows=2 width=233) (actual time=0.024..0.144 rows=2 loops=1)"
"  Buffers: shared hit=3"
"  CTE cl"
"    ->  Seq Scan on pg_class  (cost=0.00..868.60 rows=9972 width=537) (actual time=0.016..0.042 rows=101 loops=1)"
"          Buffers: shared hit=3"
"  ->  Limit  (cost=0.00..0.10 rows=1 width=233) (actual time=0.023..0.024 rows=1 loops=1)"
"        Buffers: shared hit=1"
"        ->  CTE Scan on cl  (cost=0.00..997.20 rows=9972 width=233) (actual time=0.021..0.021 rows=1 loops=1)"
"              Buffers: shared hit=1"
"  ->  Limit  (cost=10.00..10.10 rows=1 width=233) (actual time=0.117..0.118 rows=1 loops=1)"
"        Buffers: shared hit=2"
"        ->  CTE Scan on cl cl_1  (cost=0.00..997.20 rows=9972 width=233) (actual time=0.001..0.104 rows=101 loops=1)"
"              Buffers: shared hit=2"
"Planning Time: 0.634 ms"
"Execution Time: 0.248 ms"

Men at læse en plan i tekst "fra et ark" er meget vanskeligt og ikke visuelt:

i noden vises summen af undertræsressourcer
Det vil sige, for at forstå, hvor lang tid det tog at udføre en bestemt node, eller hvor meget data præcis denne aflæsning fra tabellen har fjernet fra disken, skal du på en eller anden måde trække den ene fra den anden.
nodetid krævet gange med løkker
Ja, subtraktion er ikke den sværeste operation, der skal udføres "i hovedet" - udførelsestiden er trods alt angivet som et gennemsnit for én udførelse af en node, og der kan være hundredvis af dem.
Alt dette tilsammen forhindrer os i at besvare hovedspørgsmålet - så hvem "det svageste led"?

Da vi forsøgte at forklare alt dette til flere hundrede af vores udviklere, indså vi, at det udefra set ser nogenlunde sådan ud:

Og det betyder, at vi har brug for...

Tool

I den forsøgte vi at samle alle de nøglemekanismer, der hjælper med at forstå, i henhold til planen og anmodningen, "hvem der har skylden, og hvad man skal gøre". Nå, og dele nogle af mine erfaringer med fællesskabet.
Mød og nyd - explain.tensor.ru

Planernes synlighed

Er det nemt at forstå en plan, når den ser sådan ud?

Seq Scan on pg_class (actual time=0.009..1.304 rows=6609 loops=1)
  Buffers: shared hit=263
Planning Time: 0.108 ms
Execution Time: 1.800 ms

Не очень.

Men sådan er det jo, i forkortet form, når nøgleindikatorerne er adskilt, er det allerede meget tydeligere:

Men hvis planen er mere kompliceret, kommer der hjælp Piechart tidsfordeling efter noder:

Nå, for de sværeste muligheder kommer den til undsætning udførelsesdiagram:

For eksempel er der ret ikke-trivielle situationer, hvor en plan kan have mere end én faktuel rod:

Strukturelle signaler

Nå, hvis hele planens struktur og dens svage punkter allerede er lagt ud og synlige, hvorfor så ikke fremhæve dem for bygherren og forklare dem på "russisk"?

Vi har allerede samlet et par dusin af sådanne anbefalingsskabeloner.

Linje-for-linje forespørgselsprofiler

Hvis du nu lægger den oprindelige forespørgsel oven på den plan, der analyseres, kan du se, hvor meget tid der blev brugt på hver enkelt operator - noget i retning af dette:

... eller endda sådan her:

Indsættelse af parametre i en forespørgsel

Hvis du ikke kun har knyttet forespørgslen, men også dens parametre fra loggens DETAIL-linje til planen, kan du kopiere den yderligere i en af mulighederne:

med indsættelse af værdier i forespørgslen
til direkte implementering på din egen base og yderligere profilering
```
SELECT 'const', 'param'::text;
```
med substitution af værdier via FORBERED/UDFØR
at efterligne schedulerens arbejde, når den parametriske del kan ignoreres - for eksempel når man arbejder på partitionerede tabeller
```
DEALLOCATE ALL;
PREPARE q(text) AS SELECT 'const', $1::text;
EXECUTE q('param'::text);
```