ForgeLM/experiments/worklog.md

Autoresearch Worklog: latency-p95-chat-completions

Session Summary

• Objective: reduce end-to-end p95 latency for local POST /v1/chat/completions
• Primary metric: p95_ms (lower is better)
• Secondary metrics: p50_ms, mean_ms, completion_tps_mean, success_count
• Benchmark harness: ./autoresearch.sh

Key Insights

• The first stable end-to-end benchmark is around 0.94 s p95 for a short non-streaming coding request on the local 4B GGUF model.
• The benchmark harness must use the canonical model id derived from the GGUF filename; the current server build does not actually honor the intended local-model alias path yet.
• Prompt prefill is only about 25 ms for this workload, so almost all latency sits in token generation rather than request parsing or prompt construction.
• A micro-optimization in per-token detokenization made both latency and throughput worse, which suggests the dominant cost is deeper in the generation/runtime path rather than heap allocation in Rust glue code.
• Shrinking the Turbo4B context and batch sizes also hurt throughput, so the current 4B profile appears closer to the local optimum for this hardware/workload than expected.
• Disabling internal llama.cpp perf counters produced the first real p95 improvement over baseline, which suggests a small but measurable amount of hot-path CPU overhead was coming from instrumentation rather than model math.
• Better stop behavior improved average and median latency, but it still failed to beat baseline p95, so the worst outliers are not explained solely by turn-boundary overruns.
• Switching to a Qwen-style chat template produced a severe p95 tail regression while median latency stayed near baseline, which strongly suggests worse stop behavior or occasional runaway generations rather than uniformly slower decoding.

Next Ideas

• Measure baseline first, then inspect the hottest latency contributors in prompt preparation, request handling, and session creation.
• Investigate why ModelCatalog rejects local-model despite intending to expose aliases.

Run 1: baseline - p95_ms=941.252 (KEEP)

• Timestamp: 2026-03-26 17:32
• What changed: Established the autoresearch harness, built the release server, started it against the local Qwen GGUF, and measured a fixed non-streaming coding request workload.
• Result: p95_ms=941.252, p50_ms=908.457, mean_ms=917.123, completion_tps_mean=52.427, success_count=7.
• Insight: The baseline is stable enough to compare future server/runtime changes, and the benchmark immediately exposed a compatibility bug in alias resolution that should be kept separate from true latency experiments.
• Next: fix low-risk benchmark-adjacent correctness issues only if they distort measurement; otherwise inspect hot latency contributors in the request/session path.

Run 2: stack buffer detokenization - p95_ms=1032.315 (DISCARD)

• Timestamp: 2026-03-26 17:38
• What changed: Replaced the per-token heap allocation in decode_token_piece_with() with a 256-byte stack buffer and heap fallback in crates/inference-core/src/session.rs.
• Result: p95_ms=1032.315, p50_ms=1020.402, mean_ms=1011.466, completion_tps_mean=47.671, success_count=7.
• Insight: This path is not the practical bottleneck for end-to-end latency here; generation got slower overall despite the reduced allocation churn.
• Next: discard this branch state and focus on runtime/profile-level experiments that can improve generation throughput directly.

Run 3: slim turbo4b runtime profile - p95_ms=1004.435 (DISCARD)

• Timestamp: 2026-03-26 17:40
• What changed: Reduced Turbo4B defaults in crates/inference-core/src/profile.rs from n_ctx=4096, n_batch=512, n_ubatch=128 to n_ctx=2048, n_batch=256, n_ubatch=64.
• Result: p95_ms=1004.435, p50_ms=998.919, mean_ms=990.771, completion_tps_mean=48.528, success_count=7.
• Insight: The leaner profile still reduced effective generation speed on this RTX 3070 + Q6_K workload, so the current batch/context sizing is likely not the source of the baseline latency.
• Next: revert to the best-known commit and target generation semantics or model-facing prompt/template strategy rather than detokenization or profile shrinkage.

Run 6: disable llama perf counters in hot path - p95_ms=925.587 (KEEP)

• Timestamp: 2026-03-26 17:57
• What changed: Set llama_context_params.no_perf = true in crates/inference-core/src/engine.rs and sampler_chain_default_params.no_perf = true in crates/inference-core/src/session.rs.
• Result: p95_ms=925.587, p50_ms=893.913, mean_ms=899.895, completion_tps_mean=53.618, success_count=7.
• Insight: Disabling internal perf bookkeeping shaved about 1.7% off baseline p95 with slightly better overall throughput, making this the first experiment worth keeping.
• Next: continue from this commit and look for adjacent hot-path flags or runtime settings that reduce generation overhead without changing model behavior.

Run 5: default turn-boundary stops - p95_ms=965.663 (DISCARD)

• Timestamp: 2026-03-26 17:54
• What changed: Added rolling multi-token stop detection in crates/inference-core/src/session.rs and injected default turn-boundary stop sequences in crates/inference-server/src/compat.rs when the request did not specify stop.
• Result: p95_ms=965.663, p50_ms=877.030, mean_ms=897.251, completion_tps_mean=53.686, success_count=7.
• Insight: This reduced median and mean latency and slightly improved throughput, but the p95 still stayed above baseline, so tail latency likely comes from a smaller number of deeper generation stalls rather than just missed stop boundaries.
• Next: inspect per-sample latency spread and target the remaining long-tail outliers directly, likely in warmup/first-request behavior or occasional decode stalls.

Run 4: qwen-style chat template - p95_ms=3027.145 (DISCARD)

• Timestamp: 2026-03-26 17:50
• What changed: Replaced the plain System/User/Assistant: prompt format in crates/inference-server/src/compat.rs with a Qwen-style <|im_start|>...<|im_end|> chat template.
• Result: p95_ms=3027.145, p50_ms=974.937, mean_ms=1467.026, completion_tps_mean=41.360, success_count=7.
• Insight: The template did not make typical requests much faster and introduced severe tail latency, likely because some generations stopped much later or followed a worse decoding path for this server/model combination.
• Next: revert this template change and focus on experiments that directly bound generation length or improve stop behavior without overhauling the prompt format.

Segment 1: Dynamic Chat Templates

• New objective: add dynamic prompt templates by model family with built-in coverage for Qwen, Gemma, Llama, Kimi, and a generic fallback.
• Benchmark driver: ./autoresearch.sh now runs ignored template-specific tests and reports template_score, passed_cases, failed_cases, and total_cases.
• Keep/discard rule for this segment is test-driven: higher template_score wins, while the regular non-ignored test suite must remain green.
• A minimal family detector plus embedded template registry in compat.rs was enough to move coverage from 1/5 to 5/5 without touching the runtime.

Run 7: baseline - template_score=20.0 (KEEP)

• Timestamp: 2026-03-26 18:14
• What changed: Re-initialized autoresearch to a new segment focused on dynamic chat templates, added a dedicated ignored test suite for Qwen, Gemma, Llama, Kimi, and generic fallback behavior, and switched the benchmark harness to score that suite.
• Result: template_score=20.0, passed_cases=1, failed_cases=4, total_cases=5.
• Insight: Only the generic fallback works today; all named family-template expectations fail because prompt rendering is still generic and model-agnostic.
• Next: add a minimal model-family detector and template registry in crates/inference-server/src/compat.rs, then route prepare_prompt() through it.

Run 8: add family-based chat templates - template_score=100.0 (KEEP)

• Timestamp: 2026-03-26 18:16
• What changed: Added model-family detection and template-aware prompt rendering in crates/inference-server/src/compat.rs for Qwen, Gemma, Llama, Kimi, and generic fallback, then routed system/tool/JSON-mode instructions and assistant prefixes through the selected template.
• Result: template_score=100.0, passed_cases=5, failed_cases=0, total_cases=5.
• Insight: The current seam in prepare_prompt() is sufficient for broad family-based template support; no runtime or routing changes were needed for the first successful implementation.
• Next: harden the design by adding alias-driven family detection, safer fallback behavior for mixed-case/variant model names, and more coverage for tool-call and response-format rendering under non-generic templates.

Segment 2: Dynamic Chat Template Hardening

• New objective: keep family-based template selection, but harden structure-sensitive formatting for instruct-style models, starting with Llama.
• Benchmark driver: ./autoresearch.sh still runs the ignored template suite, now with stricter Llama assertions.
• Keep/discard rule remains test-driven: higher template_score wins while the regular non-ignored suite stays green.

Run 9: baseline - template_score=71.429 (KEEP)

• Timestamp: 2026-03-26 18:21
• What changed: Expanded the ignored benchmark suite with two stronger Llama assertions that require system+user to be merged into the first instruction block and forbid leaving an open [INST] prefix at generation time.
• Result: template_score=71.429, passed_cases=5, failed_cases=2, total_cases=7.
• Insight: The current family detector is good enough, but the Llama renderer is still structurally naive; it over-produces instruction blocks and leaves the prompt in an invalid generation state.
• Next: refactor Llama rendering into a dedicated formatter that folds system context into the first user turn and emits a proper assistant generation prefix.

Run 10: harden llama chat template rendering - template_score=100.0 (KEEP)

• Timestamp: 2026-03-26 18:23
• What changed: Reworked the Llama path in crates/inference-server/src/compat.rs into a dedicated renderer that accumulates pending system/developer content, folds it into the next user/tool instruction block, and stops emitting a dangling open assistant [INST] prefix.
• Result: template_score=100.0, passed_cases=7, failed_cases=0, total_cases=7.
• Insight: Llama needed a specialized formatter instead of the generic per-message helper; once the prompt was rendered as proper closed instruction blocks with folded system context, the hardening suite passed cleanly.
• Next: raise the benchmark again around multi-turn continuity, tool-role placement, or alias-driven family detection so the next experiments target real edge cases instead of already-solved happy paths.

Segment 3: Alias-Driven Template Selection

• New objective: harden family detection so template selection can still infer the right family from an alias even when the canonical/root model id is generic.
• Benchmark driver: ./autoresearch.sh still runs the ignored template suite, now expanded with alias-sensitive cases.
• Keep/discard rule remains test-driven: higher template_score wins while the regular non-ignored suite stays green.

Run 11: baseline - template_score=88.889 (KEEP)

• Timestamp: 2026-03-26 18:27
• What changed: Expanded the ignored benchmark suite with alias-sensitive family-selection coverage, especially a case where the canonical model id is generic but the requested alias carries the qwen family hint.
• Result: template_score=88.889, passed_cases=8, failed_cases=1, total_cases=9.
• Insight: The family templates and fallback behavior are otherwise stable; the remaining gap is specifically that select_chat_template() loses the alias hint when it resolves through a generic canonical/root id.
• Next: make template selection consider both the requested model string and the resolved catalog/root metadata, preferring whichever one contains a recognized family marker.

Run 12: detect template family from aliases - template_score=100.0 (KEEP)

• Timestamp: 2026-03-26 18:28
• What changed: Updated select_chat_template() in crates/inference-server/src/compat.rs to evaluate the requested model name first, then resolved alias/canonical/root ids, so family hints present only in aliases still drive template selection.
• Result: template_score=100.0, passed_cases=9, failed_cases=0, total_cases=9.
• Insight: Alias-aware selection closes the last known family-detection gap without needing extra catalog metadata; simple ordered candidate matching is enough here.
• Next: raise the benchmark again around multi-turn continuity, tool-call/tool-role rendering, or family-specific response-format instructions to target subtler correctness gaps.

Segment 4: Variant Family Detection

• New objective: harden family detection for common model-name variants, starting with Moonshot-branded Kimi aliases.
• Benchmark driver: ./autoresearch.sh still runs the ignored template suite, now expanded with variant-sensitive cases.
• Keep/discard rule remains test-driven: higher template_score wins while the regular non-ignored suite stays green.

Run 13: baseline - template_score=90.909 (KEEP)

• Timestamp: 2026-03-26 18:32
• What changed: Expanded the ignored template suite with Moonshot/Kimi variant coverage, including one positive Moonshot alias case and one near-name generic fallback case.
• Result: template_score=90.909, passed_cases=10, failed_cases=1, total_cases=11.
• Insight: The only remaining gap is that select_chat_template() recognizes kimi but not the common moonshot naming variant; nearby names like moonshine already fall back safely.
• Next: extend family detection so Moonshot-branded aliases map to the Kimi template without broadening the match so far that unrelated names stop using the generic fallback.

Run 14: detect moonshot as kimi family - template_score=100.0 (KEEP)

• Timestamp: 2026-03-26 18:33
• What changed: Extended select_chat_template() in crates/inference-server/src/compat.rs so candidate names containing moonshot are treated as the Kimi family alongside direct kimi matches.
• Result: template_score=100.0, passed_cases=11, failed_cases=0, total_cases=11.
• Insight: A narrow Moonshot variant match closes the Kimi-family naming gap cleanly without breaking safe generic fallback for unrelated names such as moonshine-local.
• Next: raise the benchmark around multi-turn continuity, tool-role rendering, or family-specific response-format instructions.

Segment 5: CLI Control Surface

• New objective: build a complete management CLI first, ahead of the Tauri app, on top of the current backend version.
• Benchmark driver: ./autoresearch.sh now runs ignored CLI-surface tests and reports cli_surface_score, passed_cases, failed_cases, and total_cases.
• Keep/discard rule is test-driven: higher cli_surface_score wins while the regular non-ignored suite remains green.
• This segment starts by benchmarking the command surface itself before deeper execution and backend-admin semantics are implemented.

Run 15: baseline - cli_surface_score=18.182 (KEEP)

• Timestamp: 2026-03-26 18:53
• What changed: Initialized a new crates/localllm-cli crate with a minimal Clap-based CLI scaffold, switched the autoresearch harness from template tests to CLI surface tests, and defined the first ignored benchmark suite for professional command coverage.
• Result: cli_surface_score=18.182, passed_cases=2, failed_cases=9, total_cases=11.
• Insight: The scaffold already covers global flags plus status and models list, but almost the entire promised management surface is still missing.
• Next: add the remaining top-level command groups and model/auth/config/bench/logs/doctor subcommands so the CLI surface matches the intended product contract before wiring execution internals.

Run 16: expand cli command surface - cli_surface_score=100.0 (KEEP)

• Timestamp: 2026-03-26 18:55
• What changed: Expanded crates/localllm-cli/src/main.rs into a broad Clap parser with top-level status, models, auth, config, bench, logs, and doctor commands plus the expected model/auth/config/throughput subcommands and global flags.
• Result: cli_surface_score=100.0, passed_cases=11, failed_cases=0, total_cases=11.
• Insight: The professional CLI contract can be locked in quickly at the parser layer before execution internals exist; Clap gives a maintainable foundation for the full management surface.
• Next: raise the benchmark from command presence to semantic correctness, starting with command-specific arguments, defaults, and output-contract expectations for the highest-value workflows.

Segment 6: CLI Semantic Contracts

• New objective: keep the CLI surface stable, but raise the benchmark so key commands preserve useful semantic detail such as defaults, high-value arguments, and summary/intention contracts.
• Benchmark driver: ./autoresearch.sh still runs ignored localllm-cli tests and reports cli_surface_score, passed_cases, failed_cases, and total_cases.
• Keep/discard rule remains test-driven: higher cli_surface_score wins while the normal non-ignored suites remain green.

Segment 7: CLI Execution Plans

• New objective: raise the CLI benchmark from human-readable semantic summaries to machine-usable execution plans for key workflows.
• Benchmark driver: ./autoresearch.sh still runs ignored localllm-cli tests and reports cli_surface_score, passed_cases, failed_cases, and total_cases.
• Keep/discard rule remains test-driven: higher cli_surface_score wins while the normal non-ignored suites remain green.

Run 19: baseline - cli_surface_score=69.565 (KEEP)

• Timestamp: 2026-03-26 19:04
• What changed: Expanded the CLI benchmark with plan-oriented ignored tests that require key commands to map into machine-usable CommandPlan variants instead of only semantic summaries.
• Result: cli_surface_score=69.565, passed_cases=16, failed_cases=7, total_cases=23.
• Insight: The semantic summary layer is already solid, but plan_command() is still a stub that collapses everything to SummaryOnly, so execution planning has not been wired yet.
• Next: implement concrete CommandPlan mapping for status, models scan/load, auth enable, config set, bench throughput, and logs.

Run 20: add cli execution plans - cli_surface_score=100.0 (KEEP)

• Timestamp: 2026-03-26 19:05
• What changed: Implemented concrete CommandPlan mapping in crates/localllm-cli/src/main.rs for status, model scan/load, auth enable, config set, throughput bench, and logs while leaving lower-priority commands on SummaryOnly.
• Result: cli_surface_score=100.0, passed_cases=23, failed_cases=0, total_cases=23.
• Insight: The CLI now has a machine-usable planning layer for the highest-value workflows, which is a stronger base for later real handlers and Tauri reuse than summary strings alone.
• Next: raise the benchmark from structured plans to execution-ready request payloads or output contracts at the backend/control-plane seam.

Segment 8: CLI Execution Contracts

• New objective: turn the highest-value CommandPlan variants into concrete execution contracts that describe the exact HTTP or local operation each workflow intends to perform.
• Benchmark driver: ./autoresearch.sh still runs ignored localllm-cli tests and reports cli_surface_score, passed_cases, failed_cases, and total_cases.
• Keep/discard rule remains test-driven: higher cli_surface_score wins while the normal non-ignored suites remain green.

Run 17: baseline - cli_surface_score=68.75 (KEEP)

• Timestamp: 2026-03-26 18:59
• What changed: Raised the benchmark with summary-focused ignored tests that require render_command_summary() to preserve output format, models directory, command-specific arguments, and key defaults for status, models load, auth enable, bench throughput, and logs.
• Result: cli_surface_score=68.75, passed_cases=11, failed_cases=5, total_cases=16.
• Insight: The parser surface is solid, but the current summary layer is too shallow; it only reports the top-level command and server, losing the semantic detail needed for later execution planning.
• Next: upgrade render_command_summary() so it emits nested command paths and the highest-value arguments/defaults for each management workflow.

Run 18: enrich cli semantic summaries - cli_surface_score=100.0 (KEEP)

• Timestamp: 2026-03-26 19:00
• What changed: Reworked render_command_summary() in crates/localllm-cli/src/main.rs to emit nested command paths plus key defaults and high-value arguments for status, models, auth, config, bench, and logs workflows.
• Result: cli_surface_score=100.0, passed_cases=16, failed_cases=0, total_cases=16.
• Insight: A lightweight semantic/intention layer is enough to make the CLI contract meaningfully richer before wiring real handlers; the CLI now preserves actionable detail instead of collapsing everything to top-level groups.
• Next: raise the benchmark again toward execution planning or output contracts, e.g. structured action plans for backend/admin operations rather than just human-readable summaries.