feat(observability): correlation envelope across orchestrator logs, TaskEvents, agent OTel (#245)#557
Conversation
…askEvents, agent OTel (#245) Make the {task_id, user_id, repo, trace_id} correlation envelope observable on every plane so a task's actions join across CloudWatch logs, TaskEvents, and the X-Ray trace without manual stitching. Builds on #515, which already persists otel_trace_id on the TaskRecord (the orchestrator<->agent bridge). Phase 0 — contract: - docs/design/OBSERVABILITY.md: "Correlation envelope" section — field table (repo/trace_id/session_id nullable), shared snake_case naming with #215/#237/ #249, and the join model (TaskRecord bridges the two planes; no single W3C root since the orchestrator runs before the agent trace exists). Starlight mirror synced. Phase 1 — orchestrator (TS): - logger.ts: add logger.child(context) merging a persistent envelope into every line; per-call data wins on collision. - orchestrate-task.ts + shared/orchestrator.ts: derive a child logger in the lifecycle functions (orchestrate handler, finalizeTask, hydrateAndTransition, failTask) so admission->terminal log lines carry {task_id, user_id, repo}. - emitTaskEvent gains an optional EventCorrelation param; lifecycle events now stamp user_id/repo as top-level fields (repo omitted for repo-less workflows). Phase 1 — agent (Python): - progress_writer.py: _ProgressWriter takes user_id/repo; _put_event stamps {user_id, repo, trace_id} (trace_id read per-event from the active span) so the agent event stream joins to X-Ray. Optional fields omitted, never null. - observability.py: set_session_id propagates user.id/repo.url baggage, guarding each field (empty/None not stamped). - pipeline.py: root task.pipeline span gains user.id; both writer sites pass the envelope. server.py: propagate even when session_id is empty. Phase 2 needs no new code: #515's TaskRecord.otel_trace_id plus the agent event trace_id stamping give the cross-plane join. Both _ProgressWriters are built inside an active span, so trace_id is always valid. Tests: logger child-merge (4), orchestrate-task envelope incl. repo-less (3), progress_writer envelope incl. omit-not-null (4), set_session_id incl. empty session (3). No #209 SessionRole regression (user_id is read-only here). CDK 2236 pass, agent 1132 pass; eslint/ruff/docs-sync clean.
b149876 to
c2e3b11
Compare
…coverage Review (4 plugin agents) found no blocking issues; addressed the three substantive items: - silent-failure (MEDIUM): current_otel_trace_id() is read inside progress_writer._put_event's DDB try-block. If a misconfigured tracer raised, the error was caught by the DDB handler, misclassified as "unknown", and tripped the SHARED progress circuit breaker — silencing the whole event stream (turns, milestones, #251 agent_blocked) over a tracing fault. Make current_otel_trace_id() never raise: a tracer error degrades to None (its documented graceful-missing contract), so the trace_id field is simply omitted. Fixes every caller, incl. #515's crash-path persistence. - type coherence: narrow EventCorrelation.repo and failTask's repo param from `string | null` to `string | undefined`, matching the source TaskRecord.repo (never null). Removes the redundant third "absent" state; consumers already omit-on-falsy so behavior is unchanged. tsc + eslint clean. - test coverage: add the highest-value missing test — _run_task_background reaches set_session_id with the envelope on the empty-session/known-user branch (the widened trigger the feature depends on). Add a defensive test that a throwing tracer degrades current_otel_trace_id() to None. Skipped (churn > value, behavior already correct): failTask→EventCorrelation refactor, Python str=""-vs-None normalization, level/message collision guard. agent 1182 pass, CDK orchestrate-task+logger 107 pass; ruff/eslint/tsc clean.
CI 'Fail build on mutation' tripped: ruff format rewrote the backslash line-continuation `with` statements in the two new test files into the parenthesized multi-context-manager form. Apply the formatter locally and commit, matching the repo convention. No behavior change.
…nits Independent review follow-ups (all non-blocking) folded into this PR: 1. API passthrough (#1): the {user_id, repo, trace_id} envelope was stamped on TaskEvents in DDB but stripped by get-task-events.ts and get-task-replay.ts, so bgagent watch/events/replay never surfaced per-event correlation. Add the three optional fields to EventRecord + ReplayEvent (cdk) and TaskEvent + ReplayEvent (cli mirror), and pass them through in both handlers (omit-when- absent). API_CONTRACT.md documents the per-event envelope; types-sync clean. 2. Coverage docs (#2): OBSERVABILITY.md now notes task_created predates the envelope and joins by task_id alone, and that CLI consumers can join at the task level via TaskRecord.otel_trace_id. 3. Doc wording (#3): correlation-envelope table says repo is "absent (key omitted, not null/'')" for repo-less workflows, matching the implementation (#248) instead of the earlier "null". 4. Consistency (#4): failTask's transition-failure log and loadBlueprintConfig now use logger.child({task_id,user_id?,repo?}) like the rest of the lifecycle code, instead of base logger + inlined fields. Tests: direct emitTaskEvent(..., correlation) unit tests (stamp / repo-less omit / back-compat no-envelope); get-task-events + get-task-replay passthrough incl. task_created omission. CDK 2256 pass + synth clean; CLI 578 pass; agent 1182 pass; eslint/ruff/tsc/ types-sync/docs-sync clean.
Update — API passthrough follow-up + re-verified liveSince the initial Phases 0–2 work, folded in the independent-review follow-ups and re-ran the live suite against a fresh deploy. What was added (commit
|
| Scenario | Status | user_id |
repo |
trace_id (agent events) |
|---|---|---|---|---|
| Repo-less | COMPLETED | <user> ✅ |
absent ✅ | 6a4eb357… ✅ |
| Code repo | RUNNING | <user> ✅ |
<owner>/agent-plugins ✅ |
6a4eb380… ✅ |
| Fail-fast (pre-flight) | FAILED | <user> ✅ |
<owner>/agent-plugins ✅ |
n/a (failed before agent ran) |
task_created carries no envelope on all three; everything from hydration_started onward carries user_id/repo; agent events add trace_id. Fail-fast: both preflight_failed and task_failed carry user_id + repo.
API passthrough (invoked the GetTaskEvents / GetTaskReplay Lambdas with owner-scoped payloads):
GET /tasks/{id}/events— repo-less:task_createdhas no envelope,session_startedcarriesuser_id(repo absent), agent events carryuser_id+trace_id. Code repo: same plusrepo. Omit-when-absent confirmed on the wire (keys genuinely absent, notnull).GET /tasks/{id}/replay— bundle returnedotel_trace_id, events carried the envelope, and the join assertionbundle.otel_trace_id === event.trace_idpassed.
Cross-plane bridge — on the completed repo-less task, agent-event trace_id == TaskRecord.otel_trace_id == replay-bundle otel_trace_id (all 6a4eb357…). The code-repo task was still RUNNING, so its otel_trace_id isn't persisted on the TaskRecord yet (written at terminal) — expected; its events already carry the trace id, so the bridge completes on finalize. Fail-fast: otel_trace_id null (no agent trace), events join by task_id/user_id.
Net: the envelope stamping and the newly-deployed API passthrough both work end-to-end. Verified via direct Lambda invoke (no bgagent binary in the verification env; the handler + auth path are exercised identically to a real API call).
ayushtr-aws
left a comment
There was a problem hiding this comment.
Review — correlation envelope across orchestrator logs, TaskEvents, agent OTel
Verdict: well-executed — approve with minor comments. The design is documented before the code, the omit-not-null contract is enforced consistently at every write and read site, and tests cover the new branches including failure paths. I verified coverage against the branch: all 9 emitTaskEvent call sites in orchestrator.ts and all 3 in orchestrate-task.ts carry correlation (task_created is written in create-task-core.ts and is documented as pre-envelope), and both _ProgressWriter construction sites (pipeline.py, runner.py) pass the envelope.
Strengths
current_otel_trace_idhardening is thoughtful: the newtry/exceptexists specifically because callers read it inside the DDB-write try-block, where a tracer fault would be misclassified as a DDB failure and trip the progress circuit breaker. The comment explains this and there's a dedicated regression test.- Consistent optional-field contract:
if value:guards on the Python write side,...(x && { x })spreads on the TS side, and tests assert key absence at every layer — writer,emitTaskEvent, API pass-through, and replay bundle. - The widened trigger in
server.py(if session_id or user_id or repo_url:) correctly handles the empty-session case, andset_session_idnow guards each field so an emptysession_idno longer writes empty-string baggage — with a test for exactly that branch. - Durable-execution awareness preserved: correlation was added without disturbing the transition-gated emit logic or the duplicate-event-on-retry protections.
logger.childis minimal and correct: immutable merge, per-call data wins, composable, base logger unaffected — all four properties tested.- The cross-plane join holds by construction: the agent's
repo_urlis fed fromtask.repo(orchestrator.tspayload assembly), so agent-eventrepovalues match orchestrator-eventrepovalues exactly.
Minor issues
-
set_session_idis now misnamed (agent/src/observability.py). It propagates the full correlation envelope, not just the session id —server.pyeven calls it whensession_idis empty. Consider renaming (e.g.propagate_correlation_context); as-is, a reader seeingset_session_id("")has to go read the docstring to understand why that's not a bug. -
Stray
// ponytail:marker (cdk/src/handlers/shared/logger.ts:40). The comment content is useful; the prefix looks like a leftover codename/typo and should go. -
loadBlueprintConfig's child logger omitsuser_id(cdk/src/handlers/shared/orchestrator.ts). It buildslogger.child({ task_id, ...repo })while every other lifecycle function includesuser_id, andtask.user_idis in scope. This leaves the blueprint-load log lines (including thepoll_interval_ms clampedwarning) short of the "admission→terminal lines carry{task_id, user_id, repo}" acceptance criterion. One-token fix. -
Envelope-construction duplication in TS:
logger.child({ task_id, user_id, ...(task.repo && { repo: task.repo }) })plus a parallelEventCorrelationliteral is hand-rolled in four places. A smallenvelopeFor(task)helper returning{ log, correlation }would prevent the drift that already produced item 3. -
Type asymmetry in Python params:
user_id: str = ""vsrepo: str | None = Nonein bothset_session_idand_ProgressWriter. It mirrors the upstream config types, but mixing absent-value conventions (""vsNone) within one envelope invites mistakes; a short comment on why they differ would help. -
Test brittleness (very minor):
test_sets_all_envelope_fields_when_presentasserts the exact order of baggage keys. Order isn't part of the contract; a set/sorted comparison would survive harmless reordering.
Security / risk
user_id(Cognito sub) now lands in CloudWatch logs and DDB items — an opaque UUID, and attribution is the explicit purpose of the feature. The API handlers only return events for tasks the caller is authorized on, so no new exposure surface.- The broad
except Exceptionincurrent_otel_trace_idis a silent-success mask, but it's narrowly scoped, justified in docstring +nosemgrepannotation, and tested. - No schema/infra changes: DDB items gain optional attributes only, so old readers and pre-envelope items are unaffected (explicit back-compat test for the historical item shape).
Test coverage
Strong: logger child-merge semantics, lifecycle event correlation including repo-less omission, emitTaskEvent back-compat, _ProgressWriter omit-not-null in all combinations, tracer fail-open, empty-session baggage propagation, and API pass-through in both events and replay handlers. The one seam not directly unit-tested is failTask's new repo param on the successful-transition path, but it's exercised transitively and via the live fail-fast verification in the PR description.
None of the above is blocking; items 1–3 are worth a quick follow-up commit before merge.
isadeks
left a comment
There was a problem hiding this comment.
Approve with nits ✅
Clean, well-executed observability plumbing. Threads the {task_id, user_id, repo, trace_id} envelope across orchestrator logs (logger.child), TaskEvents (EventCorrelation on emitTaskEvent + agent-side _ProgressWriter stamping), and OTel baggage/spans. Strong test suite + live dev verification of the cross-plane trace_id == TaskRecord.otel_trace_id join. No correctness bugs or regressions found — the findings below are all minor.
Verified clean (the subtle bits)
- Spread patterns omit correctly — reproduced
...(correlation?.user_id && {…})and theget-task-eventspassthrough in Node: empty-string/undefinedfields are cleanly omitted, never stamped as""/null, matching the "omitted, not null" contract. - No PII leak to external channels — the TaskEvents NEW_IMAGE stream feeds
FanOutConsumer(Slack/GitHub/email), butparseStreamRecordwhitelists fields (task_id,event_id,event_type,timestamp,metadata); the new top-leveluser_id/repo/trace_id(incl. the Cognitosub) are not forwarded. - Trace-read can't trip the circuit breaker —
trace_id = current_otel_trace_id()is inside_put_event's try-block, but the function now swallows all exceptions →None, so a tracer fault won't be misclassified as a DDB failure. - All call sites consistent — all 9
failTaskcalls gottask.repo(optional param → back-compat); all 12emitTaskEventcalls well-formed;finalizeTask'suserIdparam andtask.user_idreference the same (immutable) task;failTask's catch-scopedlogis used only in-scope with the correctuserId. set_session_idhas one guarded caller (server.py,if session_id or user_id or repo_url) on a single-task thread → the never-detachedcontext.attachis genuinely thread-scoped.
Findings (all minor)
🟡 1. loadBlueprintConfig's child logger omits user_id — cdk/src/handlers/shared/orchestrator.ts:222
const log = logger.child({ task_id: task.task_id, ...(task.repo && { repo: task.repo }) });Every other function converted in this PR (hydrateAndTransition, finalizeTask, failTask, the durableHandler) includes user_id: task.user_id, and it's available on the TaskRecord here too. The comment even says this logger is "matching the orchestrate handler's child logger" — but the handler's carries user_id and this one doesn't. So the three blueprint-load lines won't surface in a CloudWatch Insights query filtered on user_id, defeating the per-line-envelope goal for this function. Not a regression, but the one I'd actually fix (one line: add user_id: task.user_id).
🟡 2. repo ""-vs-None contract drift — agent/src/pipeline.py:692 + runner.py:490 pass repo=config.repo_url (which is "", never None, for repo-less tasks), while server.py:460 normalizes repo=repo_url or None, and _ProgressWriter's comment says "repo is None for repo-less workflows." Harmless today (_put_event guards if self._repo:, so "" and None both omit the key), but the stored contract is violated and the three producers disagree — a latent trap for any consumer that distinguishes is None from == "". Suggest config.repo_url or None in pipeline/runner.
⚪ 3. Logger clobber footgun (latent only) — logger.ts serializes { level, message, ...context, ...data }, so a caller-supplied data.message/data.level would override the positional args. No current caller does this, and the ordering matches the pre-PR logger, so there's no active bug — just a sharp edge worth a comment.
⚪ 4. progress_writer now eagerly imports opentelemetry (posture note) — the new from observability import current_otel_trace_id forces an eager opentelemetry import at module-load, and the docstring advertises fail-open import safety. But that safety is specifically about boto3 (lazily imported); observability/opentelemetry is already eagerly imported by pipeline.py:29 and is a hard prod dep (aws-opentelemetry-distro==0.18.0), so practical risk ≈ nil. Noting only for completeness.
Bottom line
Solid, low-risk, no blockers. #1 is the only one worth changing before merge (restores the PR's own invariant); #2 is a nice consistency tidy; #3/#4 are optional.
Findings verified against the feat/245-observability-attribution checkout, including direct Node repro of the spread patterns and a trace of the fanout stream field-extraction.
…printConfig user_id
Second independent review (ayushtr-aws, approve-with-minor): all 6 minor items.
1. Rename set_session_id → propagate_correlation_context (observability.py): it
propagates the full envelope, not just session id, and is called with an
empty session_id — the old name misled. Updated the sole caller (server.py)
and tests.
2. Drop the stray "// ponytail:" marker prefix in logger.ts (kept the content).
3. loadBlueprintConfig's child logger now carries user_id (was task_id/repo
only) — its log lines are admission→terminal and must join by user_id per AC.
4. Extract envelopeFor(task) → { log, correlation } in orchestrator.ts, the
single source for the log child and the event correlation. Replaces the
hand-rolled logger.child + EventCorrelation literal duplicated across 5 sites
(orchestrate-task, hydrateAndTransition, finalizeTask, failTask,
loadBlueprintConfig) — the drift that produced item 3.
5. Comment on the Python ""-vs-None param asymmetry in
propagate_correlation_context (mirrors upstream config types).
6. set-compare baggage keys in the observability test instead of exact order
(order isn't part of the contract).
Tests: envelopeFor unit tests (log child carries user_id incl. repo-less
omission); observability/server tests updated for the rename.
CDK 2258 pass + synth clean; agent 1182 pass; eslint/ruff/ruff-format/tsc clean.
|
Thanks for the thorough review — all 6 items addressed in
On the one seam you flagged as not directly unit-tested — CDK 2258 pass + synth clean, agent 1182 pass, eslint/ruff/tsc all clean. |
theagenticguy
left a comment
There was a problem hiding this comment.
Approve. Reviewed the full diff and spot-verified the load-bearing claims against the source rather than trusting the description:
logger.childmerge precedence is correct —{ level, message, ...context, ...data }spreads per-calldatalast, so it wins on collision as documented.- Omit-not-null is done right on both planes: TS
...(task.repo && { repo })and Python guards (if user_id:/if repo:/if trace_id:). Absent fields are omitted, nevernull/""— important for the repo-less contract (#248). task.repois threaded through the failure path (failTask), sopreflight_failed/task_failedalso carry correlation.
Tests cover the new paths (logger child-merge, orchestrate-task envelope incl. repo-less, progress_writer omit-not-null, set_session_id empty-session, background trace-read fail-open), CI is green across the board, and scope is cleanly deferred to #555/#556. Nice, well-documented change. 🤖
What
Phases 0–2 of #245 — make the
{task_id, user_id, repo, trace_id}correlation envelope observable on every plane, so a task's actions join across CloudWatch logs, TaskEvents, and the X-Ray trace without manual stitching.Builds on #515, which already persists
otel_trace_idon theTaskRecord(the durable orchestrator↔agent bridge).Why
Vision tenet 7 (observable, attributable, replayable). Answers "who triggered this, on which repo, in which task?" for incident response, feeds #237's audit
correlationblock from real propagated context, and lets #215 Bedrock cost logs join to spans by sharedtrace_id/task_id.Changes
Phase 0 — contract
docs/design/OBSERVABILITY.md: "Correlation envelope" section — field table (repo/trace_id/session_idnullable), shared snake_case naming with feat: Bedrock cost attribution — session tags, request metadata, and operator FinOps guidance #215/RFC: Governance planes — analytics and compliance export #237/RFC: Identity propagation — composable credential delegation via AgentCore Identity Token Vault #249, and the join model: theTaskRecordbridges the two planes; there is no single W3C trace root because the orchestrator runs before the agent trace exists. Starlight mirror synced.Phase 1 — orchestrator (TS)
logger.ts:logger.child(context)merges a persistent envelope into every line (per-call data wins on collision).orchestrate-task.ts+shared/orchestrator.ts: lifecycle functions (orchestrate handler,finalizeTask,hydrateAndTransition,failTask) log via a child logger, so admission→terminal lines carry{task_id, user_id, repo}.emitTaskEventgains an optionalEventCorrelationparam; lifecycle events stampuser_id/repoas top-level fields (repoomitted for repo-less workflows, feat(tasks): capability-driven tasks — declarative steps, non-coding workflows, migrate existing task types #248).Phase 1 — agent (Python)
progress_writer.py:_ProgressWritertakesuser_id/repo;_put_eventstamps{user_id, repo, trace_id}(trace_id read per-event from the active span) — the agent event stream now joins to X-Ray. Optional fields omitted, never null.observability.py:set_session_idpropagatesuser.id/repo.urlbaggage, guarding each field (empty/None not stamped).pipeline.py: roottask.pipelinespan gainsuser.id; both writer sites pass the envelope.server.py: propagate even whensession_idis empty.Phase 2 — no new code. #515's
TaskRecord.otel_trace_id+ the Phase 1 eventtrace_idstamping give the cross-plane join. Both_ProgressWriters are constructed inside an active span, sotrace_idis always valid.Acceptance criteria (#245)
{task_id, user_id, repo, trace_id}in orchestrator logs, admission→terminaltask_id/trace_iduser_idis read-only here)Deferred to child issues
Testing
set_session_idincl. empty session (3),_run_task_backgroundenvelope propagation + trace-read fail-open (2).Live verification (deployed,
dev)Three tasks submitted post-deploy, one per scenario. Values below are redacted —
user_idshown as<user>(same Cognito sub across all three), repo owners masked, trace ids shortened to an 8-hex prefix (the prefix equality is the point).user_idon eventsrepoon eventstrace_idon agent events<user>✅"")6a4ea846…✅<user>✅<owner>/agent-plugins✅6a4ea5de…✅<user>✅<owner>/agent-plugins✅Per-plane checks
Session started/Task already in terminal statelines showuser_id+repo(repo omitted for the repo-less task) — confirms thelogger.childwiring.user_idpresent on every event fromhydration_startedonward; pre-span events (task_created) correctly havetrace_idabsent — matching the documented "read per-event, omitted before the root span opens" behavior.preflight_failedandtask_failedcarryuser_id+repo, confirming thefailTaskcorrelation threading works on the failure path (review finding Installation: docker image inspect fails #1).repois genuinely absent (notnull/"") on both the events and theTaskRecord.Cross-plane join (the core deliverable) — agent-event
trace_idexactly equals theTaskRecord.otel_trace_id(#515 bridge) on both completed tasks:TaskRecord.otel_trace_idtrace_id6a4ea846…6a4ea846…6a4ea5de…6a4ea5de…null(no agent trace)task_id/user_idinstead)Net: from any plane you can reach the others —
orchestrator log → task_id → TaskRecord → otel_trace_id → agent events/X-Ray trace.