Rails Postgres EXPLAIN ANALYZE: Query Plans Lezen om Trage Rails Queries op te Lossen

De oprichter van een B2B SaaS appte me afgelopen november op een zondagmiddag met een screenshot. De dashboard-pagina die in staging in 200ms laadde, deed er in productie 4,2 seconden over. De data had dezelfde vorm. De Rails-app was dezelfde code. Skylight wees naar één ActiveRecord-query, en het team had de voor de hand liggende index al toegevoegd. Niets veranderde. Ik vroeg hem om één ding uit te voeren: EXPLAIN (ANALYZE, BUFFERS) <query> in productie psql en de output naar me te plakken. Twee minuten later had hij zijn antwoord — Postgres koos voor een Sequential Scan op een tabel met 12 miljoen rijen omdat de rijschatting van de planner er drie ordes van grootte naast zat. De fix kostte acht minuten. De zondag werd gered door een query plan te lezen.

Na negentien jaar Rails kan ik met vertrouwen zeggen: de meeste performance-problemen in productie zijn geen framework-problemen, het zijn query plan-problemen. Rails Postgres EXPLAIN ANALYZE is het waardevolste diagnostische gereedschap dat ik gebruik, en de meeste Rails-developers kijken nooit verder dan de eerste regel van de output. Deze post is de praktische gids die ik aan engineers geef wanneer ik in een trage-query-brand spring — wat je echt moet lezen, wat je kunt negeren, en de patronen die telkens opduiken in Rails-apps die met Postgres praten.

Waarom Rails Postgres EXPLAIN ANALYZE Belangrijk Is in Productie

Een index toevoegen helpt niet altijd. Die zin is ketters voor nieuwere Rails-developers, die getraind zijn dat elke trage query een index krijgt. Het is ook waar. Postgres gebruikt een kosten-gebaseerde planner: hij schat in hoeveel rijen elke stap oplevert en kiest daarna de strategie met de laagste verwachte kosten. Als die schattingen verkeerd zijn — door verouderde statistieken, door gecorreleerde kolommen, door een scheve dataverdeling — kiest de planner de verkeerde strategie en gaat je “geïndexeerde” query toch door een Sequential Scan.

EXPLAIN ANALYZE is de enige manier om dit te zien. EXPLAIN alleen toont het plan dat de planner zou kiezen. EXPLAIN ANALYZE voert de query daadwerkelijk uit en rapporteert de echte timing en echte rijaantallen naast de schattingen. Het gat tussen geschat en daadwerkelijk is waar bijna elke Rails-Postgres-performance-bug zich verbergt.

Ik zeg het tegen elk Rails-team waarmee ik werk: als je geen query plan kunt lezen, gok je over je database. De N+1-detector in bullet en je APM-dashboard vertellen je welke query traag is. Ze vertellen je niet waarom. Het plan vertelt je het waarom, en het waarom is meestal verrassend.

EXPLAIN ANALYZE Draaien op een Rails Query

ActiveRecord maakt dit makkelijk. Elke relatie reageert op .explain, en vanaf Rails 7.1 kun je opties doorgeven:

User.joins(:orders)
    .where(orders: { status: "paid" })
    .where("orders.created_at > ?", 30.days.ago)
    .explain(:analyze, :buffers, :verbose)

Dat print een echt query plan naar je Rails-log of console, met daadwerkelijke timing en daadwerkelijke rijaantallen. Voor productiediagnose sla ik meestal ActiveRecord over en draai ik de ruwe query in psql met \timing aan, omdat ik volledige controle wil over de analyze-opties en het gedrag van de planner wil zien zonder dat Rails er omheen zit.

EXPLAIN (ANALYZE, BUFFERS, VERBOSE, FORMAT TEXT)
SELECT users.* FROM users
INNER JOIN orders ON orders.user_id = users.id
WHERE orders.status = 'paid'
  AND orders.created_at > NOW() - INTERVAL '30 days';

Een waarschuwing: EXPLAIN ANALYZE voert de query echt uit. Op een SELECT is dat prima. Op een UPDATE of DELETE moet je hem in een transactie wikkelen en terugdraaien, of je muteert stilletjes productiedata terwijl je diagnose draait.

BEGIN;
EXPLAIN (ANALYZE, BUFFERS) DELETE FROM sessions WHERE expires_at < NOW();
ROLLBACK;

Ik heb in mijn carrière precies één engineer gezien die de ROLLBACK vergat. Hij verwijderde zes maanden aan payment-audit-logs terwijl hij probeerde uit te zoeken waarom de cleanup-job traag was. Altijd BEGIN en altijd ROLLBACK.

De Vijf Regels van een Query Plan die er Echt Toe Doen

Een Postgres-plan ziet er intimiderend uit omdat het dicht beschreven is. Negentig procent van de diagnostische waarde zit in vijf dingen. Zodra je die kunt vinden, kun je bijna elke trage Rails-query debuggen.

1. Het scan-type onderaan. Elk plan eindigt met een of meerdere scans tegen tabellen. De drie die ertoe doen zijn Seq Scan (elke rij lezen), Index Scan (geselecteerde rijen via een index lezen) en Bitmap Heap Scan (de index gebruiken om een bitmap te bouwen, daarna pages lezen). Een Seq Scan op een grote tabel is meestal fout. Een Bitmap Heap Scan voor queries die duizenden rijen teruggeven is meestal goed. Een Index Scan voor queries die honderden rijen teruggeven is meestal optimaal.

2. De Rows-schatting versus Rows-werkelijk. Elke node toont (rows=N) voor de schatting en actual rows=M voor de waarheid. Als de schatting er 10x of meer naast zit, neemt de planner beslissingen op basis van verkeerde informatie. Dat is de meest voorkomende oorzaak van “ik heb de index toegevoegd en niks ging sneller.”

3. De Buffers-getallen. Met BUFFERS aan zie je shared hit=X read=Y. hit betekent dat de page in de cache van Postgres zat, read betekent dat hij naar schijf moest. Een query met 200.000 buffer reads op een 16GB server hamert op schijf, en geen enkele indextuning lost dat op zonder de data-vorm aan te pakken.

4. Total Execution Time onderaan. Dit is de daadwerkelijke kloktijd. Als die klein is maar je Rails-request is traag, dan zit de bottleneck niet in de database — het is de netwerk-round-trip, Active Record-materialisatie, of rendering.

5. Filter en Rows Removed by Filter. Als een node zegt Rows Removed by Filter: 1200000, dan heeft Postgres 1,2 miljoen rijen gescand en het grootste deel weggegooid. Dat is de duidelijke aanwijzing voor een ontbrekende partial index of een slecht geschreven WHERE-clausule.

Als je deze vijf dingen leest, kun je bijna elke trage query in een Rails-app diagnosticeren. Al het andere in het plan is ondersteunend detail.

EXPLAIN Versus EXPLAIN ANALYZE in Rails Ontwikkeling

Ik gebruik de twee vormen verschillend en met opzet.

EXPLAIN alleen is snel en gratis. Het toont het plan zonder uit te voeren. Ik gebruik het constant tijdens ontwikkeling om te checken dat de query die ik net schreef de index raakt die ik verwacht, voordat ik een test schrijf of naar CI push.

EXPLAIN ANALYZE voert de query echt uit. Het is de waarheid. Ik gebruik het wanneer het plan van EXPLAIN er prima uitziet maar de query nog steeds traag is, of wanneer productie zich anders gedraagt dan staging. De uitvoeringsoverhead is klein voor snelle queries en groot voor enorme queries — er is een reden waarom je het alleen draait als je het meent.

EXPLAIN (ANALYZE, BUFFERS) is wat ik gebruik in productiediagnose. De buffer-data vertelt me of de query CPU-bound of IO-bound is, wat bepaalt of de fix een index is, een partial index, een covering index, of een config-wijziging.

Er is ook pg_stat_statements, dat ik behandel als de eerste stop vóór EXPLAIN ANALYZE. Het aggregeert query-stats over tijd en wijst je naar welke queries je moet onderzoeken. EXPLAIN ANALYZE is de microscoop waarmee je de queries inzoomt die pg_stat_statements identificeert.

Veelvoorkomende Patronen in Rails Plans

Na bijna twee decennia trage Rails-queries diagnosticeren, blijven dezelfde vormen terugkomen.

Sequential Scan op een soft-delete kolom. Je where(deleted_at: nil) scope raakt een tabel met 14 miljoen rijen, waarvan 50 verwijderd. Postgres beslist terecht dat een index op deleted_at nutteloos is omdat 99,9% van de rijen matchen — de index zou trager zijn dan de scan. De fix is een partial index: CREATE INDEX ... ON things(other_column) WHERE deleted_at IS NULL.

Bitmap Heap Scan met grote rechecks. Je ziet Recheck Cond en Rows Removed by Index Recheck in de duizenden. Je bitmap is te grof, vaak door lage work_mem. Verhoog work_mem voor de sessie, draai opnieuw, kijk of het overschakelt naar een schone Index Scan.

Nested Loop met slechte rijschattingen. Een Nested Loop join is snel als de outer-kant heel weinig rijen heeft. Als de planner 5 outer-rijen schat en het werkelijke aantal is 50.000, dan draait de inner index-lookup 10.000 keer vaker dan verwacht. De query duurt 30 seconden. De fix is meestal ANALYZE, soms CREATE STATISTICS op gecorreleerde kolommen.

Sort die naar schijf overloopt. Een node met Sort Method: external merge Disk: 124000kB betekent dat Postgres geen work_mem meer had en de sort naar schijf dumpte. Voor analytische queries naar een dashboard is dit de stille killer — prima op een laptop, dodelijk op een beperkte productie-replica.

Hash Join met massaal geheugen. Hash-nodes met Buckets: 1024 Batches: 32 Memory Usage: 64MB betekenen dat de hash-table niet in geheugen paste en werd gepartitioneerd naar schijf. Zelfde fix-familie als sort-overloop.

Je zult deze patronen steeds weer zien zodra je plans begint te lezen. Ze vormen het grootste deel van Rails-Postgres-performance-werk.

Een Echt Voorbeeld: van 3 Seconden naar 80ms

Laat me dit concreet maken. Het admin-dashboard van een klant toonde recente betaalde orders uit de laatste 30 dagen, gejoind aan users, gesorteerd op created_at desc, limit 50. De Rails-query zag er onschuldig uit:

class Admin::OrdersController < Admin::BaseController
  def index
    @orders = Order.where(status: "paid")
                   .where("created_at > ?", 30.days.ago)
                   .includes(:user, :line_items)
                   .order(created_at: :desc)
                   .limit(50)
  end
end

De pagina duurde 3,1 seconden. Ze hadden een index op orders(status) en een index op orders(created_at). EXPLAIN ANALYZE liet zien waarom dat niet hielp:

Limit  (cost=0.43..2412.18 rows=50)
       (actual time=2891.230..2891.245 rows=50 loops=1)
  Buffers: shared hit=18234 read=124518
  ->  Index Scan Backward using orders_created_at_idx on orders
        (cost=0.43..289412.83 rows=6000 width=237)
        (actual time=2891.228..2891.240 rows=50 loops=1)
        Filter: (status = 'paid'::text)
        Rows Removed by Filter: 1483291

De planner gebruikte de created_at-index, liep er achteruit doorheen en filterde toen op status — bijna 1,5 miljoen rijen weggooiend in het proces. Twee single-column-indexes hielpen niet, omdat Postgres er voor deze query slechts één tegelijk kon gebruiken.

De fix was een composite index in de juiste kolomvolgorde:

class AddPaidOrdersCreatedAtIndex < ActiveRecord::Migration[8.0]
  disable_ddl_transaction!

  def change
    add_index :orders, [:status, :created_at],
              order: { created_at: :desc },
              algorithm: :concurrently,
              name: "index_orders_on_status_and_created_at"
  end
end

Na de migratie:

Limit  (cost=0.43..142.21 rows=50)
       (actual time=0.087..1.243 rows=50 loops=1)
  Buffers: shared hit=58
  ->  Index Scan using index_orders_on_status_and_created_at on orders
        (cost=0.43..17012.18 rows=6000 width=237)
        (actual time=0.085..1.236 rows=50 loops=1)
        Index Cond: (status = 'paid'::text)

Tachtig milliseconden. Dezelfde data, dezelfde Rails-code. Het verschil was het plan lezen en zien dat twee single-column-indexes nooit gingen samenvallen tot het access-pattern dat deze query daadwerkelijk nodig had. Dit is hetzelfde principe achter een goede database indexing strategy — de index moet matchen met het access-pad, niet alleen met de genoemde kolommen.

Tools en Workflow voor EXPLAIN ANALYZE in Rails

Ruwe tekst-plans lezen is prima voor kleine queries. Voor echte gebruik ik een paar tools:

explain.dalibo.com — plak het plan, krijg een visuele boom met hotspots gemarkeerd. Alleen de Slow Node-detectie is de moeite waard.

pev2 — dezelfde engine die je zelf kunt hosten. Ik draai deze voor klanten die productie-plans om compliance-redenen niet naar een derde partij mogen plakken.

pgMustard — betaald, maar uitstekend voor engineers die nieuw zijn met query plans. Het legt uit waarom elke node is wat hij is, niet alleen wat hij is.

ActiveRecord .explain — prima voor development. Ik gebruik het zoals ik puts gebruik — snel, inline, nooit gecommit.

pg_stat_statements — de eerste stop in productie. Het aggregeert query-stats zodat je weet welke queries je überhaupt moet EXPLAIN ANALYZE’en. Combineer met je APM (Skylight, Scout, AppSignal) en je hebt een compleet beeld van waar de tijd in zit. Combineer met de discipline uit opentelemetry production observability en je kunt trage plans correleren met de daadwerkelijke requests waarin ze draaiden.

Valkuilen die Veel Rails Developers Raken

Een paar dingen waar mensen steeds over struikelen.

EXPLAIN ANALYZE draaien in development tegen een piepkleine dataset. Je dev-database heeft 2.000 users. Productie heeft 12 miljoen. De planner kiest compleet andere strategieën. Draai analyze altijd tegen een productie-vormige dataset, idealiter op een read-replica.

ANALYZE vergeten na een bulk-import. Postgres vertrouwt op statistieken. Als je net 5 miljoen rijen hebt geïmporteerd en nooit ANALYZE hebt gedraaid, denkt de planner dat de tabel leeg is en kiest hij slechte plans. Draai expliciet ANALYZE table_name na bulk-operaties.

Plan-kostengetallen vergelijken tussen queries. De kostengetallen zijn nuttig relatief aan elkaar binnen één query. Ze zijn niet vergelijkbaar tussen verschillende queries of verschillende machines. Gebruik daadwerkelijke tijd voor kruisvergelijking.

Elke kolom indexeren die de EXPLAIN-output noemt. Elke index vertraagt writes, neemt schijfruimte in en voegt onderhoudsoverhead toe. Voeg alleen indexes toe die een echt plan-probleem oplossen dat je waarnam in EXPLAIN ANALYZE.

EXPLAIN vertrouwen zonder ANALYZE. Kosten-schattingen kunnen er enorm naast zitten. Daadwerkelijke tijd niet. Als een query traag is, heb je EXPLAIN ANALYZE nodig, geen EXPLAIN.

FAQ

Wat is het verschil tussen EXPLAIN en EXPLAIN ANALYZE in Rails?

EXPLAIN toont het query plan dat Postgres zou gebruiken, zonder de query te draaien. Het is snel en veilig. EXPLAIN ANALYZE voert de query daadwerkelijk uit en rapporteert echte timing en rijaantallen naast de schattingen van de planner. Gebruik EXPLAIN voor snelle checks en EXPLAIN ANALYZE voor echte diagnose, maar draai EXPLAIN ANALYZE nooit op een UPDATE of DELETE buiten een transactie die je van plan bent terug te draaien.

Hoe draai ik EXPLAIN ANALYZE op een ActiveRecord query?

Roep .explain(:analyze, :buffers) aan op elke ActiveRecord-relatie in Rails 7.1+: User.where(active: true).explain(:analyze, :buffers). Voor meer controle kopieer je de SQL uit .to_sql en draai je EXPLAIN (ANALYZE, BUFFERS) <query> direct in psql tegen je productie- of staging-database.

Waarom gebruikt mijn query nog steeds een Sequential Scan nadat ik een index heb toegevoegd?

Drie veelvoorkomende redenen. Ten eerste: de tabel is klein genoeg dat Postgres terecht beslist dat scannen goedkoper is dan indexeren. Ten tweede: de kolom heeft lage selectiviteit — de meeste rijen matchen het filter, dus de index is nutteloos. Ten derde: de statistieken van de planner zijn verouderd en hij schat rijaantallen verkeerd. Draai ANALYZE table_name en check de Rows-schatting versus werkelijk in je plan.

Hoe lees ik Buffers-getallen in een EXPLAIN ANALYZE plan?

shared hit betekent dat de data-page in de shared-buffer-cache van Postgres zat (snel). shared read betekent dat hij van schijf opgehaald moest worden (traag). Hoge read-getallen op een vaak draaiende query betekenen meestal onvoldoende cache-geheugen, een ontbrekende index die extra page-scans veroorzaakt, of beide. Streef ernaar om vaak benaderde tabellen warm te houden in de shared buffers.

Hulp nodig bij het oplossen van trage Rails-queries voordat ze je team om 3 uur ‘s nachts wakker maken? TTB Software tuned Rails-Postgres-performance voor startups en scale-ups, van query plans tot indexes tot schema-ontwerp. We doen dit al negentien jaar.