Exp 2026 10 09 Colsplit Whole Buffer Cache Maintenance - oRKLLM/ork-driver GitHub Wiki

Exp-2026-10-09 โ€” the colsplit's fixed per-call cost was whole-buffer cache maintenance

Board 10.3.0.236, kernel 6.1.115-vendor-rk35xx-fence. Governors verified before every timing: DDR performance @2112 MHz, cpu4..7 performance @2.4 GHz. Workload: tools/train_tiny_e2e.c, one full forward+backward+AdamW step of a full-size Qwen3.5-0.8B hybrid (24 layers, 18 GDN + 6 attention, d=1024, ffn=3584, vocab=248320), B=1 T=1024, --gdn cpu, taskset -c 4-7, OMP_NUM_THREADS=4. Continues Exp-2026-10-09 fp16 K-Slice and the Training Step ยง6, which found this cost and left it unattributed.


1. The open item

r105 measured a fixed ~24 ms per ork_f16_mm_run call that the 3-core colsplit path pays and the single-core path does not, independent of shape โ€” enough that one NPU core beat three by 1.49x end to end (30.1 vs 44.9 s/step) and by 7.8x on attention. Three suspects were named, none confirmed: the A gather, three pthread_create/join per call, and the single-threaded Sk==1 copy-back.

2. The attribution

ORK_CS_PROF=1 (new, src/npu/core/prof.c + timers in colsplit.c/dyn_ctl.c) times one ork_dyn_begin_colsplit + ork_dyn_end by phase. It counts core 0 only โ€” core 0 runs on the calling thread, so its worker phases are wall time, while cores 1-2 run concurrently and would double-count. "MB/call" is the byte count handed to the kernel's MEM_SYNC ioctl.

3 full steps, ~1073 colsplit calls per step (849 matmuls, but a wide-N matmul calls colsplit once per N-slice), warm, pre-fix tree, profiler ON โ€” and the profiler is free: that run measured 44.790 s/step against 44.752 for the same binary with it off.

phase ms/call MB/call
begin(total) 23.675
  A gather (the memcpy and its bsync) 8.227 444.0
  regcmd synth 0.085
  full-surface SENT seed 0.312 2.5
  bsync-in (maf+mrc+mtk+mcc TO_DEVICE) 6.510 418.5
  submit โ€” the blocking ioctl, i.e. the NPU 3.517
  per-core parallel accumulate 1.172 (n=552)
  bsync-out (mcc FROM_DEVICE) 4.971 292.2
  pool dispatch + join 0.024
end(total) 6.737
  end bsync (mcc FROM_DEVICE, a SECOND time) 4.898 313.2
  end copy-back 1.838

1.47 GB of DMA cache maintenance per call โ€” 24.6 ms of a 30.4 ms call, against a 3.5 ms submit. 1467 MB / 24.6 ms = 59.6 GB/s, a DRAM-rate cache-maintenance figure: the cost scales with bytes, not with ioctl count. r105 estimated the unexplained fixed cost at "about 24 ms per call"; the sync total here is 24.6 ms and the measured saving below is 22.7 ms.

All three suspects r105 named are refuted by the same table:

  • pthread_create per call โ€” 0.024 ms. There is no per-call thread creation: the pool is already persistent (orki_npu_pool_ensure / c->pgen + condvar). The suspicion was reasonable from the pthread_* calls visible in the file, but those are the dispatch to an existing pool.
  • the A gather โ€” real, but it is the orki_bsync at the end of the gather, not the memcpy: 444 MB synced for a few MB written.
  • the single-threaded Sk==1 copy-back โ€” 1.838 ms, and it is unchanged by the fix.

A note on a misleading first measurement, recorded so the next person does not repeat it. The FIRST profile of the session, taken immediately after a make -j8 with a cold page cache, read 58 ms/call and 69.4 s/step โ€” 1.55x the warm figures, with the inflation landing entirely on the memory-walking phases. The profiler was suspected and is innocent (see above). Take a profile warm.

3. The mechanism

orki_bsync() syncs b->size โ€” the whole buffer. The per-core colsplit scratch (c->maf[i], c->mrc[i], c->mtk[i], c->mcc[i]) is high-water marked: it only ever grows. So every call is charged DMA cache maintenance over the widest shape the process has ever run, not over the bytes in flight. c->mrc[i] is additionally pre-grown to a fixed 512-program chain (458 KB) whatever the 2-6 programs a call actually emits, and ork_dyn_end then invalidates the whole output buffer a second time after the worker already did.

What drove the high-water mark that high is its own bug. The fp16 arm resizes maf[i] and mcc[i] to the requested shape and only THEN discovers the shape needs more than the 512-program chain cap, at which point it bails and the matmul runs single-core anyway. The tall-M head gradient (M=248320 K=1024 N=1024, 1411 programs) therefore left ~1.5 GB of maf and ~1 GB of mcc allocated, in a 4 GiB domain, for a matmul that never used a byte of either โ€” and every later call's scratch sync was billed against it. fp16 also grew maf[1]/maf[2], which the fp16 arm never reads (it gathers A once into maf[0] and points all three cores at it).

It also explains WHICH shapes hurt most. The worker skipped the maf sync when oSk > 1, so a Sk==1 call โ€” all of attention, and every K<=1024 linear โ€” synced the LARGEST of the four buffers (maf, 444 MB) on top of the two mcc passes, ~1050 MB, while a Sk>1 call synced ~680 MB. Against attention's 2 ms of real work that is a 14x tax; against a linear's tens of ms it is ~1.5x. Hence "attention 7.8x slower on three cores, linear only 1.5x" โ€” the same absolute cost, divided by very different denominators.

4. The fix

  1. orki_bsync_live(fd, b, nbytes, flags) โ€” orki_bsync_off at offset 0 with the byte count rounded out to a page and clamped to b->size. Never syncs less than the live bytes.
  2. struct ork_csub carries this call's live extents (nb_af/nb_rc/nb_tk/nb_cc), filled by whichever of the three emission arms ran; the worker syncs those. nb_af == 0 means this core reads the shared gather in maf[0], which the build already flushed โ€” true for fp16 and for the int8 wide-K arm, so those two stop syncing maf in the worker at all.
  3. The gathers (fp16 and int8 wide-K) flush goff elements, not AFS->size.
  4. ork_dyn_end invalidates each distinct output buffer's live extent โ€” outptr - buf->cpu plus nout elements, maxed over the entries sharing a buffer. nout==0 falls back to h->N, which is the same convention ork_dyn_done_i and the copy-back already use.
  5. An over-long fp16 chain is declined before any scratch is grown (the program count depends only on M and the K-slicing, so it is decidable up front), and maf[i>0] is no longer grown on the fp16 path.

4a. And one that is NOT YET VIABLE, with the measurement that stopped it

The same bug exists on the single-core path: orki_run's loop syncs the whole 2 MB c->regcmd for the 896 bytes it just wrote, plus the whole c->Af, and orki_submit1_db the whole c->Cc. Narrowing those three measured 24.420 -> 24.248 s/step (3-core) and 30.104 -> 28.593 (1-core, 5%) โ€” and it changed the fp16 output, so it is NOT in the change.

How it was caught, and this is the value of a static golden: make test's test_matmul reported GOLDEN MISMATCH fp16 {256,3584,256} (mism=0). The mism=0 is the tell โ€” the test hashes a first set of four runs (M = 1, 1, 4, 256) and then RE-RUNS them against an fp32 reference, so "hash wrong, reference exact" means the FIRST, cold run differed and the warm re-run did not. M=1 fp16 goes single-core, which is exactly what this change touched. Bisected: pristine origin/main 0xd659053d19504e43 twice; with the single-core syncs 0x8b9b3b3e78d8e6c9 twice; with them reverted 0xd659053d19504e43 twice. Deterministic in all three, so it is a real behaviour change, not flake.

The likely mechanism, unconfirmed: the CNA fetches the activation in CBUF data-bank units (the 0x1040 split, 32 KB per bank), so cleaning only mc*Kp*esz + a page leaves part of a cold fetch window unflushed. A correct version would round the c->Af clean out to the emitted DATA_BANK capacity rather than to a page. Not attempted โ€” it needs the bank count read back from the synthesised 0x1040, the way orki_f16_mcap_n's cap already does.

The same hazard does NOT apply to the colsplit extents, and the goldens say so: with items 1-5 alone test_matmul's fp16 golden passes bit-for-bit, twice.

5. Results

One training step, --gdn cpu, steps 2..3 of a 3-step run (step 1 excluded as warm-up). This is the shipped change โ€” colsplit only โ€” so the 1-core arm is an untouched control. The AFTER arm ran FIRST, i.e. from the position this board's ~1.13x arm-position bias penalises.

arm s/step tok/s linear run attention run
BEFORE 3-core (default) 44.440 / 44.752 23.0 / 22.9 21.16 s / 218 GF/s 7.86 s / 20 GF/s
BEFORE 1-core (ORK_NPU_MC=1) 30.421 33.7 14.39 s / 321 GF/s 1.05 s / 148 GF/s
AFTER 3-core (ran first) 24.964 41.0 8.68 s / 532 GF/s 0.57 s / 272 GF/s
AFTER 3-core, repeat (A/A control) 24.420 41.9 8.70 s / 531 0.56 s / 278
AFTER 1-core (the untouched control) 30.104 34.0 14.19 s / 326 1.03 s / 150
  • 3-core 44.752 -> 24.964 s/step = 1.79x.
  • 1-core 30.421 -> 30.104 = 1.01x, i.e. unchanged โ€” the control says the win is colsplit's and not the environment's.
  • Three cores now beat one by 1.21x on the workload where they used to lose by 1.49x.
  • Attention reaches 272-278 GF/s in-model against the 237/277 GF/s the same shapes reach when probed alone (r105 ยง6). The fixed residue is GONE, not reduced.
  • A/A spread 24.964 vs 24.420 = 2.2%, inside the known position bias and in the direction it predicts.

(The ยง4a single-core arm, which is NOT in the change, measured 24.248 / 28.593 โ€” see there.)

Correctness, all arms:

  • step-1 losses byte-identical before and after on every 3-core arm (0.899665 / 0.929848 / 0.914556).
  • gradient gate --all npu --gdn cpu --steps 0: worst of 14 tensors 2.451e-03 (layers.0.linear_attn.in_proj_qkv.weight), step-1 loss |d| 3.930e-05 โ€” both IDENTICAL to the pre-change documented values.
  • positive control --break rms still FAILS at 3.120e-01: the test did not go blind.
  • test_f16colsplit nc=3 == nc=1 BIT-EXACT, maxerr 0.00e+00 on all 8 shapes including M=128 K=3584 N=18944.
  • test_matmul's static fp16 golden {256,3584,256} back to 0xd659053d19504e43, twice, i.e. byte-identical NPU output to pristine origin/main.

An inference workload too, because one workload is not evidence

ork_bench (the fork's bench target) on qwen2.5-1.5B-instruct-Q8_0, prompt 256, P=256 G=64 ubatch=256, -t 4. This is the int8 datapath, and it does reach colsplit โ€” 501 calls per run at 2.172 ms/call, confirmed with ORK_CS_PROF=1. BEFORE is a pristine origin/main build of the same fork; AFTER ran first.

arm prefill tok/s decode tok/s
AFTER (ran first) 205.92 13.02
BEFORE (pristine) 189.48 13.04
AFTER, repeat 206.42 13.00

Prefill +8.7%, decode flat. (An earlier pass of the same A/B against a differently-built pristine read 195.61 -> 208.07/208.42, +6.4%; the two BEFORE builds differ by 3%, so call it +6-9%.) Note the generated text is NOT a determinism check here โ€” the same binary produced different continuations on two runs, so it says nothing either way.

The same probe, after

Warm, final tree, ORK_CS_PROF=1 (24.204 s/step with it on โ€” again free):

phase before after
begin(total) 23.675 ms 5.646 ms
  A gather 8.227 ms / 444.0 MB 0.654 ms / 3.1 MB
  bsync-in 6.510 ms / 418.5 MB 0.033 ms / 0.8 MB
  submit (the NPU) 3.517 ms 3.800 ms
  bsync-out 4.971 ms / 292.2 MB 0.087 ms / 3.0 MB
end(total) 6.737 ms 2.054 ms
  end bsync 4.898 ms / 313.2 MB 0.216 ms / 9.2 MB
  end copy-back 1.838 ms 1.837 ms
total begin+end 30.41 ms 7.70 ms
sync bytes 1467 MB 15.1 MB (97x less)

22.7 ms/call removed. The submit is now 49% of the call. The phases the fix does not touch are unchanged to three digits (synth 0.085/0.085, seed 0.312/0.313, copy-back 1.838/1.837), which is the internal control: only the sync phases moved.

One incidental confirmation: the A-gather counter reads n=3228 before and n=3220 after, equal to the begin count. Those eight extra gathers were calls that gathered A and then bailed on the 512-program cap โ€” exactly the case the early decline removes.

6. Reproducing

On the board, in an ork-driver checkout, with the MLX fixture at $F:

make -j8 libork_npu.a test_f16colsplit
cc -O2 -fopenmp -DWITH_NPU -Iinclude -Isrc -Itools -o tte tools/train_tiny_e2e.c libork_npu.a -lm -pthread

# where the time goes, by phase, for one begin+end (core 0 == the calling thread)
sudo tools/util/npu_guard.sh -- timeout -s TERM 1200 env OMP_NUM_THREADS=4 ORK_CS_PROF=1 \
     taskset -c 4-7 ./tte $F --all npu --gdn cpu --scale 1 --cpufast --nocheck --noemu --steps 3

# the A/B. Run the arm you expect to WIN first: on this board the later arm is favoured by up to 1.13x
sudo tools/util/npu_guard.sh -- timeout -s TERM 2300 env OMP_NUM_THREADS=4 \
     taskset -c 4-7 ./tte $F --all npu --gdn cpu --scale 1 --cpufast --nocheck --noemu --steps 3
#   ... and the same with ORK_NPU_MC=1 for the single-core control

# correctness + its positive control (which must FAIL)
... ./tte $F --all npu --gdn cpu --scale 1 --cpufast --noemu --steps 0
... ./tte $F --all npu --gdn cpu --scale 1 --cpufast --noemu --steps 0 --break rms
sudo tools/util/npu_guard.sh -- ./test_f16colsplit

Every NPU run goes through sudo tools/util/npu_guard.sh -- timeout -s TERM <s> <cmd>, governors are verified before timing, and kernel faults are counted by dmesg timestamp after each run's start.

7. The default: unchanged, and now correct as it stands

fp16 multi-core colsplit was ALREADY the library default; what r105 found was that the default was losing. It no longer is โ€” three cores beat one by 1.21x on the training step and prefill is up 8.7% on an int8 inference benchmark, both from the disadvantaged arm position, with the single-core arm as an untouched control. So nothing is flipped, and r105's standing advice to try ORK_NPU_MC=1 on a many-small-fp16-matmul workload is retired rather than promoted.

8. What this leaves for next time

  • orki_bsync() on a high-water-marked reused buffer is a bug pattern, not a line. A grep for orki_bsync(.*&c-> is the audit. The ones this change did NOT touch: the single-core trio in ยง4a (worth 5% on the 1-core arm, blocked on the bank-granularity question), orki_mc_recover_resubmit's (rare, correctness-safe at full size), and orki_submit1's c->Cc (the ZC-OUT path, which has no nout).
  • A narrowed sync is a CORRECTNESS change, not a performance one, and must be gated as such. ยง4a is the proof: the only thing that caught it was a static golden over a COLD first run. If you narrow another one, the test to run is make test (not a relerr probe), and the thing to look for is a golden mismatch with mism=0.
  • make test is intermittent in-suite at its largest shapes, and it cost a diagnosis here: one run failed test_f16_load (16 floats = exactly one cache line, which looks damning) and the same binary passed it 5/5 standalone, as did pristine origin/main. Re-run in isolation before believing an in-suite failure; the registry already says this about test_f16colsplit.
  • The NPU is now ~50% of the training step rather than 73%. The next lever is the host side (weight re-tile 2.96 s, host prep 2.99 s, GDN recurrence 3.85 s, "rest" 3.26 s), not the submit.
  • The one shape still declined by colsplit is the tied head's dX (1411 programs against the 512-program chain cap). It now declines before allocating, so it costs only its own single-core time rather than taxing every other call.
โš ๏ธ **GitHub.com Fallback** โš ๏ธ