diff --git a/actions/setup/js/scripts/session_schemas.test.cjs b/actions/setup/js/scripts/session_schemas.test.cjs index 50722b0f665..effdb34f449 100644 --- a/actions/setup/js/scripts/session_schemas.test.cjs +++ b/actions/setup/js/scripts/session_schemas.test.cjs @@ -211,7 +211,7 @@ describe("Generated session schemas", () => { }); it("checks timestamp ordering, the untimed tail and execution singleton semantics", () => { - const timed = time => ({ ...unified({ type: "vendor.progress", data: {} }), provenance: { ...unified({}).provenance, timestampMs: time } }); + const timed = time => ({ ...unified({ type: "vendor.progress", data: {} }), provenance: { ...unified({}).provenance, path: `source-${time}`, timestampMs: time } }); const untimed = unified({ type: "vendor.progress", data: {} }); expect(validateSession(jsonl([header, timed(0), timed(0), timed(1), untimed]))).toBe(5); expect(() => validateSession(jsonl([header, timed(1), timed(0)]))).toThrow("timestamp ordered"); @@ -221,6 +221,24 @@ describe("Generated session schemas", () => { expect(() => validateSession(jsonl([header, { ...execution, data: { ...execution.data, exitCode: 256 } }]))).toThrow("SessionExitCode"); }); + it("uses persisted millisecond provenance when v1 source metadata omits timestampUnit", () => { + const secondsSource = { component: "agent", phase: "agent", path: "seconds.jsonl", events: 1 }; + const millisecondsSource = { component: "mcp", phase: "agent", path: "milliseconds.jsonl", events: 1 }; + const collection = { + type: "session.collection", + data: { sources: [secondsSource, millisecondsSource], warnings: 0, untimedEvents: 0, absentComponents: [] }, + provenance: { component: "collector", phase: "conclusion", path: "usage/aw_session.jsonl", index: 3 }, + }; + const event = (component, sourcePath, timestamp, timestampMs) => ({ + type: "vendor.progress", + timestamp, + data: {}, + provenance: { component, phase: "agent", path: sourcePath, index: 0, timestampMs }, + }); + + expect(validateSession(jsonl([header, event("mcp", "milliseconds.jsonl", 1500, 1500), event("agent", "seconds.jsonl", 2, 2000), collection]))).toBe(4); + }); + it("checks exact JSONL framing without requiring canonical JSON number or escape spellings", () => { const valid = jsonl([header]); expect(validateSession(valid.replace('"version":1', '"version":1.0'))).toBe(1); diff --git a/actions/setup/js/scripts/validate_session.cjs b/actions/setup/js/scripts/validate_session.cjs index 5d92649b749..4a728c4ff0c 100644 --- a/actions/setup/js/scripts/validate_session.cjs +++ b/actions/setup/js/scripts/validate_session.cjs @@ -4,6 +4,7 @@ const fs = require("node:fs"); const path = require("node:path"); const { Ajv } = require("ajv"); const { validateSessionFileHeader } = require("../unified_session_render.cjs"); +const { sessionOrderingEntries, sessionTimestampNs } = require("../unified_session_order.cjs"); const SCHEMA_DIRECTORY = path.resolve(__dirname, "../../../../docs/public/schemas"); @@ -58,16 +59,42 @@ function validateSession(content, kind = "unified", format = "jsonl") { if (!validators.array(events)) throw new Error(`Invalid ${kind} session: ${schemaDiagnostic(validators.array.errors)}`); if (kind === "unified") { validateSessionFileHeader(events); - let previousTime = -Infinity; - let untimed = false; + const sourceKey = source => JSON.stringify([source.component, source.phase, source.path]); + const sources = new Map(); + const units = new Map(events.find(event => event.type === "session.collection" && event.provenance.component === "collector")?.data.sources?.map(source => [sourceKey(source), source.timestampUnit]) ?? []); for (const [index, event] of events.entries()) { const sourcePath = event.provenance.path; if (!sourcePath || /^(?:[/\\]|[a-z]:)/i.test(sourcePath) || sourcePath.split(/[/\\]/).includes("..")) throw new Error(`Invalid relative provenance path at record ${index + 1}`); if (index === 0) continue; - const time = event.provenance.timestampMs; - if (time === undefined) untimed = true; + const key = sourceKey(event.provenance); + let source = sources.get(key); + if (!source) { + const timestampUnit = units.get(key); + const component = event.provenance.component; + source = { component, timestampUnit: timestampUnit ?? (component === "otel" ? "nanoseconds" : "milliseconds"), useProvenanceTimestamp: timestampUnit === undefined && component !== "otel", events: [] }; + sources.set(key, source); + } + if (source.component !== "otel" && source.events.at(-1)?.provenance.index > event.provenance.index) throw new Error(`Unified session is not source ordered at record ${index + 1}`); + source.events.push(event); + } + const ordered = sessionOrderingEntries( + [...sources.values()].map(source => ({ + ...source, + events: source.events.map(event => ({ + timestamp: source.useProvenanceTimestamp && !(typeof event.timestamp === "string" && sessionTimestampNs(event) !== undefined) ? event.provenance.timestampMs : (event.timestamp ?? event.provenance.timestampMs), + event, + })), + })) + ); + const keys = new Map(ordered.map(({ event, time }) => [event.event, time])); + let previousTime; + let unanchored = false; + for (const [index, event] of events.entries()) { + if (index === 0) continue; + const time = keys.get(event); + if (time === undefined) unanchored = true; else { - if (untimed || time < previousTime) throw new Error(`Unified session is not timestamp ordered at record ${index + 1}`); + if (unanchored || (previousTime !== undefined && time < previousTime)) throw new Error(`Unified session is not timestamp ordered at record ${index + 1}`); previousTime = time; } } diff --git a/actions/setup/js/types/unified_session.d.ts b/actions/setup/js/types/unified_session.d.ts index 8ab8fd2d729..abda36dfe5d 100644 --- a/actions/setup/js/types/unified_session.d.ts +++ b/actions/setup/js/types/unified_session.d.ts @@ -344,7 +344,7 @@ export interface CollectionData { phase: string; path: string; events: SessionCount; - timestampUnit?: "seconds" | "milliseconds"; + timestampUnit?: "seconds" | "milliseconds" | "nanoseconds"; }[]; warnings: SessionCount; untimedEvents: SessionCount; diff --git a/actions/setup/js/unified_session.cjs b/actions/setup/js/unified_session.cjs index 3d68a2f7a67..7888d5ffa77 100644 --- a/actions/setup/js/unified_session.cjs +++ b/actions/setup/js/unified_session.cjs @@ -10,6 +10,8 @@ const { normalizeUnifiedSessionEvent } = require("./unified_session_payload.cjs" const { ERR_SYSTEM, ERR_VALIDATION } = require("./error_codes.cjs"); const { collectAgentExecution, parseAgentExitCode, validateAgentExitCode, isAgentExecutionEvent } = require("./agent_execution.cjs"); const { normalizeEngineLogEntries, normalizeEngineSessionEvents, parseEngineLog } = require("./engine_log_parser.cjs"); +const { sessionTimestamp, orderSessionSources } = require("./unified_session_order.cjs"); +const { normalizeOtelEvents } = require("./unified_session_otel.cjs"); const SESSION_FILE_FORMAT_VERSION = 1; @@ -29,29 +31,11 @@ function isModelEndpointMismatchData(data) { } /** @typedef {import("./types/agent_session").SessionEvent} SessionEvent */ -/** @typedef {{component: string, phase: string, path: string, events: SessionEvent[], timestampUnit?: "seconds" | "milliseconds"}} SessionSource */ +/** @typedef {{component: string, phase: string, path: string, events: SessionEvent[], timestampUnit?: import("./unified_session_order.cjs").TimestampUnit}} SessionSource */ /** @param {unknown} value @returns {boolean} */ const isNativePath = value => typeof value === "string" && /^sandbox\/agent\/logs\/copilot-session-state\/[A-Za-z0-9_-]+\/events\.jsonl$/.test(value); -/** - * Timestamp units come from the source schema, never from the value's magnitude. - * Native timestamps stay unchanged; this value is only an ordering key. - * @param {any} record - * @param {"seconds" | "milliseconds"} [unit] - * @returns {number | undefined} - */ -function sessionTimestamp(record, unit = "milliseconds") { - const value = record.timestamp ?? record.ts ?? record.time ?? record.created_at ?? record.message?.timestamp; - if (typeof value === "number") { - const ms = unit === "seconds" ? value * 1000 : value; - return Number.isFinite(ms) && Math.abs(ms) <= 8640000000000000 ? ms : undefined; - } - if (typeof value !== "string" || !/^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(?:\.\d+)?(?:Z|[+-]\d{2}:\d{2})$/i.test(value)) return undefined; - const ms = Date.parse(value); - return Number.isFinite(ms) ? ms : undefined; -} - /** * Source-local positions disambiguate repeated native IDs and expanded records. * Equal timestamps and untimed observations retain deterministic source order. @@ -59,47 +43,44 @@ function sessionTimestamp(record, unit = "milliseconds") { * @returns {import("./types/unified_session").UnifiedSession} */ function mergeSessionSources(sources) { - const events = sources.flatMap(source => - source.events.map((event, index) => { - const timestampMs = sessionTimestamp(event, source.timestampUnit); - const normalized = normalizeUnifiedSessionEvent(event, source.phase); - const native = event.provenance; - const sourceIndex = - source.component === "agent" && - isNativePath(source.path) && - native && - typeof native === "object" && - "path" in native && - native.path === source.path && - (!("phase" in native) || native.phase === source.phase) && - "index" in native && - typeof native.index === "number" && - Number.isSafeInteger(native.index) && - native.index >= 0 - ? native.index - : index; - if (event.type === "detection.result" && source.path !== "usage/detection/detection_result.json") { - delete normalized.data.reason; - } - return { - ...normalized, - provenance: { - component: source.component, - phase: source.phase, - path: source.path, - index: sourceIndex, - ...(timestampMs !== undefined ? { timestampMs } : {}), - ...(Object.hasOwn(event, "provenance") ? { native: structuredClone(event.provenance) } : {}), - }, - }; - }) + return orderSessionSources( + sources.map(source => ({ + ...source, + events: source.events.map((event, index) => { + const timestampMs = sessionTimestamp(event, source.timestampUnit); + const normalized = normalizeUnifiedSessionEvent(event, source.phase); + const native = event.provenance; + const sourceIndex = + source.component === "agent" && + isNativePath(source.path) && + native && + typeof native === "object" && + "path" in native && + native.path === source.path && + (!("phase" in native) || native.phase === source.phase) && + "index" in native && + typeof native.index === "number" && + Number.isSafeInteger(native.index) && + native.index >= 0 + ? native.index + : index; + if (event.type === "detection.result" && source.path !== "usage/detection/detection_result.json") { + delete normalized.data.reason; + } + return { + ...normalized, + provenance: { + component: source.component, + phase: source.phase, + path: source.path, + index: sourceIndex, + ...(timestampMs !== undefined ? { timestampMs } : {}), + ...(Object.hasOwn(event, "provenance") ? { native: structuredClone(event.provenance) } : {}), + }, + }; + }), + })) ); - events.sort((left, right) => { - const leftTime = left.provenance.timestampMs ?? Infinity; - const rightTime = right.provenance.timestampMs ?? Infinity; - return leftTime === rightTime ? 0 : leftTime < rightTime ? -1 : 1; - }); - return events; } /** @param {"mcp" | "firewall"} component @param {any} record @returns {SessionEvent} */ @@ -133,6 +114,7 @@ function normalizeRuntimeEvent(component, record) { ...(record.timestamp !== undefined ? { timestamp: record.timestamp } : {}), ...(record.ts !== undefined ? { ts: record.ts } : {}), ...(record.time !== undefined ? { time: record.time } : {}), + ...(record.created_at !== undefined ? { created_at: record.created_at } : {}), }; } @@ -223,7 +205,7 @@ function collectUnifiedSession({ rootDir = "/tmp/gh-aw", engine, warn = message * @param {string} component * @param {string} phase * @param {`${string}.${string}` | undefined} type - * @param {"seconds" | "milliseconds"} [timestampUnit] + * @param {import("./unified_session_order.cjs").TimestampUnit} [timestampUnit] */ const add = (file, component, phase, type, timestampUnit = "milliseconds") => { if (!exists(file)) return 0; @@ -237,14 +219,21 @@ function collectUnifiedSession({ rootDir = "/tmp/gh-aw", engine, warn = message report(file, "non_object_record", undefined); continue; } - if (component === "agent") { + if (component === "otel") { + events.push( + ...normalizeOtelEvents(record, code => { + incompleteSources.add(file); + report(file, code, undefined); + }) + ); + } else if (component === "agent") { if (isSessionEvent(record)) events.push(record); else if (!hasLegacyContent || normalizeEngineLogEntries([record], engine ?? "custom").length === 0) { incompleteSources.add(file); report(file, "non_canonical_agent_event", undefined); } } else if (type) { - events.push({ type, data: record, ...(record.timestamp !== undefined ? { timestamp: record.timestamp } : {}), ...(record.created_at !== undefined ? { created_at: record.created_at } : {}) }); + events.push({ type, data: record, ...Object.fromEntries(["timestamp", "ts", "time", "created_at"].filter(key => record[key] !== undefined).map(key => [key, record[key]])) }); } else if (component === "mcp" || component === "firewall") events.push(normalizeRuntimeEvent(component, record)); else throw new Error(`${ERR_VALIDATION}: Missing event mapping for ${component}`); } @@ -434,6 +423,8 @@ function collectUnifiedSession({ rootDir = "/tmp/gh-aw", engine, warn = message ["", "agent"], ["threat-detection/", "detection"], ]) { + const otel = choose([`${prefix}otel.jsonl`, `usage/${prefix}otel.jsonl`]); + if (otel) add(otel, "otel", phase, undefined, "nanoseconds"); for (const file of walk(path.join(rootDir, prefix, "mcp-logs"))) add(file, "mcp", phase, undefined); const seen = new Set(); for (const layout of ["sandbox/firewall/logs", "sandbox/firewall/audit", "sandbox/firewall-audit-logs", "firewall-logs", "firewall-audit-logs"]) { diff --git a/actions/setup/js/unified_session.test.cjs b/actions/setup/js/unified_session.test.cjs index 4397455c182..be4243c61ba 100644 --- a/actions/setup/js/unified_session.test.cjs +++ b/actions/setup/js/unified_session.test.cjs @@ -604,10 +604,10 @@ describe("Unified conclusion session", () => { ]; const original = structuredClone(sources); const events = mergeSessionSources(sources); - expect(events.map(event => event.data.content)).toEqual(["", "second", undefined, undefined]); - expect(events.at(-1).provenance).toMatchObject({ native: { vendor: 1 }, index: 0 }); - expect(events.at(-1).timestamp).toBe("invalid"); - expect(events.at(-1).provenance).not.toHaveProperty("timestampMs"); + expect(events.map(event => event.data.content)).toEqual([undefined, "", "second", undefined]); + expect(events[0].provenance).toMatchObject({ native: { vendor: 1 }, index: 0 }); + expect(events[0].timestamp).toBe("invalid"); + expect(events[0].provenance).not.toHaveProperty("timestampMs"); expect(sources).toEqual(original); expect(mergeSessionSources(sources)).toEqual(events); }); @@ -1058,9 +1058,9 @@ describe("Unified conclusion session", () => { { type: "assistant.message", timestamp: "2026-10-02T00:00:01Z", data: { content: "first timed event" } }, ]); const events = writeUnifiedSession({ rootDir: root }); - expect(events.map(event => event.type)).toEqual(["session.format", "assistant.message", "session.format", "session.collection"]); + expect(events.map(event => event.type)).toEqual(["session.format", "session.format", "assistant.message", "session.collection"]); expect(events[0].data.version).toBe(1); - expect(events[2]).toMatchObject({ data: { version: "native-engine-format" }, provenance: { component: "agent", index: 0 } }); + expect(events[1]).toMatchObject({ data: { version: "native-engine-format" }, provenance: { component: "agent", index: 0 } }); }); it("fails explicitly on read errors and removes a stale output rather than uploading it", () => { diff --git a/actions/setup/js/unified_session_order.cjs b/actions/setup/js/unified_session_order.cjs new file mode 100644 index 00000000000..90bafee2695 --- /dev/null +++ b/actions/setup/js/unified_session_order.cjs @@ -0,0 +1,74 @@ +// @ts-check + +/** @typedef {"seconds" | "milliseconds" | "nanoseconds"} TimestampUnit */ + +/** + * Source schemas, not timestamp magnitude, determine numeric units. + * Keep nanoseconds as integers until producing the display-only millisecond key. + * @param {any} record + * @param {TimestampUnit} [unit] + * @returns {bigint | undefined} + */ +function sessionTimestampNs(record, unit = "milliseconds") { + const value = record.timestamp ?? record.ts ?? record.time ?? record.created_at ?? record.message?.timestamp; + if (unit === "nanoseconds") { + if (typeof value !== "string" || !/^\d{1,22}$/.test(value)) return undefined; + const ns = BigInt(value); + return ns <= 8640000000000000000000n ? ns : undefined; + } + if (typeof value === "number") { + const ms = unit === "seconds" ? value * 1000 : value; + if (!Number.isFinite(ms) || Math.abs(ms) > 8640000000000000) return undefined; + const whole = Math.trunc(ms); + return BigInt(whole) * 1000000n + BigInt(Math.round((ms - whole) * 1000000)); + } + if (typeof value !== "string") return undefined; + const match = /^(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2})(?:\.(\d+))?(Z|[+-]\d{2}:\d{2})$/i.exec(value); + if (!match) return undefined; + const ms = Date.parse(`${match[1]}${match[3]}`); + return Number.isFinite(ms) ? BigInt(ms) * 1000000n + BigInt((match[2] ?? "").padEnd(9, "0").slice(0, 9)) : undefined; +} + +/** @param {any} record @param {TimestampUnit} [unit] @returns {number | undefined} */ +function sessionTimestamp(record, unit = "milliseconds") { + const ns = sessionTimestampNs(record, unit); + return ns === undefined ? undefined : Number(ns / 1000000n) + Number(ns % 1000000n) / 1000000; +} + +/** + * Missing clocks inherit an ordering anchor, never an observed timestamp. + * Clock regressions cannot reverse a sequential source. OTLP exports are + * unordered batches of spans/logs, rather than an execution sequence. + * @template T + * @param {Array<{component: string, events: T[], timestampUnit?: TimestampUnit}>} sources + * @returns {Array<{event: T, time: bigint | undefined}>} + */ +function sessionOrderingEntries(sources) { + return sources.flatMap(source => { + const times = source.events.map(event => sessionTimestampNs(event, source.timestampUnit)); + let anchor = times.find(time => time !== undefined); + return source.events.map((event, index) => { + const time = times[index]; + if (time !== undefined && (anchor === undefined || time > anchor)) anchor = time; + return { event, time: source.component === "otel" ? time : anchor }; + }); + }); +} + +/** + * @template T + * @param {Array<{component: string, events: T[], timestampUnit?: TimestampUnit}>} sources + * @returns {T[]} + */ +function orderSessionSources(sources) { + const entries = sessionOrderingEntries(sources); + entries.sort((left, right) => { + if (left.time === right.time) return 0; + if (left.time === undefined) return 1; + if (right.time === undefined) return -1; + return left.time < right.time ? -1 : 1; + }); + return entries.map(entry => entry.event); +} + +module.exports = { sessionTimestamp, sessionTimestampNs, sessionOrderingEntries, orderSessionSources }; diff --git a/actions/setup/js/unified_session_order.test.cjs b/actions/setup/js/unified_session_order.test.cjs new file mode 100644 index 00000000000..a9bcfa50bba --- /dev/null +++ b/actions/setup/js/unified_session_order.test.cjs @@ -0,0 +1,162 @@ +import { describe, expect, it } from "vitest"; +import { mergeSessionSources, sessionTimestamp } from "./unified_session.cjs"; +import { orderSessionSources, sessionTimestampNs } from "./unified_session_order.cjs"; +import { validateSession } from "./scripts/validate_session.cjs"; + +const event = (id, timestamp) => ({ id, type: "vendor.observation", data: {}, ...(timestamp !== undefined ? { timestamp } : {}) }); +const source = (component, events, timestampUnit = "milliseconds") => ({ component, phase: "agent", path: `${component}.jsonl`, timestampUnit, events }); +const header = { type: "session.format", data: { version: 1 }, provenance: { component: "collector", phase: "conclusion", path: "usage/aw_session.jsonl", index: 0 } }; +const jsonl = events => [header, ...events].map(JSON.stringify).join("\n") + "\n"; + +describe("Unified trace ordering", () => { + it.each([[], [source("agent", [])], [source("agent", []), source("otel", [], "nanoseconds")]].map(sources => [sources]))("accepts empty source collections without inventing observations: %j", sources => { + expect(mergeSessionSources(sources)).toEqual([]); + }); + + it.each([1, 7, 42, 2026, 65535])("matches an independent head-selection merge for generated mixed traces (seed %i)", seed => { + let state = seed; + const random = limit => { + state = (Math.imul(state, 1664525) + 1013904223) >>> 0; + return state % limit; + }; + const queues = []; + const sources = ["agent", "firewall", "mcp", "github_api", "otel", "workflow"].map((component, sourceIndex) => { + const observations = Array.from({ length: 30 + random(20) }, (_, index) => { + const kind = random(5); + const time = component === "workflow" || kind === 0 || kind === 1 ? undefined : random(100); + const timestamp = time === undefined ? (kind === 1 ? "invalid" : undefined) : component === "otel" ? String(time * 1000000) : component === "firewall" ? time / 1000 : time; + return { event: { ...event("repeated-native-id", timestamp), data: { observation: `${sourceIndex}:${index}` } }, time, index }; + }); + let anchor = observations.find(record => record.time !== undefined)?.time; + const queue = observations.map(record => { + if (record.time !== undefined) anchor = anchor === undefined ? record.time : Math.max(anchor, record.time); + return { ...record, key: component === "otel" ? record.time : anchor, sourceIndex }; + }); + if (component === "otel") queue.sort((left, right) => (left.key ?? Infinity) - (right.key ?? Infinity)); + queues.push(queue); + return source( + component, + observations.map(record => record.event), + component === "otel" ? "nanoseconds" : component === "firewall" ? "seconds" : "milliseconds" + ); + }); + const original = structuredClone(sources); + const expected = []; + while (queues.some(queue => queue.length)) { + let selected; + for (const [index, queue] of queues.entries()) { + if (queue.length && (selected === undefined || (queue[0].key ?? Infinity) < (queues[selected][0].key ?? Infinity))) selected = index; + } + expected.push(queues[selected].shift()); + } + const merged = mergeSessionSources(sources); + expect(merged.map(record => record.data.observation)).toEqual(expected.map(record => record.event.data.observation)); + expect(merged.map(record => record.provenance.index)).toEqual(expected.map(record => record.index)); + expect(merged.map(record => record.timestamp)).toEqual(expected.map(record => record.event.timestamp)); + expect(new Set(merged.map(record => record.data.observation)).size).toBe(expected.length); + expect(sources).toEqual(original); + expect(mergeSessionSources(sources)).toEqual(merged); + const summary = { + type: "session.collection", + data: { sources: sources.map(({ events, ...rest }) => ({ ...rest, events: events.length })), warnings: 0, untimedEvents: expected.filter(record => record.time === undefined).length, absentComponents: [] }, + provenance: header.provenance, + }; + expect(validateSession(jsonl([...merged, summary]))).toBe(expected.length + 2); + }); + + it("merges 32000 observations across 16 sources without losing payloads, indices, or nanosecond order", () => { + const sourceCount = 16; + const eventsPerSource = 2000; + const start = 1790899200000000000n; + const sources = Array.from({ length: sourceCount }, (_, sourceIndex) => { + const events = Array.from({ length: eventsPerSource }, (_, index) => ({ + ...event("repeated-native-id", String(start + BigInt(index * sourceCount + sourceIndex))), + data: { observation: index * sourceCount + sourceIndex, nested: { zero: 0, flag: false, text: " retained\npayload " } }, + })).reverse(); + return { ...source("otel", events, "nanoseconds"), path: `otel/source-${sourceIndex}.jsonl` }; + }); + const merged = mergeSessionSources(sources); + const expected = Array.from({ length: sourceCount * eventsPerSource }, (_, index) => index); + expect(merged.map(record => record.data.observation)).toEqual(expected); + expect(merged.map(record => record.provenance.index)).toEqual(expected.map(index => eventsPerSource - 1 - Math.floor(index / sourceCount))); + expect(merged.map(record => record.provenance.path)).toEqual(expected.map(index => `otel/source-${index % sourceCount}.jsonl`)); + expect(merged.every(record => record.timestamp === String(start + BigInt(record.data.observation)) && record.data.nested.text === " retained\npayload " && record.data.nested.flag === false)).toBe(true); + expect(sources.every(item => item.events[0].data.observation > item.events.at(-1).data.observation)).toBe(true); + }); + + it("reads each observation clock once when computing anchors and sorting", () => { + let reads = 0; + const count = 10000; + const events = Array.from({ length: count }, (_, index) => ({ + index, + get timestamp() { + reads++; + return index % 5 === 0 ? undefined : count - index; + }, + })); + const ordered = orderSessionSources([source("agent", events)]); + expect(reads).toBe(count); + expect(ordered.map(record => record.index)).toEqual(Array.from({ length: count }, (_, index) => index)); + }); + + it("interleaves agent, AWF, MCPG and GitHub API events without moving untimed lifecycle observations to the tail", () => { + const sources = [ + source("agent", [event("init"), event("start", 1000), event("tool"), event("answer", 3000), event("done")]), + source("firewall", [event("access", 1.5), event("tracker"), event("usage", 2.5)], "seconds"), + source("mcp", [event("request", 2000), event("response"), event("end", 4000)]), + source("github_api", [event("retry", 2250), event("rate-limit", 3500)]), + source("workflow", [event("metadata")]), + ]; + const original = structuredClone(sources); + const events = mergeSessionSources(sources); + expect(events.map(item => item.id)).toEqual(["init", "start", "tool", "access", "tracker", "request", "response", "retry", "usage", "answer", "done", "rate-limit", "end", "metadata"]); + for (const id of ["init", "tool", "tracker", "response", "done", "metadata"]) { + const untimed = events.find(item => item.id === id); + expect(untimed).not.toHaveProperty("timestamp"); + expect(untimed.provenance).not.toHaveProperty("timestampMs"); + } + expect(sources).toEqual(original); + expect(mergeSessionSources(sources)).toEqual(events); + const summary = { type: "session.collection", data: { sources: sources.map(({ events, ...rest }) => ({ ...rest, events: events.length })), warnings: 0, untimedEvents: 6, absentComponents: [] }, provenance: header.provenance }; + expect(validateSession(jsonl([...events, summary]))).toBe(events.length + 2); + }); + + it("preserves source order across clock regressions and invalid clocks without rewriting timestamps", () => { + const events = mergeSessionSources([source("agent", [event("start", 3000), event("invalid", "invalid"), event("complete", 1000), event("later", 5000)]), source("mcp", [event("rpc", 2000), event("reply", 4000)])]); + expect(events.map(item => item.id)).toEqual(["rpc", "start", "invalid", "complete", "reply", "later"]); + expect(events.find(item => item.id === "complete")).toMatchObject({ timestamp: 1000, provenance: { timestampMs: 1000, index: 2 } }); + expect(validateSession(jsonl(events))).toBe(7); + const swapped = [...events]; + [swapped[1], swapped[3]] = [swapped[3], swapped[1]]; + expect(() => validateSession(jsonl(swapped))).toThrow("source ordered"); + }); + + it("retains deterministic equal-time and fully untimed source order", () => { + const sources = [source("agent", [event("a", 0), event("b"), event("c", 0)]), source("mcp", [event("d", 0)]), source("workflow", [event("e"), event("f")]), source("usage", [event("g")])]; + expect(mergeSessionSources(sources).map(item => item.id)).toEqual(["a", "b", "c", "d", "e", "f", "g"]); + }); + + it("merges OTLP nanoseconds and ISO fractional seconds without losing sub-millisecond ordering", () => { + const events = mergeSessionSources([ + source("agent", [event("agent", "2026-10-02T00:00:00.000000002Z")]), + source("otel", [event("exported-later", "1790899200000000003"), event("exported-first", "1790899200000000001")], "nanoseconds"), + source("mcp", [event("gateway", 1790899200000)]), + ]); + expect(events.map(item => item.id)).toEqual(["gateway", "exported-first", "agent", "exported-later"]); + expect(events.find(item => item.id === "exported-first").timestamp).toBe("1790899200000000001"); + expect(validateSession(jsonl(events))).toBe(5); + const swapped = [...events]; + [swapped[1], swapped[3]] = [swapped[3], swapped[1]]; + expect(() => validateSession(jsonl(swapped))).toThrow("timestamp ordered"); + }); + + it("validates schema-defined clocks and preserves nanosecond precision", () => { + expect(sessionTimestampNs({ timestamp: "1790899200123456789" }, "nanoseconds")).toBe(1790899200123456789n); + expect(sessionTimestampNs({ timestamp: "2026-10-02T00:00:00.123456789+00:00" })).toBe(1790899200123456789n); + expect(sessionTimestampNs({ timestamp: -1.25 })).toBe(-1250000n); + expect(sessionTimestamp({ timestamp: "0" }, "nanoseconds")).toBe(0); + for (const timestamp of ["", "-1", "1.5", "NaN", "8640000000000000000001", 1790899200000000000]) { + expect(sessionTimestamp({ timestamp }, "nanoseconds")).toBeUndefined(); + } + }); +}); diff --git a/actions/setup/js/unified_session_otel.cjs b/actions/setup/js/unified_session_otel.cjs new file mode 100644 index 00000000000..cba5df36521 --- /dev/null +++ b/actions/setup/js/unified_session_otel.cjs @@ -0,0 +1,81 @@ +// @ts-check + +/** @typedef {import("./types/agent_session").SessionEvent} SessionEvent */ + +/** + * Expand OTLP JSON envelopes while retaining resource/scope and trace lineage. + * Invalid nested records are reported without discarding adjacent observations. + * @param {any} payload + * @param {(code: string) => void} report + * @returns {SessionEvent[]} + */ +function normalizeOtelEvents(payload, report) { + /** @type {SessionEvent[]} */ + const events = []; + const object = value => value !== null && typeof value === "object" && !Array.isArray(value); + const array = value => { + if (Array.isArray(value)) return value; + report("malformed_otlp"); + return []; + }; + if (!object(payload) || (!Object.hasOwn(payload, "resourceSpans") && !Object.hasOwn(payload, "resourceLogs"))) { + report("unrecognized_otlp"); + return events; + } + for (const [resourceKey, scopeKey, recordsKey, type, clock] of [ + ["resourceSpans", "scopeSpans", "spans", "otel.span", "startTimeUnixNano"], + ["resourceLogs", "scopeLogs", "logRecords", "otel.log", "timeUnixNano"], + ]) { + if (!Object.hasOwn(payload, resourceKey)) continue; + for (const resource of array(payload[resourceKey])) { + if (!object(resource)) { + report("malformed_otlp"); + continue; + } + for (const scope of array(resource[scopeKey])) { + if (!object(scope)) { + report("malformed_otlp"); + continue; + } + for (const record of array(scope[recordsKey])) { + if (!object(record)) { + report("malformed_otlp"); + continue; + } + const context = { + ...(resource.resource !== undefined ? { resource: structuredClone(resource.resource) } : {}), + ...(scope.scope !== undefined ? { scope: structuredClone(scope.scope) } : {}), + ...(resource.schemaUrl !== undefined ? { resourceSchemaUrl: resource.schemaUrl } : {}), + ...(scope.schemaUrl !== undefined ? { scopeSchemaUrl: scope.schemaUrl } : {}), + }; + const timestamp = Object.hasOwn(record, clock) ? record[clock] : type === "otel.log" ? record.observedTimeUnixNano : undefined; + /** @type {SessionEvent} */ + const observation = { + type: type === "otel.span" ? "otel.span" : "otel.log", + data: { ...structuredClone(record), ...context }, + ...(timestamp !== undefined && timestamp !== null ? { timestamp } : {}), + }; + events.push(observation); + if (type === "otel.span" && record.events !== undefined) { + // Span events have their own clocks; do not substitute the span start. + delete observation.data.events; + for (const event of array(record.events)) { + if (!object(event)) { + report("malformed_otlp"); + continue; + } + events.push({ + type: "otel.span_event", + data: { ...structuredClone(event), ...context, ...(record.traceId !== undefined ? { traceId: record.traceId } : {}), ...(record.spanId !== undefined ? { spanId: record.spanId } : {}) }, + ...(event.timeUnixNano !== undefined && event.timeUnixNano !== null ? { timestamp: event.timeUnixNano } : {}), + }); + } + } + } + } + } + } + return events; +} + +module.exports = { normalizeOtelEvents }; diff --git a/actions/setup/js/unified_session_otel.test.cjs b/actions/setup/js/unified_session_otel.test.cjs new file mode 100644 index 00000000000..333fffdbefc --- /dev/null +++ b/actions/setup/js/unified_session_otel.test.cjs @@ -0,0 +1,288 @@ +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import fs from "node:fs"; +import os from "node:os"; +import path from "node:path"; +import { collectUnifiedSession, writeUnifiedSession } from "./unified_session.cjs"; +import { normalizeOtelEvents } from "./unified_session_otel.cjs"; +import { validateSession } from "./scripts/validate_session.cjs"; +import { generatePlainTextSummary } from "./log_parser_shared.cjs"; + +const traceId = "0123456789abcdef0123456789abcdef"; +const spanId = "0123456789abcdef"; +const payload = { + resourceSpans: [ + { + resource: { attributes: [{ key: "service.name", value: { stringValue: "gh-aw" } }] }, + schemaUrl: "resource-schema", + scopeSpans: [ + { + scope: { name: "gh-aw", version: "1" }, + schemaUrl: "scope-schema", + spans: [ + { + traceId, + spanId, + parentSpanId: "abcdef0123456789", + name: "github.api.run", + startTimeUnixNano: "1790899200000000001", + endTimeUnixNano: "1790899200000000009", + status: { code: 2, message: "failed" }, + attributes: [{ key: "count", value: { intValue: "0" } }], + events: [{ timeUnixNano: "1790899200000000004", name: "retry", attributes: [{ key: "retry", value: { boolValue: false } }] }], + links: [{ traceId, spanId }], + }, + { traceId, spanId: "abcdef0123456789", name: "setup", startTimeUnixNano: "1790899200000000000" }, + ], + }, + ], + }, + ], + resourceLogs: [ + { + resource: { attributes: [] }, + scopeLogs: [ + { + scope: { name: "logger" }, + logRecords: [ + { traceId, spanId, timeUnixNano: "1790899200000000003", severityNumber: 9, severityText: "INFO", body: { stringValue: " first line\nsecond line " } }, + { observedTimeUnixNano: "1790899200000000005", body: { kvlistValue: { values: [{ key: "flag", value: { boolValue: false } }] } } }, + { body: { stringValue: "" } }, + ], + }, + ], + }, + ], +}; + +describe("Unified OTel observations", () => { + let root; + beforeEach(() => { + root = fs.mkdtempSync(path.join(os.tmpdir(), "gh-aw-unified-otel-")); + }); + afterEach(() => { + vi.unstubAllEnvs(); + vi.unstubAllGlobals(); + fs.rmSync(root, { recursive: true, force: true }); + }); + const write = (root, file, entries) => { + const target = path.join(root, file); + fs.mkdirSync(path.dirname(target), { recursive: true }); + fs.writeFileSync(target, entries.map(JSON.stringify).join("\n") + "\n"); + }; + + it("expands spans, span events and log messages with context, observed clocks and exact payloads", () => { + const original = structuredClone(payload); + const events = normalizeOtelEvents(payload, code => { + throw new Error(code); + }); + expect(events).toHaveLength(6); + expect(events[0]).toMatchObject({ + type: "otel.span", + timestamp: "1790899200000000001", + data: { + traceId, + spanId, + parentSpanId: "abcdef0123456789", + name: "github.api.run", + resource: payload.resourceSpans[0].resource, + scope: { name: "gh-aw", version: "1" }, + resourceSchemaUrl: "resource-schema", + scopeSchemaUrl: "scope-schema", + links: [{ traceId, spanId }], + }, + }); + expect(events[0].data).not.toHaveProperty("events"); + expect(events[1]).toMatchObject({ type: "otel.span_event", timestamp: "1790899200000000004", data: { traceId, spanId, name: "retry" } }); + expect(events[3].data.body).toEqual(payload.resourceLogs[0].scopeLogs[0].logRecords[0].body); + expect(events[4].timestamp).toBe("1790899200000000005"); + expect(events[5]).not.toHaveProperty("timestamp"); + expect(payload).toEqual(original); + }); + + it("imports and persists a single authoritative mirror interleaved with agent, AWF, MCPG and API records", () => { + write(root, "otel.jsonl", [payload]); + write(root, "usage/otel.jsonl", [payload]); + write(root, "agent-session.jsonl", [{ type: "assistant.message", timestamp: "2026-10-02T00:00:00.000000002Z", data: { content: "answer" } }]); + write(root, "mcp-logs/rpc.jsonl", [{ event: "REQUEST", timestamp: 1790899200000, server_name: "github" }]); + write(root, "sandbox/firewall/logs/audit.jsonl", [{ ts: 1790899200, event: "http_access", status: 200 }]); + write(root, "github_rate_limits.jsonl", [{ ts: 1790899200000, remaining: 0 }]); + const events = writeUnifiedSession({ + rootDir: root, + warn: code => { + throw new Error(code); + }, + }); + expect(events.slice(1, 10).map(event => event.data.name ?? event.type)).toEqual(["setup", "mcp.rpc.request", "firewall.http_access", "github_api.rate_limit", "github.api.run", "assistant.message", "otel.log", "retry", "otel.log"]); + expect(events.filter(event => event.provenance.component === "otel")).toHaveLength(6); + expect(events.at(-1).data.sources.filter(source => source.component === "otel")).toEqual([{ component: "otel", phase: "agent", path: "otel.jsonl", events: 6, timestampUnit: "nanoseconds" }]); + const content = fs.readFileSync(path.join(root, "usage/aw_session.jsonl"), "utf8"); + expect(validateSession(content)).toBe(events.length); + expect(content).toContain("first line\\nsecond line"); + expect(writeUnifiedSession({ rootDir: root })).toEqual(events); + const summary = generatePlainTextSummary(events); + expect(summary).toContain("name=github.api.run"); + expect(summary).toContain(`traceId=${traceId}`); + expect(summary).toContain("severityText=INFO"); + expect(summary).not.toContain("first line"); + }); + + it("uses the copied mirror only when the primary is absent, including separate detection evidence", () => { + write(root, "usage/otel.jsonl", [payload]); + write(root, "threat-detection/otel.jsonl", [{ resourceLogs: payload.resourceLogs }]); + const events = collectUnifiedSession({ rootDir: root }).events; + expect(events.filter(event => event.provenance.component === "otel")).toHaveLength(9); + expect(events.some(event => event.provenance.path === "usage/otel.jsonl")).toBe(true); + expect(events.filter(event => event.provenance.phase === "detection")).toHaveLength(3); + fs.writeFileSync(path.join(root, "otel.jsonl"), ""); + expect(collectUnifiedSession({ rootDir: root }).events.filter(event => event.provenance.component === "otel")).toHaveLength(3); + }); + + it("reports malformed nested records and JSONL while retaining adjacent valid messages", () => { + write(root, "otel.jsonl", [ + { resourceSpans: [null, { scopeSpans: [{ spans: [false, { name: "valid", events: [null, { name: "event" }] }] }] }] }, + { resourceLogs: [{ scopeLogs: "invalid" }] }, + { unsupported: true }, + { resourceLogs: payload.resourceLogs }, + ]); + fs.appendFileSync(path.join(root, "otel.jsonl"), "{broken\n"); + const warnings = []; + const events = collectUnifiedSession({ rootDir: root, warn: warning => warnings.push(warning) }).events; + expect(events.filter(event => event.provenance.component === "otel")).toHaveLength(5); + expect(warnings).toHaveLength(6); + expect(events.at(-1).data.warnings).toBe(6); + expect(events.at(-1).data.untimedEvents).toBe(3); + expect(events.filter(event => event.type === "session.collection_warning").map(event => event.data.code)).toEqual(["malformed_jsonl", "malformed_otlp", "malformed_otlp", "malformed_otlp", "malformed_otlp", "unrecognized_otlp"]); + }); + + it("does not follow a symlinked mirror", () => { + write(root, "private.jsonl", [payload]); + fs.symlinkSync(path.join(root, "private.jsonl"), path.join(root, "otel.jsonl")); + const warnings = []; + const events = collectUnifiedSession({ rootDir: root, warn: warning => warnings.push(warning) }).events; + expect(events.some(event => event.provenance.component === "otel")).toBe(false); + expect(warnings).toEqual([expect.stringContaining("symlink_not_read")]); + }); + + it("keeps missing and invalid span-event clocks untimed instead of inheriting their span start", () => { + write(root, "otel.jsonl", [ + { + resourceSpans: [ + { + scopeSpans: [ + { + spans: [ + { + traceId, + spanId, + name: "parent", + startTimeUnixNano: "1000000", + events: [{ name: "missing" }, { name: "invalid", timeUnixNano: "invalid" }, { name: "null", timeUnixNano: null }, { name: "observed", timeUnixNano: "2000000" }], + }, + ], + }, + ], + }, + ], + }, + ]); + const events = collectUnifiedSession({ rootDir: root }).events; + const observed = events.filter(event => event.provenance.component === "otel"); + expect(observed.map(event => event.data.name)).toEqual(["parent", "observed", "missing", "invalid", "null"]); + expect(observed[2]).not.toHaveProperty("timestamp"); + expect(observed[2].provenance).not.toHaveProperty("timestampMs"); + expect(observed[3].timestamp).toBe("invalid"); + expect(observed[3].provenance).not.toHaveProperty("timestampMs"); + expect(observed[4]).not.toHaveProperty("timestamp"); + expect(observed[4].provenance).not.toHaveProperty("timestampMs"); + expect(observed.filter(event => event.type === "otel.span_event").every(event => event.data.traceId === traceId && event.data.spanId === spanId)).toBe(true); + expect(events.at(-1).data.untimedEvents).toBe(3); + expect(validateSession(events.map(JSON.stringify).join("\n") + "\n")).toBe(events.length); + }); + + it("preserves explicit zero log clocks instead of replacing them with observation clocks", () => { + write(root, "otel.jsonl", [ + { + resourceLogs: [ + { + scopeLogs: [ + { + logRecords: [ + { timeUnixNano: "0", observedTimeUnixNano: "9000000", body: { stringValue: "epoch" }, severityNumber: 0 }, + { observedTimeUnixNano: "1000000", body: { stringValue: "observed" } }, + { body: { stringValue: "untimed" } }, + { timeUnixNano: null, observedTimeUnixNano: "2000000", body: { stringValue: "explicit null" } }, + ], + }, + ], + }, + ], + }, + ]); + const events = collectUnifiedSession({ rootDir: root }).events; + const logs = events.filter(event => event.type === "otel.log"); + expect(logs[0]).toMatchObject({ timestamp: "0", data: { timeUnixNano: "0", observedTimeUnixNano: "9000000", severityNumber: 0 }, provenance: { timestampMs: 0 } }); + expect(logs[1]).toMatchObject({ timestamp: "1000000", provenance: { timestampMs: 1 } }); + const untimed = logs.filter(log => !Object.hasOwn(log, "timestamp")); + const explicitNull = untimed.find(log => log.data.body?.stringValue === "explicit null"); + expect(explicitNull).toBeDefined(); + expect(explicitNull).not.toHaveProperty("timestamp"); + expect(explicitNull.provenance).not.toHaveProperty("timestampMs"); + expect(untimed).toHaveLength(2); + expect(events.at(-1).data.untimedEvents).toBe(2); + }); + + it("redacts decoded secrets and registered masks in OTel bodies, attributes and correlation identifiers before persistence", () => { + const secret = "otel-private-value"; + const mask = "otel-registered-mask"; + vi.stubEnv("GH_AW_SECRET_NAMES", "OTEL_TEST_SECRET"); + vi.stubEnv("SECRET_OTEL_TEST_SECRET", secret); + vi.stubGlobal("core", { info: vi.fn(), debug: vi.fn(), warning: vi.fn() }); + write(root, "otel.jsonl", [ + { + resourceLogs: [ + { + resource: { attributes: [{ key: "custom.resource", value: { stringValue: secret } }] }, + scopeLogs: [ + { + scope: { name: "logger", version: secret }, + logRecords: [ + { + traceId: secret, + spanId: mask, + timeUnixNano: "1000000", + body: { stringValue: ` ${secret}\n${mask} ` }, + attributes: [{ key: "custom.message", value: { stringValue: secret } }], + }, + ], + }, + ], + }, + ], + }, + ]); + fs.writeFileSync(path.join(root, "agent-stdio.log"), `::add-mask::${mask}\n`); + write(root, "agent-session.jsonl", [{ type: "assistant.message", data: { content: "observed answer" } }]); + writeUnifiedSession({ + rootDir: root, + warn: warning => { + throw new Error(warning); + }, + }); + const content = fs.readFileSync(path.join(root, "usage/aw_session.jsonl"), "utf8"); + expect(content).not.toContain(secret); + expect(content).not.toContain(mask); + const log = content + .trimEnd() + .split("\n") + .map(JSON.parse) + .find(event => event.type === "otel.log"); + expect(log.data.traceId).toBe("***REDACTED***"); + expect(log.data.spanId).toBe("***"); + expect(log.data.body.stringValue).toBe(" ***REDACTED***\n*** "); + expect(log.data.resource.attributes[0].value.stringValue).toBe("***REDACTED***"); + expect(log.data.attributes[0].value.stringValue).toBe("***REDACTED***"); + expect(log.data.scope.version).toBe("***REDACTED***"); + expect(log.provenance.timestampMs).toBe(1); + expect(validateSession(content)).toBe(content.trimEnd().split("\n").length); + }); +}); diff --git a/actions/setup/js/unified_session_render.cjs b/actions/setup/js/unified_session_render.cjs index 5974e62ff15..5a370236bd5 100644 --- a/actions/setup/js/unified_session_render.cjs +++ b/actions/setup/js/unified_session_render.cjs @@ -43,6 +43,10 @@ const RUNTIME_TYPES = new Set([ "execution.result", "detection.result", "workflow.info", + "github_api.rate_limit", + "otel.span", + "otel.span_event", + "otel.log", ]); /** @param {Array} events @returns {boolean} */ @@ -155,6 +159,12 @@ function eventDetail(event) { return fields(data, ["event", "serverName", "level", "status"]); case "firewall.event": return fields(data, ["event", "level", "status"]); + case "github_api.rate_limit": + return fields(data, ["source", "operation", "resource", "status", "remaining", "limit", "attempt", "delayMs"]); + case "otel.span": + case "otel.span_event": + case "otel.log": + return fields(data, ["name", "traceId", "spanId", "parentSpanId", "severityText", "severityNumber"]) + (data.status ? ` ${fields(data.status, ["code", "message"])}` : ""); case "safe_output.request": return `${fields(data, ["type", "repo", "number"])} [requested, not executed]`; case "safe_output.result": diff --git a/actions/setup/session_parsers.go b/actions/setup/session_parsers.go index c2c01f8a6f0..1216deb55d3 100644 --- a/actions/setup/session_parsers.go +++ b/actions/setup/session_parsers.go @@ -6,6 +6,7 @@ import "embed" // dependencies, not test fixtures. The CLI uses the same sources as Actions. // //go:embed js/session_cli.cjs js/unified_session.cjs js/unified_session_payload.cjs js/unified_session_render.cjs +//go:embed js/unified_session_order.cjs js/unified_session_otel.cjs //go:embed js/parse_claude_log.cjs js/parse_codex_log.cjs js/parse_copilot_log.cjs js/parse_gemini_log.cjs //go:embed js/parse_custom_log.cjs js/parse_pi_log.cjs js/parse_opencode_log.cjs js/parse_goose_log.cjs //go:embed js/parse_agy_log.cjs diff --git a/docs/public/schemas/unified-session.schema.json b/docs/public/schemas/unified-session.schema.json index 1a96e7db4a7..ce7b70fe74f 100644 --- a/docs/public/schemas/unified-session.schema.json +++ b/docs/public/schemas/unified-session.schema.json @@ -368,7 +368,7 @@ "phase": { "type": "string" }, "path": { "type": "string" }, "events": { "$ref": "#/definitions/SessionCount" }, - "timestampUnit": { "type": "string", "enum": ["seconds", "milliseconds"] } + "timestampUnit": { "type": "string", "enum": ["seconds", "milliseconds", "nanoseconds"] } }, "required": ["component", "phase", "path", "events"], "additionalProperties": false diff --git a/docs/src/content/docs/specs/unified-agent-session-specification.md b/docs/src/content/docs/specs/unified-agent-session-specification.md index f129b0960cc..b6f9960375f 100644 --- a/docs/src/content/docs/specs/unified-agent-session-specification.md +++ b/docs/src/content/docs/specs/unified-agent-session-specification.md @@ -3,9 +3,9 @@ title: Unified Agent Session Specification description: Draft contract for canonical engine traces and essential unified session payloads across gh-aw runtime components. sidebar: order: 1365 -version: "1.7.0" +version: "1.8.0" status: Draft -publication_date: "2026-10-09" +publication_date: "2026-10-10" editors: - name: GitHub Agentic Workflows Team organization: GitHub @@ -13,9 +13,9 @@ editors: # Unified Agent Session Specification -**Version**: 1.7.0
+**Version**: 1.8.0
**Status**: Draft
-**Publication Date**: 2026-10-09
+**Publication Date**: 2026-10-10
**Editors**: GitHub Agentic Workflows Team (GitHub)
**This Version**: [unified-agent-session-specification](/gh-aw/specs/unified-agent-session-specification/)
**Latest Version**: This document @@ -30,7 +30,7 @@ This specification defines the session traces used by GitHub Agentic Workflows: This is a **GitHub Agentic Workflows project specification**, written using W3C-inspired document conventions. It is **not an official W3C standard**, W3C publication, or W3C-endorsed recommendation. -Version 1.7.0 is a draft governed by the project's normal review process. It may be updated, replaced, or superseded. The accompanying implementation and regression suites exercise this contract, including the sampled CI sessions identified in Section 9.4. This is not a blanket declaration of conformance for every engine version or source format. Section 10 records historical pre-implementation gaps, not current defects. Approval and ongoing compliance testing remain project responsibilities. +Version 1.8.0 is a draft governed by the project's normal review process. It may be updated, replaced, or superseded. The accompanying implementation and regression suites exercise this contract, including the sampled CI sessions identified in Section 9.4. This is not a blanket declaration of conformance for every engine version or source format. Section 10 records historical pre-implementation gaps, not current defects. Approval and ongoing compliance testing remain project responsibilities. The specification version belongs to this document. The unified file's leading `session.format` record carries an independent numeric serialization-format @@ -250,6 +250,11 @@ opaque because its essential fields are not defined by this specification. | Model routing | `firewall.model_routing` retains its stage, purpose, provider, labels, selection, endpoint, router, request, outcome, and deviation fields. `workflow.info` includes the observed `model`, `requestedModel`, and a compact `modelRouting` object. `model_routing.outcome` records the harness's status, wire model, effective and selected endpoints, effort, applied effort, and failure code. | | Episode lineage | `workflow.info.episode` retains supplied `episodeId`, `hopId`, `parentHopId`, `originEvent`, `rootRepo`, `rootWorkflowId`, and `rootRunId` from runner-owned `aw_info.json` context. No arbitrary caller context, credentials, or work-queue payloads. | +OpenTelemetry observations use `otel.span`, `otel.span_event`, and `otel.log`. +They retain trace/span/parent IDs, names, status, attributes, links, log bodies +and severity, resource/scope context, and original Unix-nanosecond clocks. Span +events are separate observations rather than duplicated inside the span payload. + Known payload aliases MUST use one canonical key, preferring an explicitly present canonical value even when it is `false`, `0`, `null`, or empty. `parameters` maps to `input`; `result` maps to `output` when `output` is absent. @@ -281,7 +286,7 @@ disambiguate sources. A preexisting native `provenance` field MUST survive under The TypeScript `SessionProvenance`, `UnifiedSessionEvent`, and `UnifiedSession` types describe this additive envelope. Components include `agent`, `mcp`, `firewall`, `safe_output`, `experiment`, `grader`, `eval`, `usage`, `execution`, -`detection`, `workflow`, and `collector`. Phases distinguish agent and detection +`detection`, `workflow`, `github_api`, `otel`, and `collector`. Phases distinguish agent and detection traffic, activation snapshots, evals, safe-output execution, and conclusion collection. A component is not an engine name or a success claim. @@ -305,23 +310,37 @@ MUST report a missing, invalid, or unsupported version instead of silently assuming compatibility. Parser-only canonical arrays and `agent-session.jsonl` are source traces, not versioned unified files, and do not require this header. -**T-UAS-056 — Timestamp ordering.** After the file-format header, events with a -supported source timestamp MUST sort ascending by `provenance.timestampMs`. The merger MUST preserve native +**T-UAS-056 — Timestamp ordering.** After the file-format header, the merger MUST +interleave sources by supported timestamps while preserving each sequential +source's normalized event order. A regressing clock MUST NOT reverse source-local +observations. For merging only, each sequential source uses a nondecreasing +ordering anchor: its first valid timestamp anchors preceding untimed records, +and subsequent records use the latest timestamp observed so far. These anchors +MUST NOT be written as observed timestamps. The merger MUST preserve native timestamp values and MUST derive its ordering key using the source schema's units, not an epoch-magnitude heuristic. ISO timestamps MUST carry a timezone. Numeric Squid audit timestamps use Unix seconds; native agent timestamps and token-tracker audit `ts` values use milliseconds. Pi's observed -`message.timestamp` is also a supported source timestamp. Timestamp precision is -limited to the JavaScript ordering key; original source precision remains -preserved. +`message.timestamp` is also a supported source timestamp. ISO fractional seconds +and OTLP decimal-string Unix nanoseconds MUST be compared at nanosecond precision. +`provenance.timestampMs` is an observed millisecond projection, not the exact +ordering key; native timestamps retain their original precision. + +OTLP export envelopes are unordered batches, not sequential execution streams. +Their expanded spans, span events, and logs MUST sort by their own observed +timestamps, regardless of export order. A span uses `startTimeUnixNano`; a span +event uses `timeUnixNano`; a log uses `timeUnixNano`, falling back to supplied +`observedTimeUnixNano` only when the former is absent. The merger MUST NOT +substitute a containing span's clock for an untimed span event. **T-UAS-057 — Untimed and tied observations.** Missing or invalid timestamps -MUST NOT cause observations to be discarded. Except for the pinned file-format -header, untimed observations MUST follow all timed events. Equal-time events and -untimed events MUST preserve the deterministic source enumeration and source-local -array order. The merger MUST -NOT substitute file modification time, collection time, a neighboring event's -time, or an inferred tool duration for absent evidence. Wall-clock ordering +MUST NOT cause observations to be discarded. Untimed sequential observations MUST +stay in source-local order using the merge-only anchors in T-UAS-056. Completely +untimed sources and untimed OTLP observations MUST follow anchored observations. +Equal ordering keys and unanchored observations MUST preserve deterministic source +enumeration and source-local array order. The merger MUST NOT fabricate an +observed timestamp from file modification time, collection time, a neighboring +event's time, or an inferred tool duration. Wall-clock ordering does not establish causality or correct cross-process clock skew. **T-UAS-058 — Authoritative source selection.** A persisted canonical agent @@ -333,6 +352,18 @@ and count them as separate observations. Replicated firewall paths MUST select layouts; an existing empty authoritative file MUST suppress its older copy. Distinct gateway streams and events MUST remain separate observations. +For agent-phase OTel evidence, `otel.jsonl` takes precedence over +`usage/otel.jsonl`, including an empty primary mirror. Detection evidence uses +`threat-detection/otel.jsonl`, then `usage/threat-detection/otel.jsonl`. +The collector MUST expand OTLP `resourceSpans[].scopeSpans[].spans[]` and +`resourceLogs[].scopeLogs[].logRecords[]`, retaining resource and scope context. +Malformed nested entries MUST emit collection warnings without discarding +adjacent valid spans or messages. Only available local mirrors are imported; +collection MUST NOT fetch an OTLP backend or infer missing engine spans. +Publication summaries show span identity, severity, and status rather than +dumping log bodies, attributes, links, or resource payloads. Artifact secret +redaction and symlink protections apply to these sources as to other traces. + Native Copilot session files MUST pass through the Copilot adapter before essential-payload projection so model selection, streamed assistant text, tool correlation, finalized turns, and shutdown usage remain available. The agent @@ -1366,7 +1397,7 @@ Recommended execution is fixture parsing, canonical structural assertions, accou | T-UAS-046, T-UAS-047, T-UAS-048 | Canonical snapshots, alias usage, zero/missing metrics, existing telemetry, no trailing newline, failed append | Correct single projection; no double counting/defaults; safe line boundary; best-effort failure; activity not success. | | T-UAS-049, T-UAS-050 | Hostile HTML/fences, mask values, oversized display, partial parse boundary | Safe/redacted publication, explicit truncation, canonical source remains unchanged. | | T-UAS-051, T-UAS-052, T-UAS-053 | Conformance report and isolated test harness | Applicable IDs covered; structural/round-trip/purity assertions; no real production I/O. | -| T-UAS-054–T-UAS-064 | Six engine adapters; interleaved MCPG/AWF sources; downstream snapshots/results; leading numeric format version; timestamp units and ties; malformed/missing logs; read/write failure; escaped secrets and symlinks | Complete compact `aw_session.jsonl`, pinned format header, provenance and payload preservation, deterministic chronology and untimed tail, explicit coverage, safe atomic persistence, existing accounting unchanged. | +| T-UAS-054–T-UAS-064 | Six engine adapters; interleaved agent/MCPG/AWF/GitHub API/OTel sources; downstream snapshots/results; leading numeric format version; timestamp units, ties, regressions, and nanoseconds; malformed/missing logs; read/write failure; escaped secrets and symlinks | Complete compact `aw_session.jsonl`, pinned format header, provenance and payload preservation, deterministic source-preserving interleaving, unanchored tail, explicit coverage, safe atomic persistence, existing accounting unchanged. | | T-UAS-065–T-UAS-066 | Unified file through both publication sinks and the conversation renderer; colliding source IDs; overlapping accounting; hostile/secret text; exhausted summary budget | Known runtime types remain visible, scopes and accounting remain independent, private prompts/payloads stay omitted, output is bounded and safely redacted, source artifact remains intact. | | T-UAS-067 | Repeated native/canonical/detector error observations, live timeout evidence, final-zero and missing exits, malformed or duplicate aggregate records, quoted errors and tool failures | One deterministic `agent.execution` record with distinct native codes/types, stable categories, observed exit precedence, unchanged error evidence, and matching JS/Go reader validation. | | T-UAS-068 | Goose stream messages/deltas, tool requests/results, cumulative completion usage, source-second timestamps, malformed records, error-only and partial sessions | Exact supported content and IDs, observed outcomes only, no duplicated snapshots or invented partial results, explicit diagnostics. | @@ -1854,6 +1885,12 @@ Native IDs can collide, timestamps can be out of order, and a trace can contain ## 13. Change Log (Informative) +### Version 1.8.0 — Draft (2026-10-10) + +- Preserved sequential source order across missing timestamps and clock regressions while interleaving agent, AWF, MCPG, and GitHub API evidence. +- Imported local OTLP spans, span events, and log messages with resource/scope context and nanosecond ordering; kept publication summaries metadata-only. +- Updated the ordering validator and regression coverage without changing the numeric serialization-format version. + ### Version 1.7.0 — Draft (2026-10-09) - Added final agent workflow metadata and compact model-routing attribution to `workflow.info`.