Rails + PostgreSQL Performance Audit Playbook

| # Rails + PostgreSQL Performance Audit Playbook | | | A field-tested method for finding what's actually burning your database CPU, built for a | | | Rails monolith on managed PostgreSQL (Cloud SQL / RDS / etc.). It assumes no APM — just | | | pg_stat_statements, pg_stat_activity, and discipline. It pairs well with an LLM: point | | | one at this file plus your query results and let it do the attribution; the queries below | | | are ordered so a human can run them and paste results back. | | | ## The core idea | | | Your cloud console's query dashboard will not tell you what's wrong. Ground truth lives in | | | two places: pg_stat_statements (cumulative, per-normalized-query) and pg_stat_activity | | | (live, per-backend). The method is: establish the measurement window (A), read the chronic | | | top consumers (B/C), check what's happening right now (D–G), and when "chronic" and "now" | | | disagree, measure a delta window (H). Then map each expensive query family back to code and | | | fix the mechanism, not the symptom. | | | ## Why your cloud console lies | | | - Fingerprint fragmentation. Postgres 15 and earlier fingerprint every IN (...) list | | | length separately, and Rails' where(id: array) produces every length. One logical query | | | shatters into hundreds of rows (we measured 1,000+ shapes for a single table's lookups) — | | | no single row looks scary while their sum saturates the box. PG16's list-squashing helps | | | but doesn't cover everything. Query C below is the antidote. | | | - Short retention. Console per-query views typically keep ~7 days — you cannot | | | time-slice a regression older than that. Fingerprint "birth-dating" (below) substitutes. | | | - Utility statements are invisible. REFRESH MATERIALIZED VIEW, CREATE INDEX, | | | VACUUM get one queryid per object name (or aren't tracked at all, depending on | | | pg_stat_statements.track_utility) and never aggregate into a family. A materialized-view | | | refresh can be your single biggest CPU consumer and appear NOWHERE in the top-N. | | | - Only finished statements are recorded. A query that has been running for 12 hours | | | contributes zero to pg_stat_statements until it completes. Long-running work is only | | | visible in pg_stat_activity. | | | - Duration includes lock waits. In pg_stat_activity, a backend blocked on a lock still | | | shows state = 'active' with a growing duration. Always read wait_event_type: NULL = | | | genuinely on CPU; Lock = a victim queuing behind someone else. A huge duration can be | | | either the culprit or the queue behind it. | | | ## The queries (run in this order, on the primary) | | | ### A — measurement window (always first) | | | sql | | | SELECT stats_reset, now() - stats_reset AS window FROM pg_stat_statements_info; | | | | | | If the window is months long, B/C describe chronic load, which may not be today's problem. | | | Compute average busy backends: sum(total_exec_time)/1000 / extract(epoch from window) and | | | compare with current CPU (N cores pegged ≈ N busy backends). A large gap means today's mix | | | differs from the chronic top-N → rely on H. If the window is only days old, B/C haven't seen | | | a full weekly cycle yet — same conclusion. | | | ### B — top consumers with % share | | | sql | | | SELECT | | | round((100 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 1) AS pct, | | | calls, | | | round(mean_exec_time::numeric, 2) AS mean_ms, | | | round(total_exec_time::numeric / 1000, 1) AS total_s, | | | rows, | | | left(regexp_replace(query, '\s+', ' ', 'g'), 130) AS query | | | FROM pg_stat_statements | | | ORDER BY total_exec_time DESC | | | LIMIT 25; | | | | | | ### C — fragmentation detector (collapse by prefix) | | | sql | | | SELECT | | | left(regexp_replace(query, '\s+', ' ', 'g'), 60) AS prefix, | | | count(*) AS shapes, | | | sum(calls) AS calls, | | | round(sum(total_exec_time)::numeric/1000, 1) AS total_s | | | FROM pg_stat_statements | | | GROUP BY 1 | | | ORDER BY total_s DESC | | | LIMIT 25; | | | | | | High shapes + high total_s = IN-list fragmentation; that family is invisible in your | | | console's per-query view. | | | ### D — live wait profile (run 3–4× over ~30s) | | | sql | | | SELECT state, wait_event_type, wait_event, count(*) | | | FROM pg_stat_activity | | | WHERE backend_type = 'client backend' | | | GROUP BY 1,2,3 ORDER BY count(*) DESC; | | | | | | active + NULL wait_event = on CPU. Many of those on an N-vCPU box = CPU-bound queries | | | (not IO or locks). | | | ### E — maintenance and materialized views in flight | | | sql | | | SELECT pid, wait_event_type, wait_event, now()-query_start AS dur, left(query,80) AS q | | | FROM pg_stat_activity | | | WHERE pid <> pg_backend_pid() | | | AND (query ILIKE 'autovacuum:%' OR query ILIKE '%VACUUM%' OR query ILIKE '%ANALYZE%' | | | OR query ILIKE '%MATERIALIZED VIEW%'); | | | | | | The MATERIALIZED VIEW match exists because of the utility-statement blind spot above — | | | this is the only place a runaway refresh shows up. | | | ### F — dead-tuple / vacuum pressure | | | sql | | | SELECT relname, n_live_tup, n_dead_tup, | | | round(100*n_dead_tup::numeric/nullif(n_live_tup,0),1) AS dead_pct, | | | last_autovacuum, autovacuum_count | | | FROM pg_stat_user_tables | | | ORDER BY n_dead_tup DESC LIMIT 15; | | | | | | An outlier autovacuum_count on one table = write churn. The classic Rails cause is a sync | | | job rewriting rows to the same values (no-op writes still create dead tuples). | | | ### G — live sampler (run 4–5×, ~15s apart) | | | sql | | | SELECT now() - query_start AS dur, wait_event_type, wait_event, | | | left(regexp_replace(query, '\s+', ' ', 'g'), 130) AS q | | | FROM pg_stat_activity | | | WHERE state = 'active' AND pid <> pg_backend_pid() | | | ORDER BY dur DESC; | | | | | | Whatever keeps reappearing is what's on CPU right now. Ignore your replica's | | | START_REPLICATION row. Remember: NULL wait columns = working; Lock = queued victim. | | | ### H — snapshot diff (gold standard for "what burns CPU today") | | | Same session/tab, the temp table must survive between steps: | | | sql | | | -- Step 1: run now | | | CREATE TEMP TABLE pss_snap AS | | | SELECT userid, dbid, queryid, calls, total_exec_time | | | FROM pg_stat_statements; | | | | | | Wait ~10 minutes (leave the tab open), then: | | | sql | | | -- Step 2: exec-seconds consumed in the window, per query | | | SELECT round((p.total_exec_time - COALESCE(s.total_exec_time, 0))::numeric / 1000, 1) AS exec_s_10min, | | | p.calls - COALESCE(s.calls, 0) AS calls_10min, | | | left(regexp_replace(p.query, '\s+', ' ', 'g'), 120) AS q | | | FROM pg_stat_statements p | | | LEFT JOIN pss_snap s USING (userid, dbid, queryid) | | | WHERE p.total_exec_time - COALESCE(s.total_exec_time, 0) > 1000 | | | ORDER BY 1 DESC | | | LIMIT 30; | | | | | | Sanity check: 10 min × N saturated cores ≈ N×600 exec-seconds total. If the top-30 sums to | | | ~80–90% of that, the list explains the load. Anything new-today shows here even if invisible | | | in the cumulative totals. This diff is also independent of when stats were last reset. | | | ### I — targeted drill-down (template) | | | sql | | | SELECT calls, round(mean_exec_time::numeric,1) AS mean_ms, | | | round(total_exec_time::numeric/1000,1) AS total_s, | | | left(regexp_replace(query,'\s+',' ','g'),120) AS q | | | FROM pg_stat_statements | | | WHERE query LIKE '%<table_or_keyword>%' | | | ORDER BY total_exec_time DESC LIMIT 10; | | | | | | ## Automate the capture (optional but worth it) | | | Wire your cloud provider's "high DB CPU" alert to a webhook endpoint in your app that | | | enqueues a job running queries A–G read-only, writes them to one text file, uploads it to | | | object storage, and posts the link to Slack. Whoever is on call downloads the file and | | | pastes it plus this playbook into an LLM. Two bonuses: the dump is timestamped evidence from | | | during the incident, and two dumps N minutes apart are a free query-H — subtract the | | | total_s columns to get exec-seconds burned per family in the window, no temp table needed. | | | Guard the endpoint with an access key; keep every query read-only. | | | ## Incident-time attribution without APM | | | 1. Two dumps = a delta. As above. Families with huge chronic totals but ~0 Δ are | | | historical — fixes holding, not today's problem. Don't be fooled by a scary lifetime | | | mean_ms. | | | 2. A request-log table = your poor-man's APM. If you don't have one, build it: one row | | | per request with controller/action, db_duration, query counts, IP, user agent, referer, | | | indexed on time. It answers "which endpoint is burning the DB right now" and | | | "bot or organic?" (dozens of distinct residential IPs ≈ organic; one UA walking your | | | sitemap at dawn ≈ crawler). Query it on the replica so you don't load the pegged primary. | | | 3. Web vs background jobs. application_name distinguishes your web server from your | | | job workers: | | | sql | | | SELECT application_name, | | | count(*) FILTER (WHERE state='active' AND wait_event IS NULL) AS on_cpu | | | FROM pg_stat_activity WHERE backend_type='client backend' | | | GROUP BY 1 ORDER BY on_cpu DESC NULLS LAST; | | | | | | 4. CPU spikes at a fixed minute past the hour = cron. Find the crontab, note the minute | | | it fires and the queue it lands on, and remember your graph's sampling grid can shift the | | | apparent spike a few minutes later. The suspect list for an every-hour spike is closed: | | | only jobs scheduled every hour can be on it. | | | ## Interpretation heuristics | | | - Fingerprint birth-dating: calls ÷ expected-rate estimates when a query shape first | | | appeared. High total_s with few calls relative to the stats window = recent regression → | | | check git log around the inferred birth date. | | | - rows/call ratio: thousands of rows per call = a pluck/materialization that belongs in | | | SQL (MIN/MAX, COUNT FILTER, width_bucket) or a cache. | | | - 0 rows over millions of calls = a guard-clause bug. The recurring Rails pattern: bot | | | traffic yields a nil user/visitor/session, and a find_by(visitor: nil, ...) runs forever | | | matching nothing. Guard before querying. | | | - Mean creep: if a known query's mean rises across audits without a plan change, that's | | | box saturation stretching everything — a victim, not a culprit. Attribution rule: a 9× | | | mean rise with a 20× call-rate rise is a new traffic source; a 9× mean rise with flat | | | calls is contention. | | | - t0_r0/ t1_r0 column aliases in a fingerprint = Rails eager_load / | | | includes+ references. Check the call sites for group_by, .sample, .drop, [n] | | | on relations — each forces full materialization of the join. | | | - Query → code mapping sequence: grep distinctive SQL fragments, then scopes; check the | | | schema dump for indexes (grep 'ON public.<table>'); fan out one investigation per query | | | family, each returning file:line + mechanism + fix. | | | - Never trust a dev schema dump for extension types. If your dev DBs are built by | | | restoring a prod dump, extension-provided types (e.g. pgvector's vector) can degrade to | | | TEXT and their indexes silently vanish — and a schema file regenerated from that DB lies | | | to you. Verify column types and indexes against the production catalog | | | (pg_attribute/ pg_index), never the checked-in structure file. Same for storage | | | parameters (autovacuum flags, fillfactor). | | | ## Recurring root-cause patterns (what we actually keep finding) | | | Every one of these came out of a real audit; check your codebase for each: | | | - Cache keys derived from relation.cache_key (a hash of the full SQL with binds | | | inlined): any per-user/per-filter value in the relation fragments the key space → ~0% hit | | | rate → the cache exists but caches nothing, and the DB eats every render. | | | - Aggressively short cache-store timeouts (e.g. Redis read_timeout: 0.2): latency | | | spikes count as misses, so cache degradation becomes a DB recompute stampede — a feedback | | | loop that turns a wobble into an incident. | | | - No-op sync writes: integration jobs writing synced_at/status columns even when | | | nothing changed. Millions of dead tuples, autovacuum churn, WAL volume — for zero | | | information. Skip-if-unchanged guards are one line. | | | - counter_cache with an index on the counter column itself: every increment becomes a | | | non-HOT update (new index tuples + heap copy), and concurrent increments serialize on row | | | locks. Usually an EXISTS probe replaces the counter entirely. | | | - after_touch recalculation storms: a parent recalculating aggregates by all | | | children on every touch, amplified by batch jobs touching thousands of parents. Replace | | | with one set-based UPDATE and no_touching around bulk paths. | | | - Materialized view refreshes with no guard rails: refresh lists living in database | | | tables (invisible to code review), refreshed hourly with no statement_timeout, no | | | overlap guard, and non-CONCURRENTLY (ACCESS EXCLUSIVE lock — the next run queues behind | | | a stuck one forever). Give every refresh a per-object advisory lock (skip, don't queue), | | | a generous timeout, and version the view definitions in git. And check the refresh order | | | against the dependency chain — pipelines refreshed most-derived-first serve data that's | | | hours stale by design. | | | - Catch-all routes running expensive lookups before 404ing: a wildcard route segment | | | (get ":slug") that derives an expensive "is this valid" set on every request pays full | | | price for every crawler probe and dead link. Do the cheap unique-index lookup first; | | | compute the expensive validation only when the record exists. | | | - Unindexed lookups inside cron loops: a scheduled job iterating an external dataset | | | (spreadsheet, API export) doing one find_by per row against an unindexed column. It's | | | invisible at low volume and becomes a nightly CPU plateau as the dataset grows. Batch-load | | | with one where(col: ids) + hash lookup — and mind case-insensitive column types | | | (citext): a SQL match is case-insensitive, a Ruby hash key is not. | | | - Bot traffic amplifying all of the above. Check your request logs before blaming code: | | | sanctioned crawlers (search engines, AI bots you allowlisted) walking sitemaps and tag | | | pages at dawn produce load spikes that vanish during human peak hours. Edge-block or | | | challenge what you don't want; cache or cheapen what you do. | | | - The biggest systemic lever is usually replica routing. If your app has a same-sized | | | read replica idling at 15% while the primary serves 100% of reads, Rails' multi-DB | | | connected_to(role: :reading) around stateless public pages is worth more than any single | | | query fix. | | | ## Verifying a fix without breaking production | | | - Restore a recent prod dump locally. For each fix, reconstruct the OLD expression from | | | git show <baseline-sha>:<file> and compare against the NEW code on real data — compare | | | ordered id arrays, not booleans ("returns something" hides reordering bugs). | | | - Dev Rails.cache as a NullStore is a feature here: every fetch block executes, so the | | | comparison is cache-free. | | | - Any DB write during verification goes inside | | | transaction { ...; raise ActiveRecord::Rollback }. Never run job workers against a | | | prod-shaped DB — integration jobs will make real HTTP calls. | | | - Finish with a server-level HTML diff: run the old and new code against the same local | | | server and data, curl the affected pages, normalize per-request noise (csrf token, nonces, | | | profiler ids), and diff. Byte-identical output is the strongest "same results" proof | | | you can get without deploying. | | | - Watch for the classic behavior-drift traps: eager_load dedup vs array indexing, ORDER BY | | | tie groups (plan-dependent), LIMIT 1 without ORDER BY on duplicated keys (arbitrary row | | | → make it deterministic with .order(:id)), enum String-vs-Symbol comparisons, and | | | .presence/ group_by/ drop/ sample forcing full loads. | | | - Merged ≠ deployed ≠ applied. A merged migration isn't live until deployed; a | | | DB-side change (index, view definition) isn't live until someone runs it. Verify with the | | | catalog (pg_index.indisvalid, pg_matviews.definition), not with git. | | | ## Ops guardrails this method assumes | | | - pg_stat_statements installed and preloaded; reset it after a major traffic change (e.g. | | | blocking a heavy crawler) so the window describes the workload you actually have — archive | | | the final B/C first, the cumulative totals are gone forever otherwise. | | | - Statement timeouts on batch/cron connections. One runaway refresh or analytics query | | | should die and alert, not camp on a core for 12 hours. | | | - Every scheduled job's DB work bounded: batch lookups, skip-if-unchanged writes, | | | advisory-lock overlap guards. | | | - Alert → automated diagnostics dump (above), so every incident leaves evidence even if | | | nobody was watching. |