Di cosa SPIEGARE tace e come farlo parlare

La classica domanda che uno sviluppatore pone al suo DBA o un imprenditore rivolge a un consulente PostgreSQL sembra quasi sempre la stessa: "Perché le richieste impiegano così tanto tempo per essere completate nel database?"

Motivi tradizionali:

• algoritmo inefficiente
  quando decidi di UNIRSI a più CTE su un paio di decine di migliaia di record
• statistiche obsolete
  se la distribuzione effettiva dei dati nella tabella è già molto diversa da quella raccolta da ANALYZE l'ultima volta
• "plug" sulle risorse
  e non c'è più abbastanza potenza di calcolo dedicata della CPU, i gigabyte di memoria vengono costantemente pompati o il disco non riesce a tenere il passo con tutti i "desideri" del database
• blocco da processi concorrenti

E se i blocchi sono piuttosto difficili da individuare e analizzare, allora abbiamo bisogno di tutto il resto piano di interrogazione, che può essere ottenuto utilizzando operatore SPIEGARE (È meglio, ovviamente, SPIEGARE immediatamente (ANALIZZARE, BUFFER) ...) o modulo auto_explain.

Ma, come affermato nella stessa documentazione,

“Comprendere un progetto è un’arte, e per padroneggiarlo richiede una certa esperienza...”

Ma puoi farne a meno se usi lo strumento giusto!

Che aspetto ha in genere un piano di query? Qualcosa del genere:

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

o in questo modo:

"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"

Ma leggere il piano nel testo “dal foglio” è molto difficile e poco chiaro:

• viene visualizzato nel nodo somma per risorse del sottoalbero
  cioè, per capire quanto tempo è stato necessario per eseguire un particolare nodo, o quanto esattamente questa lettura dalla tabella ha portato i dati dal disco, è necessario in qualche modo sottrarre l'uno dall'altro
• è necessario il tempo del nodo moltiplicare per loop
  sì, la sottrazione non è l'operazione più complessa che deve essere eseguita "in testa" - dopotutto, il tempo di esecuzione è indicato come medio per un'esecuzione di un nodo e possono essercene centinaia
• bene, e tutto questo insieme ci impedisce di rispondere alla domanda principale: allora chi "l'anello più debole"?

Quando abbiamo provato a spiegare tutto questo a diverse centinaia di nostri sviluppatori, ci siamo resi conto che dall'esterno assomigliava a questo:

E questo significa che abbiamo bisogno...

Strumento

In esso abbiamo cercato di raccogliere tutte le meccaniche chiave che aiutano a capire “chi è la colpa e cosa fare” in base al piano e alla richiesta. Bene, e condividi parte della tua esperienza con la community.
Incontra e usa - spiegare.tensore.ru

Visibilità dei piani

È facile capire il piano quando si presenta così?

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

Non proprio.

Ma così, in forma abbreviataquando gli indicatori chiave sono separati, è molto più chiaro:

Ma se il piano è più complicato, verrà in soccorso distribuzione temporale del grafico a torta per nodi:

Bene, per le opzioni più difficili ha fretta di aiutare grafico dei progressi:

Ad esempio, ci sono situazioni non banali in cui un piano può avere più di una radice effettiva:

Indizi strutturali

Ebbene, se l'intera struttura del piano e i suoi punti dolenti sono già strutturati e visibili, perché non evidenziarli allo sviluppatore e spiegarli in “lingua russa”?

Abbiamo già raccolto un paio di dozzine di modelli di raccomandazioni di questo tipo.

Profiler di query riga per riga

Ora, se sovrapponi la query originale al piano analizzato, puoi vedere quanto tempo è stato dedicato a ogni singola affermazione, qualcosa del genere:

...o anche così:

Sostituzione dei parametri in una richiesta

Se hai "allegato" non solo una richiesta al piano, ma anche i suoi parametri dalla riga DETTAGLI del registro, puoi inoltre copiarla in una delle opzioni:

• con sostituzione di valore nella query
  per l'esecuzione diretta su Vostra base e ulteriore profilazione

  SELECT 'const', 'param'::text;

• con sostituzione del valore tramite PREPARE/EXECUTE
  per emulare il lavoro dello scheduler, quando la parte parametrica può essere ignorata, ad esempio quando si lavora su tabelle partizionate

  DEALLOCATE ALL;
  PREPARE q(text) AS SELECT 'const', $1::text;
  EXECUTE q('param'::text);
  

Archivio dei progetti

Incolla, analizza, condividi con i colleghi! I piani rimarranno archiviati e potrai recuperarli in seguito: spiegare.tensor.ru/archive

Ma se non vuoi che gli altri vedano il tuo piano, non dimenticare di selezionare la casella “non pubblicare nell’archivio”.

Nei seguenti articoli parlerò delle difficoltà e delle decisioni che sorgono quando si analizza un piano.

Fonte: habr.com