neuralwatt-router-service #2
Reference in New Issue
Block a user
Delete Branch "neuralwatt-router-service"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Big uplift weekend work.
Swapped on measurement, not on reputation. Same prompts, same system prompt, temperature 0, cold load excluded -- 14 unambiguous category cases and 5 tier probes: qwen3.5 mistral-nemo:12b category correct 10/14 9/14 tier correct 1/5 3/5 hard failures 4 of 19 0 latency mean/max 6.6s/15.6s 1.7s/1.9s Category accuracy is a wash and should not be the deciding factor. The failure column is. All four failures are the runaway-thinking-trace mode already documented for qwen3.5: ~15s of local inference producing no JSON, degrading to source="fallback" -- tier 2, general_chat. A reasoning model is simply the wrong tool for a job whose entire output is ~45 tokens of JSON, and it is the tail that hurts, not the mean: mistral-nemo's SLOWEST call is faster than qwen3.5's median. End-to-end /route went ~10s to ~1.7s. Both scored 5/5 discriminating good answers from refusals, wrong-question answers and incoherence, so the verifier moved with it and only one model needs to stay resident. think:False is accepted for a non-reasoning model, so that path needed no change. The prompt for this turned up a real pre-existing bug. Asked to explicitly set num_ctx, I checked what it actually is rather than assuming: Ollama 0.22 runs this model at n_ctx=32768, so the common advice to set 16384 would HALVE it. But testing the boundary showed the classifier falls apart well before that, and for an unrelated reason -- output budget, not input window: ~20k-token prompt qwen3.5 28.7s, finish_reason=length, empty content mistral-nemo 41.8s, echoed the input back inside its JSON Both surface as unparseable output. That is 30-40 seconds of local inference spent to reach the same fallback an instant failure would have produced, and it predates this swap -- neither model is at fault, the input is. classifier.max_input_chars (8000) clamps the classifier's input to head + tail with the middle elided. Head AND tail because the instruction sits at one end or the other depending on phrasing ("Translate this: <doc>" vs "<doc> -- translate this"), and the middle of a pasted document is the one region that never carries it. Nothing is lost by clamping: chat_completions measures the real conversation with estimate_prompt_tokens and takes the larger value, so required_context never depended on what the classifier saw. Same prompts now classify correctly in ~2.2s. Recorded as open item 6, because it is the one thing that got slightly worse and it is not small: neither local model can identify agentic work. On six unambiguous tool-use prompts qwen3.5 scored 2/6 and mistral-nemo 1/6. tool_use_agentic has the widest proficiency spread in the table (0.33-1.00) and deepseek-v4-flash, currently winning coding, sits at the bottom of it, so this is the most expensive classification error available. The fix is probably not a better classifier: whether a request is agentic is structurally observable, since agent clients send `tools` in the request body and chat_completions never looks at it. Tests 264 -> 271. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WSkcSD2Jzkxo1Kw27ecfXJmin_tool_proficiency is now null -- the tool-competence filter ships off, pending experiment. opencode sends `tools` on essentially every request, so with the filter on, deepseek-v4-flash is excluded from ordinary agent traffic and its ~7x cost advantage goes unused; with it off, a model measured at 0.33 on tool use handles requests where tools are available. Which is right is an empirical question and the 0.33 comes from 3 benchmark tasks. POST /outcome settles it: run with the filter off, let real pass/fail accumulate, and compare deepseek's tool_use_agentic proficiency before and after. feedback.py folds client outcomes in both directions, so successes count too. Auditing which settings existed only as code defaults found a real bug in the previous commit. classifier.max_input_chars had been written into the `verification:` block instead of `classifier:`, because `max_output_tokens: 1024` appears in BOTH sections and the edit anchored on the first match. Pydantic's default extra="ignore" accepted it, discarded it, and left the code default in force -- which carried the same value, so behaviour was correct and the config file was a lie. Editing that line would have done nothing. So the fix is the class, not the instance. Every config model now inherits StrictModel (extra="forbid"), and both of these fail at load: verification.max_input_chars # right key, wrong section routing.min_tool_proficency # sic A test asserts the shipped config.yaml has no unknown keys, so the whole file is guarded rather than the sections a test happens to name. This matters most to whoever is tuning the file, which is the entire point of putting knobs there. Also removed classifier.outcome_attribution_window_seconds: declared, never read, and shadowing verification.outcome_attribution_window_seconds, which is the one dispatcher.py actually uses. Verified live that the filter is off -- identical /v1/chat/completions bodies differing only by the `tools` array now both route to deepseek-v4-flash, where before they split. Tests 276 -> 281. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WSkcSD2Jzkxo1Kw27ecfXJ`observed_at` is written by `datetime.now(timezone.utc).isoformat()`, which separates date from time with 'T': 2026-08-23T00:20:04.577131+00:00 `datetime('now', '-120 seconds')` returns a space instead: 2026-08-23 00:18:04 Compared as TEXT, 'T' (0x54) sorts after ' ' (0x20), so once the two dates match the time of day never participates. The window was not 120 seconds, it was "everything served today" -- and near midnight it reached into yesterday as well. Measured against the live router.db: the query as written matched 14 rows across 2 distinct session_keys, while the same query through julianday() matched 0. That is what produced the 409s. `_most_recent_if_unambiguous` saw two conversations where there had been one for hours, so `POST /outcome` refused reports it should have attributed -- and it made verification.outcome_attribution_window_seconds inert at every value, which is the worse half: the setting was tuned from 30 minutes down to 120 seconds to fix exactly this symptom, and the tuning could not have done anything. `quota_burn` had the same defect on its '-30 days' bound, worth about a day of slop on a 30-day sum. Both now compare instants via julianday(), the form poller.mark_stale already used. julianday() parses the stored offset and normalizes to UTC, and nothing is lost to it -- there is no index on observed_at. The tests write their timestamps through the same isoformat() call the dispatcher uses, so they stay honest if the write format changes, and they place the "old" row at the first instant of the current UTC day: sharing today's date is precisely what the string comparison needed to go wrong. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WSkcSD2Jzkxo1Kw27ecfXJscore_code ran `passed = proc.stdout.count("PASS")`, and the harness executes the model's code as `__main__`. Models routinely append a demo block: if __name__ == "__main__": print("self-test:", add(1, 2) == 3 and "PASS" or "FAIL") That line is printed into the same stdout the verdicts are read from, so it was counted as a passing check. Measured: a two-check task scored 1.50. Nothing downstream clamped it. score_judge bounds its output to [0, 1] and score_code did not, so `accumulate` and `blend` -- plain arithmetic both -- carried it into blended_score. A proficiency above 1.0 is not a local error: rank_candidates takes `best = max(proficiency_score)` and measures every other candidate's band from it, so one inflated row moves the quality band for the whole comparison. Two changes, because either alone is a half-fix. The verdict lines now carry a per-run nonce (`CHECK-<8 random bytes>`) and are parsed strictly, by check INDEX rather than counted -- the model cannot predict the nonce, so it cannot vote on its own work, and indexing bounds the total at len(checks) even if a line repeats. And add_self_eval clamps to [0, 1], because proficiency_store is documented as the one path every write goes through, and that promise is worth something only if it is enforced there. This is the fourth harness bug in this project to score the rig rather than the model. The other three deflated -- an empty content field, a leading space, an unparseable judge reply -- and were caught by reading per-task detail that looked impossibly bad. This one inflated, which is why it survived: a model scoring 1.00 on coding looks like the good news the summary already reported. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WSkcSD2Jzkxo1Kw27ecfXJWatching a live agent session against the router showed one thing: uvicorn[42989]: INFO: 127.0.0.1:37458 - "POST /v1/chat/completions" 200 OK That was the whole story, because the dispatcher had no logger. It had four print(file=sys.stderr) calls and every one of them was a failure path, so a request that WORKED said nothing -- not the category, the tier, the model chosen, the cost, or the latency. The access line does not even name the model that served it. This commit is the machinery; the events themselves come next. Three parts, in order of how much they matter. A TRACE ID per request, in a ContextVar so helpers read it without every signature growing a parameter. One request touches classification, filtering, ranking, dispatch, verification and possibly a retry, and nothing tied those together before. set_trace() exists for the streaming path specifically: a StreamingResponse's generator is iterated from a different context than the endpoint that built it, so the ContextVar set in the endpoint is invisible inside the generator -- and that is the path all agent traffic takes. LOGFMT rather than prose. `route id=r7f3a91 cat=coding_general pick=...` reads fine in journalctl and greps without a JSON parser. Values are quoted only when they need it, None renders as `-`, and floats get six significant figures so a microdollar cost is readable instead of 0.0007830000000000001. A newline inside a value is flattened: one event must be one line, or a detail string could forge a record. REAL JOURNALD PRIORITIES. systemd strips a `<N>` prefix and records the message at that priority (SyslogLevelPrefix defaults to true), which is what makes `journalctl -p warning` mean anything -- until now every line landed at PRIORITY 6 and severity could not be filtered at all. The prefix is emitted only when $JOURNAL_STREAM is set, which systemd exports when it owns our stderr and a shell does not, so a foreground uvicorn prints clean lines instead of a literal <6> on each one. The level lives in config.yaml per the usual rule, but LLM_ROUTER_LOG_LEVEL overrides it, because turning up a running service should not mean editing a tracked file and leaving a stray diff. The four existing prints are converted rather than left alongside. Two parallel logging systems is how the next one gets missed. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WSkcSD2Jzkxo1Kw27ecfXJThe machinery landed last commit; these are the events. What a routed request now leaves behind, at info: route id=r9116d9 cat=coding_refactor tier=2 ctx=500 src=classifier tools=0 latency=interactive cand=8 pick=deepseek-v4-flash est_usd=0.00016296 prof=1 ms=1868 dispatch id=r9116d9 model=deepseek-v4-flash rid=chatcmpl-... sess=c090d751 p_tok=59511 c_tok=415 kwh=4.8e-05 usd=0.000783 verdict=unverifiable upstream_ms=3980 total_ms=5692 `rid` and `sess` are columns in energy_observations, so a journal line pivots to its database row and back with a --grep. That is why no schema change was needed to get traceability. At debug it also says why, which is the half that was never recorded anywhere: classify id=r9116d9 cat=coding_refactor tier=2 ctx=500 confidence=0.95 ms=1863 filter id=r9116d9 model=gemma-4-31b reason=tier(1<2) filter id=r9116d9 model=glm-5.2-short reason=access_level(preview) filter id=r9116d9 model=kimi-k3-flex reason=latency_class(flex) rank id=r9116d9 pos=0 model=deepseek-v4-flash prof=1 est_usd=0.00016296 Those reasons come from routing.rejection_reason, which is is_eligible turned inside out: it returns the failing filter and its numbers instead of False, and is_eligible is now a one-line wrapper over it. One copy of the rules, so the log cannot drift from the decision it describes. log_decision is called by the ENDPOINTS, not by route(). chat_completions routes twice whenever the measured conversation exceeds the classifier's estimate -- with opencode sending ~32K of system prompt, essentially always -- and logging inside route() would double every line for no new information. Two things the tests caught that reasoning had not: The streaming path could not use the ContextVar. starlette resumes the generator through a threadpool and every next() gets a fresh COPY of the caller's context, so a trace id set inside is gone by the finally block that logs the dispatch line. It logged id=- until the id was carried explicitly by logs.bind() -- on the path all agent traffic takes. $JOURNAL_STREAM is inherited. A foreground uvicorn started from a systemd-managed session, output redirected to a file, put a literal <7> on every line: the variable was set, but described a stream that was no longer ours. It is now compared against the actual fd's device:inode, which is what systemd documents. A test asserts no conversation text reaches the log at any level, prompt or answer. Prompts here run 60k-150k tokens and the journal is on disk. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WSkcSD2Jzkxo1Kw27ecfXJLive traffic through the new logging showed every agent request as: route ... cat=coding_refactor tier=2 ctx=56308 src=override tools=1 `src=override` means "the client chose this", and the client chose nothing. chat_completions routes a second time when the measured conversation exceeds the classifier's estimate -- with opencode sending ~32K of system prompt, on essentially every request -- and that second call passes category and tier back in, so the resulting Classification reads source='override'. The classifier had in fact run and decided both; only the context figure was replaced. A traceability field that misreports where a decision came from is worse than no field, because it is confidently wrong in the direction someone debugging would act on: it points at the client for a choice the router made. The line now carries both, separately: route ... ctx=56308 ctx_src=measured src=classifier tools=1 ctx_src is caller | classifier | measured, so /route and /dispatch report their own provenance honestly too. Found by reading the live journal after deploying, not by a test -- the tests stub the classifier and never exercised the re-route path, which is the one all real traffic takes. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WSkcSD2Jzkxo1Kw27ecfXJopencode strips image parts client-side unless a provider model declares input image modality. Every llm-router model now carries modalities {input: [text, image]} so image requests actually reach the router, which then gates on supports_vision (or falls back to local vision). Same change applied locally to ~/.config/opencode/opencode.json (outside this repo). Ultraworked with [Sisyphus](https://github.com/code-yeongyu/oh-my-openagent) Co-authored-by: Sisyphus <clio-agent@sisyphuslabs.ai>