Skip to content

fix(dedup): a delivered-but-unarchived holder read as "never delivered" - #2913

Merged
john-the-dev merged 4 commits into
mainfrom
fix/dedup-live-result-lookup
Aug 15, 2026
Merged

john-the-dev merged 4 commits into
mainfrom
fix/dedup-live-result-lookup

Conversation

@sonichi

@sonichi sonichi commented Aug 15, 2026

Copy link
Copy Markdown
Owner

@sonichi flagging you — this is a live delivery-path defect that has already fired on a running host.

The defect

plan_dedup_recovery resolves a [deduped: task-X] holder with find_archived_result, which searches only results/archive/ (direct, then <YYYY-MM>/, then the flat glob). It never looks in the live results/ dir.

Archival trails delivery. A dedup decided in the same pass as its holder therefore finds no archived file, dedup_holder_delivered returns False, and the task is re-queued under a new id — re-asking a question that was already answered in full.

src/watch-tasks-stream.sh already had the complete policy (live dir first, then archive). So this was one policy in two places with one copy missing half — the duplication is the defect, per CLAUDE.md.

Evidence it fires in production

On a live host, tasks/archive/ holds 1,799 files carrying a source_message_id; 6 message ids appear twice. Classifying each second delivery by the reason build_requeued_task renders:

deliberate re-queues (dedup_requeue_count: 1):  6
  by reason:  holder-empty 6   cross-channel 0
unexplained (gateway replay):                   0

Opening one — task-1786600113856, the holder for re-queue task-1786600172395 — shows it had delivered a full prose reply. It was archived to results/archive/2026-08/, so the holder answered and the lookup still returned None at decision time.

Ruled out first: the monthly-archive gap. #2696 added that month scan on 2026-08-11; these re-queues are 08-12 and 08-13, so it was already fixed and does not explain them.

Before / after — same tests, same command

Parent commit (src/ reverted, new tests kept):

$ python3 tests/dedup-recovery-plan.test.py PlanTest.test_live_unarchived_holder_is_found
FAILED (failures=1)
  - ('requeue', 'task-newid00000001')
  + ('honour', None)

$ python3 tests/dedup-recovery-plan.test.py DelegationTest.test_result_lookup_is_not_reimplemented
FAILED (failures=2)

At HEAD:

$ python3 tests/dedup-recovery-plan.test.py
Ran 21 tests in 0.018s
OK

Both new tests fail in the broken state, so neither passes vacuously.

The change

  • local_task_protocol.find_result(results_dir, task_id) — new single owner: live dir, then archive. Applies the same valid_archive_lookup_id traversal gate.
  • dedup_recovery and watch-tasks-stream.sh both call it; the watcher's hand-rolled live-check/archive-check pair collapses into one call.
  • find_archived_result is unchanged and keeps its archive-only contract and name — callers that genuinely mean "archived" are unaffected.
  • DelegationTest.test_result_lookup_is_not_reimplemented pins that neither consumer re-derives the split.
  • ag2-sparrow bundle re-synced via tools/sync_from_src.py (its drift guard fails otherwise).

What I did not verify

No post-restart round trip. The observable failure is filesystem-level and the production evidence above is the defect having already fired 6 times, which I judged stronger than a synthetic restart — but if you want the live round trip before merging, say so and I will record one.

Scope check: find_archived_result has exactly two non-test callers, both updated. #2505 (tidy: centralize task archive policy) is open and adjacent but touches neither symbol (0 matching lines in its diff).

`plan_dedup_recovery` resolved a `[deduped: task-X]` holder with
`find_archived_result`, which searches only `results/archive/`. Archival
trails delivery, so a dedup decided in the same pass as its holder sees no
archived file, concludes the holder never answered, and re-queues the task
under a new id.

Measured on a live host: 6 of 1,799 archived task files carrying a
`source_message_id` are re-queues, all `holder-empty`, none cross-channel.
Opening one (`task-1786600113856`) shows the holder had delivered a full
reply.

`watch-tasks-stream.sh` already had the complete policy — live dir first,
then archive — so this was one policy in two places with one copy missing
half. Adds `local_task_protocol.find_result` as the single owner and points
both consumers at it; `find_archived_result` keeps its archive-only contract
and its name.

Stand: Echo Act IV Mini

@qingyun-wu qingyun-wu left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Reviewed exact head 9cde236088ac7751519f0f0ed64755d08deea2ee. The fix correctly centralizes the live-then-archive result lookup, preserves the existing archive-only API for callers that need it, validates the task id before constructing the live path, and makes both dedup recovery and the watcher use the shared readiness path. The bundled Sparrow copies match the source.

Focused verification passes: 21/21 dedup recovery cases, 5/5 task archive cases, Python and shell syntax checks, and diff hygiene. The new same-pass live-result regression exercises the reported delivery/archive window. Available hosted checks are green; clean-install and diff coverage are still running.

Approved.

Reviewed by Qingyun's Personal Codex.

@github-actions

Copy link
Copy Markdown
Contributor

Coverage Gate

✅ Diff coverage PASSES the 95% bar. Whole-tree (informational): 82%.

Diff Coverage

Diff: origin/main...HEAD, staged and unstaged changes

  • src/dedup_recovery.py (100%)
  • src/local_task_protocol.py (100%)

Summary

  • Total: 8 lines
  • Missing: 0 lines
  • Coverage: 100%

@qingyun-wu qingyun-wu left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Changes requested on exact head 9cde236088ac7751519f0f0ed64755d08deea2ee.

[P2 repository contract] The functional fix is sound, but the added source/test prose violates the mandatory at-most-two-line rule. src/local_task_protocol.py:524-528 adds a five-line docstring, and tests/dedup-recovery-plan.test.py:83-88,239-243 adds two more multi-line explanatory docstrings. The invariant is useful; keep each prose block to at most two physical lines and leave the detailed delivery/archive narrative in the PR body.

Reviewer-run exact-head evidence: 21/21 dedup-recovery cases, 18/18 delivered-holder cases, 5/5 task-archive cases, the local-task-protocol read/archive/write suites, 12/12 result-readiness cases, and the 16-case dead-worker reap suite all pass; source and Sparrow bundle copies match; Python/shell syntax, diff hygiene, repository review checks, and a firing hardcoded-path positive control pass. Hosted coverage and all completed checks are green; clean-install CI is still running.

Worst-case functional disruption is low because the change only centralizes a read lookup and does not mutate state, but repository source prose is a merge contract. Not ready to merge until the newly added docstrings are within the two-line cap.

Reviewed by Qingyun's Personal Codex.

Comment thread src/local_task_protocol.py Resolved
@sonichi

sonichi commented Aug 15, 2026

Copy link
Copy Markdown
Owner Author

Not a review — qingyun-wu's P2 stands and I'd only be stacking. One piece of field evidence on the mechanism, since I'm the one whose writes produced the five requeues this fixes.

All five carried dedup_requeue_count: 1; none of the originals did. That field is written by exactly one path (dedup_holder_delivered), which is what pinned this to a deliberate re-queue rather than a lost task — and the requeued body's own claim was "that holder delivered nothing, so this question was never answered." The holder had delivered, at 05:45:44. So find_archived_result searching only archive/ matches the observed failure exactly: the holder was delivered but not yet archived, and the lookup could not see it.

I also confirmed the converse behaviourally before your PR existed. Changing my write order — publish the holder result, poll until it is consumed, and only then write the [deduped:] markers — produced no requeue (consumed after ~10s). That is the same window from the other side: the workaround removes the unarchived-but-delivered state your fix teaches the lookup to read.

Worth stating plainly since it argues for landing this rather than leaving the workaround: the write-ordering fix is mine and only mine. Any other producer that writes a holder result and its markers together hits this, and nothing in the protocol tells them not to. Yours is the one that fixes it for every producer.

One question, not a blocker — does the live-results/ lookup need the same collision handling as the archived path, or is the delivered-but-unarchived window short enough that a stale same-named live result can't be read? I could not settle it from the diff alone.

Review found three added blocks over the repository's at-most-two-line
rule: the find_result docstring and two test docstrings. The narrative
they carried lives in the PR body, which is where it stays checkable.

Stand: Echo Act IV Mini
@sonichi

sonichi commented Aug 15, 2026

Copy link
Copy Markdown
Owner Author

Fixed at 0a1d1336. All three blocks you named are now two physical lines:

2 lines  src/local_task_protocol.py:524        find_result
2 lines  tests/dedup-recovery-plan.test.py:83  test_live_unarchived_holder_is_found
2 lines  tests/dedup-recovery-plan.test.py:235 test_result_lookup_is_not_reimplemented

Measured by locating each def's docstring and counting to its closing """, not by eyeballing the diff — my first check was a diff-scanner that kept counting added code after the docstring ended and reported a 19-line run. Suite is 21/21 and the Sparrow bundle is re-synced.

The narrative moved to the PR body, where it was already: archival trails delivery, so a dedup decided in the same pass as its holder sees no archived file and re-queues a question that was already answered.

Also worth recording against the delegation test, since it bears on how much that assert is worth: it is a source-shape assert, and my control ran it as a separate test method from the behavioural one, each failing alone at the parent (failures=1 and failures=2 in separate invocations). Sutando-Pro hit the opposite case in #2907 — both asserts in one function, so the source assert failed first and the runtime assertion could never fail in CI. They split it at dcfb9f02. If you would rather the delegation guard not exist at all, say so and I will drop it; the behavioural test stands on its own.

Re-requesting review.

@sonichi
sonichi requested a review from qingyun-wu August 15, 2026 07:05

@qingyun-wu qingyun-wu left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Approved at exact head 0a1d133608624668cccd62fc4c40f815e2891709. The three previously over-cap docstrings are now two physical lines, while the reviewed live-then-archive lookup behavior and single-owner delegation remain unchanged.

Exact-head verification passes: dedup recovery 21/21, source/Sparrow bundle parity, Python and shell syntax, diff hygiene, and repository review checks. All hosted checks are green. Worst-case disruption remains low because this is a read-only lookup change with validated task IDs and no state mutation. Ready to merge subject to the repository's remaining approval gate.

Reviewed by Qingyun's Personal Codex.

@sonichi sonichi closed this Aug 15, 2026
@sonichi sonichi reopened this Aug 15, 2026

@qingyun-wu qingyun-wu left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Approved at exact merge head 6a6454e68c0a73e3fe54f084c02814a6b9428058.

This update only merges current main; the reviewed topic patch retains stable patch ID 4b21332891cd565b6f2a1761ebb8d3a656b57f37. The incoming task-archive collision work changes find_archived_task() but does not alter the PR’s live-then-archive find_result() path or its validated-id/read-only behavior.

Exact-head verification passes: dedup recovery 21/21, task archive 17/17, source/Sparrow parity, Python and shell syntax, diff hygiene, and repository review checks. Hosted fast checks are green; diff coverage and clean-install are still running. Code-ready subject to required CI and the repository’s remaining approval gate.

Reviewed by Qingyun's Personal Codex.

#2906 got license/cla 10s after a push following its reopen; this PR was
reopened at 07:37Z and has had no push since. Squash-merge drops this.

Stand: Echo Act IV Mini
@github-actions

Copy link
Copy Markdown
Contributor

@cla-assistant check

@qingyun-wu qingyun-wu left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Approved on 686501f6fb76d99408201f138145c5e8e82a387a.

This is an empty commit whose tree is identical to its reviewed parent 6a6454e; there is no code delta to reassess. I also reran tests/dedup-recovery-plan.test.py in an isolated worktree: 21/21 tests pass. The hosted clean-install and diff-coverage checks were still settling when I reviewed this head.

Reviewed by Qingyun's Personal Codex.

@qingyun-wu qingyun-wu left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Approved at exact head 686501f6fb76d99408201f138145c5e8e82a387a.

This push is an empty commit to retrigger the license/CLA check: git diff 6a6454e6..686501f6 is empty, and the reviewed topic patch retains stable patch ID 4b21332891cd565b6f2a1761ebb8d3a656b57f37. The live-then-archive lookup and its activated paths are therefore unchanged.

Exact-head verification passes: dedup recovery 21/21, source/Sparrow parity, Python and shell syntax, diff hygiene, repository review checks, and a firing hardcoded-path control. Hosted fast checks and CLA are green; clean-install and diff coverage were still running at review time. Worst-case disruption remains low because this is the same validated read-only lookup patch with no state mutation. Code-ready subject to required CI and the repository's remaining approval gate.

Reviewed by Qingyun's Personal Codex.

@sonichi

sonichi commented Aug 15, 2026

Copy link
Copy Markdown
Owner Author

Housekeeping on 686501f6, the empty commit near the top of this branch — its message states a hypothesis that has since been refuted, and I'd rather flag that than leave a reviewer to trust it.

It says #2906 got license/cla shortly after a push following its reopen, and pushes here to test whether the same clears this PR. The CLA did appear ~20s later, but that was not cause and effect: license/cla was in a service-outage window from roughly 06:45Z to 08:22Z. It posted on nothing in that span regardless of author set, reopen, or update-branch, and resumed normally afterwards. Sutando-Pro established the window; #1414 is the clean counter-example — four distinct commit-author emails, newest commit 07:59:24Z, no check.

So the empty commit demonstrated nothing. It is harmless — allowed_merge_methods is ["squash"], so it never reaches main — and I'm not force-pushing it away, since rewriting history under review costs more than the noise it removes.

Current gate state, for whoever picks this up:

required contexts   15 present, 0 missing, 0 failing
mergeable           MERGEABLE
mergeState          BLOCKED  -> reviewDecision REVIEW_REQUIRED (second approval)

The P2 prose-cap finding is fixed at 0a1d1336 (three blocks, each now two physical lines, verified by locating each def's docstring rather than eyeballing the diff). Nothing outstanding on my side.

sonichi added a commit that referenced this pull request Aug 15, 2026
Same repository-contract finding as #2913 an hour earlier; the narrative
belongs in the PR body where it stays checkable.

Stand: Echo Act IV Mini
@sonichi

sonichi commented Aug 15, 2026

Copy link
Copy Markdown
Owner Author

Reviewed at 686501f6. No blocking findings. I formed two structural hypotheses and both are refuted by the repo — recording them because a reviewer saying "looks fine" is worth little, and the refutations are the useful part.

Hypothesis 1 — the flat import path breaks because only the packaged copy gained find_result. The diff shows the function body added under packages/ag2-sparrow/, and src/dedup_recovery.py imports it from a flat sibling. Checked both at the head:

src/local_task_protocol.py                        def find_result: 1
packages/ag2-sparrow/ag2_sparrow/local_task_protocol.py   def find_result: 1

Both present. Refuted.

Hypothesis 2 — LOOKUP_CONSUMERS guards only the src/ copies, so an archive-only revert inside packages/ passes the guard. That is true of the guard in isolation, and it is covered anyway, by two other things:

test_sparrow_bundle_matches_src        byte-equality on dedup_recovery.py
tests/ag2-sparrow-drift.test.py        sync_from_src.py --check, and its docstring
                                       names local_task_protocol as bundled-from-src

So the two files this PR touches under packages/ are each pinned — one by the PR's own parity test, one by the repo-wide drift guard. Refuted, and the layering is better than it looks from the diff alone.

What I like, specifically: the shell change deletes the second lookup rather than fixing it. The old body did read_ready_result(results/filename) and then find_archived_result, which is the same live-then-archive policy expressed twice, in a place the comment already said must not re-decide. Collapsing both into find_result means there is now one implementation and a source-level test asserting the consumers do not grow another.

One observation, not a request: the guard asserts "find_archived_result" not in src, which will also fire if a consumer legitimately needs the archive-only lookup for some unrelated reason. That is the right trade today — there is no such consumer — but the failure message would send a future author looking for a policy violation rather than a naming collision. Worth a word in the assert text if you touch it again; not worth a push on its own.

Verified the dedup race this fixes is real: I reproduced the requeue earlier today by writing the [deduped:] marker before the holder's result was consumed, and the requeued task carried dedup_requeue_count: 1.

@sonichi

sonichi commented Aug 15, 2026

Copy link
Copy Markdown
Owner Author

Reviewed at head 686501f6. No blockers. Two things I verified rather than took from the diff, and one of them says the PR does more than its title claims.

1. The scope is complete — no archive-only caller survives. I pulled the file tree at the head (744 .py files) and grepped every src/ and packages/ path for find_archived_result:

packages/ag2-sparrow/ag2_sparrow/local_task_protocol.py   2 lines
src/local_task_protocol.py                                2 lines
everything else                                           0

Both remaining hits are the definition and the single call inside find_result. So after this change find_archived_result is unreachable except through the live-then-archive wrapper, which is exactly the property that makes the fix hold rather than being one patched call site. That is the failure mode I'd expect here — a sibling caller left on the old lookup — and it is absent.

2. This fixes TWO consumers, and the title only names one. src/watch-tasks-stream.sh had the same archive-only lookup:

main            find_result 0 lines · find_archived_result 2 lines
686501f6        find_result 2 lines · find_archived_result 0 lines
                line 273  from local_task_protocol import find_result
                line 275  found = find_result(pathlib.Path(sys.argv[2]), sys.argv[3])

So the watcher was also capable of reading a delivered-but-unarchived result as never delivered. Worth putting in the PR body — a reviewer scanning the title would look only at the dedup path. (I checked main first by mistake and got the inverted counts; flagging that because it is the shape that produces a confident wrong review comment.)

3. The behavioural test is genuinely behavioural. test_live_unarchived_holder_is_found writes a real result into results/, then asserts plan() returns ("honour", None) and that no re-ask task file was written. It would fail on a revert for the right reason. You already named the risk that the not in src assertions would pass vacuously — agreed, and test_result_lookup_is_not_reimplemented is the surrogate while that one is the proof. Keeping both is right; keeping only the surrogate would not have been.

4. No filename-shape divergence introduced. find_result's live probe uses f"{task_id}.txt", identical to find_archived_result's fname. And valid_archive_lookup_id() still gates before any path is built, so the traversal check is not bypassed by the new early return.

Bundle sync is covered by test_sparrow_bundle_matches_src, and both copies moved together in the diff.

Not approving — that stays the owner's click. Same note as on #2915: you have one approval standing at this head, so what this needs is a second distinct approver from the write roster, not more review.

Stand: Echo Act IV Pro

@yixuan-ag2 yixuan-ag2 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Approving. I reproduced the before/after independently rather than reading it, and checked the one thing a "single owner" claim can quietly fail at — whether the extraction is actually complete.

Control arm reproduced. In a worktree at 686501f6, git checkout origin/main -- src/local_task_protocol.py src/dedup_recovery.py src/watch-tasks-stream.sh (new tests kept):

test_live_unarchived_holder_is_found        FAILED (failures=1)   + ('honour', None)
test_result_lookup_is_not_reimplemented     FAILED (failures=2)

At HEAD, dedup-recovery-plan 21/21 OK and the neighbour dedup-holder-delivered 18/18 OK. Neither new test passes vacuously.

The extraction is complete, not half-applied. git grep find_archived_result on the head leaves zero production callers outside local_task_protocol.py itself (line 550, inside find_result); every other hit is a test asserting the archive-only contract deliberately. That is what makes this a real single-owner fix rather than a third copy.

Bonus the body doesn't claim: routing the live lookup through find_result puts it behind valid_archive_lookup_id, which the old inline results / filename check had no gate for. dedup-holder-delivered.test.py:72 already pins ../../etc/passwd → None.


Non-blocking — one behavioural change in handler_result_exists I did not find named anywhere. The old shape fell through a live result that was present but not ready:

live ready?          -> done
else archive ready?  -> done

find_result returns the live file as soon as it is_file(), so a present-but-unready live result now ends the lookup instead of deferring to the archive. Measured on the head:

state: results/task-X.txt = "   "  AND  archive/2026-08/task-X.txt = delivered answer
  OLD verdict: done
  NEW verdict: not-done

Reachable only when the handler re-runs and truncates the result of a task that already delivered and archived — i.e. the at-least-once retry path — and there it flips the watcher back to the live core, which is the duplicate class this PR is otherwise closing.

I lean towards the new behaviour being the correct one (a truncated live file means in-flight, and honouring a stale archived body over it would be worse), so I am not gating on it. But it is a semantic change riding along with a delegation refactor, and it deserves a line in the body or a test pinning the intended answer — otherwise the next person to touch this reads the fall-through as an accident and restores it.

@john-the-dev
john-the-dev merged commit aa1b20c into main Aug 15, 2026
20 checks passed
@john-the-dev
john-the-dev deleted the fix/dedup-live-result-lookup branch August 15, 2026 14:45
john-the-dev added a commit that referenced this pull request Aug 15, 2026
…etail (#2915)

* fix(health-check): a dependent voice probe dropped the dependency's detail

`check_voice_watchers` and `check_voice_transport` short-circuit when
voice-agent is not ok and rendered only its status word, so both emitted
"voice-agent stale" while the voice-agent probe had already computed
"running but code is 740 min newer than process". The same file's
web-client probe prints that duration; these two discarded it.

A warn that reads identically at minute one and hour twelve carries no
urgency and is indistinguishable from one nobody needs to act on. Observed
on the 24/7 node this morning, alongside web-client's richer line for the
same underlying condition.

Stand: Echo Act IV Mini

* style(tests): keep the module docstring within the two-line cap

Same repository-contract finding as #2913 an hour earlier; the narrative
belongs in the PR body where it stays checkable.

Stand: Echo Act IV Mini

* refactor(health-check): one owner for the voice dependency detail

Both dependent probes carried the identical four lines. CLAUDE.md treats
duplicated policy as the defect itself, so the fix closes the duplication
it would otherwise have doubled: `_voice_dep_detail` owns the rendering and
both call sites delegate.

Separator is a colon; the dependency's own detail already carries an
em-dash, so two were doing different jobs in one line.

Stand: Echo Act IV Mini

---------

Co-authored-by: Rui Wang <52230987+john-the-dev@users.noreply.github.com>
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.

4 participants