rodesia.org
Blog

Measure first: six slowdowns I found and fixed

Measure first: six slowdowns I found and fixed

Most time spent making code fast before anyone uses it is wasted. You don't know yet which part is slow, and the part you polish might be deleted next month. Knuth put it this way in 1974: "We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil."

The other 3% is real, though. Over the last two months I measured and fixed six slowdowns (and chased one false alarm) in my own projects (FolioPress, Pickadate, the Forestry control panel behind them, and MacIago). I posted them on X as an eight-part series. This is the whole series in one place, with the profiling, the numbers and the commits' worth of detail that didn't fit in a post.

1. Find out where the time goes before you touch anything

One evening rodesia.org took 10 to 40 seconds to load. The obvious reading was "the server is struggling", and the obvious move was to start rewriting things.

So I timed each hop instead. From the server itself, the origin answered in 36 ms. Cloudflare had every file cached (cf-cache-status: HIT). The site resolves to four Cloudflare anycast addresses, so I tried each one on its own:

getent ahosts rodesia.org
curl -so /dev/null -w '%{time_starttransfer}\n' \
     --resolve rodesia.org:443:<ip> https://rodesia.org/

Three of the four took 17 to 38 seconds. The fourth took 0.8 s, and other Cloudflare-hosted sites answered in 50 ms. Something between my ISP and those specific Cloudflare IPs was throttling traffic, and a few hours later it cleared by itself. A rewrite would have sped up the one component that was already fast.

The order I work in now:

  1. Make it work.
  2. Make it right.
  3. Measure it, hop by hop and function by function.
  4. Speed up only what the measurement points at.

2. Profile in production: a home page rendering 12 pages nobody saw

The German home page of foliopress.io cost about 0.3 s of CPU per view on the event loop, and about 1.5 s on the first hit after a restart. FolioPress runs one async worker per site, so while that page rendered, every other request waited.

I attached py-spy to the production process. Markdown rendering was 45% of the samples, about 300 SQL queries per request were another 30%, and most of the rest was Jinja compiling templates it had already compiled.

The Markdown time was the surprising part. The home page lists 12 other pages, and the code that prepares a page for a template rendered each one's full body to HTML. No theme ever displays those bodies on a list. The queries were mostly the same few lookups (site languages, domains, translations) asked again and again.

What changed:

  1. A page's rendered content is computed only when a template actually reads it.
  2. A request-scoped memo answers site settings and translation lookups once per GET. It's off for writes and cleared when settings change.
  3. Sandboxed Jinja environments are cached per theme search path. auto_reload still checks file timestamps, so edits made in the theme editor show up immediately.
  4. Markdown conversion is memoized, and theme.yml is parsed once per file version.

On a copy of the production database, the page went from 215 ms to 42 ms warm and from 407 ms to 49 ms cold. The root URL went from 74 to 22 ms. To make sure nothing else changed, I rendered 109 URLs before and after and diffed them. Byte-identical.

Before you make work faster, check that anyone needs it done.

3. Read the network panel: 13 MB of photos behind a closed dialog

Pickadate's create-event page lets you pick a background photo from a gallery of 24. The gallery lives in a <dialog> that stays closed unless you ask for it.

The template rendered all 24 images eagerly, at their stored 2048×2048, scaled down to 160 px squares. On a phone the page came to 13.4 MB over 36 requests, for a picker most visitors never open.

The fix:

  1. A 400 px thumbnail is generated next to each stored image on first request and cached on the persistent media volume. The full set went from 13.6 MB to 673 KB. Generating on demand means old images need no backfill and a missing thumbnail repairs itself; a startup script pre-generates them so no visitor pays for the first render.
  2. The gallery images use loading="lazy" with explicit width and height. Inside a closed dialog, the browser fetches nothing until it opens.

While the network panel was open I fixed two more things it showed. The public JS bundle imported all twelve Basecoat components when the public templates use two, so scripts went from 25.2 KB to 16.2 KB gzipped. A render-blocking Google Fonts request loaded a monospace font no template used, so it went too.

The page went from 36 requests to 8, with zero image bytes until the gallery opens. It looks exactly the same.

4. Paint cost: a live CSS blur on every repaint

Pickadate's invite card has a soft coloured glow behind it. I built it from the event's 2048 px photo with filter: blur(96px), scaled past the viewport.

WebKit re-ran that blur on every repaint of the page. Tapping a vote button, which only changes a background colour, took about 1.5 s per frame in Safari.

The first fix I tried was will-change, the usual hint to give an element its own compositing layer. It made no measurable difference, so I removed it.

The real fix was to stop asking the browser to blur anything. The server now makes a 192 px copy of the photo, blurs and tints it once per colour scheme, and serves it as a plain background image. If that copy can't be built, the page falls back to the live filter. Visually it's the same glow. The vote button went to about 0.3 s a frame.

Anything expensive that always produces the same result only needs to run once. Run it ahead of time and keep the output.

5. Make background jobs incremental: a rollup that redid all of history

Forestry, the control panel that runs FolioPress sites, pings every site all day and rolls those health checks up into one summary row per site per day.

The retention job was meant to summarize the newest day and prune old pings. Instead it re-rolled every stored ping every day. That table only grows, and the job ran on the asyncio event loop, so the whole app stalled for 1.6 s while it worked. Every request in flight waited.

Now the job knows which days are already rolled up and only processes new ones, with set-based SQL (one INSERT … SELECT … GROUP BY per day instead of a Python loop), one transaction per day and pruning in batches. While I was there, all the background loops moved their database work to worker threads with short-lived sessions that never stay open across a network call.

The stall went from 1.6 s to 0.1 ms. I ran the old and new versions on a copy of production data and compared the rollup tables. Identical.

The cheapest work to speed up is work you've already done.

6. Know everything your CDN does: bypassing it lost compression

My sites sit behind Cloudflare. One evening it added about 0.4 s to every request from Lisbon: the median was 0.86 s through Cloudflare and 0.43 s straight to the origin.

So I built a bypass. When Cloudflare's median stays 0.4 s slower than going direct for five minutes, the site's DNS records flip from proxied to DNS-only, and they flip back once Cloudflare is within 0.2 s of direct again. Pages got faster right away.

Two days later I found what I'd lost. Cloudflare had been compressing every response on the way out, and my apps never compressed anything themselves. With the CDN out of the path, the editor's JavaScript went out as 988 KB instead of about 300 KB on every cold load.

A quick way to check what your origin really sends:

curl -so /dev/null -H 'Accept-Encoding: gzip, br' \
     -w '%{size_download} bytes\n' https://example.com/app.js

Now the apps compress their own text responses, and static files are compressed once per path and ETag and kept in memory. The file stays small whichever path a visitor takes.

A CDN does more jobs than the one you put it there for. Before you route around it, list everything it was doing for you.

7. Ask it to do less: a Reversi engine searching 30% fewer nodes

You play MacIago in the browser. The moves come from a Rust engine on my server running alpha-beta search with iterative deepening: it goes one ply deeper at a time until it spends its node budget.

First I made it quicker. The board used to be an array of squares; now it's two bitboards, one bit per square for each player (144 bits, for the 12×12 board). Generating moves, flipping discs and finding stable discs all became a handful of bit operations. Same positions searched, 3 to 9 times faster, and the worst move on a Raspberry Pi went from 725 ms to 81.

Faster is useless if it plays differently, so a reference test runs the engine against the original 2008 engine on 4,851 positions. Same moves and same scores on every one.

Then came the cheap win. The hardest level had a budget of 500,000 nodes per move, about 0.6 s on one server CPU. I cut it to 350,000. It now takes about 0.4 s and still beat the level below it 20 games out of 20.

Past a certain depth, extra search buys a player almost nothing they can notice. The server notices every node.

Before you make something faster, try asking it to do less.

8. The checklist, and when to stop

Everything above in one list:

  • Is anyone waiting on this? If not, leave it alone.
  • Did you measure it? A hunch doesn't count. Time each hop, then profile in production with something like py-spy.
  • Fix the biggest cost first and ignore the rest for now.
  • Does this work need doing at all? My home page rendered 12 Markdown bodies no template showed.
  • Is it bigger than it needs to be? I sent 13 MB of 2048 px photos to a closed dialog.
  • Can you compute it once and keep the result? A pre-blurred image took a repaint from 1.5 s to 0.3 s.
  • Are you redoing finished work? An incremental rollup turned a 1.6 s stall into 0.1 ms.
  • Can it do less? The Reversi engine won 20 of 20 with 30% fewer nodes.
  • Is the output still the same? Diff the HTML, compare the tables, replay the reference positions.
  • Did something else get slower? Measure again, end to end.
  • Would anyone notice more speed? If not, stop and go build something.

The last one is the hardest for me. Speeding things up is fun, and there's always one more millisecond to shave off.