Postgres EXPLAIN Slow Query Analyzer

--- name: postgres-explain-slow-query-analyzer description: Liest Postgres EXPLAIN- und EXPLAIN ANALYZE-Pläne (Text oder JSON) und findet heraus, warum eine Abfrage langsam ist - sequentielle Scans auf großen Relationen, Nested Loops mit riesigen Zeilenschätzungen, Fehlschätzungen (geschätzt vs. tatsächlich), hohe Buffer-Reads, Sort/Hash, die auf die Festplatte auslagern, fehlendes LIMIT-Pushdown und teure Knoten nach tatsächlicher Zeit. Bewertet Fixes (Index, Umschreiben, Statistiken). Offline-Stdlib-Python-Analyzer. --- # Postgres EXPLAIN Slow Query Analyzer Du hilfst Entwicklern und DBAs, Postgres-Abfragepläne zu lesen. Eine langsame Abfrage wird selten durch das bloße Ansehen des SQL behoben: Der Plan zeigt, ob Postgres einen sequentiellen Scan, einen explodierten Nested Loop, eine schlechte Zeilenschätzung, ein Sort, das auf die Festplatte ausgelagert hat, oder einen Hash Join, der Gigabytes an Buffern gelesen hat, gewählt hat. Du nimmst einen `EXPLAIN`- oder `EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT|JSON)`-Plan, benennst die teuren Knoten, erklärst, warum sie schaden, und bewertest konkrete Fixes. Diese Fähigkeit dreht sich um das Lesen von Plänen, nicht um das Umschreiben von SQL von Grund auf ohne Beweise. Du führst keine destruktiven Anweisungen aus. Bevorzuge `EXPLAIN (ANALYZE, BUFFERS)` auf einer Replik oder in einer Transaktion, die du zurücksetzen kannst; warne, dass ANALYZE die Abfrage tatsächlich ausführt. ## Dateien in dieser Fähigkeit - `scripts/explain_analyze.py` - parst Text- oder JSON-EXPLAIN / EXPLAIN ANALYZE-Ausgaben; bewertet Knoten nach tatsächlicher Zeit oder Kosten; meldet EX01-EX12 (sequentielle Scans, Nested-Loop-Explosionen, Fehlschätzungen, Festplatten-Sorts/Hashes, hohe Shared-Reads, nie ausgeführte Knoten, Parallel-Ungleichgewicht); bewertet vorgeschlagene Fixes (nur Python 3.8+ Standardbibliothek) - `references/plan-nodes-and-buffers.md` - wie man Knotentypen, Kosten, Zeilen, Loops, Buffer und temporäre Dateien liest - `references/checks-and-codes.md` - jeder Befundcode, Schweregrad und was zu tun ist, plus Eingabetipps - `templates/slow-query-review.md` - die Überprüfungsnotiz, die du mit dem Planauszug und bewerteten Fixes zurückgibst - `examples/orders_by_email.explain.txt` - ein Text-EXPLAIN ANALYZE einer langsamen Suche (Seq Scan + Nested Loop) - `examples/review-report.md` - die echte Analyzer-Ausgabe zum Beispiel ## Arbeitsablauf ### 1. Plan sammeln Frage nach der Postgres-Version, dem SQL und einem `EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT)` (oder JSON). Wenn ANALYZE in der Produktion unsicher ist, nimm `EXPLAIN (BUFFERS)` ohne ANALYZE und sage, dass Zeitangaben nur Schätzungen sind. Erfasse Tabellengrößen (`pg_stat_user_tables`, `pg_relation_size`), wenn ein Seq Scan verdächtig aussieht. ### 2. Analyzer ausführen ``` 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 ``` Exit 0 = keine hohen Befunde, 1 = hohe Befunde, 2 = schlechte Eingabe. Ohne Shell den Planbaum bottom-up mit `references/plan-nodes-and-buffers.md` durchgehen und die Codes in `references/checks-and-codes.md` anwenden. ### 3. Ergebnis lesen - Zuerst hoch: EX01 Seq Scan auf einer großen Relation mit selektivem Filter, EX03 Nested Loop mit riesigen tatsächlichen Zeilen x Loops, EX05 Fehlschätzungsverhältnis über 100x auf einem heißen Knoten, EX07 Sort/Hash, das auf temporäre Dateien ausgelagert hat. - Mittel: EX02 Join-Schlüssel ohne Index, EX04 Filter, der die meisten Zeilen nach einem Scan entfernt, EX06 hohe Shared-Read-Buffer, EX08 nie ausgeführte Zweige, die auf dem Papier trotzdem teuer aussehen. - Niedrig/Info: EX09 Parallel-Worker ungleichmäßig, EX10 Planungszeit hoch vs. Ausführung, EX11 LIMIT nicht nach unten geschoben, EX12 CTE MATERIALIZED erzwingt volle Berechnung. ### 4. Fixes bewerten Bevorzuge evidenzbasierte Änderungen: Index hinzufügen oder anpassen, der zum Filter/Join-Filter passt, Statistiken aktualisieren (`ANALYZE`), eine korrelierte Unterabfrage umschreiben, die zu einem Nested Loop wurde, `work_mem` nur erhöhen, wenn ein Sort/Hash ausgelagert hat und die Menge in den Speicher passt, oder eine CTE zu `NOT MATERIALIZED` ändern, wenn Postgres 12+ sie unnötig materialisiert hat. Erfinde keine Indizes, ohne Spalten aus dem Plan zu benennen. ### 5. Liefern Gib das Urteil, die teuersten Knoten mit tatsächlicher Zeit und Buffern, die Befundliste und eine kurze bewertete Fixliste mit `templates/slow-query-review.md` zurück. ## Beispielergebnis Im Beispielplan trieb der Nested Loop 98% der Zeit: Ein äußerer Seq Scan auf `customers`, gefiltert nach `lower(email)` (kein Ausdrucksindex), speiste einen inneren Index Scan auf `orders_customer_id_idx`, der 48.210 Loops ausführte. Geschätzte Zeilen beim äußeren Scan waren 42 vs. tatsächlich 48.210 (Fehlschätzung). Shared-Read-Buffer waren bei `orders` hoch. Bewertete Fixes: Ausdrucksindex auf `lower(email)`, dann Join-Selektivität bestätigen; `ANALYZE customers`. ## Regeln - Jede Behauptung auf einen Knoten im Plan stützen (Typ, Kosten/tatsächlich, Zeilen, Loops, Buffer). - Nur geschätztes EXPLAIN von ANALYZE unterscheiden; Kosten niemals als Millisekunden behandeln. - Nicht empfehlen, sequentielle Scans global zu deaktivieren oder random_page_cost auf Fantasiewerte zu setzen, ohne zu messen. - Warnen, dass EXPLAIN ANALYZE die Abfrage ausführt (Trigger, Schreibvorgänge, Sperren). - Dies ist eine Plan-Lesehilfe, kein Ersatz für `pg_stat_statements`-Überwachung oder eine vollständige Schemaüberprüfung. 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 # Postgres EXPLAIN-Analyse Quelle: `examples/orders_by_email.explain.txt` Ausführungszeit: 912.61 ms Planungszeit: 0.412 ms **Urteil: ARBEIT NÖTIG** - 3 hohe Befunde. ## Top-Knoten nach Zeit (oder Kosten) | Knoten | Relation | Tatsächliche ms (x Loops) | Kosten | Zeilen geschätzt -> tatsächlich | Loops | Shared-Read | |------|----------|---------------------|------|-----------------|-------|-------------| | 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 | ## Befunde | Schweregrad | Code | Detail | |-----|------|--------| | hoch | EX01 | Seq Scan auf public.customers mit selektivem Filter ((lower((email)::text) = 'ada@example.com'::text)); 151790 Zeilen entfernt | | hoch | EX03 | Nested-Loop-Kind-Index-Scan lief loops=48210 (tatsächliche Zeilen/Loop~0) und verbrauchte ~771.4 ms | | hoch | EX05 | Fehlschätzung auf Seq Scan public.customers: geschätzte Zeilen=42 tatsächlich=48210 (Verhältnis~1148x) | | mittel | EX02 | Nested Loop hat inneren/äußeren Seq Scan auf public.customers | | mittel | EX06 | Nested Loop ? shared read=88440 Blöcke | | mittel | EX06 | Index Scan public.orders shared read=86610 Blöcke | ## Bewertete Fixes (vorgeschlagen) 1. Btree-/Ausdrucksindex hinzufügen, der zum Seq-Scan-Filter passt (Funktionswrapper wie lower() prüfen). 2. Äußere Nested-Loop-Zeilen reduzieren oder inneren Join-Schlüssel indizieren; Join-Reihenfolge nach ANALYZE erneut prüfen. 3. ANALYZE auf den betroffenen Tabellen ausführen; erweiterte Statistiken für korrelierte Spalten in Betracht ziehen. 4. Shared-Reads durch einen besseren Index oder früheres Filtern senken, damit der Nested Loop keine Heaps erneut liest. FILE:references/checks-and-codes.md # Checks und Codes | Code | Schweregrad | Bedeutung | Was zu tun ist | |------|----------|---------|------------| | EX01 | hoch | Seq Scan auf einer Relation mit selektivem Filter und großen tatsächlichen Zeilen oder hoher tatsächlicher Zeit | Ausdrucks- oder Btree-Index passend zum Filter; vermeiden, die Spalte in eine Funktion zu wickeln, ohne passenden Ausdrucksindex | | EX02 | mittel | Join-Bedingung sieht nicht indiziert aus (Nested-Loop-innerer Seq Scan oder hohe Loops mit Filter auf Join-Schlüssel) | Inneren Join-Schlüssel indizieren; Datentypen abgleichen (kein Cast, der den Index tötet) | | EX03 | hoch | Nested Loop mit sehr hohen Loops * tatsächlichen Zeilen (Zeilenexplosion) | Zuerst äußere Zeilen reduzieren; Hash/Merge Join in Betracht ziehen; Fehlschätzungen beheben, die NL-Wahl antreiben | | EX04 | mittel | Filter entfernt die meisten Zeilen nach einem Scan (Zeilen rein >> Zeilen raus) | Prädikat in eine Indexbedingung schieben; so umschreiben, dass der Planer einen Index nutzen kann | | EX05 | hoch | Fehlschätzung: tatsächlich/geschätzt oder geschätzt/tatsächlich >= 100 auf einem Knoten, der zählt | ANALYZE; erweiterte Statistiken für korrelierte Spalten; nicht-immutable Funktionen in Prädikaten vermeiden | | EX06 | mittel | Hohe Shared-Read-Buffer auf einem heißen Knoten | Caching/Index zur Reduzierung von Heap-Fetches; prüfen, ob Nested Loop dieselben Seiten erneut liest | | EX07 | hoch | Sort oder Hash auf temporäre Dateien ausgelagert (externes Merge / Batches > 1 mit temp geschrieben) | Zeilen vor Sort/Hash reduzieren; work_mem vorsichtig für diese Abfragesitzung erhöhen; unterstützenden Index hinzufügen, um Sort zu vermeiden | | EX08 | niedrig | Knoten nie ausgeführt (tatsächliche Loops=0), dominiert aber geschätzte Kosten | Für Laufzeit ignorieren; nützlich beim Vergleich von Plänen ohne ANALYZE | | EX09 | niedrig | Parallele Abfrage mit ungleichmäßigem Worker-Beitrag | parallel_*-Einstellungen prüfen und ob Gather es wert ist | | EX10 | info | Planungszeit groß vs. Ausführungszeit | Prepared Statements; einmalige Planung vereinfachen; Partition-Pruning-Probleme | | EX11 | mittel | LIMIT über einem vollständigen Sort oder einer vollständigen Aggregation einer großen Menge | So umschreiben, dass order/filter einen Index-Scan mit frühem Stopp erlaubt | | EX12 | mittel | CTE Scan mit MATERIALIZED erzwingt volle Auswertung | WITH ... AS NOT MATERIALIZED (PG12+) oder CTE inline | ## Eingabetipps - Textpläne: den vollständigen Baum einfügen; Einrückung nicht entfernen. - JSON-Pläne: Postgres `FORMAT JSON`-Array mit einem Planobjekt; das Skript akzeptiert ein rohes Array oder `{Plan: ...}`. - Optionale Kopfzeilen wie `QUERY PLAN` oder gestrichelte Linien werden ignoriert. FILE:references/plan-nodes-and-buffers.md # Plan-Knoten und Buffer ## Nützlichen Plan erfassen ```sql EXPLAIN (ANALYZE, BUFFERS, VERBOSE, FORMAT TEXT) <query>; -- oder EXPLAIN (ANALYZE, BUFFERS, FORMAT JSON) <query>; ``` In der Produktion eine Hot-Standby bevorzugen oder Schreibvorgänge in eine Transaktion wickeln, die du zurücksetzt. `ANALYZE` führt die Anweisung aus. ## Text-Knotenzeile lesen Beispiel: `Seq Scan on public.customers (cost=0.00..1550.00 rows=42 width=64) (actual time=0.020..85.110 rows=48210 loops=1)` - Knotentyp und Relation - `cost=startup..total` (Planer-Einheiten, nicht ms) - `rows` = geschätzte Zeilen; unter ANALYZE auch `actual time` und `rows` und `loops` - Gesamtzeit für diesen Knoten ~= (tatsächliche Gesamtzeit) * Loops für das Unterbaum-Beitragsmuster; Blattzeit ist klarer als Elternzeit, wenn Eltern Kinder enthalten ## Häufige Knotentypen - **Seq Scan**: liest den gesamten Heap. Fein für winzige Tabellen oder wenn die meisten Zeilen passen; schmerzhaft mit selektivem Filter auf einer großen Tabelle. - **Index Scan / Index Only Scan / Bitmap Heap Scan**: gut, wenn selektiv. Bitmap Heap mit vielen Rechecks kann trotzdem schaden. - **Nested Loop**: für jede äußere Zeile inneren ausführen. Großartig für wenige äußere Zeilen + indiziertem Inneren; katastrophal, wenn das Äußere groß ist. - **Hash Join / Merge Join**: besser für größere Mengen; auf Hash achten, der auslagert (`Batches` > 1, temp geschrieben). - **Sort**: `Sort Method: external merge` bedeutet Auslagerung auf die Festplatte; `work_mem` oder weniger Zeilen früher in Betracht ziehen. - **Aggregate / GroupAggregate / HashAggregate**: prüfen, ob Gruppierungsspalten indiziert oder vorgefiltert sind. - **CTE Scan**: Postgres 12+ kann CTEs MATERIALISIEREN; kann Filter-Pushdown blockieren. - **Limit**: sollte über einem billigen Pfad sitzen; wenn Limit über einem vollständigen Sort von allem sitzt, Kriterien nach unten schieben. ## Buffer (BUFFERS-Option) - `shared hit` = in Shared Buffers gefunden (billig) - `shared read` = vom OS/Festplatte in Buffer gelesen (teuer bei Cache-Miss) - `temp read/written` = work_mem-Auslagerungsdateien Ein Knoten mit riesigem `shared read` auf einer wiederholten Nested-Loop-Innenseite braucht oft einen besseren äußeren Filter oder Index. ## Zeilenfehlschätzungen `rows` (Schätzung) mit tatsächlichen `rows` vergleichen. Verhältnisse über 10x (besonders 100x+) auf teuren Knoten bedeuten schlechte Statistiken, veraltetes `ANALYZE`, korrelierte Spalten oder eine Funktion, die eine indizierte Spalte umschließt (`lower(email)`). ## Was diese Fähigkeit nicht tut Sie ersetzt nicht `pg_stat_statements`, auto_explain oder Index-Design-Überprüfungen, die vom Schema allein ausgehen. Sie startet von einem Plan und erklärt diesen Plan. FILE:scripts/explain_analyze.py #!/usr/bin/env python3 """Postgres EXPLAIN / EXPLAIN ANALYZE-Plan-Analyzer (nur Stdlib, Python 3.8+). Parst Text- oder JSON-Pläne, bewertet teure Knoten und meldet Befunde EX01-EX12, fokussiert auf das Lesen des Plans (sequentielle Scans, Nested-Loop-Explosionen, Fehlschätzungen, Buffer-Druck, Festplatten-Auslagerungen). Verwendung: explain_analyze.py PLAN.txt|.json [--min-ms N] [--json-out] explain_analyze.py --self-test Exit: 0 = keine hohen Befunde, 1 = hohe Befunde, 2 = schlechte Eingabe. """ import argparse, json, re, sys SEV = {"hoch": 0, "mittel": 1, "niedrig": 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("keine Plan-Knoten gefunden (EXPLAIN-Text mit cost=... rows=... benötigt)") return nodes, extras def parse_json_plan(obj): if isinstance(obj, list): if not obj: raise InputError("leeres JSON-Plan-Array") obj = obj[0] if not isinstance(obj, dict): raise InputError("JSON-Plan muss ein Objekt oder ein Array von Objekten sein") plan = obj.get("Plan") or obj.get("plan") if not plan: raise InputError("JSON fehlt Plan-Objekt") extras = { "planning_ms": obj.get("Planning Time"), "execution_ms": obj.get("Execution Time"), } def conv(p, indent=0): node = { "type": p.get("Node Type", "Unbekannt"), "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("hoch", "EX01", "Seq Scan auf %s mit selektivem Filter (%s); %s Zeilen entfernt" % (rel, n["filter"], n.get("removed")), n) if t.startswith("Nested Loop"): for c in n["children"]: if c["type"].startswith("Seq Scan"): add("mittel", "EX02", "Nested Loop hat inneren/äußeren Seq Scan auf %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("hoch", "EX03", "Nested-Loop-Kind %s lief loops=%d (tatsächliche Zeilen/Loop~%s) und verbrauchte ~%.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("mittel", "EX04", "Filter auf %s %s entfernt %.0f%% der Zeilen (%d entfernt, %d behalten)" % ( 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("hoch", "EX05", "Fehlschätzung auf %s %s: geschätzte Zeilen=%d tatsächlich=%d (Verhältnis~%.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("mittel", "EX06", "%s %s shared read=%d Blöcke" % (t, rel, sread), n) sm = (n.get("sort_method") or "").lower() if "external" in sm: add("hoch", "EX07", "Sort auf Festplatte ausgelagert (%s) auf %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("hoch", "EX07", "Hash ausgelagert: Batches=%d temp geschrieben=%s" % (n["hash_batches"], n["buffers"].get("twrite")), n) if loops == 0 and n["cost_total"] >= 1000: add("niedrig", "EX08", "Knoten %s nie ausgeführt, aber Kosten=%.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("mittel", "EX11", "LIMIT über Sort einer großen Menge (%s Zeilen)" % (c.get("act_rows") or c.get("est_rows")), n) if "CTE" in t and (ms or n["cost_total"] > 1000): add("mittel", "EX12", "CTE Scan %s könnte materialisiert sein; NOT MATERIALIZED in Betracht ziehen, wenn Filter nach unten geschoben werden sollen" % (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", "Planungszeit %.1f ms > Ausführungszeit %.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("# Postgres EXPLAIN-Analyse") lines.append("") lines.append("Quelle: `%s`" % src) if extras.get("execution_ms") is not None: lines.append("Ausführungszeit: %s ms" % extras["execution_ms"]) if extras.get("planning_ms") is not None: lines.append("Planungszeit: %s ms" % extras["planning_ms"]) high = sum(1 for f in findings if f[0] == "hoch") lines.append("") if high: lines.append("**Urteil: ARBEIT NÖTIG** - %d hohe Befunde." % high) elif findings: lines.append("**Urteil: OK MIT HINWEISEN** - %d Befunde, keiner hoch." % len(findings)) else: lines.append("**Urteil: OK** - keine Befunde über den Schwellenwerten.") lines.append("") lines.append("## Top-Knoten nach Zeit (oder Kosten)") 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("| Knoten | Relation | Tatsächliche ms (x Loops) | Kosten | Zeilen geschätzt -> tatsächlich | Loops | Shared-Read |") 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("## Befunde") lines.append("") if not findings: lines.append("Keine.") else: lines.append("| Schweregrad | Code | Detail |") lines.append("|-----|------|--------|") for sev, code, msg, _ in findings: lines.append("| %s | %s | %s |" % (sev, code, msg.replace("|", "/"))) lines.append("") lines.append("## Bewertete Fixes (vorgeschlagen)") lines.append("") fixes = [] codes = {f[1] for f in findings} if "EX01" in codes: fixes.append("Btree-/Ausdrucksindex hinzufügen, der zum Seq-Scan-Filter passt (Funktionswrapper wie lower() prüfen).") if "EX03" in codes or "EX02" in codes: fixes.append("Äußere Nested-Loop-Zeilen reduzieren oder inneren Join-Schlüssel indizieren; Join-Reihenfolge nach ANALYZE erneut prüfen.") if "EX05" in codes: fixes.append("ANALYZE auf den betroffenen Tabellen ausführen; erweiterte Statistiken für korrelierte Spalten in Betracht ziehen.") if "EX07" in codes: fixes.append("Zeilen vor Sort/Hash reduzieren oder work_mem nur für diese Sitzung nach Messung erhöhen.") if "EX06" in codes: fixes.append("Shared-Reads durch einen besseren Index oder früheres Filtern senken, damit der Nested Loop keine Heaps erneut liest.") if "EX11" in codes: fixes.append("So umschreiben, dass LIMIT auf einem geordneten Index-Scan stoppen kann, statt die volle Menge zu sortieren.") if "EX12" in codes: fixes.append("WITH ... AS NOT MATERIALIZED versuchen oder CTE inline, damit Filter nach unten geschoben werden.") if not fixes: fixes.append("Keine hochprioritären strukturellen Fixes aus den Schwellenwerten; Plan unter pg_stat_statements-Beobachtung halten.") 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("ungültiges JSON: %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("Wurzel-Nested-Loop geparst", nodes[0]["type"] == "Nested Loop") t("zwei Kinder", len(nodes[0]["children"]) == 2) t("Ausführungszeit", extras["execution_ms"] == 912.610) findings = analyze(nodes, extras) codes = {f[1] for f in findings} t("EX01 selektiver Seq Scan", "EX01" in codes) t("EX03 Nested-Loop-Explosion", "EX03" in codes) t("EX05 Fehlschätzung", "EX05" in codes) t("EX06 Shared-Reads", "EX06" in codes) r = report(nodes, extras, findings, "t") t("Berichtsurteil Arbeit nötig", "ARBEIT NÖTIG" 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("winzige Tabelle kein hoch", not any(x[0] == "hoch" 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 externes Sort", 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("kein Plan") ok = False except InputError: ok = True t("schlechte Eingabe abgelehnt", ok) for name, ok in tests: print(("PASS " if ok else "FAIL ") + name) passed = sum(ok for ok in tests) print("%d/%d bestanden" % (passed, len(tests))) return 0 if passed == len(tests) else 1 def main(argv=None): ap = argparse.ArgumentParser(description="Postgres EXPLAIN / EXPLAIN ANALYZE-Pläne analysieren.") 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("Fehler: %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] == "hoch" for f in findings) else 0 if __name__ == "__main__": sys.exit(main()) FILE:templates/slow-query-review.md # Überprüfung des langsamen Abfrageplans - Datum: - Datenbank / Postgres-Version: - Umgebung (Produktions-Replik / Staging): - Abfragename oder Ticket: ## SQL (kurz) ```sql ``` ## Urteil - Insgesamt: - Dominante Zeitfresser: ## Top-Knoten | Knoten | Tatsächliche Zeit / Kosten | Zeilen geschätzt -> tatsächlich | Loops | Buffer | Notizen | |------|--------------------|-----------------|-------|---------|-------| | | | | | | | ## Befunde | Code | Schweregrad | Detail | |------|----------|--------| | | | | ## Bewertete Fixes 1. 2. 3. ## Nachverfolgungen - [ ] `EXPLAIN (ANALYZE, BUFFERS)` nach der Änderung erfassen - [ ] `pg_stat_user_indexes` / ungenutzte Indizes prüfen, bevor weitere hinzugefügt werden - [ ] Notieren, ob ANALYZE auf Basistabellen veraltet war