rbrooks/Quest-Board
Watch
1
0
Fork
You've already forked Quest-Board
 0
Code Issues 77 Pull requests 2 Projects Releases 42 Packages Wiki Activity Actions

[Backend] Hardware preflight's LLM probe fails on reasoning models, so the profile reads "Not measured" (#354) #507

New issue
Closed
opened 2026-09-05 07:31:47 +00:00 by claude-bot · 5 comments
claude-bot commented 2026-09-05 07:31:47 +00:00
Contributor
Copy link

Found validating v4.2.0 on dev (2026-09-05), against the bundled llama.cpp endpoint running qwen3.5.

run_preflight (#354) stores this for the LLM half:

"llm": {"probe": {"ok": false, "error": "LLM hit its output token limit (max_tokens) before producing any visible text (finish_reason='length'). If this is a reasoning model, it likely spent the whole budget on hidden reasoning — disable thinking at the endpoint, or raise max_tokens in Admin → Bot Settings.", "prompt_tokens": null, "completion_tokens": null, "tokens_per_second": null, "elapsed_seconds": 15.53}}
"profile": "unknown", "profile_label": "Not measured", "tokens_per_second": null
"expected_session": {"hours": 3.5, "complete": false, "asr_seconds": 895, "llm_seconds": null, "asr_basis": "measured over the last 2 run(s)", "llm_basis": "not measured"}

The ASR half is fine (realtime factor 0.12, retained fraction 0.12, basis "measured over the last 2 run(s)", which means it correctly consumed the #357 usage rows). The failure is specific to the probe's token budget: the same endpoint summarised two full synthetic sessions (12 LLM calls) and passed the #359 canary in the same hour. Capability discovery already flags reasoning: true for this model, so the probe is asking a thinking model for prose inside a budget its hidden reasoning consumes. This is the same endpoint property recorded earlier: prose needs max_tokens unset or well above 512.

Effect: any self-hoster on a reasoning model behind llama.cpp gets "Not measured" and no timeout profile, and the Admin → AI → Preflight panel shows an error for a configuration that works.

Proposed fix, in order of preference:

  1. Make the probe reasoning-aware: when the provider's capabilities declare reasoning, raise the probe's max_tokens to what a thinking model needs (or leave it unset) and measure tokens per second on the visible completion only.
  2. Failing that, raise the probe's max_tokens for everyone and accept a slower probe.

The error message is already right; it just should not be the normal outcome on the default self-hosted stack. Patch-sized, wants to go out in v4.2.1.

Found validating v4.2.0 on dev (2026-09-05), against the bundled llama.cpp endpoint running `qwen3.5`. `run_preflight` (#354) stores this for the LLM half: ``` "llm": {"probe": {"ok": false, "error": "LLM hit its output token limit (max_tokens) before producing any visible text (finish_reason='length'). If this is a reasoning model, it likely spent the whole budget on hidden reasoning — disable thinking at the endpoint, or raise max_tokens in Admin → Bot Settings.", "prompt_tokens": null, "completion_tokens": null, "tokens_per_second": null, "elapsed_seconds": 15.53}} "profile": "unknown", "profile_label": "Not measured", "tokens_per_second": null "expected_session": {"hours": 3.5, "complete": false, "asr_seconds": 895, "llm_seconds": null, "asr_basis": "measured over the last 2 run(s)", "llm_basis": "not measured"} ``` The ASR half is fine (realtime factor 0.12, retained fraction 0.12, basis "measured over the last 2 run(s)", which means it correctly consumed the #357 usage rows). The failure is specific to the probe's token budget: the same endpoint summarised two full synthetic sessions (12 LLM calls) and passed the #359 canary in the same hour. Capability discovery already flags `reasoning: true` for this model, so the probe is asking a thinking model for prose inside a budget its hidden reasoning consumes. This is the same endpoint property recorded earlier: prose needs `max_tokens` unset or well above 512. Effect: any self-hoster on a reasoning model behind llama.cpp gets "Not measured" and no timeout profile, and the Admin → AI → Preflight panel shows an error for a configuration that works. Proposed fix, in order of preference: 1. Make the probe reasoning-aware: when the provider's capabilities declare `reasoning`, raise the probe's `max_tokens` to what a thinking model needs (or leave it unset) and measure tokens per second on the visible completion only. 2. Failing that, raise the probe's `max_tokens` for everyone and accept a slower probe. The error message is already right; it just should not be the normal outcome on the default self-hosted stack. Patch-sized, wants to go out in v4.2.1.
claude-bot commented 2026-09-05 15:00:03 +00:00
Author
Contributor
Copy link

Picking this up for v4.2.1. Approach: probe_llm reads the resolved provider's declared reasoning capability and, when set, gives the probe the budget a thinking model needs instead of PROBE_MAX_TOKENS = 128; as a belt-and-braces path, a probe that hits the length limit with no visible text on a provider that did not declare reasoning retries once with the larger budget. Tokens per second is measured on what the provider reports as completion tokens, which on llama.cpp includes the reasoning tokens, and that is the right figure for extrapolating session time because the summariser pays for them too. Tests assert the max_tokens the probe sends for a reasoning and a non-reasoning provider.

Picking this up for **v4.2.1**. Approach: `probe_llm` reads the resolved provider's declared `reasoning` capability and, when set, gives the probe the budget a thinking model needs instead of `PROBE_MAX_TOKENS = 128`; as a belt-and-braces path, a probe that hits the length limit with no visible text on a provider that did *not* declare reasoning retries once with the larger budget. Tokens per second is measured on what the provider reports as completion tokens, which on llama.cpp includes the reasoning tokens, and that is the right figure for extrapolating session time because the summariser pays for them too. Tests assert the `max_tokens` the probe sends for a reasoning and a non-reasoning provider.
claude-bot commented 2026-09-05 15:44:27 +00:00
Author
Contributor
Copy link

Fixed in PR #509 (merged), shipping in v4.2.1.

The probe's output cap was a constant when it is really a capability question. 128 tokens is not a short answer for a thinking model, it is no answer at all: the hidden reasoning spends the whole budget before the first visible word, and llama.cpp returns finish_reason='length' with empty content. On the bundled stack with qwen3.5, the default self-hosted configuration, that failed every time.

Providers already declare this (LlmCapabilities.reasoning), so the declaration now chooses the budget: PROBE_MAX_TOKENS_REASONING = 2048 where it is declared, the cheap 128 everywhere else, resolved through llm_provider_for on the config like every generation path and never sniffed from the URL. Bounded rather than max_tokens=None, because an uncapped generation is unbounded in time on exactly the slow hardware the preflight exists to describe, and 2048 still fits inside the deadline at the slowest rate the bands call viable.

The declaration is per adapter and the model is the operator's choice, so a provider that declared no reasoning and ran out of budget anyway (the OpenAI adapter pointed at an o-series model, Ollama serving qwen3) is retried exactly once with the larger budget, and the result records retried_with_reasoning_budget so the panel can explain why that measurement took twice as long. One retry, never a loop.

Detection is structural, not textual: llm_service.OutputBudgetExhausted (a RuntimeError subclass, so every existing caller and test is unchanged) types the llama.cpp raise, and UsageMeter now keeps the truncation flag Usage has always carried per call, which is how the transports that return an empty string instead of raising are recognised. tokens_per_second still counts reasoning tokens, since they decode at the same rate and a real summarisation run pays for them through the same meter.

Residual, recorded rather than fixed: a sub-10 tok/s box running a thinking model can now hit the HTTP deadline instead of returning empty. That is a different failure message for a box that could not be measured before either, and once a run classifies it CPU the deadlines are 6×.

Nine new tests assert on the max_tokens that goes over the wire through the existing mock transport, not on a patched generate_structured_text. Full backend suite 2321 passed / 13 skipped, frontend 505 passed, ruff and eslint clean. Verify on dev after the v4.2.1 deploy: Admin → AI → Preflight should show a measured LLM rate and a profile band instead of "Not measured".

Fixed in PR #509 (merged), shipping in v4.2.1. The probe's output cap was a constant when it is really a capability question. 128 tokens is not a *short* answer for a thinking model, it is no answer at all: the hidden reasoning spends the whole budget before the first visible word, and llama.cpp returns `finish_reason='length'` with empty content. On the bundled stack with qwen3.5, the default self-hosted configuration, that failed every time. Providers already declare this (`LlmCapabilities.reasoning`), so the declaration now chooses the budget: `PROBE_MAX_TOKENS_REASONING = 2048` where it is declared, the cheap 128 everywhere else, resolved through `llm_provider_for` on the config like every generation path and never sniffed from the URL. Bounded rather than `max_tokens=None`, because an uncapped generation is unbounded in time on exactly the slow hardware the preflight exists to describe, and 2048 still fits inside the deadline at the slowest rate the bands call viable. The declaration is per adapter and the model is the operator's choice, so a provider that declared no reasoning and ran out of budget anyway (the OpenAI adapter pointed at an o-series model, Ollama serving qwen3) is retried exactly once with the larger budget, and the result records `retried_with_reasoning_budget` so the panel can explain why that measurement took twice as long. One retry, never a loop. Detection is structural, not textual: `llm_service.OutputBudgetExhausted` (a `RuntimeError` subclass, so every existing caller and test is unchanged) types the llama.cpp raise, and `UsageMeter` now keeps the truncation flag `Usage` has always carried per call, which is how the transports that return an empty string instead of raising are recognised. `tokens_per_second` still counts reasoning tokens, since they decode at the same rate and a real summarisation run pays for them through the same meter. Residual, recorded rather than fixed: a sub-10 tok/s box running a thinking model can now hit the HTTP deadline instead of returning empty. That is a different failure message for a box that could not be measured before either, and once a run classifies it CPU the deadlines are 6×. Nine new tests assert on the `max_tokens` that goes over the wire through the existing mock transport, not on a patched `generate_structured_text`. Full backend suite 2321 passed / 13 skipped, frontend 505 passed, ruff and eslint clean. Verify on dev after the v4.2.1 deploy: Admin → AI → Preflight should show a measured LLM rate and a profile band instead of "Not measured".
rbrooks referenced this issue from a commit 2026-09-05 16:03:00 +00:00
chore(release): v4.2.1
claude-bot commented 2026-09-05 16:30:08 +00:00
Author
Contributor
Copy link

Reopening: the v4.2.1 fix does not hold on the bundled stack. Live on dev after the v4.2.1 deploy, run_preflight produced:

llm.probe: {"ok": false, "max_tokens": 2048, "reasoning": true, "retried_with_reasoning_budget": false,
            "prompt_tokens": null, "completion_tokens": null, "tokens_per_second": null, "elapsed_seconds": 60.927,
            "error": "LLM hit its output token limit (max_tokens) before producing any visible text (finish_reason='length') ..."}
profile: unknown | Not measured

and the transport log line underneath: llama.cpp returned empty content (finish_reason='length', usage={'completion_tokens': 2048, 'prompt_tokens': 197, 'total_tokens': 2245, ...}).

So the declaration was honoured (reasoning: true, budget 2048) and qwen3.5 still spent the entire 2048 tokens thinking. Raising the cap further is the wrong lever: it is unbounded on this prompt, and a cap large enough for a 3090 is a deadline timeout on a CPU box.

The evidence also contains the fix. The endpoint reported 2048 completion tokens in 60.9 s, which is 33.6 tokens per second, and that is the measurement the preflight exists to take. Reasoning tokens decode at the same rate as visible ones, and a real summarisation run pays for them through the same meter (the point already made in the v4.2.1 comment). The probe was discarding a perfectly good throughput sample because the model had not finished its sentence.

Fix forward for v4.2.2: an exhausted output budget that comes with reported completion tokens is a successful rate measurement, with a separate flag saying no visible text was produced. The reasoning budget can then be modest (a few hundred tokens is a long enough decode sample and stays inside the deadline at CPU speeds); the retry for undeclared reasoning providers stays. The usage on the raise path must reach the meter or the exception, which is what the empty completion_tokens: null above shows it currently does not.

v4.2.1 is tagged and on dev; it is not going to prod. v4.2.2 will carry this and go to both.

**Reopening: the v4.2.1 fix does not hold on the bundled stack.** Live on dev after the v4.2.1 deploy, `run_preflight` produced: ``` llm.probe: {"ok": false, "max_tokens": 2048, "reasoning": true, "retried_with_reasoning_budget": false, "prompt_tokens": null, "completion_tokens": null, "tokens_per_second": null, "elapsed_seconds": 60.927, "error": "LLM hit its output token limit (max_tokens) before producing any visible text (finish_reason='length') ..."} profile: unknown | Not measured ``` and the transport log line underneath: `llama.cpp returned empty content (finish_reason='length', usage={'completion_tokens': 2048, 'prompt_tokens': 197, 'total_tokens': 2245, ...})`. So the declaration was honoured (`reasoning: true`, budget 2048) and qwen3.5 still spent the entire 2048 tokens thinking. Raising the cap further is the wrong lever: it is unbounded on this prompt, and a cap large enough for a 3090 is a deadline timeout on a CPU box. The evidence also contains the fix. The endpoint reported 2048 completion tokens in 60.9 s, which is 33.6 tokens per second, and that **is** the measurement the preflight exists to take. Reasoning tokens decode at the same rate as visible ones, and a real summarisation run pays for them through the same meter (the point already made in the v4.2.1 comment). The probe was discarding a perfectly good throughput sample because the model had not finished its sentence. Fix forward for v4.2.2: an exhausted output budget that comes with reported completion tokens is a successful *rate* measurement, with a separate flag saying no visible text was produced. The reasoning budget can then be modest (a few hundred tokens is a long enough decode sample and stays inside the deadline at CPU speeds); the retry for undeclared reasoning providers stays. The usage on the raise path must reach the meter or the exception, which is what the empty `completion_tokens: null` above shows it currently does not. v4.2.1 is tagged and on dev; it is **not** going to prod. v4.2.2 will carry this and go to both.
rbrooks referenced this issue from a commit 2026-09-05 17:05:51 +00:00
chore(release): v4.2.2
claude-bot commented 2026-09-05 17:28:41 +00:00
Author
Contributor
Copy link

Fixed for real in PR #512, shipping as v4.2.2. Verified live on dev.

The premise of the v4.2.1 fix was wrong rather than its number. Against llama.cpp serving qwen3.5 the probe spent all 2048 tokens thinking (60.9 s, finish_reason='length', no visible text) and reported "Not measured" a second time. Raising the cap further is no lever at all: the thinking is unbounded on this prompt, and any budget a 3090 can finish inside is a deadline timeout on a CPU box. But 2048 tokens in 60.9 s is 33.6 tok/s, which is the only figure the preflight exists to obtain. Reasoning tokens decode at the same rate as visible ones and measure_llm_tokens_per_run already counts them through the same meter. The probe was discarding a good throughput sample because the model had not finished its sentence.

What changed:

  • The llama.cpp transport records usage on the meter before raising OutputBudgetExhausted. It was the only transport raising ahead of _check_usage, which is why the probe saw completion_tokens: null while the transport's own log line printed 2048. Recorded directly rather than through _check_usage, which under json_mode raises before reaching the meter and would replace the typed exception. Session cost telemetry gains these tokens too, previously invisible GPU time.
  • An exhausted budget with reported tokens is a successful measurement: ok: true, visible_text: false, rate filled in, error: "", plus a note saying where the sample came from. An exhausted budget with no usage stays ok: false with the error, so a broken endpoint still reads as broken.
  • PROBE_MAX_TOKENS_REASONING 2048 → 512: a rate sample, not room for an answer (about 100 s at 5 tok/s, inside the 300 s deadline). PROBE_MAX_TOKENS stays 128, the single retry for undeclared reasoning providers stays, and the retry never replaces a measurement with a failure.
  • run_preflight already read the rate rather than probe["ok"], so the band, expected-session estimate and timeout profile follow; now stated in the code and covered end to end. Admin → Hardware profile explains a rate measured without a finished answer.

Live on dev, v4.2.2, same endpoint that failed twice before:

PROBE: {"ok": true, "visible_text": false, "max_tokens": 512, "reasoning": true, "retried_with_reasoning_budget": false,
        "prompt_tokens": 197, "completion_tokens": 512, "tokens_per_second": 25.41, "elapsed_seconds": 20.151, "error": ""}
PROFILE: modest | Modest GPU or fast CPU | tok/s: 25.41
EXPECTED_SESSION: {"hours": 3.5, "speakers": 5, "asr_seconds": 946, "llm_seconds": 808, "total_seconds": 1754, "complete": true,
                   "llm_basis": "extrapolated from 25.41 tok/s and this deployment's last 3 run(s)", "asr_basis": "measured over the last 3 run(s)"}

The 512-token sample reads 25.4 tok/s against 33.6 for the 2048-token one, which is the per-request overhead the retry comment predicted; it errs conservative, which is the right direction for a timeout profile. Backend 2335 passed / 13 skipped, frontend 509 passed, ruff and eslint clean. Closing once prod is on v4.2.2 and shows the same.

**Fixed for real in PR #512, shipping as v4.2.2. Verified live on dev.** The premise of the v4.2.1 fix was wrong rather than its number. Against llama.cpp serving qwen3.5 the probe spent all 2048 tokens thinking (60.9 s, `finish_reason='length'`, no visible text) and reported "Not measured" a second time. Raising the cap further is no lever at all: the thinking is unbounded on this prompt, and any budget a 3090 can finish inside is a deadline timeout on a CPU box. But 2048 tokens in 60.9 s **is** 33.6 tok/s, which is the only figure the preflight exists to obtain. Reasoning tokens decode at the same rate as visible ones and `measure_llm_tokens_per_run` already counts them through the same meter. The probe was discarding a good throughput sample because the model had not finished its sentence. What changed: - The llama.cpp transport records usage on the meter **before** raising `OutputBudgetExhausted`. It was the only transport raising ahead of `_check_usage`, which is why the probe saw `completion_tokens: null` while the transport's own log line printed 2048. Recorded directly rather than through `_check_usage`, which under `json_mode` raises before reaching the meter and would replace the typed exception. Session cost telemetry gains these tokens too, previously invisible GPU time. - An exhausted budget with reported tokens is a successful measurement: `ok: true`, `visible_text: false`, rate filled in, `error: ""`, plus a `note` saying where the sample came from. An exhausted budget with **no** usage stays `ok: false` with the error, so a broken endpoint still reads as broken. - `PROBE_MAX_TOKENS_REASONING` 2048 → 512: a rate sample, not room for an answer (about 100 s at 5 tok/s, inside the 300 s deadline). `PROBE_MAX_TOKENS` stays 128, the single retry for undeclared reasoning providers stays, and the retry never replaces a measurement with a failure. - `run_preflight` already read the rate rather than `probe["ok"]`, so the band, expected-session estimate and timeout profile follow; now stated in the code and covered end to end. Admin → Hardware profile explains a rate measured without a finished answer. **Live on dev, v4.2.2, same endpoint that failed twice before:** ``` PROBE: {"ok": true, "visible_text": false, "max_tokens": 512, "reasoning": true, "retried_with_reasoning_budget": false, "prompt_tokens": 197, "completion_tokens": 512, "tokens_per_second": 25.41, "elapsed_seconds": 20.151, "error": ""} PROFILE: modest | Modest GPU or fast CPU | tok/s: 25.41 EXPECTED_SESSION: {"hours": 3.5, "speakers": 5, "asr_seconds": 946, "llm_seconds": 808, "total_seconds": 1754, "complete": true, "llm_basis": "extrapolated from 25.41 tok/s and this deployment's last 3 run(s)", "asr_basis": "measured over the last 3 run(s)"} ``` The 512-token sample reads 25.4 tok/s against 33.6 for the 2048-token one, which is the per-request overhead the retry comment predicted; it errs conservative, which is the right direction for a timeout profile. Backend 2335 passed / 13 skipped, frontend 509 passed, ruff and eslint clean. Closing once prod is on v4.2.2 and shows the same.
claude-bot commented 2026-09-05 17:30:30 +00:00
Author
Contributor
Copy link

Prod is on v4.2.2 (17:28 UTC) and shows the same. Preflight against prod's own configuration: ok: true, visible_text: false, 512 tokens in 24.7 s → 20.75 tok/s, profile modest ("Modest GPU or fast CPU"), expected LLM time for a 3.5-hour session 578 s. The ASR half reads "not yet measured" there only because prod has no usage rows yet (its sessions predate #357); the first processed session fills it in. Closing.

**Prod is on v4.2.2 (17:28 UTC) and shows the same.** Preflight against prod's own configuration: `ok: true`, `visible_text: false`, 512 tokens in 24.7 s → **20.75 tok/s**, profile `modest` ("Modest GPU or fast CPU"), expected LLM time for a 3.5-hour session 578 s. The ASR half reads "not yet measured" there only because prod has no usage rows yet (its sessions predate #357); the first processed session fills it in. Closing.
Sign in to join this conversation.
No Branch/Tag specified
Branches Tags
main
ui/table-notes-label
renovate/npm-vitest-vulnerability
chore/87-align-python-3.12
v4.3.0
v4.2.3
v4.2.2
v4.2.1
v4.2.0
v4.1.2
v4.1.1
v4.1.0
v4.0.1
v4.0.0
v3.11.4
v3.11.3
v3.11.2
v3.11.1
v3.11.0
v3.10.0
v3.9.1
v3.9.0
v3.8.0
v3.7.0
v3.6.1
v3.6.0
v3.5.0
v3.4.1
v3.4.0
v3.3.0
v3.2.0
v3.1.0
v3.0.0
v2.1.0
v2.0.0
v1.1.0
v1.0.0
v0.12.0
v0.11.0
v0.10.0
v0.9.1
v0.3.3
v0.9.0
v0.8.0
v0.3.2
v0.3.1
v0.3.0
v0.7.0
v0.6.0
v0.5.0
v0.4.0
v0.2.1
v0.2.0
v0.1.1
v0.1.0
Labels
Clear labels   
backend
Issue related to the backend

  
bot
Issue related to the bot

  
bug
Something is not working

  
duplicate
This issue or pull request already exists

  
enhancement
New feature

  
frontend
Issue related to the frontend

  
help wanted
Need some help

  
invalid
Something is wrong

  
question
More information is needed

  
recording
Issue related to the recording system

  
security
Security hardening / vulnerability work

  
wontfix
This won't be fixed

No labels
backend
bot
bug
duplicate
enhancement
frontend
help wanted
invalid
question
recording
security
wontfix
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
rbrooks/Quest-Board#507
No description provided.