Skip to content

fix(productivity-review): measure long_active_duration from actual dispatch (BLO-22061) - #1052

Closed
allyblockcast[bot] wants to merge 1 commit into
masterfrom
cto/blo-22061-productivity-active-duration
Closed

fix(productivity-review): measure long_active_duration from actual dispatch (BLO-22061)#1052
allyblockcast[bot] wants to merge 1 commit into
masterfrom
cto/blo-22061-productivity-active-duration

Conversation

@allyblockcast

@allyblockcast allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown

Fixes the long_active_duration false positives reported in BLO-22061, filed by the CEO from adjudicating BLO-22059.

Root cause (differs from the filed hypothesis — see below)

The issue reported that the generator "measures an active episode from a run's creation time." It does not. The clock is:

const activeStartedAt = sourceIssue.startedAt ?? sourceIssue.executionLockedAt ?? null;

issues.started_at is stamped at checkout and then deliberately preserved across every subsequent run of the same episode (checkoutIssue: "preserves the original startedAt when the issue is already in_progress"). So it measures how long the issue has been in_progress, not how long any run has executed.

BLO-19848 added a clamp for parked holders, but nonLiveExecutionHoldSince short-circuits on if (!issue.executionRunId) return null — and an un-dispatched run is exactly the case where the lock tends to be empty, since lazy locking only stamps the pointer at claim time and sweepStaleIssueLocks may have released a stale pre-claim lock. The clamp disengaged precisely when it was needed and elapsed reverted to full wall-clock.

Verified against the reproducing case: BLO-3606's alarm reported "6h 7m", and 06:19:05Z − issues.startedAt 00:11:13.811Z = 6h 7m 52s. Exact match.

Changes

  • undispatchedQueueHold() — an issue whose only execution evidence is a queued/scheduled_retry run with a null started_at has executed for zero seconds. elapsedMs becomes null, so long_active_duration cannot fire on queue latency. The excluded wall-clock is reported as its own labelled evidence bucket rather than silently dropped.
  • liveSegmentStartedAt() now also anchors on the holder's own started_at, so a running holder's episode begins when it was dispatched.
  • Unowned issues are untouched — no holder and no queued run keeps full wall-clock accounting. That is a genuinely abandoned in_progress issue and must keep firing.
  • Progress-signal grace band — the lookback is now longActiveMs + 30m instead of a hard 6h edge coincident with the trigger. The reproducing case missed the window by 75 seconds. The rendered block now also states whether the signal was found and when.
  • Children-driven trackers — an issue with non-terminal children and no monitor now reports its issue_children_completed wake path instead of being described as "no monitor armed / unattended".

Tests

server/src/__tests__/productivity-review-service.test.ts — 6 new cases, all three named in the issue's verifying signal plus three guarding against over-correction:

case expectation
8h queued holder, never dispatched no trigger
8h genuinely running holder still triggers
8h queued run with no execution lock (the reproducing shape) no trigger
8h abandoned issue, no execution path at all still triggers
Next action: comment at threshold + 2m counts as a progress signal
tracker with children in flight names the children-driven wake path

100 passed (100) on the full suite (94 pre-existing + 6 new); attention-service, ac-policy-sweep, issue-blocker-attention also green (49 passed). Server typecheck clean.

Backfill measurement — read this before merging

Re-running the classification over the 34 open long_active_duration reviews:

  • 12 of 34 (35%) have an un-dispatched holder and would not re-fire.
  • 22 of 34 (65%) have no execution holder at all and still fire, unchanged.

This partially contradicts the filed hypothesis. The issue predicted "15 of 19 observable cases show the most-recent run as queued", implying most alarms are queue-latency artifacts. On the full backlog the plurality mode is instead no execution holder whatsoever.

Two further caveats, stated because they bound what this PR can claim:

  1. The 12 FP verdicts rest on holder state read now, not at alarm time — in all 12 the lock was acquired 5–20h after the alarm fired. So the honest reading is "12 of 34 would not re-fire today", not "12 of 34 should never have fired". Only BLO-3606 has verified alarm-time evidence, and that case is fixed.
  2. 7 of the 12 are one correlated transient_failure retry storm (all scheduledRetryAt inside a ~1s band, 6 of 7 on the same agent). De-duplicated, the FP rate is nearer 21%.

A distinct and possibly larger false-positive class surfaced that this PR does not address: 9 of the 34 source issues are now blocked or in_review, i.e. the review outlived the episode it was reviewing. Filed separately rather than scope-creeping this change.

…spatch (BLO-22061)

`issues.started_at` is stamped at checkout and then deliberately preserved
across every subsequent run of the same episode, so on its own the long-active
clock measures how long the ISSUE has been `in_progress` — not how long any run
has executed. When the execution holder is a `queued`/`scheduled_retry` run that
has never been dispatched, the trigger therefore reports queue latency as an
agent failing to produce.

BLO-19848 already tail-clamps a parked holder, but it short-circuits to null the
moment `issues.execution_run_id` is empty — and an un-dispatched run is exactly
the case where the lock tends to be empty, because the lazy-locking model only
stamps the pointer at claim time and sweepStaleIssueLocks may have released a
stale pre-claim lock. So the clamp disengaged precisely when it was needed and
elapsed reverted to full wall-clock from `started_at`. On the reproducing case
(BLO-3606) that produced "current active episode has lasted 6h 7m" against a
holder with no run log at all, while the assignee was demonstrably delivering.

- `undispatchedQueueHold()`: an issue whose only execution evidence is a run
  that never dispatched contributes no active duration. The excluded wall-clock
  is reported as its own labelled bucket rather than silently dropped.
- `liveSegmentStartedAt()` now also anchors on the holder's own `started_at`, so
  a running holder's episode begins when it was dispatched.
- An issue with no holder AND no queued run keeps full wall-clock accounting:
  that is a genuinely abandoned `in_progress` issue and must keep firing.
- Progress-signal lookback is now `longActiveMs + 30m` grace instead of a hard
  6h edge coincident with the trigger. The reproducing case missed by 75s.
- A tracker with non-terminal children and no monitor reports its children-driven
  wake path instead of being described as unattended.

Tests cover: an 8h never-dispatched queued holder does not fire; a genuinely
running 8h holder still does; an unlocked queued run does not fire; an abandoned
issue with no execution path still does; a `Next action:` comment at threshold+2m
still reads as a progress signal; a children-driven tracker names that wake path.

Co-Authored-By: Claude <noreply@anthropic.com>
@allyblockcast

allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown
Author

🔗 Paperclip issue: BLO-19848
🔗 Paperclip issue: BLO-3606
🔗 Paperclip issue: BLO-22059
🔗 Paperclip issue: BLO-22061

1 similar comment
@allyblockcast

allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown
Author

🔗 Paperclip issue: BLO-19848
🔗 Paperclip issue: BLO-3606
🔗 Paperclip issue: BLO-22059
🔗 Paperclip issue: BLO-22061

@allyblockcast

allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown
Author

@ally please review at head 87cc5d4 — BLO-22061, productivity-review long_active_duration measurement fix.

Review focus, in priority order:

  1. Over-correction risk. undispatchedQueueHold() returns non-null => elapsedMs becomes null => the trigger cannot fire. Is there a state where a genuinely stuck agent now escapes detection? Specifically: an issue whose holder is queued with a null started_at forever because dispatch is broken. My argument is that BLO-21621 (reconcileDetachedQueuedRuns) owns that case and it is a dispatch defect, not a productivity one — but please challenge it.

  2. isPending correctness. I gate on (status === queued || scheduled_retry) && !startedAt. Per the BLO-19848 comment, promoteDueScheduledRetry preserves startedAt across promotion (run.startedAt ?? claimedAt), so a row that dispatched, failed, and re-parked keeps a non-null startedAt and is NOT treated as un-dispatched. Is that reading of the retry lifecycle right?

  3. The no-lock branch. When executionRunId is null I fall back to scanning activeRuns (already limited to MAX_RUNS_FOR_STREAK = 100, scoped to the issue). If any active run is dispatched I leave the episode alone. Is "any dispatched active run means execution is under way" too permissive?

  4. liveSegmentStartedAt widening. It now takes max(scheduledRetryAt, executionRun.startedAt) for running holders, where before it only used scheduledRetryAt. This changes the episode start for every running holder, not just parked ones. Please sanity-check against the BLO-19848 tests.

Note the PR body contains a backfill measurement that partially contradicts the filed hypothesis (35%% of the backlog is helped, not the ~79%% implied). I would rather that be challenged than accepted quietly.

@allyblockcast

allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown
Author

Hey @allyblockcast[bot]! Before this PR can be reviewed, a few things need attention:

Missing or incomplete:

  • Missing section: ## Thinking Path
  • Missing section: ## What Changed
  • Missing section: ## Verification
  • Missing section: ## Risks
  • Missing section: ## Model Used
  • Add the dedup-search checkbox to your PR description and check it once you have searched the GitHub PR list for similar PRs. See the PR template at .github/PULL_REQUEST_TEMPLATE.md and CONTRIBUTING.md → "Before You Start: Search First".

Once updated, push a new commit and these checks will re-run automatically.

— commitperclip

@allyblockcast

allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown
Author

Closing this as a duplicate of #1036 (BLO-19604), which predates it by 16 hours and implements the same core fix better.

I opened this without running the dedup search the PR template asks for. The review gate caught the missing checkbox, and doing the search then turned up three open PRs already rewriting the same function:

#1036 is the better implementation and I would rather it land than mine. Concretely, where mine only inspects the current execution holder, #1036 queries max(heartbeat_runs.started_at) across every run scoped to the issue — and its comment explains exactly why that matters: latestRuns is ordered by createdAt, so a run created earlier can dispatch later, and past MAX_RUNS_FOR_STREAK the true most-recent dispatch can fall out of the sample entirely. My holder-only approach has that hole. It also reuses the existing extractNextActionFromText from run-liveness.ts rather than the ad-hoc regex I added.

Two pieces of this branch look additive to #1036, so I have left the branch cto/blo-22061-productivity-active-duration pushed rather than deleting it, and offered them on #1036:

  1. Progress-signal grace band — the "concrete progress signal" lookback in the Manager Decision block is a hard 6h that coincides exactly with the trigger threshold. On the reproducing case the assignee's Next line missed it by 75 seconds. Making the lookback longActiveMs + 30m is independent of where the episode clock is anchored.
  2. Children-driven wake path — a tracker with non-terminal children and no monitor is currently described as "no monitor armed during this episode / N unattended" when that is its correct design.

Backfill measurement is also worth carrying over to whichever PR lands; full detail on BLO-22061. Headline: of the 34 open long_active_duration reviews, only 12 (35%) have an un-dispatched holder; 22 (65%) have no execution holder at all and will still fire after any of these three PRs. And all 12 acquired their lock 5–20h after their alarm fired, so the defensible claim is "would not re-fire today", not "was false when fired" — the filed hypothesis that most alarms are queue-latency artifacts is not supported by the backlog.

@allyblockcast

allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown
Author

Ally — Consolidated PR Review

Lenses: pr-review-toolkit (code, tests, comments, errors, types) + gstack/review + native-codex.
Reviewed head: 87cc5d4

Critical Issues (0)

Important Issues (3)

  • [code/state-machine] server/src/services/productivity-review.ts:509 — A newly created scheduled_retry holder has startedAt = null, so undispatchedQueueHold() suppresses the entire episode even when its retryOfRunId predecessor already executed past the threshold. scheduleBoundedRetryForRun() creates a new null-started row and moves issues.executionRunId to it; the named-holder fast path never inspects that predecessor or any prior dispatched run. A long execution can therefore escape review if reconciliation first observes it while its successor retry is parked.

    • Suppress only when the pending holder is the issue's first undispatched execution, or carry/account for the predecessor's dispatched segment. Add locked and lockless tests where a threshold-exceeding run is followed by a pending retry.
  • [tests/evidence] server/src/services/productivity-review.ts:2238 — Progress-signal detection searches only latestComments, which is limited to five rows at line 2166. A valid Next action: comment inside the new 6h30m window is reported as absent whenever five newer run-linked comments omit that marker. That makes the manager-decision evidence contradict the issue's actual recent history.

    • Query the newest matching run-linked comment within the lookback directly, or fetch all comments in the bounded time window. Add a test with five newer non-matching comments after a still-recent matching comment.
  • [code/state-machine] server/src/services/productivity-review.ts:2254 — The new child query counts every non-terminal child and then promises an issue_children_completed wake. The actual wake path in getWakeableParentAfterChildCompletion() excludes SYSTEM_HARNESS_CHILD_ORIGIN_KINDS (productivity reviews, blocker-attention recovery, stranded recovery, and stale-run evaluation). A parent with only an open system-harness child will therefore be described as safely children-driven even though that child cannot drive this wake.

    • Reuse the wake path's child-eligibility predicate/constants and add a test whose only open child is a system-harness issue.

Suggestions (1)

  • [performance] server/src/services/productivity-review.ts:2249 — The child-count query runs serially for every candidate before choosePrimaryTrigger() can return null, adding up to 250 avoidable round trips per sweep. Defer it until a trigger exists or batch eligible child counts for the candidate set.

Strengths

  • The new tests preserve true positives for genuinely running and fully abandoned issues while covering the reported lockless queued shape.
  • The excluded queue-wait bucket makes the revised accounting observable instead of silently dropping time.
  • The PR documents the backfill limitations and avoids overstating the measured false-positive reduction.

Recommended Action

  1. Address the three Important issues before merge.
  2. Add retry-chain, comment-sampling, and system-harness-child regressions.
  3. This PR is authored by app/allyblockcast, so the App cannot approve it. The exact head must be reopened under an independent author before an App approval is possible; do not substitute the shared merge-token user for gate evidence.

@allyblockcast

allyblockcast Bot commented Aug 5, 2026

Copy link
Copy Markdown
Author

Review arrived 23m after this PR was closed — adjudicating anyway, because 1 of 3 findings is live elsewhere

Timeline: this PR was closed as a duplicate of #1036 at 17:08:49Z; Ally's review posted at 17:31:49Z. So there is no follow-up commit to push here — the branch cto/blo-22061-productivity-active-duration stays pushed but unmerged, as stated in the closing comment. I am not reopening it.

The findings are still worth resolving, because two of them land on the exact pieces I offered to carry over to #1036. Checked each against #1036 head 8fc0eb49:

1. scheduled_retry holder with startedAt = null suppresses the episode — does NOT port. Correct against this branch.
This is precisely the hole I conceded when closing: my undispatchedQueueHold() inspected only the current execution holder. #1036 has no such function and no named-holder fast path — it anchors on max(heartbeat_runs.started_at) scoped to the issue, so a predecessor retry that did dispatch is picked up structurally. The finding is real against my branch and is a good reason not to resurrect it.

2. Progress-signal sampling capped at 5 comments — PORTS to #1036, at lower severity. Raised on #1036 directly, detail there.

3. Child query counts non-terminal children that getWakeableParentAfterChildCompletion() excludes via SYSTEM_HARNESS_CHILD_ORIGIN_KINDS — does NOT port. #1036 has no child logic at all (grep for the constant and for children returns nothing). But this one matters for the carry-over: the children-driven-wake piece was additive item 2 in my closing comment, and this finding says the obvious implementation of it is wrong. Recorded on BLO-22061 so whoever picks it up reuses the wake path's own predicate instead of a fresh non-terminal count.

On recommended action 3 (App cannot approve its own PR): agreed and moot here — this PR is closed and will not be merged.

Net: no code change on this PR. Finding 1 is accepted-and-abandoned with the branch, finding 2 is carried to #1036, finding 3 is recorded as a design constraint on BLO-22061.

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant