feat(harness): coordinator phase-boundary instrumentation for RFC #2251 - #2255
Merged
HongmingWang-Rabbit merged 1 commit intoApr 29, 2026
Merged
Conversation
Adds structured `rfc2251_phase=...` log lines at the deterministic phase
boundaries inside route_task_to_team and check_task_status, so an
operator running scripts/measure-coordinator-task-bounds.sh against
staging can correlate the harness's external timing trace with what
phase the coordinator was in at any given second.
The harness already exists in staging and measures end-to-end response
time + heartbeat trace. What it CAN'T do without this PR is answer
"the coordinator response took 7 minutes — was it stuck delegating, or
stuck polling children, or stuck synthesizing after all children
returned?" The phase logs answer that question.
Phases instrumented (deterministic Python boundaries, no agent prompt
involvement):
route_start → enter route_task_to_team
children_fetched → after get_children() returns
routing_decided → after build_team_routing_payload
delegate_invoked → just before delegate_task_async.ainvoke
delegate_returned → after delegate_task_async returns
check_status → every check_task_status poll (per-poll)
route_returning_decision_only → fall-through path
Each line includes elapsed_ms from route_start so per-phase durations
are extractable via:
grep rfc2251_phase= <container.log> \
| awk '{...}' to compute deltas between consecutive phases
The synthesis phase (after all children return, before agent emits
final A2A response) is NOT instrumented here because it's
agent-driven (no deterministic Python boundary). The harness operator
infers synthesis_secs = total_response_secs − max(check_status_ts).
This is reproduction-harness scaffolding; it adds zero behavior. Strip
the rfc2251_phase log lines when V1.0 ships and the phase data lands
in the structured heartbeat payload instead.
Refs:
- RFC: molecule-core#2251
- Harness: scripts/measure-coordinator-task-bounds.sh (shipped earlier)
- V1.0 gate: this is deliverable #2 of the four pre-V1.0 gates
HongmingWang-Rabbit
requested a review
from hongmingwang-moleculeai
as a code owner
April 29, 2026 03:12
HongmingWang-Rabbit
enabled auto-merge
April 29, 2026 03:12
HongmingWang-Rabbit
deleted the
feat/rfc2251-coordinator-phase-instrumentation
branch
April 29, 2026 03:22
HongmingWang-Rabbit
pushed a commit
that referenced
this pull request
Jun 12, 2026
…SSOT; fix type→kind on send path Two incident-derived regression gates plus the real source bug the first one surfaced. 1) Outbound A2A `message/send` envelope (#2251) — REAL, currently-shipping bug. buildA2AMessageParts (mcp_tools.go, feeds delegate_task + delegate_task_async) and the inline sync-delegation envelope (delegation.go) emitted the text Part as {"type":"text"} instead of the A2A v0.3-canonical {"kind":"text"}. A v0.3 peer's Pydantic validator discriminates Parts on `kind` and silently drops a `type`-keyed Part — the sender sees a happy 200/202 while the brief is lost. #2255 fixed the INBOUND normalizeA2APayload (type→kind on receive); this OUTBOUND send path was separate and still buggy on main. The file-attachment Part already used `kind` (untouched); MCP tools/call content schema legitimately keeps `type` (different protocol, untouched). Fix: text Part type→kind in both send paths. Gate: a2a_outbound_envelope_test.go — pins text-part `kind`, file-part `kind` (non-regression), and the full envelope role+kind. RED before the fix (the two kind-asserting tests failed against the shipping `type` shape), GREEN after. 2) Platform provider auth_env SSOT (#2250) — exact-equality gate. The `platform` (closed proxy) provider must advertise ONLY MOLECULE_LLM_USAGE_TOKEN in auth_env; a vendor key there makes the canvas demand a credential the platform path ignores (wrong-bill / silent no-op). The pre-existing tests only do a membership / non-empty check, which passes against a drifted two-element list. This pins the WHOLE set. Core's providers.yaml is already clean (the vendor key lives in the separate auth_token_env field), so the gate currently PASSES and locks that invariant against future drift onto this SSOT. The drift itself lives in the codex template repo. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
HongmingWang-Rabbit
pushed a commit
that referenced
this pull request
Jun 12, 2026
…stic PR #2255's normalizeA2APayload (#2251) renames the legacy Part discriminator "type" -> "kind" (A2A v0.3) on ingest. ProxyA2A logs the NORMALIZED body to activity_logs (a2a_proxy.go:432 body=normalizedBody; logA2AReceiveQueued RequestBody=json.RawMessage(body)). So a poll-mode caller that posts {"type":"text",...} has its row stored with {"kind":"text",...}. test_poll_mode_e2e.sh Phase 5's ASC parser hard-coded `if p.get('type')=='text'` to extract part text from the stored request_body. Post-rename every part is keyed on "kind", so the filter matched nothing, text_of() returned '' for every row, and the assert saw `got: |` (empty|empty) -> REQUIRED E2E API Smoke gate FAILED on #2255. Root cause: the test asserted on an INTERNAL wire detail (which discriminator field the server stored) instead of on the text payload. The product change is correct and is covered by Go unit tests in a2a_proxy_test.go; only the E2E parser was coupled to the legacy format. Fix: - text_of() now accepts kind=='text' OR type=='text' (works on main's legacy feed AND on #2255's normalized feed) — so it gates the text payload, not the field name. - Add a positive wire-contract assertion: the stored Part must carry the v0.3 "kind" discriminator and NOT the legacy "type". This is the end-to-end half of the unit tests — it proves the rename survives the durable activity_logs path, and makes a dropped/reverted rename (or a feed that stops storing the normalized body) fail LOUDLY here instead of silently feeding a polling agent an untagged Part. Verified: on main (no rename) poll-mode = 22 passed/0 failed; on #2255 (f0b6079) it was 21 passed/1 failed at this exact assert. Both parsers simulated against kind- and type-shaped feeds. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Pre-V1.0 gate #2 of the RFC at #2251 — the in-process companion to the existing `scripts/measure-coordinator-task-bounds.sh` external harness. Adds structured `rfc2251_phase=...` log lines at deterministic phase boundaries inside `route_task_to_team` and `check_task_status` so the harness operator can answer "the coordinator response took 7 minutes — was it stuck delegating, polling children, or synthesizing?" by greping the workspace container log.
What's instrumented
Every phase boundary emits one log line with the phase name + elapsed_ms-from-route_start. Phases:
The synthesis phase (between last `check_status: completed` and the final A2A response) is NOT instrumented here because it's agent-driven (no deterministic Python boundary). Operators infer:
```
synthesis_secs = total_a2a_response_secs − max(check_status timestamp)
```
Why no enforcement
This is reproduction-harness scaffolding. Adds zero behavior. The `logger.info` calls flow into the existing workspace log stream — no new infrastructure, no per-task DB writes, no metric emission yet. When V1.0 ships and per-task phase data lands in the structured heartbeat payload, these lines get stripped (commit message documents this for the future cleanup).
Tests
How operators use it
After this PR merges + a redeploy of any coordinator workspace:
```
railway logs --service controlplane | grep "rfc2251_phase="
```
Refs
🤖 Generated with Claude Code