diff --git a/backend/src/lambda/__tests__/trace-query-handler.test.ts b/backend/src/lambda/__tests__/trace-query-handler.test.ts index 8bec4f3..cd6ae75 100644 --- a/backend/src/lambda/__tests__/trace-query-handler.test.ts +++ b/backend/src/lambda/__tests__/trace-query-handler.test.ts @@ -526,11 +526,16 @@ describe("TRACE_BACKEND=spans dispatch (design §3 dual-backend, §1 query mecha status: "Complete", results: [ [ - { field: "traceId", value: "1-5f84c7c1-000000000000000000000001" }, - { field: "spanId", value: "root-1" }, - { field: "name", value: "root-op" }, - { field: "startTimeUnixNano", value: "1000000000000" }, - { field: "endTimeUnixNano", value: "1001000000000" }, + { + field: "@message", + value: JSON.stringify({ + traceId: "5f84c7c1000000000000000000000001", + spanId: "root-1", + name: "root-op", + startTimeUnixNano: 1000000000000, + endTimeUnixNano: 1001000000000, + }), + }, ], ], }); @@ -551,7 +556,7 @@ describe("TRACE_BACKEND=spans dispatch (design §3 dual-backend, §1 query mecha expect(body).toHaveProperty("truncated"); expect(body).toHaveProperty("meta"); expect(body.traces).toHaveLength(1); - expect(body.traces[0].traceId).toBe("1-5f84c7c1-000000000000000000000001"); + expect(body.traces[0].traceId).toBe("5f84c7c1000000000000000000000001"); }); test("TRACE_BACKEND=spans, query Complete with zero rows + entry fresh -> status:indexing", async () => { @@ -688,22 +693,27 @@ describe("TRACE_BACKEND=spans dispatch (design §3 dual-backend, §1 query mecha expect(startCall).toBeDefined(); const input = (startCall!.args[0] as StartQueryCommand).input; expect(input.queryString).toContain( - 'filter `annotation.run_id` = "run-22222222-2222-2222-2222-222222222222"', + 'filter `attributes.run_id` = "run-22222222-2222-2222-2222-222222222222"', ); }); - test("TRACE_BACKEND=spans, admin raw traceId route queries aws/spans by traceId, response shape unchanged", async () => { + test("TRACE_BACKEND=spans, admin raw traceId route with an X-Ray-format id normalizes to 32-hex before querying aws/spans (finding a3d8a2ea #9)", async () => { process.env.TRACE_BACKEND = "spans"; logsMock.on(StartQueryCommand).resolves({ queryId: "q-h8" }); logsMock.on(GetQueryResultsCommand).resolves({ status: "Complete", results: [ [ - { field: "traceId", value: "1-5f84c7c1-000000000000000000000002" }, - { field: "spanId", value: "root-2" }, - { field: "name", value: "root-op-2" }, - { field: "startTimeUnixNano", value: "1000000000000" }, - { field: "endTimeUnixNano", value: "1001000000000" }, + { + field: "@message", + value: JSON.stringify({ + traceId: "5f84c7c1000000000000000000000002", + spanId: "root-2", + name: "root-op-2", + startTimeUnixNano: 1000000000000, + endTimeUnixNano: 1001000000000, + }), + }, ], ], }); @@ -720,6 +730,58 @@ describe("TRACE_BACKEND=spans dispatch (design §3 dual-backend, §1 query mecha expect(body.status).toBe("ready"); expect(body.traces).toHaveLength(1); expect(xrayMock.calls()).toHaveLength(0); + + const startCall = logsMock + .calls() + .find((c) => c.args[0] instanceof StartQueryCommand); + expect(startCall).toBeDefined(); + const input = (startCall!.args[0] as StartQueryCommand).input; + // Normalized to plain 32-hex — no `1-` prefix, no dash separators. + expect(input.queryString).toContain( + 'filter traceId = "5f84c7c1000000000000000000000002"', + ); + expect(input.queryString).not.toContain("1-5f84c7c1"); + }); + + test("TRACE_BACKEND=spans, admin raw traceId route with an already-32-hex id passes it through unchanged (finding a3d8a2ea #9, both formats)", async () => { + process.env.TRACE_BACKEND = "spans"; + logsMock.on(StartQueryCommand).resolves({ queryId: "q-h8b" }); + logsMock.on(GetQueryResultsCommand).resolves({ + status: "Complete", + results: [ + [ + { + field: "@message", + value: JSON.stringify({ + traceId: "6a7e5de027c150316d0ff197004e14b1", + spanId: "021348f2ab124f06", + name: "root-op-3", + startTimeUnixNano: 1000000000000, + endTimeUnixNano: 1001000000000, + }), + }, + ], + ], + }); + + const event = makeEvent( + "GET /traces/{traceId}", + { traceId: "6a7e5de027c150316d0ff197004e14b1" }, + { "custom:organization": "org-1", "custom:role": "admin" }, + ); + + const res = await handler(event); + expect(res.statusCode).toBe(200); + const body = JSON.parse(res.body!); + expect(body.traces).toHaveLength(1); + + const startCall = logsMock + .calls() + .find((c) => c.args[0] instanceof StartQueryCommand); + const input = (startCall!.args[0] as StartQueryCommand).input; + expect(input.queryString).toContain( + 'filter traceId = "6a7e5de027c150316d0ff197004e14b1"', + ); }); test("TRACE_BACKEND=spans, non-admin raw traceId route -> still 403, zero Logs Insights calls (invariant 2 unchanged)", async () => { @@ -1197,11 +1259,16 @@ describe("TRACE_BACKEND=spans — defensive filter rejects, failed-status mappin // SPANS_QUERY_ROW_LIMIT is 1000 — return exactly 1000 rows so // runSpanQuery reports truncated (rows.length >= limit). const results = Array.from({ length: 1000 }, (_, i) => [ - { field: "traceId", value: "1-5f84c7c1-00000000000000000000000e" }, - { field: "spanId", value: `span-${i}` }, - { field: "name", value: `op-${i}` }, - { field: "startTimeUnixNano", value: "1000000000000" }, - { field: "endTimeUnixNano", value: "1001000000000" }, + { + field: "@message", + value: JSON.stringify({ + traceId: "5f84c7c100000000000000000000000e", + spanId: `span-${i}`, + name: `op-${i}`, + startTimeUnixNano: 1000000000000, + endTimeUnixNano: 1001000000000, + }), + }, ]); logsMock.on(StartQueryCommand).resolves({ queryId: "q-trunc" }); logsMock @@ -1223,12 +1290,17 @@ describe("TRACE_BACKEND=spans — defensive filter rejects, failed-status mappin }); const metadataRow = [ - { field: "traceId", value: "1-5f84c7c1-00000000000000000000000f" }, - { field: "spanId", value: "meta-span-1" }, - { field: "name", value: "meta-op" }, - { field: "startTimeUnixNano", value: "1000000000000" }, - { field: "endTimeUnixNano", value: "1001000000000" }, - { field: "attributes.custom.stage", value: "prod" }, + { + field: "@message", + value: JSON.stringify({ + traceId: "5f84c7c100000000000000000000000f", + spanId: "meta-span-1", + name: "meta-op", + startTimeUnixNano: 1000000000000, + endTimeUnixNano: 1001000000000, + attributes: { custom: { stage: "prod" } }, + }), + }, ]; test("spans: includeMetadata=1 as ADMIN -> metadata bag included on spans (admin + explicit opt-in honored)", async () => { diff --git a/backend/src/lambda/trace-query-handler.ts b/backend/src/lambda/trace-query-handler.ts index 9276d90..57c8f6a 100644 --- a/backend/src/lambda/trace-query-handler.ts +++ b/backend/src/lambda/trace-query-handler.ts @@ -70,6 +70,25 @@ const xrayClient = new XRayClient({}); * start; a warm invocation reflects whatever the env held at that * cold-start snapshot, matching how every other env-driven Lambda config * in this codebase (e.g. AGENT_MODEL in services-stack.ts) is read. */ +/** Matches an X-Ray-format trace id: `1-{8hex}-{24hex}` (e.g. + * `1-5f84c7c1-000000000000000000000001`). */ +const XRAY_TRACE_ID_RE = /^1-([0-9a-f]{8})-([0-9a-f]{24})$/i; + +/** + * Normalizes an X-Ray-format traceId (`1-{8hex}-{24hex}`) to the plain + * 32-hex form aws/spans stores its `traceId` field as (verified: all + * sampled aws/spans traceIds are 32-hex with no `1-` prefix — evidence + * report finding a3d8a2ea, verdict #1). Any other shape (already 32-hex, + * or unrecognized) is passed through unchanged, so existing links minted + * before this normalization, and ids that are already in the spans-native + * form, keep working identically. + */ +export function normalizeToSpansTraceId(traceId: string): string { + const match = XRAY_TRACE_ID_RE.exec(traceId); + if (!match) return traceId; + return `${match[1]}${match[2]}`; +} + function traceBackend(): "xray" | "spans" { return process.env.TRACE_BACKEND === "spans" ? "spans" : "xray"; } @@ -440,7 +459,12 @@ async function handleRawTraceId( // form, checked at the route level by the admin gate above, never a // user-supplied filter target for annotation purposes here) and is // the natural Logs Insights equivalent of BatchGetTraces([traceId]). - const filter = buildSpanCorrelationFilter(traceId); + // Old links (minted while TRACE_BACKEND=xray) carry the X-Ray-format + // `1-{8hex}-{24hex}` id; aws/spans stores plain 32-hex (verified, + // evidence report finding a3d8a2ea) — normalize before filtering so + // those links keep resolving under the spans backend too. + const spansTraceId = normalizeToSpansTraceId(traceId); + const filter = buildSpanCorrelationFilter(spansTraceId); if (!filter.ok) { return json(200, { query: { kind: "traceId", id: traceId, correlationId: null }, @@ -454,7 +478,7 @@ async function handleRawTraceId( // Filter on traceId itself, not the correlation-id annotation — build // the clause directly rather than reusing the annotation-targeted // builder's field name. - const traceIdClause = `filter traceId = "${traceId}"`; + const traceIdClause = `filter traceId = "${spansTraceId}"`; const { traces, queryStatus } = await fetchTracesBySpanFilter( traceIdClause, new Date(Date.now() - DEFAULT_WINDOW_MS).toISOString(), diff --git a/backend/src/lambda/utils/__tests__/spans-query.test.ts b/backend/src/lambda/utils/__tests__/spans-query.test.ts index 568432d..996765f 100644 --- a/backend/src/lambda/utils/__tests__/spans-query.test.ts +++ b/backend/src/lambda/utils/__tests__/spans-query.test.ts @@ -19,21 +19,29 @@ beforeEach(() => { }); describe("runSpanQuery — happy path", () => { - test("Complete with rows -> queryStatus:complete, rows returned", async () => { + test("Complete with rows -> queryStatus:complete, @message JSON parsed+flattened into row fields", async () => { logsMock.on(StartQueryCommand).resolves({ queryId: "q-1" }); logsMock.on(GetQueryResultsCommand).resolves({ status: "Complete", results: [ [ - { field: "spanId", value: "span-1" }, - { field: "traceId", value: "trace-1" }, + { + field: "@message", + value: JSON.stringify({ + traceId: "6a7e5de027c150316d0ff197004e14b1", + spanId: "021348f2ab124f06", + name: "PopObservability-dev-CanaryFnEAA4AF84-rA1uxPLOe98U/LambdaService", + startTimeUnixNano: 1786666464924999936, + status: { code: "UNSET" }, + }), + }, ], ], }); const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -41,11 +49,31 @@ describe("runSpanQuery — happy path", () => { expect(result.queryStatus).toBe("complete"); expect(result.rows).toHaveLength(1); - expect(result.rows[0].spanId).toBe("span-1"); - expect(result.rows[0].traceId).toBe("trace-1"); + expect(result.rows[0].spanId).toBe("021348f2ab124f06"); + expect(result.rows[0].traceId).toBe("6a7e5de027c150316d0ff197004e14b1"); + expect(result.rows[0]["status.code"]).toBe("UNSET"); }); - test("passes logGroupName/startTime/endTime/queryString/limit through to StartQuery", async () => { + test("a malformed @message value is skipped without throwing, no fields surface for that row", async () => { + logsMock.on(StartQueryCommand).resolves({ queryId: "q-1b" }); + logsMock.on(GetQueryResultsCommand).resolves({ + status: "Complete", + results: [[{ field: "@message", value: "{not valid json" }]], + }); + + const result = await runSpanQuery({ + logGroupName: "aws/spans", + queryString: 'filter `attributes.correlation_id` = "exec-1"', + startTimeSec: 1000, + endTimeSec: 2000, + limit: 100, + }); + + expect(result.rows).toHaveLength(1); + expect(Object.keys(result.rows[0])).toHaveLength(0); + }); + + test("passes logGroupName/startTime/endTime/queryString/limit through to StartQuery, including the @message fields projection", async () => { logsMock.on(StartQueryCommand).resolves({ queryId: "q-2" }); logsMock .on(GetQueryResultsCommand) @@ -53,7 +81,7 @@ describe("runSpanQuery — happy path", () => { await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.run_id` = "run-1"', + queryString: 'filter `attributes.run_id` = "run-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 50, @@ -67,8 +95,13 @@ describe("runSpanQuery — happy path", () => { expect(input.logGroupName).toBe("aws/spans"); expect(input.startTime).toBe(1000); expect(input.endTime).toBe(2000); - expect(input.queryString).toContain("filter `annotation.run_id`"); + expect(input.queryString).toContain("filter `attributes.run_id`"); + expect(input.queryString).toContain("| fields @message"); expect(input.queryString).toContain("limit 50"); + // The fields projection must precede the limit clause. + expect(input.queryString!.indexOf("fields @message")).toBeLessThan( + input.queryString!.indexOf("limit 50"), + ); }); }); @@ -81,12 +114,14 @@ describe("runSpanQuery — bounded poll", () => { .resolvesOnce({ status: "Running", results: [] }) .resolves({ status: "Complete", - results: [[{ field: "spanId", value: "span-2" }]], + results: [ + [{ field: "@message", value: JSON.stringify({ spanId: "span-2" }) }], + ], }); const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -107,7 +142,7 @@ describe("runSpanQuery — bounded poll", () => { const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -133,7 +168,7 @@ describe("runSpanQuery — bounded poll", () => { const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -154,7 +189,7 @@ describe("runSpanQuery — failure statuses", () => { const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -174,7 +209,7 @@ describe("runSpanQuery — failure statuses", () => { const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -191,7 +226,7 @@ describe("runSpanQuery — failure statuses", () => { await expect( runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -208,7 +243,7 @@ describe("runSpanQuery — failure statuses", () => { await expect( runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -220,16 +255,18 @@ describe("runSpanQuery — failure statuses", () => { }); describe("runSpanQuery — row shape / malformed rows never throw", () => { - test("a row missing a value field is skipped for that field, never throws", async () => { + test("an @message cell whose JSON body omits a field leaves that field undefined, never throws", async () => { logsMock.on(StartQueryCommand).resolves({ queryId: "q-9" }); logsMock.on(GetQueryResultsCommand).resolves({ status: "Complete", - results: [[{ field: "spanId" }, { field: "traceId", value: "trace-9" }]], + results: [ + [{ field: "@message", value: JSON.stringify({ traceId: "trace-9" }) }], + ], }); const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 100, @@ -245,14 +282,14 @@ describe("runSpanQuery — row shape / malformed rows never throw", () => { logsMock.on(GetQueryResultsCommand).resolves({ status: "Complete", results: [ - [{ field: "spanId", value: "s1" }], - [{ field: "spanId", value: "s2" }], + [{ field: "@message", value: JSON.stringify({ spanId: "s1" }) }], + [{ field: "@message", value: JSON.stringify({ spanId: "s2" }) }], ], }); const result = await runSpanQuery({ logGroupName: "aws/spans", - queryString: 'filter `annotation.correlation_id` = "exec-1"', + queryString: 'filter `attributes.correlation_id` = "exec-1"', startTimeSec: 1000, endTimeSec: 2000, limit: 2, diff --git a/backend/src/lambda/utils/__tests__/spans-waterfall.test.ts b/backend/src/lambda/utils/__tests__/spans-waterfall.test.ts index f7d6249..fff611d 100644 --- a/backend/src/lambda/utils/__tests__/spans-waterfall.test.ts +++ b/backend/src/lambda/utils/__tests__/spans-waterfall.test.ts @@ -3,14 +3,13 @@ * `TraceEntry[]`/`TraceSpan[]` shaping (design §2 "aws/spans -> TraceEntry/ * TraceSpan mapping", §8 "spans-waterfall.test.ts"). * - * SCHEMA-VERIFICATION GATE (design §2, HIGH risk #1): the exact aws/spans - * field names used below are a captured Red-phase FIXTURE, not a verified - * real-account sample — spans-waterfall.ts itself carries the same - * unverified-schema comment at every field-name assumption. This fixture - * exists so the shaping/tree-building/allowlist LOGIC has test coverage - * now; the field names must be reconciled against a real Transaction - * Search span the first time TRACE_BACKEND=spans is exercised against a - * live account (see docs/TRACING_RUNBOOK.md cutover procedure). + * SCHEMA VERIFIED (evidence report, finding a3d8a2ea): fixtures below are + * built from the VERBATIM real span/subsegment events captured against + * `aws/spans` (2026-08-03 archived sample + 2026-08-14 fresh samples), + * already flattened the way spans-query.ts's flatten() would produce from + * the real nested JSON `@message` body. Structure is kept intact; PII + * (user-agent/IP) is [REDACTED]. See spans-waterfall.ts's module header + * for the field-name corrections this fixture set encodes. */ import { shapeSpanRows, type SpanQueryRowLike } from "../spans-waterfall"; @@ -19,37 +18,41 @@ function row(fields: Partial): SpanQueryRowLike { } describe("shapeSpanRows — tree building", () => { - test("root span with one child -> nested children[], same TraceEntry/TraceSpan shape as xray-waterfall", () => { + test("root segment with one subsegment child -> nested children[], same TraceEntry/TraceSpan shape as xray-waterfall", () => { const rows: SpanQueryRowLike[] = [ row({ - traceId: "1-5f84c7c1-000000000000000000000001", - spanId: "root-1", - parentSpanId: undefined, - name: "root-op", - startTimeUnixNano: "1000000000000", - endTimeUnixNano: "1002000000000", - "annotation.correlation_id": "exec-1", + traceId: "6a700e664c404f251827e0c81544e084", + spanId: "edcde8a7f824252d", + name: "citadel-document-ingest-poller-dev/LambdaExecutionEnvironment", + startTimeUnixNano: "1785728614687603968", + endTimeUnixNano: "1785728614718127104", + "status.code": "UNSET", + "_aws.xray.name": "citadel-document-ingest-poller-dev", + "_aws.xray.type": "segment", }), row({ - traceId: "1-5f84c7c1-000000000000000000000001", - spanId: "child-1", - parentSpanId: "root-1", - name: "child-op", - startTimeUnixNano: "1000500000000", - endTimeUnixNano: "1001000000000", + traceId: "6a700e664c404f251827e0c81544e084", + spanId: "144ee6e12cda94ee", + parentSpanId: "edcde8a7f824252d", + name: "", + startTimeUnixNano: "1785728614690000000", + endTimeUnixNano: "1785728614710000000", + "status.code": "UNSET", + "_aws.xray.name": "Attempt #1", + "_aws.xray.type": "subsegment", }), ]; const shaped = shapeSpanRows(rows, { includeMetadata: false }); expect(shaped.traces).toHaveLength(1); const entry = shaped.traces[0]; - expect(entry.traceId).toBe("1-5f84c7c1-000000000000000000000001"); + expect(entry.traceId).toBe("6a700e664c404f251827e0c81544e084"); expect(entry.spans).toHaveLength(1); - expect(entry.spans[0].id).toBe("root-1"); + expect(entry.spans[0].id).toBe("edcde8a7f824252d"); expect(entry.spans[0].parentId).toBeNull(); expect(entry.spans[0].children).toHaveLength(1); - expect(entry.spans[0].children[0].id).toBe("child-1"); - expect(entry.spans[0].children[0].parentId).toBe("root-1"); + expect(entry.spans[0].children[0].id).toBe("144ee6e12cda94ee"); + expect(entry.spans[0].children[0].parentId).toBe("edcde8a7f824252d"); }); test("a row whose parentSpanId is not in the set is treated as a root (orphan-safe)", () => { @@ -95,6 +98,99 @@ describe("shapeSpanRows — tree building", () => { }); }); +describe("shapeSpanRows — dedup of in-progress snapshot vs completed event (finding a3d8a2ea #5)", () => { + test("same spanId as in-progress snapshot (no endTimeUnixNano, aws.xray.inprogress) and completed event -> completed wins, no duplicate tree node", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "6a7e5de027c150316d0ff197004e14b1", + spanId: "021348f2ab124f06", + name: "PopObservability-dev-CanaryFnEAA4AF84-rA1uxPLOe98U/LambdaService", + startTimeUnixNano: "1786666464924999936", + // in-progress snapshot: no endTimeUnixNano + "attributes.aws.xray.inprogress": "true", + "status.code": "UNSET", + "_aws.xray.name": "PopObservability-dev-CanaryFnEAA4AF84-rA1uxPLOe98U", + "_aws.xray.type": "segment", + }), + row({ + traceId: "6a7e5de027c150316d0ff197004e14b1", + spanId: "021348f2ab124f06", + name: "PopObservability-dev-CanaryFnEAA4AF84-rA1uxPLOe98U/LambdaService", + startTimeUnixNano: "1786666464924999936", + endTimeUnixNano: "1786666467263000064", + "status.code": "UNSET", + "_aws.xray.name": "PopObservability-dev-CanaryFnEAA4AF84-rA1uxPLOe98U", + "_aws.xray.type": "segment", + }), + ]; + + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces).toHaveLength(1); + expect(shaped.traces[0].spans).toHaveLength(1); + const span = shaped.traces[0].spans[0]; + expect(span.id).toBe("021348f2ab124f06"); + expect(span.inProgress).toBe(false); + expect(span.endTime).not.toBeNull(); + }); + + test("two in-progress snapshots of the same spanId, no completed event yet -> keeps the latest snapshot, still one tree node", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "trace-dup", + spanId: "span-dup", + name: "snapshot-1", + startTimeUnixNano: "1000000000000", + "attributes.aws.xray.inprogress": "true", + }), + row({ + traceId: "trace-dup", + spanId: "span-dup", + name: "snapshot-2", + startTimeUnixNano: "1000000000000", + "attributes.aws.xray.inprogress": "true", + }), + ]; + + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans).toHaveLength(1); + expect(shaped.traces[0].spans[0].name).toBe("snapshot-2"); + expect(shaped.traces[0].spans[0].inProgress).toBe(true); + }); + + test("dedup applies across parent+child pairs without breaking tree assembly", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "trace-tree-dedup", + spanId: "root-1", + name: "root", + startTimeUnixNano: "1000000000000", + "attributes.aws.xray.inprogress": "true", + }), + row({ + traceId: "trace-tree-dedup", + spanId: "root-1", + name: "root", + startTimeUnixNano: "1000000000000", + endTimeUnixNano: "1005000000000", + }), + row({ + traceId: "trace-tree-dedup", + spanId: "child-1", + parentSpanId: "root-1", + name: "", + startTimeUnixNano: "1001000000000", + endTimeUnixNano: "1002000000000", + "_aws.xray.name": "Attempt #1", + }), + ]; + + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans).toHaveLength(1); + expect(shaped.traces[0].spans[0].children).toHaveLength(1); + expect(shaped.traces[0].spans[0].inProgress).toBe(false); + }); +}); + describe("shapeSpanRows — field mapping", () => { test("startTimeUnixNano/endTimeUnixNano map to epoch-seconds startTime/endTime, durationMs computed", () => { const rows: SpanQueryRowLike[] = [ @@ -131,7 +227,7 @@ describe("shapeSpanRows — field mapping", () => { expect(span.durationMs).toBe(0); }); - test("http status mapped from attributes.http.response.status_code fallback http.status_code", () => { + test("http status mapped from attributes.http.response.status_code, fallback attributes.http.status_code (attributes-prefixed, finding a3d8a2ea #7/#8)", () => { const rows: SpanQueryRowLike[] = [ row({ traceId: "trace-1", @@ -147,7 +243,9 @@ describe("shapeSpanRows — field mapping", () => { name: "op2", startTimeUnixNano: "1000000000000", endTimeUnixNano: "1001000000000", - "http.status_code": "429", + // fallback key is attributes-prefixed, per the real subsegment + // sample (attributes.http.status_code), NOT bare http.status_code + "attributes.http.status_code": "429", }), ]; @@ -156,7 +254,54 @@ describe("shapeSpanRows — field mapping", () => { expect(shaped.traces[1].spans[0].http).toEqual({ status: 429 }); }); - test("annotation.* attributes surface on TraceEntry.annotations, pinned correlation_id/run_id keys survive", () => { + test("a bare (non-attributes-prefixed) http.status_code fallback key is NOT honored (negative case for #7)", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "trace-bare-http", + spanId: "s1", + name: "op", + startTimeUnixNano: "1000000000000", + endTimeUnixNano: "1001000000000", + "http.status_code": "429", + }), + ]; + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans[0].http).toBeNull(); + }); + + test("subsegment name falls back to _aws.xray.name when top-level name is empty (finding a3d8a2ea #6)", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "trace-subseg-name", + spanId: "s1", + name: "", + startTimeUnixNano: "1786666464967000064", + endTimeUnixNano: "1786666467263000064", + "_aws.xray.name": "Attempt #1", + "_aws.xray.type": "subsegment", + }), + ]; + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans[0].name).toBe("Attempt #1"); + }); + + test("namespace mapped from _aws.xray.namespace, not attributes.namespace (finding a3d8a2ea #6/#11)", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "trace-ns", + spanId: "s1", + name: "partner-offering-api-dev", + startTimeUnixNano: "1786666467044000000", + endTimeUnixNano: "1786666467046999808", + "_aws.xray.namespace": "aws", + "attributes.namespace": "should-be-ignored", + }), + ]; + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans[0].namespace).toBe("aws"); + }); + + test("annotations extracted from attributes. enumerated by attributes.aws.xray.annotation_keys, not an annotation. prefix (finding a3d8a2ea #7)", () => { const rows: SpanQueryRowLike[] = [ row({ traceId: "trace-1", @@ -164,8 +309,12 @@ describe("shapeSpanRows — field mapping", () => { name: "op", startTimeUnixNano: "1000000000000", endTimeUnixNano: "1001000000000", - "annotation.correlation_id": "exec-1", - "annotation.run_id": "run-1", + "attributes.aws.xray.annotation_keys": JSON.stringify([ + "correlation_id", + "run_id", + ]), + "attributes.correlation_id": "exec-1", + "attributes.run_id": "run-1", }), ]; @@ -174,6 +323,28 @@ describe("shapeSpanRows — field mapping", () => { expect(shaped.traces[0].annotations.run_id).toBe("run-1"); }); + test("real AppSync annotation_keys sample (request_id) extracts via the array, an annotation.* prefixed field is ignored (negative case)", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "6a7e5de3482f491c1277d50434df3636", + spanId: "5a075ffebf0c12fe", + name: "POST /graphql", + startTimeUnixNano: "1786666467044000000", + endTimeUnixNano: "1786666467046999808", + "attributes.aws.xray.annotation_keys": JSON.stringify(["request_id"]), + "attributes.request_id": "d1edb09a-360f-4075-9876-d1ffbcbbec97", + // Should NOT be picked up — annotation. prefix does not exist on + // the real schema and must not be treated as a source. + "annotation.request_id": "wrong-shape-should-be-ignored", + }), + ]; + + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].annotations.request_id).toBe( + "d1edb09a-360f-4075-9876-d1ffbcbbec97", + ); + }); + test("metadata/aws/sql dropped by default, present only with includeMetadata:true (allowlist invariant 5)", () => { const rows: SpanQueryRowLike[] = [ row({ @@ -195,7 +366,7 @@ describe("shapeSpanRows — field mapping", () => { }); describe("shapeSpanRows — status trichotomy (best-effort OTel -> ok|error|fault|throttle)", () => { - test("ERROR + http>=500 -> fault", () => { + test("status.code=ERROR + http>=500 -> fault", () => { const rows: SpanQueryRowLike[] = [ row({ traceId: "t1", @@ -203,7 +374,7 @@ describe("shapeSpanRows — status trichotomy (best-effort OTel -> ok|error|faul name: "op", startTimeUnixNano: "1000000000000", endTimeUnixNano: "1001000000000", - statusCode: "ERROR", + "status.code": "ERROR", "attributes.http.response.status_code": "503", }), ]; @@ -228,21 +399,38 @@ describe("shapeSpanRows — status trichotomy (best-effort OTel -> ok|error|faul expect(shaped.traces[0].hasThrottle).toBe(true); }); - test("ERROR without 5xx/429 -> error", () => { + test("real ERROR AppSync 401 sample: status.code=ERROR, http=401 -> error (not fault, not ok) — finding a3d8a2ea #5", () => { const rows: SpanQueryRowLike[] = [ row({ - traceId: "t1", + traceId: "6a7e5de3482f491c1277d50434df3636", + spanId: "5a075ffebf0c12fe", + name: "POST /graphql", + startTimeUnixNano: "1786666467044000000", + endTimeUnixNano: "1786666467046999808", + "status.code": "ERROR", + "attributes.http.response.status_code": "401", + "attributes.aws.xray.error": "true", + }), + ]; + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans[0].status).toBe("error"); + expect(shaped.traces[0].hasError).toBe(true); + expect(shaped.traces[0].hasFault).toBe(false); + }); + + test("a bare (non-flattened) statusCode:'ERROR' field is NOT honored — must be status.code (negative case for #4)", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "t-bare-status", spanId: "s1", name: "op", startTimeUnixNano: "1000000000000", endTimeUnixNano: "1001000000000", statusCode: "ERROR", - "attributes.http.response.status_code": "400", }), ]; const shaped = shapeSpanRows(rows, { includeMetadata: false }); - expect(shaped.traces[0].spans[0].status).toBe("error"); - expect(shaped.traces[0].hasError).toBe(true); + expect(shaped.traces[0].spans[0].status).toBe("ok"); }); test("no error signal -> ok", () => { @@ -260,6 +448,61 @@ describe("shapeSpanRows — status trichotomy (best-effort OTel -> ok|error|faul }); }); +describe("shapeSpanRows — error/exception message (finding a3d8a2ea #8)", () => { + test("_aws.xray.cause.message fallback surfaces the real ERROR span's cause text when attributes.exception.* is absent", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "6a7e5de3482f491c1277d50434df3636", + spanId: "5a075ffebf0c12fe", + name: "POST /graphql", + startTimeUnixNano: "1786666467044000000", + endTimeUnixNano: "1786666467046999808", + "status.code": "ERROR", + "_aws.xray.cause.message": "Valid authorization header not provided.", + }), + ]; + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans[0].error).toEqual({ + type: "Error", + message: "Valid authorization header not provided.", + }); + }); + + test("attributes.exception.message still takes priority over _aws.xray.cause.message when both are present", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "t1", + spanId: "s1", + name: "op", + startTimeUnixNano: "1000000000000", + endTimeUnixNano: "1001000000000", + "attributes.exception.message": "otel exception message", + "attributes.exception.type": "CustomError", + "_aws.xray.cause.message": "xray cause message", + }), + ]; + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans[0].error).toEqual({ + type: "CustomError", + message: "otel exception message", + }); + }); + + test("neither key present -> error null", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "t1", + spanId: "s1", + name: "op", + startTimeUnixNano: "1000000000000", + endTimeUnixNano: "1001000000000", + }), + ]; + const shaped = shapeSpanRows(rows, { includeMetadata: false }); + expect(shaped.traces[0].spans[0].error).toBeNull(); + }); +}); + describe("shapeSpanRows — malformed rows never throw (invariant-4 analog)", () => { test("a row missing spanId is skipped entirely", () => { const rows: SpanQueryRowLike[] = [ @@ -288,6 +531,23 @@ describe("shapeSpanRows — malformed rows never throw (invariant-4 analog)", () ); }); + test("a row with a malformed attributes.aws.xray.annotation_keys value (not JSON array) is skipped for annotation extraction, never throws", () => { + const rows: SpanQueryRowLike[] = [ + row({ + traceId: "t1", + spanId: "s1", + name: "op", + startTimeUnixNano: "1000000000000", + endTimeUnixNano: "1001000000000", + "attributes.aws.xray.annotation_keys": "{not valid json", + }), + ]; + expect(() => shapeSpanRows(rows, { includeMetadata: false })).not.toThrow(); + expect( + shapeSpanRows(rows, { includeMetadata: false }).traces[0].annotations, + ).toEqual({}); + }); + test("empty rows array -> empty traces, never throws", () => { expect(() => shapeSpanRows([], { includeMetadata: false })).not.toThrow(); expect(shapeSpanRows([], { includeMetadata: false }).traces).toHaveLength( diff --git a/backend/src/lambda/utils/__tests__/trace-span-query.test.ts b/backend/src/lambda/utils/__tests__/trace-span-query.test.ts index 0453dca..bdbba9c 100644 --- a/backend/src/lambda/utils/__tests__/trace-span-query.test.ts +++ b/backend/src/lambda/utils/__tests__/trace-span-query.test.ts @@ -67,7 +67,7 @@ describe("buildSpanCorrelationFilter", () => { expect(result.ok).toBe(true); if (result.ok) { expect(result.clause).toBe( - 'filter `annotation.correlation_id` = "exec-1"', + 'filter `attributes.correlation_id` = "exec-1"', ); } }); @@ -86,7 +86,7 @@ describe("buildSpanRunIdFilter", () => { expect(result.ok).toBe(true); if (result.ok) { expect(result.clause).toBe( - 'filter `annotation.run_id` = "run-11111111-1111-1111-1111-111111111111"', + 'filter `attributes.run_id` = "run-11111111-1111-1111-1111-111111111111"', ); } }); diff --git a/backend/src/lambda/utils/spans-query.ts b/backend/src/lambda/utils/spans-query.ts index ca07377..d7fe745 100644 --- a/backend/src/lambda/utils/spans-query.ts +++ b/backend/src/lambda/utils/spans-query.ts @@ -70,14 +70,61 @@ const IN_PROGRESS_STATUSES = new Set(["Scheduled", "Running"]); * Cancelled/Timeout status: log + fall back to window mapping"). */ const FAILED_STATUSES = new Set(["Failed", "Cancelled", "Timeout"]); +/** Flattens a nested JSON value into dot-notation string keys (e.g. + * `{status:{code:"ERROR"}}` -> `{"status.code":"ERROR"}`), matching the + * flattened-field naming Logs Insights itself uses when a field is + * projected directly (e.g. `status.code`, `_aws.xray.name`). Arrays are + * kept as JSON-stringified leaves (e.g. `aws.xray.annotation_keys`) + * rather than flattened by index, since callers consume them as whole + * lists, not per-element fields. */ +function flatten(value: unknown, prefix: string, out: SpanQueryRow): void { + if (Array.isArray(value)) { + out[prefix] = JSON.stringify(value); + return; + } + if (value !== null && typeof value === "object") { + for (const [key, child] of Object.entries( + value as Record, + )) { + flatten(child, prefix.length > 0 ? `${prefix}.${key}` : key, out); + } + return; + } + if (value === null || value === undefined) return; + out[prefix] = typeof value === "string" ? value : String(value); +} + +/** + * Row shape once `| fields @message` is projected (see runSpanQuery + * below): each result row carries exactly one cell, `@message`, holding + * the full JSON document for that span event (verified: probe A showed + * an unprojected query returns only `@timestamp`/`@message`/`@ptr`, and + * `row.spanId`/`row.traceId` were undefined — evidence report finding + * a3d8a2ea). Parsing + flattening `@message` here recovers the nested + * `status.code`, `_aws.xray.*`, and `attributes.*` field names the rest + * of the spans pipeline (trace-span-query.ts/spans-waterfall.ts) expects, + * without changing the flat `SpanQueryRow` contract downstream. + */ function rowToObject( row: Array<{ field?: string; value?: string }> | undefined, ): SpanQueryRow { const obj: SpanQueryRow = {}; for (const cell of row ?? []) { - if (typeof cell?.field === "string" && typeof cell.value === "string") { - obj[cell.field] = cell.value; + if (typeof cell?.field !== "string" || typeof cell.value !== "string") { + continue; + } + if (cell.field === "@message") { + try { + const parsed = JSON.parse(cell.value) as unknown; + flatten(parsed, "", obj); + } catch (err: unknown) { + console.error("spans-query: failed to JSON.parse @message row", { + error: err instanceof Error ? err.message : String(err), + }); + } + continue; } + obj[cell.field] = cell.value; } return obj; } @@ -102,7 +149,7 @@ export async function runSpanQuery( logGroupName: options.logGroupName, startTime: options.startTimeSec, endTime: options.endTimeSec, - queryString: `${options.queryString} | limit ${options.limit}`, + queryString: `${options.queryString} | fields @message | limit ${options.limit}`, }), ); diff --git a/backend/src/lambda/utils/spans-waterfall.ts b/backend/src/lambda/utils/spans-waterfall.ts index fb3100d..7faf3ac 100644 --- a/backend/src/lambda/utils/spans-waterfall.ts +++ b/backend/src/lambda/utils/spans-waterfall.ts @@ -6,25 +6,34 @@ * backend produced a response. * * ============================================================================ - * SCHEMA-VERIFICATION GATE (design §2, HIGH risk #1) — READ BEFORE EDITING + * SCHEMA VERIFIED (evidence report, finding a3d8a2ea, 2026-08-03 + + * 2026-08-14 real-account samples — see docs/TRACING_RUNBOOK.md cutover + * procedure) — READ BEFORE EDITING * ============================================================================ - * EVERY aws/spans field name referenced in this file (`spanId`, - * `parentSpanId`, `traceId`, `startTimeUnixNano`/`endTimeUnixNano`, the - * `attributes.*`/`annotation.*` attribute-key shapes, `statusCode`) is an - * ASSUMPTION carried from the design doc, not a value verified against a - * real CloudWatch Transaction Search span. Do NOT trust these names as - * ground truth. Before `TRACE_BACKEND=spans` is ever flipped against a - * real account, run a real query against `aws/spans` (see - * docs/TRACING_RUNBOOK.md cutover procedure's "verify span schema with a - * real sample" step) and reconcile every field-name constant below (and - * the corresponding `spans-query.ts`/`trace-span-query.ts` query text) - * against the actual result columns. Until that verification happens, - * treat every mapping in this file as best-effort and unverified. + * Every aws/spans field name below was reconciled against real + * CloudWatch Transaction Search span/subsegment events (Lambda + AppSync + * producers). Key corrections from the original design-doc assumptions: + * - Annotations are merged into `attributes.` (bare key), NOT + * `annotation.` — enumerated via + * `attributes["aws.xray.annotation_keys"]`. + * - OTel status is the flattened `status.code` field (UNSET/ERROR + * observed; OK never observed — untested), not `statusCode`. + * - Subsegment display name/namespace live at `_aws.xray.name` / + * `_aws.xray.namespace` — top-level `name` is `""` on subsegments. + * - http-status fallback key is `attributes.http.status_code` + * (attributes-prefixed), not bare `http.status_code`. + * - Exception text observed at `_aws.xray.cause.message`; OTel + * `attributes.exception.*` is kept as primary but unobserved. + * - In-progress snapshots (`attributes["aws.xray.inprogress"]===true`, + * no `endTimeUnixNano`) and the completed event share a `spanId` — + * deduped before tree-building. + * Re-verify against a live sample if aws/spans schema changes upstream. * ============================================================================ * * Pure and I/O-free — no AWS SDK imports. Consumes the plain * `SpanQueryRow` shape `spans-query.ts` returns (a flat string-keyed - * record per Logs Insights result row). + * record per Logs Insights result row, with each row's `@message` JSON + * document flattened into dot-notation keys by spans-query.ts). * * Invariant-4 analog (binding, mirrors xray-waterfall.ts): malformed or * incomplete rows (missing spanId/traceId) are skipped, never thrown. @@ -43,8 +52,9 @@ import type { export type { SpanStatus, TraceEntry, TraceSpan, TraceWaterfallShape }; /** Flat string-keyed view of one Logs Insights `aws/spans` result row — - * matches `SpanQueryRow` from spans-query.ts. Field names are the - * UNVERIFIED assumptions flagged in the module header above. */ + * matches `SpanQueryRow` from spans-query.ts (dot-flattened `@message` + * JSON). Field names are verified against real samples per the module + * header above. */ export type SpanQueryRowLike = Record; function parseUnixNanoToSeconds(value: string | undefined): number | null { @@ -55,14 +65,18 @@ function parseUnixNanoToSeconds(value: string | undefined): number | null { } function statusOf(row: SpanQueryRowLike): SpanStatus { - // UNVERIFIED field names (module header): `statusCode` (OTel - // status.code, expected "UNSET"|"OK"|"ERROR"), the http-status - // attribute keys below. Best-effort trichotomy (design §2): OTel is - // binary UNSET/OK/ERROR vs X-Ray's fault/error/throttle four-state. + // Verified (evidence report finding a3d8a2ea, probe B): the OTel status + // is a flattened `status.code` field (values observed: UNSET, ERROR; + // OK never observed — treat as untested). The http-status fallback key + // is `attributes.http.status_code` (attributes-prefixed), not bare + // `http.status_code` (probe B/D). Best-effort trichotomy (design §2): + // OTel is binary UNSET/OK/ERROR vs X-Ray's fault/error/throttle + // four-state. const httpStatusRaw = - row["attributes.http.response.status_code"] ?? row["http.status_code"]; + row["attributes.http.response.status_code"] ?? + row["attributes.http.status_code"]; const httpStatus = httpStatusRaw ? Number(httpStatusRaw) : undefined; - const isError = row.statusCode === "ERROR"; + const isError = row["status.code"] === "ERROR"; if (httpStatus === 429) return "throttle"; if (isError && typeof httpStatus === "number" && httpStatus >= 500) { @@ -74,7 +88,8 @@ function statusOf(row: SpanQueryRowLike): SpanStatus { function httpOf(row: SpanQueryRowLike): { status: number } | null { const raw = - row["attributes.http.response.status_code"] ?? row["http.status_code"]; + row["attributes.http.response.status_code"] ?? + row["attributes.http.status_code"]; if (typeof raw !== "string" || raw.length === 0) return null; const status = Number(raw); return Number.isFinite(status) ? { status } : null; @@ -83,8 +98,14 @@ function httpOf(row: SpanQueryRowLike): { status: number } | null { function errorOf( row: SpanQueryRowLike, ): { type: string; message: string } | null { - // UNVERIFIED (module header): exception attribute key shape. - const message = row["attributes.exception.message"]; + // `attributes.exception.*` is NOT-OBSERVABLE in the evidence report + // (no SDK-instrumented producer sampled emits it) but is kept as the + // primary OTel-standard key for producers that do emit it. The real + // sampled ERROR span (AppSync, 401) carried its cause text at + // `_aws.xray.cause.message` instead — added as a fallback so real + // X-Ray-origin error spans surface a message. + const message = + row["attributes.exception.message"] ?? row["_aws.xray.cause.message"]; if (typeof message !== "string" || message.length === 0) return null; return { type: row["attributes.exception.type"] ?? "Error", @@ -93,15 +114,27 @@ function errorOf( } function collectAnnotations(rows: SpanQueryRowLike[]): Record { + // Verified (evidence report finding a3d8a2ea, probe B/C + archived + // sample): annotations are NOT under an `annotation.` prefix — X-Ray + // annotations are merged into `attributes` under their bare key, and + // enumerated by the `attributes["aws.xray.annotation_keys"]` array + // (JSON-stringified array leaf per spans-query.ts's flatten()). const annotations: Record = {}; for (const row of rows) { - for (const [key, value] of Object.entries(row)) { - // UNVERIFIED (module header): the `annotation.` prefix is the - // expected attribute-key shape carrying X-Ray-style annotations - // through aws/spans; may need to become a flattened column name - // (e.g. `annotation_correlation_id`) once verified. - if (key.startsWith("annotation.") && typeof value === "string") { - annotations[key.slice("annotation.".length)] = value; + const keysRaw = row["attributes.aws.xray.annotation_keys"]; + if (typeof keysRaw !== "string" || keysRaw.length === 0) continue; + let keys: unknown; + try { + keys = JSON.parse(keysRaw); + } catch { + continue; + } + if (!Array.isArray(keys)) continue; + for (const key of keys) { + if (typeof key !== "string" || key.length === 0) continue; + const value = row[`attributes.${key}`]; + if (typeof value === "string") { + annotations[key] = value; } } } @@ -134,11 +167,21 @@ function buildSpan( const span: TraceSpan = { id: spanId, parentId: row.parentSpanId ?? null, - name: typeof row.name === "string" ? row.name : "", - // UNVERIFIED (module header): namespace/origin attribute-key shape. + // Verified (evidence report finding a3d8a2ea, samples + probe D): + // subsegments always carry an empty top-level `name` (""); their + // display name lives only in `_aws.xray.name`. Fall back to it when + // the top-level name is empty/absent. + name: + typeof row.name === "string" && row.name.length > 0 + ? row.name + : typeof row["_aws.xray.name"] === "string" + ? row["_aws.xray.name"]! + : "", + // Verified: namespace lives at `_aws.xray.namespace` (e.g. "aws" on + // the AppSync segment), never `attributes.namespace` (unobserved). namespace: - typeof row["attributes.namespace"] === "string" - ? row["attributes.namespace"]! + typeof row["_aws.xray.namespace"] === "string" + ? row["_aws.xray.namespace"]! : null, origin: typeof row["resource.attributes.service.name"] === "string" @@ -178,13 +221,46 @@ function buildSpan( return span; } +/** In-progress snapshots (`attributes["aws.xray.inprogress"]===true`, no + * `endTimeUnixNano`) and the eventual completed event share the same + * `spanId` — Transaction Search emits both as the stream progresses + * (evidence report finding a3d8a2ea: 3 duplicate spanIds observed in a + * 10-event window). Dedup before tree-building: keep the completed row + * (has `endTimeUnixNano`) when both are present for a spanId, else keep + * whichever snapshot row was seen last (the latest in-progress state). + */ +function dedupBySpanId(rows: SpanQueryRowLike[]): SpanQueryRowLike[] { + const bySpanId = new Map(); + const order: string[] = []; + for (const row of rows) { + const spanId = row.spanId as string; + const existing = bySpanId.get(spanId); + if (!existing) { + bySpanId.set(spanId, row); + order.push(spanId); + continue; + } + const existingCompleted = + typeof existing.endTimeUnixNano === "string" && + existing.endTimeUnixNano.length > 0; + const rowCompleted = + typeof row.endTimeUnixNano === "string" && row.endTimeUnixNano.length > 0; + if (rowCompleted || !existingCompleted) { + // Either this row is the completed one (always wins), or neither + // row is completed yet and this is the latest snapshot seen. + bySpanId.set(spanId, row); + } + } + return order.map((id) => bySpanId.get(id)!); +} + function shapeSingleTrace( traceId: string, rows: SpanQueryRowLike[], options: { includeMetadata: boolean }, ): TraceEntry { - const validRows = rows.filter( - (r) => typeof r.spanId === "string" && r.spanId.length > 0, + const validRows = dedupBySpanId( + rows.filter((r) => typeof r.spanId === "string" && r.spanId.length > 0), ); const byId = new Set(validRows.map((r) => r.spanId as string)); @@ -226,10 +302,16 @@ function shapeSingleTrace( const hasThrottle = validRows.some((r) => statusOf(r) === "throttle"); const rootRow = roots[0]; + const rootName = + rootRow && typeof rootRow.name === "string" && rootRow.name.length > 0 + ? rootRow.name + : rootRow && typeof rootRow["_aws.xray.name"] === "string" + ? rootRow["_aws.xray.name"]! + : null; return { traceId, - rootName: rootRow && typeof rootRow.name === "string" ? rootRow.name : null, + rootName, startTime: minStartTime, endTime: endTimes.length > 0 ? maxEndTime : null, durationMs: Math.max(0, (maxEndTime - minStartTime) * 1000), diff --git a/backend/src/lambda/utils/trace-span-query.ts b/backend/src/lambda/utils/trace-span-query.ts index 162bcce..0610627 100644 --- a/backend/src/lambda/utils/trace-span-query.ts +++ b/backend/src/lambda/utils/trace-span-query.ts @@ -39,9 +39,13 @@ export type SpanFilterResult = { ok: true; clause: string } | { ok: false }; * it fails the allowlist (reject-first — never falls back to a * sanitized/escaped variant, matching xray-filter.ts's posture). * - * Backtick-quoted field name (`` `annotation.correlation_id` ``) because - * Logs Insights field names containing `.` must be backtick-quoted to be - * parsed as a single field reference rather than nested-field access. + * Verified (evidence report finding a3d8a2ea, probe B vs probe C): + * `aws/spans` merges X-Ray annotations into `attributes.` — there is + * no `annotation.*` field. Filters on `` `attributes.correlation_id` ``. + * + * Backtick-quoted field name because Logs Insights field names containing + * `.` must be backtick-quoted to be parsed as a single field reference + * rather than nested-field access. */ export function buildSpanCorrelationFilter(id: string): SpanFilterResult { if (!isAllowlistedSpanId(id)) { @@ -49,7 +53,7 @@ export function buildSpanCorrelationFilter(id: string): SpanFilterResult { } return { ok: true, - clause: `filter \`annotation.correlation_id\` = "${id}"`, + clause: `filter \`attributes.correlation_id\` = "${id}"`, }; } @@ -65,6 +69,6 @@ export function buildSpanRunIdFilter(id: string): SpanFilterResult { } return { ok: true, - clause: `filter \`annotation.run_id\` = "${id}"`, + clause: `filter \`attributes.run_id\` = "${id}"`, }; }