What Started This
At 9:13 in the morning, an import at work entered a step called something like "create or ensure provider and group requirement statuses." At 1:30 in the afternoon, it was still in that step.
So I did what any reasonable engineer does. I counted the rows in the table it was writing to.
80,416,756.
I waited five minutes and counted again.
80,416,756.
Not slow. Not a little behind. The exact same number, down to the row, from a job that was supposedly working. That step ended up running for 8 hours and 56 minutes. When I went back through the history, I found a night in July where the same step had run for 26 hours and 26 minutes and inserted exactly zero rows.
This is the story of the couple of weeks I spent finding out why, the fix we shipped, and the slightly uncomfortable realization at the end that the fix was treating a symptom.
The Plan
Written after the fact, like all the best plans.
- [x] Figure out if the import is stuck or just slow
- [x] Find out where the hours actually go
- [x] Measure the waste instead of guessing at it
- [x] Sell a stepping stone instead of a rewrite
- [x] Replay a real production import on a restored snapshot, old code against new
- [x] Prove the new code writes exactly the same rows
- [x] Ship it and compare production nights
- [x] Watch the biggest file go through the new code in production
- [ ] Give the big hash join the memory it keeps asking for
- [ ] Future proof solution (part 2)
The Scale, Because None of This Happens Small
Numbers first, because every questionable decision in this story is a perfectly fine decision at a smaller size.
| What | How much |
|---|---|
| Rows in the table this post is about | ~82 million |
| That table plus its four indexes, on disk | ~14 GB |
| Provider program memberships on record for our biggest customer | ~1.3 million |
| Requirements per program, on average | ~66 |
| Combinations the step generated, every night | ~86 million |
| Rows that actually needed inserting, most nights | 0 |
| Rows that actually needed inserting, busiest night of the month | ~2.2 million |
| How long the step took for that customer over a month | 34 minutes to 26 hours |
| Other big imports sharing the same Postgres instance that day | three |
Here's the trap. Hand the exact same code a customer with 50,000 combinations and it finishes in a few seconds. It passes code review. It passes every test. It runs happily for years and nobody thinks about it again.
The cost grows with memberships times requirements, and every individual lookup gets slower as the index outgrows the cache and the neighbors get louder. The useful work per night stays roughly flat. None of this is a bug you'd catch at small scale. It's a bill that only arrives at large scale.
The Shape of the Data
Every night we import data from our customers, and two pieces matter for this story:
- A membership file from the customer, one line per provider per program. A provider in three programs shows up three times.
- Program requirements, configured in the app: the requirements each program comes with. Our biggest customer has three programs with 198 requirements between them, so about 66 per program.
And then the table, requirement_statuses: one row for every provider, for every requirement of every program they're in, each with an active flag.
program memberships program_requirements requirement_statuses
(provider, program) x (program, requirement) = (provider, requirement, active)
~1.3M on record ~66 per program ~86M combinations
It's a fully expanded cross product, stored as real rows. Groups get the same treatment from a much smaller file of their own.
Here's the life of a row. The nightly import creates it, active, the first time a provider and a requirement meet: a new line shows up in the membership file, or a program adds a requirement. After that, the import leaves it alone. What changes it is a person. On a provider's page in the app (or a group's page), a user can exclude a requirement that doesn't apply to them, which sets that row to active = false. From then on, that requirement is excluded for that provider, and the nightly import must never undo that decision.
Almost every one of those rows says the same thing: active, never touched by anyone. Hold on to that thought. It's what part 2 is about.
I didn't write this code, and at the size it was built for, it was a reasonable design.
Imports Happen Next Door
One more piece of context, because it keeps coming back.
Every customer has their own Postgres schema, and that's what the app reads from all day. Imports never write to it directly. Each import creates a brand new import schema right next to it, copies over the tables it needs (data and indexes included, so yes, all 82 million rows of requirement_statuses), and does all of its work in there. Right before the import finishes, the import schema gets swapped in, and its tables replace the live ones.
Until that swap, nobody using the app sees a single change, and nothing outside the import ever touches the import schema. On the live side, the app also blocks certain write actions (not all of them) while an import is running. If it allowed writes on both sides, every import would have to merge whatever changed in the live schema into the import schema right before swapping it in. Blocking those writes sidesteps that merge entirely.
The import schema explains a surprising amount of this story: why every count I ran had to target the import schema instead of the live one, why nothing else could possibly be writing to that table mid-import, and why a failed import simply throws its import schema away. In the queries below, import_schema stands in for that night's actual schema name.
The Step That Ran All Day
Every night, a step makes sure the matrix is complete. Loading the membership file into a temp table takes a minute or two, because it streams in with COPY, which is about as fast as getting data into Postgres gets. Then comes the part that took all day. Here's the shape of it:
def call
with_temp_membership_table do # CREATE TEMP TABLE, then COPY the file in
next skip_empty_file! if temp_membership_table_empty?
analyze_temp_membership_table!
log_progress('STARTED', 'requirement status creation')
connection.execute(insert_every_combination_sql)
log_progress('FINISHED', 'requirement status creation')
end
end
def insert_every_combination_sql
<<~SQL
INSERT INTO requirement_statuses
(member_id, program_requirement_id, member_type, active, created_at, updated_at)
SELECT file.member_id, pr.id, #{connection.quote(member_type)}, TRUE, now(), now()
FROM #{temp_membership_table} file
JOIN programs p ON p.external_id = file.program_external_id
JOIN program_requirements pr ON pr.program_id = p.id
ON CONFLICT DO NOTHING
SQL
end
Looks harmless, and the intent makes sense. The step runs once for providers and once for groups (that's what member_type is), and each run has to add rows for any new combination without touching the rows that already exist, especially the exclusions people made by hand. So it tries to insert every combination and lets ON CONFLICT DO NOTHING quietly skip whatever is already there.
The whole story is in how that skip works. For every row the join produces, Postgres walks down the unique index on (program_requirement_id, member_id, member_type) to check whether that row already exists. If it does, the row gets thrown away and Postgres moves on to the next one.
On a typical night, almost every combination had already been created on some earlier night, so this step doesn't really insert anything. It generates all ~86 million combinations and asks the index, one at a time, "do you already have this one?" The answer was yes. Eighty-six million times in a row.
It's re-reading every folder in a filing cabinet, one at a time, every single night, to find the two folders someone added today. And most nights, nobody added any.
Stuck or Slow?
I didn't know any of that yet. All I had was a frozen row count. Here's what I learned about telling "stuck" apart from "slow" in Postgres.
A frozen count doesn't mean frozen work. The whole step is one INSERT statement, which means one transaction. count(*) only sees committed rows, and nothing commits until the very end. There was never going to be a moving number.
pg_stat_activity is the real answer. I ran this every few minutes for the rest of the day:
SELECT pid, wait_event_type, wait_event,
now() - xact_start AS xact_age,
left(query, 40) AS query
FROM pg_stat_activity
WHERE state <> 'idle'
ORDER BY xact_start;
Trimmed, the first sweep looked like this:
pid | wait_event_type | wait_event | xact_age | query
--------+-----------------+------------------+----------+------------------------------------------
124965 | LWLock | WALWrite | 05:37:49 | INSERT INTO requirement_statuses (member
134110 | IO | DataFileRead | 05:24:52 | INSERT INTO requirement_statuses (member
205759 | IO | DataFilePrefetch | 00:08:02 | ANALYZE ...
132948 | LWLock | WALWrite | 00:07:47 | CREATE UNIQUE INDEX ...
205705 | Lock | relation | 00:06:07 | ANALYZE ...
230393 | IO | DataFileRead | 00:02:30 | autovacuum: VACUUM ...
Reading it:
- pid 124965 is our step. One statement, five and a half hours old. Waiting on
WALWriteorDataFileReadmeans working, not blocked, and watching the wait event change between samples means alive. ALockwait that never changes would have meant blocked, which is a different day entirely. - pid 134110 is another customer's import, grinding through its own version of the same step.
- The rest is an index build, a queue of
ANALYZEs waiting on each other, and autovacuum. Four big imports were sharing this database that afternoon.
The table's size on disk is a progress meter. Uncommitted rows still get written into the table's files, so pg_total_relation_size grows even when count(*) doesn't:
SELECT now(), pg_total_relation_size('import_schema.requirement_statuses') AS bytes;
Five minutes apart, it grew by 216 KB. At roughly 190 bytes per row, indexes included, that's about a thousand rows in five minutes. The back of my envelope said this step had around 6.4 million new rows to write. At a thousand rows every five minutes, that's weeks.
That was the first real clue. The step wasn't spending its time writing. It was spending its time reading.
I did try to help. I paused a downstream job queue to take some load off the database, and nothing changed. I unpaused it, and things got worse. I paused it again, a pile of other jobs finished around the same time, and the write rate jumped about 200 times. I would love to tell you which of those did it. Several things changed at once, so I honestly can't. Killing the statement was never on the table either, because one transaction means one giant rollback and a full redo.
The Disk Wasn't Busy. That Was the Problem.
I spent that day pairing with Claude, pasting in pg_stat_activity output and screenshots of database metrics. Its first theory was a saturated disk: several imports hammering the same storage and starving each other.
Then I pulled up the metrics. 16,000 provisioned IOPS, and we were using somewhere between 1,000 and 3,000. CPU under a quarter of its limit. The database looked bored.
Both things turned out to be true, and the reason was the most useful thing I learned all week: this workload was limited by latency, not throughput.
One Postgres backend was running the entire statement, one lookup at a time. Each lookup is a walk down a b-tree with about 80 million entries, and every page that isn't already in memory is a random read. Do that serially and you top out at a few thousand lookups per second, which is exactly the modest IOPS the chart was showing. 86 million lookups at roughly 3,400 per second is about seven hours. The math wasn't mysterious. It was just slow.
The neighbors made it worse without ever maxing anything out. Every other import competes for the same buffer cache, so pages our step needed kept getting evicted and read back in. They all share one write-ahead log too, which is what that WALWrite wait was about.
And one more detail makes it worse still. The unique index leads with program_requirement_id, but the join hands out rows one provider at a time. Consecutive lookups for the same provider land in completely different parts of the index, so nearly every one is a fresh random read. The workload defeats its own cache.
Measuring Instead of Guessing
With a theory in hand, I wanted numbers instead of vibes.
What does "already exists" actually look like? I picked five providers created since the last successful import and counted their existing rows. A provider in all three programs would have 198:
existing rows: 0, 177, 198, 198, 0
Three different stories in five rows. Two providers had nothing, genuinely new. Two already had every row, most likely because the import had re-created their records under the same provider ID. And one had 177 of 198.
That 177 mattered a lot. It means programs gain requirements over time, and existing providers need rows for the new ones. Which quietly killed the obvious fix, the one we almost wrote up: "only process providers created since the last import." It would have been much faster, and silently wrong, skipping every existing provider in every program that added a requirement.
How many combinations, exactly? I couldn't count the step's temp table, because temp tables are private to the session that creates them. But the membership file also gets imported into a regular table, so the same join can be reproduced from any session:
SELECT count(*) AS candidates
FROM import_schema.program_memberships m
JOIN import_schema.program_requirements pr ON pr.program_id = m.program_id
WHERE m.member_type = 'Provider';
85,851,131. Measured, not estimated. That's about 1.3 million provider program memberships, each fanning out to the roughly 66 requirements of its program.
How many were actually missing? This is where I got humbled. Our first estimate, new providers times 198, said about 410,000. Then I counted it properly against that same imported table and got 5,678,128. When the step finally committed, I counted the rows it had really written, using created_at inside the step's time window: 2,176,589.
So the estimate was five times too low, and the careful measurement was two and a half times too high. The second miss had a boring cause: the imported program_memberships table keeps every line customers have ever sent, including lines they've since dropped from their file, so it over-counts compared to the file the step actually reads.
That same quirk explains why the table holds about 82 million rows and not 86 million. The step only creates rows for lines in the current file, so dropped lines never get rows. Even right after an import had filled in everything from the file, the same anti-join still found 3,501,539 combinations with no row. That's the gap.
Is this a one-off? I pulled a month of history for this step: how long each run took, and how many rows each run actually inserted. Our biggest customer's month, slowest first:
| Step started | Duration | Rows inserted |
|---|---|---|
| Jul 24 | 26.45 h | 0 |
| Jul 26 | 12.61 h | 302,291 |
| Aug 19 | 8.94 h | 2,176,589 |
| Jul 23 | 7.23 h | 0 |
| Jul 28 | 3.65 h | 0 |
| Aug 7 | 3.37 h | 0 |
| Aug 6 | 3.25 h | 0 |
| Aug 5 | 2.96 h | 0 |
| Aug 3 | 2.26 h | 0 |
| Aug 12 | 2.19 h | 200,641 |
| Aug 4 | 1.55 h | 0 |
| Jul 29 | 1.50 h | 0 |
| Jul 31 | 1.40 h | 0 |
| Aug 11 | 1.10 h | 0 |
| Jul 21 | 1.07 h | 0 |
| Aug 2 | 0.59 h | 0 |
| Aug 9 | 0.57 h | 0 |
Fourteen of seventeen runs inserted nothing. About 81 hours of step time in a month, 57 of them spent producing zero rows. The slowest run wrote nothing at all. Elsewhere on the same code path, a 35 minute run wrote 801,786 rows. Duration and rows inserted weren't just unrelated. They were close to inversely related.
Selling the Stepping Stone
When I brought this to my manager, the reaction was immediate and fair: this step is a long-known issue, and it gets expensive to upsert that many records, which usually comes down to having a lot of providers and a lot of requirements.
My suspicion going in was that the conversation would drift toward modeling this data differently. Which, honestly, is the right long-term conversation. Inserting fewer rows would help everything. It just wasn't a conversation that could be finished that week, and there was a smaller fix sitting right in front of us. So instead of arguing, I put the receipts in the ticket:
On our biggest customer the step ran up to 26 hours per import, with 14 of the last 17 runs inserting zero rows, and about 74 of 100 step hours across everything on this code path in the last month produced no inserts.
It became an exploratory ticket: implement the fix, benchmark it against a realistic snapshot, and evaluate the bigger ideas as a follow-up. A teammate picked up the implementation, and I took the review and the benchmarking.
The Fix: Stop Asking One Row at a Time
First, the ideas that didn't make it.
"Batch it." One of my first questions was whether batching the insert would help. For speed, not really. Batching 86 million lookups gets you 86 million lookups in smaller, more frequent doses. It does help with other things, which I'll get to.
"Only process new providers." Fast, and quietly wrong, thanks to that 177.
"Use UNION to deduplicate first, then insert." This one was mine, and the instinct was right: think in sets, not rows. The operator was wrong. UNION removes duplicates within a set, and our 86 million candidates were already mostly distinct from each other. The waste was candidates colliding with rows already in the table. That isn't deduplication. It's subtraction.
Subtraction in SQL is EXCEPT, the less famous sibling of UNION:
SELECT <candidate keys> FROM <the join>
EXCEPT
SELECT program_requirement_id, member_id, member_type FROM requirement_statuses;
That works, but the more common way to write it is an anti-join: left join the candidates to the table on the unique key and keep the rows where nothing matched. Same answer, and the planner gets more freedom in how to run it.
And how it runs is the entire point. Instead of 86 million random walks down an index, Postgres scans the existing table once, sequentially, builds a hash of its keys, and streams the candidates through that hash. Sequential reads move at the disk's full throughput. Random reads pay latency every single time. Same rows, different physics.
Here's the shape of the new version:
INSERT_BATCH_SIZE = 100_000
def call
with_temp_tables_cleanup do # drops both temp tables in an ensure
next skip_empty_file! if temp_membership_table_empty?
analyze_temp_membership_table!
log_progress('STARTED', 'requirement status creation')
create_missing_statuses_table
insert_missing_statuses_in_batches
log_progress('FINISHED', 'requirement status creation')
end
end
def create_missing_statuses_table
connection.execute(<<~SQL)
CREATE TEMP TABLE missing_statuses AS
SELECT row_number() OVER (ORDER BY program_requirement_id, member_id) AS row_no,
member_id,
program_requirement_id
FROM (
SELECT DISTINCT file.member_id, pr.id AS program_requirement_id
FROM #{temp_membership_table} file
JOIN programs p ON p.external_id = file.program_external_id
JOIN program_requirements pr ON pr.program_id = p.id
LEFT JOIN requirement_statuses existing
ON existing.program_requirement_id = pr.id
AND existing.member_id = file.member_id
AND existing.member_type = #{connection.quote(member_type)}
WHERE existing.id IS NULL
) missing
SQL
connection.execute('CREATE INDEX ON missing_statuses (row_no)')
end
def insert_missing_statuses_in_batches
missing_count = connection.select_value('SELECT count(*) FROM missing_statuses')
batch_count = missing_count.fdiv(INSERT_BATCH_SIZE).ceil
batch_count.times do |batch_index|
lower_bound = batch_index * INSERT_BATCH_SIZE
connection.execute(<<~SQL)
INSERT INTO requirement_statuses
(member_id, program_requirement_id, member_type, active, created_at, updated_at)
SELECT member_id, program_requirement_id, #{connection.quote(member_type)}, TRUE, now(), now()
FROM missing_statuses
WHERE row_no > #{lower_bound} AND row_no <= #{lower_bound + INSERT_BATCH_SIZE}
SQL
log_progress('IN_PROGRESS', "batch #{batch_index + 1} of #{batch_count}")
end
end
A few details that earn their place:
WHERE existing.id IS NULLlives inside theCREATE TABLE AS. If you instead store every candidate with amissingflag and filter it later, congratulations, you've materialized all 86 million rows in order to keep two million of them. It's an easy one to slip into while refactoring, so it's worth saying out loud.row_number()is ordered by the unique index's key. Batches insert in index order, so each new entry lands right next to the previous one. The old lookups were close to worst case for the cache. These are close to best case.- No
ON CONFLICT. That one gets its own section further down.
Why always take the new path, instead of only when the waste is high? I asked exactly that: could we detect the waste ratio up front and switch strategies when it's bad? It turns out the anti-join is never meaningfully worse:
| The night looks like | Old: check every candidate | New: anti-join first |
|---|---|---|
| Mostly new rows (a brand new customer) | about the cost of the inserts | about the cost of the inserts, plus one extra sequential pass |
| Mostly existing rows (our biggest customer, every night) | 86 million random lookups, a lost working day | a sequential pass, plus only the real inserts |
When nearly everything is new, the old lookups aren't wasted, they're just the first half of inserting each row. When nearly everything already exists, they're pure waste. The new path's worst case is one redundant pass. Its best case is a working day back. A switch between the two would be one more code path and one more knob, in exchange for nothing.
And batching? Claude originally sold batching partly as crash recovery: committed batches survive a failure, so a rerun picks up where it left off. True of Postgres in general, and false here. Our import jobs don't retry, and a failed import throws its entire import schema away, committed batches and all. There's nothing left to resume. The reasons that actually hold up:
- Short transactions. A transaction that runs for 8 hours stops vacuum from cleaning up any row that died after it started, anywhere in the database, for all 8 hours. On a database already busy with four imports.
- Progress you can see.
batch 14 of 22beats inferring signs of life frompg_total_relation_size. - Insurance for the heavy tail. On a normal night batching barely matters. On the night programs add a pile of new requirements, it's the difference between a bounded, observable process and a repeat of the day that started all this.
The Replay That Didn't Impress Anyone
Benchmarking on production data without touching production took some setup:
- Restore a production backup from just before the August import onto a beta database.
- Pull the exact versions of that night's input files. Bucket versioning made this possible, and copying a 29 GB file between buckets took two and a half minutes, which felt illegal.
- Deploy the branch. Discover, by way of a stack trace, that the deploy had dutifully run its migrations against a different database than the one I'd just restored. Run them against the right one.
- Run the full import once on the old code, restore again, then run it once on the new code.
The results:
| Beta replay, same snapshot, same files | Step duration |
|---|---|
| Old code | 46 min |
| New code, first cut | 41 min 51 s |
I'd been expecting a lot more than five minutes back.
A Quiet Box Can't Show You the Disease
Look at the old code's number again, though. 46 minutes. In production, the exact same import on the exact same code took 8 hours and 56 minutes, and production's database is the bigger machine.
Same code, same data, and almost twelve times slower with neighbors. On a quiet box, 86 million random lookups are merely slow. On a busy shared database, the cache pages each lookup needs keep getting evicted, and the same work stretches into the evening. Sequential scans don't fall apart like that under load. They share the throughput and slow down gradually. That's the whole reason this fix should matter most in production, and it's exactly the thing a quiet benchmark box can't show you.
So the replay mostly proved something I hadn't set out to test: most of production's pain was contention multiplying a random IO workload. Fine. But 41 minutes still bugged me.
Where the 41 Minutes Went
My next theory was a bad query plan. Maybe the planner had no statistics on the big table, picked a nested loop, and faithfully rebuilt 86 million index lookups inside the new query. A good theory, dead in two queries: autovacuum had analyzed the table seven hours before the step ran, and EXPLAIN showed the hash join I wanted.
So I ran the same anti-join with EXPLAIN (ANALYZE, BUFFERS) against the replay's import schema, which was still around because the import itself was busy with later stages. Trimmed:
Gather (actual time=173531.969..691984.802 loops=1)
Workers Launched: 2
Buffers: shared hit=192 read=949144, temp read=1097289 written=1102100
-> Parallel Hash Left Join (actual time=172967.216..647613.762 loops=3)
Hash Cond: ((pr.id = existing.program_requirement_id) AND ((m.member_id)::text = (existing.member_id)::text))
Filter: (existing.id IS NULL)
-> Hash Join (actual time=1.369..4609.778 rows=28617044 loops=3)
Hash Cond: (m.program_id = pr.program_id)
-> Parallel Hash (actual time=101374.685..101374.685 rows=27449864 loops=3)
Buckets: 262144 Batches: 512 Memory Usage: 13472kB
-> Parallel Seq Scan on requirement_statuses existing (actual rows=27449864 loops=3)
Execution Time: 692137.511 ms
Reading it:
- Generating all ~86 million candidates took under five seconds. Three processes, about 28.6 million rows each. The thing the old code spent hours on, enumerating combinations, was never the expensive part.
Batches: 512is the headline. The hash of ~82 million existing keys didn't fit in memory, so Postgres split it into 512 batches on disk.temp written=1102100is counted in 8 KB pages. That's roughly 9 GB of temporary files written and then read back.- The whole query took 11.5 minutes, and most of that looks like the spill.
Why so little memory? Because that's what the database was configured with, which is sensible for a database serving lots of connections and not at all sensible for this one query:
SHOW work_mem; -- 20MB
SHOW hash_mem_multiplier; -- 1
SHOW max_parallel_workers_per_gather; -- 2
A parallel hash join gets roughly work_mem × hash_mem_multiplier × (workers + 1) to work with. That's 20 MB × 1 × 3, so 60 MB for a hash that wanted something like 6 to 7 GB.
I found the other half of the time without any logs, using a trick I really like. Each batch stamps now() at the start of its own transaction, so the inserted rows are their own timeline:
SELECT member_type, count(*),
min(created_at) AS first_batch,
max(created_at) AS last_batch
FROM import_schema.requirement_statuses
WHERE created_at >= '<when the step started>'
GROUP BY member_type;
| Phase | Duration |
|---|---|
| Load the file, anti-join into the temp table | ~21 min |
| Insert 2,176,589 rows in 22 batches | ~21 min (about 1,700 rows per second) |
| The small group file, start to finish | seconds |
For that small file, by the way, EXPLAIN showed the planner choosing plain index lookups instead of a hash. Which is exactly right at that size. Lookups aren't evil. Eighty-six million of them are.
Half the time in the anti-join, half in the inserts. Two halves, two changes.
Change One: Give the Hash Its Memory
work_mem can be set per session, so this doesn't need a database-wide change. On a production database with hundreds of connections, a global bump is how you invite the OOM killer to dinner. Roughly this shape, with numbers sized for the real box:
def with_large_hash_budget
connection.execute("SET work_mem = '1GB'")
connection.execute('SET hash_mem_multiplier = 2.0')
yield
ensure
connection.execute('RESET work_mem')
connection.execute('RESET hash_mem_multiplier')
end
Two notes. First, plain SET lasts for the whole session, and pooled connections outlive jobs, so the RESET has to live in an ensure or the next job on that connection inherits a 1 GB work_mem. SET LOCAL resets itself, but only at the end of a transaction, and every execute here is its own transaction. Second, a lesson I learned the fun way: I tested the settings in my own SQL session, disconnected, and watched them quietly revert. Session settings die with the session.
And don't copy my numbers. Do the multiplication for your own box, then multiply again by how many imports can reach this step at the same time.
This one hasn't shipped yet. It matters most on nights with the big provider file.
Change Two: Delete the Safety Net
The first cut of the new code kept ON CONFLICT DO NOTHING on the batch inserts, "just in case something else writes the same row between the anti-join and the insert." So I asked the obvious question: what else, exactly?
Remember the import schema. Nothing outside the import touches it, and only one import runs per customer at a time. Between the anti-join and the insert, nothing else can write to that table. The guard was guarding against nobody.
And it wasn't free:
- It costs an extra lookup per inserted row.
ON CONFLICTchecks the unique index before inserting, and then the insert walks the same index again to place the new entry. On the beta box every row cost about 0.58 ms, spread across five or six index walks, so dropping one of them is a real slice of the insert phase. - It hides bugs. If the anti-join ever grows a logic bug that produces a duplicate,
ON CONFLICT DO NOTHINGswallows it silently and the bug lives forever. Without it, the unique index raises an error and fails the import loudly, at the exact moment the bug happens.
The correctness checks in the next section prove the anti-join finds the right rows today. The bare insert makes sure nobody quietly breaks that later. That's the pair I want: tests for now, a loud unique index forever.
Things That Won't Make Inserts Faster
I asked about every one of these. Saving you the trouble:
COPY. It's the fastest way to get rows into Postgres from a client. Our rows were already inside Postgres, moving from one table to another in a single server-side statement.COPYwould mean exporting them just to stream them back in.- Multi-row
INSERT ... VALUES. Each batch is already one statement inserting 100,000 rows.VALUESlists fix the problem of one statement per row, which we didn't have. - Fewer, bigger batches. I worried that 22 batches meant 22 expensive index updates on an 82 million row table. That's not how b-trees work. Index maintenance happens per row, as each row goes in. Inserting 2.2 million rows means about 2.2 million new entries per index, whether that happens in one statement or twenty-two. The batch count costs a few extra commits, which adds up to seconds.
- Dropping the secondary indexes and rebuilding them afterwards. This one is real, just not yet. It's only an option at all because nothing outside the import reads the import schema, so an index can go missing for twenty minutes without anyone noticing. Incremental inserts pay retail per new entry. A rebuild pays wholesale, but for every entry in the table. With 2.2 million new rows against 82 million existing ones, under 3%, incremental wins easily. The rule of thumb we landed on: think about it once the new rows are over roughly 20% of the table. The code already knows the missing count before it inserts anything, so it's a clean branch to add the day it's needed.
The pattern behind all four: every bulk loading trick speeds up delivering rows to Postgres. None of them can skip the per-row index work that happens after delivery.
Proving It Writes the Same Rows
A faster step that writes different data is a very efficient way to ruin somebody's week. After each replay I ran the same four queries against the final table. The last one is my favorite:
SELECT count(*) AS row_count,
sum(hashtext(program_requirement_id::text || '|' || member_id || '|' || member_type)::bigint)
AS key_digest,
sum(hashtext(program_requirement_id::text || '|' || member_id || '|' || member_type)::bigint)
FILTER (WHERE active) AS active_digest
FROM requirement_statuses;
Every row's business key gets hashed into a number, and all 82 million numbers get added up. Addition doesn't care about order, so two tables holding the same set of rows produce the same sum, no matter how or when the rows were inserted. One missing row, one extra row, or one different key moves the total. id and the timestamps are deliberately left out, because those legitimately differ between runs. The other three queries (totals, counts per requirement, distinct members) are there so an accidental cancellation would have to fool all four at once.
Old code and the first cut of the new code, same snapshot, same files:
row_count | key_digest | active_digest
-----------+---------------+---------------
82593345 | -415383459249 | -415383459249
Identical in both runs, down to the last digit.
One caveat: hashtext is an internal Postgres function, not a documented API, and its output can change between major versions. It's perfect for comparing two runs on the same server. Don't save the digests and compare them next year.
And look at the last two columns again. active_digest is equal to key_digest. We'll come back to that.
Production
The new code shipped with the bare insert and without the memory settings. Here are three nightly imports for the same customer, all with similar input: the worst night of the summer, the last night before the deploy, and the first night after it.
| Nightly import | This step | Whole import |
|---|---|---|
| July 24, old code (the worst one) | 26 h 26 m | 30 h 59 m |
| September 3, old code (the night before the deploy) | 2 h 43 m | 9 h 45 m |
| September 4, new code (the first night after) | 4 m 42 s | 4 h 47 m |
A few honest notes:
- The step went from 2 hours 43 minutes to 4 minutes 42 seconds overnight, about 35 times faster. The whole import went from 9 hours 45 minutes to 4 hours 47 minutes. This step accounts for about 2 hours 39 minutes of that difference. The rest came from later stages having a better night, and I'm not going to claim it.
- That July number is not a typo. The whole import took almost 31 hours, and this one step was 26 and a half of them, to insert nothing. I can't fully reconstruct that night. My best explanation is the same neighbor problem we watched live, turned all the way up.
- It's one night after the deploy, which makes it a very good data point and not yet a trend.
Turns Out the Data Model Matters After All
Here's the thing that kept nagging me through all of this.
Every fix above makes the step better at maintaining 82 million rows. None of them asks why there are 82 million rows.
Think about what that table actually knows. The membership file says which provider is in which program. The program configuration says which requirements each program has. Multiply those together and you've derived every row in the table, for free. The only thing in requirement_statuses that can't be derived from those two is which rows a human deliberately excluded.
Now go back to that digest. active_digest equal to key_digest means every single row is active. On our biggest customer, in that snapshot, that's 82,593,345 rows and not one exclusion. Every one of them restates a default we could have computed. And at the start of every import, all 82 million of them get copied, indexes included, into the import schema, just so the step can check them all again.
That's where my manager's first reaction was pointing. It really does come down to having a lot of providers and a lot of requirements. I was right that the hours were going into lookups rather than inserts. The data model is the reason there were 86 million lookups to do in the first place.
So the first question for part 2 is how many rows, across every customer, a human has ever actually excluded. Automated writes set created_at and updated_at in the same transaction, while a human excludes a row later, so the timestamps tell them apart:
SELECT member_type, count(*) AS excluded_by_a_human
FROM requirement_statuses
WHERE NOT active
AND updated_at > created_at + interval '5 seconds'
GROUP BY member_type;
Which brings me to where this is going. Part 2 deletes requirement_statuses.
In its place goes a small table holding only the exclusions, the rows someone deliberately switched off. "Does this requirement apply to this provider?" stops being a row you look up and becomes an answer you compute: the provider is in the program, the program has the requirement, and there's no exclusion for it. The nightly step doesn't get faster. It stops existing. So does the 177 of 198 problem, because a requirement added to a program applies to every provider in that program the moment it exists. And nothing that big gets copied into an import schema ever again.
Part 1 already holds a strong hint that computing the answer is cheap. Remember that generating all ~86 million combinations took under five seconds? And the 512 batch spill came from hashing 82 million existing rows. An exclusions table is small enough to hash in memory.
There's a tempting middle option: only process the changes. Keep the big table, but instead of rediscovering what changed every night, insert exactly what the import already knows is new: new providers, new membership lines, requirements added to existing programs. It even made the original ticket as the follow-up idea. It also keeps all 82 million rows around, and it only works if every source of change is accounted for, because a missed one quietly leaves holes. Part 2 covers why I'm passing on it.
The hard part of storing only exclusions is everything that reads this table today. Every one of those readers has to be re-validated against the new shape, and that is not a short list.
What I Learned
Scale is the whole story. The same code costs seconds at 50,000 combinations and a working day at 86 million. If you only ever test small, you will ship this, and it will be fine for years.
ON CONFLICT DO NOTHING is a duplicate filter with a per-row price. Great when most rows are new. Brutal when most rows already exist, because it checks them one random index lookup at a time.
Count before you write. Two set-based counts, candidates and missing, would have predicted the entire lost day in a few minutes.
Low IOPS doesn't mean the disk is fine. A single backend doing serial random reads is limited by latency, and the metrics will look relaxed the entire time.
A quiet test box is a polite liar. The old code took 46 minutes alone and almost 9 hours with neighbors. Benchmark the mechanism with EXPLAIN (ANALYZE, BUFFERS), not just the stopwatch.
Batches: 512 is Postgres asking for memory. Do the work_mem × hash_mem_multiplier × processes math before blaming the query.
Prove equality with a digest, not a count. Counts catch "different amount." Digests catch "same amount, different rows," which is the dangerous one.
Measure, then measure your measurement. Our estimate was five times too low, and our careful proxy was two and a half times too high. That's why every number in the ticket carries a note saying how it was measured.
Fixing the algorithm buys time. The data model sends the bill. We got hours back every night. We're still storing 82 million rows to remember, on our biggest customer, zero human decisions.
What's Next (Part 2)
- Run the census across every customer: how many rows has a human ever excluded? That number is roughly the size of the exclusions table.
- Watch the big provider file go through the new code in production, and land the memory settings before it does, because the big table isn't going anywhere until part 2 ships.
- Explain why "only process the changes" lost.
- Find every reader of
requirement_statusesand re-validate each one against the new shape. - Delete a table with 82 million rows in it, which is the fun kind of scary.
Featured Image Prompt
I used this prompt to generate the featured image.
A vast, dimly lit archive hall stretching to the horizon, lined with endless identical filing drawers, each stamped with the same small green checkmark. A lone small robot holding a flashlight opens one drawer at a time, while on a desk in the foreground a clipboard labeled "new today" shows a nearly empty list next to a stethoscope. Cool blue server room lighting mixed with the warm amber glow of a desk lamp, faint glowing grid lines across the floor like rows in a database table. Cinematic, moody tech aesthetic, photorealistic, 16:9 aspect ratio.