slowbench
RetrievalInferenceEvalsAgentsFindingsSeriesBenchmarksArchive
Inference8 min1,550 words

The GPU was not slow, it was waiting

CoreML made indexing three times slower. Utilisation said the accelerator was idle, and the cause was one padding setting.

Contents · 8 sections
  1. 1Idle is a different problem from busy
  2. 2What it was waiting for
  3. 3How to tell which kind of slow you have
  4. 4Two things that looked like fixes and weren't
  5. 5Why PyTorch users don't hit this
  6. 6The cost of the wrong mental model
  7. 7Where it ended
  8. 8What I take from it

Before I got Metal working, I tried the path that looked obvious: keep the ONNX runtime and let it dispatch to CoreML. One execution provider flag, no new code, hardware acceleration for free.

It was three times slower.

CPU execution provider     242s
ANE  execution provider    >360s, killed
GPU  execution provider    12min+, never finished

I spent a while assuming CoreML was just bad at this model. Then I looked at utilisation instead of wall clock, and the picture inverted.

Idle is a different problem from busy

CPU provider    CPU 800%   (all cores saturated)
ANE provider    CPU 145%
GPU provider    CPU  21%

The GPU run used 21% of one core's worth of CPU and produced nothing for twelve minutes. That is not a device struggling with a heavy workload. That is a device sitting still.

This distinction changed how I debug performance, so it's worth stating plainly: a slow run where the accelerator is saturated and a slow run where it's idle have nothing in common. The first is a capacity problem and you fix it with better kernels, smaller precision, more parallelism. The second is a plumbing problem, and none of those things help. You have to find out what the device is waiting for.

I had spent an afternoon on the first kind of fix for the second kind of problem.

Five steps of one batch through the ONNX CoreML embedding path. A batch of texts is padded to the longest sequence in that batch, so every batch is a shape CoreML has not seen: 312, 287, 341 tokens. CoreML runs the model split into 39 segments, and the batch crosses those boundaries in both directions on every batch. That crossing is the bottleneck and cost twelve minutes with the GPU at 21 percent CPU. A compilation cache of 654 files and 898 megabytes reported full reuse and changed nothing, because caching removes compilation and not the boundary. Setting with_static_input_shapes pushed work back to the CPU. Skipping ONNX and running the forward pass through candle on Metal took cold indexing from 294 seconds to 152 and CPU time from 1,736 seconds to 7

What it was waiting for

CoreML compiles a model into a plan specialised to specific input shapes. Give it a shape it has seen, and it executes. Give it a new one, and it recompiles that portion of the graph before it can run.

The embedding library pads each batch to the longest sequence in that batch:

PaddingStrategy::BatchLongest

Which means every batch has a different sequence length. Batch one is 312 tokens, batch two is 287, batch three is 341. Every batch is a shape CoreML has never seen.

So the run becomes: compile, execute briefly, compile again, execute briefly. The device is idle for most of the wall clock because it's waiting on the host to finish specialising the next variant. Twelve minutes of mostly compilation, with brief interludes of the work I actually wanted.

The library authors knew this was a limitation, in the general sense. There's a comment right next to the setting:

// TODO: the user should be able to choose

Nobody had wired that choice through. It doesn't matter for CPU execution, where dynamic shapes are free.

How to tell which kind of slow you have

The check is cheap enough to make a habit, and it points at completely different fixes depending on what it says.

# CPU time consumed versus wall clock elapsed
ps -o etime=,time=,%cpu= -p <pid>
 
# whether the Apple GPU is doing anything, no sudo needed
ioreg -r -d 1 -w 0 -c IOAccelerator | grep -o '"Device Utilization %"=[0-9]*'

Four combinations, and each means something different:

CPUGPUWhat it is
highhighgenuinely working, optimise the kernels
highlowthe accelerator isn't being used, dispatch is falling back
lowhighthe accelerator is saturated, the host is idle. Normal for a good GPU run
lowlowwaiting on something. Compilation, transfer, a lock

My CoreML run was the last row and I spent an afternoon treating it as the first. When both numbers are low, no amount of tuning the computation helps, because the computation is not what's taking the time.

For contrast, the Metal path that eventually worked sits in the third row: GPU at 99%, CPU at about 7 seconds across a run that takes 152. That's what the accelerator actually doing the job looks like.

Two things that looked like fixes and weren't

A compilation cache. ONNX Runtime lets you cache compiled CoreML models. I pointed it at a directory, ran once to populate it, and ran again.

Second run: identical time. The cache directory had 654 files and 898 MB in it, and the run reported 100% reuse.

Which makes sense in retrospect. The model was split into 39 segments at boundaries CoreML couldn't absorb, and the cost was never compiling those segments. It was the round trip across the boundary, every batch, in both directions. Caching removes compilation. It does not remove a boundary.

with_static_input_shapes. The name reads like "make the shapes static," which is exactly what I wanted. It isn't what it does.

It restricts CoreML to taking only the nodes that are already statically shaped. On a model whose inputs are dynamic, that means CoreML takes almost nothing and everything falls back to CPU. Setting it made the run more CPU-bound, not less.

Two hours on an option that does the opposite of what its name suggests. Reading the source was faster than reading the name.

Why PyTorch users don't hit this

Worth noting because it explains why the internet has little to say about it: PyTorch's Metal backend handles dynamic shapes natively. No recompilation, no segment boundaries, no cache to warm.

A related benchmark on this same machine, a Python embedding service through PyTorch MPS, was fast. Same hardware, same class of model, no issue at all. For a while that made me think my measurements were wrong, since clearly the GPU could do this.

The GPU could. The path through ONNX and CoreML could not, and the difference is entirely in how the two runtimes treat a shape they haven't seen before.

The cost of the wrong mental model

I want to be specific about where the afternoon went, because the wasted work was all reasonable-looking.

I tried smaller batches first, on the theory that memory pressure was causing thrashing. No change, of course, since nothing was computing.

Then quantisation, on the theory that int8 would move less data. No change, same reason.

Then I looked for a thermal issue, since the machine was cool and quiet during a supposedly heavy workload. That one at least was the right kind of suspicion (a cool machine under load means something isn't running) but I read it as "the accelerator is throttled" rather than "the accelerator is idle," and those lead to opposite investigations.

Every one of those experiments was a valid technique aimed at the wrong problem. What they had in common is that they all assumed the device was busy and I needed it to be more efficient. Fifteen seconds with a utilisation number would have ruled all three out before I started.

That's the transferable part. Not "CoreML has a dynamic shape problem", which is specific to one runtime on one platform and may be fixed by the time you read this. The transferable part is that you can spend a whole afternoon optimising a computation that is not happening.

Where it ended

I closed this path. Fixing it properly means forking the embedding library to offer fixed or bucketed padding, and at that point you're maintaining a fork of a dependency to work around a limitation of a runtime you didn't want in the first place.

What worked instead was skipping ONNX for this operation entirely: running the forward pass through candle on Metal, about two hundred lines. Same model, same weights, direct control of batching and padding. Cold indexing went from 294 seconds to 152, and CPU time from 1,736 seconds to 7.

The CoreML flags are still in the code, defaulted off, with a comment saying they lose. Negative results are worth keeping where the next person will find them.

What I take from it

The whole diagnosis turned on one number I collected after the wrong afternoon rather than before it. Utilisation says whether you have a capacity problem or a plumbing problem, and those want opposite responses. More parallelism helps the first and makes the second worse. I spent the afternoon on the first.

The other thing I would tell myself is to read the source for options whose names sound obvious. with_static_input_shapes cost me two hours because I trusted the name; the implementation is one function and I could have read it in a minute. And when a fix starts requiring a fork of a dependency, price it as an ongoing obligation rather than a fix. Going around that dependency turned out to be less code and much less future work than going through it.