Skip to content

Plan-path task_result always reports secs: 0.0 #96

Description

@wseaton

Every plan-path task_result goes out with secs: 0.0. task_result_event (crucible/src/plan/cli.rs:362) hardcodes it because plan::exec::TaskResult (crucible/src/plan/exec.rs:141) carries status/attempts/cost_usd/output/note/fanout and no timing, and Attempt (exec.rs:47) is outcome + cost_usd. The only clock in the executor is the plan-wide wall_clock ceiling (exec.rs:274). The secs field on the wire event is populated by the measure-DAG emitter and defaulted by everyone else.

Downstream is faithful to the lie: the controller stores 0.0 in run_task_results.secs, and 0.0 is a number, so the run page renders 0.0s per task and every duration bar collapses to its floor. It cannot tell "took 0s" from "not measured" (it is patched for now to treat a run where nothing is positive as untimed).

Plan

Time at the runner boundary, not in the executor. Under run_many a batch runs concurrently, so the executor only sees batch wall time; the runner is the one thing that knows per-item elapsed.

  1. Attempt gains secs: f64. Add a constructor that takes the Instant the runner started at so the ~50 construction sites (most are tests, or undispatched paths where 0.0 is honest) do not each open a stopwatch. The real runners are plan/runner.rs:26, plan/harness.rs:138,208, loop_graph.rs:447,452,705,747,1187,1224; each measures around the actual work. The trait-default run_many (exec.rs:81) inherits it by delegating to run.
  2. exec::TaskResult gains secs: f64, summed across retries in run_with_retries (exec.rs:787) and per-index in run_batch_with_retries (exec.rs:883), the same way cost_usd accumulates. fold_instances (exec.rs:697) sums instance secs; undispatched and reduce_top_k stay 0.0.
  3. task_result_event passes r.secs instead of 0.0. The three loop_graph.rs callers (133, 375, 886) and the plan run caller (cli.rs:686) need nothing.
  4. SessionEvent::TaskResult.secs doc gets the plan-path semantics: wall clock across all attempts of that report, 0.0 only for a task that never dispatched.

Tests

  • Executor: a TaskRunner test double that sleeps (or returns a fixed secs) proves run_with_retries sums across transport retries and run_batch_with_retries keeps per-item figures rather than the batch's wall time.
  • task_result_event round-trip (cli.rs:1070) asserts secs survives encode/decode with a non-zero value.
  • fold_instances sums instances.
  • The undispatched paths (blocked, truncated) still report 0.0.

Rollout

Pin bump in crucible-domains (core-pin.toml + the crucible/crucible-contract/forge git revs in crucible-controller/Cargo.toml) and a loop image rebuild. The controller's ingest (ingest.rs) and run_task_results.secs already carry f64; no migration. Once the pin lands, drop the controller UI's "all zeros means untimed" normalization (ui/src/pages/taskGraph.ts timedResults).

Activity

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions