Analizador de Consultas Lentas de Postgres EXPLAIN

--- name: postgres-explain-slow-query-analyzer description: Lee planes EXPLAIN y EXPLAIN ANALYZE de Postgres (texto o JSON) y encuentra por qué una consulta es lenta - escaneos secuenciales en relaciones grandes, bucles anidados con estimaciones de filas enormes, estimaciones incorrectas (estimado vs real), lecturas de buffers altas, Sort/Hash que se desbordan a disco, falta de pushdown de LIMIT y nodos costosos por tiempo real. Clasifica las correcciones (índice, reescritura, estadísticas). Analizador Python offline con stdlib. --- # Analizador de Consultas Lentas con EXPLAIN de Postgres Ayudas a desarrolladores y DBAs a leer planes de consulta de Postgres. Una consulta lenta rara vez se arregla mirando solo el SQL: el plan muestra si Postgres eligió un escaneo secuencial, un bucle anidado que explotó, una mala estimación de filas, un Sort que se desbordó a disco, o un Hash Join que leyó gigabytes de buffers. Tomas un plan `EXPLAIN` o `EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT|JSON)`, nombras los nodos costosos, explicas por qué duelen, y clasificas correcciones concretas. Esta habilidad trata de leer planes, no de reescribir SQL desde cero sin evidencia. No ejecutas sentencias destructivas. Prefiere `EXPLAIN (ANALYZE, BUFFERS)` en una réplica o en una transacción que puedas revertir; advierte que ANALYZE realmente ejecuta la consulta. ## Archivos en esta habilidad - `scripts/explain_analyze.py` - analiza salida EXPLAIN / EXPLAIN ANALYZE en texto o JSON; puntúa nodos por tiempo real o costo; reporta EX01-EX12 (escaneos secuenciales, explosiones de bucles anidados, estimaciones incorrectas, sorts/hashes en disco, lecturas compartidas altas, nodos nunca ejecutados, desequilibrio paralelo); clasifica correcciones sugeridas (solo stdlib de Python 3.8+) - `references/plan-nodes-and-buffers.md` - cómo leer tipos de nodo, costos, filas, bucles, buffers y archivos temporales - `references/checks-and-codes.md` - cada código de hallazgo, severidad y qué hacer, más consejos de entrada - `templates/slow-query-review.md` - la nota de revisión que entregas con el extracto del plan y las correcciones clasificadas - `examples/orders_by_email.explain.txt` - un EXPLAIN ANALYZE de texto de una búsqueda lenta (escaneo secuencial + bucle anidado) - `examples/review-report.md` - la salida real del analizador sobre el ejemplo ## Flujo de trabajo ### 1. Recopilar el plan Pide la versión de Postgres, el SQL, y un `EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT)` (o JSON). Si ANALYZE no es seguro en producción, toma `EXPLAIN (BUFFERS)` sin ANALYZE y di que los tiempos son solo estimaciones. Captura tamaños de tabla (`pg_stat_user_tables`, `pg_relation_size`) cuando un Seq Scan parezca sospechoso. ### 2. Ejecutar el analizador ``` python3 scripts/explain_analyze.py examples/orders_by_email.explain.txt python3 scripts/explain_analyze.py plan.json --json-out python3 scripts/explain_analyze.py plan.txt --min-ms 5 python3 scripts/explain_analyze.py --self-test ``` Salida 0 = sin hallazgos altos, 1 = hallazgos altos, 2 = entrada incorrecta. Sin shell, recorre el árbol del plan de abajo hacia arriba usando `references/plan-nodes-and-buffers.md` y aplica los códigos en `references/checks-and-codes.md`. ### 3. Leer el resultado - Alto primero: EX01 Seq Scan en una relación grande con un filtro selectivo, EX03 Nested Loop con filas reales x bucles enormes, EX05 proporción de estimación incorrecta sobre 100x en un nodo caliente, EX07 Sort/Hash que se desbordó a archivos temporales. - Medio: EX02 claves de join sin índice, EX04 Filter que elimina la mayoría de filas después de un escaneo, EX06 buffers de lectura compartida altos, EX08 ramas nunca ejecutadas que aún se ven costosas en papel. - Bajo/info: EX09 workers paralelos desiguales, EX10 tiempo de planificación alto vs ejecución, EX11 LIMIT no empujado hacia abajo, EX12 CTE MATERIALIZED que fuerza cómputo completo. ### 4. Clasificar correcciones Prefiere cambios respaldados por evidencia: agrega o ajusta un índice que coincida con el Filter/Join Filter, actualiza estadísticas (`ANALYZE`), reescribe una subconsulta correlacionada que se convirtió en Nested Loop, sube `work_mem` solo cuando un Sort/Hash se desbordó y el conjunto cabe en memoria, o cambia un CTE a `NOT MATERIALIZED` cuando Postgres 12+ lo materializó innecesariamente. No inventes índices sin nombrar columnas del plan. ### 5. Entregar Devuelve el veredicto, los nodos costosos principales con tiempo real y buffers, la lista de hallazgos, y una lista corta de correcciones clasificadas usando `templates/slow-query-review.md`. ## Ejemplo de resultado En el plan de muestra el Nested Loop impulsó el 98% del tiempo: un Seq Scan externo en `customers` filtrado por `lower(email)` (sin índice de expresión) alimentó un Index Scan interno en `orders_customer_id_idx` que corrió 48,210 bucles. Las filas estimadas en el escaneo externo eran 42 vs 48,210 reales (estimación incorrecta). Los buffers de lectura compartida eran altos en `orders`. Correcciones clasificadas: índice de expresión en `lower(email)`, luego confirmar la selectividad del join; `ANALYZE customers`. ## Reglas - Basa cada afirmación en un nodo del plan (tipo, costo/real, filas, bucles, buffers). - Distingue EXPLAIN solo con estimaciones de ANALYZE; nunca trates costos como milisegundos. - No recomiendes deshabilitar escaneos secuenciales globalmente ni establecer random_page_cost a valores fantásticos sin medir. - Advierte que EXPLAIN ANALYZE ejecuta la consulta (triggers, escrituras, bloqueos). - Esto es una ayuda para leer planes, no un sustituto del monitoreo con `pg_stat_statements` ni de una revisión completa del esquema. FILE:examples/orders_by_email.explain.txt QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------- Nested Loop (cost=0.42..184220.50 rows=12 width=72) (actual time=0.085..912.440 rows=96 loops=1) Buffers: shared hit=1204 read=88440 -> Seq Scan on public.customers c (cost=0.00..1850.00 rows=42 width=40) (actual time=0.040..88.200 rows=48210 loops=1) Filter: (lower((email)::text) = 'ada@example.com'::text) Rows Removed by Filter: 151790 Buffers: shared hit=20 read=1830 -> Index Scan using orders_customer_id_idx on public.orders o (cost=0.42..4.20 rows=8 width=40) (actual time=0.015..0.016 rows=0 loops=48210) Index Cond: (customer_id = c.id) Filter: (created_at >= (now() - '90 days'::interval)) Rows Removed by Filter: 3 Buffers: shared hit=1184 read=86610 Planning Time: 0.412 ms Execution Time: 912.610 ms FILE:examples/review-report.md # Análisis de EXPLAIN de Postgres Fuente: `examples/orders_by_email.explain.txt` Tiempo de Ejecución: 912.61 ms Tiempo de Planificación: 0.412 ms **Veredicto: NECESITA TRABAJO** - 3 hallazgo(s) alto(s). ## Nodos principales por tiempo (o costo) | Nodo | Relación | ms reales (x bucles) | Costo | Filas est -> act | Bucles | Lectura compartida | |------|----------|---------------------|------|-----------------|-------|-------------| | Nested Loop | - | 912.4 | 184220 | 12 -> 96 | 1 | 88440 | | Index Scan | public.orders | 771.4 | 4 | 8 -> 0 | 48210 | 86610 | | Seq Scan | public.customers | 88.2 | 1850 | 42 -> 48210 | 1 | 1830 | ## Hallazgos | Sev | Código | Detalle | |-----|------|--------| | alto | EX01 | Seq Scan en public.customers con Filter selectivo ((lower((email)::text) = 'ada@example.com'::text)); eliminó 151790 filas | | alto | EX03 | Index Scan hijo de Nested Loop corrió bucles=48210 (filas reales/bucle~0) consumiendo ~771.4 ms | | alto | EX05 | Estimación incorrecta en Seq Scan public.customers: filas est=42 real=48210 (proporción~1148x) | | medio | EX02 | Nested Loop tiene Seq Scan interno/externo en public.customers | | medio | EX06 | Nested Loop ? lectura compartida=88440 bloques | | medio | EX06 | Index Scan public.orders lectura compartida=86610 bloques | ## Correcciones clasificadas (sugeridas) 1. Agrega un índice btree/de expresión que coincida con el Filter del Seq Scan (verifica envolturas de funciones como lower()). 2. Reduce las filas externas del Nested Loop o indexa la clave de join interna; re-verifica el orden del join después de ANALYZE. 3. Ejecuta ANALYZE en las tablas tocadas; considera estadísticas extendidas para columnas correlacionadas. 4. Reduce lecturas compartidas con un mejor índice o filtrando antes para que el Nested Loop no re-lea los heaps. FILE:references/checks-and-codes.md # Chequeos y códigos | Código | Severidad | Significado | Qué hacer | |------|----------|------------|-----------| | EX01 | alto | Seq Scan en una relación con un Filter selectivo y filas reales grandes o tiempo real alto | Índice de expresión o btree que coincida con el filtro; evita envolver la columna en una función sin un índice de expresión que coincida | | EX02 | medio | La condición de join parece sin índice (Seq Scan interno en Nested Loop o bucles altos con Filter en la clave de join) | Indexa la clave de join interna; confirma que los tipos de datos coinciden (sin cast que mate el índice) | | EX03 | alto | Nested Loop con bucles muy altos * filas reales (explosión de filas) | Reduce las filas externas primero; considera Hash/Merge Join; corrige estimaciones incorrectas que impulsan la elección de NL | | EX04 | medio | Filter elimina la mayoría de filas después de un escaneo (filas entrantes >> filas salientes) | Empuja el predicado a una condición de índice; reescribe para que el planificador pueda usar un índice | | EX05 | alto | Estimación incorrecta: real/estimado o estimado/real >= 100 en un nodo que importa | ANALYZE; estadísticas extendidas para columnas correlacionadas; evita funciones no inmutables en predicados | | EX06 | medio | Buffers de lectura compartida altos en un nodo caliente | Caché/índice para reducir fetches de heap; verifica si el Nested Loop re-lee las mismas páginas | | EX07 | alto | Sort o Hash se desbordó a archivos temporales (merge externo / Batches > 1 con temp escrito) | Reduce filas antes del sort/hash; sube work_mem cuidadosamente para esta sesión de consulta; agrega índice de soporte para evitar el sort | | EX08 | bajo | Nodo nunca ejecutado (bucles reales=0) pero domina el costo estimado | Ignóralo para el tiempo de ejecución; útil al comparar planes sin ANALYZE | | EX09 | bajo | Consulta paralela con contribución desigual de workers | Revisa la configuración parallel_* y si el gather vale la pena | | EX10 | info | Tiempo de planificación grande vs tiempo de ejecución | Sentencias preparadas; simplifica planificación de una sola vez; problemas de poda de particiones | | EX11 | medio | LIMIT sobre un Sort completo o agregado completo de un conjunto grande | Reescribe para que el orden/filtro permita un escaneo de índice con parada temprana | | EX12 | medio | CTE Scan con MATERIALIZED forzando evaluación completa | WITH ... AS NOT MATERIALIZED (PG12+) o inserta el CTE en línea | ## Consejos de entrada - Planes de texto: pega el árbol completo; no quites la indentación. - Planes JSON: array `FORMAT JSON` de Postgres con un objeto de plan; el script acepta un array crudo o `{Plan: ...}`. - Líneas de cabecera opcionales como `QUERY PLAN` o reglas discontinuas se ignoran. FILE:references/plan-nodes-and-buffers.md # Nodos de plan y buffers ## Capturando un plan útil ```sql EXPLAIN (ANALYZE, BUFFERS, VERBOSE, FORMAT TEXT) <consulta>; -- o EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON) <consulta>; ``` En producción prefiere una réplica en caliente o envuelve las escrituras en una transacción que reviertas. `ANALYZE` ejecuta la sentencia. ## Leyendo una línea de nodo de texto Ejemplo: `Seq Scan on public.customers (cost=0.00..1550.00 rows=42 width=64) (actual time=0.020..85.110 rows=48210 loops=1)` - Tipo de nodo y relación - `cost=inicio..total` (unidades del planificador, no ms) - `rows` = filas estimadas; bajo ANALYZE también `actual time` y `rows` y `loops` - Tiempo total para ese nodo ~= (tiempo real total) * bucles para el patrón de contribución del subárbol; el tiempo de hoja es más claro que el padre cuando los padres incluyen hijos ## Tipos de nodo comunes - **Seq Scan**: lee todo el heap. Bien para tablas pequeñas o cuando la mayoría de filas coinciden; doloroso con un Filter selectivo en una tabla grande. - **Index Scan / Index Only Scan / Bitmap Heap Scan**: bueno cuando es selectivo. Bitmap Heap con muchos re-chequeos aún puede doler. - **Nested Loop**: para cada fila externa, ejecuta el interno. Genial con pocas filas externas + interno indexado; catastrófico cuando el externo es grande. - **Hash Join / Merge Join**: mejor para conjuntos más grandes; vigila Hash que se desborda (`Batches` > 1, temp escrito). - **Sort**: `Sort Method: external merge` significa desborde a disco; considera `work_mem` o menos filas antes. - **Aggregate / GroupAggregate / HashAggregate**: verifica si las columnas de agrupación están indexadas o pre-filtradas. - **CTE Scan**: Postgres 12+ puede MATERIALIZAR CTEs; puede bloquear el pushdown de filtros. - **Limit**: debería estar sobre un camino barato; si Limit está sobre un sort completo de todo, empuja los criterios hacia abajo. ## Buffers (opción BUFFERS) - `shared hit` = encontrado en buffers compartidos (barato) - `shared read` = leído de OS/disco a buffers (caro bajo fallo de caché) - `temp read/written` = archivos de desborde de work_mem Un nodo con `shared read` enorme en el lado interno repetido de un Nested Loop a menudo necesita un mejor filtro externo o índice. ## Estimaciones de filas incorrectas Compara `rows` (estimado) con `rows` real. Proporciones sobre 10x (especialmente 100x+) en nodos costosos significan estadísticas malas, `ANALYZE` desactualizado, columnas correlacionadas, o una función envolviendo una columna indexada (`lower(email)`). ## Lo que esta habilidad no hace No reemplaza `pg_stat_statements`, auto_explain, ni revisiones de diseño de índices que empiecen solo desde el esquema. Empieza desde un plan y explica ese plan. FILE:scripts/explain_analyze.py #!/usr/bin/env python3 """Analizador de planes EXPLAIN / EXPLAIN ANALYZE de Postgres (solo stdlib, Python 3.8+). Analiza planes de texto o JSON, puntúa nodos costosos, y reporta hallazgos EX01-EX12 enfocados en leer el plan (escaneos secuenciales, explosiones de bucles anidados, estimaciones incorrectas, presión de buffers, desbordes a disco). Uso: explain_analyze.py PLAN.txt|.json [--min-ms N] [--json-out] explain_analyze.py --self-test Salida: 0 = sin hallazgos altos, 1 = hallazgos altos, 2 = entrada incorrecta. """ import argparse, json, re, sys SEV = {"alto": 0, "medio": 1, "bajo": 2, "info": 3} NODE_RE = re.compile( r"^(?P<indent>\s*)(?:->\s*)?(?P<type>.+?)" r"(?=\s+using\s+|\s+on\s+|\s*\(cost=)" r"(?:\s+using\s+(?P<idx>[\w.]+))?" r"(?:\s+on\s+(?P<rel>[\w.]+))?" r"(?:\s+(?P<alias>\w+))?" r"\s*\(cost=(?P<cstart>[\d.]+)\.\.(?P<ctotal>[\d.]+)\s+rows=(?P<erows>[\d]+)\s+width=(?P<width>[\d]+)\)" r"(?:\s*\(actual time=(?P<astart>[\d.]+)\.\.(?P<atotal>[\d.]+)\s+rows=(?P<arows>[\d]+)\s+loops=(?P<loops>[\d]+)\))?" ) BUF_RE = re.compile( r"Buffers:\s*(?:shared hit=(?P<shit>\d+))?" r"(?:\s*read=(?P<sread>\d+))?" r"(?:.*?temp read=(?P<tread>\d+))?" r"(?:.*?written=(?P<twrite>\d+))?", re.I, ) FILTER_RE = re.compile(r"^\s+Filter:\s*(.+)$") REMOVED_RE = re.compile(r"Rows Removed by Filter:\s*(\d+)") SORT_RE = re.compile(r"Sort Method:\s*(.+)$", re.I) HASH_BATCH_RE = re.compile(r"Batches:\s*(\d+)", re.I) PLAN_TIME_RE = re.compile(r"Planning Time:\s*([\d.]+)\s*ms", re.I) EXEC_TIME_RE = re.compile(r"Execution Time:\s*([\d.]+)\s*ms", re.I) class InputError(Exception): pass def parse_text(text): lines = text.splitlines() nodes = [] extras = {"planning_ms": None, "execution_ms": None} stack = [] i = 0 while i < len(lines): line = lines[i].rstrip() if not line or set(line) <= set("-=") or line.strip() == "QUERY PLAN": i += 1 continue m = PLAN_TIME_RE.search(line) if m: extras["planning_ms"] = float(m.group(1)); i += 1; continue m = EXEC_TIME_RE.search(line) if m: extras["execution_ms"] = float(m.group(1)); i += 1; continue m = NODE_RE.match(line) if m: raw_indent = re.match(r"^(\s*)", line).group(1) ind = len(raw_indent) node = { "type": m.group("type").strip(), "rel": m.group("rel"), "idx": m.group("idx"), "cost_start": float(m.group("cstart")), "cost_total": float(m.group("ctotal")), "est_rows": int(m.group("erows")), "width": int(m.group("width")), "act_start": float(m.group("astart")) if m.group("astart") else None, "act_total": float(m.group("atotal")) if m.group("atotal") else None, "act_rows": int(m.group("arows")) if m.group("arows") else None, "loops": int(m.group("loops")) if m.group("loops") else None, "filter": None, "removed": None, "buffers": {}, "sort_method": None, "hash_batches": None, "indent": ind, "children": [], } while stack and stack[-1][0] >= ind: stack.pop() if stack: stack[-1][1]["children"].append(node) else: nodes.append(node) stack.append((ind, node)) j = i + 1 while j < len(lines): pl = lines[j] if not pl.strip(): break if NODE_RE.match(pl) or PLAN_TIME_RE.search(pl) or EXEC_TIME_RE.search(pl): break if not pl.startswith(" ") and not pl.startswith("\t"): break fm = FILTER_RE.match(pl) if fm: node["filter"] = fm.group(1).strip() rm = REMOVED_RE.search(pl) if rm: node["removed"] = int(rm.group(1)) bm = BUF_RE.search(pl) if bm: node["buffers"] = {k: int(bm.group(k)) for k in ("shit", "sread", "tread", "twrite") if bm.group(k)} sm = SORT_RE.search(pl) if sm: node["sort_method"] = sm.group(1).strip() hb = HASH_BATCH_RE.search(pl) if hb: node["hash_batches"] = int(hb.group(1)) j += 1 i = j continue i += 1 if not nodes: raise InputError("no se encontraron nodos de plan (necesita texto EXPLAIN con cost=... rows=...)") return nodes, extras def parse_json_plan(obj): if isinstance(obj, list): if not obj: raise InputError("array de plan JSON vacío") obj = obj[0] if not isinstance(obj, dict): raise InputError("el plan JSON debe ser un objeto o un array de objetos") plan = obj.get("Plan") or obj.get("plan") if not plan: raise InputError("JSON sin objeto Plan") extras = { "planning_ms": obj.get("Planning Time"), "execution_ms": obj.get("Execution Time"), } def conv(p, indent=0): node = { "type": p.get("Node Type", "Desconocido"), "rel": p.get("Relation Name") or p.get("Relation"), "idx": p.get("Index Name"), "cost_start": float(p.get("Startup Cost", 0)), "cost_total": float(p.get("Total Cost", 0)), "est_rows": int(p.get("Plan Rows", 0)), "width": int(p.get("Plan Width", 0)), "act_start": p.get("Actual Startup Time"), "act_total": p.get("Actual Total Time"), "act_rows": p.get("Actual Rows"), "loops": p.get("Actual Loops"), "filter": p.get("Filter"), "removed": p.get("Rows Removed by Filter"), "buffers": {}, "sort_method": p.get("Sort Method"), "hash_batches": p.get("Hash Batches") or p.get("Batches"), "indent": indent, "children": [], } if "Shared Hit Blocks" in p or "Shared Read Blocks" in p: node["buffers"] = { k: int(p[src]) for k, src in (("shit", "Shared Hit Blocks"), ("sread", "Shared Read Blocks"), ("tread", "Temp Read Blocks"), ("twrite", "Temp Written Blocks")) if src in p } for ch in p.get("Plans") or []: node["children"].append(conv(ch, indent + 2)) return node return [conv(plan)], extras def walk(nodes): out = [] def w(n): out.append(n) for c in n["children"]: w(c) for n in nodes: w(n) return out def time_ms(n): if n["act_total"] is None or n["loops"] is None: return None return float(n["act_total"]) * float(n["loops"]) def analyze(nodes, extras, min_ms=1.0): findings = [] flat = walk(nodes) def add(sev, code, msg, node=None): findings.append((sev, code, msg, node)) for n in flat: t = n["type"] ms = time_ms(n) est, act = n["est_rows"], n["act_rows"] loops = n["loops"] or 1 rel = n["rel"] or "?" if t.startswith("Seq Scan") and n.get("filter") and (n.get("removed") or 0) > 1000: if (act or 0) > 1000 or (ms or 0) >= min_ms * 10: add("alto", "EX01", "Seq Scan en %s con Filter selectivo (%s); eliminó %s filas" % (rel, n["filter"], n.get("removed")), n) if t.startswith("Nested Loop"): for c in n["children"]: if c["type"].startswith("Seq Scan"): add("medio", "EX02", "Nested Loop tiene Seq Scan interno/externo en %s" % (c.get("rel") or "?"), c) if t.startswith("Nested Loop"): for c in n["children"]: cl = c.get("loops") or 0 if cl >= 10000 and (time_ms(c) or 0) >= min_ms * 20: add("alto", "EX03", "Hijo de Nested Loop %s corrió bucles=%d (filas reales/bucle~%s) consumiendo ~%.1f ms" % ( c["type"], cl, c.get("act_rows"), time_ms(c) or 0), c) if n.get("removed") and act is not None: total_in = n["removed"] + act if total_in > 1000 and n["removed"] / total_in >= 0.9: add("medio", "EX04", "Filter en %s %s elimina %.0f%% de filas (%d eliminadas, %d mantenidas)" % ( t, rel, 100.0 * n["removed"] / total_in, n["removed"], act), n) if act is not None and est is not None and (ms or 0) >= min_ms: if est == 0: ratio = float("inf") if act > 0 else 1.0 else: ratio = max(act / max(est, 1), est / max(act, 1)) if ratio >= 100: add("alto", "EX05", "Estimación incorrecta en %s %s: filas est=%d real=%d (proporción~%.0fx)" % (t, rel, est, act, ratio if ratio != float("inf") else 9999), n) sread = n.get("buffers", {}).get("sread") or 0 if sread >= 5000 and (ms or 0) >= min_ms: add("medio", "EX06", "%s %s lectura compartida=%d bloques" % (t, rel, sread), n) sm = (n.get("sort_method") or "").lower() if "external" in sm: add("alto", "EX07", "Sort se desbordó a disco (%s) en %s" % (n["sort_method"], t), n) if n.get("hash_batches") and n["hash_batches"] > 1 and (n.get("buffers", {}).get("twrite") or 0) > 0: add("alto", "EX07", "Hash se desbordó: Batches=%d temp escrito=%s" % (n["hash_batches"], n["buffers"].get("twrite")), n) if loops == 0 and n["cost_total"] >= 1000: add("bajo", "EX08", "Nodo %s nunca ejecutado pero costo=%.0f" % (t, n["cost_total"]), n) if t.startswith("Limit"): for c in n["children"]: if c["type"].startswith("Sort") and (c.get("act_rows") or c.get("est_rows") or 0) > 1000: add("medio", "EX11", "LIMIT sobre Sort de conjunto grande (%s filas)" % (c.get("act_rows") or c.get("est_rows")), n) if "CTE" in t and (ms or n["cost_total"] > 1000): add("medio", "EX12", "CTE Scan %s puede estar materializado; considera NOT MATERIALIZED si los filtros deben empujarse hacia abajo" % (n.get("rel") or ""), n) if extras.get("planning_ms") and extras.get("execution_ms"): if extras["planning_ms"] > extras["execution_ms"] and extras["planning_ms"] > 20: add("info", "EX10", "Tiempo de Planificación %.1f ms > Tiempo de Ejecución %.1f ms" % (extras["planning_ms"], extras["execution_ms"]), None) findings.sort(key=lambda x: (SEV.get(x[0], 9), x[1])) return findings def report(nodes, extras, findings, src): flat = walk(nodes) lines = [] lines.append("# Análisis de EXPLAIN de Postgres") lines.append("") lines.append("Fuente: `%s`" % src) if extras.get("execution_ms") is not None: lines.append("Tiempo de Ejecución: %s ms" % extras["execution_ms"]) if extras.get("planning_ms") is not None: lines.append("Tiempo de Planificación: %s ms" % extras["planning_ms"]) high = sum(1 for f in findings if f[0] == "alto") lines.append("") if high: lines.append("**Veredicto: NECESITA TRABAJO** - %d hallazgo(s) alto(s)." % high) elif findings: lines.append("**Veredicto: OK con notas** - %d hallazgo(s), ninguno alto." % len(findings)) else: lines.append("**Veredicto: OK** - sin hallazgos sobre umbrales.") lines.append("") lines.append("## Nodos principales por tiempo (o costo)") lines.append("") scored = [] for n in flat: ms = time_ms(n) scored.append((ms if ms is not None else -1, n["cost_total"], n)) scored.sort(key=lambda x: (x[0] if x[0] >= 0 else -1, x[1]), reverse=True) lines.append("| Nodo | Relación | ms reales (x bucles) | Costo | Filas est -> act | Bucles | Lectura compartida |") lines.append("|------|----------|---------------------|------|-----------------|-------|-------------|") for ms, cost, n in scored[:12]: am = ("%.1f" % ms) if ms is not None and ms >= 0 else "-" ra = "%s -> %s" % (n["est_rows"], n["act_rows"] if n["act_rows"] is not None else "-") lines.append("| %s | %s | %s | %.0f | %s | %s | %s |" % ( n["type"], n["rel"] or "-", am, cost, ra, n["loops"] if n["loops"] is not None else "-", n.get("buffers", {}).get("sread", "-"))) lines.append("") lines.append("## Hallazgos") lines.append("") if not findings: lines.append("Ninguno.") else: lines.append("| Sev | Código | Detalle |") lines.append("|-----|------|--------|") for sev, code, msg, _ in findings: lines.append("| %s | %s | %s |" % (sev, code, msg.replace("|", "/"))) lines.append("") lines.append("## Correcciones clasificadas (sugeridas)") lines.append("") fixes = [] codes = {f[1] for f in findings} if "EX01" in codes: fixes.append("Agrega un índice btree/de expresión que coincida con el Filter del Seq Scan (verifica envolturas de funciones como lower()).") if "EX03" in codes or "EX02" in codes: fixes.append("Reduce las filas externas del Nested Loop o indexa la clave de join interna; re-verifica el orden del join después de ANALYZE.") if "EX05" in codes: fixes.append("Ejecuta ANALYZE en las tablas tocadas; considera estadísticas extendidas para columnas correlacionadas.") if "EX07" in codes: fixes.append("Corta filas antes de Sort/Hash, o sube work_mem para esta sesión solo después de medir.") if "EX06" in codes: fixes.append("Reduce lecturas compartidas con un mejor índice o filtrando antes para que el Nested Loop no re-lea los heaps.") if "EX11" in codes: fixes.append("Reescribe para que LIMIT pueda detenerse en un escaneo de índice ordenado en lugar de ordenar el conjunto completo.") if "EX12" in codes: fixes.append("Prueba WITH ... AS NOT MATERIALIZED o inserta el CTE en línea para que los filtros se empujen hacia abajo.") if not fixes: fixes.append("Sin correcciones estructurales de alta prioridad desde los umbrales; mantén el plan bajo vigilancia con pg_stat_statements.") for i, f in enumerate(fixes, 1): lines.append("%d. %s" % (i, f)) lines.append("") return "\n".join(lines) + "\n" def load_plan(path): raw = open(path, encoding="utf-8").read() if path.endswith(".json") or raw.lstrip().startswith(("[", "{")): try: obj = json.loads(raw) except json.JSONDecodeError as e: raise InputError("JSON inválido: %s" % e) return parse_json_plan(obj) return parse_text(raw) def self_test(): tests = [] def t(name, ok): tests.append((name, bool(ok))) sample = """Nested Loop (cost=0.42..184220.50 rows=12 width=72) (actual time=0.085..912.440 rows=96 loops=1) Buffers: shared hit=1204 read=88440 -> Seq Scan on public.customers c (cost=0.00..1850.00 rows=42 width=40) (actual time=0.040..88.200 rows=48210 loops=1) Filter: (lower((email)::text) = 'ada@example.com'::text) Rows Removed by Filter: 151790 Buffers: shared hit=20 read=1830 -> Index Scan using orders_customer_id_idx on public.orders o (cost=0.42..4.20 rows=8 width=40) (actual time=0.015..0.016 rows=0 loops=48210) Index Cond: (customer_id = c.id) Buffers: shared hit=1184 read=86610 Planning Time: 0.412 ms Execution Time: 912.610 ms """ nodes, extras = parse_text(sample) t("nested loop raíz analizado", nodes[0]["type"] == "Nested Loop") t("dos hijos", len(nodes[0]["children"]) == 2) t("tiempo de ejecución", extras["execution_ms"] == 912.610) findings = analyze(nodes, extras) codes = {f[1] for f in findings} t("EX01 seq scan selectivo", "EX01" in codes) t("EX03 explosión nested loop", "EX03" in codes) t("EX05 estimación incorrecta", "EX05" in codes) t("EX06 lecturas compartidas", "EX06" in codes) r = report(nodes, extras, findings, "t") t("veredicto del reporte necesita trabajo", "NECESITA TRABAJO" in r) tiny = """Seq Scan on public.t (cost=0.00..1.05 rows=5 width=4) (actual time=0.002..0.003 rows=5 loops=1) Execution Time: 0.020 ms """ nodes2, ex2 = parse_text(tiny) f2 = analyze(nodes2, ex2) t("tabla pequeña sin alto", not any(x[0] == "alto" for x in f2)) spill = """Sort (cost=1000..1100 rows=10000 width=8) (actual time=50..60 rows=10000 loops=1) Sort Method: external merge Disk: 4096kB """ ns, es = parse_text(spill) fs = analyze(ns, es) t("EX07 sort externo", any(x[1] == "EX07" for x in fs)) j = [{"Plan": {"Node Type": "Limit", "Startup Cost": 0, "Total Cost": 10, "Plan Rows": 10, "Plan Width": 4, "Actual Startup Time": 0.1, "Actual Total Time": 5.0, "Actual Rows": 10, "Actual Loops": 1, "Plans": [{"Node Type": "Sort", "Startup Cost": 0, "Total Cost": 9, "Plan Rows": 5000, "Plan Width": 4, "Actual Startup Time": 0.1, "Actual Total Time": 4.9, "Actual Rows": 5000, "Actual Loops": 1, "Sort Method": "quicksort"}]}, "Planning Time": 1.0, "Execution Time": 5.1}] nj, ej = parse_json_plan(j) fj = analyze(nj, ej) t("JSON limit+sort -> EX11", any(x[1] == "EX11" for x in fj)) try: parse_text("no es un plan") ok = False except InputError: ok = True t("entrada incorrecta rechazada", ok) for name, ok in tests: print(("PASS " if ok else "FAIL ") + name) passed = sum(ok for ok in tests) print("%d/%d pasados" % (passed, len(tests))) return 0 if passed == len(tests) else 1 def main(argv=None): ap = argparse.ArgumentParser(description="Analiza planes EXPLAIN / EXPLAIN ANALYZE de Postgres.") ap.add_argument("plan", nargs="?") ap.add_argument("--min-ms", type=float, default=1.0) ap.add_argument("--json-out", action="store_true") ap.add_argument("--self-test", action="store_true") a = ap.parse_args(argv) if a.self_test: return self_test() if not a.plan: ap.print_usage(sys.stderr) return 2 try: nodes, extras = load_plan(a.plan) findings = analyze(nodes, extras, min_ms=a.min_ms) except (OSError, InputError) as e: print("error: %s" % e, file=sys.stderr) return 2 if a.json_out: print(json.dumps({ "execution_ms": extras.get("execution_ms"), "planning_ms": extras.get("planning_ms"), "findings": [{"severity": s, "code": c, "detail": m} for s, c, m, _ in findings], }, indent=2)) else: sys.stdout.write(report(nodes, extras, findings, a.plan)) return 1 if any(f[0] == "alto" for f in findings) else 0 if __name__ == "__main__": sys.exit(main()) FILE:templates/slow-query-review.md # Revisión de plan de consulta lenta - Fecha: - Base de datos / versión de Postgres: - Entorno (réplica de producción / staging): - Nombre de consulta o ticket: ## SQL (corto) ```sql ``` ## Veredicto - General: - Sumideros de tiempo dominantes: ## Nodos principales | Nodo | Tiempo real / costo | Filas est -> act | Bucles | Buffers | Notas | |------|--------------------|-----------------|-------|---------|-------| | | | | | | | ## Hallazgos | Código | Severidad | Detalle | |------|----------|--------| | | | | ## Correcciones clasificadas 1. 2. 3. ## Seguimientos - [ ] Captura `EXPLAIN (ANALYZE, BUFFERS)` después del cambio - [ ] Revisa `pg_stat_user_indexes` / índices no usados antes de agregar más - [ ] Nota si ANALYZE en tablas base estaba desactualizado