diff --git a/PR-COMMENT.md b/PR-COMMENT.md new file mode 100644 index 000000000..85d87e90c --- /dev/null +++ b/PR-COMMENT.md @@ -0,0 +1,13 @@ +Thank you for the review guidance. I understand that maintainer review is still pending. + +Verification used Windows 10.0.19045.0, supported Node v22.23.3 and npm 10.9.9, with Temporal CLI 1.9.1 / Server 1.32.0. +Tested HEAD: 98bcb3859778b85951c6f15902fe82f156562f9e plus the PR working-tree changes. +Recorded contracts/runtime/worker builds and API/worker type checks passed; runtime tests passed 7 tests and the API selection passed 14. +OPEN BLOCKER: the initial worker selection timed out (46 passed, 1 failed, 1 skipped). Its unchanged rerun passed, but further sequential repeats passed twice and failed once with the same 5000ms continuity-test timeout. +Each new passing repeat had 47 passed and 1 skipped; the failed repeat had 46 passed, 1 failed and 1 skipped. The cause remains unknown; no timeout or behavior change was made. +All 6 Temporal/HTTP integration tests, including replay emitting zero spans and secret-sentinel assertions, passed in both new passing repeats; only the unavailable-server diagnostic was skipped. +The recorded full worker suite had 242 passed, 14 failed and 1 skipped; the same 14 failures reproduced on the merge-base. +The recorded root check passed 7 architecture tests before the Windows gateway bundler failed; that bundler failure also reproduced on the merge-base. +The earlier Node 20 undici error did not recur. Windows socket, symlink, fsync, path and permission limitations remain. +Removed only the two reported extra EOF blank lines; whole-tree git diff --check now exits 0. Historical failed results are retained. +See NOTES.md, "Verification for review" and its latest audit follow-up, for commands, counts, baseline comparisons, limitations and log locations. Stable targeted verification is still blocked. diff --git a/apps/api/src/memory-consolidation-coordinator.ts b/apps/api/src/memory-consolidation-coordinator.ts index df237c648..5f5f9aa32 100644 --- a/apps/api/src/memory-consolidation-coordinator.ts +++ b/apps/api/src/memory-consolidation-coordinator.ts @@ -1,3 +1,4 @@ +import { traceparentForTraceId, workflowCorrelationMemo } from "./trace-context.js"; import { Client, Connection } from "@temporalio/client"; import { MEMORY_CONSOLIDATION_TASK_QUEUE, @@ -16,6 +17,7 @@ export interface MemoryConsolidationStartResult { } interface WorkflowStartOptions { + memo?: Record; args: [MemoryConsolidationWorkflowInput]; taskQueue: typeof MEMORY_CONSOLIDATION_TASK_QUEUE; workflowId: string; @@ -43,9 +45,11 @@ export async function scheduleMemoryConsolidation( startWorkflow: MemoryConsolidationWorkflowStarter ): Promise { const input = memoryConsolidationWorkflowInputSchema.parse(rawInput); + const traceparent = traceparentForTraceId(input.traceId); try { const handle = await startWorkflow(MEMORY_CONSOLIDATION_WORKFLOW_TYPE, { args: [input], + ...(traceparent ? { memo: workflowCorrelationMemo({ traceId: input.traceId, traceparent }) } : {}), taskQueue: MEMORY_CONSOLIDATION_TASK_QUEUE, workflowId, workflowIdReusePolicy: "REJECT_DUPLICATE", diff --git a/apps/api/src/memory-mutation-coordinator.ts b/apps/api/src/memory-mutation-coordinator.ts index f7d3d48bb..b33c4e4aa 100644 --- a/apps/api/src/memory-mutation-coordinator.ts +++ b/apps/api/src/memory-mutation-coordinator.ts @@ -1,3 +1,4 @@ +import { traceparentForTraceId, workflowCorrelationMemo } from "./trace-context.js"; import { Client, Connection } from "@temporalio/client"; import { MEMORY_MUTATION_TASK_QUEUE, @@ -17,6 +18,7 @@ export interface MemoryMutationStartResult { } interface WorkflowStartOptions { + memo?: Record; args: [MemoryMutationWorkflowInput]; taskQueue: typeof MEMORY_MUTATION_TASK_QUEUE; workflowId: string; @@ -45,9 +47,11 @@ export async function scheduleMemoryMutation( ): Promise { const input = memoryMutationWorkflowInputSchema.parse(rawInput); const workflowId = buildMemoryMutationWorkflowId(input.changeSetId, commandHash); + const traceparent = traceparentForTraceId(input.traceId); try { const handle = await startWorkflow(MEMORY_MUTATION_WORKFLOW_TYPE, { args: [input], + ...(traceparent ? { memo: workflowCorrelationMemo({ traceId: input.traceId, traceparent }) } : {}), taskQueue: MEMORY_MUTATION_TASK_QUEUE, workflowId, workflowIdReusePolicy: "REJECT_DUPLICATE", diff --git a/apps/api/src/trace-context.ts b/apps/api/src/trace-context.ts index af9e55efd..f45617fc6 100644 --- a/apps/api/src/trace-context.ts +++ b/apps/api/src/trace-context.ts @@ -96,7 +96,7 @@ export const requestTraceContexts = new TraceContextRegistry(); /** traceparent for work started on behalf of this Space request id, if known. */ export function traceparentForTraceId(traceId: string | null | undefined, registry = requestTraceContexts): string | null { - return childTraceparent(registry.lookup(traceId)?.traceparent ?? null); + return registry.lookup(traceId)?.traceparent ?? null; } /** Adds the request's traceparent to a turn input unless it already has a valid one. */ diff --git a/apps/api/tests/otlp-parent-continuity.test.ts b/apps/api/tests/otlp-parent-continuity.test.ts new file mode 100644 index 000000000..e8b7cd085 --- /dev/null +++ b/apps/api/tests/otlp-parent-continuity.test.ts @@ -0,0 +1,21 @@ +import { describe, expect, it } from "vitest"; +import { createRequestTraceContext, requestTraceContexts, traceparentForTraceId } from "../src/trace-context.js"; +import { scheduleMemoryConsolidation } from "../src/memory-consolidation-coordinator.js"; +import { scheduleMemoryMutation } from "../src/memory-mutation-coordinator.js"; + +describe("OTLP API parent continuity", () => { + it("uses the exported request span for direct turn and memory workflow starts", async () => { + const context = createRequestTraceContext(undefined); + const traceId = "req:otlp-parent-test"; + requestTraceContexts.remember(traceId, context); + expect(traceparentForTraceId(traceId)).toBe(context.traceparent); + const memos: unknown[] = []; + const start = async (_type: string, options: { workflowId: string; memo?: Record }) => { + memos.push(options.memo); + return { workflowId: options.workflowId }; + }; + await scheduleMemoryConsolidation({ runId: "audit:test", traceId }, "workflow:test", start); + await scheduleMemoryMutation({ changeSetId: "change:test", traceId }, start); + expect(memos).toEqual([0, 1].map(() => ({ spaceTraceId: traceId, traceparent: context.traceparent, w3cTraceId: context.w3cTraceId }))); + }); +}); diff --git a/apps/api/tests/trace-correlation.test.ts b/apps/api/tests/trace-correlation.test.ts index ff8a47758..61d7e49fd 100644 --- a/apps/api/tests/trace-correlation.test.ts +++ b/apps/api/tests/trace-correlation.test.ts @@ -50,6 +50,7 @@ describe("request trace context", () => { registry.remember("req:dddddddddddd", createRequestTraceContext(inbound)); const filled = withTurnTraceparent({ traceId: "req:dddddddddddd" }, registry); expect(parseTraceparent(filled.traceparent)?.traceId).toBe(inboundTraceId); + expect(filled.traceparent).toBe(registry.lookup("req:dddddddddddd")?.traceparent); const kept = withTurnTraceparent({ traceId: "req:dddddddddddd", traceparent: inbound }, registry); expect(kept.traceparent).toBe(inbound); expect(withTurnTraceparent({ traceId: "req:unknown00000" }, registry)).toEqual({ traceId: "req:unknown00000" }); diff --git a/apps/worker/package.json b/apps/worker/package.json index abd012313..ea0fb80b9 100644 --- a/apps/worker/package.json +++ b/apps/worker/package.json @@ -26,6 +26,7 @@ "undici": "8.10.2" }, "devDependencies": { + "@temporalio/testing": "1.24.0", "typescript": "^5.9.3", "vitest": "^4.1.11" }, diff --git a/apps/worker/src/activity-observability.ts b/apps/worker/src/activity-observability.ts index ea4d021d1..e47fd1b54 100644 --- a/apps/worker/src/activity-observability.ts +++ b/apps/worker/src/activity-observability.ts @@ -1,7 +1,8 @@ +import { allowlistSpanAttributes } from "./tracing/span-attributes.js"; import { AsyncLocalStorage } from "node:async_hooks"; import { randomBytes } from "node:crypto"; import type { Context } from "@temporalio/activity"; -import type { ActivityInterceptorsFactory } from "@temporalio/worker"; +import { defaultPayloadConverter, type ActivityExecuteInput, type ActivityInterceptorsFactory } from "@temporalio/worker"; import { categorizeFailureCode, formatTraceparent, @@ -10,7 +11,8 @@ import { traceIdFromTraceparent, type FailureCategory } from "@space/contracts"; -import type { SpanExporter } from "@space/runtime"; +import { type SpanExporter } from "@space/runtime"; +import { TRACEPARENT_HEADER } from "./workflow-tracing-headers.js"; import { logIdentifier, workerLog, type WorkerLogValue } from "./worker-log.js"; import { workerMetrics, type WorkerMetrics } from "./worker-metrics.js"; @@ -135,16 +137,42 @@ export interface ObserveActivityDependencies { metrics?: WorkerMetrics; now?: () => number; cancelled?: () => boolean; - /** OTLP export (SPACE_OTEL_EXPORTER_OTLP_ENDPOINT): one span per activity whose input carries a traceparent. */ + /** + * OTLP export (SPACE_OTEL_EXPORTER_OTLP_ENDPOINT): one span per activity + * attempt under the workflow span (`space-traceparent` header) or, without + * that header, under the traceparent in the activity input. + */ spans?: SpanExporter | null; + /** The workflow span from the activity's `space-traceparent` header. */ + parentTraceparent?: string | null; } -function activityTraceparent(args: readonly unknown[]) { +function activityTraceparent(args: readonly unknown[], header: string | null | undefined) { + const fromHeader = parseTraceparent(header); + if (fromHeader) return fromHeader; const found: Partial> = {}; for (const arg of args) readCorrelation(arg, found, 2); return parseTraceparent(found.traceparent); } +/** The traceparent in a Temporal header, or null when absent or not a valid string payload. */ +export function traceparentFromHeaders(headers: ActivityExecuteInput["headers"] | undefined): string | null { + const payload = headers?.[TRACEPARENT_HEADER]; + if (!payload) return null; + try { + const value: unknown = defaultPayloadConverter.fromPayload(payload); + return parseTraceparent(value) ? (value as string) : null; + } catch { + return null; + } +} + +function randomSpanId(): string { + let spanId = randomBytes(8).toString("hex"); + while (/^0+$/.test(spanId)) spanId = randomBytes(8).toString("hex"); + return spanId; +} + export async function observeActivityExecution( info: ActivityInfo, args: readonly unknown[], @@ -194,19 +222,40 @@ export async function observeActivityExecution( queueMs, rssBytes: process.memoryUsage().rss }); - const parent = dependencies.spans ? activityTraceparent(args) : null; - if (parent) { - dependencies.spans!.record({ - traceId: parent.traceId, - spanId: randomBytes(8).toString("hex"), - parentSpanId: parent.parentId, - name: `activity ${activityType}`, - startTimeUnixNano: BigInt(startedAt) * 1_000_000n, - endTimeUnixNano: BigInt(startedAt + durationMs) * 1_000_000n, - attributes: { "space.activity_type": activityType, "space.outcome": outcome, "space.attempt": info.attempt }, - error: outcome === "FAILED" || outcome === "FAILED_RESULT", - kind: 1 - }); + // Export never affects the activity: a full queue drops, a bad span is skipped. + try { + const parent = dependencies.spans ? activityTraceparent(args, dependencies.parentTraceparent) : null; + if (parent) { + dependencies.spans!.record({ + traceId: parent.traceId, + spanId: randomSpanId(), + parentSpanId: parent.parentId, + name: `activity ${activityType}`, + startTimeUnixNano: BigInt(startedAt) * 1_000_000n, + endTimeUnixNano: BigInt(startedAt + durationMs) * 1_000_000n, + attributes: allowlistSpanAttributes({ + "temporal.activity.type": activityType, + "temporal.activity.id": info.activityId, + "temporal.activity.attempt": info.attempt, + "temporal.workflow.id": info.workflowExecution?.workflowId, + "temporal.workflow.run_id": info.workflowExecution?.runId, + "temporal.workflow.type": info.workflowType, + "space.outcome": outcome, + "error.code": reasonCode, + "space.error.category": category, + "space.duration_ms": durationMs, + "space.queue_ms": queueMs, + "space.trace_id": base.traceId, + "space.room_id": base.roomId, + "space.pane_id": base.paneId, + "space.mission_id": base.missionId, + }), + error: outcome === "FAILED" || outcome === "FAILED_RESULT", + kind: 1 + }); + } + } catch { + // Tracing is best effort. } }; @@ -229,6 +278,7 @@ export function createActivityObservabilityInterceptors(dependencies: Omit observeActivityExecution(context.info, input.args, () => next(input), { ...dependencies, + parentTraceparent: dependencies.spans ? traceparentFromHeaders(input.headers) : null, cancelled: () => context.cancellationSignal.aborted }) } diff --git a/apps/worker/src/memory-maintenance-worker.ts b/apps/worker/src/memory-maintenance-worker.ts index 28122f546..1c3e114ec 100644 --- a/apps/worker/src/memory-maintenance-worker.ts +++ b/apps/worker/src/memory-maintenance-worker.ts @@ -7,8 +7,7 @@ import { memoryMaintenanceWorkerOptions } from "./memory-maintenance-config.js"; import { DEFAULT_TEMPORAL_ADDRESS, DEFAULT_TEMPORAL_NAMESPACE } from "./constants.js"; -import { otlpSpanExporterFromEnv } from "@space/runtime"; -import { createActivityObservabilityInterceptors } from "./activity-observability.js"; +import { workerObservabilityOptions, workerTracing } from "./worker-tracing.js"; const service = "space-memory-maintenance-worker"; @@ -21,7 +20,7 @@ if (!memoryMaintenanceEnabled(process.env)) { try { const connection = await NativeConnection.connect({ address }); - const spans = otlpSpanExporterFromEnv(process.env, service); + const tracing = workerTracing(process.env, service); const worker = await Worker.create({ connection, namespace, @@ -29,7 +28,7 @@ if (!memoryMaintenanceEnabled(process.env)) { workflowsPath, activities, ...memoryMaintenanceWorkerOptions, - interceptors: { activity: [createActivityObservabilityInterceptors({ spans })] } + ...workerObservabilityOptions(tracing) }); console.log(JSON.stringify({ service, @@ -39,8 +38,11 @@ if (!memoryMaintenanceEnabled(process.env)) { taskQueue: MEMORY_MAINTENANCE_TASK_QUEUE, activityConcurrency: memoryMaintenanceWorkerOptions.maxConcurrentActivityTaskExecutions })); - await worker.run(); - await spans?.close(); + try { + await worker.run(); + } finally { + await tracing?.close(); + } } catch (error) { console.error(JSON.stringify({ service, diff --git a/apps/worker/src/memory-mutation-worker.ts b/apps/worker/src/memory-mutation-worker.ts index adc069daf..effe36d90 100644 --- a/apps/worker/src/memory-mutation-worker.ts +++ b/apps/worker/src/memory-mutation-worker.ts @@ -3,8 +3,7 @@ import { NativeConnection, Worker } from "@temporalio/worker"; import { executePersistedMemoryChangeSet } from "./memory-mutation-activity.js"; import { MEMORY_MUTATION_TASK_QUEUE, memoryMutationsEnabled, memoryMutationWorkerOptions } from "./memory-mutation-config.js"; import { DEFAULT_TEMPORAL_ADDRESS, DEFAULT_TEMPORAL_NAMESPACE } from "./constants.js"; -import { otlpSpanExporterFromEnv } from "@space/runtime"; -import { createActivityObservabilityInterceptors } from "./activity-observability.js"; +import { workerObservabilityOptions, workerTracing } from "./worker-tracing.js"; const service = "space-memory-mutation-worker"; @@ -14,7 +13,7 @@ if (!memoryMutationsEnabled(process.env)) { const address = process.env.SPACE_TEMPORAL_ADDRESS ?? DEFAULT_TEMPORAL_ADDRESS; const namespace = process.env.SPACE_TEMPORAL_NAMESPACE ?? DEFAULT_TEMPORAL_NAMESPACE; const connection = await NativeConnection.connect({ address }); - const spans = otlpSpanExporterFromEnv(process.env, service); + const tracing = workerTracing(process.env, service); const worker = await Worker.create({ connection, namespace, @@ -22,12 +21,12 @@ if (!memoryMutationsEnabled(process.env)) { workflowsPath: fileURLToPath(new URL("./memory-mutation-workflows.js", import.meta.url)), activities: { executePersistedMemoryChangeSet }, ...memoryMutationWorkerOptions, - interceptors: { activity: [createActivityObservabilityInterceptors({ spans })] } + ...workerObservabilityOptions(tracing) }); console.log(JSON.stringify({ service, status: "running", address, namespace, taskQueue: MEMORY_MUTATION_TASK_QUEUE })); try { await worker.run(); } finally { - await spans?.close(); + await tracing?.close(); } } diff --git a/apps/worker/src/room-background-continuation.ts b/apps/worker/src/room-background-continuation.ts index 129ebf62a..6acafe1db 100644 --- a/apps/worker/src/room-background-continuation.ts +++ b/apps/worker/src/room-background-continuation.ts @@ -1,6 +1,9 @@ +import { randomBytes } from "node:crypto"; import { buildCodexAppServerTurnWorkflowId, buildRoomAgentSupervisorWorkflowId, + formatTraceparent, + parseTraceparent, roomAgentSupervisorQueueItemSchema, spaceAgentRoomActionRequestSchema, type RoomAgentActionRecord, @@ -38,6 +41,15 @@ export function continuationEvidence(actions: RoomAgentActionRecord[], budget: n return JSON.stringify(result); } +/** Fresh random root W3C traceparent; never all-zero and never the excluded trace id. */ +export function freshRootTraceparent(excludedTraceId?: string): string { + let traceId: string; + let spanId: string; + do { traceId = randomBytes(16).toString("hex"); } while (/^0+$/.test(traceId) || traceId === excludedTraceId); + do { spanId = randomBytes(8).toString("hex"); } while (/^0+$/.test(spanId)); + return formatTraceparent(traceId, spanId, "01"); +} + const activeStatuses = ["QUEUED", "RUNNING", "PAUSED"]; export type BackgroundContinuationResult = | { state: "WAITING" | "DONE" } @@ -122,10 +134,14 @@ maxMissionTokens: number | null = DEFAULT_ROOM_AGENT_MAX_MISSION_TOKENS): Promis ].join("\n"); const prefix = `${instructions}\n\nOperator request:\n${request}\n\nSettled action results (bounded; inspect for details):\n`; const prompt = prefix + continuationEvidence(actions, Math.max(0, 8000 - prefix.length)); + const sourceTraceparent = parseTraceparent(source.queueItem.turn.traceparent); const item = roomAgentSupervisorQueueItemSchema.parse({ missionId: input.missionId, turn: { ...source.queueItem.turn, prompt, roomAgentOperatorRequest: request, roomAgentContinuation: { sourceRunId: source.run.runId, generation }, + // Fresh root W3C context so logs and internal API calls stay joinable without a collector; the interceptor roots the workflow span on this trace id and only links the prior span. + traceparent: freshRootTraceparent(sourceTraceparent?.traceId), + continuationTraceparent: sourceTraceparent ? source.queueItem.turn.traceparent : undefined, artifactIds: [], agentRunId: runId, agentUserMessageId: `agent_msg:bg-context-${input.continuationId}`, agentAssistantMessageId: `agent_msg:bg-response-${input.continuationId}`, diff --git a/apps/worker/src/tracing/sinks.ts b/apps/worker/src/tracing/sinks.ts new file mode 100644 index 000000000..648d60b77 --- /dev/null +++ b/apps/worker/src/tracing/sinks.ts @@ -0,0 +1,20 @@ +import type { Sinks } from "@temporalio/workflow"; + +export type WorkflowSpanOutcome = "COMPLETED" | "FAILED" | "CANCELLED" | "CONTINUED_AS_NEW"; +export type WorkflowSpanLinkReason = "continue_as_new" | "background_continuation"; + +export interface WorkflowSpanRecord { + traceId: string; + spanId: string; + parentSpanId: string | null; + startTimeMs: number; + endTimeMs: number; + outcome: WorkflowSpanOutcome; + errorCode: string | null; + correlation: { spaceTraceId?: string; roomId?: string; paneId?: string; missionId?: string; goalId?: string }; + links: Array<{ traceId: string; spanId: string; reason: WorkflowSpanLinkReason }>; +} + +export interface SpaceTracingSinks extends Sinks { + spaceTracing: { workflowSpan(record: WorkflowSpanRecord): void }; +} diff --git a/apps/worker/src/tracing/span-attributes.ts b/apps/worker/src/tracing/span-attributes.ts new file mode 100644 index 000000000..cc8299d67 --- /dev/null +++ b/apps/worker/src/tracing/span-attributes.ts @@ -0,0 +1,4 @@ +// This subpath has no Node imports or exporter timers and is safe in a workflow bundle. +export { SPAN_ATTRIBUTE_ALLOWLIST, allowlistSpanAttributes } from "@space/runtime/span-attributes"; +export { parseTraceparent, formatTraceparent } from "@space/contracts"; +export { TRACEPARENT_HEADER as TRACE_HEADER, LINK_TRACEPARENT_HEADER as LINK_HEADER } from "../workflow-tracing-headers.js"; diff --git a/apps/worker/src/worker-tracing.ts b/apps/worker/src/worker-tracing.ts new file mode 100644 index 000000000..14038c172 --- /dev/null +++ b/apps/worker/src/worker-tracing.ts @@ -0,0 +1,120 @@ +import { allowlistSpanAttributes } from "./tracing/span-attributes.js"; +import { existsSync } from "node:fs"; +import { fileURLToPath } from "node:url"; +import { categorizeFailureCode } from "@space/contracts"; +import { otlpSpanExporterFromEnv, otlpTracesUrl, type ServerSpan, type SpanExporter } from "@space/runtime"; +import type { InjectedSinks, WorkerOptions } from "@temporalio/worker"; +import type { WorkflowInfo } from "@temporalio/workflow"; +import { createActivityObservabilityInterceptors } from "./activity-observability.js"; +import type { SpaceTracingSinks, WorkflowSpanRecord } from "./workflow-tracing-interceptors.js"; + +/** + * Worker-process half of OTLP span export. With SPACE_OTEL_EXPORTER_OTLP_ENDPOINT + * unset, `workerTracing` returns null and Worker.create gets exactly the options + * it had before: no workflow interceptor module, no sinks, no exporter timer. + */ + +const CLOSE_TIMEOUT_MS = 2_000; + +export interface WorkerTracing { + exporter: SpanExporter; + spans: SpanExporter; + workflowModules: string[]; + sinks: InjectedSinks; + /** Flushes queued spans, capped so a stuck collector never holds up shutdown. */ + close(): Promise; +} + +/** The workflow interceptor module next to this file (`.js` when built, `.ts` under vitest). */ +export function workflowTracingModulePath(): string { + const built = fileURLToPath(new URL("./workflow-tracing-interceptors.js", import.meta.url)); + return existsSync(built) ? built : fileURLToPath(new URL("./workflow-tracing-interceptors.ts", import.meta.url)); +} + +/** The OTLP span for a finished workflow run; attributes pass the allowlist. */ +export function toWorkflowSpan(info: Pick & Partial>, record: WorkflowSpanRecord): ServerSpan { + const startTimeMs = Math.max(0, Math.floor(record.startTimeMs)); + const endTimeMs = Math.max(startTimeMs, Math.floor(record.endTimeMs)); + const category = record.outcome === "FAILED" + ? categorizeFailureCode(record.errorCode) + : record.outcome === "CANCELLED" ? "CANCELLED" : null; + return { + traceId: record.traceId, + spanId: record.spanId, + parentSpanId: record.parentSpanId, + name: `workflow ${info.workflowType}`, + kind: 1, + startTimeUnixNano: BigInt(startTimeMs) * 1_000_000n, + endTimeUnixNano: BigInt(endTimeMs) * 1_000_000n, + attributes: allowlistSpanAttributes({ + "temporal.workflow.id": info.workflowId, + "temporal.workflow.run_id": info.runId, + "temporal.workflow.type": info.workflowType, + "space.outcome": record.outcome, + "error.code": record.errorCode, + "space.error.category": category, + "space.duration_ms": endTimeMs - startTimeMs, + "space.trace_id": record.correlation.spaceTraceId ?? info.memo?.spaceTraceId, + "space.room_id": record.correlation.roomId, + "space.pane_id": record.correlation.paneId, + "space.mission_id": record.correlation.missionId ?? info.memo?.missionId, + }), + links: record.links.map(link => ({ traceId: link.traceId, spanId: link.spanId, attributes: allowlistSpanAttributes({ "space.link.kind": link.reason }) })), + error: record.outcome === "FAILED" + }; +} + +/** The `spaceTracing` sink: never called during replay, never throws into the worker. */ +export function spaceTracingSinks(spans: SpanExporter): InjectedSinks { + return { + spaceTracing: { + workflowSpan: { + fn: (info, record) => { + try { + spans.record(toWorkflowSpan(info, record)); + } catch { + // Tracing is best effort. + } + }, + callDuringReplay: false + } + } + }; +} + +function tracingForExporter(spans: SpanExporter): WorkerTracing { + return { + exporter: spans, + spans, + workflowModules: [workflowTracingModulePath()], + sinks: spaceTracingSinks(spans), + async close() { + let timer: NodeJS.Timeout | undefined; + await Promise.race([ + spans.close().catch(() => undefined), + new Promise(resolve => { timer = setTimeout(resolve, CLOSE_TIMEOUT_MS); }) + ]); + clearTimeout(timer); + } + }; +} + +/** Tracing for a worker process, or null when SPACE_OTEL_EXPORTER_OTLP_ENDPOINT is unset or invalid. */ +export function createWorkerTracing(spans: SpanExporter): WorkerTracing; +export function createWorkerTracing(env: NodeJS.ProcessEnv, serviceName: string, options?: { exporter?: SpanExporter }): WorkerTracing | null; +export function createWorkerTracing(input: SpanExporter | NodeJS.ProcessEnv, serviceName?: string, options?: { exporter?: SpanExporter }): WorkerTracing | null { + if (serviceName === undefined) return tracingForExporter(input as SpanExporter); + const env = input as NodeJS.ProcessEnv; + if (!otlpTracesUrl(env.SPACE_OTEL_EXPORTER_OTLP_ENDPOINT)) return null; + const spans = options?.exporter ?? otlpSpanExporterFromEnv(env, serviceName); + return spans ? tracingForExporter(spans) : null; +} + +export const workerTracing = (env: NodeJS.ProcessEnv, serviceName: string): WorkerTracing | null => createWorkerTracing(env, serviceName); + +/** Worker.create options for observability: activity records always, workflow spans only with tracing. */ +export function workerObservabilityOptions(tracing: WorkerTracing | null): Pick { + const activity = [createActivityObservabilityInterceptors({ spans: tracing?.spans ?? null })]; + if (!tracing) return { interceptors: { activity } }; + return { interceptors: { activity, workflowModules: tracing.workflowModules }, sinks: tracing.sinks }; +} diff --git a/apps/worker/src/worker.ts b/apps/worker/src/worker.ts index 521335543..5ff5feac0 100644 --- a/apps/worker/src/worker.ts +++ b/apps/worker/src/worker.ts @@ -3,10 +3,10 @@ import { hostname } from "node:os"; import { assertDevInstanceIsolated, instanceBackgroundJobEnabled } from "@space/contracts"; import { PostgresSpaceStore, PostgresStreamingBotRepository, PostgresStreamingRepository } from "@space/db"; import { StreamingCredentialStore } from "@space/streaming"; -import { TelegramDeliveryWorker, TelegramSecretStore, otlpSpanExporterFromEnv } from "@space/runtime"; +import { TelegramDeliveryWorker, TelegramSecretStore } from "@space/runtime"; import { NativeConnection, Runtime, Worker } from "@temporalio/worker"; import * as activities from "./activities.js"; -import { createActivityObservabilityInterceptors } from "./activity-observability.js"; +import { workerObservabilityOptions, workerTracing } from "./worker-tracing.js"; import { resolveTemporalCoreMetricsBind, resolveWorkerMetricsListen, startWorkerMetricsServer } from "./worker-metrics.js"; import { workerLog } from "./worker-log.js"; import { sweepCodexCliCompletions } from "./codex-cli-completion.js"; @@ -35,16 +35,16 @@ if (temporalCoreMetricsBind) { } const connection = await NativeConnection.connect({ address }); -const spans = otlpSpanExporterFromEnv(process.env, "space-worker"); +const tracing = workerTracing(process.env, "space-worker"); const worker = await Worker.create({ connection, namespace, taskQueue, workflowsPath, activities, - // Structured, correlated activity records and worker metrics. Activity-side - // only: the workflow sandbox and its replay behaviour are unchanged. - interceptors: { activity: [createActivityObservabilityInterceptors({ spans })] } + // Structured, correlated activity records and worker metrics. With OTLP export + // on, also workflow spans through a sink that is never called during replay. + ...workerObservabilityOptions(tracing) }); // Optional loopback-only Prometheus endpoint for worker metrics. @@ -173,5 +173,5 @@ try { telegramNotificationLoop?.stop(); streamingBotLoop?.stop(); chessMoveServer?.close(); - await spans?.close(); + await tracing?.close(); } diff --git a/apps/worker/src/workflow-tracing-headers.ts b/apps/worker/src/workflow-tracing-headers.ts new file mode 100644 index 000000000..ec2edcbed --- /dev/null +++ b/apps/worker/src/workflow-tracing-headers.ts @@ -0,0 +1,10 @@ +/** + * Temporal header names shared by the workflow tracing interceptors (sandbox) + * and the activity interceptor (worker process). Both carry W3C traceparents + * only, never data. + */ + +/** The span that work started from a workflow nests under. */ +export const TRACEPARENT_HEADER = "space-traceparent"; +/** Set on continue-as-new: the span of the run that finished. */ +export const LINK_TRACEPARENT_HEADER = "space-link-traceparent"; diff --git a/apps/worker/src/workflow-tracing-interceptors.ts b/apps/worker/src/workflow-tracing-interceptors.ts new file mode 100644 index 000000000..973872fc8 --- /dev/null +++ b/apps/worker/src/workflow-tracing-interceptors.ts @@ -0,0 +1,170 @@ +import { + ContinueAsNew, + defaultPayloadConverter, + isCancellation, + proxySinks, + workflowInfo, + uuid4, + type Headers, + type WorkflowInterceptorsFactory +} from "@temporalio/workflow"; +import { formatTraceparent, isSafeCode as isSafeErrorCode, parseTraceparent, type ParsedTraceparent } from "./workflows/trace-ids.js"; +import { LINK_TRACEPARENT_HEADER, TRACEPARENT_HEADER } from "./workflow-tracing-headers.js"; + +export { LINK_TRACEPARENT_HEADER, TRACEPARENT_HEADER }; +import type { SpaceTracingSinks, WorkflowSpanOutcome, WorkflowSpanRecord } from "./tracing/sinks.js"; +export type { SpaceTracingSinks, WorkflowSpanRecord } from "./tracing/sinks.js"; + +/** + * Workflow span for OTLP export (SPACE_OTEL_EXPORTER_OTLP_ENDPOINT). This module + * runs inside the deterministic workflow sandbox and is registered only when + * export is on (see worker-tracing.ts). It does no I/O: the finished span leaves + * the sandbox through the `spaceTracing` sink, which the worker registers with + * `callDuringReplay: false`, so a replayed history emits nothing. + * + * IDs use Temporal's deterministic workflow random stream. + */ + +const identifierPattern = /^[A-Za-z0-9:._-]{1,200}$/; +const nestedKeys = ["turn", "input", "turnInput"] as const; + +function readHeader(headers: Headers | undefined, key: string): ParsedTraceparent | null { + const payload = headers?.[key]; + if (!payload) return null; + try { + return parseTraceparent(defaultPayloadConverter.fromPayload(payload)); + } catch { + return null; + } +} + +/** First value of `key` in the argument or its nested turn/input objects (depth 2). */ +function findArgument(value: unknown, key: string, depth: number): unknown { + if (!value || typeof value !== "object" || Array.isArray(value)) return undefined; + const record = value as Record; + if (record[key] !== undefined) return record[key]; + if (depth <= 0) return undefined; + for (const nested of nestedKeys) { + const found = findArgument(record[nested], key, depth - 1); + if (found !== undefined) return found; + } + return undefined; +} + +function identifier(value: unknown): string | undefined { + return typeof value === "string" && identifierPattern.test(value) ? value : undefined; +} + +function errorCodeOf(error: unknown): string { + const record = error as { type?: unknown; code?: unknown; cause?: { type?: unknown } } | null; + if (isSafeErrorCode(record?.type)) return record!.type as string; + if (isSafeErrorCode(record?.code)) return record!.code as string; + if (isSafeErrorCode(record?.cause?.type)) return record.cause.type; + return "WORKFLOW_FAILED"; +} + +function withHeader(headers: Headers, key: string, traceparent: string | null): Headers { + return traceparent ? { ...headers, [key]: defaultPayloadConverter.toPayload(traceparent) } : headers; +} + +/** One instance per workflow run: the factory closure holds that run's span. */ +export const interceptors: WorkflowInterceptorsFactory = () => { + let current: { traceId: string; spanId: string; flags: string; parentTraceparent: string | null } | null = null; + const own = () => (current ? formatTraceparent(current.traceId, current.spanId, current.flags) : null); + const { spaceTracing } = proxySinks(); + + return { + inbound: [{ + async execute(input, next) { + const info = workflowInfo(); + const first = input.args[0]; + const carrier = readHeader(input.headers, TRACEPARENT_HEADER); + const argument = parseTraceparent(findArgument(first, "traceparent", 2)); + const memo = parseTraceparent(info.memo?.traceparent); + const links: WorkflowSpanRecord["links"] = []; + const continued = parseTraceparent(info.memo?.continuationTraceparent) ?? parseTraceparent(findArgument(first, "continuationTraceparent", 2)); + // Background turns start a new root. Older queued turns may still carry + // a fresh traceparent: retain its trace id, never its unexported parent. + const backgroundRoot = !carrier && Boolean(continued || findArgument(first, "roomAgentContinuation", 2)); + const parent = backgroundRoot ? null : carrier ?? argument ?? memo; + const traceId = parent?.traceId ?? (backgroundRoot ? argument?.traceId : undefined) ?? uuid4().replace(/-/g, ""); + const span = { + traceId, + spanId: uuid4().replace(/-/g, "").slice(0, 16), + flags: parent?.flags ?? "01", + parentTraceparent: parent ? formatTraceparent(parent.traceId, parent.parentId, parent.flags) : null + }; + current = span; + const previousRun = readHeader(input.headers, LINK_TRACEPARENT_HEADER); + if (previousRun) links.push({ traceId: previousRun.traceId, spanId: previousRun.parentId, reason: "continue_as_new" }); + if (continued) links.push({ traceId: continued.traceId, spanId: continued.parentId, reason: "background_continuation" }); + const correlation: WorkflowSpanRecord["correlation"] = {}; + const spaceTraceId = identifier(findArgument(first, "traceId", 2)); + const roomId = identifier(findArgument(first, "roomId", 2)); + const paneId = identifier(findArgument(first, "paneId", 2)); + const missionId = identifier(findArgument(first, "missionId", 2)) ?? identifier(findArgument(first, "roomAgentMissionId", 2)); + const goalId = identifier(findArgument(first, "goalId", 2)); + if (spaceTraceId) correlation.spaceTraceId = spaceTraceId; + if (roomId) correlation.roomId = roomId; + if (paneId) correlation.paneId = paneId; + if (missionId) correlation.missionId = missionId; + if (goalId) correlation.goalId = goalId; + + let outcome: WorkflowSpanOutcome = "COMPLETED"; + let errorCode: string | null = null; + try { + return await next(input); + } catch (error) { + if (error instanceof ContinueAsNew) outcome = "CONTINUED_AS_NEW"; + else if (isCancellation(error)) outcome = "CANCELLED"; + else { + outcome = "FAILED"; + errorCode = errorCodeOf(error); + } + throw error; + } finally { + try { spaceTracing.workflowSpan({ + traceId: span.traceId, + spanId: span.spanId, + parentSpanId: parent?.parentId ?? null, + startTimeMs: info.runStartTime?.getTime() ?? Date.now(), + endTimeMs: Date.now(), + outcome, + errorCode, + correlation, + links + }); } catch { /* Tracing must never change the workflow result. */ } + } + } + }], + outbound: [{ + scheduleActivity: (input, next) => next({ ...input, headers: withHeader(input.headers, TRACEPARENT_HEADER, own()) }), + scheduleLocalActivity: (input, next) => next({ ...input, headers: withHeader(input.headers, TRACEPARENT_HEADER, own()) }), + startChildWorkflowExecution: (input, next) => { + let tracedInput = input; + try { + const first = input.options?.args?.[0]; + const link = parseTraceparent(findArgument(first, "continuationTraceparent", 2)); + const argument = parseTraceparent(findArgument(first, "traceparent", 2)); + const background = Boolean(link || findArgument(first, "roomAgentContinuation", 2)); + // Per-request turns under a long-lived supervisor keep their API parent. + const parent = argument && current && argument.traceId !== current.traceId + ? formatTraceparent(argument.traceId, argument.parentId, argument.flags) : own(); + const headers = { ...input.headers }; + if (background) delete headers[TRACEPARENT_HEADER]; + tracedInput = { ...input, + headers: background ? headers : withHeader(headers, TRACEPARENT_HEADER, parent), + ...(link ? { options: { ...input.options, memo: { ...input.options?.memo, continuationTraceparent: formatTraceparent(link.traceId, link.parentId, link.flags) } } } : {}) + }; + } catch { /* Tracing must never prevent a child from starting. */ } + // Keep next outside the catch: never retry a failed child start. + return next(tracedInput); + }, + continueAsNew: (input, next) => { + // The next run stays in this trace under the same parent and links back to this run. + const headers = withHeader(input.headers, TRACEPARENT_HEADER, current?.parentTraceparent ?? own()); + return next({ ...input, headers: withHeader(headers, LINK_TRACEPARENT_HEADER, own()) }); + } + }] + }; +}; diff --git a/apps/worker/src/workflows/trace-ids.ts b/apps/worker/src/workflows/trace-ids.ts new file mode 100644 index 000000000..2bb77c145 --- /dev/null +++ b/apps/worker/src/workflows/trace-ids.ts @@ -0,0 +1,17 @@ +/** Pure trace helpers for the deterministic workflow sandbox. */ +export interface ParsedTraceparent { traceId: string; parentId: string; flags: string } +export function parseTraceparent(value: unknown): ParsedTraceparent | null { + if (typeof value !== "string") return null; + const match = /^00-([0-9a-f]{32})-([0-9a-f]{16})-([0-9a-f]{2})$/.exec(value); + if (!match || /^0+$/.test(match[1]!) || /^0+$/.test(match[2]!)) return null; + return { traceId: match[1]!, parentId: match[2]!, flags: match[3]! }; +} +export function formatTraceparent(traceId: string, spanId: string, flags = "01"): string { + return `00-${traceId}-${spanId}-${flags}`; +} +export function isSafeId(value: unknown): value is string { + return typeof value === "string" && /^[A-Za-z0-9:._-]{1,200}$/.test(value); +} +export function isSafeCode(value: unknown): value is string { + return typeof value === "string" && /^[A-Z][A-Z0-9_]{1,79}$/.test(value); +} diff --git a/apps/worker/tests/activity-observability.test.ts b/apps/worker/tests/activity-observability.test.ts index 654bf7962..f52c11c73 100644 --- a/apps/worker/tests/activity-observability.test.ts +++ b/apps/worker/tests/activity-observability.test.ts @@ -186,8 +186,10 @@ it("registers the activity interceptor on every Temporal worker, including both const { readFile } = await import("node:fs/promises"); for (const entry of ["worker.ts", "memory-maintenance-worker.ts", "memory-mutation-worker.ts"]) { const source = await readFile(new URL(`../src/${entry}`, import.meta.url), "utf8"); - expect(source, entry).toMatch(/interceptors: \{ activity: \[createActivityObservabilityInterceptors\(\{ spans \}\)\] \}/); + expect(source, entry).toMatch(/\.\.\.workerObservabilityOptions\(tracing\)/); } + const builder = await readFile(new URL("../src/worker-tracing.ts", import.meta.url), "utf8"); + expect(builder).toMatch(/createActivityObservabilityInterceptors\(\{ spans: tracing\?\.spans \?\? null \}\)/); }); it("exports one INTERNAL span per activity under the caller's traceparent", async () => { diff --git a/apps/worker/tests/otlp-attribute-domains.test.ts b/apps/worker/tests/otlp-attribute-domains.test.ts new file mode 100644 index 000000000..3e015f354 --- /dev/null +++ b/apps/worker/tests/otlp-attribute-domains.test.ts @@ -0,0 +1,19 @@ +import { expect, it } from "vitest"; +import { allowlistSpanAttributes } from "../src/tracing/span-attributes.js"; +import { parseTraceparent } from "../src/workflows/trace-ids.js"; +it("rejects values outside each attribute's domain", () => { + expect(allowlistSpanAttributes({ + "space.room_id": true, "temporal.activity.attempt": -1, + "space.duration_ms": 1.5, "space.queue_ms": Infinity, + "space.outcome": "SECRET", "space.link.kind": "SECRET", + prompt: "SECRET-PROMPT", filePath: "/home/x", url: "https://x", + "error.code": "SECRET-ERR", "space.pane_id": "/home/x" + })).toEqual({}); +}); +it("accepts only strict nonzero version-00 traceparents", () => { + const valid = "00-11111111111111111111111111111111-2222222222222222-01"; + expect(parseTraceparent(valid)?.parentId).toBe("2222222222222222"); + for (const value of [null, valid + "-extra", " " + valid, valid.replace("00-", "01-"), valid.replace(/1/g, "0"), valid.replace(/2/g, "0")]) { + expect(parseTraceparent(value)).toBeNull(); + } +}); diff --git a/apps/worker/tests/otlp-background-continuation-link.test.ts b/apps/worker/tests/otlp-background-continuation-link.test.ts new file mode 100644 index 000000000..6e67262ab --- /dev/null +++ b/apps/worker/tests/otlp-background-continuation-link.test.ts @@ -0,0 +1,130 @@ +import { randomBytes } from "node:crypto"; +import { describe, expect, it, vi } from "vitest"; +import { dummyTurnInputSchema, parseTraceparent } from "@space/contracts"; +import { activityCorrelation, createActivityObservabilityInterceptors } from "../src/activity-observability.js"; +import { getCodexAppServerTurnActivityConfig } from "../src/activities.js"; +import { executeRoomActionBridge } from "../src/room-action-bridge.js"; +import { freshRootTraceparent, prepareBackgroundContinuation } from "../src/room-background-continuation.js"; +import { captureWorkerLogs } from "../src/worker-log.js"; +import { continuationFixture } from "./room-continuation-fixture.js"; + +vi.mock("node:crypto", async (importOriginal) => { + const actual = await importOriginal(); + return { ...actual, randomBytes: vi.fn(actual.randomBytes) }; +}); + +const originating = "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"; + +describe("background continuation span link", () => { + it("carries the originating turn's traceparent as continuationTraceparent and keeps the trace:bg id", async () => { + const c = continuationFixture("OPEN_TYPES", originating); + const prepared = await prepareBackgroundContinuation(c.input, c.store); + if (prepared.state !== "READY") throw Error("Missing continuation"); + expect(prepared.item.turn.traceId).toBe("trace:bg-test-1"); + expect(prepared.item.turn.continuationTraceparent).toBe(originating); + expect(prepared.item.turn.traceparent).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-01$/); + const root = parseTraceparent(prepared.item.turn.traceparent); + expect(root).not.toBeNull(); + expect(root?.traceId).not.toMatch(/^0+$/); + expect(root?.traceId).not.toBe(parseTraceparent(originating)!.traceId); + }); + + it("returns the identical fresh root traceparent when preparation is retried", async () => { + const c = continuationFixture("OPEN_TYPES", originating); + const first = await prepareBackgroundContinuation(c.input, c.store); + const retry = await prepareBackgroundContinuation(c.input, c.store); + if (first.state !== "READY" || retry.state !== "READY") throw Error("Missing continuation"); + expect(retry.item.turn.traceparent).toBe(first.item.turn.traceparent); + expect(retry.item.turn.continuationTraceparent).toBe(originating); + }); + + it("never reuses the trace id it continues or an all-zero id", () => { + const excluded = parseTraceparent(originating)!.traceId; + const random = vi.mocked(randomBytes) as unknown as { mockReturnValueOnce(value: Buffer): unknown }; + // Forced collisions: an all-zero trace id, the source trace id, then an all-zero span id. + random.mockReturnValueOnce(Buffer.alloc(16)); + random.mockReturnValueOnce(Buffer.from(excluded, "hex")); + random.mockReturnValueOnce(Buffer.from("0af7651916cd43dd8448eb211c80319c", "hex")); + random.mockReturnValueOnce(Buffer.alloc(8)); + random.mockReturnValueOnce(Buffer.from("b7ad6b7169203331", "hex")); + expect(freshRootTraceparent(excluded)).toBe("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"); + const roots = new Set(); + for (let index = 0; index < 200; index++) { + const root = freshRootTraceparent(excluded); + roots.add(root); + const parsed = parseTraceparent(root)!; + expect(root).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-01$/); + expect(parsed.traceId).not.toBe(excluded); + expect(parsed.traceId).not.toMatch(/^0+$/); + expect(parsed.parentId).not.toMatch(/^0+$/); + } + expect(roots.size).toBe(200); + }); + + it("adds no link field when the originating turn had no traceparent", async () => { + const c = continuationFixture(); + const prepared = await prepareBackgroundContinuation(c.input, c.store); + if (prepared.state !== "READY") throw Error("Missing continuation"); + expect(prepared.item.turn.continuationTraceparent).toBeUndefined(); + expect(parseTraceparent(prepared.item.turn.traceparent)).not.toBeNull(); + }); + + it("still starts a fresh root when the originating traceparent is invalid", async () => { + const c = continuationFixture("OPEN_TYPES", "00-00000000000000000000000000000000-00f067aa0ba902b7-01"); + const prepared = await prepareBackgroundContinuation(c.input, c.store); + if (prepared.state !== "READY") throw Error("Missing continuation"); + expect(prepared.item.turn.continuationTraceparent).toBeUndefined(); + expect(prepared.item.turn.traceparent).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-01$/); + }); + + it("keeps logs and internal API calls joinable by W3C trace id with OTLP export off", async () => { + const c = continuationFixture("OPEN_TYPES", originating); + const prepared = await prepareBackgroundContinuation(c.input, c.store); + if (prepared.state !== "READY") throw Error("Missing continuation"); + const root = parseTraceparent(prepared.item.turn.traceparent)!; + // No space-traceparent header exists: correlation comes from the activity input alone. + expect(activityCorrelation([prepared.item.turn]).w3cTraceId).toBe(root.traceId); + expect(activityCorrelation([prepared.item]).w3cTraceId).toBe(root.traceId); + const sent: Array> = []; + const actions = [{ toolId: "room:inspect", action: { type: "inspect" } }]; + await executeRoomActionBridge({ + turnInput: prepared.item.turn, + assistantContent: "```space-room-actions\n" + JSON.stringify({ version: 1, actions }) + "\n```", + config: { ...getCodexAppServerTurnActivityConfig({}), internalApiToken: "test-only" }, + fetchImpl: async (_url, init) => { + sent.push(init!.headers as Record); + return Response.json({ id: "space-agent-room-action-bridge", results: actions.map(request => ({ + request, status: "EXECUTED", statusReason: "Recorded evidence", evidence: {} })) }); + } + }); + expect(sent).toHaveLength(1); + const child = parseTraceparent(sent[0]!.traceparent)!; + expect(child.traceId).toBe(root.traceId); + expect(child.parentId).not.toBe(root.parentId); + expect(child.parentId).not.toMatch(/^0+$/); + }); + + it("stamps the fresh root trace id on worker log records with OTLP export off", async () => { + const c = continuationFixture("OPEN_TYPES", originating); + const prepared = await prepareBackgroundContinuation(c.input, c.store); + if (prepared.state !== "READY") throw Error("Missing continuation"); + const root = parseTraceparent(prepared.item.turn.traceparent)!; + const records: Array> = []; + const restore = captureWorkerLogs(line => records.push(JSON.parse(line))); + try { + const hooks = createActivityObservabilityInterceptors({ spans: null })({ + info: { activityType: "runCodexAppServerTurn", activityId: "1", attempt: 1 }, + cancellationSignal: new AbortController().signal + } as never); + await hooks.inbound!.execute!({ args: [prepared.item.turn], headers: {} } as never, async () => "done"); + expect(records.map(record => record.event)).toEqual(["activity.started", "activity.finished"]); + for (const record of records) expect(record.w3cTraceId).toBe(root.traceId); + } finally { restore(); } + }); + + it("validates the field as a W3C traceparent", () => { + const turn = { roomId: "room_otlp_link", paneId: "pane_otlp_link", prompt: "hi", traceId: "req:abcdefghijkl" }; + expect(dummyTurnInputSchema.parse({ ...turn, continuationTraceparent: originating }).continuationTraceparent).toBe(originating); + expect(dummyTurnInputSchema.safeParse({ ...turn, continuationTraceparent: "https://example.test" }).success).toBe(false); + }); +}); diff --git a/apps/worker/tests/otlp-interceptors.test.ts b/apps/worker/tests/otlp-interceptors.test.ts new file mode 100644 index 000000000..5a0bc0a3b --- /dev/null +++ b/apps/worker/tests/otlp-interceptors.test.ts @@ -0,0 +1,134 @@ +import { beforeEach, expect, it, vi } from "vitest"; +const fixture = vi.hoisted(() => ({ + sink: vi.fn(), + memo: {} as Record, + n: 0 +})); +vi.mock("@temporalio/workflow", () => ({ + ContinueAsNew: class ContinueAsNew extends Error {}, + defaultPayloadConverter: { toPayload: (value: unknown) => value, fromPayload: (value: unknown) => value }, + isCancellation: (error: { name?: string }) => error?.name === "CancelledFailure", + proxySinks: () => ({ spaceTracing: { workflowSpan: fixture.sink } }), + workflowInfo: () => ({ runId: "run-test", runStartTime: new Date(0), memo: fixture.memo }), + uuid4: () => (++fixture.n).toString(16).padStart(16, "0") + "123456789abcdef0" +})); +import { ContinueAsNew } from "@temporalio/workflow"; +import { interceptors } from "../src/workflow-tracing-interceptors.js"; +const trace = "4bf92f3577b34da6a3ce929d0e0e4736"; +const carrier = (id: string) => `00-${trace}-${id}-01`; +beforeEach(() => { fixture.sink.mockReset(); fixture.memo = {}; fixture.n = 0; }); +it("uses headers before arguments before memo and propagates the workflow span", async () => { + for (const [headers, args, expected] of [ + [{ "space-traceparent": carrier("1111111111111111") }, [{ traceparent: carrier("2222222222222222") }], "1111111111111111"], + [{}, [{ turn: { traceparent: carrier("2222222222222222") } }], "2222222222222222"], + [{}, [], "3333333333333333"] + ] as const) { + fixture.memo = { traceparent: carrier("3333333333333333") }; + const hooks = interceptors(); + await hooks.inbound![0]!.execute!({ args, headers } as never, async () => { + for (const method of ["scheduleActivity", "scheduleLocalActivity", "startChildWorkflowExecution"] as const) { + await hooks.outbound![0]![method]!({ headers: {}, options: { args: [] } } as never, ((input: { headers: Record }) => { + expect(input.headers["space-traceparent"]).toMatch(new RegExp(`^00-${trace}-[0-9a-f]{16}-01$`)); + return Promise.resolve(undefined); + }) as never); + } + return "ok"; + }); + expect(fixture.sink.mock.lastCall![0].parentSpanId).toBe(expected); + } +}); +it("preserves success and failure when the sink throws", async () => { + fixture.sink.mockImplementation(() => { throw new Error("sink failure"); }); + const hooks = interceptors(); + const input = { args: [], headers: {} }; + await expect(hooks.inbound![0]!.execute!(input, async () => "ok")).resolves.toBe("ok"); + const failure = new Error("workflow failure"); + await expect(hooks.inbound![0]!.execute!(input, async () => { throw failure; })).rejects.toBe(failure); +}); + +it("puts validated background links in child memo without inheriting a parent", async () => { + const hooks = interceptors(); + const old = carrier("1111111111111111"); + const fresh = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + await hooks.inbound![0]!.execute!({ args: [{ traceparent: old }], headers: {} }, async () => { + await hooks.outbound![0]!.startChildWorkflowExecution!({ + headers: {}, options: { args: [{ traceparent: fresh, continuationTraceparent: old }] } + } as never, ((input: { headers: Record; options: { memo: Record } }) => { + expect(input.options.memo.continuationTraceparent).toBe(old); + expect(input.headers["space-traceparent"]).toBeUndefined(); + return Promise.resolve(undefined); + }) as never); + }); +}); + +it("tolerates child starts without options or args", async () => { + const hooks = interceptors(); + for (const input of [{ headers: {} }, { headers: {}, options: {} }]) { + const next = vi.fn().mockResolvedValue("child"); + await expect(hooks.outbound![0]!.startChildWorkflowExecution!(input as never, next)).resolves.toBe("child"); + expect(next).toHaveBeenCalledOnce(); + } +}); + +it("falls through once when child tracing fails and preserves downstream errors", async () => { + const hooks = interceptors(); + const input = { headers: {}, options: { get args(): never { throw Error("tracing failure"); } } }; + const next = vi.fn().mockResolvedValue("child"); + await expect(hooks.outbound![0]!.startChildWorkflowExecution!(input as never, next)).resolves.toBe("child"); + expect(next).toHaveBeenCalledOnce(); + expect(next.mock.calls[0]![0]).toBe(input); + const failure = Error("child failure"); + next.mockReset().mockRejectedValue(failure); + await expect(hooks.outbound![0]!.startChildWorkflowExecution!({ headers: {}, options: {} } as never, next)).rejects.toBe(failure); + expect(next).toHaveBeenCalledOnce(); +}); + +it("records WORKFLOW_FAILED for an unclassified failure", async () => { + const hooks = interceptors(); + const failure = Error("private error message"); + await expect(hooks.inbound![0]!.execute!({ args: [], headers: {} }, async () => { throw failure; })).rejects.toBe(failure); + expect(fixture.sink.mock.lastCall![0]).toMatchObject({ outcome: "FAILED", errorCode: "WORKFLOW_FAILED" }); +}); + +it("starts background continuations as roots with a validated link", async () => { + const old = carrier("1111111111111111"); + for (const traceparent of [undefined, "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"]) { + const hooks = interceptors(); + await hooks.inbound![0]!.execute!({ args: [{ traceparent, continuationTraceparent: old }], headers: {} }, async () => "ok"); + const span = fixture.sink.mock.lastCall![0]; + expect(span.parentSpanId).toBeNull(); + expect(span.traceId).not.toBe(trace); + expect(span.links).toEqual([{ traceId: trace, spanId: "1111111111111111", reason: "background_continuation" }]); + if (traceparent) expect(span.traceId).toBe("0af7651916cd43dd8448eb211c80319c"); + } +}); + +it("creates a fresh root for a background turn whose source had no W3C context", async () => { + const hooks = interceptors(); + const turn = { roomAgentContinuation: { sourceRunId: "run-old", generation: 1 } }; + await hooks.inbound![0]!.execute!({ args: [{ traceparent: carrier("1111111111111111") }], headers: {} }, async () => { + await hooks.outbound![0]!.startChildWorkflowExecution!({ + headers: { "space-traceparent": carrier("1111111111111111") }, options: { args: [turn] } + } as never, (async (input: { headers: Record }) => { + expect(input.headers["space-traceparent"]).toBeUndefined(); + const child = interceptors(); + await child.inbound![0]!.execute!({ args: [turn], headers: input.headers } as never, async () => "ok"); + const span = fixture.sink.mock.lastCall![0]; + expect(span.parentSpanId).toBeNull(); + expect(span.traceId).not.toBe(trace); + expect(span.links).toEqual([]); + }) as never); + }); +}); + +it("records cancellation, continue-as-new and safe wrapped failure codes without swallowing errors", async () => { + for (const [error, outcome, errorCode] of [ + [Object.assign(new Error("private"), { name: "CancelledFailure" }), "CANCELLED", null], + [Object.create(ContinueAsNew.prototype), "CONTINUED_AS_NEW", null], + [Object.assign(new Error("private"), { cause: { type: "TOOL_UNAVAILABLE" } }), "FAILED", "TOOL_UNAVAILABLE"] + ] as const) { + const hooks = interceptors(); + await expect(hooks.inbound![0]!.execute!({ args: [], headers: {} }, async () => { throw error; })).rejects.toBe(error); + expect(fixture.sink.mock.lastCall![0]).toMatchObject({ outcome, errorCode }); + } +}); diff --git a/apps/worker/tests/otlp-worker-tracing.test.ts b/apps/worker/tests/otlp-worker-tracing.test.ts new file mode 100644 index 000000000..f9feda5f0 --- /dev/null +++ b/apps/worker/tests/otlp-worker-tracing.test.ts @@ -0,0 +1,199 @@ +import { describe, expect, it } from "vitest"; +import { defaultPayloadConverter } from "@temporalio/worker"; +import { MetricsRegistry, createOtlpSpanExporter, type ServerSpan, type SpanExporter } from "@space/runtime"; +import { createActivityObservabilityInterceptors, observeActivityExecution, traceparentFromHeaders } from "../src/activity-observability.js"; +import { captureWorkerLogs } from "../src/worker-log.js"; +import { createWorkerMetrics } from "../src/worker-metrics.js"; +import { createWorkerTracing, spaceTracingSinks, toWorkflowSpan, workerObservabilityOptions, workerTracing, workflowTracingModulePath } from "../src/worker-tracing.js"; +import type { WorkflowSpanRecord } from "../src/workflow-tracing-interceptors.js"; + +const traceparent = "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01"; +const workflowSpanTraceparent = "00-4bf92f3577b34da6a3ce929d0e0e4736-a3ce929d0e0e4736-01"; + +function recordingExporter(): SpanExporter & { recorded: ServerSpan[] } { + const recorded: ServerSpan[] = []; + return { + recorded, + record: (span) => { recorded.push(span); }, + flush: async () => undefined, + close: async () => undefined, + stats: () => ({ exported: 0, dropped: 0, failed: 0 }) + }; +} + +const workflowInfo = { workflowId: "workflow:codex-app-server:room_1:pane_1:req:abc", runId: "0190-run", workflowType: "codexAppServerTurnWorkflow", taskQueue: "space-turns" }; +const record: WorkflowSpanRecord = { + traceId: "4bf92f3577b34da6a3ce929d0e0e4736", + spanId: "a3ce929d0e0e4736", + parentSpanId: "00f067aa0ba902b7", + startTimeMs: 1_000, + endTimeMs: 1_400, + outcome: "FAILED", + errorCode: "CODEX_APP_SERVER_TURN_TIMEOUT", + correlation: { spaceTraceId: "req:abc", roomId: "room_1", paneId: "/etc/passwd" }, + links: [{ traceId: "0af7651916cd43dd8448eb211c80319c", spanId: "b7ad6b7169203331", reason: "continue_as_new" }] +}; + +describe("worker tracing switch", () => { + it("is off without SPACE_OTEL_EXPORTER_OTLP_ENDPOINT and leaves the Worker options unchanged", () => { + expect(workerTracing({}, "space-worker")).toBeNull(); + expect(createWorkerTracing({}, "space-worker")).toBeNull(); + expect(workerTracing({ SPACE_OTEL_EXPORTER_OTLP_ENDPOINT: "ftp://collector" }, "space-worker")).toBeNull(); + const options = workerObservabilityOptions(null); + expect(Object.keys(options)).toEqual(["interceptors"]); + expect(Object.keys(options.interceptors!)).toEqual(["activity"]); + expect(options.interceptors!.activity).toHaveLength(1); + }); + + it("registers the workflow interceptor module, the sink and the activity exporter when on", async () => { + const tracing = workerTracing({ SPACE_OTEL_EXPORTER_OTLP_ENDPOINT: "http://127.0.0.1:4318" }, "space-worker")!; + try { + const options = workerObservabilityOptions(tracing); + expect(options.interceptors!.workflowModules).toEqual([workflowTracingModulePath()]); + expect(workflowTracingModulePath()).toMatch(/workflow-tracing-interceptors\.(js|ts)$/); + expect(options.sinks).toBe(tracing.sinks); + expect(tracing.sinks.spaceTracing.workflowSpan.callDuringReplay).toBe(false); + expect(options.interceptors!.activity).toHaveLength(1); + } finally { + await tracing.close(); + } + }); + + it("wires every Temporal worker through the shared options builder", async () => { + const { readFile } = await import("node:fs/promises"); + for (const entry of ["worker.ts", "memory-maintenance-worker.ts", "memory-mutation-worker.ts"]) { + const source = await readFile(new URL(`../src/${entry}`, import.meta.url), "utf8"); + expect(source, entry).toMatch(/const tracing = workerTracing\(process\.env, /); + expect(source, entry).toMatch(/\.\.\.workerObservabilityOptions\(tracing\)/); + expect(source, entry).toMatch(/await tracing\?\.close\(\)/); + } + }); + + it("caps shutdown at two seconds when the collector hangs", async () => { + const exporter = createOtlpSpanExporter({ endpoint: "http://127.0.0.1:4318", serviceName: "space-worker", fetch: () => new Promise(() => undefined), timeoutMs: 60_000 }); + exporter.record({ ...toWorkflowSpan(workflowInfo, record) }); + const started = Date.now(); + await createWorkerTracing(exporter).close(); + expect(Date.now() - started).toBeLessThan(3_000); + }); +}); + +describe("workflow span sink", () => { + it("builds an INTERNAL workflow span with allowlisted attributes and reasoned links", () => { + const span = toWorkflowSpan(workflowInfo, record); + expect(span).toMatchObject({ + traceId: record.traceId, spanId: record.spanId, parentSpanId: "00f067aa0ba902b7", kind: 1, error: true, + name: "workflow codexAppServerTurnWorkflow", startTimeUnixNano: 1_000_000_000n, endTimeUnixNano: 1_400_000_000n + }); + expect(span.attributes).toEqual({ + "temporal.workflow.id": workflowInfo.workflowId, + "temporal.workflow.run_id": "0190-run", + "temporal.workflow.type": "codexAppServerTurnWorkflow", + "space.outcome": "FAILED", + "error.code": "CODEX_APP_SERVER_TURN_TIMEOUT", + "space.error.category": "TIMEOUT", + "space.duration_ms": 400, + "space.trace_id": "req:abc", + "space.room_id": "room_1" + }); + expect(span.links).toEqual([{ traceId: "0af7651916cd43dd8448eb211c80319c", spanId: "b7ad6b7169203331", attributes: { "space.link.kind": "continue_as_new" } }]); + }); + + it("is never called during replay and never throws into the worker", () => { + const throwing = { ...recordingExporter(), record: () => { throw new Error("collector bug"); } }; + const sinks = spaceTracingSinks(throwing); + expect(sinks.spaceTracing.workflowSpan.callDuringReplay).toBe(false); + expect(() => sinks.spaceTracing.workflowSpan.fn(workflowInfo as never, record)).not.toThrow(); + const exporter = recordingExporter(); + spaceTracingSinks(exporter).spaceTracing.workflowSpan.fn(workflowInfo as never, { ...record, outcome: "COMPLETED", errorCode: null }); + expect(exporter.recorded[0]!.attributes).not.toHaveProperty("error.code"); + expect(exporter.recorded[0]!.error).toBe(false); + }); +}); + +describe("activity attempt spans", () => { + const info = { activityType: "runTurn", activityId: "7", attempt: 2, currentAttemptScheduledTimestampMs: 900, workflowType: "codexAppServerTurnWorkflow", workflowExecution: { workflowId: "w-1", runId: "r-1" } } as never; + + it("nests under the workflow span from the header, ahead of the traceparent in the input", async () => { + const exporter = recordingExporter(); + const restore = captureWorkerLogs(() => undefined); + let clock = 1_000; + try { + await observeActivityExecution(info, [{ turn: { traceparent, traceId: "req:abc", roomId: "room_1", prompt: "never exported" } }], async () => { clock += 25; return { status: "FAILED" }; }, { + metrics: createWorkerMetrics(new MetricsRegistry()), now: () => clock, spans: exporter, parentTraceparent: workflowSpanTraceparent + }); + } finally { + restore(); + } + expect(exporter.recorded).toHaveLength(1); + const span = exporter.recorded[0]!; + expect(span).toMatchObject({ traceId: "4bf92f3577b34da6a3ce929d0e0e4736", parentSpanId: "a3ce929d0e0e4736", kind: 1, error: true, name: "activity runTurn" }); + expect(span.attributes).toEqual({ + "temporal.activity.type": "runTurn", + "temporal.activity.id": "7", + "temporal.activity.attempt": 2, + "temporal.workflow.id": "w-1", + "temporal.workflow.run_id": "r-1", + "temporal.workflow.type": "codexAppServerTurnWorkflow", + "space.outcome": "FAILED_RESULT", + "error.code": "ACTIVITY_RESULT_FAILED", + "space.error.category": "INTERNAL", + "space.duration_ms": 25, + "space.queue_ms": 100, + "space.trace_id": "req:abc", + "space.room_id": "room_1" + }); + expect(JSON.stringify(span.attributes)).not.toContain("never exported"); + }); + + it("reads the traceparent header and ignores anything that is not one", () => { + expect(traceparentFromHeaders({ "space-traceparent": defaultPayloadConverter.toPayload(workflowSpanTraceparent) })).toBe(workflowSpanTraceparent); + expect(traceparentFromHeaders({ "space-traceparent": defaultPayloadConverter.toPayload("https://example.test") })).toBeNull(); + expect(traceparentFromHeaders({})).toBeNull(); + expect(traceparentFromHeaders(undefined)).toBeNull(); + }); + + it("passes the header to the span through the interceptor", async () => { + const exporter = recordingExporter(); + const factory = createActivityObservabilityInterceptors({ spans: exporter, metrics: createWorkerMetrics(new MetricsRegistry()) }); + const interceptors = factory({ info, cancellationSignal: new AbortController().signal } as never); + const restore = captureWorkerLogs(() => undefined); + try { + await interceptors.inbound!.execute!({ args: [{}], headers: { "space-traceparent": defaultPayloadConverter.toPayload(workflowSpanTraceparent) } }, async () => "ok"); + } finally { + restore(); + } + expect(exporter.recorded[0]).toMatchObject({ traceId: "4bf92f3577b34da6a3ce929d0e0e4736", parentSpanId: "a3ce929d0e0e4736" }); + }); + + it("preserves activity results when the exporter throws", async () => { + const exporter = { ...recordingExporter(), record: () => { throw new Error("export failure"); } }; + const restore = captureWorkerLogs(() => undefined); + const dependencies = { spans: exporter, parentTraceparent: workflowSpanTraceparent, metrics: createWorkerMetrics(new MetricsRegistry()) }; + try { + await expect(observeActivityExecution(info, [], async () => "ok", dependencies)).resolves.toBe("ok"); + const error = new Error("activity failure"); + await expect(observeActivityExecution(info, [], async () => { throw error; }, dependencies)).rejects.toBe(error); + } finally { restore(); } + }); + + it("is not delayed or failed by a collector that never answers", async () => { + const exporter = createOtlpSpanExporter({ endpoint: "http://127.0.0.1:4318", serviceName: "space-worker", batchSize: 1, maxQueue: 1, fetch: () => new Promise(() => undefined) }); + const restore = captureWorkerLogs(() => undefined); + try { + const started = Date.now(); + for (let index = 0; index < 5; index += 1) { + await expect(observeActivityExecution(info, [{}], async () => "done", { + metrics: createWorkerMetrics(new MetricsRegistry()), spans: exporter, parentTraceparent: workflowSpanTraceparent + })).resolves.toBe("done"); + } + await expect(observeActivityExecution(info, [{}], async () => { throw new Error("activity failure stays the activity's"); }, { + metrics: createWorkerMetrics(new MetricsRegistry()), spans: exporter, parentTraceparent: workflowSpanTraceparent + })).rejects.toThrow("activity failure stays the activity's"); + expect(Date.now() - started).toBeLessThan(1_000); + expect(exporter.stats().dropped).toBeGreaterThan(0); + } finally { + restore(); + } + }); +}); diff --git a/apps/worker/tests/otlp-workflow-tracing.test.ts b/apps/worker/tests/otlp-workflow-tracing.test.ts new file mode 100644 index 000000000..0c855b37b --- /dev/null +++ b/apps/worker/tests/otlp-workflow-tracing.test.ts @@ -0,0 +1,261 @@ +// End to end: a real Temporal test server (@temporalio/testing), a real Worker +// with OTLP tracing pointed at a fake collector (local http.createServer), and +// test-only workflows with stub activities. No Docker, no AI provider. +import http from "node:http"; +import { fileURLToPath } from "node:url"; +import { afterAll, beforeAll, describe, expect, it } from "vitest"; +import { ApplicationFailure, Context } from "@temporalio/activity"; +import { TestWorkflowEnvironment } from "@temporalio/testing"; +import { Runtime, Worker, DefaultLogger } from "@temporalio/worker"; +import { MEMORY_MAINTENANCE_TASK_QUEUE } from "../src/memory-maintenance-config.js"; +import { SPAN_ATTRIBUTE_ALLOWLIST } from "@space/runtime"; +import { workerObservabilityOptions, workerTracing, workflowTracingModulePath, type WorkerTracing } from "../src/worker-tracing.js"; +import { captureWorkerLogs } from "../src/worker-log.js"; +import type { TracedInput, TracingStubActivities } from "./support/otlp-tracing-workflows.js"; + +interface OtlpAttribute { key: string; value: { stringValue?: string; intValue?: string } } +interface OtlpSpan { + traceId: string; + spanId: string; + parentSpanId?: string; + name: string; + kind: number; + attributes: OtlpAttribute[]; + links?: Array<{ traceId: string; spanId: string; attributes: OtlpAttribute[] }>; + status: { code: number }; +} + +const workflowsPath = fileURLToPath(new URL("./support/otlp-tracing-workflows.ts", import.meta.url)); +const inboundTraceId = "4bf92f3577b34da6a3ce929d0e0e4736"; +const inboundSpanId = "00f067aa0ba902b7"; +const inboundTraceparent = `00-${inboundTraceId}-${inboundSpanId}-01`; +const canary = { + prompt: "CANARY-PROMPT summarise the secret plan", + filePath: "/home/canary-user/secret-notes.txt", + url: "https://canary-leak.example/path?token=abc" +}; + +Runtime.install({ logger: new DefaultLogger("WARN") }); + +let unavailable: string | null = null; +let env: TestWorkflowEnvironment | null = null; +try { + // Starts (and on first use downloads) the Temporal CLI dev server. + env = await TestWorkflowEnvironment.createLocal(); +} catch (error) { + unavailable = `Temporal test server unavailable (${error instanceof Error ? error.message.slice(0, 160) : "unknown"}); the OTLP integration and replay tests are skipped`; + console.warn(unavailable); +} + +const bodies: string[] = []; +let collector: http.Server; +let endpoint = ""; +let tracing: WorkerTracing; +let restoreLogs: () => void = () => undefined; + +function spans(): OtlpSpan[] { + return bodies.flatMap(body => (JSON.parse(body) as { resourceSpans: Array<{ scopeSpans: Array<{ spans: OtlpSpan[] }> }> }) + .resourceSpans.flatMap(resource => resource.scopeSpans.flatMap(scope => scope.spans))); +} +/** Flushes until the collector has a matching span: the sink runs just after the workflow completes. */ +async function waitForSpan(predicate: (span: OtlpSpan) => boolean): Promise { + for (let attempt = 0; attempt < 100; attempt += 1) { + await tracing.spans.flush(); + if (spans().some(predicate)) return; + await new Promise(resolve => setTimeout(resolve, 50)); + } +} +const attribute = (span: OtlpSpan, key: string) => { + const value = span.attributes.find(entry => entry.key === key)?.value; + return value?.intValue !== undefined ? Number(value.intValue) : value?.stringValue; +}; + +describe.skipIf(!env)("OTLP workflow and activity spans", () => { + const taskQueue = `otlp-tracing-${Date.now()}`; + let worker: Worker; + let workerRun: Promise; + let memoryWorker: Worker; + let memoryWorkerRun: Promise; + + beforeAll(async () => { + restoreLogs = captureWorkerLogs(() => undefined); + collector = http.createServer((request, response) => { + const chunks: Buffer[] = []; + request.on("data", chunk => chunks.push(chunk as Buffer)); + request.on("end", () => { + if (request.method === "POST" && request.url === "/v1/traces") bodies.push(Buffer.concat(chunks).toString("utf8")); + response.writeHead(200, { "content-type": "application/json" }).end("{}"); + }); + }); + await new Promise(resolve => collector.listen(0, "127.0.0.1", resolve)); + endpoint = `http://127.0.0.1:${(collector.address() as { port: number }).port}`; + tracing = workerTracing({ SPACE_OTEL_EXPORTER_OTLP_ENDPOINT: endpoint }, "space-worker")!; const failedOnce = new Set(); + const activities: TracingStubActivities = { + async stubStep() { return "ok"; }, + async flakyStep() { + const key = Context.current().info.workflowExecution.workflowId; + if (!failedOnce.has(key)) { + failedOnce.add(key); + throw ApplicationFailure.retryable(`first attempt fails: ${canary.prompt} ${canary.url}`, "TOOL_UNAVAILABLE"); + } + return "ok"; + } + }; + worker = await Worker.create({ + connection: env!.nativeConnection, + namespace: env!.namespace ?? "default", + taskQueue, + workflowsPath, + activities: { + ...activities, + refreshMemoryGraphSnapshot: async () => ({ sourceHash: "source-test" }), + refreshAllMonthsMemoryGraphSnapshot: async () => ({}), + reconcileStaleSpaceAgentSessions: async () => ({}), + createScheduledMemoryAudit: async () => ({ id: "audit-test", workflowId: "otlp-memory-child" }) + }, + ...workerObservabilityOptions(tracing) + }); + workerRun = worker.run(); + memoryWorker = await Worker.create({ + connection: env!.nativeConnection, namespace: env!.namespace ?? "default", + taskQueue: MEMORY_MAINTENANCE_TASK_QUEUE, workflowsPath, + activities: { prepareMemoryConsolidation: async () => ({ changeSetId: null, run: { id: "audit-test" } }) }, + ...workerObservabilityOptions(tracing) + }); + memoryWorkerRun = memoryWorker.run(); + }, 120_000); + + afterAll(async () => { + memoryWorker?.shutdown(); + await memoryWorkerRun?.catch(() => undefined); + worker?.shutdown(); + await workerRun?.catch(() => undefined); + await tracing?.close(); + await new Promise(resolve => collector?.close(resolve)); + restoreLogs(); + await env?.teardown(); + }, 60_000); + + it("connects the API span, the workflow, every activity attempt and the child workflow in one trace", async () => { + const workflowId = `otlp-parent-${Date.now()}`; + const input: TracedInput = { traceId: "req:otlp-integration", roomId: "room_otlp", paneId: "pane_otlp", traceparent: inboundTraceparent, ...canary }; + await env!.client.workflow.execute("tracedParentWorkflow", { + args: [input], taskQueue, workflowId, memo: { traceparent: inboundTraceparent, spaceTraceId: input.traceId } + }); + await waitForSpan(span => span.name === "workflow tracedParentWorkflow" && attribute(span, "temporal.workflow.id") === workflowId); + const trace = spans().filter(span => span.traceId === inboundTraceId); + const parent = trace.find(span => span.name === "workflow tracedParentWorkflow")!; + const child = trace.find(span => span.name === "workflow tracedChildWorkflow")!; + expect(parent).toBeDefined(); + expect(child).toBeDefined(); + expect(parent.parentSpanId).toBe(inboundSpanId); + expect(parent.kind).toBe(1); + expect(attribute(parent, "temporal.workflow.id")).toBe(workflowId); + expect(attribute(parent, "space.outcome")).toBe("COMPLETED"); + expect(attribute(parent, "space.trace_id")).toBe("req:otlp-integration"); + expect(attribute(parent, "space.room_id")).toBe("room_otlp"); + expect(child.parentSpanId).toBe(parent.spanId); + + const flaky = trace.filter(span => span.name === "activity flakyStep").sort((a, b) => Number(attribute(a, "temporal.activity.attempt")) - Number(attribute(b, "temporal.activity.attempt"))); + expect(flaky.map(span => attribute(span, "temporal.activity.attempt"))).toEqual([1, 2]); + expect(flaky.every(span => span.parentSpanId === parent.spanId && span.kind === 1)).toBe(true); + expect(attribute(flaky[0]!, "space.outcome")).toBe("FAILED"); + expect(attribute(flaky[0]!, "error.code")).toBe("TOOL_UNAVAILABLE"); + expect(attribute(flaky[0]!, "space.error.category")).toBe("TOOL_UNAVAILABLE"); + expect(flaky[0]!.status.code).toBe(2); + expect(attribute(flaky[1]!, "space.outcome")).toBe("COMPLETED"); + + const stubs = trace.filter(span => span.name === "activity stubStep"); + expect(stubs.map(span => span.parentSpanId).sort()).toEqual([parent.spanId, child.spanId].sort()); + // Every span of this run is in the request's trace. + expect(spans().filter(span => attribute(span, "temporal.workflow.id")?.toString().startsWith(workflowId)).every(span => span.traceId === inboundTraceId)).toBe(true); + }); + + it("nests the real memory maintenance and consolidation workflows", async () => { + const workflowId = "otlp-memory-parent"; + await env!.client.workflow.execute("memoryMaintenanceWorkflow", { + args: [{ traceId: "req:memory-test" }], taskQueue, workflowId, + memo: { traceparent: inboundTraceparent } + }); + await waitForSpan(span => span.name === "workflow memoryMaintenanceWorkflow"); + const parent = spans().find(span => span.name === "workflow memoryMaintenanceWorkflow")!; + const child = spans().find(span => span.name === "workflow memoryConsolidationWorkflow")!; + expect(parent.parentSpanId).toBe(inboundSpanId); + expect(child.traceId).toBe(inboundTraceId); + expect(child.parentSpanId).toBe(parent.spanId); + expect(spans().find(span => span.name === "activity prepareMemoryConsolidation")?.parentSpanId).toBe(child.spanId); + }, 30_000); + + it("keeps a continue-as-new run in the same trace with a link to the previous run", async () => { + const workflowId = `otlp-continue-${Date.now()}`; + await env!.client.workflow.execute("tracedContinueWorkflow", { args: [{ iteration: 0, traceparent: inboundTraceparent }], taskQueue, workflowId }); + await waitForSpan(span => attribute(span, "temporal.workflow.id") === workflowId && attribute(span, "space.outcome") === "COMPLETED"); + const runs = spans().filter(span => span.name === "workflow tracedContinueWorkflow" && attribute(span, "temporal.workflow.id") === workflowId); + expect(runs).toHaveLength(2); + const first = runs.find(span => attribute(span, "space.outcome") === "CONTINUED_AS_NEW")!; + const second = runs.find(span => attribute(span, "space.outcome") === "COMPLETED")!; + expect(first.traceId).toBe(inboundTraceId); + expect(second.traceId).toBe(inboundTraceId); + expect(second.parentSpanId).toBe(inboundSpanId); + expect(second.links?.[0]).toMatchObject({ traceId: inboundTraceId, spanId: first.spanId }); + expect(second.links?.[0]?.attributes).toEqual([{ key: "space.link.kind", value: { stringValue: "continue_as_new" } }]); + }); + + it("links a background continuation to the turn it continues", async () => { + const workflowId = `otlp-continuation-${Date.now()}`; + const ownTraceparent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + await env!.client.workflow.execute("tracedContinuationWorkflow", { + args: [{ traceId: "trace:bg-otlp", roomId: "room_otlp", paneId: "pane_otlp", traceparent: ownTraceparent, continuationTraceparent: inboundTraceparent }], + taskQueue, workflowId + }); + await waitForSpan(entry => attribute(entry, "temporal.workflow.id") === workflowId); + const span = spans().find(entry => entry.name === "workflow tracedContinuationWorkflow" && attribute(entry, "temporal.workflow.id") === workflowId)!; + expect(span.traceId).toBe("0af7651916cd43dd8448eb211c80319c"); + expect(span.parentSpanId).toBeUndefined(); + expect(span.links).toEqual([{ traceId: inboundTraceId, spanId: inboundSpanId, attributes: [{ key: "space.link.kind", value: { stringValue: "background_continuation" } }] }]); + }); + + it("exports allowlisted attributes only and never the prompt, paths, URLs or error messages", async () => { + expect(bodies.length).toBeGreaterThan(0); + for (const span of spans()) { + for (const { key, value } of [...span.attributes, ...(span.links ?? []).flatMap(link => link.attributes)]) { + expect(SPAN_ATTRIBUTE_ALLOWLIST.has(key), key).toBe(true); + if (value.stringValue !== undefined) expect(value.stringValue).toMatch(/^[A-Za-z0-9:._-]{1,200}$/); + } + } + const all = bodies.join("\n"); + for (const secret of ["CANARY", "canary-user", "secret-notes", "canary-leak", "first attempt fails", "summarise"]) expect(all).not.toContain(secret); + }); + + it("replaying a recorded history emits no spans", async () => { + const workflowId = `otlp-replay-${Date.now()}`; + const handle = await env!.client.workflow.start("tracedParentWorkflow", { + args: [{ traceId: "req:otlp-replay", roomId: "room_otlp", paneId: "pane_otlp", traceparent: inboundTraceparent }], taskQueue, workflowId + }); + await handle.result(); + await waitForSpan(span => span.name === "workflow tracedParentWorkflow" && attribute(span, "temporal.workflow.id") === workflowId); + const history = await handle.fetchHistory(); + const postsBefore = bodies.length; + const sinkCalls: unknown[] = []; + await Worker.runReplayHistory({ + workflowsPath, + interceptors: { workflowModules: [workflowTracingModulePath()] }, + sinks: { spaceTracing: { workflowSpan: { fn: (_info: unknown, record: unknown) => { sinkCalls.push(record); }, callDuringReplay: false } } } + }, history, workflowId); + await tracing.spans.flush(); + expect(sinkCalls).toEqual([]); + expect(bodies.length).toBe(postsBefore); + // Control: the interceptor does run during replay; only the sink option keeps it silent. + const controlCalls: unknown[] = []; + await Worker.runReplayHistory({ + workflowsPath, + interceptors: { workflowModules: [workflowTracingModulePath()] }, + sinks: { spaceTracing: { workflowSpan: { fn: (_info: unknown, record: unknown) => { controlCalls.push(record); }, callDuringReplay: true } } } + }, history, workflowId); + expect(controlCalls).toHaveLength(1); + }, 120_000); +}); + +it.skipIf(!unavailable)("records why the Temporal integration tests were skipped", () => { + expect(unavailable).toMatch(/Temporal test server unavailable/); +}); diff --git a/apps/worker/tests/room-continuation-fixture.ts b/apps/worker/tests/room-continuation-fixture.ts index 340e964e0..9307f2623 100644 --- a/apps/worker/tests/room-continuation-fixture.ts +++ b/apps/worker/tests/room-continuation-fixture.ts @@ -1,7 +1,7 @@ import { buildCodexAppServerTurnWorkflowId, roomAgentSupervisorQueueItemSchema } from "@space/contracts"; import { InMemorySpaceStore } from "@space/runtime"; -export function continuationFixture(actionType: "OPEN_TYPES" | "CONFIGURE_PANE" = "OPEN_TYPES") { +export function continuationFixture(actionType: "OPEN_TYPES" | "CONFIGURE_PANE" = "OPEN_TYPES", traceparent?: string) { const store = new InMemorySpaceStore(); const room = store.createRoom({ name: "Continuation regression", initialPaneCount: 0 }); const pane = store.getOrCreateRoomAgentPane(room.id); @@ -14,7 +14,7 @@ export function continuationFixture(actionType: "OPEN_TYPES" | "CONFIGURE_PANE" modelId: "gpt-5.6-sol", reasoningEffort: "high", agentSessionId: session.sessionId, agentRunId: `agent_run:${suffix}`, agentUserMessageId: `agent_msg:user-${suffix}`, agentAssistantMessageId: `agent_msg:assistant-${suffix}`, roomAgentMissionId: "mission:continuation", - traceId: `trace:continuation-${suffix}`, selectedToolIds: ["room:inspect", "room:open_types", "room:send"] + traceId: `trace:continuation-${suffix}`, ...(traceparent ? { traceparent } : {}), selectedToolIds: ["room:inspect", "room:open_types", "room:send"] } }); return store.enqueueRoomAgentMission({ requestId: `request:${suffix}`, clientRequestId: `client-${suffix}`, content: prompt, supervisorWorkflowId: `room-supervisor:${room.id}`, childWorkflowId: buildCodexAppServerTurnWorkflowId(item.turn), diff --git a/apps/worker/tests/support/otlp-tracing-workflows.ts b/apps/worker/tests/support/otlp-tracing-workflows.ts new file mode 100644 index 000000000..c6068024c --- /dev/null +++ b/apps/worker/tests/support/otlp-tracing-workflows.ts @@ -0,0 +1,53 @@ +// Test-only workflows for the OTLP tracing integration test: a parent with a +// stub activity, a retried activity and a child workflow, a run that continues +// as new once, and a background continuation. No Space services involved. +import { continueAsNew, executeChild, proxyActivities, workflowInfo } from "@temporalio/workflow"; + +export interface TracedInput { + traceId: string; + roomId: string; + paneId: string; + traceparent?: string; + continuationTraceparent?: string; + // Canary values: must never reach the collector. + prompt?: string; + filePath?: string; + url?: string; +} + +export interface TracingStubActivities { + stubStep(input: TracedInput): Promise; + flakyStep(input: TracedInput): Promise; +} + +const { stubStep, flakyStep } = proxyActivities({ + startToCloseTimeout: "10 seconds", + retry: { maximumAttempts: 3, initialInterval: "10 milliseconds", backoffCoefficient: 1 } +}); + +export async function tracedParentWorkflow(input: TracedInput): Promise { + await stubStep(input); + await flakyStep(input); + await executeChild(tracedChildWorkflow, { + args: [{ traceId: input.traceId, roomId: input.roomId, paneId: input.paneId }], + workflowId: `${workflowInfo().workflowId}:child` + }); + return "parent-done"; +} + +export async function tracedChildWorkflow(input: TracedInput): Promise { + await stubStep(input); + return "child-done"; +} + +export async function tracedContinueWorkflow(input: { iteration: number; traceparent?: string }): Promise { + if (input.iteration === 0) await continueAsNew({ iteration: 1 }); + return input.iteration; +} + +export async function tracedContinuationWorkflow(input: TracedInput): Promise { + await stubStep(input); + return "continuation-done"; +} + +export { memoryMaintenanceWorkflow, memoryConsolidationWorkflow } from "../../src/memory-maintenance-workflows.js"; diff --git a/apps/worker/vitest.config.ts b/apps/worker/vitest.config.ts index 5b1ed61f7..036767b9d 100644 --- a/apps/worker/vitest.config.ts +++ b/apps/worker/vitest.config.ts @@ -8,6 +8,7 @@ const __dirname = path.dirname(fileURLToPath(import.meta.url)); export default defineConfig({ resolve: { alias: { + "@space/runtime/span-attributes": resolve(__dirname, "../../packages/runtime/src/span-attributes.ts"), "@space/db": resolve(__dirname, "../../packages/db/src/index.ts"), "@space/contracts": resolve(__dirname, "../../packages/contracts/src/index.ts"), "@space/runtime": resolve(__dirname, "../../packages/runtime/src/index.ts"), diff --git a/docs/configuration-reference.md b/docs/configuration-reference.md index e432af4c6..02568a8c4 100644 --- a/docs/configuration-reference.md +++ b/docs/configuration-reference.md @@ -52,3 +52,14 @@ background work, and is hidden in the web app. Public installs upgraded from 1.1.x that used Job Copilot, the games, channels, Telegram or the desktop routes set the modules they keep, for example `SPACE_OPTIONAL_MODULES=job-copilot,games`. + +### OTLP span export + +`SPACE_OTEL_EXPORTER_OTLP_ENDPOINT` enables optional OTLP/HTTP JSON export for the +API and all three Temporal workers. It is off by default. Set a collector base +URL, for example `http://127.0.0.1:4318`; `/v1/traces` is appended. Credentials, +query strings and fragments are rejected. Service names are `space-api`, +`space-worker`, `space-memory-maintenance-worker` and `space-memory-mutation-worker`. +Workers export workflow runs and activity attempts with parent/child relationships +and continuation links. The shared exporter has a bounded queue, counts drops, +and times out each POST. Replay exports no spans; no OpenTelemetry SDK is needed. diff --git a/docs/quality/observability.md b/docs/quality/observability.md index 488fc3036..854ab260e 100644 --- a/docs/quality/observability.md +++ b/docs/quality/observability.md @@ -217,11 +217,26 @@ Without the endpoint, every activity still writes `activity.started` and The trace context is local by default. An optional OTLP/HTTP (JSON) exporter sends one SERVER span per API request when `SPACE_OTEL_EXPORTER_OTLP_ENDPOINT` is set (no -OpenTelemetry dependency; `packages/runtime/src/otlp-span-exporter.ts`). Since -2026-10-16 the worker and both memory workers use the same exporter (services +OpenTelemetry dependency; `packages/runtime/src/otlp-span-exporter.ts`). The +worker and both memory workers use the same exporter (services `space-worker`, `space-memory-maintenance-worker`, `space-memory-mutation-worker`): -one INTERNAL span per activity whose input carries a `traceparent`, as a child of -that span, with the activity type, outcome and attempt only. +one INTERNAL span per workflow run under the API SERVER span, and one INTERNAL +span per activity attempt under its workflow. Child workflows nest under their +parent workflow. Temporal headers propagate these parents, including to local +activities. A workflow sink with `callDuringReplay: false` prevents replay export. +Continue-as-new runs link to their preceding run; background continuations use +a fresh trace and a `background_continuation` link to their originating trace. +Worker attributes are allowlisted identifiers, types, attempts, outcomes, stable +error codes/categories and durations. Prompts, output, paths, URLs, error messages +and stacks are excluded. Collector failures do not affect workflow/activity work. + +Worker spans are named `workflow ` and `activity `. +The allowlist admits Space trace/room/pane/mission IDs, Temporal workflow type, +ID and run ID, activity type, ID and attempt, `space.outcome`, `error.code`, +`space.error.category`, `space.duration_ms` and `space.queue_ms`. Numeric +attributes must be nonnegative integers. Links carry only `space.link.kind`, +with value `continue_as_new` or `background_continuation`. + - **API:** a valid inbound `traceparent` is continued (same trace ID, new span). An invalid or missing header gets a new trace ID. Every API log line carries `w3cTraceId` (Fastify `childLoggerFactory`). @@ -233,28 +248,17 @@ that span, with the activity type, outcome and attempt only. - **Worker:** worker logs read the trace ID from the activity input. Internal room-action calls from the worker send a child `traceparent`, so the internal API request joins the same trace. -- **Workflow code is unchanged.** Correlation is done in the API starter - (input/memo) and in an activity interceptor. The workflow bundle only gains the - optional contract field. +- **Workflow tracing:** an optional deterministic interceptor propagates headers + and records run completion through a worker sink; workflow code performs no I/O. ### Replay compatibility -No file under `apps/worker/src` that the workflow bundle imports was changed -(`workflows.ts`, `room-supervisor-state.ts`, `turn-runtime-policy.ts`, -`dot-goal-loop.ts`). The `agent-turns` workflow bundle was built for the base -commit and for this change and compared after normalizing paths and webpack -module numbers. The only differences are in `@space/contracts`: -- the new `observability` module; -- the optional `traceparent` turn-input field; -- the optional file search and readiness fields. - -A history without `traceparent` parses exactly as before. Activity inputs are -not part of Temporal's determinism check. - -The read-only live replay (`node scripts/temporal-replay-check.mjs --limit 30`) -could not be run from the agent sandbox that made this change. Its network -namespace has no route to the Temporal container (`172.18.0.5:7233`), and -`127.0.0.1:7233` refuses connections. Run it before deploying this change. +The workflow interceptor uses Temporal's deterministic UUID generator and sandbox +clock. Its sink has `callDuringReplay: false`. The integration test captures a +history and replays it with `Worker.runReplayHistory`, checking zero sink calls +and zero collector posts. Tracing is omitted entirely when the endpoint is unset. +Replay representative production histories before deploying to existing runs; +the integration proof covers the fixture histories, not every production history. ## Redaction policy @@ -315,7 +319,7 @@ No credential or transcript export was added. continuation from the run it continues (`roomAgentContinuation.sourceRunId`, indexed by migration 0206, at most 50 generations and the row limit) and marks it with `continuationOf`. Its events and logs remain under its own - trace ID. Chat-pane sends from room actions use `:chat`. + trace ID; OTLP spans now link back to the originating trace. Chat-pane sends from room actions use `:chat`. - **CLI terminal task IDs are not linked.** `cliTaskId` and `revisionId` are not tied to request IDs. - **Hosts are observed from the API, not instrumented.** Since 2026-10-12 the @@ -337,7 +341,7 @@ No credential or transcript export was added. trace's workflows, joined by workflow id, with their status and error code, and names a failed run's code as the cause when no event carries one. - **Hosts emit no spans.** Since 2026-10-16 the OTLP exporter sends API SERVER - spans and worker activity spans (the worker and both memory workers); the CLI + spans and worker workflow/activity spans (the worker and both memory workers); the CLI and Browser Hosts still join traces through log lines only. - **Recovery counters are partial.** Recovery counters exist for plan model retries, CLI terminal reconnects and worker activity retries only. diff --git a/package-lock.json b/package-lock.json index 8fb65e91c..7f4897647 100644 --- a/package-lock.json +++ b/package-lock.json @@ -210,6 +210,7 @@ "undici": "8.10.2" }, "devDependencies": { + "@temporalio/testing": "1.24.0", "typescript": "^5.9.3", "vitest": "^4.1.11" } @@ -3685,6 +3686,25 @@ "node": ">=12.0.0" } }, + "node_modules/@temporalio/testing": { + "version": "1.24.0", + "resolved": "https://registry.npmjs.org/@temporalio/testing/-/testing-1.24.0.tgz", + "integrity": "sha512-XKCuvgb7smKR3oXy5nDgwYSFX/hmg9zTJ2rZQQsVwJzFkga1TbnWDiuT5YMU0INKjoLhnM6c5YA/uLKlp8sdfg==", + "dev": true, + "license": "MIT", + "dependencies": { + "@temporalio/activity": "1.24.0", + "@temporalio/client": "1.24.0", + "@temporalio/common": "1.24.0", + "@temporalio/core-bridge": "1.24.0", + "@temporalio/proto": "1.24.0", + "@temporalio/worker": "1.24.0", + "@temporalio/workflow": "1.24.0" + }, + "engines": { + "node": ">= 20.3.0" + } + }, "node_modules/@temporalio/worker": { "version": "1.24.0", "resolved": "https://registry.npmjs.org/@temporalio/worker/-/worker-1.24.0.tgz", diff --git a/packages/contracts/src/schemas.ts b/packages/contracts/src/schemas.ts index 0e8ce49f8..ef178e7db 100644 --- a/packages/contracts/src/schemas.ts +++ b/packages/contracts/src/schemas.ts @@ -6751,6 +6751,9 @@ export const dummyTurnInputSchema = z.object({ // Optional W3C trace context of the originating request (additive; see // docs/quality/observability.md). Never part of a workflow id. traceparent: traceparentSchema.optional(), + // A background continuation: the traceparent of the turn it continues. The + // worker exports it as an OTLP span link, never as a parent. + continuationTraceparent: traceparentSchema.optional(), // Space Dots Stage 3 (additive): a gateway-enabled native Chat turn. dotId: dotIdSchema.optional(), toolGateway: z.literal("space-dot-tools-v1").optional(), diff --git a/packages/runtime/package.json b/packages/runtime/package.json index d05b6c5c3..45576da1f 100644 --- a/packages/runtime/package.json +++ b/packages/runtime/package.json @@ -6,6 +6,10 @@ "main": "dist/index.js", "types": "dist/index.d.ts", "exports": { + "./span-attributes": { + "types": "./dist/span-attributes.d.ts", + "import": "./dist/span-attributes.js" + }, ".": { "types": "./dist/index.d.ts", "import": "./dist/index.js" diff --git a/packages/runtime/src/__tests__/otlp-span-links.test.ts b/packages/runtime/src/__tests__/otlp-span-links.test.ts new file mode 100644 index 000000000..3c29bd705 --- /dev/null +++ b/packages/runtime/src/__tests__/otlp-span-links.test.ts @@ -0,0 +1,122 @@ +import { describe, expect, it } from "vitest"; +import { SPAN_ATTRIBUTE_ALLOWLIST, allowlistSpanAttributes, createOtlpSpanExporter, otlpTraceRequest, type ServerSpan } from "../index.js"; + +const base: ServerSpan = { + traceId: "4bf92f3577b34da6a3ce929d0e0e4736", + spanId: "00f067aa0ba902b7", + parentSpanId: null, + name: "workflow probe", + startTimeUnixNano: 1n, + endTimeUnixNano: 2n, + attributes: {}, + error: false +}; + +const encoded = (span: ServerSpan) => otlpTraceRequest([span], "space-worker").resourceSpans[0]!.scopeSpans[0]!.spans[0]! as Record; + +describe("OTLP span kind and links", () => { + it("keeps the API encoding when kind and links are absent", () => { + const span = encoded(base); + expect(span.kind).toBe(2); + expect(span).not.toHaveProperty("links"); + expect(encoded({ ...base, links: [] })).not.toHaveProperty("links"); + }); + + it("encodes kind and valid links with allowlisted attributes, dropping invalid ids", () => { + const span = encoded({ + ...base, + kind: 1, + links: [ + { traceId: "0af7651916cd43dd8448eb211c80319c", spanId: "b7ad6b7169203331", attributes: { "space.link.kind": "continue_as_new", prompt: "secret" } }, + { traceId: "0".repeat(32), spanId: "b7ad6b7169203331" }, + { traceId: base.traceId, spanId: "0".repeat(16) }, + { traceId: "not-a-trace", spanId: "b7ad6b7169203331" }, + { traceId: "0af7651916cd43dd8448eb211c80319c", spanId: "short" } + ] + }); + expect(span.kind).toBe(1); + expect(span.links).toEqual([{ + traceId: "0af7651916cd43dd8448eb211c80319c", + spanId: "b7ad6b7169203331", + attributes: [{ key: "space.link.kind", value: { stringValue: "continue_as_new" } }] + }]); + }); +}); + +describe("flush", () => { + it("still exports after a flush found the queue empty", async () => { + const posts: string[] = []; + const exporter = createOtlpSpanExporter({ + endpoint: "http://127.0.0.1:4318", + serviceName: "space-worker", + flushIntervalMs: 60_000, + fetch: async (_url, init) => { posts.push(init.body); return { ok: true }; } + }); + await exporter.flush(); + exporter.record(base); + await exporter.flush(); + expect(posts).toHaveLength(1); + expect(exporter.stats()).toEqual({ exported: 1, dropped: 0, failed: 0 }); + await exporter.close(); + }); +}); + +describe("allowlistSpanAttributes", () => { + it("keeps allowlisted identifier-shaped values", () => { + expect(allowlistSpanAttributes({ + "temporal.workflow.id": "workflow:codex-app-server:room_1:pane_1:req:abc", + "temporal.activity.attempt": 2, + "error.code": "CODEX_APP_SERVER_TURN_TIMEOUT", + "space.error.category": "TIMEOUT", + "space.duration_ms": 12 + })).toEqual({ + "temporal.workflow.id": "workflow:codex-app-server:room_1:pane_1:req:abc", + "temporal.activity.attempt": 2, + "error.code": "CODEX_APP_SERVER_TURN_TIMEOUT", + "space.error.category": "TIMEOUT", + "space.duration_ms": 12 + }); + }); + + it("drops unknown keys, free text, paths, URLs, long strings, non-finite numbers and unsafe codes", () => { + expect(allowlistSpanAttributes({ + prompt: "write me a poem", + "error.message": "boom", + "space.room_id": "/etc/passwd", + "space.pane_id": "https://example.test/x", + "space.mission_id": "has spaces", + "space.trace_id": "x".repeat(201), + "space.duration_ms": Number.POSITIVE_INFINITY, + "space.queue_ms": Number.NaN, + "error.code": "lower case message", + "space.error.category": "MADE_UP", + "temporal.activity.attempt": { nested: true }, + "space.outcome": null + })).toEqual({}); + }); + + it("only allows the documented keys", () => { + expect([...SPAN_ATTRIBUTE_ALLOWLIST].sort()).toEqual([ + "space.duration_ms", "space.error.category", "error.code", "space.queue_ms", + "space.link.kind", "space.mission_id", "space.outcome", + "space.pane_id", "space.room_id", "space.trace_id", + "temporal.activity.attempt", "temporal.activity.id", "temporal.activity.type", + "temporal.workflow.run_id", "temporal.workflow.id", "temporal.workflow.type" + ].sort()); + }); +}); + +it("aborts a hanging collector and counts failed spans", async () => { + let signal: AbortSignal | undefined; + const exporter = createOtlpSpanExporter({ + endpoint: "http://127.0.0.1:4318", serviceName: "test", timeoutMs: 10, + fetch: (_url, init) => new Promise((_resolve, reject) => { + signal = init.signal; + init.signal.addEventListener("abort", () => reject(init.signal.reason), { once: true }); + }) + }); + exporter.record(base); + await exporter.close(); + expect(signal?.aborted).toBe(true); + expect(exporter.stats()).toEqual({ exported: 0, dropped: 0, failed: 1 }); +}); diff --git a/packages/runtime/src/otlp-span-exporter.ts b/packages/runtime/src/otlp-span-exporter.ts index 86a0edf05..c2feb73a5 100644 --- a/packages/runtime/src/otlp-span-exporter.ts +++ b/packages/runtime/src/otlp-span-exporter.ts @@ -1,16 +1,31 @@ +import { allowlistSpanAttributes } from "./span-attributes.js"; +export { allowlistSpanAttributes, SPAN_ATTRIBUTE_ALLOWLIST } from "./span-attributes.js"; + /** - * Optional OTLP/HTTP (JSON) export of API server spans and worker activity spans. Off unless - * SPACE_OTEL_EXPORTER_OTLP_ENDPOINT names a collector base URL (spans go to - * `/v1/traces`). No dependency, no collector required: Space logs stay - * joinable by W3C trace id without it. + * Optional OTLP/HTTP (JSON) export of API server spans and worker workflow and + * activity spans. Off unless SPACE_OTEL_EXPORTER_OTLP_ENDPOINT names a collector + * base URL (spans go to `/v1/traces`). No dependency, no collector + * required: Space logs stay joinable by W3C trace id without it. * - * Spans carry only the method, route template, status code, service name and + * API spans carry only the method, route template, status code, service name and * Space request id; never URLs with parameters, headers, bodies or user data. + * Worker spans pass their attributes through `allowlistSpanAttributes`: + * identifiers, types, attempts, outcomes, stable error codes and durations only. * Export is best effort: a bounded queue drops (and counts) spans instead of * growing, each POST has a timeout, and a failing collector never affects a * request. */ +/** OTLP span kind: INTERNAL 1, SERVER 2, CLIENT 3, PRODUCER 4, CONSUMER 5. */ +export type SpanKind = 1 | 2 | 3 | 4 | 5; + +/** A causal link to a span of another run or trace (continue-as-new, background continuation). */ +export interface SpanLink { + traceId: string; + spanId: string; + attributes?: Readonly>; +} + export interface ServerSpan { traceId: string; spanId: string; @@ -18,12 +33,16 @@ export interface ServerSpan { name: string; startTimeUnixNano: bigint; endTimeUnixNano: bigint; - attributes: Readonly>; + attributes: Readonly>; error: boolean; - /** OTLP span kind; SERVER (2) unless given. Worker activities use INTERNAL (1). */ - kind?: number; + /** OTLP span kind; SERVER (2) unless given. Worker workflows and activities use INTERNAL (1). */ + kind?: SpanKind; + /** Links to the run or trace this span continues; omitted from the request when empty. */ + links?: readonly SpanLink[]; } +export type ExportSpan = ServerSpan; + export interface SpanExporterStats { exported: number; dropped: number; @@ -66,28 +85,47 @@ export function otlpTracesUrl(value: string | undefined): string | null { return `${url.origin}${url.pathname.replace(/\/+$/, "")}/v1/traces`; } -function attributeValue(value: string | number) { +function attributeValue(value: string | number | boolean) { + if (typeof value === "boolean") return { boolValue: value }; return typeof value === "number" && Number.isInteger(value) ? { intValue: String(value) } : { stringValue: String(value) }; } +function encodeAttributes(attributes: Readonly>) { + return Object.entries(attributes).map(([key, value]) => ({ key, value: attributeValue(value) })); +} + +function encodeLinks(links: readonly SpanLink[] | undefined) { + return (links ?? []) + .filter(link => traceIdPattern.test(link.traceId) && !/^0+$/.test(link.traceId) && spanIdPattern.test(link.spanId) && !/^0+$/.test(link.spanId)) + .map(link => ({ + traceId: link.traceId, + spanId: link.spanId, + ...(Object.keys(allowlistSpanAttributes(link.attributes ?? {})).length ? { attributes: encodeAttributes(allowlistSpanAttributes(link.attributes ?? {})) } : {}) + })); +} + export function otlpTraceRequest(spans: readonly ServerSpan[], serviceName: string) { return { resourceSpans: [{ resource: { attributes: [{ key: "service.name", value: { stringValue: serviceName } }] }, scopeSpans: [{ scope: { name: serviceName }, - spans: spans.map(span => ({ - traceId: span.traceId, - spanId: span.spanId, - ...(span.parentSpanId ? { parentSpanId: span.parentSpanId } : {}), - name: span.name, - kind: span.kind ?? 2, - startTimeUnixNano: span.startTimeUnixNano.toString(), - endTimeUnixNano: span.endTimeUnixNano.toString(), - attributes: Object.entries(span.attributes).map(([key, value]) => ({ key, value: attributeValue(value) })), - // STATUS_CODE_ERROR or STATUS_CODE_UNSET - status: { code: span.error ? 2 : 0 } - })) + spans: spans.map(span => { + const links = encodeLinks(span.links); + return { + traceId: span.traceId, + spanId: span.spanId, + ...(span.parentSpanId ? { parentSpanId: span.parentSpanId } : {}), + name: span.name, + kind: span.kind ?? 2, + startTimeUnixNano: span.startTimeUnixNano.toString(), + endTimeUnixNano: span.endTimeUnixNano.toString(), + attributes: encodeAttributes(span.attributes), + ...(links.length ? { links } : {}), + // STATUS_CODE_ERROR or STATUS_CODE_UNSET + status: { code: span.error ? 2 : 0 } + }; + }) }] }] }; @@ -99,7 +137,7 @@ export function createOtlpSpanExporter(options: OtlpSpanExporterOptions): SpanEx const send: FetchLike = options.fetch ?? ((target, init) => fetch(target, init)); const batchSize = options.batchSize ?? 256; const maxQueue = options.maxQueue ?? 4096; - const timeoutMs = options.timeoutMs ?? 3000; + const timeoutMs = options.timeoutMs ?? 5000; const queue: ServerSpan[] = []; const stats: SpanExporterStats = { exported: 0, dropped: 0, failed: 0 }; let inFlight: Promise | null = null; @@ -121,15 +159,18 @@ export function createOtlpSpanExporter(options: OtlpSpanExporterOptions): SpanEx } }; const flush = (): Promise => { - if (!inFlight) { - inFlight = (async () => { - try { - while (queue.length) await flushOnce(); - } finally { - inFlight = null; - } - })(); - } + if (inFlight) return inFlight; + // With an empty queue the loop below would finish synchronously and clear + // inFlight before it is assigned, leaving a settled promise that blocks + // every later flush. + if (!queue.length) return Promise.resolve(); + inFlight = (async () => { + try { + while (queue.length) await flushOnce(); + } finally { + inFlight = null; + } + })(); return inFlight; }; const timer = setInterval(() => void flush(), options.flushIntervalMs ?? 5000); diff --git a/packages/runtime/src/span-attributes.ts b/packages/runtime/src/span-attributes.ts new file mode 100644 index 000000000..613e92e46 --- /dev/null +++ b/packages/runtime/src/span-attributes.ts @@ -0,0 +1,51 @@ +import { failureCategorySchema, isSafeErrorCode } from "@space/contracts"; + +/** Keys a worker span or link may carry. Everything else is dropped before export. */ +export const SPAN_ATTRIBUTE_ALLOWLIST: ReadonlySet = new Set([ + "space.trace_id", + "space.room_id", + "space.pane_id", + "space.mission_id", + "temporal.workflow.id", + "temporal.workflow.run_id", + "temporal.workflow.type", + "temporal.activity.type", + "temporal.activity.id", + "temporal.activity.attempt", + "space.outcome", + "error.code", + "space.error.category", + "space.duration_ms", + "space.queue_ms", + "space.link.kind" +]); + +// Same shape as the Temporal memo ids: no slashes, spaces, URLs or free text. +const identifierValuePattern = /^[A-Za-z0-9:._-]{1,200}$/; +const failureCategories: ReadonlySet = new Set(failureCategorySchema.options); + +/** + * Allowlisted, identifier-shaped attributes only. Unknown keys, free text, + * paths, URLs, non-finite numbers, unsafe error codes and unknown failure + * categories are dropped silently. + */ +export function allowlistSpanAttributes(input: Readonly>): Record { + const output: Record = {}; + for (const [key, value] of Object.entries(input)) { + if (!SPAN_ATTRIBUTE_ALLOWLIST.has(key)) continue; + if (key === "error.code") { + if (isSafeErrorCode(value)) output[key] = value; + } else if (key === "space.error.category") { + if (typeof value === "string" && failureCategories.has(value)) output[key] = value; + } else if (["temporal.activity.attempt", "space.duration_ms", "space.queue_ms"].includes(key)) { + if (typeof value === "number" && Number.isInteger(value) && value >= 0) output[key] = value; + } else if (key === "space.outcome") { + if (typeof value === "string" && ["COMPLETED", "FAILED_RESULT", "FAILED", "CANCELLED", "CONTINUED_AS_NEW"].includes(value)) output[key] = value; + } else if (key === "space.link.kind") { + if (value === "continue_as_new" || value === "background_continuation") output[key] = value; + } else if (typeof value === "string" && identifierValuePattern.test(value)) { + output[key] = value; + } + } + return output; +}