Skip to content

feat(obs): run + attempt latency histograms, configurable REFINE_TIMEOUT - #232

Open
wanyiwang06 wants to merge 3 commits into
Mininglamp-OSS:mainfrom
wanyiwang06:feat/obs-histogram-worker-path
Open

feat(obs): run + attempt latency histograms, configurable REFINE_TIMEOUT#232
wanyiwang06 wants to merge 3 commits into
Mininglamp-OSS:mainfrom
wanyiwang06:feat/obs-histogram-worker-path

Conversation

@wanyiwang06

@wanyiwang06 wanyiwang06 commented Aug 27, 2026

Copy link
Copy Markdown
Contributor

Problem

llm_call_duration_seconds_total (from #219) is a cumulative sum. Divided by llm_calls_total it yields a mean, and a mean over this workload describes no real request: refine calls are sub-second while long-context agent turns are documented at 60–100s in internal/agent/llm.go.

#220 defers the final LLM_TIMEOUT value to per-scenario P95/P99 ("不直接规定 LLM_TIMEOUT=60,最终值应结合各场景 P95/P99 决定"). Those percentiles require bucket counts, which no metric in the repo currently produces.

Change

internal/llmobs: two latency histograms

llm_run_duration_seconds{path} — whole-Run wall-clock, including backoff sleeps and every model tried. Use it to size parent budgets (REFINE_TIMEOUT, AGENT_STEP_TIMEOUT).

llm_attempt_duration_seconds{path,outcome} — a single upstream attempt. Use it to size the per-attempt LLM_TIMEOUT.

The split matters: LLM_TIMEOUT is applied per attempt (http.Client.Timeout in service/llm.go, the per-attempt context in agent/llm.go), but a run's wall-clock also carries backoffs and earlier models. On the happy path they coincide, so a run-level P95 is roughly usable — a run-level P99 is not, because the P99 is the retried runs. AttemptEvent.Duration was already delivered to ObserveAttempt and discarded.

Buckets are fixed at package scope (0.5s → 300s) so paths stay comparable. Labels are deliberately narrow — bucket series multiply by len(buckets)+3, so model and position are left to the existing counters. Hand-rolled to match the package's existing registry; see the package doc for why client_golang is not used here.

Named llm_run_duration_seconds, not llm_call_duration_seconds: the latter is valid alongside llm_call_duration_seconds_total in text format 0.0.4, but under OpenMetrics a counter's family name is its name minus _total, so both would normalize to one family with conflicting TYPEs. Free to fix now, expensive once dashboards exist.

internal/api/handler: REFINE_TIMEOUT

Four call sites hardcoded a 90s parent context around a Run whose per-attempt timeout is LLM_TIMEOUT (180s default). A parent smaller than a single attempt means a hanging primary consumes the whole budget and no fallback attempt can start, so LLM_FALLBACK_MODELS is effectively inert on refine.

The default is deliberately unchanged at 90s. Raising it changes user-visible latency on a path that errors at 90s today, and the correct value depends on the refine percentiles this PR starts collecting. What changes is that the number stops being welded into four call sites.

Values are clamped to [1s, 30m] with a once-per-process log on rejection or clamp. Parsing alone was not enough: REFINE_TIMEOUT=90000 (milliseconds assumption) parses into a 25-hour deadline, and an int64-max value overflows time.Duration negative, making all four handlers build an already-expired context — every refine failing instantly and silently.

Path tagging

  • POST /api/v1/summaries/document/preview is a live wired route calling CallStream with no WithPath; its latency landed in path="unknown". Adds PathDocumentPreview.
  • The worker's post-retrieval narrowing (CallRaw, worker/processor.go and personal_processor.go) was untagged and runs on every worker task. Adds PathWorkerNarrow.
  • CallReduceByPerson, CallReduceByPersonWithModel, CallReduceByPersonStream are tagged pre-emptively. None has a production caller today — only CallReduceByPersonStreamWithModel is wired (internal/worker/meta_processor.go:235) and it was already tagged. The five CallMap*/CallReduce* methods the worker actually uses were already tagged too, so worker attribution has been correct all along.

CONFIGURATION.md

Adds the REFINE_TIMEOUT row and corrects the LLM_FALLBACK_MODELS row: refine no longer has a fixed 90s deadline, and the early-escalation guard's scope is stated as agent chat only, with the reason for each exclusion.

The sizing guidance is the part worth reading. With the guard unarmed, Run gives the primary all MaxAttempts (3) attempts before considering another model, so at defaults:

Budget Behaviour
>= (MaxAttempts+1) * LLM_TIMEOUT + backoffs = 723s a fallback gets one complete attempt
< MaxAttempts * LLM_TIMEOUT + backoffs = 543s a hanging primary consumes the budget; run ends Terminal, no fallback attempted

The 90s default is deliberately in the second regime. An earlier revision of this PR documented 2 * LLM_TIMEOUT + backoff, which was only true under the reverted guard behaviour — sizing to that number would have put an operator in the second regime while believing they were in the first.

Tests

  • Exact cumulative bucket values, not "some bucket moved" — an off-by-one in the boundary search still produces plausible output
  • A 400s over-range sample that must still reach +Inf, _sum and _count
  • Label-set pins on both histograms, nil-guarded
  • Negative-observation clamp (one negative sample would skew _sum permanently)
  • Run vs attempt divergence for the same logical call (2×10s attempts + 1s backoff → 20s attempt _sum, 21s run _sum)
  • Concurrent observation, for the worker's parallel Map chunks
  • A 15-row refineTimeout() parse table: unset / valid / malformed / non-positive / wrong-unit / overflow, asserting the result is always a usable positive deadline inside the clamp range
  • parseExposition taught to resolve _bucket/_sum/_count back to their base family, as a real scraper does

Verification

CGO_LDFLAGS=-L/home/mlamp/.local/lib go test -race -count=1 -timeout 15m ./...  PASS
CGO_LDFLAGS=-L/home/mlamp/.local/lib go vet ./...                              PASS
git diff --check                                                               PASS

No new Go modules. No new endpoints — both histograms appear on the existing /internal/metrics, which both binaries already serve.

Deliberately out of scope

The aggregate worker deadline (#220 §2). Worker LLM calls root at context.Background() with no deadline anywhere down the chain, so worst-case fallback latency (~18–27 min with multiple models) can exceed the ~10-minute stuck scanner and the 20-minute lease, causing duplicate dispatch. That needs its own PR, together with the budget-matrix test #220's acceptance criterion 4 already asks for.

Arming PerModelTimeout on Call/CallStream. An earlier revision of this PR did that; it was wrong in two different ways and has been reverted — see the review thread and internal/service/llm.go for the recorded reasoning. Arming the guard requires either the worker deadline above or a per-attempt budget derived from the remaining parent budget.

The streaming refine write deadline. Both streaming refine handlers clear the response write deadline before streaming (from #157), and the server sets no WriteTimeout, so a connected-but-not-reading client is bounded by neither. REFINE_TIMEOUT therefore bounds the LLM run, not the request — now stated in the docs rather than fixed here.

The chunk#%d cardinality bomb. timing.RecordLLMSince receives fmt.Sprintf("Map: 分块总结 chunk#%d", idx) as purpose. That value only reaches log lines today, so normalizing it now is a no-op; it must be collapsed to a bounded purpose_class in the same PR that first feeds timing into a metric label.

Wiring RunTrace.Report() and timing.Record() to metrics (S3 in #231). Separate PR.

Refs #231, #220

… guard

Batch 1 + S1 from Mininglamp-OSS#231. No new dependencies, no new endpoints.

## llmobs: add histogramVec, expose llm_call_duration_seconds

The existing llm_call_duration_seconds_total is a cumulative sum, so the
only statistic derivable from it is a mean. A mean over this workload
describes no real request: refine calls are sub-second while long-context
agent turns are documented at 60-100s. Mininglamp-OSS#220 explicitly defers the final
LLM_TIMEOUT to per-scenario P95/P99, which needs bucket counts.

Buckets are fixed at package scope (0.5s..300s) so paths stay comparable,
and the series is labelled by path ONLY: bucket series multiply by
len(buckets)+3, so a stray dimension is far more expensive here than on a
counter. The counter is kept; this is additive.

Hand-rolled to match the package's existing text-exposition registry --
see the package doc for why client_golang is not used here.

## service/llm: pass PerModelTimeout on the generic Call/CallStream paths

llmfallback.Run's deadline-aware escalation only arms when it is told what
one attempt costs: before a backoff it checks whether the remaining parent
budget can still fit that sleep, the pending retry AND one full attempt on
the next model, escalating early (SwitchReason budget_starved) when it
cannot. agent/llm.go and CallWithTools already passed it; the two generic
entry points did not, so every worker Map/Reduce and API refine call ran
with the guard disabled -- spending the primary's whole retry budget and
handing the fallback whatever remained. That is the starvation Mininglamp-OSS#220 §1
describes, and it was also unreportable: budget_starved could not be
emitted on those paths at all.

## service/llm: tag the three untagged ReduceByPerson variants

CallReduceByPerson, CallReduceByPersonWithModel and CallReduceByPersonStream
did not call WithPath, so their metrics would land in path="unknown".
None has a production caller today (only the ...StreamWithModel variant is
wired, and it was already tagged), so this is pre-emptive: the next caller
inherits correct attribution instead of silently polluting a bucket.

## handler: make the refine budget configurable (REFINE_TIMEOUT)

Four call sites hardcoded a 90s parent context around a Run whose
per-attempt budget is LLM_TIMEOUT (default 180s). A parent smaller than one
attempt means no fallback model is ever reachable, so LLM_FALLBACK_MODELS
is inert on refine. The default is deliberately unchanged at 90s -- raising
it alters user-visible latency and the right value depends on the refine
P95 this commit starts collecting. What changes is that it stops being
welded into four call sites.

## Tests

- exact cumulative bucket/_sum/_count values, including a 400s over-range
  sample that must still reach +Inf (a histogram that drops outliers hides
  precisely the tail these percentiles exist for)
- a label-set assertion pinning {path,le} as the permitted set
- concurrent observation, for the worker's parallel Map chunks
- parseExposition taught to resolve _bucket/_sum/_count back to the base
  family, as a real scraper does

Verification:
  CGO_LDFLAGS=-L/home/mlamp/.local/lib go test -race -count=1 ./...  PASS
  CGO_LDFLAGS=-L/home/mlamp/.local/lib go vet ./...                  PASS
  git diff --check                                                   PASS

Refs Mininglamp-OSS#231, Mininglamp-OSS#220
@wanyiwang06
wanyiwang06 requested a review from a team as a code owner August 27, 2026 09:05
@github-actions github-actions Bot added the size/L PR size: L label Aug 27, 2026
Jerry-Xin
Jerry-Xin previously approved these changes Aug 27, 2026

@Jerry-Xin Jerry-Xin left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Superseding review — REQUEST_CHANGES on 7ed3e73

⚠️ This supersedes my earlier APPROVE (review 5039187716) on this same head. yujiwei's review (5039197102) raised two blockers that I independently byte-verified and confirm; one of them I had derived mechanically but wrongly classified as intended behaviour. Credit to yujiwei for both. Details in the new REQUEST_CHANGES review.

@yujiawei yujiawei left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review — PR #232 (octo-smart-summary)

Reviewed at head 7ed3e73, against merge-base eb9e0e3. I checked the branch out and ran the suites locally (go1.26.5): go test -race -count=1 ./internal/llmobs/... ./internal/llmfallback/... ./internal/api/handler/... — all PASS.

The histogram is good work and I'd take it as-is. The problem is the other half of the PR: the two hunks that change runtime behaviour have no tests, and when you trace them through the call graph they do close to the opposite of what the description claims. Details below, with the probe I used to confirm.


1. Spec compliance

Result: not met.

Measured against this PR's own "Change" section:

Stated change Status
internal/llmobs: add histogramVec, expose llm_call_duration_seconds Implemented as described
Tag the three untagged ReduceByPerson variants Implemented; the "no production caller today" claim is correct (verified by grep — only CallReduceByPersonStreamWithModel is wired, at internal/worker/meta_processor.go:235, and it was already tagged)
internal/api/handler: make the refine budget configurable Implemented, but incomplete — see 2.5 (undocumented) and 2.6 (no tests)
internal/service/llm.go: pass PerModelTimeout on Call/CallStream"Arms the deadline guard on worker Map/Reduce, and makes budget_starved reportable on those paths for the first time" Diverges. Both halves of that sentence are false. See 2.1

The divergence in the last row is the blocking one, and it is not a wording quibble — the same claim is now baked into a source comment at internal/service/llm.go:270-278, where it will be read as ground truth by whoever next debugs a fallback.


2. Code quality

Result: changes requested. Two P1, six P2.

P1-1 — PerModelTimeout is inert on worker Map/Reduce; the guard is still disarmed there

The guard is gated on the parent context having a deadline:

// internal/llmfallback/fallback.go:306-315
if hasNext && cfg.PerModelTimeout > 0 {
    if dl, ok := ctx.Deadline(); ok {
        remaining := time.Until(dl)
        if remaining > delay && remaining < delay+2*cfg.PerModelTimeout {
            return zero, TryNextModel, &budgetStarvedErr{...}

Every worker entry point starts from context.Background() and propagates it unchanged:

  • internal/worker/processor.go:183, :253
  • internal/worker/meta_processor.go:78
  • internal/worker/personal_processor.go:623

A repo-wide grep for context.WithTimeout|context.WithDeadline (excluding tests) confirms there is no deadline anywhere between those roots and callWithPolicyAndModel. The repo's own docs already say so — CONFIGURATION.md:21: "Worker/API paths have no aggregate fallback deadline" — and so does issue #220 §2: "调用方也没有聚合 deadline".

I confirmed it against the real llmfallback.Run with a throwaway probe (two models, PerModelTimeout: 180s, MaxAttempts: 3, every attempt classified RetrySameModel):

parent = context.Background()          → switch primary->fallback reason=retries_exhausted attempts=3
parent = context.WithTimeout(.., 90s)  → switch primary->fallback reason=budget_starved      attempts=1

So on worker_map / worker_reduce nothing changed, and budget_starved is still unemittable there — which is precisely the "diagnostic dead end" the description says this hunk removes. It is now worse than before the PR: an operator who queries llm_model_switch_total{path="worker_map",reason="budget_starved"} == 0 will read it as "starvation is not happening", when the true meaning is "the guard never ran". Before, at least the absence of PerModelTimeout in the config literal made that obvious at the call site.

One more thing worth correcting: the description attributes the worker gap to "the starvation #220 §1 describes." #220 §1 is about the agent path and AGENT_STEP_TIMEOUT — which already passed PerModelTimeout (internal/agent/llm.go:101). The worker gap is #220 §2, and what §2 asks for is an aggregate deadline bounded below the ~10-minute stuck scanner and the 20-minute lease, because the worst case there is ~18–27 minutes of retries causing duplicate dispatch. That risk is untouched here.

Fix — pick one:

  • (a) Add the aggregate deadline #220 §2 asks for at the worker call sites. PerModelTimeout then becomes meaningful and the description becomes true. This is the real fix, and probably its own PR.
  • (b) Keep the one-line change but scope the claim to api_refine, and delete the worker sentence from both the PR body and internal/service/llm.go:270-278.

Either way, please don't ship a comment asserting a guard is armed on a path where it provably is not.

P1-2 — On api_refine, the shipped defaults make the guard fire on every first retry

With REFINE_TIMEOUT defaulting to 90s (internal/api/handler/refine_budget.go:29) and PerModelTimeout = c.timeout = LLM_TIMEOUT = 180s (internal/config/config.go:210, internal/service/llm.go:85), the guard condition is:

remaining < delay + 2*cfg.PerModelTimeout   //  ≤90 < 1 + 360  → always true

So whenever LLM_FALLBACK_MODELS is non-empty and the primary hits any transient 429/5xx/transport error, the primary is abandoned after one attempt with budget_starved, instead of retrying three times. Concretely: primary returns a single transient 503 and then recovers, fallback is misconfigured or returns 401 — refine used to succeed on the primary's second request and now fails.

Two knock-on effects that make this more than a policy preference:

  1. Every routine blip becomes an ERROR log. internal/llmobs/observer.go:64-68 deliberately logs budget_starved at slog.LevelError because it is "a configuration fault, not an upstream one." Under these defaults that fault is permanent, so the level carries no information.
  2. It destroys the query this PR proposes. The description says querying llm_model_switch_total{reason="budget_starved"} is how you'd decide whether #220 §1 is real. On api_refine that series will now read ~100% of switches by construction of the defaults, not because of any incident.

refine_budget.go:21 states the precondition itself — REFINE_TIMEOUT >= 2 * LLM_TIMEOUT + backoff — and then the file deliberately ships a default that violates it (90 < 360). Arming a guard under a permanently-violated precondition is a permanent misfire, not a diagnostic. I agree with the reasoning for not raising the default silently; the issue is arming the guard anyway.

Also note the guard cannot rescue the case #220 §3 actually describes. If the primary simply hangs and eats the whole 90s, c.client.Do returns with ctx.Err() != nil and the attempt classifies Terminal (internal/service/llm.go:309-315), so Run returns immediately and no fallback is attempted at all. The guard only helps when the primary fails fast.

Suggested fixes (any one): gate the arming on parentBudget >= 2*perModel; or derive PerModelTimeout from the remaining parent budget rather than the raw LLM_TIMEOUT; or raise the default and accept the latency change explicitly. At minimum, add the budget-matrix test that #220's acceptance criteria already ask for (see P2-6) so the chosen behaviour is pinned.

P2-1 — The histogram measures Run wall-clock, but LLM_TIMEOUT is a per-attempt budget

ObserveResult receives e.Duration = time.Since(start) for the entire Run (internal/llmfallback/fallback.go:174) — including backoff sleeps (1s + 2s) and every model tried. But LLM_TIMEOUT is applied per attempt: http.Client{Timeout: ...} at internal/service/llm.go:87, and context.WithTimeout(ctx, c.timeout) at internal/agent/llm.go:137.

Sizing a per-attempt cap from a whole-run distribution over-estimates exactly where it matters — the P99 is the retried runs, which is where run duration and attempt duration diverge most. On the happy path they coincide, so P95 is roughly usable; P99 is not.

The right input already exists and is being thrown away: AttemptEvent.Duration is delivered to llmobs.Observer.ObserveAttempt (internal/llmobs/observer.go:33) but Metrics.ObserveAttempt (internal/llmobs/metrics.go:301-308) only increments a counter and drops the duration.

Suggestion: add llm_attempt_duration_seconds{path} over the same buckets — it's a two-line change given histogramVec now exists — or narrow the HELP text and the PR rationale to "run latency, for sizing parent budgets (REFINE_TIMEOUT / AGENT_STEP_TIMEOUT)", which is what it genuinely measures.

P2-2 — document_preview is a live untagged path, and it was skipped

The PR pre-emptively tags three CallReduceByPerson* methods it correctly identifies as having no production caller. Meanwhile internal/api/handler/document_preview.go:316 calls client.CallStream(genCtx, …) with no llmfallback.WithPath, on a wired route — internal/api/router/router.go:177, POST /v1/summaries/document/preview.

That endpoint's latency lands in path="unknown", and the new histogram now spends 15 bucket series on that mixed bucket. Given the PR's stated goal is per-scenario percentiles, tagging the path with real traffic seems higher value than tagging three with none. One line, same file pattern as the others.

P2-3 — Metric naming: llm_call_duration_seconds next to the existing llm_call_duration_seconds_total

I dumped the rendered exposition by hand and confirmed there is no collision in Prometheus text format 0.0.4 — _bucket / _sum / _count are all distinct from _total, and both families scrape cleanly. So this is not a blocker.

The concern is downstream: in OpenMetrics a counter's family name is the name minus _total, so both families normalize to llm_call_duration_seconds with conflicting TYPEs. Consumers that normalize — the OTel Collector prometheus receiver, promtool check metrics, OpenMetrics-negotiating scrapers — would see a duplicate family. Since #231 plans to adopt OpenTelemetry for exactly this repo, it's cheap to sidestep now (llm_run_duration_seconds?). Worth noting too that _sum is now the same quantity as llm_call_duration_seconds_total, so the counter is fully redundant and could be deprecated rather than "retained".

Caveat: no promtool or Prometheus binary available in my environment, so this is a naming-convention argument, not an observed scrape failure. Treat it as advisory.

P2-4 — refineTimeout() parsing: the "a typo degrades to the previous behaviour" comment overclaims

internal/api/handler/refine_budget.go:34-50. Only unset / unparsable / non-positive fall back to 90s. Two live failure modes survive:

  • Wrong unit. REFINE_TIMEOUT=90000 (someone assumes milliseconds) parses fine → a 25-hour refine deadline. The handler holds the connection and goroutine essentially forever instead of erroring at 90s.
  • Overflow. time.Duration(secs) * time.Second is unchecked. REFINE_TIMEOUT=9223372036854775807 yields -1s; all four refine handlers then build an already-expired context and every refine request fails instantly, silently.

Suggestion: clamp to a sane range (e.g. 1s–30m) and log once when the env value is rejected or clamped, so a typo is visible rather than silent. That would make the comment's promise actually true.

P2-5 — REFINE_TIMEOUT is undocumented and CONFIGURATION.md is now stale

CONFIGURATION.md documents all 52 environment variables, including LLM_TIMEOUT, AGENT_STEP_TIMEOUT and TOOL_CALL_TIMEOUT. REFINE_TIMEOUT has no entry — no unit, no default, no stated relationship to LLM_TIMEOUT. That defeats the stated purpose ("a deployment can widen it without a build"): an operator reading the configuration reference cannot discover the knob exists.

Two existing sentences in CONFIGURATION.md:21 also go stale with this PR:

  • "API refine has a 90-second request deadline" — no longer fixed.
  • "For agent chat … it escalates early when the remaining deadline cannot fit both the pending retry and a fallback attempt" — after this PR that is also true of api_refine, and per P1-2 it is true unconditionally there.

P2-6 — The two behaviour-changing hunks have zero tests

grep -rn 'refineTimeout|REFINE_TIMEOUT'      --include=*_test.go .            → (nothing)
grep -rn 'budget_starved|ReasonBudgetStarved' --include=*_test.go internal/service internal/api → (nothing)

The histogram — which is purely additive and cannot change behaviour — got four careful new tests, and they are genuinely good (exact cumulative values, the 400s over-range case, the label-set pin, concurrency). The two hunks that do change runtime behaviour got none.

A budget-matrix table over (model count, PerModelTimeout, parent deadline, backoff) → observed attempt sequence — which is #220's own acceptance criterion 4, already on the books — would have caught P1-1 on the first run. That's the test I'd most like to see added here.

Nits

  • internal/llmobs/metrics.go:154newHistogramVec keeps the caller's buckets slice by reference. A defensive copy makes the strictly-increasing invariant that sort.SearchFloat64s depends on unbreakable, for one line.
  • internal/api/handler/refine_budget.go:32RefineTimeoutEnvVar is exported but referenced nowhere, including tests. Either use it in a test or unexport it; right now it's public surface on handler with no consumer.
  • internal/llmobs/metrics_test.goTestHistogram_LabelSetMatchesCounter dereferences fams["llm_call_duration_seconds"].samples with no nil check, so a rename turns a clean test failure into a nil-pointer panic. TestHistogram_QuantileInputsAreExact guards this correctly a few lines above.
  • The if v < 0 { v = 0 } clamp in observe is untested.
  • refineTimeout() re-reads and re-parses the environment on every request. The cost is trivial next to a multi-second LLM call and it matches the agentStepTimeoutOverride precedent the comment cites, so I don't think it needs changing — noting it only because reading env inside a handler tends to attract review comments.

3. What I verified as correct

Worth saying explicitly, because the histogram is the bulk of the diff and it holds up:

  • Boundary search. sort.SearchFloat64s returns the least i with buckets[i] >= v, which is exactly le (≤) semantics. Checked on-boundary (0.5 → le="0.5") and over-range (400s → +Inf only).
  • Over-range samples reach _sum, _count and +Inf rather than being dropped.
  • Cumulative rendering, +Inf == _count, and %g shortest-round-trip boundary formatting — I dumped the full exposition and read it line by line.
  • Lock discipline. One mutex; write takes a consistent snapshot of counts/sums/totals before rendering. -race clean locally.
  • parseExposition's new suffix resolution checks the exact name first, so the pre-existing llm_call_duration_seconds_total counter is not misrouted into the histogram family. That ordering matters and it's right.
  • The path-only label decision and the reasoning about bucket-series multiplication — agreed, and the label-set pin test is the right way to keep it that way.

On the open question in "Notes for reviewers": I'd leave the bucket layout alone for now. Tightening 60–180s costs you the sub-second refine resolution you need for REFINE_TIMEOUT, and until P2-1 is resolved you don't yet know which band the real signal lives in.


4. Verdict

CHANGES_REQUESTED.

P1-1 and P1-2 are both blocking, and they're the same root cause seen from two ends: PerModelTimeout was added to two call sites without checking what the parent context actually looks like at either. On the worker there is no deadline, so it does nothing; on refine the deadline is smaller than one attempt, so it does something drastic on every blip.

Smallest path to approval, if you want to keep this PR narrow:

  1. Drop the worker half, or add the aggregate deadline that makes it real (P1-1).
  2. Decide the refine behaviour deliberately and pin it with a budget-matrix test (P1-2 + P2-6).
  3. Add the REFINE_TIMEOUT row to CONFIGURATION.md and fix the two stale sentences (P2-5).
  4. Clamp the parsed value (P2-4).

P2-1, P2-2 and P2-3 are fine as follow-ups.

The histogram itself I'd merge today.


5. Coverage note

Ran and verified: full -race test suite on internal/llmobs, internal/llmfallback, internal/api/handler (go1.26.5, all PASS); hand-dumped Prometheus exposition; a synthetic probe against the real llmfallback.Run for both context lineages; repo-wide grep for every context.WithTimeout/WithDeadline outside tests.

Not verified:

  • No promtool / Prometheus binary available, so P2-3's OpenMetrics normalization concern is reasoned from the spec, not observed. Flagged advisory for that reason.
  • No deployment manifests reviewed. Whether P1-2 bites today depends on whether LLM_FALLBACK_MODELS is actually set in each environment — if it's empty, hasNext is false and the refine behaviour is unchanged. Please confirm against the deployment config before deciding P1-2's urgency.
  • No production metrics. The refine firing rate is derived from the code path and the synthetic probe, not measured against real traffic.
  • #220 §2's lease/stuck-scanner overrun (worst case ~18–27 min vs. a ~10-min scanner and 20-min lease) is out of this PR's scope and I did not check whether it's tracked elsewhere. Raising it because P1-1 means it is still fully open.
  • CI: check-sprint and label are failing on this PR. Both are project-board automation and unrelated to the diff, but they'll need clearing before merge.

@Jerry-Xin Jerry-Xin left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review — PR #232 (octo-smart-summary) — REQUEST_CHANGES

⚠️ This supersedes my APPROVE (review 5039187716) posted minutes earlier on the same head. yujiwei's review (5039197102) raised two P1s; I byte-verified both independently and confirm them as blockers. One of them (P1-2) I had mechanically derived in my first pass but wrongly framed as intended semantics — that was my miss. Credit to yujiwei for both findings.

Verified on head 7ed3e73 (checked out locally; go build ./... clean, go vet clean, go test -race -count=1 on ./internal/llmobs/... ./internal/llmfallback/... ./internal/service/... ./internal/api/handler/... all PASS; CI Build/Lint/Test/Test(race,cgo)/Vet/secret-scan/dependency-review/osv-scan green at review time).

🔴 Blocker 1 — PerModelTimeout is inert on worker Map/Reduce; the "guard armed" claim is false there and is now baked into source comments

The guard (internal/llmfallback/fallback.go:306) is gated on the parent context having a deadline (ctx.Deadline(), ok). Every worker LLM entry point propagates context.Background() unchanged — internal/worker/meta_processor.go:78, internal/worker/processor.go:183,187,253, internal/worker/personal_processor.go:623 — and a repo-wide grep finds no WithTimeout/WithDeadline between those roots and callWithPolicyAndModel. So on worker paths the guard never runs and budget_starved is still unemittable there.

I had flagged this in my superseded review as a wording issue; yujiwei is right that it is blocking:

  • The same false claim is now asserted in a source comment at internal/service/llm.go:270-278 ("Omitting it silently disabled that guard on every worker Map/Reduce and API refine call"), which the next debugger will read as ground truth.
  • It inverts the diagnostic this PR proposes: llm_model_switch_total{path="worker_map",reason="budget_starved"} == 0 will read as "starvation is not happening" when it actually means "the guard never ran" — strictly worse than before, when the absent field was obvious at the call site.

Fix — pick one: (a) add the aggregate worker deadline #220 §2 asks for so PerModelTimeout becomes meaningful (likely its own PR), or (b) keep the one-line change but scope the claim to api_refine and delete the worker sentence from the PR body and the comment at internal/service/llm.go:270-278.

🔴 Blocker 2 — On api_refine the shipped defaults make the guard fire on EVERY first transient failure: a precondition the PR itself documents is violated by default

Byte-verified arithmetic: REFINE_TIMEOUT defaults to 90s (internal/api/handler/refine_budget.go:29) and PerModelTimeout = c.timeout = LLM_TIMEOUT = 180s (internal/config/config.go:210, internal/service/llm.go:85). The guard condition remaining < delay + 2*PerModelTimeout becomes ≤90 < 1 + 360 — always true. Consequences, all verified in code:

  1. Primary loses its entire retry budget on one blip. Any transient 429/5xx/transport error abandons the primary after ONE attempt (budget_starved) instead of retrying 3 times. Reachable regression: primary returns one transient 503 then recovers, fallback is misconfigured and answers 401 → ClassifyStatus(401) = Terminal → refine fails outright, where before this PR the second primary attempt would have succeeded. Scope caveat confirmed: LLM_FALLBACK_MODELS defaults to empty (internal/config/config.go:209), so single-model deployments are untouched (hasNext false) — the regression hits exactly the deployments that configured a fallback, i.e. this PR's audience.
  2. Permanent ERROR-log noise. budget_starved is logged at slog.LevelError (internal/llmobs/observer.go:63-69, comment: "costs the primary its retry budget on every single blip"). Under these defaults that is every routine blip on api_refine; the level carries no information.
  3. It destroys the query this PR proposes. On api_refine, llm_model_switch_total{reason="budget_starved"} reads ~100% of switches by construction of the defaults, not because of any incident.
  4. The guard cannot rescue the hang case it is justified by. A hanging primary eats the 90s inside c.client.Do; the attempt then sees ctx.Err() != nil and classifies Terminal (internal/service/llm.go:310-315), so Run returns with no fallback at all. The guard only changes fast-fail behaviour.

internal/api/handler/refine_budget.go:19-21 states the precondition itself (REFINE_TIMEOUT >= 2 * LLM_TIMEOUT + backoff) and then deliberately ships a default that violates it while arming the guard anyway — that is a permanent misfire, not a diagnostic. Fix options (any): gate the arming on parentBudget >= 2*perModel; derive PerModelTimeout for these call sites from the remaining parent budget; or raise the default and own the latency change explicitly. Whichever is chosen, pin it with the budget-matrix test #220's acceptance criteria already ask for (see below).

Verified good (merge-quality, no changes needed)

  • Histogram: bucket units consistent (seconds vs Duration.Seconds()); sort.SearchFloat64s gives correct le-inclusive boundary semantics (on-boundary sample lands in that bucket — pinned by the exact-cumulative test); over-range 400s sample reaches +Inf/_sum/_count; negatives clamped without corrupting _sum; snapshot-under-lock rendering is race-free; Install() is once-per-binary and the hand-rolled registry cannot panic on re-registration. The three new tests (exact cumulative values, label-set pin, concurrency) pass locally with -race.
  • Observation coverage: every LLM call in the repo travels through llmfallback.Run (all four call sites; every client.Do is inside a Run attempt) and Run emits exactly one terminal ObserveResult — one observation per call, no double-counting on retry/fallback/streaming paths.
  • Path tagging: the three newly tagged ReduceByPerson variants indeed have zero production callers (grep-verified; only CallReduceByPersonStreamWithModel is wired at internal/worker/meta_processor.go:235, already tagged). Pre-emptive as claimed.
  • Cross-PR collisions: none with #213 or #215 — neither touches internal/llmobs or internal/service/llm.go, and none of the new symbols (histogramVec, durationBuckets, withLE, formatBucket, refineTimeout, RefineTimeoutEnvVar, defaultRefineTimeout) appear in either diff.

Non-blocking (agree with yujiwei's list; adding my verified items)

  • 🟡 internal/api/handler/document_preview.go:316 calls CallStream without WithPath on a live wired route (POST /v1/summaries/document/preview) — its latency lands in path="unknown" and spends 15 bucket series there. Tagging a path with real traffic is higher value than tagging three with none. One line.
  • 🟡 CONFIGURATION.md:21 is stale twice over (fixed-90s refine sentence; the escalation sentence now also applies to api_refine), and REFINE_TIMEOUT has no entry despite the knob's stated purpose. Also: the required code-review check and merge are blocked until these reviews are resolved.
  • 🔵 refineTimeout() parse: REFINE_TIMEOUT=9223372036854775807 overflows time.Duration negative → all four refine handlers build already-expired contexts and every refine fails instantly; a wrong-unit value (90000 read as seconds) parses fine into a 25-hour deadline. Clamp to a sane range and log when rejected. (Same unchecked pattern pre-exists in AGENT_STEP_TIMEOUT; the overflow class matches the finding above.)
  • 🔵 Zero tests on the two behaviour-changing hunks: nothing pins that callWithPolicyAndModel/callStreamWithModel pass PerModelTimeout, and no parse table for refineTimeout (unset/valid/malformed/non-positive). A (models, PerModelTimeout, parent deadline, backoff) → attempt sequence matrix would have caught both blockers.
  • 🔵 Advisory (yujiwei P2-1/P2-3, concur): the histogram measures whole-Run wall-clock while LLM_TIMEOUT is per-attempt — fine for sizing parent budgets, not for per-attempt P99; AttemptEvent.Duration already exists if an attempt-level series is wanted. Naming llm_call_duration_seconds next to llm_call_duration_seconds_total is valid in text format 0.0.4 but both normalize to one family under OpenMetrics — cheap to sidestep before the #231 OTel adoption.

Merge state

mergeable_state=blocked is correct and now doubly so: the main ruleset requires 2 approvals + code-owner + last-push approval + thread resolution, and the required code-review status check is red (this review). check-sprint/label failures are project-board automation, not in the ruleset's required list.

@Jerry-Xin
Jerry-Xin dismissed their stale review August 27, 2026 09:25

Superseded by REQUEST_CHANGES review 5039232364 (verified peer blockers)

mochashanyao
mochashanyao previously approved these changes Aug 27, 2026

@mochashanyao mochashanyao left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[Octo-Q · automated review]

Verdict: Approve — no blocking findings; notes below (data-flow traced).


Reviewer: Octo-Q (automated review)
PR: #232 | head: 7ed3e737ed1841b958ff8844c3d4284958592401 | base(merge-base): eb9e0e3adabd03208b7d3695290d7bb5c034fae4 | 轮次: 首轮

Code Review — PR #232 (octo-smart-summary)

Summary

This PR adds a labelled latency histogram (llm_call_duration_seconds) to the hand-rolled Prometheus exposition in internal/llmobs, arms the existing deadline-aware fallback escalation on the two generic llmfallback.Run sites by passing PerModelTimeout: c.timeout (internal/service/llm.go:280, :408), extracts the refine LLM budget from four welded 90*time.Second call sites into a REFINE_TIMEOUT env knob with the same 90s default (internal/api/handler/refine_budget.go), and completes PathWorkerReduce tagging across the CallReduceByPerson family. Defaults are deliberately unchanged, so out-of-the-box behavior should be identical except that refine now escalates to a configured fallback earlier on transient failures instead of spending the primary's whole retry budget.

Overall the change is careful: the histogram math, locking, and exposition format are correct, and the timeout wiring is symmetric across call sites. The two findings below are an operator-docs gap and a parse-boundary hardening item, neither blocking.

Verification

Static analysis only at head 7ed3e737ed1841b958ff8844c3d4284958592401; build and tests not executed in this environment.

  • Histogram boundary mathsort.SearchFloat64s is lower-bound, so a sample exactly on a boundary lands in that bucket (le-inclusive, as the exposition format requires); hand-checked against the exact-value test: 0.25/0.5 → le="0.5" (cum 2), 75 → le="90" (cum 3), 400 → only +Inf/_sum/_count (sum 475.75).
  • Concurrency — one mutex covers observe and the snapshot copy in write; durationBuckets is an immutable package-level slice read outside the lock; the new race test pins loss-free counts.
  • Guard arming is zero-safeinternal/llmfallback/fallback.go:306 gates on cfg.PerModelTimeout > 0 and on ctx.Deadline(), so a zero timeout or deadline-less ctx keeps prior behavior; c.timeout traces to LLM_TIMEOUT (default 180, internal/config/config.go:210) and equals the per-attempt http.Client.Timeout.
  • Call-site parity — all four refine sites now use refineTimeout() (internal/api/handler/edit.go:277,:444, internal/api/handler/personal_refine.go:110,:336); the other two production Run sites (agent chat, CallWithTools) already passed PerModelTimeout; plain CallMap/CallReduce wrappers delegate to the tagged WithModel variants.
  • Metric wiring end-to-endllmobs.Install in both cmd/summary-api and cmd/summary-worker, every Run exit path emits ResultEvent.Duration, and WritePrometheus is served at internal/api/router/router.go:198.

Findings

No P0/P1 issues; two P2 items below.

P2 — REFINE_TIMEOUT is undocumented and CONFIGURATION.md still hardcodes the 90s refine deadline (internal/api/handler/refine_budget.go:33)

The whole point of the new file is that the refine budget becomes one operator-tunable knob, but CONFIGURATION.md never mentions it: there is no REFINE_TIMEOUT row in the env table, and the LLM_FALLBACK_MODELS row at CONFIGURATION.md:21 still states "API refine has a 90-second request deadline" as a constant. Since this PR also arms the deadline guard on refine calls, the guidance the docs already give for agent chat (maxAttempts*LLM_TIMEOUT + backoffs <= AGENT_STEP_TIMEOUT) now has a refine analogue (REFINE_TIMEOUT >= 2*LLM_TIMEOUT + backoff, per the comment at internal/api/handler/refine_budget.go:21) that operators also need. Add the env row with its degrade-to-90s semantics and update the stale sentence.

P2 — refineTimeout() Duration overflow defeats its own typo contract (internal/api/handler/refine_budget.go:50)

time.Duration(secs) * time.Second overflows for values strconv.Atoi still accepts: any REFINE_TIMEOUT above 9,223,372,036 (about 292 years) wraps to a negative Duration, context.WithTimeout then yields an already-expired context, and every refine request fails immediately with deadline exceeded. That contradicts the function's stated contract (":36") that an unparsable value degrades to the historical 90s instead of removing the deadline. The identical unbounded pattern pre-exists in agentStepTimeoutOverride (internal/agent/profile.go:171), so this is not newly introduced logic — but this new knob can carry the fix: reject secs > math.MaxInt64/int64(time.Second) as unparsable, and add parse-branch tests (empty/garbage/negative/overflow), which the new file currently lacks.

Things I checked that are fine

  • Exposition shape: HELP/TYPE under the base name, cumulative _bucket lines with le appended via withLE, _sum/_count without le, formatBucket round-trips every boundary ("0.5"…"300"), +Inf equals the total, negative samples clamp to 0 instead of corrupting _sum.
  • Cardinality: histogram labels are path only (pinned by TestHistogram_LabelSetMatchesCounter), path is a closed 7-value constant set, series count = paths × 15 lines.
  • Test-side parseExposition suffix resolution only fires for the new histogram family; the pre-existing llm_call_duration_seconds_total counter family is untouched.
  • Worker Map/Reduce behavior is unchanged today: worker contexts carry no deadline, so the newly armed guard is inert there until a deadline exists — harmless future-proofing, and time imports remain used in both edited handlers.
  • The three newly path-tagged CallReduceByPerson* functions have no production callers yet (tests only), so the tagging cannot shift any live metric attribution.

Verdict: APPROVED

No P0/P1 blockers found. The histogram math, locking, and exposition format hold up under static tracing of every consumed value, and the timeout wiring is symmetric across call sites. The two P2 items — documenting REFINE_TIMEOUT and hardening its parse boundary — are non-blocking and can land in a follow-up.


Octo 附录(内部审查记录,非对外正文)

验证结论

✅ 直方图数学/并发/渲染正确(internal/llmobs/metrics.go:186-258,手工对 sort.SearchFloat64s 语义与测试精确值交叉验证);✅ PerModelTimeout 接线对称且 0 值/无 deadline 安全(internal/llmfallback/fallback.go:306);✅ 四处 refine 调用点全部换用 refineTimeout()internal/api/handler/edit.go:277,444internal/api/handler/personal_refine.go:110,336);⚠️ 两项 P2 见正文。

数据流回溯(被消费数据 → 上游来源 → 是否真流到消费点)

  1. e.Duration.Seconds()llmfallback.Run 全部 5 个 ObserveResult 出口均设 Duration: time.Since(start)fallback.go empty-model/loop-top-ctx-err/Success/Terminal/exhausted)→ 每次完成的 Run 都进直方图 ✅
  2. e.Pathcfg.pathFor(ctx):Config.Path(agent Chat)或 WithPath 标签;refine handler 在 context.WithTimeout 内层先打 PathAPIRefine(顺序已验),worker 包装函数入口打 PathWorkerMap/Reduce;未打标 → PathUnknown 常量,永不为空 ✅
  3. c.timeoutNewLLMClient(timeoutSec)cfg.LLMTimeoutenvInt("LLM_TIMEOUT", 180)internal/config/config.go:210);与 http.Client.Timeout 同值(单次 attempt 预算语义一致);为 0 时守卫自动不启用(>0 门控)✅
  4. refineTimeout()REFINE_TIMEOUT env,TrimSpace+Atoi,空/非法/非正 → defaultRefineTimeout=90s;被 4 个 context.WithTimeout 消费 ✅(>9.22e9 秒溢出为负 → 见 P2-2)
  5. h.buckets=durationBuckets → 包级不可变切片,SearchFloat64s 只读消费,锁外读安全 ✅
  6. 测试 hand-feed → 直接调 ObserveResult(即生产 observer 接缝本身:Install→SetDefaultObserver→Run 调用它);端到端链 cmd/*/main.go Install + internal/api/router/router.go:198 WritePrometheus 静态验证 ✅ 无绕过真实路径问题

盲点 checklist

  • C1 双路径 parity:HIT 已清 — 4/4 refine 点替换(grep 证明仓内唯一剩余 90*time.Second 是默认常量本身);2/2 通用 Run 点补 PerModelTimeout(另 2 个生产 Run 点 agent Chat/CallWithTools 已有);ByPerson 家族 WithPath 补齐(此前仅 StreamWithModel 有标签,其余 3 个无生产调用者,补标签无运行时归因漂移);plain wrapper 全部委托带标签的 WithModel 变体。
  • C2 control-flow ordering/嵌套复用:CLEAR — refineTimeout() 无状态、每调用点现读,嵌套/复用无双重作用;守卫检查在 backoff sleep 之前、每 attempt 至多一次、不改变任何状态。安全控件非 canonical 形式试穿:env 值 "+90"(Atoi 接受,正常)、" 90 "(TrimSpace 覆盖)、"90.5"/"1e3"(Atoi 拒绝→默认)、超大值(溢出,P2-2)。
  • C3 授权边界:N/A — 无 auth/jail/tool/凭证面改动。
  • C4 授权生命周期/容器级联:N/A — 无鉴权改动。
  • C5 build/运行期路径:静态推演(审查约束不跑 build/test,报告已如实标注)——time import 在两个改动 handler 中仍有其他引用(edit.go:124personal_refine.go:249 等),新增 strconv import 被 formatBucket 使用;Install→observer→histogram→/metrics 全链静态走通。
  • C6 治理/文档自洽:HIT — CONFIGURATION.md 与新旋钮漂移(P2-1);不涉及 SECURITY.md/披露流程。
  • R3 分布式副作用:CLEAR — 仅进程内指标,无通知/推送/计数 fan-out;多实例各自 expose,scraper 端 sum by(path,le) 聚合,无 dedup 问题。

定级说明(R1/R2/R4)

  • P2-1(文档漂移):R2=new(本 PR 引入可调旋钮并使守卫在 refine 生效,文档契约随之过期);不满足 R1(无运行期破坏)→ P2。
  • P2-2(Duration 溢出):R2=new code 复刻既有模式(agent/profile.go:171 同款无上界);触发需 >292 年的 env 配置,属配置错误非运行期可达,失败模式为显性全量报错而非静默错误数据 → 按 R1 判不构成"生产可达的能工作路径破坏" → P2 而非 P1。
  • R4:无 P0/P1 → APPROVED。

跨轮 blocker 复检(R6)

N/A — 本 PR 首轮审查,无上一轮未解决 blocker。

流程备注

本轮按 skill 单腿执行:当前 skill 安装不含双模型 fan-out 脚本(glm_review.py/merge_reviews.py 缺失),无 /tmp/merged.findings.json,按降级规则从 /tmp/review.final.json 渲染。gh 在本环境无凭据,base 判定完全用本地 git(merge-base eb9e0e3 = origin/main tip,单 commit PR)。

…run vs attempt latency

Addresses both P1 blockers from @yujiawei and @Jerry-Xin on Mininglamp-OSS#232.

## P1-1 + P1-2: revert PerModelTimeout on Call/CallStream

Both reviewers are right, and the two findings are one root cause: the
field was added without checking the parent context at either consumer.

llmfallback.Run's escalation is gated on ctx.Deadline() being present:

  - worker Map/Reduce roots at context.Background() with no deadline
    anywhere down the chain, so the field was inert. budget_starved
    remains unemittable there. Worse, the PR asserted the opposite in a
    source comment, which would have inverted the diagnostic: reading
    {path="worker_map",reason="budget_starved"} == 0 as "not happening"
    when it means "never ran".
  - api_refine passes 90s while PerModelTimeout would be LLM_TIMEOUT
    (180s), so `remaining < delay + 2*PerModelTimeout` is 90 < 361 —
    permanently true. Any transient 429/5xx would abandon the primary
    after ONE attempt, log budget_starved at ERROR on every blip, and
    make that series read ~100% of switches by construction of the
    defaults. The very query this PR proposed for diagnosing Mininglamp-OSS#220.

Both entry points are shared by worker and refine, so the field cannot be
scoped to one side here. Reverted, with a comment recording why arming it
needs either Mininglamp-OSS#220 §2's aggregate worker deadline or a per-attempt budget
derived from the remaining parent budget.

Also corrects the attribution: the worker gap is Mininglamp-OSS#220 §2 (aggregate
deadline vs the ~10min stuck scanner and 20min lease), not §1, which is
the agent path and already passed PerModelTimeout.

## P2-4: clamp and log REFINE_TIMEOUT

The old comment claimed a typo degrades to previous behaviour; it did not.
REFINE_TIMEOUT=90000 (milliseconds assumption) parsed into a 25-hour
deadline, and int64-max overflowed time.Duration to a negative value,
making all four refine handlers build an already-expired context — every
refine failing instantly and silently. Now clamped to [1s, 30m] with a
once-per-process log on any rejection or clamp.

## P2-1: add llm_attempt_duration_seconds

LLM_TIMEOUT is a per-attempt cap, but ResultEvent.Duration is whole-run
wall-clock including backoffs and earlier models. Sizing the cap from the
run distribution over-estimates precisely at P99, because the P99 IS the
retried runs. AttemptEvent.Duration was already delivered to
ObserveAttempt and discarded; it now feeds a per-attempt histogram
labelled {path, outcome} (no model/position — bucket series multiply by
len(buckets)+3).

## P2-3: rename llm_call_duration_seconds -> llm_run_duration_seconds

Valid in text format 0.0.4, but under OpenMetrics a counter's family name
is its name minus _total, so it would collide with the existing
llm_call_duration_seconds_total. Free to fix now, expensive once
dashboards exist. The new name is also more honest about what it measures.

## P2-2: tag document_preview

POST /v1/summaries/document/preview is a live wired route calling
CallStream with no WithPath, so its latency landed in path="unknown".
Adds PathDocumentPreview. Tagging a path with real traffic matters more
than the three pre-emptive tags already in this PR.

## P2-5: document REFINE_TIMEOUT, fix two stale sentences

CONFIGURATION.md gains a REFINE_TIMEOUT row. The LLM_FALLBACK_MODELS row
no longer claims refine has a fixed 90s deadline, and now states which
paths the escalation guard is actually active on and why.

## P2-6 + nits

- refine_budget_test.go: 15-row parse table covering unset/valid/
  malformed/non-positive/wrong-unit/overflow, asserting the result is
  always a usable positive deadline inside the clamp range
- negative-observation clamp test (a single negative sample would skew
  _sum permanently)
- a test pinning that run and attempt histograms report different values
  for the same logical call
- defensive copy of the bucket slice (SearchFloat64s needs a stable
  strictly-increasing slice)
- label-set pin now nil-guarded and covers both histograms
- RefineTimeoutEnvVar unexported (no consumer)

Not in this PR: the aggregate worker deadline (Mininglamp-OSS#220 §2) and its
budget-matrix test. That test would have caught P1-1 on the first run.

Verification:
  CGO_LDFLAGS=-L/home/mlamp/.local/lib go test -race -count=1 ./...  PASS
  CGO_LDFLAGS=-L/home/mlamp/.local/lib go vet ./...                  PASS
  git diff --check                                                   PASS

Refs Mininglamp-OSS#231, Mininglamp-OSS#220
@github-actions github-actions Bot added size/XL PR size: XL and removed size/L PR size: L labels Aug 27, 2026
@wanyiwang06 wanyiwang06 changed the title feat(obs): histogram for LLM call latency + arm the fallback deadline guard feat(obs): run + attempt latency histograms, configurable REFINE_TIMEOUT Aug 27, 2026
@wanyiwang06

Copy link
Copy Markdown
Contributor Author

Thanks to both reviewers — the two P1s were correct, and they were one root cause seen from two ends. Pushed 33a40bb.

P1-1 / P1-2 — PerModelTimeout reverted

Both entry points (callWithPolicyAndModel, callStreamWithModel) are shared by worker and refine, so the field cannot be scoped to one side at that line. Reverted rather than patched.

Confirmed independently before reverting:

  • the guard is gated on ctx.Deadline() being present; worker roots at context.Background() (processor.go:183,253, meta_processor.go:78, personal_processor.go:623) with no WithTimeout/WithDeadline in between — the field was inert
  • on refine, 90 < 1 + 2*180 holds unconditionally, so the primary would lose its retry budget on every transient blip, at ERROR level, and {reason="budget_starved"} would read ~100% of switches by construction of the defaults

The second one is the part I most want to acknowledge: that series was the diagnostic this PR itself proposed for #220, and arming the guard would have destroyed it. internal/service/llm.go now carries a comment recording why the field is absent, with both preconditions, so the next person doesn't re-add it as harmless hardening.

Also corrected the attribution — the worker gap is #220 §2 (aggregate deadline vs the stuck scanner and lease), not §1, which is the agent path and already passed PerModelTimeout. That sentence is gone from the PR body and the source.

P2-1 — taken, and it changed my mind on the PR's value

Added llm_attempt_duration_seconds{path,outcome}. You're right that this is what #220 actually needs: LLM_TIMEOUT is per-attempt, and the run distribution over-estimates exactly at P99 because the P99 is the retried runs. Without it this PR would have shipped a number that looks like the answer and isn't.

outcome is kept as a label (a timed-out attempt and a fast 403 have different distributions); model and position are not, for the bucket-multiplication reason.

There's now a test asserting the two series report different values for the same logical call — 2×10s attempts + 1s backoff gives attempt _sum 20s, run _sum 21s — so the distinction can't silently collapse.

P2-3 — taken, renamed to llm_run_duration_seconds

Agreed it's cheap now and expensive later, and the new name is more honest about what it measures. Left llm_call_duration_seconds_total in place rather than deprecating it in the same PR.

P2-2 — taken

Added PathDocumentPreview and tagged document_preview.go. Fair hit: I tagged three methods with no callers and missed the one with real traffic.

P2-4 — taken

Clamped to [1s, 30m] with a once-per-process log. Both cases you named are covered by the new parse table, including 9223372036854775807 → previously -1s → every refine building an already-expired context.

P2-5 — taken

REFINE_TIMEOUT row added. Both stale sentences fixed; the escalation sentence now states which paths the guard is actually active on and why the other two are excluded.

P2-6 — taken

15-row parse table for refineTimeout(), plus the negative-clamp and run-vs-attempt tests. The budget-matrix test stays with the worker-deadline PR, where it has something to assert against — and you're right that having written it first would have caught P1-1 on the first run. That's the lesson I'm taking from this review: the purely-additive histogram got four tests, the two hunks that changed runtime behaviour got none.

Nits

Bucket slice now defensively copied; label-set pin nil-guarded and extended to both histograms; negative clamp tested; RefineTimeoutEnvVar unexported. Left refineTimeout() re-reading the env per request, per your own note that it matches the agentStepTimeoutOverride precedent.

On the open question

Taking @yujiawei's advice to leave the bucket layout alone. With the attempt histogram now in, the sub-second and long-context bands are separable without re-cutting the boundaries.

Still open, by design

The aggregate worker deadline (#220 §2) is untouched — worst case ~18–27 min against a ~10-min scanner and 20-min lease is a real duplicate-dispatch risk, and it needs its own PR with the budget matrix.

Re: LLM_FALLBACK_MODELS in deployments — with the hunk reverted, P1-2's blast radius is moot, but the question is still worth answering for #220 §2's urgency and I don't have visibility into the deployment configs.

check-sprint and label are still red; both are project-board automation.

@yujiawei yujiawei left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review — PR #232 (octo-smart-summary)

Re-review at head 33a40bb, against merge-base eb9e0e3. I checked the branch out and ran locally (go1.26.5): go build ./..., go vet ./internal/llmobs/... ./internal/api/handler/... ./internal/service/..., and go test -race -count=1 ./internal/llmobs/... ./internal/llmfallback/... ./internal/api/handler/... ./internal/service/... — all clean, all PASS. CI on this head is green except check-sprint (project-board automation, unrelated to the diff).

The previous round's two blockers are genuinely fixed, not papered over. Reverting the PerModelTimeout hunk and replacing it with a comment that explains why the field is absent is the right call, and the new llm_attempt_duration_seconds series is a better answer to the run-vs-attempt problem than the doc-narrowing I suggested. Every P2 and nit from the last round is addressed too.

One thing did not survive the fix, and it is the same class of defect the last round blocked on: the CONFIGURATION.md sentence that was rewritten to state the guard's actual scope now states it wrongly, and it does so in the direction that was previously correct. That is the only blocker, and it is a one-line edit.


1. Spec compliance

Result: not met — one deviation, plus a stale PR title.

Measured against this PR's own "Change" section:

Stated change Status
llm_run_duration_seconds{path} — whole-Run wall-clock Implemented as described
llm_attempt_duration_seconds{path,outcome} — single attempt Implemented; AttemptEvent.Duration correctly excludes the backoff sleep (fallback.go:322 starts the clock after the select)
Buckets fixed at package scope, 0.5s → 300s Implemented; defensive copy in newHistogramVec as requested
Rename to avoid the OpenMetrics family collision Implemented
REFINE_TIMEOUT, default unchanged at 90s, clamped to [1s, 30m], logged once Implemented; all four call sites converted (no 90 * time.Second left outside the const and its test)
PathDocumentPreview on the live preview route Implemented; Call/CallStream set no path of their own, so the caller's tag propagates — verified
Three CallReduceByPerson* variants tagged Implemented
CONFIGURATION.md: add the REFINE_TIMEOUT row, correct two sentences in the LLM_FALLBACK_MODELS row Diverges — see 2.1
Tests (exact cumulative, 400s over-range, label pins nil-guarded, negative clamp, run-vs-attempt divergence, concurrency, 15-row parse table, parseExposition suffix resolution) All present; the parse table is exactly 15 rows

Stale title. The PR is still titled "feat(obs): histogram for LLM call latency + arm the fallback deadline guard", but this head explicitly does the opposite of the second clause — internal/service/llm.go:270-286 now documents at length why the guard is deliberately not armed. If this is squash-merged, git log will permanently assert the reverted behaviour, which is the same trap the last round blocked on, one level up. Not a code change; please just fix the title box before merging.


2. Code quality

Result: changes requested. One P1, five P2, four nits.

P1 — CONFIGURATION.md:21 now says the early-escalation guard is active on tool calls. It is not, on any production caller.

The rewritten sentence is:

The early-escalation guard … requires BOTH a per-attempt budget and a parent deadline, so today it is active on agent chat and tool calls only — worker Map/Reduce roots at a deadline-less context, and API refine deliberately does not arm it …

The rule it states is correct. The conclusion it draws from that rule is not, and the sentence contradicts itself. Walking the two candidate readings of "tool calls":

PathToolCall (CallWithTools). It does set the per-attempt budget — internal/service/llm.go:569, PerModelTimeout: c.toolCallTimeout. But the guard is gated on the parent context carrying a deadline (internal/llmfallback/fallback.go:306-315; PerModelTimeout is budget arithmetic only, it never wraps the attempt context). Every production caller of CallWithTools is the worker:

  • internal/worker/processor.go:755 — the toolCallFn closure defined at :753, over the ctx := context.Background() created at internal/worker/processor.go:739
  • internal/worker/personal_processor.go:706, reached e.g. from personal_processor.go:801 (pipeline.ResolveTopicTarget(ctx, …)) with that same untimed context

Nothing between those roots and the tool call adds a deadline. The only context.WithTimeout in internal/pipeline on this side is octo_search_fetch.go:131, and it is scoped to fetchViaBatch (message fetching via the search client), which invokes no toolCallFn. So ctx.Deadline() returns ok == false and the guard cannot fire — the same argument the row itself already makes for worker Map/Reduce.

PathAgentTool (merge / narrow / summarize). These go through Call / CallStrict / CallDisclosingTruncationcallWithPolicyAndModel, which as of this head sets no PerModelTimeout at all (internal/service/llm.go:270-286). Guard not armed regardless of deadline.

So under either reading the claim is false, and the only path where the guard actually runs today is agent_chat: PerModelTimeout at internal/agent/llm.go:101 plus a real parent deadline from internal/agent/runner.go:156 (context.WithTimeout(ctx, r.policy.StepTimeout)).

What makes this blocking rather than a nit is that the diff introduced it. The pre-PR sentence was:

For agent chat, keep maxAttempts*LLM_TIMEOUT + backoffs (3s) <= AGENT_STEP_TIMEOUT; it escalates early when the remaining deadline cannot fit both the pending retry and a fallback attempt.

Scoped to agent chat — correct. This PR broadened it. An operator reading the configuration reference will now believe the worker's tool-call path has starvation protection it does not have, and anyone picking up #220 §2 will read "tool calls: armed" and skip exactly the path that needs the aggregate deadline. That is the operational trap the last round blocked on, moved from a Go comment into the file operators actually read.

Fix: drop and tool callsso today it is active on agent chat only — and, if you want the exclusion list to stay complete, add the one-clause reason (tool calls set a per-attempt budget but their only callers are the worker, which has no parent deadline). One line, no code change.

P2-1 — CallRaw is still untagged on two live worker call sites

The PR correctly hunted down document_preview by reasoning that a wired route landing in path="unknown" is worth more than tagging three methods with no callers. The same sweep misses CallRaw:

  • internal/worker/processor.go:763-765 — the llmFn closure, 检索后裁剪 PostRetrievalNarrow
  • internal/worker/personal_processor.go:716-718 — same shape

CallRaw (internal/service/llm.go:547-554) delegates to Call, which sets no path, and both closures carry the untimed worker context with no WithPath anywhere above them. Post-retrieval narrowing runs on every worker task, so this is real traffic, and it now costs path="unknown" a full bucket family on llm_run_duration_seconds plus one per observed outcome on llm_attempt_duration_seconds — mixed in with whatever else falls through. Either tag the two closures or give them their own worker_narrow path.

P2-2 — CONFIGURATION.md:53 calls REFINE_TIMEOUT a "Total request deadline", which the two streaming endpoints cannot enforce

Both streaming refine handlers clear the response write deadline before streaming:

// internal/api/handler/edit.go:429   (and personal_refine.go:321)
_ = http.NewResponseController(w).SetWriteDeadline(time.Time{})

If a client stays connected but stops reading, writeSSE / Flush blocks once the socket buffer fills, and cancelling llmCtx does not interrupt an in-flight write. There is also no WriteTimeout on the server (cmd/summary-api/main.go:128, :135) to bound it. So on RefineSummaryStream and RefinePersonalSummaryStream, REFINE_TIMEOUT bounds the LLM run, not the request.

This behaviour predates the PR (the SetWriteDeadline call comes from #157) and I am not asking you to fix it here. It becomes in-scope only because this PR is the one making the promise: the new row says "Total request deadline … for the four summary-refine endpoints … both streaming and non-streaming". Narrowing that to "the LLM budget for the refine call" would keep the row true. Worth its own issue.

P2-3 — llm_attempt_duration_seconds is right-censored at LLM_TIMEOUT, so it cannot answer half the question its HELP text claims

internal/llmobs/metrics.go:316: "This is the series to size the per-attempt LLM_TIMEOUT from."

Every attempt is already capped at LLM_TIMEOUT: http.Client{Timeout: …} at internal/service/llm.go:89, and context.WithTimeout(ctx, c.timeout) at internal/agent/llm.go:137. An upstream that would have taken 400s is recorded at ~180s (and classified retry_same_model, since ctx.Err() is nil when the client timeout fires — internal/service/llm.go:318-322). The distribution's right tail is therefore a pile-up at the current cap, sitting exactly on the le="180" boundary.

That is fine for deciding whether to lower LLM_TIMEOUT, and useless for deciding whether raising it would recover requests — the observations that would tell you were truncated by the cap you are trying to size. Given the whole point of the series is #220's timeout decision, one clause in the HELP saying so would stop someone reading a censored P99 as the real one.

P2-4 — the attempt histogram's cardinality reasoning omits its own second label

internal/llmobs/metrics.go:332-336 justifies excluding model and position because "bucket series multiply by len(buckets)+3" — but the label set it ships is {path, outcome}, and outcome multiplies too. Concretely: 8 paths (observer.go:10-21, including unknown) × 4 reachable outcomes × 15 lines ≈ 480 series for this family alone, against 120 for runDur. That is affordable and I am not asking you to drop outcome — the "a timed-out attempt and a fast 403 have different distributions" argument is right. But the comment reads as if path were the only dimension, and it is the comment a future reader will use to decide whether adding one more label is cheap.

P2-5 — llm_call_duration_seconds_total is now exactly llm_run_duration_seconds_sum

Both are cumulative Run seconds labelled by path, both fed from e.Duration in the same ObserveResult (metrics.go:373 and :377). The PR keeps the counter as "purely additive", which is the safe choice for this PR, but they are now two hand-maintained copies of one quantity that will silently diverge the first time someone edits one observe site. Worth a deprecation note on the counter's HELP so the next person knows which one is canonical.

Nits

  • internal/api/handler/refine_budget.go:87if d < minRefineTimeout is unreachable. secs <= 0 is rejected at :76, so secs >= 1 and d >= 1s always. The "below the minimum; clamped" log can never fire, and the test's at the minimum row exercises the pass-through, not the clamp. Either drop the branch or move the floor check before the <= 0 rejection if you want REFINE_TIMEOUT=0 to clamp rather than fall back.
  • internal/api/handler/refine_budget.go:75strconv.Atoi returns a platform-width int. On a 32-bit build the 9223372036854775807 row of the parse table would hit ErrRange and return the default instead of maxRefineTimeout, failing the test. Irrelevant for this deployment target; strconv.ParseInt(raw, 10, 64) would make the table architecture-independent.
  • internal/llmobs/metrics_test.go:746 — the doc comment says "path is the only permitted label", but the allowed map two lines down permits outcome on llm_attempt_duration_seconds. Stale as written.
  • internal/api/handler/refine_budget_test.go — the unset row does not defend against an ambient REFINE_TIMEOUT in the test environment. t.Setenv(...) followed by os.Unsetenv(...) in the !tc.set branch would register the cleanup and pin it.

3. What I verified as correct

  • Boundary semantics. sort.SearchFloat64s returns the least i with buckets[i] >= v, which is le (≤) inclusive. Checked on-boundary (0.5le="0.5"), just-under (0.4999le="0.5"), and over-range (400+Inf only, still in _sum/_count).
  • Cumulative rendering, +Inf == _count, %g shortest-round-trip on both boundaries and _sum.
  • Lock discipline. The boundary search is outside the lock (buckets are immutable after the defensive copy); write snapshots counts, sums and totals under one acquisition. counts[l] is allocated before the i < len(buckets) check, so an over-range-only series still registers a key and renders. -race clean.
  • parseExposition's suffix resolution checks the exact name first, so llm_call_duration_seconds_total is not misrouted into a histogram family — and after the rename there is no ambiguity left at all.
  • Attempt vs run semantics. AttemptEvent.Duration starts after the backoff select, so the 20s-vs-21s assertion in TestAttemptHistogram_IsPerAttemptNotPerRun is measuring the right thing.
  • log.Printf in refine_budget.go matches the handler package convention exactly (144 log.Printf, 0 slog), so no consistency issue there.
  • Per-request env read. I raised no objection last round and still have none: it matches the agentStepTimeoutOverride precedent it cites, the cost is nothing next to a multi-second LLM call, and the handlers really are constructed in tests without a deps container.
  • The 30m clamp ceiling is well chosen, not arbitrary: worst-case reachable run (3 attempts × 180s × 2 models + backoffs ≈ 18 min) sits under it, and c.Request.Context() still cancels on client disconnect.
  • Everything from the previous round: P1-1 and P1-2 resolved by reverting the hunk and recording why; P2-1 (run vs attempt) answered with a second histogram rather than a doc narrowing; P2-2 (document_preview), P2-3 (naming), P2-4 (clamp + log), P2-5 (CONFIGURATION.md row), P2-6 (parse table) all done; all four nits (bucket copy, unexported env const, nil-guarded label test, negative-clamp test) done.

4. Verdict

CHANGES_REQUESTED.

The single blocker is the CONFIGURATION.md:21 guard-scope sentence (P1) — and tool calls is wrong and the diff introduced it. That plus the PR title are both edits you can make without touching code. Everything else on this list is a P2 or a nit and I would not hold the PR for any of them; the histogram work is merge-quality and the response to the last round was thorough.

Smallest path to approval:

  1. Drop and tool calls from CONFIGURATION.md:21 (P1).
  2. Fix the PR title so the squash commit does not assert the reverted behaviour.
  3. Optional but cheap while you are in there: P2-1 (two CallRaw tags) and the refine_budget.go:87 dead branch.

P2-2 through P2-5 are fine as follow-ups.


5. Coverage note

Ran and verified: go build, go vet, and go test -race -count=1 across internal/llmobs, internal/llmfallback, internal/api/handler, internal/service (go1.26.5, all PASS); hand-traced the histogram boundary/cumulative/render path; repo-wide grep for every context.WithTimeout/WithDeadline outside tests, and a full call-graph walk from each worker root to every llmfallback.Run entry point; enumerated every LLM call site in the repo against its WithPath tag; confirmed all four refine call sites converted. Two independent parallel review passes were run alongside mine and both completed; their findings are folded in above, each one re-verified against the source before inclusion (the CallRaw and stale-title items were independently reached by more than one pass; the SSE write-deadline item came from one and I downgraded it to P2 after confirming it predates this PR).

Not verified:

  • No promtool or Prometheus binary available, so the exposition was read and hand-parsed, not scraped. The OpenMetrics reasoning behind the rename is from the spec, not an observed scrape — but the rename removes the risk either way, so nothing turns on it now.
  • No deployment manifests reviewed (different repo). Whether REFINE_TIMEOUT or LLM_FALLBACK_MODELS is set per environment is unconfirmed; P2-2's exposure depends on the former.
  • No dashboards or alert rules checked for consumers of llm_call_duration_seconds_total that P2-5 would affect.
  • No production metrics. The censoring in P2-3 is derived from the code path, not measured.
  • #220 §2's lease / stuck-scanner overrun (worst case ~18–27 min against a ~10-min scanner and a 20-min lease) is correctly listed as out of scope here and remains fully open. Please make sure it is tracked before this merges, since the reverted hunk was the only thing gesturing at it.
  • The SetWriteDeadline behaviour in P2-2 was traced statically; I did not exercise a stalled-reader client against a running server.

@Jerry-Xin Jerry-Xin left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Re-review @ 33a40bb0 (fix commit: drop the PerModelTimeout hunk; clamp REFINE_TIMEOUT; split run vs attempt latency)

Byte-verified delta against the previously reviewed head 7ed3e737ed18 (merge-base eb9e0e3): the fix commit is honest — the arming hunks are gone from both Call/CallStream entry points, the histogram is split into run + attempt series, refineTimeout() gets a clamped parse with real tests, and document_preview is tagged. Every prior-round blocker is resolved at the code level. The revert did leave one blocking documentation contradiction behind.

🔴 Blocking

🔴 1. REFINE_TIMEOUT >= 2 * LLM_TIMEOUT + backoff is stale after the revert — following it still leaves refine fallback unreachable in the worst case

internal/api/handler/refine_budget.go:21 and the new CONFIGURATION.md REFINE_TIMEOUT row both state:

For a fallback to get one full attempt the budget must satisfy roughly: REFINE_TIMEOUT >= 2 * LLM_TIMEOUT + backoff

That formula was only true under the arming behaviour this commit reverted (where the budget guard abandoned the primary after its first retry). After the revert, callWithPolicyAndModel runs with MaxAttempts: 3 and no PerModelTimeout, so the primary exhausts three full attempts before switching:

  • A hanging attempt is cut by http.Client.Timeout (= LLM_TIMEOUT, 180s default) and classifies RetrySameModel because the parent context is still alive (internal/service/llm.go:318-323).
  • Only when the parent deadline fires inside an attempt does it classify Terminal (service/llm.go:319-321), and Run returns without ever trying a fallback.

Worst-case budget for one complete fallback attempt = 3 primary attempts × LLM_TIMEOUT + 1s + 2s backoffs (internal/llmfallback/fallback.go:109, backoff = 2^(a-1) s) + one LLM_TIMEOUT for the fallback = (MaxAttempts+1) * LLM_TIMEOUT + 3s = 723s at defaults, not 363s. At the documented 363s: attempts 1–2 plus backoff consume 361s, the parent dies during the third backoff/attempt → ctx.Err()Terminalno fallback attempt ever starts. An operator who sizes REFINE_TIMEOUT with the documented formula gets exactly the failure the row's own previous sentence warns about ("if a hanging primary consumes it, no fallback attempt can start").

This is a docs/comment fix, not a code change — but it is this PR's own new text contradicting this PR's own shipped behaviour, on exactly the quantity (refine fallback reachability) the previous round flagged. Fix: correct the refine_budget.go comment, the CONFIGURATION.md row, and the PR body to the real worst case — e.g. "a fallback gets one complete attempt only when REFINE_TIMEOUT >= (MaxAttempts+1) * LLM_TIMEOUT + backoffs (723s at defaults); below MaxAttempts * LLM_TIMEOUT + backoffs (543s) a hanging primary exhausts the budget before a fallback can start" — or state plainly that under the 3-attempt semantics a hanging primary makes fallback unreachable at any realistic budget, and the knob exists to be sized against measured refine percentiles.

💬 Non-blocking

  • 🟡 CONFIGURATION.md (LLM_FALLBACK_MODELS row) and the PR body say the early-escalation guard "is active on agent chat and tool calls only". The tool-call path also sits on a deadline-less context: CallWithTools is only invoked from the worker pipeline toolCallFn closures (internal/worker/processor.go:755, internal/worker/personal_processor.go:706), whose ctx roots at executePipeline's ctx := context.Background() (processor.go:739) with no WithTimeout/WithDeadline anywhere between (only octo_search_fetch.go wraps, on a different path). The guard (fallback.go:306-315) is gated on ctx.Deadline(), so it cannot fire on tool calls either — agent chat (runner.go:156 step deadline) is the only live path. Docs-only, and the tool-call inertness pre-exists this PR, but the sentence is new and mildly repeats last round's failure mode.
  • 🔵 internal/llmfallback/observer.go:19 comment says POST /v1/summaries/document/preview; the mounted public path is /api/v1/summaries/document/preview (internal/api/router/router.go:177, pinned by document_preview_route_test.go). Trivial.
  • 🔵 The d < minRefineTimeout branch in refine_budget.go is unreachable (Atoi rejects non-positive, so secs >= 1d >= 1s = min). Harmless defensive code; noting only.

Prior-round findings, adjudicated byte-against 33a40bb0

Finding Status
Jerry-Xin 🔴1 / yujiwei P1-1 — guard inert on worker Map/Reduce, claim it was armed FIXEDPerModelTimeout removed from both Run config literals (service/llm.go:287, :415); comments replaced by an accurate why-not-to-arm note; PR title/body rewritten ("Deliberately out of scope"); #220 §2 attribution corrected
Jerry-Xin 🔴2 / yujiwei P1-2 — refine guard misfires on every first retry FIXED — field unset ⇒ the cfg.PerModelTimeout > 0 gate (fallback.go:306) is false on api_refine; budget_starved can no longer read ~100% of refine switches by construction of the defaults
yujiwei P2-1 — attempt-level series FIXEDllm_attempt_duration_seconds{path,outcome}, exactly one observation per attempt (fallback.go:324); divergence pinned by test (2×10s attempts + 1s backoff ⇒ attempt _sum 20s vs run _sum 21s); labels deliberately narrow (no model/position)
yujiwei P2-2 — document_preview untagged FIXEDPathDocumentPreview added; the route's single CallStream site tagged (document_preview.go:317-318); this is what the file is doing in the delta — requested fix, not drift
yujiwei P2-3 — OpenMetrics name collision FIXED — renamed llm_run_duration_seconds with the rationale recorded; repo-wide grep finds no consumer of the old histogram name (it never shipped)
yujiwei P2-4 / mochashanyao 🟡 — clamp + overflow FIXED[1s, 30m] clamp with a pre-multiplication overflow guard (secs > maxRefineTimeout/time.Second checked before the multiply, so no time.Duration wrap) and once-per-process logging; wrong-unit (90000→30m) and int64-max (→30m) rows in the parse table
yujiwei P2-5 / mochashanyao 🟡 — REFINE_TIMEOUT docs PARTIAL — row added, stale 90s sentences fixed, but the row carries the stale formula above (🔴) and the inaccurate guard-scope sentence (🟡)
yujiwei P2-6 — tests for the behaviour-changing hunks FIXED — 15-row parse table + default-pin test + negative-clamp test + run-vs-attempt test; the budget-matrix test moving to the #220 §2 worker-deadline PR is the right home now that nothing arms the guard in this PR
yujiwei nits (defensive bucket copy, unexport env var, nil-guarded label pin, negative clamp untested) FIXED — all four; RefineTimeoutEnvVar has zero remaining references
Histogram core (prior head) Still merge-quality: build/vet clean, -race green, buckets defensively copied in newHistogramVec, negative observations clamped in observe

Verification performed at this head

  • git diff 7ed3e737ed18..33a40bb0dec3 reviewed hunk-by-hunk (8 files, 637 lines).
  • go build ./... ✅ · go vet ./...
  • go test -race -count=1 ./internal/llmobs/... ./internal/llmfallback/... ./internal/api/handler/... ./internal/service/... ✅ all ok; new tests re-run verbosely and passing (TestRefineTimeout_ParseTable 15 subtests, TestRefineTimeout_DefaultIsUnchanged, TestAttemptHistogram_IsPerAttemptNotPerRun, TestHistogram_NegativeObservationIsClamped, label-set pin, quantile-inputs exact).
  • Guard context lineage enumerated for all four Run sites: agent chat (step deadline ⇒ guard live; pre-existing), tool call (deadline-less ⇒ inert; pre-existing), worker Call/CallStream (deadline-less; field now unset), refine (90s parent; field now unset).
  • Cross-PR: #213 and #215 are both already merged and are ancestors of this PR's merge-base — no open-PR symbol collision possible; only shared file is CONFIGURATION.md.
  • CI: Build / Lint / Test / Test (race, cgo) / Vet / dependency-review / history / label / pr-title-lint / osv-scan / secret-scan all pass; check-sprint is project-board automation and not in the required ruleset; code-review status check is this review.

Verdict

REQUEST_CHANGES — one 🔴: the revert left the refine fallback-budget formula stale in refine_budget.go + CONFIGURATION.md (+ PR body); the documented 363s budget provably cannot reach a fallback attempt in the hanging-primary worst case the docs themselves discuss (723s at defaults). Everything else raised in both prior reviews is fixed and byte-verified. The remaining fix is docs/comment-only; with it, this is approvable.

mochashanyao
mochashanyao previously approved these changes Aug 27, 2026

@mochashanyao mochashanyao left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[Octo-Q · automated review]

Verdict: Approve — no blocking findings; notes below (data-flow traced).


Code Review — PR #232 (octo-smart-summary)

Reviewer: Octo-Q (automated review)

Summary

This PR adds latency histograms for the LLM fallback runner, makes the API refine deadline configurable, and closes two remaining path-label gaps. It introduces two hand-rolled cumulative histograms in internal/llmobsllm_run_duration_seconds (whole-Run wall-clock, by path) and llm_attempt_duration_seconds (single upstream attempts, by path+outcome) — to feed the P95/P99 sizing work that #220 defers. It replaces the four hardcoded 90s refine contexts with a REFINE_TIMEOUT env override (refine_budget.go) clamped to [1s, 30m] against wrong-unit and duration-overflow typos, keeping the 90s default. It tags the document-preview generation call (document_preview) and the three reduce-by-person worker wrappers (worker_reduce) that previously landed in unknown. Finally it documents why PerModelTimeout is deliberately NOT armed on the service entry points — the arming hunk from the first commit was dropped in follow-up 33a40bb. Overall: a careful, defensive change; histogram math, clamp logic, and path propagation all verified end-to-end, and no P0/P1 issues found.

Verification

Static analysis only at head 33a40bb0; build and tests not executed in this environment (review protocol forbids running them here; the PR ships its own test coverage, described below).

  • Histogram bucket semanticssort.SearchFloat64s at internal/llmobs/metrics.go:196 returns the first boundary >= v, so a sample exactly ON a boundary counts into that bucket (correct inclusive-le semantics); over-range samples still reach _sum/_count and +Inf (:198-202); negatives clamp to 0 (:191).
  • Concurrencyobserve mutates under h.mu; write snapshots under the same lock and renders after unlock (metrics.go:207-228); the bucket slice is defensively copied in newHistogramVec (:180-182) and never mutated, so the lock-free read in write is safe.
  • Bounded cardinality — runDur labels = path only (metrics.go:374); attemptDur = path+outcome (:334-337); both from closed constant sets; series = paths × (12 buckets + 3).
  • No naming collisionllm_run_duration_seconds cannot collide with the pre-existing llm_call_duration_seconds_total under OpenMetrics family normalization; no existing series renamed or removed, so existing dashboards keep working.
  • REFINE_TIMEOUT parse/clamp — wrong-unit (90000 → clamped 30m), int64-max (no negative wrap), non-numeric/float/duration-string/zero/negative (→ default 90s) all pinned by internal/api/handler/refine_budget_test.go; warning uses %q, so log-injection-safe.
  • Refine parity — all four call sites converted (internal/api/handler/edit.go:277, :444, internal/api/handler/personal_refine.go:110, :336); grep confirms no remaining 90 * time.Second outside the default constant.
  • Path propagationcallStreamWithModel/callWithPolicyAndModel build llmfallback.Config without Path, so the context value wins (internal/llmfallback/context.go:27); the document_preview tag set at internal/api/handler/document_preview.go:318 reaches Run intact.
  • Duration data sources — every ObserveAttempt/ObserveResult emission fills Duration: time.Since(...) (internal/llmfallback/fallback.go:136/:147/:172/:183/:202/:327), so both histograms receive real non-negative wall-clock on every terminal path, including cancel/timeout and the empty-model-list error path.

Findings

No P0/P1 issues; two nits below.

Nit — PR title overstates what ships (internal/service/llm.go:270)

The title/branch says "arm the fallback deadline guard", but the final diff deliberately leaves PerModelTimeout unset — the arming hunk was dropped in 33a40bb and replaced by this explanatory comment, and CONFIGURATION.md:21 now documents that the guard is active on agent chat and tool calls only. Code and docs are correct and self-consistent; only the title may mislead changelog readers. Suggest retitling, e.g. "histogram for LLM call latency + REFINE_TIMEOUT override".

Nit — Unreachable branch + shared warn-once, both as documented (internal/api/handler/refine_budget.go:87)

(1) d < minRefineTimeout is unreachable: the secs <= 0 gate at :76 already guarantees secs >= 1, hence d >= 1s == minRefineTimeout — pure defense. (2) The single shared sync.Once at :58 covers all three warning branches, so if REFINE_TIMEOUT moved between deviation classes within one process lifetime, only the first class would log. Both match the documented "logged once per process" contract; no change required.

Things I checked that are fine

  • document_preview.go hunk is pure closure re-indentation plus WithPath; the SSE delta logic is byte-identical, and the handler has exactly one LLM call.
  • parseExposition change in metrics_test.go resolves _bucket/_sum/_count samples to the base family only when its TYPE is histogram; no existing counter/gauge name ends in those suffixes, so legacy assertions are unaffected.
  • New tests drive the real public surface (NewMetricsObserveResult/ObserveAttemptWritePrometheus) with exact cumulative assertions, a race test, and a negative-clamp test — no hand-fed internal state bypassing the production path.
  • Guard-arming surface is exactly as documented: PerModelTimeout set only at internal/service/llm.go:569 (tool calls) and internal/agent/llm.go:101 (agent chat); worker Map/Reduce roots at deadline-less context.Background() (internal/worker/processor.go:739), confirming the new comment's claim that the guard would be inert there.
  • Per-attempt cap remains http.Client{Timeout: LLM_TIMEOUT} (internal/service/llm.go:89), unchanged; attempt-vs-run divergence the help texts describe is therefore real and correctly attributed.

Data-flow trace (per consumed datum)

  • e.Duration (histogram input) ← time.Since(start) / time.Since(attemptStart) at every emission site in internal/llmfallback/fallback.go — always populated, monotonic, non-negative; flows to observe() on all terminal paths (success, terminal, exhausted, cancel, timeout, misconfiguration).
  • path label ← cfg.pathFor(ctx) = Config.Path (tool_call only) else PathFromContext; this PR sets it at the four refine handlers, the three reduce-by-person wrappers (internal/service/llm.go:951/:958/:966), and the document-preview handler (internal/api/handler/document_preview.go:318); everything else stays unknown. No intermediate WithPath/Config.Path override exists in any of those chains.
  • refineTimeout() result ← REFINE_TIMEOUT env (TrimSpace → Atoi → clamp) or 90s default → context.WithTimeout at the four refine sites → parent deadline for llmfallback.Run; per-attempt cap unchanged (LLM_TIMEOUT via http.Client).
  • h.buckets ← defensive copy of durationBuckets in newHistogramVec; immutable after construction; consumed by the boundary search and the render loop.

Blind-spot checklist (C1–C6)

  • C1 dual-path parity — clear. Streaming/non-streaming refine pairs both converted (edit.go x2, personal_refine.go x2); Call/CallStream entry points both leave PerModelTimeout unset with mirrored comments (internal/service/llm.go:270 / :412); reduce-by-person WithModel variants were already tagged at base — this PR completes the three untagged wrappers.
  • C2 control-flow ordering / nested reuse — clear. refineTimeout() is invoked independently at four sites (no nesting, no double application); parse probed with non-canonical inputs ("+90" accepted as 90 — safe; "1_800", "0x708", unicode digits rejected → default — safe).
  • C3 authorization boundary vs capability — N/A: no auth/permission/tool/credential changes in the diff.
  • C4 authorization lifecycle / container cascade — N/A: no authorization or container/member status logic touched.
  • C5 build/note pass ≠ runtime correctness — clear with stated caveat: no packaging/build artifact changes; runtime paths were traced end-to-end (emission → observe → render; env → clamp → context deadline) rather than relying on "tests exist"; per protocol, builds/tests were not executed in this environment.
  • C6 governance/docs self-consistency — clear. CONFIGURATION.md:21 and :53 cross-checked against code (default 90s, clamp [1s, 30m], guard-active scope, llm_run_duration_seconds naming); consistent with unchanged rows (LLM_TIMEOUT=180, AGENT_STEP_TIMEOUT sizing advice).

Cross-round blocker re-check (R6)

N/A — no prior review round exists on this issue; nothing outstanding to re-verify.

Verdict: APPROVED

The histogram implementation is mathematically correct (boundary-inclusive buckets, cumulative rendering, +Inf/sum/count consistency, outlier retention), concurrency-safe, and cardinality-bounded; the REFINE_TIMEOUT override is clamped against exactly the two failure modes that parse cleanly but break production (wrong unit, duration overflow) while preserving the historical 90s default; all four refine call sites and every path-tagging site are wired consistently; and every datum feeding the new series was traced back to its emission point. Two nits, neither blocking.

[Octo-Q] verdict: APPROVE — zero P0/P1 at head 33a40bb; histogram math, REFINE_TIMEOUT clamp, four-site parity, and emission→render data flow all verified end-to-end; only two non-blocking nits (stale PR title vs dropped arming hunk; informational refine_budget notes). Recommend the terminal review approve if it concurs with the trace above.

Both blockers from the re-review are documentation defects introduced by
the previous commit's revert, and both assert something the shipped code
does not do.

## P1 (Jerry-Xin) — the refine sizing formula was stale after the revert

refine_budget.go and CONFIGURATION.md both stated

    REFINE_TIMEOUT >= 2 * LLM_TIMEOUT + backoff

That held only under the budget-guard behaviour the previous commit
reverted, where the primary was abandoned after its first retry. With the
guard unarmed, Run gives the primary all MaxAttempts (3) attempts before
considering another model: a hanging attempt is cut by http.Client.Timeout
and classifies RetrySameModel, so it costs a full LLM_TIMEOUT and the loop
continues. Only when the parent deadline fires inside an attempt does it
classify Terminal, and then Run returns with no fallback attempted at all.

Real thresholds at defaults:

    fallback gets one complete attempt  >=  (MaxAttempts+1)*LLM_TIMEOUT + backoffs = 723s
    fallback cannot start at all         <   MaxAttempts*LLM_TIMEOUT + backoffs    = 543s

An operator sizing to the documented 363s would have landed squarely in the
second regime while believing they were in the first — the exact failure the
same row warns about. Both texts now carry the real arithmetic, note that
the 90s default is in the unreachable regime deliberately, and record why
the old number was wrong so it does not get restored.

## P1 (yujiawei) — "and tool calls" was false on every production caller

The rewritten guard-scope sentence claimed the escalation guard is active
on "agent chat and tool calls only". Tool calls do set PerModelTimeout
(service/llm.go:569), but the guard is additionally gated on the PARENT
context carrying a deadline, and CallWithTools' only callers are the worker
pipeline closures (worker/processor.go:755, personal_processor.go:706) over
the deadline-less context.Background() at processor.go:739. Nothing in
between adds a deadline.

Agent chat is the only live path: PerModelTimeout at agent/llm.go:101 plus
a real parent deadline from runner.go:156. The sentence now says so, with
the per-path exclusion reasons.

This one stings: the pre-PR text was correctly scoped to agent chat and
this PR broadened it. Someone picking up Mininglamp-OSS#220 §2 would have read
"tool calls: armed" and skipped a path that needs the aggregate deadline.

## Also addressed

- P2-1: tag the two CallRaw sites (PostRetrievalNarrow) with a new
  PathWorkerNarrow. Runs on every worker task, so it was real recurring
  traffic sitting in path="unknown" — the same class of gap the previous
  commit fixed for document_preview.
- P2-2: CONFIGURATION.md no longer calls REFINE_TIMEOUT a "total request
  deadline". Both streaming handlers clear the response write deadline, so
  it bounds the LLM run, not the request. Predates this PR; worth its own
  issue.
- P2-3: llm_attempt_duration_seconds HELP now states it is right-censored
  at LLM_TIMEOUT — sound for deciding to lower the cap, useless for
  deciding what raising it would recover.
- P2-4: the cardinality comment now includes outcome in its own arithmetic
  (~480 series vs runDur's 120) instead of reading as if path were the
  only dimension.
- P2-5: deprecation note on llm_call_duration_seconds_total, which is now
  exactly llm_run_duration_seconds_sum from the same ResultEvent.Duration.
- Nits: dropped the unreachable minRefineTimeout branch; ParseInt(.., 64)
  instead of platform-width Atoi so the overflow row is architecture-
  independent; corrected the preview route to /api/v1/...; unset row in
  the parse table now pins against an ambient REFINE_TIMEOUT; stale test
  doc comment fixed; added a row asserting 723s is expressible.

Verification:
  CGO_LDFLAGS=-L/home/mlamp/.local/lib go test -race -count=1 ./...  PASS
  CGO_LDFLAGS=-L/home/mlamp/.local/lib go vet ./...                  PASS
  git diff --check                                                   PASS

Refs Mininglamp-OSS#231, Mininglamp-OSS#220
@wanyiwang06

Copy link
Copy Markdown
Contributor Author

Both P1s were real and both were mine — pushed da8e819. They're the same defect twice: the revert in 33a40bb changed the runtime semantics, and I updated the prose around it without re-deriving what the new semantics actually imply.

P1 (@Jerry-Xin) — stale sizing formula

2 * LLM_TIMEOUT + backoff described the reverted behaviour, where the guard abandoned the primary after one retry. With the guard unarmed, Run gives the primary all 3 attempts, a hanging attempt is cut by http.Client.Timeout and classifies RetrySameModel (costing a full LLM_TIMEOUT each), and only a parent-deadline expiry inside an attempt classifies Terminal — at which point Run returns with no fallback attempted.

Corrected in refine_budget.go, the CONFIGURATION.md row and the PR body:

Budget Behaviour
>= (MaxAttempts+1) * LLM_TIMEOUT + backoffs = 723s fallback gets one complete attempt
< MaxAttempts * LLM_TIMEOUT + backoffs = 543s hanging primary eats the budget; Terminal, no fallback

Your point about the 363s trap is what makes this blocking rather than cosmetic: it puts the operator in the second regime while the text promises the first. The comment now records why the old number was wrong, so it doesn't get restored by someone reading the guard code in isolation. The 90s default staying in the unreachable regime is now stated outright rather than implied.

P1 (@yujiawei) — "and tool calls" was false

Confirmed your call-graph walk. CallWithTools does set PerModelTimeout, but the guard also needs a parent deadline, and its only callers are the worker closures over processor.go:739's context.Background(). PathAgentTool goes through callWithPolicyAndModel, which sets no PerModelTimeout at all as of this head. Agent chat is the only live path.

The part I want to name explicitly: the pre-PR sentence was correctly scoped and I broadened it. Someone picking up #220 §2 would have read "tool calls: armed" and skipped a path that needs the aggregate deadline. Now agent chat only, with the exclusion reason per path.

P2s taken in this commit

  • P2-1 — tagged both CallRaw sites with a new PathWorkerNarrow. You're right that this is the same class as document_preview, and worse: post-retrieval narrowing runs on every worker task. Given the histograms, leaving recurring traffic in unknown costs a bucket family for nothing.
  • P2-2 — the row no longer says "total request deadline"; it says the LLM budget, and notes the streaming handlers clear the write deadline. Not fixing the underlying SetWriteDeadline behaviour here, agreed it wants its own issue.
  • P2-3 — HELP now states the series is right-censored at LLM_TIMEOUT: sound for deciding to lower the cap, useless for deciding what raising it would recover. Good catch — that's precisely the direction fix(llm): unify fallback timeout budgets with Worker leases and refine deadlines #220 is likely to want, so a censored P99 read as real would have been actively misleading.
  • P2-4 — the arithmetic now includes outcome (~480 vs 120 series). Fair: the comment was the thing a future reader would use to judge whether one more label is cheap, and it omitted its own second dimension.
  • P2-5 — deprecation note on llm_call_duration_seconds_total. Left in place, marked non-canonical.

Nits

Dropped the unreachable minRefineTimeout branch (you were right, <= 0 already guarantees >= 1s; REFINE_TIMEOUT=0 falling back to the default rather than clamping is the behaviour I want, so removing the branch is the honest fix). Switched to ParseInt(raw, 10, 64) so the overflow row is architecture-independent. Corrected the preview route to /api/v1/... (@Jerry-Xin). The unset row now t.Setenv + os.Unsetenv to pin against an ambient value. Stale test doc comment fixed. Added a row asserting 723s is expressible through the knob, so the documented threshold and the clamp ceiling can't silently drift apart.

Title

Already retitled to feat(obs): run + attempt latency histograms, configurable REFINE_TIMEOUT before this round — thanks for catching that the squash commit would otherwise have asserted the reverted behaviour permanently.

Still open

#220 §2 (the aggregate worker deadline, ~18–27 min worst case against a ~10-min scanner and 20-min lease) remains untouched and is the single most important follow-up — the reverted hunk was the only thing gesturing at it. I'll open a dedicated issue referencing #220 §2 so it can't get lost, since #220 bundles five separate problems.

check-sprint is still red; project-board automation.

@yujiawei yujiawei left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review — PR #232 (octo-smart-summary)

Reviewed at head da8e819, against merge-base eb9e0e3. I checked the branch out and ran locally (go1.26.5):

go build ./...                                                                            OK
go vet ./internal/llmobs/... ./internal/api/handler/... ./internal/service/...
        ./internal/llmfallback/... ./internal/worker/...                                  OK
go test -race -count=1 ./internal/llmobs/... ./internal/llmfallback/...
        ./internal/api/handler/... ./internal/service/...                                 PASS

CI on this head is green except check-sprint (project-board automation, unrelated to the diff).

I also rendered the real exposition output from a scratch test to check the histogram end-to-end rather than trusting the unit assertions:

llm_run_duration_seconds_bucket{path="document_preview",le="300"} 1
llm_run_duration_seconds_bucket{path="document_preview",le="+Inf"} 2
llm_run_duration_seconds_sum{path="document_preview"} 400.1
llm_run_duration_seconds_count{path="document_preview"} 2
llm_call_duration_seconds_total{path="document_preview"} 400.1

The 400s sample reaches +Inf/_sum/_count and no finite bucket, the cumulative counts are right, and the deprecated counter really is byte-identical to the histogram's _sum — which is what the new HELP text claims.

The previous round's blocker is genuinely fixed. The 2 * LLM_TIMEOUT + backoff formula is gone and both its replacements are correct against the source, which I traced rather than took on faith (details in §1). Nothing in this round rises to a blocker.


1. Spec compliance

Result: met.

Stated change Status
llm_run_duration_seconds{path} — whole-Run wall-clock Implemented as described
llm_attempt_duration_seconds{path,outcome} — single attempt Implemented as described; AttemptEvent.Duration was indeed already delivered and discarded
REFINE_TIMEOUT, default unchanged at 90s, clamped [1s, 30m] Implemented; default pinned by a test
PathDocumentPreview on the live preview route Implemented (document_preview.go:318); that route's only CallStream site, verified by grep
PathWorkerNarrow on the worker's post-retrieval narrowing Implemented; verified below
Three CallReduceByPerson* variants tagged Implemented; the "no production caller today" claim still holds — CallReduceByPersonStreamWithModel (internal/worker/meta_processor.go:235) is the only wired one and was already tagged
PerModelTimeout arming reverted, replaced by recorded reasoning Implemented (internal/service/llm.go:270-286, :412-414)
CONFIGURATION.md rows Implemented

No missing work, no scope violations. Behaviour at defaults is unchanged: with REFINE_TIMEOUT unset, refineTimeout() returns defaultRefineTimeout and all four handlers build the same 90s context they built before.

Claims I verified rather than accepted

The 723s / 543s sizing formulas are correct. With PerModelTimeout unset, the guard at internal/llmfallback/fallback.go:306 (if hasNext && cfg.PerModelTimeout > 0) is unreachable, so runModel spends the full MaxAttempts budget. A hanging attempt is cut by http.Client.Timeout (internal/service/llm.go:89, single client shared by streaming and non-streaming) and internal/service/llm.go:317-322 classifies it RetrySameModel because the parent context is still alive — so it costs a full LLM_TIMEOUT and the loop continues. Default backoffs are backoff(1)+backoff(2) = 1s+2s = 3s. Primary exhaustion is therefore 3*180+3 = 543s, and one complete fallback attempt needs 4*180+3 = 723s. Both numbers check out.

"The early-escalation guard is active on agent chat only" is correct. PerModelTimeout is set in exactly two places: internal/agent/llm.go:101 (PathAgentChat, and internal/agent/runner.go:156 gives that call a real StepTimeout deadline) and internal/service/llm.go:569 (PathToolCall), whose only callers are internal/worker/processor.go:756 and internal/worker/personal_processor.go:707 — both rooted at context.Background() (processor.go:740), no deadline. The agent tool paths (tool_merge_summaries.go:174, tool_narrow_channels.go:58, tool_summarize_chunk.go:508) go through callWithPolicyAndModel, which sets no per-attempt budget. So the sentence is accurate on every branch.

The refine rationale for not arming is correct. With PerModelTimeout=180s and a 90s parent, a fast first failure leaves ~89s, which satisfies remaining > delay && remaining < delay+2*PerModelTimeout (89 < 361) — the guard would fire on every first retry, exactly as the comment says.

The worker path tag lands where the comment claims. Both llmFn closures reach pipeline.ResolveAndFetchMessagesForPersonal (processor.go:798, personal_processor.go:735), and inside it llmFn is consumed at exactly one site, internal/pipeline/fetch.go:991PostRetrievalNarrow. It is not the same closure NarrowByTopicReport takes, so worker_narrow is not silently absorbing channel narrowing. No existing tag is shadowed: CallRawCallcallWithPolicyAndModel sets no Config.Path, so pathFor falls through to the context value.


2. Code quality

Result: Approved.

The histogram is careful work. The boundary search is right — sort.SearchFloat64s is a lower bound, so a sample exactly on a boundary lands in that bucket, which is what le (≤) requires; over-range samples touch no finite bucket but still reach +Inf/_sum/_count; cumulation happens at render time so observe stays O(1) on the update; the write path snapshots under the lock and formats outside it; formatBucket uses the same 'g'/-1 rendering the reference client does. The bucket slice is copied on construction, which is the kind of defence that only looks paranoid until someone sorts the package-level slice elsewhere. No naming collision is introduced: under OpenMetrics normalization llm_call_duration_seconds_totalllm_call_duration_seconds, which does not meet llm_run_duration_seconds.

The tests assert exact cumulative values rather than "a bucket moved", which is the difference between catching an off-by-one and not. refine_budget_test.go covers the two rows that actually matter (wrong-unit and int64-overflow) and asserts the invariant — always a usable positive deadline — on every row, not just the interesting ones. No test in internal/api/handler calls t.Parallel(), so the t.Setenv table carries no flake risk.

The findings below are all non-blocking.

P2-1 — llm_run_duration_seconds cannot resolve the region it is advertised to size

internal/llmobs/metrics.go:161:

var durationBuckets = []float64{0.5, 1, 2, 5, 10, 20, 30, 60, 90, 120, 180, 300}

The HELP text sells this series as the tool for sizing parent budgets:

Use it to size PARENT budgets (REFINE_TIMEOUT, AGENT_STEP_TIMEOUT)

and CONFIGURATION.md sends the operator here to decide whether to raise REFINE_TIMEOUT. But the top finite boundary is 300s, and the parent budgets under discussion live past it:

  • the fallback-reachable refine budget this PR documents is 723s, and REFINE_TIMEOUT accepts up to 1800s;
  • worker runs carry no deadline at all — the PR's own out-of-scope note puts worst-case worker fallback latency at ~18–27 min.

So for path="worker_map" / worker_reduce, and for any refine deployment that takes the PR's own advice and raises the budget, everything interesting collapses into +Inf and histogram_quantile returns the last boundary or +Inf for P95/P99. The right-censoring caveat in the HELP text is attached to llm_attempt_duration_seconds (where it is fine, since LLM_TIMEOUT defaults to 180s < 300s) — llm_run_duration_seconds carries no equivalent warning and is the series with the wider distribution.

Two extra boundaries (say 600, 1800) would cover it. Worth doing in this PR by the same argument the PR makes for the metric name — cheap before dashboards exist. I am not blocking on it: adding boundaries later is backwards-compatible for histogram_quantile (unlike a rename), _sum/_count and the +Inf count remain correct in the meantime, and no existing behaviour is wrong.

P2-2 — the attempt-histogram HELP is wrong for path="tool_call"

internal/llmobs/metrics.go:316:

Use it to size the per-attempt LLM_TIMEOUT; … every attempt is already capped by the current LLM_TIMEOUT

That holds for agent_chat / agent_tool (internal/agent/llm.go:51, built from h.llmTimeout at internal/api/handler/agent_chat.go:181) and for everything on the shared http.Client (internal/service/llm.go:89). It does not hold for tool_call, which caps each attempt with a different knob:

// internal/service/llm.go:602
attemptCtx, cancel := context.WithTimeout(ctx, c.toolCallTimeout)

TOOL_CALL_TIMEOUT defaults to 30s, so llm_attempt_duration_seconds{path="tool_call"} piles up at le="30" and an operator following the HELP text would tune LLM_TIMEOUT from a series that LLM_TIMEOUT does not govern. One clause naming the exception fixes it.

P2-3 — the cardinality arithmetic in the comment no longer matches the code

internal/llmobs/metrics.go:338-341:

// = 8 x 4 x 15 = ~480 series for this family, against 8 x 15 = 120 for
// runDur.

After this PR there are nine Path constants (internal/llmfallback/observer.go:11-26 — the two new ones plus unknown), so the real figures are 9 × 4 × 15 = 540 and 9 × 15 = 135. outcomeLabel (metrics.go:400-413) also has a fifth "unknown" arm, unreachable today but part of the label domain. The comment exists specifically so the next person adding a label sees the true cost, which makes stale arithmetic worth a one-line fix.

P2-4 — CONFIGURATION.md is looser than the source comment it summarises

CONFIGURATION.md:21:

a fallback is reachable only at (MaxAttempts+1) * LLM_TIMEOUT + backoffs (723s at defaults)

refine_budget.go:30-32 is precise about this — it distinguishes "fallback gets one complete attempt" (≥723s) from "fallback cannot start at all" (<543s), correctly leaving the 543–723s band as a partial attempt. "Reachable only at 723s" flattens that: between 543s and 723s a fallback is reached, just with a truncated budget, and a fast-answering fallback can still succeed there.

This errs on the safe side — an operator following it over-provisions rather than under-provisions, the opposite of the defect the last round blocked on — so it is a wording fix, not a blocker. Matching the doc row to the source comment's two-regime phrasing would close it.

P2-5 — deprecating a live metric is not mentioned in the description

internal/llmobs/metrics.go:296 rewrites the HELP of the existing counter to open with DEPRECATED, prefer llm_run_duration_seconds. The reasoning is sound and I verified the underlying claim (the counter and the histogram's _sum are fed from the same ResultEvent.Duration and agree to the last digit in the dump above). But this is an operator-visible deprecation of an existing published metric — it shows up in the scrape and in every metric browser — and the "Change" section does not mention it. Worth a line in the PR description so whoever owns the dashboards sees it, especially since no removal timeline is stated.

Nits

  • CONFIGURATION.md:21, guard scope: the guard also requires a next model (fallback.go:306, hasNext), so with LLM_FALLBACK_MODELS empty — the default — it is inert even on agent chat. Implicit from the row it lives in, but a parenthetical would make it exact.
  • refine_budget.go:80: one process-wide sync.Once is shared by the reject and clamp branches, so a second, different misconfiguration is silent. Fine for a value read from a fixed environment; noting it because refineTimeout() re-reads the env per request, which invites the assumption that it re-reports too.
  • The test helper parseExposition validates structure, not Prometheus grammar — it would accept duplicate labels or misplaced braces. Pre-existing, and out of scope here, but a promtool check metrics step over the rendered output would be a cheap real guard for a hand-written renderer.

3. Verdict

APPROVED.

No P0/P1. Behaviour at defaults is unchanged, the histogram math is verified correct against rendered output rather than only against its own assertions, and every load-bearing claim in the new comments and docs — the 723s/543s formulas, the guard-scope statement, the path-tag routing, the no-production-caller claim — traces cleanly to the source. The five P2s are resolution and documentation-precision items; P2-1 and P2-2 are the two I would most like to see folded in, either here or as an immediate follow-up.

4. Coverage — what I did not check

  • No live Prometheus or promtool validation of the rendered exposition; correctness is argued from the format spec and an eyeballed dump, not from a real scraper.
  • No load or GC-pressure measurement of the per-scrape snapshot copying in histogramVec.write; fine at the current label counts, unverified at scale.
  • No runtime exercise of the four refine handlers with a non-default REFINE_TIMEOUTrefineTimeout() is unit-tested, but the handler wiring is verified by reading, not by driving the endpoints.
  • No cross-check against the other open PRs on this repo for post-merge semantic conflict; none of them appear to touch internal/llmobs, internal/llmfallback, or internal/service/llm.go, but I did not build any merged combination.
  • Sub-0.5s resolution is absent from both histograms by construction; I did not assess whether any path's real distribution sits low enough for that to matter in practice.

@Jerry-Xin Jerry-Xin left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review — PR #232 (octo-smart-summary) — re-review at da8e8199

Verdict: APPROVE. Re-review at head da8e8199838d, single new commit da8e819 ("docs(obs): correct the refine budget formula and the guard-scope claim") vs previously reviewed head 33a40bb0. Verified locally: byte-level delta diff, independent recomputation of the budget arithmetic from code constants, a full call-graph walk of the guard arming sites, and go build / go vet / go test -race -count=1 on all four touched packages (all green).

1. Prior-round blockers and peer findings — all fixed

Formula mismatch (my prior 🔴). Fixed in all three places, and I recomputed the arithmetic from code rather than trusting the new text:

  • MaxAttempts: 3 hardcoded at internal/service/llm.go:289, :417, :570 and internal/agent/llm.go:102
  • LLM_TIMEOUT default 180 (internal/config/config.go:210)
  • Backoff 2^(attempt-1) seconds (internal/llmfallback/fallback.go:109-114): 1s + 2s = 3s across the 3 primary attempts
  • Guard-less worst case: primary consumes 3×180+3 = 543s; one complete fallback attempt needs 543+180 = 723s

refine_budget.go:28-37, both CONFIGURATION.md rows (LLM_FALLBACK_MODELS, REFINE_TIMEOUT), and the PR body (723s/543s table) now all state this correctly, including the second regime (< 543s the run ends Terminal with no fallback attempt at all). The old 2*LLM_TIMEOUT + backoff survives only as an explicit historical note. ✓

Guard-scope claim (my prior 🟡; yujiwei's P1 🔴). Fixed. CONFIGURATION.md now says the guard is "active on agent chat only", with a per-exclusion reason, each byte-verified:

  • Agent chat: PerModelTimeout at internal/agent/llm.go:101 + a real parent deadline (context.WithTimeout(ctx, r.policy.StepTimeout) at internal/agent/runner.go:156) → guard live ✓
  • CallWithTools sets PerModelTimeout: c.toolCallTimeout (internal/service/llm.go:570), but every production caller is the worker pipeline rooted at context.Background() (internal/worker/processor.go:740; personal pipeline likewise) with no deadline added anywhere down the chain → ctx.Deadline() returns ok==false, guard cannot fire ✓
  • Call/CallStream deliberately leave PerModelTimeout unset (internal/service/llm.go:270-286) → inert on worker Map/Reduce and API refine ✓

Observer path comment (my 🟡). Fixed: /api/v1/summaries/document/preview now matches the mounted group (internal/api/router/router.go:76 + :177). ✓

Unreachable branch (my 🟡). Fixed: the d < minRefineTimeout branch and the minRefineTimeout constant are removed. Confirmed genuinely unreachable — secs <= 0 is rejected first, so secs >= 1 and d >= 1s always. ✓

yujiwei's title 🔴. Fixed: PR title is now "feat(obs): run + attempt latency histograms, configurable REFINE_TIMEOUT" — the "arm the guard" wording is gone. ✓

yujiwei's remaining P2s and nits (all marked optional/follow-up, all addressed anyway). P2-1 CallRaw tagging → done via the new PathWorkerNarrow + WithPath on both worker closures (the exact worker_narrow name the review suggested); P2-2 "Total request deadline" → now "LLM budget … does not bound the HTTP request", correct given SetWriteDeadline(time.Time{}) at edit.go:429 / personal_refine.go:321; P2-3 right-censoring → attempt HELP now says "CENSORED ON THE RIGHT"; P2-4 cardinality reasoning → arithmetic comment added; P2-5 duplicate counter → HELP now starts "DEPRECATED, prefer llm_run_duration_seconds"; stale metrics_test.go comment and the ambient-REFINE_TIMEOUT test defense (t.Setenv+os.Unsetenv) → done.

2. Delta hunk inventory — the commit is NOT docs-only (non-blocking)

The commit is titled docs(obs) but contains three executable changes; each verified safe, and the first two implement prior-round review asks:

Hunk Class Assessment
refine_budget.go comment expansion comment-only ✓ accurate
refine_budget.go AtoiParseInt(raw,10,64) + minRefineTimeout clamp removal executable Safe: identical on 64-bit; on 32-bit builds int64-overflow values now clamp instead of defaulting (architecture-independent parse table, as the prior nit requested); removed floor clamp was unreachable
refine_budget_test.go (os import, setenv/unsetenv rework, 723 row, ceiling assertion) test-only
llmfallback/observer.go route comment comment-only
llmfallback/observer.go new PathWorkerNarrow const executable Safe: label-only; no switch/control flow branches on Path anywhere
llmobs/metrics.go HELP strings runtime string (exposition text only, no samples)
worker/processor.go / personal_processor.go WithPath(ctx, PathWorkerNarrow) on the two CallRaw sites executable Safe: metric attribution moves unknownworker_narrow; implements prior-round P2-1 verbatim

🟡 Non-blocking note: these runtime changes (a new metric label on every path-labelled family, plus parse hardening) ship under a docs(...) commit title. They are benign and reviewer-requested, and a squash merge preserves the (accurate) PR title, so this is not a merge blocker — but if this lands via merge/rebase, please amend the commit message first so git log doesn't hide a metric-label change behind a docs title.

3. Tests and CI

  • go build ./internal/..., go vet ./internal/...: clean (the cmd/ link step needs libtokenizers, as in CI)
  • go test -race -count=1: internal/api/handler ok (35s), internal/worker ok, internal/llmobs ok, internal/llmfallback ok
  • CI at da8e8199: Build / Lint / Test / Test (race, cgo) / Vet / dependency-review / osv-scan / gitleaks / pr-title-lint all pass; check-sprint fails with "No linked issue found — add a 'Closes #' reference" (process gate, not in the ruleset's required-check list, but please fix it); code-review pending.

Merge gate (ruleset "main branch protection", id 16278120): requires 2 approvals + code-owner review + last-push approval + all review threads resolved + the code-review status check + linear history. mergeable=true (no conflicts); the blocked state is purely the approval/thread/check requirements above.

Cross-PR: no symbol collisions — this head's new identifiers live in llmfallback/llmobs, which no other open PR touches (#233 only overlaps router.go, untouched here). #209/#214 overlap internal/worker/personal_processor.go textually but in disjoint regions (finalize / citation cap vs the llmFn closure) — ordinary merge-order resolution, nothing to do now.

4. Remaining nits (non-blocking)

  1. The new cardinality comment in internal/llmobs/metrics.go says 8 x 4 x 15 = ~480 series for attemptDur — but this same commit adds the 9th path (worker_narrow), so it is now 9 x 4 x 15 = ~540 (and 9 x 15 = 135 for runDur). The conclusion ("affordable; a third dimension likely is not") is unchanged; please correct the numbers next time the file is touched.
  2. 723s is the idealized arithmetic floor (request setup/classification overhead is small but non-zero); operators sizing REFINE_TIMEOUT should leave some headroom rather than dialling exactly 723. Optional wording polish.
  3. check-sprint is red: add the Closes #<issue> linkage to the PR body (or have a maintainer assign the sprint on the board).

Jerry-Xin
Jerry-Xin previously approved these changes Aug 27, 2026

@Jerry-Xin Jerry-Xin left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

APPROVE on da8e819.

Re-review of the fix commit docs(obs): correct the refine budget formula and the guard-scope claim, byte-verified against the prior head.

Prior blocking findings — all resolved

  • Refine budget formula (prior 🔴): refine_budget.go now documents the runner's actual retry semantics: the primary receives all MaxAttempts (3) attempts before any fallback is tried, and the early-escalation guard is deliberately not armed on refine. The sizing regimes are now correct — a fallback reaches one complete attempt only when REFINE_TIMEOUT >= (MaxAttempts+1)*LLM_TIMEOUT + backoffs = 723s at defaults, and below MaxAttempts*LLM_TIMEOUT + backoffs = 543s a hanging primary consumes the whole budget and the run ends Terminal with no fallback attempt at all. The old 2*LLM_TIMEOUT + backoff figure is explicitly called out as valid only under the reverted budget-guard behaviour. CONFIGURATION.md (both the LLM_FALLBACK_MODEL and REFINE_TIMEOUT rows) carries the same corrected arithmetic, plus the pre-existing note that on the two streaming refine handlers this bounds the LLM run, not the HTTP request.
  • Guard-scope claim (prior 🟡): the docs now state the guard is active on agent chat only, with the accurate reasoning — tool calls do set a per-attempt budget (internal/service/llm.go sets PerModelTimeout for tool calls), but their callers run in the worker pipeline whose context carries no deadline; worker Map/Reduce sets neither; API refine deliberately does not arm it. Verified against the call sites.
  • Path comment (prior 🟡): PathDocumentPreview comment corrected to the full /api/v1/... route.
  • PR title: now reflects the PR's actual content (run + attempt latency histograms, configurable REFINE_TIMEOUT) instead of claiming the guard was armed.

Note: this commit contains code changes despite the docs(obs): prefix

All of them are safe and tested, but the label undersells the diff:

  • refineTimeout() drops the minRefineTimeout floor clamp — correct: the secs <= 0 rejection already guarantees any accepted value is ≥ 1s, so the floor branch was unreachable.
  • strconv.Atoistrconv.ParseInt(raw, 10, 64): removes platform-width dependence (on 32-bit builds huge values previously took the ErrRange path instead of the clamp).
  • New PathWorkerNarrow metric path, wired identically in both worker processors for the post-retrieval narrowing call, moving recurring traffic out of path="unknown". Bounded label set; cardinality arithmetic is documented at the observe site.
  • refine_budget_test.go updated accordingly (includes the documented 723s budget case).

Non-blocking (🟡)

  • The commit message says docs(obs): while the diff contains the code changes above — harmless, but the history label is misleading.
  • The REFINE_TIMEOUT row in CONFIGURATION.md still says values are "clamped to [1s, 30m]"; after the floor-clamp removal the lower bound is enforced by the ≤0 rejection (falls back to the default) rather than a clamp. Accepted range is unchanged; the mechanism wording is slightly stale.

Verification

  • Full hunk inventory of 33a40bb0..da8e8199 reviewed line by line; no unintended logic changes.
  • go build, go vet, and go test -race green for internal/llmobs and internal/llmfallback locally; CI (Build / Lint / Test / Vet / race) all pass on this head.
  • No symbol collisions with other open PRs in the touched packages.

@Jerry-Xin
Jerry-Xin dismissed their stale review August 27, 2026 11:14

Duplicate of 5040090701 (double-post during remediation); superseding copy dismissed.

@mochashanyao mochashanyao left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[Octo-Q · automated review]

Verdict: Approve — no blocking findings; notes below (data-flow traced).


Reviewer: Octo-Q (automated review)
PR: Mininglamp-OSS/octo-smart-summary #232 — feat(obs): run + attempt latency histograms, configurable REFINE_TIMEOUT
Head: da8e8199838d0af56f93c4dca609d16e95f1298aMerge-base: eb9e0e3 (= origin/main) | Scope: 12 files +688/-25(与 GitHub PR diff 完全一致)
轮次: 第 2 轮(上轮审 33a40bb,APPROVED;本轮新增 commit da8e819 后复审)
运行说明: 本环境 skill 安装无 GLM 腿脚本(无 glm_review.py/merge_reviews.py),按降级策略单腿产出,/tmp/review.final.json 即最终 findings 源。

1. 验证结论

可合入。 全部 12 个变更文件逐一回溯,零 P0/P1/P2,仅 1 条 cosmetic Nit。静态分析(未在本环境跑 build/test;按 skill 纪律不在 checkout 内执行构建)。

  • ✅ 直方图数学正确:sort.SearchFloat64s 下界搜索 ⇒ le 边界包含语义正确;越界样本仍计入 _sum/_count/+Inf;负值钳 0;render 在锁内快照、写出时累加(internal/llmobs/metrics.go:191-268
  • ✅ 事件数据流完整:ObserveResult 全部 5 个 emit 点 + ObserveAttempt 唯一 emit 点均填 Duration = time.Since(...)internal/llmfallback/fallback.go:136/147/172/183/202/324),两个直方图不存在零值/缺值灌入
  • ✅ 四个 refine 入口全部换用 refineTimeout()edit.go:277/444personal_refine.go:110/336),无遗留硬编码 90s(全仓 grep 仅剩默认值常量)
  • REFINE_TIMEOUT 解析安全:ParseInt(_,10,64) + 乘前溢出检查 + <=0 拒绝 + 30m 上限(≥ 文档最坏 723s),每类畸形输入均降级为默认值且 once-per-process 告警(internal/api/handler/refine_budget.go:96-118
  • ✅ 文档断言与代码逐条核对一致(723s/543s 公式、"guard 仅 agent chat 生效",见下 §5)

2. 发现问题

无 P0/P1/P2。

Nit — 测试用例名过期引用 Atoiinternal/api/handler/refine_budget_test.go:33):用例名 "float is rejected by Atoi",实现实际用 strconv.ParseInt(raw, 10, 64)refine_budget.go:106 注释明确说明选 64 位显式宽度以避免 32 位平台 Atoi 行为差异)。仅命名误导,改名即可。

  • diff-scope 三问:本 PR 新引入(测试文件全新);非既有行为;不触碰任何运行时路径 ⇒ Nit,不影响 verdict(R4:仅 Nit ⇒ APPROVE)。

3. 建议

  • (可选)顺手把上述测试名改为 "float is rejected by ParseInt"。
  • 无需其他改动;#220 后续按 llm_run_duration_seconds 实测 P95/P99 再决定是否上调 REFINE_TIMEOUT 默认值,当前保持 90s 的决策有测试守护(TestRefineTimeout_DefaultIsUnchanged),合理。

4. 额外发现

  • callSecsllm_call_duration_seconds_total)与 runDur._sum 同源(均在 ObserveResult 由同一 e.Duration 喂入,metrics.go:378-382),help 文本已标 DEPRECATED,dashboard 兼容期内不会分叉。
  • 新命名 llm_run_duration_seconds 刻意避开 OpenMetrics 家族名归一化与既有 llm_call_duration_seconds_total 冲突(metrics.go:298-304 注释),判断正确。
  • attemptDur 帮助文本新增 "CENSORED ON THE RIGHT" 说明(attempt 被 LLM_TIMEOUT 截尾,顶桶是堆积不是尾部)——对运维解读是正确且必要的提示。

5. 数据流回溯(逐消费点 → 上游来源)

消费点 上游来源 是否真流到
runDur.observe (metrics.go:382) ResultEvent.Durationtime.Since(start),Run 的全部 5 个退出路径均填
attemptDur.observe (metrics.go:344) AttemptEvent.Durationtime.Since(attemptStart),runModel 每次 attempt 后唯一 emit(fallback.go:324-327),含 Success/Terminal/TryNextModel/RetrySameModel 全部分支
path 标签 cfg.pathFor(ctx):Config.Path 在 diff 涉及的全部 Run 调用点均未设置 ⇒ ctx 标签生效(context.go:59-62)。WithPath 注入点:worker narrow 两处 CallRaw(→CallcallWithPolicyAndModelRun)、document_preview CallStream(→callStreamWithModelRun)、reduce-by-person 三个入口(→callDisclosingTerminalReduceWithModel/callStreamWithTruncationNoticeRun ✅ 每条链逐跳确认
refineTimeout() 返回值 四个调用点全部喂给 context.WithTimeout 作为父截止时间
文档 723s/543s 公式 runModel 语义:primary 独占 MaxAttempts=3 次(fallback.go:298 循环);挂起 attempt 被 http.Client.Timeout 切断 ⇒ RetrySameModel 续跑(service/llm.go:317-322:仅 ctx.Err()!=nil 才 Terminal);默认 backoff 1s+2s=3s ⇒ 543s 后 fallback 才可能启动,723s 才够 fallback 完整一次 ✅ 公式与代码一致
"guard 仅 agent chat 生效" PerModelTimeout>0 且 ctx 带 deadline 才激活(fallback.go:306-315)。PerModelTimeout 仅两处:service/llm.go:569(CallWithTools,调用方 worker 两处理器均 context.Background() 无 deadline ⇒ 惰性)+ agent/llm.go:101(agent chat,runner.go:156 StepTimeout deadline ⇒ 激活)。agent 工具走 CallStrict/Call 链,不设 PerModelTimeout
worker narrow "每个任务都跑" executePipelineprocessor.go:763-769)与 executePersonalPipelinepersonal_processor.go:716-722)的 PostRetrievalNarrow llmFn;全仓 CallRaw 仅这两处,无漏标兄弟 ✅(C1 成对核验)

6. 盲点 checklist

  • C1 双路径 parity — CLEAR:4 个 refine 入口全换 refineTimeout();2 个 CallRaw 全标 PathWorkerNarrow;4 个 reduce-by-person 变体全标 PathWorkerReduce(第 4 个变体 base 已有标签);无遗漏兄弟。
  • C2 control-flow ordering / 复用 — CLEAR:refineTimeout() 为纯函数、四处复用行为一致;guard 条件在嵌套复用下不会被二次触发(仅 runModel backoff 前检查一次/轮)。无正则/escape 类控件改动。
  • C3 授权边界 — N/A:本 PR 无权限/endpoint 暴露变更(文档预览路由为既有,仅加 ctx 标签)。
  • C4 授权生命周期/级联 — N/A:同上,无鉴权改动。
  • C5 build/运行期 — CLEAR:无构建/打包改动;/metrics 暴露面为既有(PR#219 引入,llmobs.Install 双 cmd 装配),本 PR 仅新增两个家族进 WritePrometheus
  • C6 治理/文档自洽 — CLEAR:CONFIGURATION.md 新增 REFINE_TIMEOUT 行与 LLM_FALLBACK_MODELS 行修订互相一致,且与代码行为逐条核对(默认 90、上限 30m、拒绝/钳制均 once 告警);"clamped to [1s, 30m]" 表述后半句已明确非正值回落默认,不构成误导。

7. 跨轮 blocker 复检(R6)

上轮(automated review,head 33a40bb)verdict=APPROVED,无 blocker,仅 2 条 Nit:

  • Nit①(PR 标题/guard-scope 声明与实现不符)→ 已修:标题已改为 "run + attempt latency histograms, configurable REFINE_TIMEOUT"(gh pr view 确认);guard-scope 文档改为 "agent chat only" 并给出 tool-call 调用方无 deadline 的理由(§5 核验属实)。
  • Nit②(minRefineTimeout 下界分支不可达)→ 已修:da8e819 删除 minRefineTimeout 常量,注释说明 <=0 拒绝已保证 ≥1s(refine_budget.go:75-77),测试同步更新。
  • da8e819 相对 33a40bb新增行为(非仅文档):PathWorkerNarrow 常量 + 两个 worker 标注点 + 测试抗环境污染加固(t.Setenv+Unsetenv)——本轮已独立核验(§5)。

Code Review — PR #232 (octo-smart-summary)

Summary

This PR adds two hand-rolled cumulative latency histograms to the llmfallback observability set — llm_run_duration_seconds (whole-run wall clock by path) and llm_attempt_duration_seconds (single-attempt wall clock by path and classified outcome) — deprecates the mean-only llm_call_duration_seconds_total counter, and replaces the four hardcoded 90s refine budgets with a REFINE_TIMEOUT env knob (default 90s, ceiling 30m). It also attributes previously-unlabelled traffic: the document-preview endpoint and the worker's post-retrieval narrow calls get their own path labels, and the three remaining reduce-by-person entry points are tagged. The follow-up commit corrects the documented fallback-reachability math to the runner's real retry semantics (723s at defaults) and narrows the guard-scope claim to "agent chat only".

Verification

Static analysis only at head da8e8199; build and tests not executed in this environment.

  • Histogram mathsort.SearchFloat64s gives inclusive-le boundary semantics; out-of-range samples still land in _sum/_count/+Inf; negatives clamp to 0; rendering snapshots under the lock and cumulates buckets at write time (internal/llmobs/metrics.go:191).
  • Event data flow — all five ObserveResult emit sites and the single ObserveAttempt site fill Duration = time.Since(...) (internal/llmfallback/fallback.go:136), so neither histogram can observe a missing duration.
  • Path wiringConfig.Path is unset on every Run call site touched here, so the ctx tag wins: CallRawCall (worker narrow), the CallStream chain (document preview), and CallReduceByPerson* (reduce). Both CallRaw sites are tagged; no untagged sibling remains.
  • REFINE_TIMEOUT safetyParseInt(...,10,64) plus a pre-multiply overflow check plus <= 0 rejection; the 30m ceiling clears the documented worst-case 723s budget. All four refine call sites consume refineTimeout(); no leftover hardcoded 90s (internal/api/handler/refine_budget.go:96).
  • Doc claims — the 723s/543s formulas and "guard active on agent chat only" hold against runModel: PerModelTimeout is set only at internal/service/llm.go:569 (tool calls; worker callers carry no deadline) and internal/agent/llm.go:101 (agent chat under the StepTimeout deadline).

Findings

No P0/P1/P2 issues; one nit below.

Nit — Stale test-case name references Atoi (internal/api/handler/refine_budget_test.go:33)

The row is named "float is rejected by Atoi", but the implementation parses with strconv.ParseInt(raw, 10, 64) — deliberately, per internal/api/handler/refine_budget.go:106, to keep the width explicit on 32-bit builds. Cosmetic; rename so a future edit doesn't assume platform-width Atoi semantics.

Things I checked that are fine

  • OpenMetrics family naming: llm_run_duration_seconds avoids the _total-normalization clash with the retained counter; le is appended only on _bucket lines; label values escape through the existing helper.
  • Cardinality is bounded and documented (closed path enum × 4 outcomes × 15 series); attemptDur deliberately drops model/position.
  • warn-once is shared across rejection/clamp classes by design, matching the documented "logged once per process".
  • The streaming refine handlers' write-deadline caveat predates this knob and is now documented, not introduced.
  • Prior-round nits (stale title/guard-scope claim, unreachable minRefineTimeout clamp) are both resolved at this head.

Verdict: APPROVED

The observability additions are exact where it matters (boundary semantics, duration sourcing, label cardinality), and the new timeout knob degrades safely on every malformed-input class with the runner's retry semantics correctly documented. The nit is cosmetic and non-blocking.


[Octo-Q] verdict: APPROVE — 零 P0/P1/P2;数据流全链回溯无断点,文档断言与代码逐条一致,上轮 2 条 Nit 均已修复,仅 1 条 cosmetic Nit(测试用例名)。建议终审放行。

@yujiawei

Copy link
Copy Markdown
Contributor

Addendum to my review above — one more nit I missed, verdict unchanged (still APPROVED).

internal/api/handler/refine_budget_test.go:33 — the table row is named "float is rejected by Atoi", but the implementation deliberately does not use Atoi:

// internal/api/handler/refine_budget.go:97
// ParseInt with an explicit 64-bit width rather than Atoi: Atoi returns a
// platform-width int, so on a 32-bit build a value like 9223372036854775807
// would take the ErrRange path instead of being clamped, making the
// behaviour architecture-dependent.
secs, err := strconv.ParseInt(raw, 10, 64)

So the row names the exact function the code was written to avoid, and the reasoning for avoiding it lives four lines above the call. Cosmetic, but worth renaming to ParseInt while you're in here — a future editor reading the test name could reasonably conclude platform-width semantics are fine and undo the int64 width.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

size/XL PR size: XL

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants