266 timeouts a night, one line in a function
For a while, the related-news panel on Statpro was quietly failing. Not every call, and never loudly: just statement timeouts, about 266 of them per 24 hours, all traced to one Postgres function. Here's the bug class, because it's a good one to know.
When your ORDER BY doesn't match your index
The function ordered results with published_at DESC, id DESC. In Postgres that means NULLs sort first. Our feed indexes were built DESC NULLS LAST. Mismatched null ordering sounds like trivia until you learn what the planner does about it: it can no longer walk the index in order, so it plans to materialize the whole join set, sort it, then hand you the first page. On one panel that meant roughly 45,000 buffer pages touched per call, and the verification predicates inside the join misestimated to one row, so the planner never saw the cost coming.
The rewrite is a reviewed custom-SQL migration. The comment at the top records the receipts:
-- prod saw ~266 statement timeouts (57014) per 24h. The prior body ordered by
-- published_at DESC, id DESC (NULLS FIRST) while the feed indexes are DESC NULLS LAST,
-- and the joined verification predicates misestimated to one row, so every call
-- touched ~45k buffers.Three moves in the new body
- Walk the index newest-first, so the plan is "stop when you have a page" instead of "sort the world."
- Verify each candidate with a per-row
EXISTS (... OFFSET 0), which stops early rather than validating the whole candidate set. - Bound the league window to a fixed number of rows, so the worst case is a known size.
What you can steal from this
If a query is slow in a way that surprises you, compare the ORDER BY's null ordering against the index's. It's a two-minute check. Also worth borrowing: the migration file keeps a plain-English receipt at the top, so six months from now nobody has to guess why the function looks like this.
That same night we split player game-log reads in two to dodge a related timeout, and scoped single-prop lookups to the prop's own lines. Same instinct: stop paying for rows you never show.
266 timeouts a night, one line in a function
For a while, the related-news panel on Statpro was quietly failing. Not every call, and never loudly: just statement timeouts, about 266 of them per 24 hours, all traced to one Postgres function. Here's the bug class, because it's a good one to know.
When your ORDER BY doesn't match your index
The function ordered results with published_at DESC, id DESC. In Postgres that means NULLs sort first. Our feed indexes were built DESC NULLS LAST. Mismatched null ordering sounds like trivia until you learn what the planner does about it: it can no longer walk the index in order, so it plans to materialize the whole join set, sort it, then hand you the first page. On one panel that meant roughly 45,000 buffer pages touched per call, and the verification predicates inside the join misestimated to one row, so the planner never saw the cost coming.
The rewrite is a reviewed custom-SQL migration. The comment at the top records the receipts:
-- prod saw ~266 statement timeouts (57014) per 24h. The prior body ordered by
-- published_at DESC, id DESC (NULLS FIRST) while the feed indexes are DESC NULLS LAST,
-- and the joined verification predicates misestimated to one row, so every call
-- touched ~45k buffers.Three moves in the new body
- Walk the index newest-first, so the plan is "stop when you have a page" instead of "sort the world."
- Verify each candidate with a per-row
EXISTS (... OFFSET 0), which stops early rather than validating the whole candidate set. - Bound the league window to a fixed number of rows, so the worst case is a known size.
What you can steal from this
If a query is slow in a way that surprises you, compare the ORDER BY's null ordering against the index's. It's a two-minute check. Also worth borrowing: the migration file keeps a plain-English receipt at the top, so six months from now nobody has to guess why the function looks like this.
That same night we split player game-log reads in two to dodge a related timeout, and scoped single-prop lookups to the prop's own lines. Same instinct: stop paying for rows you never show.