tts validation pack: the half-way cancel rarely lands in the Metal audio decode, and results do not record where it landed

[leehack]

The tts validation pack's cancel check waits half of the adapter's last completed generation, then cancels. On Metal the final step, which runs the code2wav decode (leehack/llamadart-native#86), is the last 18-36% of a synthesis, so that point usually falls in an earlier one-frame step: 11 of 12 times in the probe below. A Metal cancel_latency_bound PASS therefore says little about cancelling the decode, which leehack/llamadart-native#87 makes possible. speech-results.json records lead_ms and reference_generation_ms, not the step the cancel hit, so no reader can tell where a sample landed.

On the pinned v0.4.1, which cannot stop the decode, every Metal cancel measured inside the decode took 27.2-349.7 ms, under the 500 ms budget.

Repro

Apple M4 Max, macOS arm64, Flutter 3.47.1. llamadart main ec6ad6f9b, llamadart-native v0.4.1 (macOS arm64 archive sha256 41d0a529…b1487). ggml-org/Qwen3-TTS-12Hz-1.7B-Base-GGUF at ca27d74b: Q4_K_M (sha256 8d18c94a…85129) + mmproj Q8_0 (6fd65188…cfcce2), both verified by the pack.

M=<snapshot>/Qwen3-TTS-12Hz-1.7B-Base-Q4_K_M.gguf
P=<snapshot>/mmproj-Qwen3-TTS-12Hz-1.7B-Base-Q8_0.gguf
dart pub get && (cd packages/llamadart_validation && dart pub get)
dart run tool/testing/validation.dart speech --pack tts --backend metal \
  --out <new dir> --model $M --projector $P
# step timing: probe below, copied to packages/llamadart_validation/bin/
(cd packages/llamadart_validation && dart run bin/i86_probe.dart $M $P metal 6)

The probe builds the engine and request the pack uses. It timestamps each TextToSpeechProgressEvent. The worker emits one after every native step except the final one, which breaks out of the loop. So the final step runs from the last progress event to done. Each of its 6 cycles runs a full synthesis, then a cancel at 0.5 × that synthesis, then a cancel aimed at the middle of that synthesis's final step. It does not reload between cycles, and frame counts varied from 26 to 40. A cancel is in the final step when its gap after the last progress event is far longer than a frame step.

Measured

Probe (1-min loadavg per run):

run	frame step (median)	final step	final step starts at	0.5 × cancels
probe-2 (20.87 → 20.20)	19.7-20.2 ms	361-368 ms	66-74%	6/6 in a frame step: gap 0-15 ms, latency 5.1-24.3 ms
probe-1 (10.67 → 18.15)	39.1-56.1 ms	566-819 ms	64-82%	5/6 in a frame step: gap 0-44 ms, latency 3.4-37.5 ms. 1/6 in the final step: its reference ran 3710 ms, the cancel came at 1856.9 ms, 448.5 ms after that synthesis's last frame step, and took 201.2 ms

Of 12 cancels aimed at the final step, 8 landed there (gap 89-530 ms) and took 67.8-273.2 ms (probe-2, n=4) and 27.2-349.7 ms (probe-1, n=4); 2 hit a frame step and 2 came after the synthesis finished. The 27.2 ms one came 529.6 ms into the final step, near its end, so a short latency does not prove a frame step.

Pack on main + v0.4.1, all 15 checks PASS in every run:

• ec6ad6f9b (loadavg 18.15 → 20.87): leads [1277.1, 700.6, 676.2, 648.2] ms, latencies [82.4, 20.6, 18.9, 11.2] ms. The 1277.1 ms lead is half the first generation after load (2549 ms); reload and the three cycle generations took 1293-1399 ms. The JSON cannot say whether that sample hit the decode.
• 4 runs at 0f88c09f6 (only WebGPU files differ from ec6ad6f9b), loadavg 3.79-29.10: leads 638.1-1336.9 ms, latencies 1.3-28.8 ms. Their 38-frame generations took 1271-2668 ms.

Source at ec6ad6f9b

• speech_runner.dart#L239-L264: waits _lastGenerationMs × speechCancelInFlightLeadFraction, cancels, and records only cancel_after_ms, cancel_in_flight and reference_generation_ms.
• #L425: speechCancelInFlightLeadFraction = 0.5. #L433: speechCancelLatencyBudgetMs = 500.0.
• llama_cpp_service.dart#L7815-L7861: one api.step per iteration; the COMPLETED step breaks before onProgress.

Not known

• Where the 20 pack samples landed.
• Vulkan, CUDA, OpenCL and iOS Metal: not run.
• Texts past 72 frames also decode at frames 72 and 144 (leehack/llamadart-native#86); the pack text is 38 frames.
• Why some Metal runs take about twice as long per step (probe-1, and pack generations of 2.0-2.7 s). The machine was shared.
• Not run on a runtime with leehack/llamadart-native#87, which main does not pin.

i86_probe.dart

import 'dart:async';
import 'dart:convert';
import 'dart:io';

import 'package:llamadart/llamadart.dart';

Future<void> main(List<String> args) async {
  final model = args[0];
  final projector = args[1];
  final backend = GpuBackend.values.byName(args[2]);
  final pairs = int.parse(args[3]);
  final engine = LlamaEngine(LlamaBackend());
  await engine.setLogLevel(LlamaLogLevel.info);
  await engine.loadModel(
    model,
    modelParams: ModelParams(
      contextSize: 4096,
      preferredBackend: backend,
      gpuLayers: backend == GpuBackend.cpu ? 0 : 99,
    ),
  );
  await engine.loadMultimodalProjector(projector);
  emit({
    'backend_name': await engine.getBackendName(),
    'resolved_gpu_layers': await engine.getResolvedGpuLayers(),
  });

  Future<Map<String, Object?>> run({double? cancelAtMs}) async {
    final watch = Stopwatch()..start();
    final synth = TextToSpeechEngine(
      engine,
      modelProfile: TextToSpeechModelProfile.qwen3Tts,
    );
    final cap = await synth.capabilities;
    if (!cap.isSupported) throw StateError('unsupported');
    final task = await synth.synthesize(
      const TextToSpeechRequest(
        text: 'Hello from llamadart. The answer is forty two.',
        language: 'English',
        maxFrames: 384,
        seed: 1,
      ),
    );
    final steps = <List<Object>>[];
    double? cancelMs;
    var framesAtCancel = -1;
    final cancelWatch = Stopwatch();
    Timer? timer;
    if (cancelAtMs != null) {
      timer = Timer(
        Duration(microseconds: (cancelAtMs * 1000).round()),
        () {
          cancelMs = watch.elapsedMicroseconds / 1000;
          framesAtCancel = steps.isEmpty ? 0 : steps.last[2] as int;
          cancelWatch.start();
          task.cancel();
        },
      );
    }
    var frames = -1;
    await for (final e in task.events) {
      final t = watch.elapsedMicroseconds / 1000;
      if (e is TextToSpeechProgressEvent) {
        steps.add([t, e.phase.name, e.framesGenerated]);
      } else if (e is TextToSpeechFinalEvent) {
        frames = e.result.framesGenerated;
      }
    }
    final c = await task.done;
    cancelWatch.stop();
    final doneMs = watch.elapsedMicroseconds / 1000;
    timer?.cancel();
    final gen = steps.where((s) => s[1] == 'generating').toList();
    final lastStepMs = steps.isEmpty ? null : steps.last[0] as double;
    return {
      'state': c.state.name,
      'done_ms': doneMs,
      'frames': frames,
      'progress_events': steps.length,
      'prompt_events': steps.length - gen.length,
      'first_frame_ms': gen.isEmpty ? null : gen.first[0],
      'last_progress_ms': lastStepMs,
      'last_progress_frames': steps.isEmpty ? null : steps.last[2],
      'final_step_ms': lastStepMs == null ? null : doneMs - lastStepMs,
      'frame_step_ms_median': _median([
        for (var i = 1; i < gen.length; i++)
          (gen[i][0] as double) - (gen[i - 1][0] as double),
      ]),
      if (cancelAtMs != null) ...{
        'cancel_at_ms': cancelMs,
        'frames_at_cancel': framesAtCancel,
        'cancel_latency_ms': cancelWatch.elapsedMicroseconds / 1000,
      },
    };
  }

  for (var i = 0; i < pairs; i++) {
    final full = await run();
    emit({'pair': i, 'kind': 'full', ...full});
    final ref = full['done_ms'] as double;
    final half = await run(cancelAtMs: ref * 0.5);
    emit({'pair': i, 'kind': 'cancel_0.5', 'reference_ms': ref, ...half});
    final lastProgress = full['last_progress_ms'] as double;
    final target = lastProgress + (ref - lastProgress) / 2;
    final late = await run(cancelAtMs: target);
    emit({
      'pair': i,
      'kind': 'cancel_final_step_mid',
      'reference_ms': ref,
      'target_fraction': target / ref,
      ...late,
    });
  }
  await engine.dispose();
}

double? _median(List<double> xs) {
  if (xs.isEmpty) return null;
  xs.sort();
  return xs[xs.length ~/ 2];
}

void emit(Map<String, Object?> m) => stdout.writeln('I86 ${jsonEncode(m)}');