¿Cómo se lee un plan de ejecución de consultas (EXPLAIN/EXPLAIN ANALYZE) para encontrar el cuello de botella real?

#EXPLAIN te dice el plan; EXPLAIN ANALYZE te dice la verdad

EXPLAIN le pregunta al planificador de consultas qué piensa hacer y te muestra sus estimaciones de costo, sin ejecutar nada. EXPLAIN ANALYZE ejecuta la consulta de verdad —incluyendo cualquier efecto secundario si es una sentencia que modifica datos— y agrega tiempos y conteos de filas reales junto a las estimaciones. La brecha entre esos dos números, lo estimado contra lo real, suele ser lo más útil de toda la página: cuando coinciden, el planificador tenía buena información; cuando no, el planificador tomó una decisión basada en una suposición que resultó equivocada, y todo lo que está por encima de ese nodo heredó el error.

#Leer la forma del plan

Un plan es un árbol de nodos representado como texto con sangría. El orden de ejecución es de abajo hacia arriba y de adentro hacia afuera: los nodos con más sangría se ejecutan primero, y su salida alimenta al nodo justo encima, hasta llegar al nodo raíz en la parte superior, que es lo que el cliente realmente recibe. Cada línea de nodo trae la misma forma:

TipoDeNodo  (cost=inicio..total rows=N width=W) (actual time=inicio..total rows=N loops=L)

• cost=inicio..total — el costo estimado del planificador en unidades arbitrarias (aproximadamente, lecturas de página), no milisegundos. inicio es el costo antes de que el nodo pueda producir su primera fila; total es el costo de producirlas todas.
• rows=N (en el paréntesis de costo) — el conteo estimado de filas que sale de ese nodo.
• actual time=inicio..total — milisegundos reales, presente solo con ANALYZE.
• rows=N (en el paréntesis de "actual") — el conteo real de filas, por ejecución.
• loops=L — cuántas veces se ejecutó este nodo. Un nodo anidado dentro de un Nested Loop puede correr una vez por cada fila del lado externo: su tiempo y filas reales son por ejecución (loop), así que su contribución total real es actual time * loops, no el número impreso.

#La checklist para encontrar el cuello de botella real

1. Compara filas estimadas contra reales en cada nodo, no solo en el de arriba. Una brecha grande (un orden de magnitud o más) significa que las estadísticas del planificador están desactualizadas o que el predicado es difícil de estimar (columnas correlacionadas, una función aplicada a una columna); esto suele ser la causa raíz de un mal plan más arriba, porque una estimación de filas equivocada lleva al planificador a elegir el algoritmo de join incorrecto.
2. Busca Seq Scan sobre una tabla grande con un Rows Removed by Filter grande. Eso es un escaneo completo que descarta casi todo lo que leyó: un fuerte candidato para un índice faltante sobre la columna filtrada.
3. Vigila los conteos de loops en el lado interno de un Nested Loop. Un nested loop está bien cuando el lado externo devuelve pocas filas y el lado interno es una búsqueda puntual indexada; es un problema cuando el lado interno es en sí mismo un escaneo que ahora corre una vez por cada fila externa.
4. Revisa los nodos Sort en busca de Sort Method: external merge Disk:. Eso significa que el ordenamiento no cupo en work_mem y se derramó a disco: a menudo se arregla subiendo work_mem para la sesión/consulta o reduciendo el número de filas antes en el plan.
5. Corre EXPLAIN (ANALYZE, BUFFERS) para ver shared hit (servido desde caché) contra shared read (I/O físico). Un nodo dominado por lecturas de disco es un problema de I/O —más memoria o un conjunto de trabajo más chico ayuda—; un nodo dominado por hits pero igual lento es un problema de CPU/algoritmo, ahí es donde importa más el tipo de join o las llamadas a funciones.
6. Compara el Planning Time con el Execution Time. Si el tiempo de planificación es sorprendentemente grande en relación a una ejecución rápida, el problema puede ser demasiadas particiones, demasiados índices para considerar, o estadísticas del planificador costosas de calcular; no el plan de ejecución en sí.

#Un ejemplo trabajado

EXPLAIN ANALYZE
SELECT o.id, o.total_cents, o.created_at
FROM orders o
JOIN customers c ON c.id = o.customer_id
WHERE c.email = 'jane.doe@example.com'
ORDER BY o.created_at DESC
LIMIT 20;

Antes de un índice sobre customers.email:

Ajustar líneas largas
Limit  (cost=18453.21..18453.26 rows=20 width=24) (actual time=142.318..142.324 rows=3 loops=1)
  ->  Sort  (cost=18453.21..18455.71 rows=1000 width=24) (actual time=142.316..142.318 rows=3 loops=1)
        Sort Key: o.created_at DESC
        Sort Method: quicksort  Memory: 25kB
        ->  Nested Loop  (cost=0.43..18429.85 rows=1000 width=24) (actual time=45.201..142.291 rows=3 loops=1)
              ->  Seq Scan on customers c  (cost=0.00..8459.00 rows=1 width=8) (actual time=45.180..142.240 rows=1 loops=1)
                    Filter: (email = 'jane.doe@example.com'::text)
                    Rows Removed by Filter: 499999
              ->  Index Scan using idx_orders_customer_id on orders o  (cost=0.43..9950.00 rows=1000 width=24) (actual time=0.020..0.038 rows=3 loops=1)
                    Index Cond: (customer_id = c.id)
Planning Time: 0.412 ms
Execution Time: 142.401 ms

Leyendo de abajo hacia arriba: el Seq Scan on customers es todo el problema. Se estimó que devolvería 1 fila, encontró 1 fila (la estimación acertó en este caso), pero tuvo que leer y descartar 499.999 filas para encontrarla —eso es Rows Removed by Filter: 499999— y por sí solo representa 142.24 de los 142.4 milisegundos totales de la consulta. El Index Scan sobre orders debajo del nested loop está bien (0.038ms): ya está usando idx_orders_customer_id. El arreglo es un índice faltante, no una reescritura del join.

Después de agregar CREATE INDEX idx_customers_email ON customers(email);:

Ajustar líneas largas
Limit  (cost=8.60..8.65 rows=20 width=24) (actual time=0.045..0.048 rows=3 loops=1)
  ->  Sort  (cost=8.60..8.61 rows=3 width=24) (actual time=0.044..0.045 rows=3 loops=1)
        Sort Key: o.created_at DESC
        Sort Method: quicksort  Memory: 25kB
        ->  Nested Loop  (cost=0.86..8.58 rows=3 width=24) (actual time=0.030..0.038 rows=3 loops=1)
              ->  Index Scan using idx_customers_email on customers c  (cost=0.43..4.45 rows=1 width=8) (actual time=0.015..0.016 rows=1 loops=1)
                    Index Cond: (email = 'jane.doe@example.com'::text)
              ->  Index Scan using idx_orders_customer_id on orders o  (cost=0.43..4.10 rows=3 width=24) (actual time=0.010..0.018 rows=3 loops=1)
                    Index Cond: (customer_id = c.id)
Planning Time: 0.198 ms
Execution Time: 0.089 ms

Misma consulta, mismo join, mismo resultado — 142ms se convirtieron en 0.089ms porque el único nodo que hacía un escaneo completo ahora hace una búsqueda por índice. Nada más en el plan tuvo que cambiar; el planificador eligió la misma estrategia de join las dos veces, simplemente ahora tiene una forma barata de alimentarla una vez que existe el índice.

#Una nota sobre portabilidad

Este recorrido usa el formato de EXPLAIN ANALYZE de PostgreSQL? porque es el más detallado y el que más se pregunta en entrevistas, pero la estrategia de lectura se traslada: el EXPLAIN ANALYZE de MySQL (8.0.18+) imprime un árbol de costo/real parecido; el EXPLAIN más antiguo de MySQL (sin ANALYZE) solo da estimaciones y una columna rows/Extra, donde Using filesort y Using temporary son más o menos el equivalente de "ordenamiento externo" y una mala estimación de filas, respectivamente. La sintaxis específica cambia; "encuentra el nodo donde la estimación y la realidad no coinciden, o donde un escaneo lee mucho más de lo que devuelve" no cambia.

🧠 Check your understanding
0/2 · 0/2 answered
1. En un plan de EXPLAIN ANALYZE, un nodo muestra `actual time=2.500..2.510 rows=50 loops=800`. ¿Cuál es la contribución real total de ese nodo al tiempo de ejecución de la consulta?
2.51 ms, porque ese es el actual time mostrado50 ms, porque devolvió 50 filasAlrededor de 2.008 ms, porque actual time es por ejecución (loop) y hay que multiplicarlo por el número de loops800 ms, porque loops representa milisegundos directamente
2. Un plan muestra `Seq Scan on events (cost=0.00..95000.00 rows=1200 width=40) (actual time=0.015..980.221 rows=3 loops=1)` con `Filter: (event_type = 'checkout')` y `Rows Removed by Filter: 4998000`. ¿Qué sugiere esto con más fuerza?
Que la consulta debería reescribirse para evitar usar una cláusula WHEREQue se está leyendo y descartando una fracción enorme de la tabla para encontrar muy pocas filas coincidentes: un fuerte candidato para un índice sobre event_typeQue la estimación del planificador (1200) está razonablemente cerca de la realidad (3), así que no hace falta acción algunaQue la tabla necesita replicarse a otra región