Measuring a GUI app without lying to yourself

What I learned

• A benchmark has to give the same answer twice. A realistic test that gives a different number every run can't tell me whether a change helped, because I have nothing steady to compare against.
• Take yourself out of the measurement. If measuring something needs me driving the app, I script the steps instead, even if the script is less true to life than a real session.
• Write down why the test does what it does. "120 thumbnails, because that's two screenfuls" is something someone can question. "120" on its own is just a number nobody understands.
• Measure memory as well as time. One function was responsible for 47% of the memory the app asked for, and none of my timing reports showed it. It mattered most in the browser version, where memory is tightest.

I spent a good while making the thumbnail grid faster. It was already fast, and nobody was waiting on it.

What people were actually waiting on was opening a RAW file. I'd never measured that, because measuring it properly was annoying and I had a hunch about where the time was going. My hunch was wrong.

Why I couldn't just use the app

The usual approach is to attach a profiler (a tool that records where the program spends its time), click around for thirty seconds, and read the chart it produces. That's fine for finding something badly broken. It didn't help me decide whether a change made things better, and that's the question I actually care about.

The problem is that I can't do the same thing twice. On the first run I scrolled a bit fast and reached row 40. On the second, row 31. On the first run the thumbnail cache was empty, and on the second it was full, because the first run filled it.

Running the code without the window

My fix was a command-line flag. --profile <folder> starts the app and runs the real code for listing the folder, loading photos, the catalog and thumbnails against that folder. Then it prints timings and exits. It never opens a window, so the UI library and the graphics card aren't involved.

It follows a fixed script. It lists the folder, fills thumbnails for 120 photos, which is about two screenfuls, then opens ten photos one after another, the way you do when stepping through a shoot with the arrow keys. Each of those numbers sits in the code with a comment explaining it. They're my guess about how people use the app, so I want that guess written down right next to the number.

The whole thing is about 230 lines. It's nothing clever. It just gives me the same number twice.

Keeping it out of the version you download

The timing code is attached to functions with small markers, and it's only switched on by two build settings that are off by default. With them off, the markers leave the function exactly as it was, so the release build carries none of it and the browser build doesn't get any bigger.

One detail caught me out. The profiling library has to be a normal dependency instead of an optional one, because the markers have to make sense to the compiler in every build, even when they do nothing.

The first report

I had been speeding up the wrong thing, and the report showed me in about four seconds.

It also pointed at a fix I'd never have found by reading the code. The app fetches the quick, low-quality preview of the next photo ahead of time, but not the slow, sharp version. So when you arrow through a folder of RAW files, you wait the full 200 ms every time, even though the app knew half a second earlier which photo you were about to look at.

The second report

The profiler can also count how much memory each function asks for, instead of how long it takes. One function was responsible for 12.0 MB out of 25.3 MB, 47% of all the memory the app asked for in that session. It was the function that hands thumbnails to the UI library to draw.

The cause was the way the UI library expects to be given images. Its image type can only be made by copying the pixels into fresh memory, even though the pixels were already sitting in the loader's cache in exactly the right layout. Writing them straight to the graphics card instead took that function from 12.0 MB to 0.16 MB, and the whole session from 25.3 MB to 13.4 MB.

Nothing was slow, and no user would ever have reported it. But in the browser build, the app runs as WebAssembly, and its memory never shrinks once it has grown. So memory the app only needed for a moment stays taken for as long as the tab is open.

The third report

On 200 photos with a warm cache, decoding all 200 thumbnails across 8 workers took 39.5 ms in total. Analysing one photo took 7.39 ms, so 1.48 seconds for the batch. The analysis runs on the main thread and can't be split across the processor's cores, so it costs about fifty-five times as much as the decoding.

My plan had been to make the decoding faster and to fetch it all ahead of time. Neither would have made any noticeable difference.