Skip to content

Parallel branch stages permanently lose inference/tool time (active_time_ms always 0) #644

Description

@brynary

Parallel branch stages report inference_time_ms: 0, tool_time_ms: 0, and active_time_ms: 0 permanently — not just while running, but after the branch and the whole run have completed. Only wall_time_ms survives.

Any workflow that does real agent or command work inside a parallel node under-reports its active time by exactly that work, in the run header's Duration popover, in GET /runs/{id}/billing, and in the aggregate billing rollup.

Cause

The branch's Outcome carries a full timing breakdown, and it is in scope at the emit site — outcome.status is read two lines below — but outcome.timing is never passed through.

lib/components/fabro-workflow/src/handler/parallel.rs:270-277:

emit_branch_completed(
    &branch_services.run.emitter,
    &branch_scope,
    group_id.clone(),
    parallel_branch_id.clone(),
    branch_index,
    millis_u64(branch_start.elapsed()),   // wall only
    outcome.status,                        // outcome.timing dropped here
);

ParallelBranchCompletedProps therefore carries only duration_ms, and the projection stores it as wall-only — lib/components/fabro-store/src/run_state.rs:628:

stage.timing = Some(fabro_types::StageTiming::wall_only(props.duration_ms));

A parallel branch never emits its own stage.completed (see the comment above that line), so this is the only place the branch's timing is ever written. The breakdown is lost with it.

Fix shape

  1. Add timing: Option<StageTiming> to ParallelBranchCompletedProps (#[serde(default)] so historical events still deserialize).
  2. Thread outcome.timing through emit_branch_completed (parallel.rs:458). Three call sites:
    • :270 — normal completion; outcome.timing is available.
    • :288 — panic path; failed_branch_result builds the outcome, so pass whatever it carries (likely None).
    • :330 — cancellation path; same treatment.
  3. In run_state.rs:628, use StageTiming::new(props.duration_ms, inference, tool) when timing is present, falling back to wall_only for legacy events.

Notes

  • Read docs/internal/events-strategy.md before changing the event props, per CLAUDE.md.
  • ParallelBranchCompletedProps flows through lib/components/fabro-workflow/src/event/convert.rs:393-398.
  • Worth a test that a parallel branch running an agent node reports non-zero active_time_ms after completion, and that a legacy event without timing still projects as wall-only.

Context

Found while investigating a separate bug: active_time_ms is not accumulated for in-flight stages either, so a running stage contributes zero to the run rollup. That one is being fixed separately in the run projection (live_run_timing / a new StageProjection::live_timing). This issue is orthogonal — it is a data-loss bug in the finalized value, not a live-ticking gap — and was split out deliberately.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions