Cómo leer la salida de EXPLAIN ANALYZE de PostgreSQL
EXPLAIN muestra lo que el planificador pretende hacer; EXPLAIN ANALYZE ejecuta la consulta y muestra lo que realmente ocurrió. Leer bien la salida es la habilidad de mayor impacto en el trabajo de rendimiento de PostgreSQL, y tiene unas cuantas trampas que atrapan incluso a desarrolladores con experiencia.
La anatomía de un nodo del plan
Cada línea de un plan es un nodo de un árbol. Las filas fluyen desde los nodos más internos (los más indentados) hacia arriba. Un nodo típico tiene este aspecto:
Index Scan using orders_customer_idx on orders
(cost=0.43..152.80 rows=42 width=98)
(actual time=0.031..0.512 rows=38 loops=1)
Dos grupos de números, y significan cosas distintas:
cost=0.43..152.80— la estimación del planificador, en unidades de coste arbitrarias (no milisegundos). El primer número es el coste de arranque antes de que se pueda producir la primera fila, el segundo es el coste total de todas las filas.rows=42(en el grupo de coste) — cuántas filas esperaba el planificador.actual time=0.031..0.512— milisegundos medidos, de nuevo arranque..total, por loop.rows=38 loops=1(en el grupo real) — filas realmente devueltas, promediadas por loop.
Trampa n.º 1: todo es por loop
Cuando un nodo está en el lado interno de un nested loop, puede ejecutarse miles de veces. PostgreSQL informa de su actual time y sus rows como un promedio por ejecución, y loops te dice cuántas ejecuciones hubo:
Index Scan using items_order_idx on items
(actual time=0.005..0.021 rows=3 loops=12000)
Este nodo no devolvió 3 filas en 0.021 ms. Devolvió aproximadamente 36.000 filas y consumió alrededor de 250 ms en total (0.021 × 12.000). Multiplica siempre por loops antes de decidir si un nodo es barato.
Trampa n.º 2: los tiempos son acumulativos
El actual time de un nodo incluye el de todos sus hijos. Si un Sort informa de 900 ms y el Seq Scan que tiene debajo informa de 850 ms, el sort en sí solo costó ~50 ms. Para averiguar dónde se gasta realmente el tiempo, necesitas el tiempo exclusivo de cada nodo: su total menos los totales de sus hijos. Esta es exactamente la aritmética que se vuelve tediosa en un plan de 40 nodos, y la razón principal por la que existen los visualizadores de planes.
Trampa n.º 3: filas estimadas frente a reales
El diagnóstico más valioso de toda la salida es la diferencia entre las filas estimadas y las reales. El plan se eligió en función de la estimación: si el planificador esperaba 40 filas y obtuvo 400.000, todas las decisiones aguas abajo de ese nodo (estrategia de join, dimensionamiento de memoria, index scan frente a sequential scan) se tomaron sobre supuestos equivocados.
Cuando veas una discrepancia grande:
- Ejecuta
ANALYZEsobre las tablas implicadas: puede que las estadísticas simplemente estén desactualizadas. - Si la mala estimación persiste en una columna concreta, aumenta el detalle de su muestreo:
ALTER TABLE t ALTER COLUMN c SET STATISTICS 1000; ANALYZE t; - Si la condición combina columnas correlacionadas (ciudad + código postal, categoría + marca), el planificador multiplica sus selectividades como si fueran independientes.
CREATE STATISTICScon el tipodependenciesexiste precisamente para este caso.
Usa BUFFERS. Siempre.
EXPLAIN (ANALYZE, BUFFERS) añade una línea como:
Buffers: shared hit=1520 read=8943 dirtied=12
hit— bloques de 8 KB encontrados en la caché de shared buffers de PostgreSQL.read— bloques que hubo que traer desde fuera de los shared buffers (caché del SO o disco).dirtied/written— bloques modificados o expulsados mientras se ejecutaba la consulta.
Los recuentos de buffers explican la diferencia entre "rápido en mi sesión, lento en producción": el mismo plan es órdenes de magnitud más lento cuando sus bloques no están en caché. También hacen visible el bloat: una consulta que lee 50.000 bloques para devolver 100 filas estrechas está leyendo en su mayoría espacio muerto o escaneando mucho más de lo que debería.
Otra salida que conviene conocer
Rows Removed by Filter— filas obtenidas y luego descartadas. Un número grande significa que la ruta de acceso no es selectiva: un índice (o un índice mejor) podría evitar la mayoría de esas lecturas.Sort Method: external merge Disk: 210400kB— el sort no cupo enwork_memy se derramó a disco. Lo mismo ocurre con los hash joins que informan deBatches: 4(más de un batch = derrame).(never executed)— el nodo nunca se ejecutó (por ejemplo, el otro lado del join produjo cero filas). Sus números no significan nada; no lo optimices.loopscon workers paralelos — un nodo paralelo muestra un loop por worker; los números por loop son promedios por worker.
Una checklist de lectura
- Busca el
Execution Timetotal al final: ese es tu presupuesto. - Recorre el árbol buscando nodos cuyo tiempo exclusivo (total menos hijos, por loops) sea una parte grande de él. Normalmente dominan 1–3 nodos.
- Para cada nodo caliente, compara las filas estimadas frente a las reales. Una diferencia de 10× es un problema del planificador antes que un problema de hardware.
- Revisa
BUFFERS: ¿está leyendo mucho más datos de los que justifica el resultado? - Solo entonces piensa en soluciones: estadísticas, índices, forma de la consulta,
work_mem, más o menos en ese orden de probabilidad.
