# The benchmark said 27x faster. It felt worse.

URL: https://tuios.dev/blog/measuring-before-optimising

> Fixing pane resize lag in TUIOS with Go benchmarks and pprof. Two of four theories were wrong, and the benchmark measured the wrong thing for three rounds.

Dragging a [pane divider](https://tuios.dev/docs/bsp-tiling) in TUIOS trailed the mouse.
Worse the longer you dragged.

That last detail is the whole diagnosis, though I nearly skipped past it. A
uniformly slow frame feels the same at the start of a gesture as at the end.
Something that degrades as you go is a queue you are not draining fast enough.

## Backlog, not slow frame

Every mouse motion event composed a full frame. A frame during a tiling resize
costs 3.3 to 6.7 ms, which caps the drain rate somewhere around 150 to 300
events per second. A drag emits roughly one event per cell crossed, and a brisk
drag across a terminal easily outpaces that.

So the queue grows for the duration of the drag, and what you see is wherever
the pointer was some number of events ago. Stop moving and it catches up. That
is why it read as lag rather than as slowness. (A flooded pane
[fell behind the same way](https://tuios.dev/blog/drawing-the-backlog) later, with PTY output
in place of mouse events.)

The fix bounds redraws to one per frame interval. Every event's geometry is
still applied before the draw decision, so no input is dropped and the layout
still settles exactly where you released the button. Only the redundant
intermediate frames go.

*[An interactive figure goes here. Open the page to use it.](https://tuios.dev/blog/measuring-before-optimising)*

The difference is easier to feel than to read:

*[An interactive figure goes here. Open the page to use it.](https://tuios.dev/blog/measuring-before-optimising)*

## The tooling, and the flags that mattered

Go's benchmark support did most of the work, and the useful flags are not the
obvious ones.

```
go test -run XXX -bench BenchmarkResizeMotion -benchmem -count=5 ./internal/input/
```

`-run XXX` matches no test, so nothing but the benchmark runs. `-benchmem`
gives allocations per operation, which mattered more than nanoseconds in two
places below. `-count=5` runs the whole thing five times, and the spread across
those runs is the only thing that tells you whether a 15% improvement is real.
Absolute timings on this machine drift with thermal state, so anything I
compared had to be interleaved rather than measured an hour apart.

TUIOS wires up `net/http/pprof` behind a flag:

```go
if pprofAddr != "" {
    runtime.SetBlockProfileRate(10000) // one sample per ~10us blocked
    runtime.SetMutexProfileFraction(100)
    go func() { _ = http.ListenAndServe(pprofAddr, nil) }()
}
```

Block and mutex profiling are off by default in Go and cost real overhead when
on, which is why they sit behind the same flag instead of being always
enabled. They are sampled too, because recording every event made a `--pprof`
run feel much slower than a normal one. For a program that spends its life
waiting on PTY reads and holding locks, those are the two profiles that explain
anything.

> **Corrected 22 September 2026**
>
> An earlier version of this post showed `SetBlockProfileRate(1)` and
> `SetMutexProfileFraction(1)`. The code used those values for 25 minutes on
> the morning of 4 July, before this post was written. The snippet now shows
> the sampled rates it actually used.

## Four hypotheses. Two wrong.

I wrote them down before measuring, mostly so that being wrong would stay
visible afterwards instead of quietly evaporating.

**One: the whole-tree ratio sync is expensive.** It recomputes every split
ratio in the BSP tree on every motion event, which sounds bad. Measured at 6 to
86 us against a multi-millisecond frame. Roughly 1%. I would have spent a day
there.

**Two: damage tracking is doing nothing.** Mine, and wrong in a way that still
stings. I read a benchmark where the one-dirty case measured slightly slower
than all-dirty and concluded the tracking was dead weight. At one window,
one-dirty and all-dirty are the same case. Identical timings prove nothing. At
four and nine windows it does substantial work: 929 against 1343 us, and 737
against 1221 us. I had compared a thing to itself, written it down as
settled, and built the next hour of work on top of it.

**Three: the tick throttle is not helping.** True. `SlowTickCmd` governed the
periodic tick during a drag while motion events drove their own renders anyway,
so it lowered the ceiling without touching the flood. Removed.

**Four: PTY resizes are firing per event.** Not happening, and worth having
checked, because a `TIOCSWINSZ` per motion event would produce exactly these
symptoms. Confirming it was already deferred to drag completion cost one grep.

Two of four wrong is about my usual rate. That is the argument for writing them
down.

## Fixing the top cost promotes the next one

With renders coalesced, the handler still ran on every event, so it became the
new floor. That exposed a gap the old cost had been hiding.

*[An interactive figure goes here. Open the page to use it.](https://tuios.dev/blog/measuring-before-optimising)*

Allocations said it more bluntly: 10,665 B in 8 allocations against 57,238 B in
34, per event, at nine windows.

The culprit was `SyncBSPTreeFromGeometry` running on every motion event,
rebuilding a geometry map over every window and re-deriving every ratio in the
tree. Same medicine as the renders: defer the sync to the frame that actually
draws. The drag-completion sync stays unconditional, because a stale tree means
the next retile silently discards the user's resize. After the change, 7,215
and 7,278 ns at four and nine windows, flat again, back to 8 allocations.

A performance conclusion has a shelf life. Hypothesis one, correctly measured
at 1% of a frame, was the bottleneck an hour later, because I had removed
everything that used to dwarf it.

## The performance fix caused a rendering bug

Deferring the ratio sync meant the separator overlay could draw from tree state
that lagged the real window geometry. The overlay takes divider positions from
the tree and the highlight from live geometry, so mid-drag it drew the divider
where the drag had already left, in the unfocused colour, because that column
was no longer on the focused pane's perimeter.

It looked like a red afterimage trailing the cyan separator.

My first fix put the flush on the paths that change geometry, which is the
obvious place and the wrong one. Any frame composed for another reason bypassed
it, and `PTYDataMsg` composes constantly during a real drag, because the
terminals in the other panes are still producing output. That is why it showed
up all the time in use but needed interleaved PTY output to reproduce in a test.

The flush belongs in `View`, immediately before composing. Geometry can be
applied whenever, but the ratios have to agree with it on any frame that
reaches the screen.

Eighteen of twenty-four mid-drag frames wrong before, none after. Removing the
flush with the test in place fails twenty-four of twenty-four.

## Where micro-optimisation could not help

Two bugs where tuning the hot path would have been wasted effort.

### A quadratic behind a passing benchmark

Typing in the [browser client](https://tuios.dev/docs/web) was unusable. `getLine` walked the whole viewport
for every row, making a frame O(rows squared times cols).

No amount of constant-factor work closes a quadratic gap. It took three
changes, each of which promoted the next bottleneck:

| change                                 | Chromium      | Firefox          |
| -------------------------------------- | ------------- | ---------------- |
| reuse one view per viewport walk       | 6.3 to 1.3 ms | 11.64 to 3.32 ms |
| preallocated ring for getLine rows     | 0.3 to 0.1 ms | 2.24 to 0.34 ms  |
| read only the rows the VT marked dirty | 1.4 to 0.0 ms | 3.90 to 0.12 ms  |

Full repaint stayed at 11.5 to 11.2 ms through that last one, which is correct.
That path has no dirty rows to skip. A change that improved it too would have
meant I was measuring something else by accident.

An aside from the same stretch of work, because it wasted three runs before I
saw it. The browser test harness reused an already-running server when outside
CI, and the client assets are compiled into the Go binary. So a server left
over from an earlier build kept serving the previous client, and editing the
client then rerunning the tests exercised the old build, with nothing logged.
Three confident results about code that was never loaded. The harness now
rebuilds per run, and I trust "the test passed" a little less than I used to.

### A freeze no profiler would find

The multiplexer locked up within seconds of any command producing output.

The render path took a window's I/O read lock, then called a function that took
the same lock again. Go's `RWMutex` is not reentrant for readers. If a writer
queues between the two acquisitions, the second read blocks behind the writer,
the writer blocks behind the first read, and everything stops.

*[An interactive figure goes here. Open the page to use it.](https://tuios.dev/blog/measuring-before-optimising)*

There is no hot path to profile here. The program is not slow, it is stopped.
What finds it is `SIGQUIT` with `GOTRACEBACK=all`, reading the goroutine dump,
and spotting two frames of the same stack holding and wanting the same lock.
The fix was hoisting the cursor query above the lock.

There was also an optimisation I measured and threw away entirely: porting
correct grapheme width tables from ghostty-vt, which changed nothing because
cluster advance was never a per-codepoint question in the first place. That one
got [its own post](https://tuios.dev/blog/the-width-table-that-changed-nothing).

## What a benchmark cannot tell you

Later in the same work, shared-border drags still felt wrong. The benchmark
disagreed, emphatically. At nine windows a frame had gone from 8,981,357 ns to
326,214 ns across this work, which is 27 times faster, and the shared-border
path had improved more than the plain one.

Then I used it, and it felt worse. Not marginally. Worse than before I
started.

Three reasons the measurement could not see it.

Building an animation object is cheap. The cost was that panes never arrived at
the pointer, because each frame cancelled the previous animation and started a
fresh 300 ms ease toward a target that had already moved. Not arriving is felt,
never timed.

The daemon resize callback is nil under test. So 205 socket round trips per 30
frames cost a nil check in the benchmark and a real round trip in production.

And the benchmark drove motion into idle terminals, where coalescing made
almost every frame a cache hit. The layout reapply ran once in twenty motion
events under test. In use, with output flowing, it ran on every frame.

What found it was instrumenting the running program: log the pointer position,
the grabbed divider, and every window whose geometry changed, then do the drag
and read the log. One drag showed five windows moving where two should have,
one of them reversing direction twenty-two times. The benchmarks had been
accurately measuring the wrong thing for three rounds. That log turned up three
separate defects and one suspect that turned out to be correct behaviour, and
they got [their own post](https://tuios.dev/blog/one-divider-five-windows).

When the numbers and the experience disagree, the experience wins. The
benchmark is not wrong. It is answering the question you encoded, precisely,
and it has no opinion on whether that was the right question.