The Query Wasn't Slow. The Storage Was.
Keyword search on 170,000 news articles took up to 36 seconds. EXPLAIN ANALYZE pointed at the wrong thing. The fix was a narrow table, and search now answers in 29 ms.
contents (7)
Plus234Feed has a keyword search over its news archive, about 170,000 Nigerian articles. The website uses it, and so does an MCP server that lets AI assistants search the archive. Both call the same Postgres function, search_articles_ranked.
For a while it simply did not work for popular terms. Any word matching more than about 1,600 articles ran past the 8-second statement budget and failed. That was 17 of the 20 most common terms in Nigerian news, including Tinubu and Lagos. The words people search for most were the ones that broke.
This is how I found the cause, including the first diagnosis, which was wrong.
The function
Stripped down, the query looked like this:
select a.id, ts_rank(a.search_vector, q.tsq) as rank, count(*) over() as total_countfrom articles a, qwhere a.search_vector @@ q.tsq and a.deleted_at is null and a.is_publishedorder by rank desc, a.published_at desclimit 20;A GIN index finds the matching rows. ts_rank scores each one. count(*) over() gives the total for paging.
The wrong diagnosis
EXPLAIN ANALYZE showed about 9.2 seconds against the WindowAgg node, the one that computes count(*) over(). A window function over thousands of rows looked like a reasonable suspect, so I wrote that down as the cause.
It wasn’t. A plan node’s time includes evaluating the expressions its input produces, and ts_rank was sitting in that input. The window count was getting the blame for work done underneath it.
What settled it was measuring each piece on its own instead of reading the plan:
| Variant | Execution time |
|---|---|
ts_rank, no count(*) over() |
35,872 ms |
count(*) over(), no ts_rank |
1,100 ms |
Removing the count changed nothing. Removing the ranking took the query from 36 seconds to about 1. The problem was ts_rank, and the ranking maths itself is cheap, so the question became what it was waiting on.
The real cause: TOAST
Postgres keeps rows in fixed-size pages. When a row gets too big, it moves large values out of line into a separate TOAST table and leaves a pointer behind. Columns declared EXTENDED, the default for types like tsvector, are eligible to be moved.
The articles rows are wide. Each one carries the full article body, a detailed summary, and a 1536-dimension embedding stored uncompressed. So Postgres pushed the search vector out of line too. The table was 375 MB of heap against 2,396 MB of TOAST.
The index can find matching rows without reading the vector. ts_rank cannot: it needs the whole tsvector for every match. That meant one random TOAST read per matching row, and on a database with 512 MB of shared_buffers for 4.4 GB of data, most of those reads missed the cache. Each one cost roughly 21 ms.
The arithmetic matches. Dangote Refinery matched 1,626 articles. At 21 ms each, that is about 34 seconds, close to the 35.9 seconds measured.
The fix: a narrow table
The vector was not the problem. Where it lived was. So I copied it, with the few columns the query filters and sorts on, into its own narrow table:
create table public.article_search ( article_id uuid primary key references public.articles(id) on delete cascade, search_vector tsvector not null, published_at timestamptz, category text, source_name text, visible boolean not null default true);
alter table public.article_search alter column search_vector set storage plain;create index on public.article_search using gin (search_vector);STORAGE PLAIN keeps the vector in the table’s own pages. These rows carry nothing else bulky, so there is no reason to let them move to TOAST again. All 168,000 vectors come to about 210 MB, small enough to stay in cache.
A trigger on articles keeps the copy in sync. It copies the vector the existing trigger already built rather than recomputing it, so the field weighting (headline, summary, detailed summary, keywords) can never drift between the two tables. Deletes need no trigger: the foreign key cascades.
Then search_articles_ranked was repointed at the new table, with the same signature, the same ranking and the same ordering. Neither the website nor the MCP server needed a code change or a redeploy.
The results
Measured on production after the swap:
| Term | Matches | Before | After |
|---|---|---|---|
Dangote Refinery |
1,626 | 8.9 to 35.9 s | 29 ms |
Lagos |
15,001 | never completed | 125 ms |
Tinubu |
23,875 | never completed | fast |
Nigeria |
70,086 | never completed | fast |
Things I would do the same way again
Ship it in two steps. The first migration only added the table, the trigger and a backfill. Nothing that read data changed. The function swap was a separate migration with its own rollback script. Until the copy was complete, swapping would have made search quietly return fewer results instead of failing, which is the worst way for a search endpoint to break. So the swap waited until a reconciliation query returned zero missing rows.
Prove it returns the same results. Before production, I ran the old and new functions over eight query shapes (plain terms, filters, quoted phrases, or, paging, no match). Same rows, same order, same ranks.
Backfill with set-based SQL, not a cursor. My first backfill paged through articles by ID. That forces index-ordered reads, which means one random TOAST read per row: the exact cost I was migrating away from. It managed about 20,000 rows in several minutes. A single statement with a not exists anti-join reads the table sequentially, and it finished the remaining 163,000 in under a minute.
Write down the wrong diagnosis. The project notes had blamed the window function. I corrected them and recorded why the first reading was wrong, because a plausible wrong explanation is exactly the kind that gets acted on later.
What is still open
The embedding column has the same problem. It is stored uncompressed and out of line, about 1 GB of that TOAST table, and semantic search probably pays a similar cost. That is the next fix.
The general lesson is simple. When EXPLAIN ANALYZE points at a node, it tells you where time was counted, not always where it was spent. Take the query apart and measure each piece. Ten minutes of that would have saved me the wrong fix.