A production Rails application where deletes took seven minutes

The application manages orders and the work that fulfils them, across 65 tables with a closure-table hierarchy underneath, self-referencing foreign keys, and a set of database triggers that maintain denormalised columns and materialised views. It runs on Lambda behind an API gateway with a thirty-second response ceiling, which mattered more than it sounds: everything below was found because a request crossed that line and the browser reported a timeout while the function behind it ran on and committed its work anyway.

What was wrong

No single cause, which is the honest answer and the least useful one. What the work produced instead was a small number of shapes that kept recurring.

Loops that were doing per-row what one statement could do. The clearest case was a cascade delete that walked a tree and issued a destroy for every node. Deleting one template produced 133,973 statements and spent 387 seconds, of which 110,641 statements were automations, triggers, actions and conditions destroyed one row at a time. Collected into a single recursive statement, following the same closure the tree already had, the same delete ran in 8,724 ms and 3,099 statements — and the surviving statements were the real work rather than the overhead around it.

Queries whose cost was structural rather than volumetric. A delete that opened with a two-column OR was reading the same 67,138-element id array through a sequential scan twice; split into one statement per column it went from 21.4 seconds to 133 milliseconds, deleting the identical 136,292 rows.

Denormalised columns maintained on every write whether or not anybody read them. Every insert into the main table ran a recursive query over the whole tree to maintain two columns that had no readers at all. Removing the maintenance rather than optimising it took a row insert from 6.16 ms to 0.79 ms, and the gap widened with the table because the old cost was proportional to the table, not to the insert.

How it was found

The application had no APM, so the only slow-action detector in production was the request ceiling itself — which tells you something happened and nothing about where. The first piece of work was building the instrument: a per-request and per-job timing subscriber emitting one structured line per unit of work, gated behind an environment variable so it costs nothing when off.

That line changed the character of the work. Ranking candidates by measurement instead of by reading code repeatedly found that the parts everyone assumed were slow were not, and that the expensive thing was usually a callback nobody had looked at.

How it was verified

Every change was measured on a restored copy of production data, comparing the statement being replaced against its replacement in transactions that were rolled back, so both arms saw identical state. Each comparison ran a parity check asserting the two produced identical results — the same rows, or the same table checksum for a delete.

That discipline caught two things worth mentioning. It caught a performance “fix” whose two arms differed by seven times on a DELETE neither change touched, which meant the two arms had not started from the same state and the wall-clock win was not attributable. And it surfaced a pre-existing bug — a reparent that dropped closure rows — that had been sitting under a query everybody had been optimising around.

What I would tell the next person

The recurring lesson was that the plan is not the whole story and the count of statements often tells you more than the clock. Of the incidents here, the ones that mattered were not slow queries. They were ordinary ORM operations whose expense was in how many statements they issued, and none of that appears in any single query’s plan.