From 3fadee114ea633767c5fc75f0182b5be6e2104cc Mon Sep 17 00:00:00 2001 From: Noah Gift Date: Mon, 21 Sep 2026 18:26:38 +0200 Subject: [PATCH 1/5] WIP PMAT-3718: run --json prompt_tokens/completion_tokens/finish_reason; serve never reports a cut as stop Co-Authored-By: Claude Opus 5 (1M context) --- .../apr-cli/src/commands/inference_output.rs | 17 +- crates/apr-cli/src/commands/run.rs | 22 ++ crates/apr-cli/src/commands/run_07.rs | 1 + crates/apr-cli/src/commands/run_entry.rs | 9 + .../src/commands/run_tests_accel_reconcile.rs | 2 + .../src/commands/run_tests_chrome_trace.rs | 12 + .../commands/run_tests_inference_output.rs | 2 + .../src/commands/run_tests_layer_trace.rs | 1 + .../src/commands/run_tests_model_source.rs | 2 + .../src/commands/run_tests_parse_token_ids.rs | 3 + .../src/commands/run_tests_stream_output.rs | 6 + .../src/commands/run_tests_usage_3718.rs | 64 ++++ .../serve/handler_apr_cpu_completion.rs | 2 +- crates/apr-cli/src/commands/serve/handlers.rs | 21 +- .../src/api/cuda_chat_backend.rs | 13 +- crates/aprender-serve/src/api/tests/mod.rs | 2 + .../src/api/tests/usage_finish_3718.rs | 160 ++++++++++ crates/aprender-serve/src/api/types.rs | 53 +--- .../src/gguf/inference/generate_quantized.rs | 2 +- .../src/infer/inference_result.rs | 88 +++++- crates/aprender-serve/src/infer/mod.rs | 1 + crates/aprender-serve/src/infer/run_report.rs | 285 ++++++++++++++++++ docs/roadmaps/entries/PMAT-3718.yaml | 20 ++ 23 files changed, 712 insertions(+), 76 deletions(-) create mode 100644 crates/apr-cli/src/commands/run_tests_usage_3718.rs create mode 100644 crates/aprender-serve/src/api/tests/usage_finish_3718.rs create mode 100644 crates/aprender-serve/src/infer/run_report.rs create mode 100644 docs/roadmaps/entries/PMAT-3718.yaml diff --git a/crates/apr-cli/src/commands/inference_output.rs b/crates/apr-cli/src/commands/inference_output.rs index ff185c912d..6afd5c9e1a 100644 --- a/crates/apr-cli/src/commands/inference_output.rs +++ b/crates/apr-cli/src/commands/inference_output.rs @@ -184,6 +184,8 @@ struct InferenceOutput { /// Populated only when `--stream` asked for it (see /// [`decode_token_pieces`]) — every other mode renders the whole `text`. token_texts: Option>, + /// Prompt and completion counts plus the finish reason (#3718). + usage: RunUsage, } /// Execute inference on model @@ -231,6 +233,7 @@ fn execute_inference( used_gpu: None, generated_tokens: None, token_texts: None, + usage: RunUsage::default(), }) } } @@ -299,7 +302,8 @@ fn execute_with_realizar( options: &RunOptions, _use_mmap: bool, ) -> Result { - use realizar::{run_inference, InferenceConfig}; + use realizar::infer::run_inference_report; + use realizar::InferenceConfig; // Get prompt from options or input file let prompt = if let Some(ref p) = options.prompt { @@ -343,7 +347,10 @@ fn execute_with_realizar( } // Run inference via realizar - let result = run_inference(&config).map_err(inference_error)?; + // #3718: the report carries what only the decode path knows (finish reason, + // context window); the prompt count is `input_token_count`, taken after the + // chat template, so it is the number the model actually read. + let (result, report) = run_inference_report(&config).map_err(inference_error)?; // Report performance if benchmarking if options.benchmark { @@ -381,6 +388,12 @@ fn execute_with_realizar( used_gpu: Some(result.used_gpu), generated_tokens, token_texts, + usage: RunUsage { + prompt_tokens: Some(result.input_token_count), + completion_tokens: Some(result.generated_token_count), + finish_reason: report.finish_reason.map(|r| r.as_str()), + context_length: report.context_length, + }, }) } diff --git a/crates/apr-cli/src/commands/run.rs b/crates/apr-cli/src/commands/run.rs index d56b9a967c..0f95c96150 100644 --- a/crates/apr-cli/src/commands/run.rs +++ b/crates/apr-cli/src/commands/run.rs @@ -207,6 +207,25 @@ impl Default for RunOptions { } } +/// What `apr run --json` reports about the prompt and how generation ended (#3718). +/// +/// RAH (#3716) rebuilt Qwen3.5's tokenizer from the GGUF just to learn how many +/// prompt tokens the model saw, and could not tell a reply cut at `--max-tokens` +/// from one that finished. Every field is `None` when the inference path did not +/// report it, which is `null` in the JSON and never a zero that reads as measured. +#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)] +pub(crate) struct RunUsage { + /// Tokens actually fed to the model: after the chat template, including BOS. + pub prompt_tokens: Option, + /// Tokens the engine generated. Unlike `RunResult::tokens_generated`, never a + /// word-count stand-in. + pub completion_tokens: Option, + /// `"stop"` (a stop token ended it) or `"length"` (the budget did). + pub finish_reason: Option<&'static str>, + /// The model's context window, from its metadata. + pub context_length: Option, +} + /// Run result #[derive(Debug, Clone)] pub(crate) struct RunResult { @@ -230,6 +249,8 @@ pub(crate) struct RunResult { /// could be resolved. `--stream` used to emit `"text":""` for every token /// because nothing ever decoded the ids one at a time. pub token_texts: Option>, + /// Prompt and completion counts plus the finish reason (#3718). + pub usage: RunUsage, } /// Resolve a user-supplied model argument into a [`ModelSource`]. @@ -316,6 +337,7 @@ pub(crate) fn run_model(source: &str, options: &RunOptions) -> Result used_gpu: output.used_gpu, generated_tokens: output.generated_tokens, token_texts: output.token_texts, + usage: output.usage, }) } diff --git a/crates/apr-cli/src/commands/run_07.rs b/crates/apr-cli/src/commands/run_07.rs index 607f57955c..2f280e89a5 100644 --- a/crates/apr-cli/src/commands/run_07.rs +++ b/crates/apr-cli/src/commands/run_07.rs @@ -11,4 +11,5 @@ include!("run_tests_chrome_trace.rs"); include!("run_tests_layer_trace.rs"); include!("run_tests_stream_output.rs"); include!("run_tests_accel_reconcile.rs"); +include!("run_tests_usage_3718.rs"); } diff --git a/crates/apr-cli/src/commands/run_entry.rs b/crates/apr-cli/src/commands/run_entry.rs index e62666df49..c662141885 100644 --- a/crates/apr-cli/src/commands/run_entry.rs +++ b/crates/apr-cli/src/commands/run_entry.rs @@ -527,6 +527,15 @@ fn build_final_json( "inference_time_ms": (result.duration_secs * 1000.0 * 100.0).round() / 100.0, "used_gpu": result.used_gpu.unwrap_or(false), "cached": result.cached, + // #3718: what the model read and why it stopped writing. `prompt_tokens` is + // the post-chat-template count (BOS included) fed to the model, so a + // consumer no longer rebuilds the tokenizer to learn it. `finish_reason` + // is "length" when the budget ended the reply, so a cut answer is never + // mistaken for a finished one. Each is null when the path did not report it. + "prompt_tokens": result.usage.prompt_tokens, + "completion_tokens": result.usage.completion_tokens, + "finish_reason": result.usage.finish_reason, + "context_length": result.usage.context_length, // #3602: `used_gpu: false` alone collapses two different outcomes — "no // accelerator was asked for" and "one was asked for, attempted, and // REFUSED at runtime". A consumer cannot tell a CPU run from a rejected diff --git a/crates/apr-cli/src/commands/run_tests_accel_reconcile.rs b/crates/apr-cli/src/commands/run_tests_accel_reconcile.rs index de7f96ad61..d0c5da3588 100644 --- a/crates/apr-cli/src/commands/run_tests_accel_reconcile.rs +++ b/crates/apr-cli/src/commands/run_tests_accel_reconcile.rs @@ -62,6 +62,7 @@ fn a_forced_accelerator_that_ran_on_cpu_is_refused() { used_gpu: Some(false), generated_tokens: Some(vec![9707]), token_texts: None, + usage: Default::default(), }; let err = reconcile_accelerator(true, &result) @@ -148,6 +149,7 @@ fn gpu_result(used_gpu: Option) -> RunResult { used_gpu, generated_tokens: Some(vec![9707]), token_texts: None, + usage: Default::default(), } } diff --git a/crates/apr-cli/src/commands/run_tests_chrome_trace.rs b/crates/apr-cli/src/commands/run_tests_chrome_trace.rs index 5eb2df77bc..55acf6e4f6 100644 --- a/crates/apr-cli/src/commands/run_tests_chrome_trace.rs +++ b/crates/apr-cli/src/commands/run_tests_chrome_trace.rs @@ -24,6 +24,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), }; let json = build_chrome_trace_events(&result, "model.gguf", 16, true); @@ -54,6 +55,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; let json = build_chrome_trace_events(&result, "empty.gguf", 0, false); @@ -73,6 +75,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; let json = build_chrome_trace_events(&result, "model.gguf", 10, false); @@ -92,6 +95,7 @@ used_gpu: Some(true), generated_tokens: None, token_texts: None, + usage: Default::default(), }; let json = build_chrome_trace_events(&result, "my-model.gguf", 64, true); @@ -111,6 +115,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), }; let json = build_chrome_trace_events(&result, "model.gguf", 10, false); @@ -140,6 +145,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), }; let json = build_chrome_trace_events(&result, "model.gguf", 10, false); @@ -159,6 +165,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; let json = build_chrome_trace_events(&result, "m.gguf", 1, false); assert_eq!(json["displayTimeUnit"], "ms"); @@ -178,6 +185,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), }; // Just ensure no panic; file creation is best-effort print_chrome_trace(&result, "test-model.gguf", 32, false, None); @@ -210,6 +218,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), }; print_chrome_trace(&result, "test-model.gguf", 32, false, Some(&target)); @@ -239,6 +248,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), }; print_benchmark_results(&result, "model.gguf", "text", 100); } @@ -254,6 +264,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), }; print_benchmark_results(&result, "model.gguf", "json", 50); } @@ -269,6 +280,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; print_benchmark_results(&result, "model.gguf", "text", 10); } diff --git a/crates/apr-cli/src/commands/run_tests_inference_output.rs b/crates/apr-cli/src/commands/run_tests_inference_output.rs index 10caee8089..0174ecadf6 100644 --- a/crates/apr-cli/src/commands/run_tests_inference_output.rs +++ b/crates/apr-cli/src/commands/run_tests_inference_output.rs @@ -15,6 +15,7 @@ used_gpu: Some(false), generated_tokens: Some(vec![1, 2, 3, 4, 5]), token_texts: None, + usage: Default::default(), }; assert_eq!(output.text, "hello"); assert_eq!(output.tokens_generated, Some(5)); @@ -32,6 +33,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; assert!(output.tokens_generated.is_none()); assert!(output.inference_ms.is_none()); diff --git a/crates/apr-cli/src/commands/run_tests_layer_trace.rs b/crates/apr-cli/src/commands/run_tests_layer_trace.rs index e71ea0609d..2da4e9c7df 100644 --- a/crates/apr-cli/src/commands/run_tests_layer_trace.rs +++ b/crates/apr-cli/src/commands/run_tests_layer_trace.rs @@ -20,6 +20,7 @@ used_gpu: Some(false), generated_tokens: None, token_texts: None, + usage: Default::default(), } } diff --git a/crates/apr-cli/src/commands/run_tests_model_source.rs b/crates/apr-cli/src/commands/run_tests_model_source.rs index 3779970053..cb8bdd5322 100644 --- a/crates/apr-cli/src/commands/run_tests_model_source.rs +++ b/crates/apr-cli/src/commands/run_tests_model_source.rs @@ -39,6 +39,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; let _debug = format!("{:?}", result); assert_eq!(result.tokens_generated, Some(5)); @@ -191,6 +192,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; let cloned = result.clone(); assert_eq!(result.text, cloned.text); diff --git a/crates/apr-cli/src/commands/run_tests_parse_token_ids.rs b/crates/apr-cli/src/commands/run_tests_parse_token_ids.rs index 32e2045b48..7977032b32 100644 --- a/crates/apr-cli/src/commands/run_tests_parse_token_ids.rs +++ b/crates/apr-cli/src/commands/run_tests_parse_token_ids.rs @@ -232,6 +232,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; let result_zero = RunResult { text: String::new(), @@ -242,6 +243,7 @@ used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; assert_ne!( result_none.tokens_generated, result_zero.tokens_generated, @@ -262,6 +264,7 @@ used_gpu: Some(true), generated_tokens: Some(vec![10, 20, 30]), token_texts: None, + usage: Default::default(), }; assert_eq!(result.text, "output"); assert!((result.duration_secs - 1.234).abs() < f64::EPSILON); diff --git a/crates/apr-cli/src/commands/run_tests_stream_output.rs b/crates/apr-cli/src/commands/run_tests_stream_output.rs index e6062f9a66..20bc6952b3 100644 --- a/crates/apr-cli/src/commands/run_tests_stream_output.rs +++ b/crates/apr-cli/src/commands/run_tests_stream_output.rs @@ -16,6 +16,7 @@ fn stream_output_emits_n_plus_one_json_lines() { " world".to_string(), "!".to_string(), ]), + usage: Default::default(), }; let mut buf: Vec = Vec::new(); @@ -85,6 +86,7 @@ fn stream_token_events_carry_their_own_decoded_text() { " here".to_string(), " to help".to_string(), ]), + usage: Default::default(), }; let mut buf: Vec = Vec::new(); @@ -125,6 +127,7 @@ fn stream_token_events_degrade_to_empty_text_without_a_tokenizer() { used_gpu: Some(false), generated_tokens: Some(vec![7, 9]), token_texts: None, + usage: Default::default(), }; let mut buf: Vec = Vec::new(); @@ -150,6 +153,7 @@ fn stream_output_no_tokens_emits_only_final() { used_gpu: Some(false), generated_tokens: Some(Vec::new()), token_texts: None, + usage: Default::default(), }; let mut buf: Vec = Vec::new(); @@ -175,6 +179,7 @@ fn stream_output_none_tokens_emits_only_final() { used_gpu: None, generated_tokens: None, token_texts: None, + usage: Default::default(), }; let mut buf: Vec = Vec::new(); @@ -199,6 +204,7 @@ fn build_final_json_matches_legacy_json_shape() { used_gpu: Some(true), generated_tokens: Some(vec![1, 2, 3]), token_texts: None, + usage: Default::default(), }; let v = build_final_json(&result, "src.apr", 100, false); assert_eq!(v["model"], "src.apr"); diff --git a/crates/apr-cli/src/commands/run_tests_usage_3718.rs b/crates/apr-cli/src/commands/run_tests_usage_3718.rs new file mode 100644 index 0000000000..d3ed93b341 --- /dev/null +++ b/crates/apr-cli/src/commands/run_tests_usage_3718.rs @@ -0,0 +1,64 @@ +// #3718: `apr run --json` says how many tokens the model read and why it stopped. + +fn result_with(usage: RunUsage) -> RunResult { + RunResult { + text: "4".to_string(), + duration_secs: 1.0, + cached: true, + // The word-count stand-in `run_model` substitutes when the engine + // reports nothing. `completion_tokens` must never echo it. + tokens_generated: Some(1), + tok_per_sec: None, + used_gpu: Some(false), + generated_tokens: None, + token_texts: None, + usage, + } +} + +#[test] +fn json_carries_the_engine_counts_and_the_finish() { + let usage = RunUsage { + prompt_tokens: Some(79), + completion_tokens: Some(32), + finish_reason: Some("length"), + context_length: Some(262_144), + }; + let v = build_final_json(&result_with(usage), "m.gguf", 32, false); + assert_eq!(v["prompt_tokens"], 79); + assert_eq!(v["completion_tokens"], 32); + assert_eq!(v["finish_reason"], "length"); + assert_eq!(v["context_length"], 262_144); +} + +/// Not reported is `null`, never `0` or `"stop"`: a zero reads as measured and +/// a default "stop" is the silent cut this row removes. +#[test] +fn unreported_fields_are_null_not_zero() { + let v = build_final_json(&result_with(RunUsage::default()), "m.apr", 32, false); + for key in ["prompt_tokens", "completion_tokens", "finish_reason", "context_length"] { + assert!(v.get(key).is_some(), "{key} must be present so consumers can key on it"); + assert!(v[key].is_null(), "{key} must be null when unreported, got {}", v[key]); + } + assert_eq!(v["tokens_generated"], 1, "the legacy field keeps its stand-in"); +} + +/// `--stream`'s terminal event is built by the same function, so it carries +/// the same fields. +#[test] +fn stream_final_event_carries_them_too() { + let usage = RunUsage { + prompt_tokens: Some(12), + completion_tokens: Some(3), + finish_reason: Some("stop"), + context_length: Some(4096), + }; + let mut buf: Vec = Vec::new(); + write_stream_output(&mut buf, &result_with(usage), "m.gguf", 8, false).expect("write"); + let text = String::from_utf8(buf).expect("utf-8"); + let last = text.lines().last().expect("final line"); + let v: serde_json::Value = serde_json::from_str(last).expect("json"); + assert_eq!(v["event"], "final"); + assert_eq!(v["prompt_tokens"], 12); + assert_eq!(v["finish_reason"], "stop"); +} diff --git a/crates/apr-cli/src/commands/serve/handler_apr_cpu_completion.rs b/crates/apr-cli/src/commands/serve/handler_apr_cpu_completion.rs index e4651ca2f8..0cc52d93d0 100644 --- a/crates/apr-cli/src/commands/serve/handler_apr_cpu_completion.rs +++ b/crates/apr-cli/src/commands/serve/handler_apr_cpu_completion.rs @@ -376,7 +376,7 @@ async fn handle_apr_cpu_chat_completion( let latency_ms = start.elapsed().as_millis() as u64; let mut response = serde_json::json!({ "id": request_id, "object": "chat.completion", "created": created, "model": &s.model_name, - "choices": [{"index": 0, "message": {"role": "assistant", "content": out.text}, "finish_reason": "stop"}], + "choices": [{"index": 0, "message": {"role": "assistant", "content": out.text}, "finish_reason": out.finish_reason.as_str()}], "usage": {"prompt_tokens": out.input_token_count, "completion_tokens": out.tokens_generated, "total_tokens": out.input_token_count + out.tokens_generated}, "_apr_metrics": {"latency_ms": latency_ms, "tok_per_sec": tok_per_sec} }); diff --git a/crates/apr-cli/src/commands/serve/handlers.rs b/crates/apr-cli/src/commands/serve/handlers.rs index c6b7d51fe2..1645c7e58d 100644 --- a/crates/apr-cli/src/commands/serve/handlers.rs +++ b/crates/apr-cli/src/commands/serve/handlers.rs @@ -1074,6 +1074,8 @@ struct AprInferenceOutput { tokens_generated: usize, gen_duration: std::time::Duration, input_token_count: usize, + /// Why the loop ended, judged against the budget it ran with (#3718). + finish_reason: realizar::infer::run_report::FinishReason, } /// Run the tokenize → generate → decode pipeline for APR CPU inference. @@ -1123,12 +1125,11 @@ fn run_apr_cpu_inference( }; let gen_duration = gen_start.elapsed(); - // Extract new tokens - let new_tokens = if output_tokens.len() > input_tokens.len() { - &output_tokens[input_tokens.len()..] - } else { - &output_tokens[..] - }; + // Extract new tokens. `generate_with_cache` returns prompt + generated, so + // nothing past the prompt means nothing was generated. The old fallback + // (`&output_tokens[..]`) handed the PROMPT back as the completion, decoded it + // as the reply, and counted it as `completion_tokens` (#3718). + let new_tokens = output_tokens.get(input_tokens.len()..).unwrap_or(&[]); // Decode: embedded APR tokenizer → sibling tokenizer.json → character-level fallback let text = if let Some(ref tok) = state.embedded_tokenizer { @@ -1142,11 +1143,19 @@ fn run_apr_cpu_inference( .collect() }; + // #3718: the chat handler hardcoded "stop", so a reply cut at `max_tokens` + // (which the handler caps at 4096) read as finished. The loop's stop set is + // `gen_config.stop_tokens` (empty here) plus token 0, which it pushes before + // breaking (`is_eos_token`, apr_transformer/generation.rs). + let finish_reason = + realizar::infer::run_report::FinishReason::from_decode(new_tokens, &[0], max_tokens); + Ok(AprInferenceOutput { text, tokens_generated: new_tokens.len(), gen_duration, input_token_count, + finish_reason, }) } diff --git a/crates/aprender-serve/src/api/cuda_chat_backend.rs b/crates/aprender-serve/src/api/cuda_chat_backend.rs index 1b0b556d9a..b6139865c9 100644 --- a/crates/aprender-serve/src/api/cuda_chat_backend.rs +++ b/crates/aprender-serve/src/api/cuda_chat_backend.rs @@ -319,7 +319,16 @@ fn try_quantized_backend( state.should_trace(trace_level), cancel, ); - let max_tokens = q_config.max_tokens; + // #3718: the dense CPU loop spends `effective_max_tokens` (the request clamped + // to the context room), so the finish is judged against THAT budget. Judged + // against the request's number, every context-clamped cut read as "stop". A + // prompt that cannot fit at all is the request's fault: refused here with 400, + // not a 500 after the fact or a streamed error that still ends "stop" at 200. + let max_tokens = match quantized_model.effective_max_tokens(prompt_tokens, q_config.max_tokens) + { + Ok(budget) => budget, + Err(e) => return Some(fail_response(state, crate::api::generation_error_status(&e), e)), + }; if request.stream { let (tx, rx) = tokio::sync::mpsc::channel::>(16); @@ -358,7 +367,7 @@ fn try_quantized_backend( // Non-streaming quantized let generated = match quantized_model.generate_with_cache(&prompt_ids, &q_config) { Ok(g) => g, - Err(e) => return Some(fail_response(state, StatusCode::INTERNAL_SERVER_ERROR, e)), + Err(e) => return Some(fail_response(state, crate::api::generation_error_status(&e), e)), }; let token_ids: Vec = generated.iter().skip(prompt_tokens).copied().collect(); diff --git a/crates/aprender-serve/src/api/tests/mod.rs b/crates/aprender-serve/src/api/tests/mod.rs index ae725c1292..262dc6e7b9 100644 --- a/crates/aprender-serve/src/api/tests/mod.rs +++ b/crates/aprender-serve/src/api/tests/mod.rs @@ -66,3 +66,5 @@ mod chat_stream_route_2375; // aprender#2375(4): POST /v1/chat/completions/strea mod apr_model_routes_2609; // aprender#2609: routed endpoints on an AprTransformer server; one condition, one status mod effective_config_route_pp2; // PP-LLAMA-001 §12 row 6 / PP-2 / PP-13 / PP-14 / PP-24 / PP-30: GET /v1/effective-config reports residency, not cfg! mod stream_mode_pp27; // PP-LLAMA-001 PP-27 / §3: an SSE stream declares live vs replayed, and the terminal chunk carries usage + measured timings +#[cfg(feature = "gpu")] // create_test_quantized_model is gpu-gated +mod usage_finish_3718; // aprender#3718: a context-clamped cut is "length", an unfittable prompt is 400 diff --git a/crates/aprender-serve/src/api/tests/usage_finish_3718.rs b/crates/aprender-serve/src/api/tests/usage_finish_3718.rs new file mode 100644 index 0000000000..b2657a65fb --- /dev/null +++ b/crates/aprender-serve/src/api/tests/usage_finish_3718.rs @@ -0,0 +1,160 @@ +//! aprender#3718: `/v1/chat/completions` on a GGUF server must never report a cut as +//! a finished reply, and a prompt that cannot fit must be refused as the client's +//! error. +//! +//! The dense CPU backend clamps `max_tokens` to the room left in the context +//! (`effective_max_tokens`, aprender#2376), then judged `finish_reason` against the +//! UNCLAMPED request. So a reply cut at the context edge said `"stop"`, and a +//! consumer could not tell it from a complete answer. A prompt longer than the +//! context was a 500 (non-streaming) or a 200 stream carrying an error event that +//! still ended `"stop"`. +//! +//! The fixture's greedy pick is token 0, which is also the EOS fallback when a +//! model declares none (`chat_gen_params`). With `ignore_eos` a run ends on its +//! budget, which is what the clamp tests vary; without it the run stops at once, +//! which is the converse. + +use axum::body::Body; +use axum::http::{Request, StatusCode}; +use tower::util::ServiceExt; + +use crate::api::{create_router, AppState}; + +/// A quantized-only server with a `context_length`-token window. +fn quantized_state(context_length: usize) -> AppState { + use crate::api::test_helpers::create_test_quantized_model; + use crate::gguf::{ArchConstraints, GGUFConfig}; + + let config = GGUFConfig { + architecture: "llama".to_string(), + constraints: ArchConstraints::from_architecture("llama"), + hidden_dim: 64, + intermediate_dim: 128, + num_layers: 2, + num_heads: 4, + num_kv_heads: 4, + vocab_size: 256, + context_length, + rope_theta: 10000.0, + eps: 1e-5, + rope_type: 0, + explicit_head_dim: None, + query_pre_attn_scalar: None, + bos_token_id: None, + eos_token_id: None, + }; + AppState::with_quantized_model(create_test_quantized_model(&config)) + .expect("build quantized AppState") +} + +async fn chat( + state: AppState, + max_tokens: usize, + stream: bool, + ignore_eos: bool, +) -> (StatusCode, String) { + let body = serde_json::json!({ + "model": "default", + "messages": [{"role": "user", "content": "Hi"}], + "max_tokens": max_tokens, + "temperature": 0.0, + "stream": stream, + "ignore_eos": ignore_eos, + }); + let response = create_router(state) + .oneshot( + Request::builder() + .method("POST") + .uri("/v1/chat/completions") + .header("content-type", "application/json") + .body(Body::from(body.to_string())) + .expect("request"), + ) + .await + .expect("response"); + let status = response.status(); + let bytes = axum::body::to_bytes(response.into_body(), usize::MAX) + .await + .expect("body"); + (status, String::from_utf8_lossy(&bytes).into_owned()) +} + +/// How many tokens the templated `"Hi"` prompt is, measured through the server +/// itself with a budget small enough that nothing clamps. +async fn templated_prompt_tokens() -> usize { + let (status, body) = chat(quantized_state(512), 1, false, true).await; + assert_eq!(status, StatusCode::OK, "{body}"); + let v: serde_json::Value = serde_json::from_str(&body).expect("json"); + v["usage"]["prompt_tokens"].as_u64().expect("prompt_tokens") as usize +} + +#[tokio::test] +async fn a_context_clamped_cut_is_length_not_stop() { + let prompt = templated_prompt_tokens().await; + let context = prompt + 6; + let (status, body) = chat(quantized_state(context), 1000, false, true).await; + assert_eq!(status, StatusCode::OK, "{body}"); + let v: serde_json::Value = serde_json::from_str(&body).expect("json"); + assert_eq!(v["usage"]["prompt_tokens"], prompt, "{body}"); + assert_eq!( + v["usage"]["completion_tokens"], 6, + "control: the run must stop at the context edge (6 tokens of room), or this \ + is not measuring a clamp: {body}" + ); + assert_eq!(v["usage"]["total_tokens"], context, "{body}"); + assert_eq!(v["choices"][0]["finish_reason"], "length", "{body}"); +} + +#[tokio::test] +async fn a_context_clamped_stream_ends_length_not_stop() { + let prompt = templated_prompt_tokens().await; + let (status, body) = chat(quantized_state(prompt + 6), 1000, true, true).await; + assert_eq!(status, StatusCode::OK, "{body}"); + assert!( + body.contains(r#""finish_reason":"length""#), + "the terminal chunk must say the stream was cut: {body}" + ); + assert!(!body.contains(r#""finish_reason":"stop""#), "{body}"); +} + +#[tokio::test] +async fn a_prompt_longer_than_the_context_is_a_400() { + let prompt = templated_prompt_tokens().await; + for stream in [false, true] { + let (status, body) = chat(quantized_state(prompt - 1), 8, stream, true).await; + assert_eq!( + status, + StatusCode::BAD_REQUEST, + "stream={stream}: the request cannot fit, which is the client's error: {body}" + ); + assert!(!body.contains("finish_reason"), "stream={stream}: nothing ran: {body}"); + } +} + +/// The converse, so the clamp tests cannot pass by reporting "length" for +/// everything: with EOS honoured the fixture stops on its first pick, under +/// budget and under the clamp, and that is a finished reply. +#[tokio::test] +async fn a_stop_under_budget_is_stop() { + let prompt = templated_prompt_tokens().await; + for stream in [false, true] { + let (status, body) = chat(quantized_state(prompt + 6), 1000, stream, false).await; + assert_eq!(status, StatusCode::OK, "stream={stream}: {body}"); + assert!( + body.contains(r#""completion_tokens":0"#), + "control: the fixture must stop on its first pick: {body}" + ); + assert!(body.contains(r#""finish_reason":"stop""#), "stream={stream}: {body}"); + assert!(!body.contains(r#""finish_reason":"length""#), "stream={stream}: {body}"); + } +} + +/// With room to spare, the budget that ends the run is the REQUEST's. +#[tokio::test] +async fn an_unclamped_run_is_cut_at_the_request_budget() { + let (status, body) = chat(quantized_state(512), 4, false, true).await; + assert_eq!(status, StatusCode::OK, "{body}"); + let v: serde_json::Value = serde_json::from_str(&body).expect("json"); + assert_eq!(v["usage"]["completion_tokens"], 4, "{body}"); + assert_eq!(v["choices"][0]["finish_reason"], "length", "{body}"); +} diff --git a/crates/aprender-serve/src/api/types.rs b/crates/aprender-serve/src/api/types.rs index 1475a33a76..a13f613a7d 100644 --- a/crates/aprender-serve/src/api/types.rs +++ b/crates/aprender-serve/src/api/types.rs @@ -196,55 +196,10 @@ pub struct ModelsResponse { /// Why a completion stopped, in OpenAI's vocabulary. /// -/// Dogfood 0.63.0 (#2375 finding 6): the STREAMING chat path emitted the string -/// literal `"stop"` in its terminal chunk no matter what happened, while the -/// non-streaming path on the identical request correctly reported `"length"` -/// when the generation hit `max_tokens`. A client that streams therefore cannot -/// tell a truncated answer from a finished one, and every "continue from where -/// you stopped" flow silently breaks. -/// -/// The type exists so that literal cannot come back: the terminal-chunk -/// constructor takes a `FinishReason`, which is only obtainable from -/// [`FinishReason::from_generation`] (or an explicit, named variant). There is -/// no `&str` parameter left to hardcode. -#[derive(Debug, Clone, Copy, PartialEq, Eq)] -pub enum FinishReason { - /// The model emitted a stop token or a stop string matched. - Stop, - /// Generation was cut off at the `max_tokens` budget. - Length, -} - -impl FinishReason { - /// Decide the reason from what the generation actually did. - /// - /// Mirrors `finalize_chat_text` / `completion_finish_reason`: a matched stop - /// string wins over the budget, and a model that terminated early is - /// `Stop`. Only "ran to the budget with no stop match" is `Length`. - #[must_use] - pub fn from_generation(stopped: bool, completion_tokens: usize, max_tokens: usize) -> Self { - if !stopped && completion_tokens >= max_tokens { - Self::Length - } else { - Self::Stop - } - } - - /// The wire string OpenAI clients match on. - #[must_use] - pub fn as_str(self) -> &'static str { - match self { - Self::Stop => "stop", - Self::Length => "length", - } - } -} - -impl std::fmt::Display for FinishReason { - fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - f.write_str(self.as_str()) - } -} +/// Declared once in [`crate::infer::run_report`] so `apr run --json` and this +/// server spell the same outcome the same way (#3718); `infer` is not behind the +/// `server` feature, so the CLI can reach it without the HTTP stack. +pub use crate::infer::run_report::FinishReason; /// The OpenAI `n` field: how many completions the client asked for. /// diff --git a/crates/aprender-serve/src/gguf/inference/generate_quantized.rs b/crates/aprender-serve/src/gguf/inference/generate_quantized.rs index 059878fb6b..ab7d1da0fa 100644 --- a/crates/aprender-serve/src/gguf/inference/generate_quantized.rs +++ b/crates/aprender-serve/src/gguf/inference/generate_quantized.rs @@ -19,7 +19,7 @@ impl OwnedQuantizedModel { /// [`RealizarError::ContextLimitExceeded`] when the PROMPT alone exceeds the /// context window (GH-167) — that one is unsatisfiable, and callers map it to /// HTTP 400 because it is determined entirely by the request. - fn effective_max_tokens(&self, prompt_len: usize, requested: usize) -> Result { + pub(crate) fn effective_max_tokens(&self, prompt_len: usize, requested: usize) -> Result { if prompt_len > self.config.context_length { return Err(RealizarError::ContextLimitExceeded { provided: prompt_len, diff --git a/crates/aprender-serve/src/infer/inference_result.rs b/crates/aprender-serve/src/infer/inference_result.rs index c5fbc35b94..1130ef03e3 100644 --- a/crates/aprender-serve/src/infer/inference_result.rs +++ b/crates/aprender-serve/src/infer/inference_result.rs @@ -108,9 +108,26 @@ pub(crate) fn validate_model_path(path: &std::path::Path) -> Result<()> { /// - Model format is unsupported /// - Generation fails pub fn run_inference(config: &InferenceConfig) -> Result { + run_inference_report(config).map(|(result, _)| result) +} + +/// [`run_inference`], plus what only the decode path knows (#3718): why +/// generation ended and the model's context window. +/// +/// A separate entry point rather than new `InferenceResult` fields, so the +/// dozens of places that build an `InferenceResult` literal are untouched. +/// +/// # Errors +/// +/// Exactly those of [`run_inference`]. +pub fn run_inference_report( + config: &InferenceConfig, +) -> Result<(InferenceResult, run_report::RunReport)> { // PMAT-COV-95: Mock backend for testing without disk I/O if config.use_mock_backend { - return run_mock_inference(config); + let result = run_mock_inference(config)?; + let report = mock_run_report(config, &result); + return Ok((result, report)); } // GH-213: Detect sharded SafeTensors index.json BEFORE reading the file. @@ -123,7 +140,8 @@ pub fn run_inference(config: &InferenceConfig) -> Result { let format = ModelFormat::SafeTensors; let prepared = prepare_tokens(config, &format)?; - return run_sharded_safetensors_inference(config, &prepared); + return run_sharded_safetensors_inference(config, &prepared) + .map(|r| (r, run_report::RunReport::default())); } // Validate path to prevent traversal attacks (F-SEC-222) @@ -163,8 +181,27 @@ pub fn run_inference(config: &InferenceConfig) -> Result { match format { ModelFormat::Gguf => run_gguf_inference(config, &prepared), - ModelFormat::Apr => run_apr_inference(config, &prepared), - ModelFormat::SafeTensors => run_safetensors_inference(config, &prepared), + // Not reported on these paths yet: `None`, never a guess. + ModelFormat::Apr => { + run_apr_inference(config, &prepared).map(|r| (r, run_report::RunReport::default())) + }, + ModelFormat::SafeTensors => run_safetensors_inference(config, &prepared) + .map(|r| (r, run_report::RunReport::default())), + } +} + +/// The report for the mock backend: it generates `min(max_tokens, 32)` tokens +/// and no stop token, so a budget of 32 or less is spent and anything larger +/// ended as if on a stop. +fn mock_run_report(config: &InferenceConfig, result: &InferenceResult) -> run_report::RunReport { + let generated = result.tokens.get(result.input_token_count..).unwrap_or(&[]); + run_report::RunReport { + finish_reason: Some(run_report::FinishReason::from_decode( + generated, + &config.stop_tokens, + config.max_tokens, + )), + context_length: None, } } @@ -174,7 +211,7 @@ pub fn run_inference(config: &InferenceConfig) -> Result { fn run_gguf_inference( config: &InferenceConfig, prepared: &PreparedTokens, -) -> Result { +) -> Result<(InferenceResult, run_report::RunReport)> { use crate::gguf::{MappedGGUFModel, OwnedQuantizedModel, QuantizedGenerateConfig}; if config.verbose { @@ -291,17 +328,38 @@ fn run_gguf_inference( used_gpu, ); - Ok(InferenceResult { - text, - tokens, + // #3718: only the dense CPU loop (`generate_with_cache`) shrinks the budget to + // the context room; the hybrid, MoE, CUDA and wgpu loops run `max_tokens`. + let clamps_to_context = !is_qwen35 && canonical_arch != "qwen3_moe" && !used_gpu; + let budget = run_report::decode_budget( + gen_config.max_tokens, input_token_count, - generated_token_count, - inference_ms, - tok_per_sec: tps, - load_ms, - format: "GGUF".to_string(), - used_gpu, - }) + model_config.context_length, + clamps_to_context, + ); + let report = run_report::RunReport { + finish_reason: Some(run_report::FinishReason::from_decode( + generated_tokens, + &gen_config.stop_tokens, + budget, + )), + context_length: Some(model_config.context_length), + }; + + Ok(( + InferenceResult { + text, + tokens, + input_token_count, + generated_token_count, + inference_ms, + tok_per_sec: tps, + load_ms, + format: "GGUF".to_string(), + used_gpu, + }, + report, + )) } /// Print verbose model info for GGUF inference diff --git a/crates/aprender-serve/src/infer/mod.rs b/crates/aprender-serve/src/infer/mod.rs index 40c75ed64f..ea513812d9 100644 --- a/crates/aprender-serve/src/infer/mod.rs +++ b/crates/aprender-serve/src/infer/mod.rs @@ -575,3 +575,4 @@ include!("mod_05.rs"); include!("batch.rs"); pub mod qwen3_moe_generate; +pub mod run_report; diff --git a/crates/aprender-serve/src/infer/run_report.rs b/crates/aprender-serve/src/infer/run_report.rs new file mode 100644 index 0000000000..bec8788ce7 --- /dev/null +++ b/crates/aprender-serve/src/infer/run_report.rs @@ -0,0 +1,285 @@ +//! What a run owes its caller beyond the text (#3718). +//! +//! `apr run --json` reported the generated tokens and nothing about the prompt, so a +//! consumer that needed "how many tokens did the model actually read" rebuilt the +//! model's tokenizer from the GGUF to count them (RAH, #3716: 13,495 on one lane). And +//! a reply cut at `max_tokens` looked exactly like a reply that finished, so a +//! consumer could not tell a truncated verdict from a malformed one. +//! +//! [`RunReport`] carries the two facts only the decode path knows: why generation +//! ended, and the context window the prompt was measured against. The prompt count +//! itself is `InferenceResult::input_token_count`, which is the post-chat-template +//! count `prepare_tokens` fed to the model. + +/// Why generation ended. +/// +/// Shared by `apr run --json` and the OpenAI-compatible server (`api::types` +/// re-exports it), so both surfaces spell the same outcome the same way. +/// +/// Dogfood 0.63.0 (#2375 finding 6): the STREAMING chat path emitted the string +/// literal `"stop"` in its terminal chunk no matter what happened, while the +/// non-streaming path on the identical request correctly reported `"length"` +/// when the generation hit `max_tokens`. A client that streams therefore cannot +/// tell a truncated answer from a finished one, and every "continue from where +/// you stopped" flow silently breaks. +/// +/// The type exists so that literal cannot come back: the terminal-chunk +/// constructor takes a `FinishReason`, which is only obtainable from +/// [`FinishReason::from_generation`] (or an explicit, named variant). There is +/// no `&str` parameter left to hardcode. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum FinishReason { + /// The model emitted a stop token or a stop string matched. + Stop, + /// Generation was cut off at its token budget: `max_tokens`, or the room left + /// in the context window when a path shrinks the budget to fit it. + Length, +} + +impl FinishReason { + /// Decide the reason from what the generation actually did. + /// + /// Mirrors `finalize_chat_text` / `completion_finish_reason`: a matched stop + /// string wins over the budget, and a model that terminated early is + /// `Stop`. Only "ran to the budget with no stop match" is `Length`. + /// + /// `max_tokens` must be the budget the loop RAN with, not the one requested: + /// a server that clamps the request to the context window and then compares + /// against the unclamped number reports every clamped cut as `Stop` (#3718). + #[must_use] + pub fn from_generation(stopped: bool, completion_tokens: usize, max_tokens: usize) -> Self { + if !stopped && completion_tokens >= max_tokens { + Self::Length + } else { + Self::Stop + } + } + + /// Decide the reason from the tokens a decode loop returned. + /// + /// Every generate loop `apr run` reaches ends, short of an error, in one of two + /// ways: it sampled a stop token, or it spent its budget. The loops disagree + /// about the stop token itself. The Qwen3.5 hybrid, MoE and wgpu loops push it + /// and then break; the dense CPU and CUDA loops break before pushing. So the + /// last token alone cannot separate "stopped" from "cut": + /// + /// - a last token in `stop_tokens` is `Stop` (a loop that pushes it); + /// - otherwise a run that filled `budget` is `Length`; + /// - a shorter run can only have ended on a stop token its loop consumed + /// without pushing, which is `Stop`. + #[must_use] + pub fn from_decode(generated: &[u32], stop_tokens: &[u32], budget: usize) -> Self { + let ended_on_stop = generated.last().is_some_and(|t| stop_tokens.contains(t)); + Self::from_generation(ended_on_stop, generated.len(), budget) + } + + /// The wire string OpenAI clients match on. + #[must_use] + pub fn as_str(self) -> &'static str { + match self { + Self::Stop => "stop", + Self::Length => "length", + } + } +} + +impl std::fmt::Display for FinishReason { + fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + f.write_str(self.as_str()) + } +} + +/// The token budget a decode loop actually ran with. +/// +/// Only the dense CPU loop shrinks `max_tokens` to the room left in the context +/// window (`effective_max_tokens`, aprender#2376), so `clamps_to_context` is true +/// for that loop alone. Every other loop runs the request's `max_tokens` as is. +/// A prompt that does not fit at all is refused before this is asked +/// (`ContextLimitExceeded`), so the subtraction saturates only on paths that do +/// not check. +#[must_use] +pub fn decode_budget( + max_tokens: usize, + prompt_len: usize, + context_length: usize, + clamps_to_context: bool, +) -> usize { + if clamps_to_context { + max_tokens.min(context_length.saturating_sub(prompt_len)) + } else { + max_tokens + } +} + +/// What a run reports beyond [`super::InferenceResult`]. +/// +/// Each field is `None` on a path that does not know it, never a default that +/// reads as a measurement. The APR and SafeTensors paths report neither today. +#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)] +pub struct RunReport { + /// Why generation ended. + pub finish_reason: Option, + /// The model's context window, from its metadata. + pub context_length: Option, +} + +#[cfg(test)] +mod tests { + use super::*; + + const EOS: u32 = 7; + + /// The case table. Each row names the loop shape it stands for, because the + /// rule is only correct if it is correct for every shape. + #[test] + fn from_decode_case_table() { + let rows: &[(&str, &[u32], usize, FinishReason)] = &[ + // Loops that PUSH the stop token (qwen35, MoE, wgpu). + ("pushed stop, under budget", &[5, 6, EOS], 8, FinishReason::Stop), + ("pushed stop as the last budgeted token", &[5, 6, EOS], 3, FinishReason::Stop), + // Loops that CONSUME it (dense CPU, dense CUDA). + ("consumed stop, under budget", &[5, 6], 8, FinishReason::Stop), + ("consumed stop, nothing generated", &[], 8, FinishReason::Stop), + // The cut, on either shape. + ("budget spent, no stop", &[5, 6, 9], 3, FinishReason::Length), + ("zero budget", &[], 0, FinishReason::Length), + // A clamped budget (dense CPU at the context edge): the cut is below + // max_tokens, and it is still a cut. + ("clamped budget spent", &[5, 6], 2, FinishReason::Length), + ]; + for (name, generated, budget, want) in rows { + assert_eq!( + FinishReason::from_decode(generated, &[EOS], *budget), + *want, + "{name}" + ); + } + } + + /// The defect this rule exists for: a clamped cut compared against the + /// REQUESTED budget reads as a stop. Pinned so the call sites cannot regress + /// to passing `max_tokens` where the loop's budget belongs. + #[test] + fn clamped_cut_is_length_only_against_the_budget_it_ran_with() { + let generated = [5, 6, 9, 10]; + let requested = 256; + let ran_with = decode_budget(requested, 60, 64, true); + assert_eq!(ran_with, 4); + assert_eq!( + FinishReason::from_decode(&generated, &[EOS], requested), + FinishReason::Stop + ); + assert_eq!( + FinishReason::from_decode(&generated, &[EOS], ran_with), + FinishReason::Length + ); + } + + #[test] + fn decode_budget_clamps_only_when_the_loop_does() { + assert_eq!(decode_budget(100, 10, 64, true), 54); + assert_eq!(decode_budget(100, 10, 64, false), 100); + assert_eq!(decode_budget(20, 10, 64, true), 20); + assert_eq!(decode_budget(100, 70, 64, true), 0); + } + + #[test] + fn wire_strings_are_the_openai_ones() { + assert_eq!(FinishReason::Stop.as_str(), "stop"); + assert_eq!(FinishReason::Length.to_string(), "length"); + } + + #[test] + fn an_unreported_run_is_none_not_a_default_reason() { + let report = RunReport::default(); + assert_eq!(report.finish_reason, None); + assert_eq!(report.context_length, None); + } + + // ----------------------------------------------------------------------- + // Through `run_inference_report` on a real GGUF file: the dense CPU loop, + // which clamps its budget to the context and consumes its stop token. + // ----------------------------------------------------------------------- + + /// The pygmy GGUF's context window (`build_executable_pygmy_gguf`). + const PYGMY_CONTEXT: usize = 32; + + fn pygmy_file() -> tempfile::NamedTempFile { + use std::io::Write; + let mut file = tempfile::NamedTempFile::with_suffix(".gguf").expect("temp gguf"); + file.write_all(&crate::gguf::test_factory::build_executable_pygmy_gguf()) + .expect("write gguf"); + file.flush().expect("flush gguf"); + file + } + + fn run( + file: &tempfile::NamedTempFile, + prompt: Vec, + max_tokens: usize, + stop: Vec, + ) -> crate::error::Result<(super::super::InferenceResult, RunReport)> { + let config = super::super::InferenceConfig::new(file.path()) + .with_input_tokens(prompt) + .with_max_tokens(max_tokens) + .with_stop_tokens(stop) + .without_gpu(); + super::super::run_inference_report(&config) + } + + /// The case #3718 exists for, at the `apr run` layer: a request whose budget + /// is larger than the room left in the context. The dense CPU loop stops at + /// the context edge, short of `max_tokens`, and that is a cut. + #[test] + fn context_clamped_cut_reports_length_with_the_counts() { + let file = pygmy_file(); + let prompt = vec![1, 2, 3, 4]; + let (result, report) = run(&file, prompt.clone(), 1000, vec![]).expect("run"); + assert_eq!(result.input_token_count, prompt.len()); + assert_eq!(report.context_length, Some(PYGMY_CONTEXT)); + assert_eq!( + result.generated_token_count, + PYGMY_CONTEXT - prompt.len(), + "control: the loop must run to the context edge, or this is not measuring a clamp" + ); + assert_eq!(report.finish_reason, Some(FinishReason::Length)); + } + + #[test] + fn max_tokens_cut_reports_length() { + let file = pygmy_file(); + let (result, report) = run(&file, vec![1, 2, 3, 4], 3, vec![]).expect("run"); + assert_eq!(result.generated_token_count, 3); + assert_eq!(report.finish_reason, Some(FinishReason::Length)); + } + + /// The converse: a stop token under budget is `Stop`. The dense CPU loop + /// consumes it without pushing, so this is the "shorter run" branch. + #[test] + fn a_stop_token_under_budget_reports_stop() { + let file = pygmy_file(); + let prompt = vec![1, 2, 3, 4]; + let (first, _) = run(&file, prompt.clone(), 1, vec![]).expect("probe run"); + let first_token = first.tokens[prompt.len()]; + let (result, report) = run(&file, prompt, 10, vec![first_token]).expect("run"); + assert_eq!( + result.generated_token_count, 0, + "control: greedy is deterministic, so the probed token must stop the run at once" + ); + assert_eq!(report.finish_reason, Some(FinishReason::Stop)); + } + + /// A prompt that does not fit is refused, never cut to fit: done_when 3's + /// "or an error". + #[test] + fn a_prompt_longer_than_the_context_is_refused() { + let file = pygmy_file(); + let prompt: Vec = (0..(PYGMY_CONTEXT as u32 + 4)).map(|t| t % 32).collect(); + let err = run(&file, prompt, 4, vec![]).expect_err("an over-long prompt must be refused"); + let msg = err.to_string(); + assert!( + msg.contains(&(PYGMY_CONTEXT + 4).to_string()) && msg.contains(&PYGMY_CONTEXT.to_string()), + "the refusal must name the prompt length and the context: {msg}" + ); + } +} diff --git a/docs/roadmaps/entries/PMAT-3718.yaml b/docs/roadmaps/entries/PMAT-3718.yaml new file mode 100644 index 0000000000..6f3a25aa98 --- /dev/null +++ b/docs/roadmaps/entries/PMAT-3718.yaml @@ -0,0 +1,20 @@ +- id: PMAT-3718 + github_issue: 3718 + item_type: task + title: 'apr run --json: prompt_tokens + completion_tokens + finish_reason; serve usage and finish_reason never report a cut as a stop (#3718, RAH #3716)' + status: in_progress + priority: high + assigned_to: aprender-a8 + created: 2026-09-21T16:20:00Z + updated: 2026-09-21T16:20:00Z + spec: null + acceptance_criteria: + - 'Issue #3718 done_when 1, verbatim: "`apr run --json` emits `prompt_tokens` (the post-template token count actually fed to the model) and `completion_tokens`, and the numbers match the tokenizer (a case row checks a fixed prompt''s count)"' + - 'done_when 2, verbatim: "the same fields are in `apr serve`''s `/v1/chat/completions` `usage` object (OpenAI shape)"' + - 'done_when 3, verbatim: "a prompt truncated or refused for length says so in the JSON (`truncated: true` or an error), never a silent cut"' + phases: [] + subtasks: [] + estimated_effort: null + labels: + - kind:code + notes: 'PENDING — filled with the measured record before the quorum.' From d8405c6b503bc2e3138eb156f640d27f8730fdbb Mon Sep 17 00:00:00 2001 From: Noah Gift Date: Mon, 21 Sep 2026 19:09:45 +0200 Subject: [PATCH 2/5] PMAT-3718: rustfmt + the measured record in the fragment Co-Authored-By: Claude Opus 5 (1M context) --- crates/aprender-serve/src/infer/run_report.rs | 31 ++++++++++++++++--- docs/roadmaps/entries/PMAT-3718.yaml | 2 +- 2 files changed, 27 insertions(+), 6 deletions(-) diff --git a/crates/aprender-serve/src/infer/run_report.rs b/crates/aprender-serve/src/infer/run_report.rs index bec8788ce7..1855f3e60b 100644 --- a/crates/aprender-serve/src/infer/run_report.rs +++ b/crates/aprender-serve/src/infer/run_report.rs @@ -135,11 +135,31 @@ mod tests { fn from_decode_case_table() { let rows: &[(&str, &[u32], usize, FinishReason)] = &[ // Loops that PUSH the stop token (qwen35, MoE, wgpu). - ("pushed stop, under budget", &[5, 6, EOS], 8, FinishReason::Stop), - ("pushed stop as the last budgeted token", &[5, 6, EOS], 3, FinishReason::Stop), + ( + "pushed stop, under budget", + &[5, 6, EOS], + 8, + FinishReason::Stop, + ), + ( + "pushed stop as the last budgeted token", + &[5, 6, EOS], + 3, + FinishReason::Stop, + ), // Loops that CONSUME it (dense CPU, dense CUDA). - ("consumed stop, under budget", &[5, 6], 8, FinishReason::Stop), - ("consumed stop, nothing generated", &[], 8, FinishReason::Stop), + ( + "consumed stop, under budget", + &[5, 6], + 8, + FinishReason::Stop, + ), + ( + "consumed stop, nothing generated", + &[], + 8, + FinishReason::Stop, + ), // The cut, on either shape. ("budget spent, no stop", &[5, 6, 9], 3, FinishReason::Length), ("zero budget", &[], 0, FinishReason::Length), @@ -278,7 +298,8 @@ mod tests { let err = run(&file, prompt, 4, vec![]).expect_err("an over-long prompt must be refused"); let msg = err.to_string(); assert!( - msg.contains(&(PYGMY_CONTEXT + 4).to_string()) && msg.contains(&PYGMY_CONTEXT.to_string()), + msg.contains(&(PYGMY_CONTEXT + 4).to_string()) + && msg.contains(&PYGMY_CONTEXT.to_string()), "the refusal must name the prompt length and the context: {msg}" ); } diff --git a/docs/roadmaps/entries/PMAT-3718.yaml b/docs/roadmaps/entries/PMAT-3718.yaml index 6f3a25aa98..f25810807a 100644 --- a/docs/roadmaps/entries/PMAT-3718.yaml +++ b/docs/roadmaps/entries/PMAT-3718.yaml @@ -17,4 +17,4 @@ estimated_effort: null labels: - kind:code - notes: 'PENDING — filled with the measured record before the quorum.' + notes: 'SCOPE. The three done_when rows quoted above. `prefill_ms` is deliberately NOT emitted by this row. The cop''s lane message asked for it, but it is not in #3718''s done_when, and it is owned elsewhere: aprender-a8 and aprender-3e agreed one definition (wall-clock over the forward passes on the post-template prompt, up to the first token''s logits; load, h2d, the F2 validate and tokenization excluded; null, never 0, where a path does not split prefill). It rides #3606''s StageTimings and 3e''s #3596 timer (`run_qwen35_generate_dispatch_timed`, not on main). Wiring it into this JSON is a follow-up once those land. RUN (done_when 1, 3). New `realizar::infer::run_inference_report(config) -> (InferenceResult, RunReport)`; `run_inference` is a thin wrapper over it. It is a separate entry point so that none of the ~75 `InferenceResult` literals change. `RunReport { finish_reason, context_length }` is None on a path that does not report it (APR, SafeTensors), never a default. The GGUF path computes it where the stop set and the budget are known. `FinishReason::from_decode(generated, stop, budget)`: a last token in the stop set is Stop; otherwise a run that filled its budget is Length; a shorter run ended on a stop token its loop consumed. This rule holds for both loop shapes, traced: the qwen35 CPU/GPU, MoE and wgpu loops PUSH the stop token, the dense CPU (`generate_with_cache`) and CUDA (`decode_blocking`) loops break BEFORE pushing, and every loop''s only other non-error exit is its budget. `decode_budget` clamps to `context_length - prompt` only on the dense CPU loop, the one loop that does (`effective_max_tokens`). `FinishReason` is declared once, in `infer::run_report` (not behind the `server` feature); `api::types::FinishReason` is now a re-export. apr-cli: `RunUsage { prompt_tokens, completion_tokens, finish_reason, context_length }` on `RunResult`, emitted by `build_final_json`, so it appears in both `--json` and the `--stream` final event. `prompt_tokens` = `input_token_count`, the post-chat-template count including BOS that `prepare_tokens` fed the model. `completion_tokens` is the engine count, never the word-count stand-in `tokens_generated` falls back to. No path truncates a prompt (traced: `prepare_tokens` has no truncation). An over-long prompt is REFUSED (ContextLimitExceeded -> error exit), which is done_when 3''s "or an error"; the completion-side cut is now `finish_reason: length`, where before it was silent. SERVE (done_when 2, 3). `/v1/chat/completions` `usage` was already OpenAI-shaped with the post-template count on the realizar backends (`tokenize_chat_prompt`: template, encode, `len`). Three silent cuts are fixed. (a) The dense CPU backend (`try_quantized_backend`) judged finish against the REQUESTED max_tokens after `effective_max_tokens` had clamped the loop to the context room, so a context-clamped cut said "stop"; it is now judged against the budget the loop ran with, both streaming and not. (b) A prompt that cannot fit was a 500 (non-stream) or a 200 SSE carrying an error event that still ended "stop". It is now a 400 before generation on both, via the existing `generation_error_status`, whose doc already said callers map it to 400. (c) The APR CPU fallback (apr-cli handler_apr_cpu_completion.rs) hardcoded "stop" while capping max_tokens at 4096. It now uses `from_decode` against that cap with the loop''s real stop set (token 0, pushed; `is_eos_token`). Its `run_apr_cpu_inference` also returned the PROMPT as the completion when nothing was generated (`else { &output_tokens[..] }`); that now yields empty. MEASURED on lambda, CPU, Qwen3.5-0.8B-Q4_K_M, pinned `apr 0.69.0 (3fadee114)` via scripts/apr_bin.sh. `apr run -i <"What is 2+2? Answer with one number."> --chat --json`: prompt_tokens 24, context_length 262144. The same templated string through llama.cpp 41fc758 `llama-tokenize --ids` gives 24 ids, identical id-for-id to apr''s `--verbose` encode (with and without llama.cpp''s BOS policy). That is done_when 1''s case row against an independent tokenizer. max-tokens 4 and 1024: completion 2, finish stop (the model ends on EOS). A 20-line-poem prompt at max-tokens 6: completion 6, finish length. TESTS. infer::run_report: a case table over both loop shapes, the clamped-cut pin, budget arithmetic, and four rows through `run_inference_report` on the pygmy GGUF (context 32): a context-clamped cut is Length with 28 = 32 - 4 tokens, a max_tokens cut is Length, a stop token under budget is Stop (0 tokens, dense loop consumed it), and an over-long prompt is refused naming both lengths. api::tests::usage_finish_3718 runs through the real router on a quantized AppState: clamped cut -> length with usage prompt+completion == context, clamped stream -> terminal chunk length, prompt > context -> 400 on stream and non-stream, stop under budget -> stop (both), unclamped -> cut at the request budget. apr-cli run_tests_usage_3718: JSON carries the four fields, null (not 0 or "stop") when unreported, stream final event carries them. MUTANTS, each run and each RED: serve clamp reverted (2 red), 400 reverted to the old path (1), run-report clamp off (1), from_generation always Length (4), never Length (7). SUITES at 3fadee114 + rustfmt: `cargo test -p aprender-serve --lib` 15913 passed; `cargo test -p apr-cli --lib` 7301 passed; `cargo test -p aprender-contracts --lib` 1684 passed; clippy -D warnings on aprender-serve and apr-cli clean; fmt clean. KNOWN, NOT CHANGED. completion_tokens counts the pushed stop token on the qwen35/MoE/wgpu loops and not on the dense loops, because that is what each loop returns (measured: qwen35 `tokens: [17, 248046]`, completion 2). The CUDA backends were not exercised on hardware in this row: the report logic is backend-agnostic and clamps only on the dense CPU loop. Streaming chat does not apply stop STRINGS on the true-streaming path; that is pre-existing and not a length cut. Found while measuring and routed separately: `--prompt P --chat` double-templates (24 -> 56 prompt_tokens), which is #3743 = #3672 in batch-1.' From c5355eee846e50b4ecea8859cdaa18f2b814dbf5 Mon Sep 17 00:00:00 2001 From: Noah Gift Date: Mon, 21 Sep 2026 19:30:47 +0200 Subject: [PATCH 3/5] =?UTF-8?q?PMAT-3718:=20done=5Fwhen=201=20case=20row?= =?UTF-8?q?=20=E2=80=94=20a=20fixed=20text=20prompt=20through=20the=20GGUF?= =?UTF-8?q?=20tokenizer,=20count=20derived=20from=20the=20vocab?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-Authored-By: Claude Opus 5 (1M context) --- .../src/gguf/test_factory_create.rs | 33 +++++++++++------ crates/aprender-serve/src/infer/run_report.rs | 37 +++++++++++++++++++ docs/roadmaps/entries/PMAT-3718.yaml | 2 +- 3 files changed, 60 insertions(+), 12 deletions(-) diff --git a/crates/aprender-serve/src/gguf/test_factory_create.rs b/crates/aprender-serve/src/gguf/test_factory_create.rs index 3c335635f4..e2a7578943 100644 --- a/crates/aprender-serve/src/gguf/test_factory_create.rs +++ b/crates/aprender-serve/src/gguf/test_factory_create.rs @@ -298,6 +298,15 @@ pub fn build_minimal_llama_gguf( /// - num_layers: 1 #[must_use] pub fn build_executable_pygmy_gguf() -> Vec { + build_executable_pygmy_gguf_with(|builder| builder) +} + +/// [`build_executable_pygmy_gguf`] with extra metadata (a tokenizer, a chat +/// template) added by `metadata` before the tensors. +#[must_use] +pub fn build_executable_pygmy_gguf_with( + metadata: impl FnOnce(GGUFBuilder) -> GGUFBuilder, +) -> Vec { // Active Pygmy dimensions (T-COV-95) // All dimensions chosen to align with Q4_0's 32-element block size const VOCAB_SIZE: usize = 32; @@ -335,17 +344,19 @@ pub fn build_executable_pygmy_gguf() -> Vec { // This is separate from token_embd to avoid the "type 0" fallback let lm_head_data = create_q4_0_data(HIDDEN_DIM * VOCAB_SIZE); // 32x32 = 1024 elements - GGUFBuilder::new() - // Metadata - full LLaMA config - .architecture("llama") - .hidden_dim("llama", HIDDEN_DIM as u32) - .num_layers("llama", 1) - .num_heads("llama", NUM_HEADS as u32) - .num_kv_heads("llama", NUM_KV_HEADS as u32) - .context_length("llama", CONTEXT_LENGTH as u32) - .rope_freq_base("llama", 10000.0) - .rms_epsilon("llama", 1e-5) - .ffn_hidden_dim("llama", INTERMEDIATE_DIM as u32) + metadata( + GGUFBuilder::new() + // Metadata - full LLaMA config + .architecture("llama") + .hidden_dim("llama", HIDDEN_DIM as u32) + .num_layers("llama", 1) + .num_heads("llama", NUM_HEADS as u32) + .num_kv_heads("llama", NUM_KV_HEADS as u32) + .context_length("llama", CONTEXT_LENGTH as u32) + .rope_freq_base("llama", 10000.0) + .rms_epsilon("llama", 1e-5) + .ffn_hidden_dim("llama", INTERMEDIATE_DIM as u32), + ) // Token embedding - F32 (lookup table, not matmul) .add_f32_tensor( "token_embd.weight", diff --git a/crates/aprender-serve/src/infer/run_report.rs b/crates/aprender-serve/src/infer/run_report.rs index 1855f3e60b..0a87d790e5 100644 --- a/crates/aprender-serve/src/infer/run_report.rs +++ b/crates/aprender-serve/src/infer/run_report.rs @@ -289,6 +289,43 @@ mod tests { assert_eq!(report.finish_reason, Some(FinishReason::Stop)); } + /// done_when 1's case row: a fixed TEXT prompt through the GGUF's own + /// tokenizer, the path `apr run --prompt` takes. The expected ids are derived + /// by hand from the vocabulary, not from apr's encoder: under a SentencePiece + /// vocabulary that holds `▁Hello`, `▁world` and `!` whole, "Hello world!" is + /// ` ▁Hello ▁world !`, so a conforming tokenizer feeds 4 tokens. + #[test] + fn a_fixed_text_prompt_counts_the_tokens_the_tokenizer_feeds() { + use std::io::Write; + let mut vocab: Vec = ["", "", "", "▁Hello", "▁world", "!"] + .map(String::from) + .to_vec(); + vocab.extend((vocab.len()..32).map(|i| format!(""))); + let pieces: Vec<&str> = vocab.iter().map(String::as_str).collect(); + let bytes = crate::gguf::test_factory::build_executable_pygmy_gguf_with(|b| { + b.add_string("tokenizer.ggml.model", "llama") + .add_string_array("tokenizer.ggml.tokens", &pieces) + .add_u32("tokenizer.ggml.bos_token_id", 1) + .add_u32("tokenizer.ggml.eos_token_id", 2) + }); + let mut file = tempfile::NamedTempFile::with_suffix(".gguf").expect("temp gguf"); + file.write_all(&bytes).expect("write gguf"); + file.flush().expect("flush gguf"); + + let config = super::super::InferenceConfig::new(file.path()) + .with_prompt("Hello world!") + .with_max_tokens(2) + .without_gpu(); + let (result, report) = super::super::run_inference_report(&config).expect("run"); + assert_eq!( + result.tokens.get(..4), + Some(&[1, 3, 4, 5][..]), + "the prompt must be fed as ▁Hello ▁world !" + ); + assert_eq!(result.input_token_count, 4, "prompt_tokens is what was fed"); + assert_eq!(report.context_length, Some(PYGMY_CONTEXT)); + } + /// A prompt that does not fit is refused, never cut to fit: done_when 3's /// "or an error". #[test] diff --git a/docs/roadmaps/entries/PMAT-3718.yaml b/docs/roadmaps/entries/PMAT-3718.yaml index f25810807a..229ce1e760 100644 --- a/docs/roadmaps/entries/PMAT-3718.yaml +++ b/docs/roadmaps/entries/PMAT-3718.yaml @@ -17,4 +17,4 @@ estimated_effort: null labels: - kind:code - notes: 'SCOPE. The three done_when rows quoted above. `prefill_ms` is deliberately NOT emitted by this row. The cop''s lane message asked for it, but it is not in #3718''s done_when, and it is owned elsewhere: aprender-a8 and aprender-3e agreed one definition (wall-clock over the forward passes on the post-template prompt, up to the first token''s logits; load, h2d, the F2 validate and tokenization excluded; null, never 0, where a path does not split prefill). It rides #3606''s StageTimings and 3e''s #3596 timer (`run_qwen35_generate_dispatch_timed`, not on main). Wiring it into this JSON is a follow-up once those land. RUN (done_when 1, 3). New `realizar::infer::run_inference_report(config) -> (InferenceResult, RunReport)`; `run_inference` is a thin wrapper over it. It is a separate entry point so that none of the ~75 `InferenceResult` literals change. `RunReport { finish_reason, context_length }` is None on a path that does not report it (APR, SafeTensors), never a default. The GGUF path computes it where the stop set and the budget are known. `FinishReason::from_decode(generated, stop, budget)`: a last token in the stop set is Stop; otherwise a run that filled its budget is Length; a shorter run ended on a stop token its loop consumed. This rule holds for both loop shapes, traced: the qwen35 CPU/GPU, MoE and wgpu loops PUSH the stop token, the dense CPU (`generate_with_cache`) and CUDA (`decode_blocking`) loops break BEFORE pushing, and every loop''s only other non-error exit is its budget. `decode_budget` clamps to `context_length - prompt` only on the dense CPU loop, the one loop that does (`effective_max_tokens`). `FinishReason` is declared once, in `infer::run_report` (not behind the `server` feature); `api::types::FinishReason` is now a re-export. apr-cli: `RunUsage { prompt_tokens, completion_tokens, finish_reason, context_length }` on `RunResult`, emitted by `build_final_json`, so it appears in both `--json` and the `--stream` final event. `prompt_tokens` = `input_token_count`, the post-chat-template count including BOS that `prepare_tokens` fed the model. `completion_tokens` is the engine count, never the word-count stand-in `tokens_generated` falls back to. No path truncates a prompt (traced: `prepare_tokens` has no truncation). An over-long prompt is REFUSED (ContextLimitExceeded -> error exit), which is done_when 3''s "or an error"; the completion-side cut is now `finish_reason: length`, where before it was silent. SERVE (done_when 2, 3). `/v1/chat/completions` `usage` was already OpenAI-shaped with the post-template count on the realizar backends (`tokenize_chat_prompt`: template, encode, `len`). Three silent cuts are fixed. (a) The dense CPU backend (`try_quantized_backend`) judged finish against the REQUESTED max_tokens after `effective_max_tokens` had clamped the loop to the context room, so a context-clamped cut said "stop"; it is now judged against the budget the loop ran with, both streaming and not. (b) A prompt that cannot fit was a 500 (non-stream) or a 200 SSE carrying an error event that still ended "stop". It is now a 400 before generation on both, via the existing `generation_error_status`, whose doc already said callers map it to 400. (c) The APR CPU fallback (apr-cli handler_apr_cpu_completion.rs) hardcoded "stop" while capping max_tokens at 4096. It now uses `from_decode` against that cap with the loop''s real stop set (token 0, pushed; `is_eos_token`). Its `run_apr_cpu_inference` also returned the PROMPT as the completion when nothing was generated (`else { &output_tokens[..] }`); that now yields empty. MEASURED on lambda, CPU, Qwen3.5-0.8B-Q4_K_M, pinned `apr 0.69.0 (3fadee114)` via scripts/apr_bin.sh. `apr run -i <"What is 2+2? Answer with one number."> --chat --json`: prompt_tokens 24, context_length 262144. The same templated string through llama.cpp 41fc758 `llama-tokenize --ids` gives 24 ids, identical id-for-id to apr''s `--verbose` encode (with and without llama.cpp''s BOS policy). That is done_when 1''s case row against an independent tokenizer. max-tokens 4 and 1024: completion 2, finish stop (the model ends on EOS). A 20-line-poem prompt at max-tokens 6: completion 6, finish length. TESTS. infer::run_report: a case table over both loop shapes, the clamped-cut pin, budget arithmetic, and four rows through `run_inference_report` on the pygmy GGUF (context 32): a context-clamped cut is Length with 28 = 32 - 4 tokens, a max_tokens cut is Length, a stop token under budget is Stop (0 tokens, dense loop consumed it), and an over-long prompt is refused naming both lengths. api::tests::usage_finish_3718 runs through the real router on a quantized AppState: clamped cut -> length with usage prompt+completion == context, clamped stream -> terminal chunk length, prompt > context -> 400 on stream and non-stream, stop under budget -> stop (both), unclamped -> cut at the request budget. apr-cli run_tests_usage_3718: JSON carries the four fields, null (not 0 or "stop") when unreported, stream final event carries them. MUTANTS, each run and each RED: serve clamp reverted (2 red), 400 reverted to the old path (1), run-report clamp off (1), from_generation always Length (4), never Length (7). SUITES at 3fadee114 + rustfmt: `cargo test -p aprender-serve --lib` 15913 passed; `cargo test -p apr-cli --lib` 7301 passed; `cargo test -p aprender-contracts --lib` 1684 passed; clippy -D warnings on aprender-serve and apr-cli clean; fmt clean. KNOWN, NOT CHANGED. completion_tokens counts the pushed stop token on the qwen35/MoE/wgpu loops and not on the dense loops, because that is what each loop returns (measured: qwen35 `tokens: [17, 248046]`, completion 2). The CUDA backends were not exercised on hardware in this row: the report logic is backend-agnostic and clamps only on the dense CPU loop. Streaming chat does not apply stop STRINGS on the true-streaming path; that is pre-existing and not a length cut. Found while measuring and routed separately: `--prompt P --chat` double-templates (24 -> 56 prompt_tokens), which is #3743 = #3672 in batch-1.' + notes: 'SCOPE. The three done_when rows quoted above. `prefill_ms` is deliberately NOT emitted by this row. The cop''s lane message asked for it, but it is not in #3718''s done_when, and it is owned elsewhere: aprender-a8 and aprender-3e agreed one definition (wall-clock over the forward passes on the post-template prompt, up to the first token''s logits; load, h2d, the F2 validate and tokenization excluded; null, never 0, where a path does not split prefill). It rides #3606''s StageTimings and 3e''s #3596 timer (`run_qwen35_generate_dispatch_timed`, not on main). Wiring it into this JSON is a follow-up once those land. RUN (done_when 1, 3). New `realizar::infer::run_inference_report(config) -> (InferenceResult, RunReport)`; `run_inference` is a thin wrapper over it. It is a separate entry point so that none of the ~75 `InferenceResult` literals change. `RunReport { finish_reason, context_length }` is None on a path that does not report it (APR, SafeTensors), never a default. The GGUF path computes it where the stop set and the budget are known. `FinishReason::from_decode(generated, stop, budget)`: a last token in the stop set is Stop; otherwise a run that filled its budget is Length; a shorter run ended on a stop token its loop consumed. This rule holds for both loop shapes, traced: the qwen35 CPU/GPU, MoE and wgpu loops PUSH the stop token, the dense CPU (`generate_with_cache`) and CUDA (`decode_blocking`) loops break BEFORE pushing, and every loop''s only other non-error exit is its budget. `decode_budget` clamps to `context_length - prompt` only on the dense CPU loop, the one loop that does (`effective_max_tokens`). `FinishReason` is declared once, in `infer::run_report` (not behind the `server` feature); `api::types::FinishReason` is now a re-export. apr-cli: `RunUsage { prompt_tokens, completion_tokens, finish_reason, context_length }` on `RunResult`, emitted by `build_final_json`, so it appears in both `--json` and the `--stream` final event. `prompt_tokens` = `input_token_count`, the post-chat-template count including BOS that `prepare_tokens` fed the model. `completion_tokens` is the engine count, never the word-count stand-in `tokens_generated` falls back to. No path truncates a prompt (traced: `prepare_tokens` has no truncation). An over-long prompt is REFUSED (ContextLimitExceeded -> error exit), which is done_when 3''s "or an error"; the completion-side cut is now `finish_reason: length`, where before it was silent. SERVE (done_when 2, 3). `/v1/chat/completions` `usage` was already OpenAI-shaped with the post-template count on the realizar backends (`tokenize_chat_prompt`: template, encode, `len`). Three silent cuts are fixed. (a) The dense CPU backend (`try_quantized_backend`) judged finish against the REQUESTED max_tokens after `effective_max_tokens` had clamped the loop to the context room, so a context-clamped cut said "stop"; it is now judged against the budget the loop ran with, both streaming and not. (b) A prompt that cannot fit was a 500 (non-stream) or a 200 SSE carrying an error event that still ended "stop". It is now a 400 before generation on both, via the existing `generation_error_status`, whose doc already said callers map it to 400. (c) The APR CPU fallback (apr-cli handler_apr_cpu_completion.rs) hardcoded "stop" while capping max_tokens at 4096. It now uses `from_decode` against that cap with the loop''s real stop set (token 0, pushed; `is_eos_token`). Its `run_apr_cpu_inference` also returned the PROMPT as the completion when nothing was generated (`else { &output_tokens[..] }`); that now yields empty. MEASURED on lambda, CPU, Qwen3.5-0.8B-Q4_K_M, pinned `apr 0.69.0 (3fadee114)` via scripts/apr_bin.sh. `apr run -i <"What is 2+2? Answer with one number."> --chat --json`: prompt_tokens 24, context_length 262144. The same templated string through llama.cpp 41fc758 `llama-tokenize --ids` gives 24 ids, identical id-for-id to apr''s `--verbose` encode (with and without llama.cpp''s BOS policy). That is done_when 1''s case row against an independent tokenizer. max-tokens 4 and 1024: completion 2, finish stop (the model ends on EOS). A 20-line-poem prompt at max-tokens 6: completion 6, finish length. DONE_WHEN 1 CASE ROW, automated (added after the round-2 quorum FAIL, which correctly said a manual measurement is not a case row): infer::run_report::a_fixed_text_prompt_counts_the_tokens_the_tokenizer_feeds builds the pygmy GGUF with a SentencePiece vocabulary (` ▁Hello ▁world !` + filler; bos 1, eos 2) through the new `test_factory::build_executable_pygmy_gguf_with` metadata hook, runs the TEXT prompt "Hello world!" through `run_inference_report` (the `apr run --prompt` path: prepare_tokens_gguf, the GGUF tokenizer, BOS policy) and asserts the fed ids are [1, 3, 4, 5] and input_token_count (which becomes prompt_tokens) is 4. The expectation is derived by hand from the vocabulary, not from apr's encoder. Mutant: prepare_tokens_gguf reports tokens.len()-1 -> the row goes RED. The post-template count on a real model is the llama.cpp row above (24 == 24, id for id). TESTS. infer::run_report: a case table over both loop shapes, the clamped-cut pin, budget arithmetic, and four rows through `run_inference_report` on the pygmy GGUF (context 32): a context-clamped cut is Length with 28 = 32 - 4 tokens, a max_tokens cut is Length, a stop token under budget is Stop (0 tokens, dense loop consumed it), and an over-long prompt is refused naming both lengths. api::tests::usage_finish_3718 runs through the real router on a quantized AppState: clamped cut -> length with usage prompt+completion == context, clamped stream -> terminal chunk length, prompt > context -> 400 on stream and non-stream, stop under budget -> stop (both), unclamped -> cut at the request budget. apr-cli run_tests_usage_3718: JSON carries the four fields, null (not 0 or "stop") when unreported, stream final event carries them. MUTANTS, each run and each RED: serve clamp reverted (2 red), 400 reverted to the old path (1), run-report clamp off (1), from_generation always Length (4), never Length (7). SUITES at 3fadee114 + rustfmt: `cargo test -p aprender-serve --lib` 15913 passed; `cargo test -p apr-cli --lib` 7301 passed; `cargo test -p aprender-contracts --lib` 1684 passed; clippy -D warnings on aprender-serve and apr-cli clean; fmt clean. KNOWN, NOT CHANGED. completion_tokens counts the pushed stop token on the qwen35/MoE/wgpu loops and not on the dense loops, because that is what each loop returns (measured: qwen35 `tokens: [17, 248046]`, completion 2). The CUDA backends were not exercised on hardware in this row: the report logic is backend-agnostic and clamps only on the dense CPU loop. Streaming chat does not apply stop STRINGS on the true-streaming path; that is pre-existing and not a length cut. Found while measuring and routed separately: `--prompt P --chat` double-templates (24 -> 56 prompt_tokens), which is #3743 = #3672 in batch-1.' From 187b390e1dcfcd6c565d3f27aa779c06a60f8c82 Mon Sep 17 00:00:00 2001 From: Noah Gift Date: Mon, 21 Sep 2026 19:32:16 +0200 Subject: [PATCH 4/5] =?UTF-8?q?PMAT-3718:=20fragment=20=E2=80=94=20double?= =?UTF-8?q?=20the=20quote=20in=20apr's=20(YAML=20single-quoted=20scalar)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-Authored-By: Claude Opus 5 (1M context) --- docs/roadmaps/entries/PMAT-3718.yaml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/roadmaps/entries/PMAT-3718.yaml b/docs/roadmaps/entries/PMAT-3718.yaml index 229ce1e760..27b80c1fd5 100644 --- a/docs/roadmaps/entries/PMAT-3718.yaml +++ b/docs/roadmaps/entries/PMAT-3718.yaml @@ -17,4 +17,4 @@ estimated_effort: null labels: - kind:code - notes: 'SCOPE. The three done_when rows quoted above. `prefill_ms` is deliberately NOT emitted by this row. The cop''s lane message asked for it, but it is not in #3718''s done_when, and it is owned elsewhere: aprender-a8 and aprender-3e agreed one definition (wall-clock over the forward passes on the post-template prompt, up to the first token''s logits; load, h2d, the F2 validate and tokenization excluded; null, never 0, where a path does not split prefill). It rides #3606''s StageTimings and 3e''s #3596 timer (`run_qwen35_generate_dispatch_timed`, not on main). Wiring it into this JSON is a follow-up once those land. RUN (done_when 1, 3). New `realizar::infer::run_inference_report(config) -> (InferenceResult, RunReport)`; `run_inference` is a thin wrapper over it. It is a separate entry point so that none of the ~75 `InferenceResult` literals change. `RunReport { finish_reason, context_length }` is None on a path that does not report it (APR, SafeTensors), never a default. The GGUF path computes it where the stop set and the budget are known. `FinishReason::from_decode(generated, stop, budget)`: a last token in the stop set is Stop; otherwise a run that filled its budget is Length; a shorter run ended on a stop token its loop consumed. This rule holds for both loop shapes, traced: the qwen35 CPU/GPU, MoE and wgpu loops PUSH the stop token, the dense CPU (`generate_with_cache`) and CUDA (`decode_blocking`) loops break BEFORE pushing, and every loop''s only other non-error exit is its budget. `decode_budget` clamps to `context_length - prompt` only on the dense CPU loop, the one loop that does (`effective_max_tokens`). `FinishReason` is declared once, in `infer::run_report` (not behind the `server` feature); `api::types::FinishReason` is now a re-export. apr-cli: `RunUsage { prompt_tokens, completion_tokens, finish_reason, context_length }` on `RunResult`, emitted by `build_final_json`, so it appears in both `--json` and the `--stream` final event. `prompt_tokens` = `input_token_count`, the post-chat-template count including BOS that `prepare_tokens` fed the model. `completion_tokens` is the engine count, never the word-count stand-in `tokens_generated` falls back to. No path truncates a prompt (traced: `prepare_tokens` has no truncation). An over-long prompt is REFUSED (ContextLimitExceeded -> error exit), which is done_when 3''s "or an error"; the completion-side cut is now `finish_reason: length`, where before it was silent. SERVE (done_when 2, 3). `/v1/chat/completions` `usage` was already OpenAI-shaped with the post-template count on the realizar backends (`tokenize_chat_prompt`: template, encode, `len`). Three silent cuts are fixed. (a) The dense CPU backend (`try_quantized_backend`) judged finish against the REQUESTED max_tokens after `effective_max_tokens` had clamped the loop to the context room, so a context-clamped cut said "stop"; it is now judged against the budget the loop ran with, both streaming and not. (b) A prompt that cannot fit was a 500 (non-stream) or a 200 SSE carrying an error event that still ended "stop". It is now a 400 before generation on both, via the existing `generation_error_status`, whose doc already said callers map it to 400. (c) The APR CPU fallback (apr-cli handler_apr_cpu_completion.rs) hardcoded "stop" while capping max_tokens at 4096. It now uses `from_decode` against that cap with the loop''s real stop set (token 0, pushed; `is_eos_token`). Its `run_apr_cpu_inference` also returned the PROMPT as the completion when nothing was generated (`else { &output_tokens[..] }`); that now yields empty. MEASURED on lambda, CPU, Qwen3.5-0.8B-Q4_K_M, pinned `apr 0.69.0 (3fadee114)` via scripts/apr_bin.sh. `apr run -i <"What is 2+2? Answer with one number."> --chat --json`: prompt_tokens 24, context_length 262144. The same templated string through llama.cpp 41fc758 `llama-tokenize --ids` gives 24 ids, identical id-for-id to apr''s `--verbose` encode (with and without llama.cpp''s BOS policy). That is done_when 1''s case row against an independent tokenizer. max-tokens 4 and 1024: completion 2, finish stop (the model ends on EOS). A 20-line-poem prompt at max-tokens 6: completion 6, finish length. DONE_WHEN 1 CASE ROW, automated (added after the round-2 quorum FAIL, which correctly said a manual measurement is not a case row): infer::run_report::a_fixed_text_prompt_counts_the_tokens_the_tokenizer_feeds builds the pygmy GGUF with a SentencePiece vocabulary (` ▁Hello ▁world !` + filler; bos 1, eos 2) through the new `test_factory::build_executable_pygmy_gguf_with` metadata hook, runs the TEXT prompt "Hello world!" through `run_inference_report` (the `apr run --prompt` path: prepare_tokens_gguf, the GGUF tokenizer, BOS policy) and asserts the fed ids are [1, 3, 4, 5] and input_token_count (which becomes prompt_tokens) is 4. The expectation is derived by hand from the vocabulary, not from apr's encoder. Mutant: prepare_tokens_gguf reports tokens.len()-1 -> the row goes RED. The post-template count on a real model is the llama.cpp row above (24 == 24, id for id). TESTS. infer::run_report: a case table over both loop shapes, the clamped-cut pin, budget arithmetic, and four rows through `run_inference_report` on the pygmy GGUF (context 32): a context-clamped cut is Length with 28 = 32 - 4 tokens, a max_tokens cut is Length, a stop token under budget is Stop (0 tokens, dense loop consumed it), and an over-long prompt is refused naming both lengths. api::tests::usage_finish_3718 runs through the real router on a quantized AppState: clamped cut -> length with usage prompt+completion == context, clamped stream -> terminal chunk length, prompt > context -> 400 on stream and non-stream, stop under budget -> stop (both), unclamped -> cut at the request budget. apr-cli run_tests_usage_3718: JSON carries the four fields, null (not 0 or "stop") when unreported, stream final event carries them. MUTANTS, each run and each RED: serve clamp reverted (2 red), 400 reverted to the old path (1), run-report clamp off (1), from_generation always Length (4), never Length (7). SUITES at 3fadee114 + rustfmt: `cargo test -p aprender-serve --lib` 15913 passed; `cargo test -p apr-cli --lib` 7301 passed; `cargo test -p aprender-contracts --lib` 1684 passed; clippy -D warnings on aprender-serve and apr-cli clean; fmt clean. KNOWN, NOT CHANGED. completion_tokens counts the pushed stop token on the qwen35/MoE/wgpu loops and not on the dense loops, because that is what each loop returns (measured: qwen35 `tokens: [17, 248046]`, completion 2). The CUDA backends were not exercised on hardware in this row: the report logic is backend-agnostic and clamps only on the dense CPU loop. Streaming chat does not apply stop STRINGS on the true-streaming path; that is pre-existing and not a length cut. Found while measuring and routed separately: `--prompt P --chat` double-templates (24 -> 56 prompt_tokens), which is #3743 = #3672 in batch-1.' + notes: 'SCOPE. The three done_when rows quoted above. `prefill_ms` is deliberately NOT emitted by this row. The cop''s lane message asked for it, but it is not in #3718''s done_when, and it is owned elsewhere: aprender-a8 and aprender-3e agreed one definition (wall-clock over the forward passes on the post-template prompt, up to the first token''s logits; load, h2d, the F2 validate and tokenization excluded; null, never 0, where a path does not split prefill). It rides #3606''s StageTimings and 3e''s #3596 timer (`run_qwen35_generate_dispatch_timed`, not on main). Wiring it into this JSON is a follow-up once those land. RUN (done_when 1, 3). New `realizar::infer::run_inference_report(config) -> (InferenceResult, RunReport)`; `run_inference` is a thin wrapper over it. It is a separate entry point so that none of the ~75 `InferenceResult` literals change. `RunReport { finish_reason, context_length }` is None on a path that does not report it (APR, SafeTensors), never a default. The GGUF path computes it where the stop set and the budget are known. `FinishReason::from_decode(generated, stop, budget)`: a last token in the stop set is Stop; otherwise a run that filled its budget is Length; a shorter run ended on a stop token its loop consumed. This rule holds for both loop shapes, traced: the qwen35 CPU/GPU, MoE and wgpu loops PUSH the stop token, the dense CPU (`generate_with_cache`) and CUDA (`decode_blocking`) loops break BEFORE pushing, and every loop''s only other non-error exit is its budget. `decode_budget` clamps to `context_length - prompt` only on the dense CPU loop, the one loop that does (`effective_max_tokens`). `FinishReason` is declared once, in `infer::run_report` (not behind the `server` feature); `api::types::FinishReason` is now a re-export. apr-cli: `RunUsage { prompt_tokens, completion_tokens, finish_reason, context_length }` on `RunResult`, emitted by `build_final_json`, so it appears in both `--json` and the `--stream` final event. `prompt_tokens` = `input_token_count`, the post-chat-template count including BOS that `prepare_tokens` fed the model. `completion_tokens` is the engine count, never the word-count stand-in `tokens_generated` falls back to. No path truncates a prompt (traced: `prepare_tokens` has no truncation). An over-long prompt is REFUSED (ContextLimitExceeded -> error exit), which is done_when 3''s "or an error"; the completion-side cut is now `finish_reason: length`, where before it was silent. SERVE (done_when 2, 3). `/v1/chat/completions` `usage` was already OpenAI-shaped with the post-template count on the realizar backends (`tokenize_chat_prompt`: template, encode, `len`). Three silent cuts are fixed. (a) The dense CPU backend (`try_quantized_backend`) judged finish against the REQUESTED max_tokens after `effective_max_tokens` had clamped the loop to the context room, so a context-clamped cut said "stop"; it is now judged against the budget the loop ran with, both streaming and not. (b) A prompt that cannot fit was a 500 (non-stream) or a 200 SSE carrying an error event that still ended "stop". It is now a 400 before generation on both, via the existing `generation_error_status`, whose doc already said callers map it to 400. (c) The APR CPU fallback (apr-cli handler_apr_cpu_completion.rs) hardcoded "stop" while capping max_tokens at 4096. It now uses `from_decode` against that cap with the loop''s real stop set (token 0, pushed; `is_eos_token`). Its `run_apr_cpu_inference` also returned the PROMPT as the completion when nothing was generated (`else { &output_tokens[..] }`); that now yields empty. MEASURED on lambda, CPU, Qwen3.5-0.8B-Q4_K_M, pinned `apr 0.69.0 (3fadee114)` via scripts/apr_bin.sh. `apr run -i <"What is 2+2? Answer with one number."> --chat --json`: prompt_tokens 24, context_length 262144. The same templated string through llama.cpp 41fc758 `llama-tokenize --ids` gives 24 ids, identical id-for-id to apr''s `--verbose` encode (with and without llama.cpp''s BOS policy). That is done_when 1''s case row against an independent tokenizer. max-tokens 4 and 1024: completion 2, finish stop (the model ends on EOS). A 20-line-poem prompt at max-tokens 6: completion 6, finish length. DONE_WHEN 1 CASE ROW, automated (added after the round-2 quorum FAIL, which correctly said a manual measurement is not a case row): infer::run_report::a_fixed_text_prompt_counts_the_tokens_the_tokenizer_feeds builds the pygmy GGUF with a SentencePiece vocabulary (` ▁Hello ▁world !` + filler; bos 1, eos 2) through the new `test_factory::build_executable_pygmy_gguf_with` metadata hook, runs the TEXT prompt "Hello world!" through `run_inference_report` (the `apr run --prompt` path: prepare_tokens_gguf, the GGUF tokenizer, BOS policy) and asserts the fed ids are [1, 3, 4, 5] and input_token_count (which becomes prompt_tokens) is 4. The expectation is derived by hand from the vocabulary, not from apr''s encoder. Mutant: prepare_tokens_gguf reports tokens.len()-1 -> the row goes RED. The post-template count on a real model is the llama.cpp row above (24 == 24, id for id). TESTS. infer::run_report: a case table over both loop shapes, the clamped-cut pin, budget arithmetic, and four rows through `run_inference_report` on the pygmy GGUF (context 32): a context-clamped cut is Length with 28 = 32 - 4 tokens, a max_tokens cut is Length, a stop token under budget is Stop (0 tokens, dense loop consumed it), and an over-long prompt is refused naming both lengths. api::tests::usage_finish_3718 runs through the real router on a quantized AppState: clamped cut -> length with usage prompt+completion == context, clamped stream -> terminal chunk length, prompt > context -> 400 on stream and non-stream, stop under budget -> stop (both), unclamped -> cut at the request budget. apr-cli run_tests_usage_3718: JSON carries the four fields, null (not 0 or "stop") when unreported, stream final event carries them. MUTANTS, each run and each RED: serve clamp reverted (2 red), 400 reverted to the old path (1), run-report clamp off (1), from_generation always Length (4), never Length (7). SUITES at 3fadee114 + rustfmt: `cargo test -p aprender-serve --lib` 15913 passed; `cargo test -p apr-cli --lib` 7301 passed; `cargo test -p aprender-contracts --lib` 1684 passed; clippy -D warnings on aprender-serve and apr-cli clean; fmt clean. KNOWN, NOT CHANGED. completion_tokens counts the pushed stop token on the qwen35/MoE/wgpu loops and not on the dense loops, because that is what each loop returns (measured: qwen35 `tokens: [17, 248046]`, completion 2). The CUDA backends were not exercised on hardware in this row: the report logic is backend-agnostic and clamps only on the dense CPU loop. Streaming chat does not apply stop STRINGS on the true-streaming path; that is pre-existing and not a length cut. Found while measuring and routed separately: `--prompt P --chat` double-templates (24 -> 56 prompt_tokens), which is #3743 = #3672 in batch-1.' From a814867c955ec19ead85b75a5832b610e9129d61 Mon Sep 17 00:00:00 2001 From: Noah Gift Date: Mon, 21 Sep 2026 19:38:14 +0200 Subject: [PATCH 5/5] =?UTF-8?q?PMAT-3718:=20AD-04=20quorum=20receipt=20?= =?UTF-8?q?=E2=80=94=203/3=20PASS=20(gemini-3.1-pro-high=20x2,=20gemini-3.?= =?UTF-8?q?1-pro-low;=202=20distinct=20ids=20recorded)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-Authored-By: Claude Opus 5 (1M context) --- docs/audits/quorum-PMAT-3718.json | 241 ++++++++++++++++++++++++++++++ 1 file changed, 241 insertions(+) create mode 100644 docs/audits/quorum-PMAT-3718.json diff --git a/docs/audits/quorum-PMAT-3718.json b/docs/audits/quorum-PMAT-3718.json new file mode 100644 index 0000000000..4c907d2ced --- /dev/null +++ b/docs/audits/quorum-PMAT-3718.json @@ -0,0 +1,241 @@ +{ + "ticket": "PMAT-3718", + "base": "225b2a9ab", + "base_resolved": "225b2a9ab", + "base_note": "no origin/225b2a9ab exists; judged against the local ref", + "head": "187b390e1dcfcd6c565d3f27aa779c06a60f8c82", + "diff_sha256": "20f9de301805687f8fb0e6c0853636df2b1aa308c0fbc03c28fe5ff343120b8f", + "width": 3, + "executor": "agy", + "prompt_mode": "inline", + "prompt_bytes": 65794, + "author": { + "model": "claude-opus-5", + "family": "claude", + "source": "flag" + }, + "agreed": true, + "lanes": [ + { + "lane": 1, + "status": "SUCCESS", + "verdict": "PASS", + "summary": "The diff successfully implements PMAT-3718, correctly adding `prompt_tokens`, `completion_tokens`, and `finish_reason` to `apr run --json` and fixing `apr serve` endpoints to accurately report truncations. It resolves the silent stream cuts for clamped requests by judging the finish against the actual ran budget, maps unfittable prompts to a proper 400 error, and stops the APR CPU handler from echoing the prompt when no tokens are generated. The implementation conforms to all acceptance criteria and the provided receipt claims.", + "findings": [ + { + "claim": "Adds accurate token counts and finish_reason to CLI usage output using the actual engine count.", + "file": "crates/apr-cli/src/commands/inference_output.rs", + "grounding": "cited", + "line": 184 + }, + { + "claim": "Shadows max_tokens with clamped budget for correct length evaluation, and maps unfittable prompt errors to a 400 response.", + "file": "crates/aprender-serve/src/api/cuda_chat_backend.rs", + "grounding": "cited", + "line": 322 + }, + { + "claim": "Implements budget-aware finish reason determination correctly handling clamped runs and intrinsic stop token consumption.", + "file": "crates/aprender-serve/src/infer/run_report.rs", + "grounding": "cited", + "line": 39 + }, + { + "claim": "Fixes APR CPU fallback to yield empty instead of the prompt when nothing is generated, and uses `from_decode` to determine stop reason accurately.", + "file": "crates/apr-cli/src/commands/serve/handlers.rs", + "grounding": "cited", + "line": 1129 + } + ], + "raw_bytes": 4150, + "err_bytes": 0, + "envelope_status": "SUCCESS", + "verdict_source": "structured_output", + "grounding_check": "parity", + "model": "gemini-3.1-pro-high", + "model_measured": "gemini-3.1-pro-high", + "model_source": "measured", + "family": "gemini", + "role": "independent", + "fallback": { + "judged_by": "gemini-3.1-pro-high", + "exhausted": false, + "attempts": [ + { + "model": "gemini-3.1-pro-high", + "family": "gemini", + "outcome": "answered" + } + ], + "skipped": [] + } + }, + { + "lane": 2, + "status": "SUCCESS", + "verdict": "PASS", + "summary": "The diff strictly conforms to the acceptance criteria of PMAT-3718 and makes no unauthorized changes. `RunUsage` is implemented and emitted by `apr run --json` with `null` fallbacks. `FinishReason` correctly distinguishes cuts from stops via `from_decode`, fixing silent cuts in both CPU non-streaming and streaming `serve` paths. The context-clamped budgets are correctly used to evaluate the finish reason for the dense CPU loop, and over-long prompts now return a 400 error. The `a_fixed_text_prompt_counts_the_tokens_the_tokenizer_feeds` test adequately verifies the token count via the newly exposed `build_executable_pygmy_gguf_with` metadata hook. All receipt claims are backed by the code and tests.", + "findings": [], + "raw_bytes": 2788, + "err_bytes": 100, + "envelope_status": "SUCCESS", + "verdict_source": "structured_output", + "grounding_check": "parity", + "model": "gemini-3.1-pro-low", + "model_measured": "gemini-3.1-pro-low", + "model_source": "measured", + "family": "gemini", + "role": "independent", + "fallback": { + "judged_by": "gemini-3.1-pro-low", + "exhausted": false, + "attempts": [ + { + "model": "gemini-3.1-pro-low", + "family": "gemini", + "outcome": "answered" + } + ], + "skipped": [] + } + }, + { + "lane": 3, + "status": "SUCCESS", + "verdict": "PASS", + "summary": "The diff perfectly implements the requested features from PMAT-3718. It adds `prompt_tokens`, `completion_tokens`, `finish_reason`, and `context_length` to `apr run --json` using the new `RunUsage` structure and the `run_inference_report` hook, returning `null` when a specific backend does not report these metrics. \nFor `apr serve`, it correctly calculates the `finish_reason` in `/v1/chat/completions` against the effective clamped budget rather than the requested one, preventing context-clamped responses from being falsely reported as `stop`. It correctly throws a 400 error (instead of truncating or throwing a 500 after the fact) when the prompt exceeds the context window. \nThe comprehensive test additions and updates enforce these behaviors properly, including the exact `a_fixed_text_prompt_counts_the_tokens_the_tokenizer_feeds` case row required by the ticket's done criteria.", + "findings": [], + "raw_bytes": 3040, + "err_bytes": 0, + "envelope_status": "SUCCESS", + "verdict_source": "structured_output", + "grounding_check": "parity", + "model": "gemini-3.1-pro-high", + "model_measured": "gemini-3.1-pro-high", + "model_source": "measured", + "family": "gemini", + "role": "independent", + "fallback": { + "judged_by": "gemini-3.1-pro-high", + "exhausted": false, + "attempts": [ + { + "model": "gemini-3.1-pro-high", + "family": "gemini", + "outcome": "answered" + } + ], + "skipped": [] + } + } + ], + "dissent": [], + "dedup": [ + { + "file": "crates/apr-cli/src/commands/inference_output.rs", + "line": 184, + "lanes_agreeing": [ + 1 + ], + "claims": [ + "Adds accurate token counts and finish_reason to CLI usage output using the actual engine count." + ] + }, + { + "file": "crates/apr-cli/src/commands/serve/handlers.rs", + "line": 1129, + "lanes_agreeing": [ + 1 + ], + "claims": [ + "Fixes APR CPU fallback to yield empty instead of the prompt when nothing is generated, and uses `from_decode` to determine stop reason accurately." + ] + }, + { + "file": "crates/aprender-serve/src/api/cuda_chat_backend.rs", + "line": 322, + "lanes_agreeing": [ + 1 + ], + "claims": [ + "Shadows max_tokens with clamped budget for correct length evaluation, and maps unfittable prompt errors to a 400 response." + ] + }, + { + "file": "crates/aprender-serve/src/infer/run_report.rs", + "line": 39, + "lanes_agreeing": [ + 1 + ], + "claims": [ + "Implements budget-aware finish reason determination correctly handling clamped runs and intrinsic stop token consumption." + ] + } + ], + "uncovered": [], + "coverage_source": "lanes", + "partial": false, + "partial_reasons": [ + "lane models: only 2 distinct model ids across 3 lanes (gemini-3.1-pro-high, gemini-3.1-pro-low) — lanes sharing an id are resamples, not independent reviewers (PMAT-125)" + ], + "fallback": { + "same_family_width": 1, + "chain": [ + { + "model": "gemini-3.1-pro-high", + "family": "gemini", + "disposition": "configured" + }, + { + "model": "gemini-3.1-pro-low", + "family": "gemini", + "disposition": "configured" + }, + { + "model": "gpt-oss-120b-medium", + "family": "openai", + "disposition": "fallback" + }, + { + "model": "qwen3.5", + "family": "qwen", + "disposition": "not-run", + "why": "no quorum.local_lane in the config — the aprender lane has no model to load" + }, + { + "model": "claude-opus-4-6-thinking", + "family": "claude", + "disposition": "width", + "why": "same family as the author: at most 1 lane, recorded role width, counted toward no floor (R-15a)" + }, + { + "model": "claude-sonnet-4-6", + "family": "claude", + "disposition": "width", + "why": "same family as the author: at most 1 lane, recorded role width, counted toward no floor (R-15a)" + } + ], + "precheck": [ + { + "family": "gemini", + "model": "gemini-3.1-pro-high", + "probe": 1, + "outcome": "live" + } + ], + "prah": { + "source": "install-receipt", + "path": "/home/noah/.claude/skills/paiml-implement/bin/prah" + } + }, + "auto_merge": { + "checked": false, + "was_armed": false, + "disarmed": false, + "note": "no --pr given: nothing to disarm" + }, + "lint": { + "ok": true, + "output": "receipt complete: kind=artifact lanes=3 author=claude-opus-5/claude" + } +}