Sobre qué guarda silencio EXPLAIN y cómo lograr que hable

La clásica pregunta que un desarrollador le hace a su DBA o que el propietario de un negocio le hace a un consultor de PostgreSQL casi siempre suena igual: "¿Por qué las solicitudes tardan tanto en completarse en la base de datos?"

Conjunto tradicional de razones:

• algoritmo ineficiente
  cuando decide UNIR varios CTE en un par de decenas de miles de registros
• estadísticas irrelevantes
  si la distribución real de los datos en la tabla ya es muy diferente de la que recopiló ANALYZE la última vez
• "conectar" los recursos
  y ya no hay suficiente potencia informática dedicada de la CPU, se bombean constantemente gigabytes de memoria o el disco no puede satisfacer todos los "deseos" de la base de datos
• bloqueo de procesos competitivos

Y si los bloqueos son bastante difíciles de detectar y analizar, entonces para todo lo demás necesitamos plan de consulta, que se puede obtener utilizando EXPLICAR operador (Es mejor, por supuesto, EXPLICAR (ANALIZAR, BUFFERS) inmediatamente ...) O módulo auto_explain.

Pero, como se indica en la misma documentación,

"Comprender un plan es un arte, y dominarlo requiere cierta experiencia..."

¡Pero puedes prescindir de él si utilizas la herramienta adecuada!

¿Cómo suele ser un plan de consulta? Algo como eso:

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 así:

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

Pero leer el plan en el texto "de la hoja" es muy difícil y poco claro:

• se muestra en el nodo suma por recursos del subárbol
  es decir, para comprender cuánto tiempo tomó ejecutar un nodo en particular, o cuánto exactamente esta lectura de la tabla generó datos del disco, es necesario restar de alguna manera uno del otro.
• se necesita tiempo de nodo multiplicar por bucles
  sí, la resta no es la operación más compleja que debe realizarse "en la cabeza"; después de todo, el tiempo de ejecución se indica como el promedio para una ejecución de un nodo, y puede haber cientos de ellos.
• bueno, y todo esto en conjunto nos impide responder la pregunta principal: entonces, ¿quién "el eslabón más débil"?

Cuando intentamos explicar todo esto a varios cientos de nuestros desarrolladores, nos dimos cuenta de que desde fuera se veía así:

Y eso significa que necesitamos...

Herramienta

En él intentamos recopilar todas las mecánicas clave que ayudan a comprender “quién tiene la culpa y qué hacer” según el plan y la solicitud. Bueno, y comparte parte de tu experiencia con la comunidad.
Conoce y usa - Explique.tensor.ru

Visibilidad de los planes.

¿Es fácil entender el plan cuando se ve así?

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

En realidad no

Pero así, en forma abreviadacuando se separan los indicadores clave, queda mucho más claro:

Pero si el plan es más complicado, él vendrá al rescate. distribución del tiempo en gráfico circular por nodos:

Bueno, para las opciones más difíciles tiene prisa por ayudar. tabla de progreso:

Por ejemplo, hay situaciones bastante no triviales en las que un plan puede tener más de una raíz real:

Pistas estructurales

Bueno, si toda la estructura del plan y sus puntos delicados ya están expuestos y son visibles, ¿por qué no resaltarlos ante el desarrollador y explicárselos en “idioma ruso”?

Ya hemos recopilado un par de docenas de plantillas de recomendaciones de este tipo.

Perfilador de consultas línea por línea

Ahora, si superpone la consulta original al plan analizado, podrá ver cuánto tiempo se dedicó a cada declaración individual, algo como esto:

...o incluso así:

Sustituir parámetros en una solicitud

Si "adjuntó" no solo una solicitud al plan, sino también sus parámetros desde la línea DETALLE del registro, también puede copiarla en una de las opciones:

• con sustitución de valor en la solicitud
  para ejecución directa en su base y elaboración de perfiles adicionales

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

• con sustitución de valor mediante PREPARE/EXECUTE
  para emular el trabajo del planificador, cuando la parte paramétrica se puede ignorar, por ejemplo, cuando se trabaja en tablas particionadas

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

Archivo de planos

¡Pegue, analice, comparta con colegas! Los planos permanecerán archivados y podrás volver a ellos más tarde: explicar.tensor.ru/archive

Pero si no desea que otros vean su plan, no olvide marcar la casilla "no publicar en el archivo".

En los siguientes artículos hablaré de las dificultades y decisiones que surgen al analizar un plan.

Fuente: habr.com