diff --git a/.changeset/bench-histogram-run-trace-links.md b/.changeset/bench-histogram-run-trace-links.md new file mode 100644 index 0000000000..94b370657f --- /dev/null +++ b/.changeset/bench-histogram-run-trace-links.md @@ -0,0 +1,4 @@ +--- +--- + +Log the run id of each sequential-steps benchmark iteration alongside two Datadog APM links — the trigger request's trace and a span search for the run — so a suspicious STSO distribution can be opened in APM directly instead of hunted down by deployment id and time window. diff --git a/packages/core/e2e/benchmark.test.ts b/packages/core/e2e/benchmark.test.ts index 312dae14b2..8baf436bb7 100644 --- a/packages/core/e2e/benchmark.test.ts +++ b/packages/core/e2e/benchmark.test.ts @@ -193,6 +193,9 @@ interface StreamIterationResult { interface SequentialIterationResult { runId: string; + /** Datadog trace id for the `/api/bench` request that started this run, when + * the deployment's route reports one (older deployments won't). */ + traceId?: string; /** STSO gaps preceding an 'inline' step (same warm process as the step * before it) — the framework's pure step-to-step overhead. */ stsoInlineMs: number[]; @@ -221,6 +224,8 @@ interface BenchTriggerResponse { runId: string; /** Date.now() stamped in the route immediately before start(). */ clientStart: number; + /** Datadog trace id for this request, when the route reports one. */ + traceId?: string; } function withTimeout( @@ -272,7 +277,13 @@ async function triggerBenchRun( `bench trigger for ${workflowFn} returned malformed body: ${JSON.stringify(data)?.slice(0, 200)}` ); } - return { runId: data.runId, clientStart: data.clientStart }; + return { + runId: data.runId, + clientStart: data.clientStart, + // Optional: a deployment built before the route reported it simply logs + // the run id without a trace link. + traceId: typeof data.traceId === 'string' ? data.traceId : undefined, + }; } /** Poll a run's return value to completion (the handle polls internally). */ @@ -340,7 +351,7 @@ async function runStreamIteration( async function runSequentialIteration( stepCount: number ): Promise { - const { runId, clientStart } = await triggerBenchRun( + const { runId, clientStart, traceId } = await triggerBenchRun( 'benchSequentialStepsWorkflow', [stepCount] ); @@ -366,6 +377,7 @@ async function runSequentialIteration( return { runId, + traceId, stsoInlineMs, stsoQueueHopMs, woMs: workflowOverheadMs(clientStart, steps), @@ -636,6 +648,29 @@ const SCENARIO_DESCRIPTIONS = [ }, ]; +// Datadog APM permalink for a trace id. The benchmark deployment exports its +// OTel spans to Datadog, and `/api/bench` returns the trace id of the request +// that started each run. +const DATADOG_TRACE_URL = 'https://app.datadoghq.com/apm/trace/'; + +/** + * Datadog APM search for the spans tagged with a given `workflow.run.id`. + * + * The permalink above opens the *trigger's* trace, which under the default + * `WORKFLOW_TRACE_MODE=linked` holds only `workflow.start` plus span links out + * to the per-invocation trace roots — an entry point to the run rather than the + * run itself. This search lands straight on the execution spans, which is where + * an STSO investigation actually goes, so both are logged. + * + * Depends on `workflow.run.id` being an indexed span tag in the Datadog org. If + * it isn't, this returns an empty search and the trace permalink stays the way + * in; neither link is load-bearing for the benchmark itself. + */ +function datadogRunSearchUrl(runId: string): string { + const query = encodeURIComponent(`@workflow.run.id:${runId}`); + return `https://app.datadoghq.com/apm/traces?query=${query}`; +} + describe('workflow benchmarks', () => { // Preflight: prove the deployment executes workflows (and the trigger route // works) before any scenario spends its attempt budget. Without this, a @@ -777,6 +812,19 @@ describe('workflow benchmarks', () => { extraAttempts: Math.max(2, Math.ceil(SEQUENTIAL_ITERATIONS * 0.5)), } ); + // Name the runs behind the STSO histograms in this job's own log, right + // where they were produced. When a bucket looks wrong the investigation + // starts in APM, and this saves the usual hunt by deployment id + time + // window. Logged rather than rendered into the PR comment so it is also + // there for a local `pnpm bench` and for a run whose comment step never + // gets to execute. + for (const { runId, traceId } of results) { + console.log( + `[bench] ${SCENARIO_SEQUENTIAL} run ${runId}` + + (traceId ? ` — trace ${DATADOG_TRACE_URL}${traceId}` : '') + + ` — spans ${datadogRunSearchUrl(runId)}` + ); + } // Report STSO split by whether the step that ends the gap was 'inline' // (same warm process as the step before it — pure framework overhead) or // a 'queue-hop' (first step of a fresh process — dispatch + reinit cost). diff --git a/workbench/nextjs-turbopack/app/api/bench/route.ts b/workbench/nextjs-turbopack/app/api/bench/route.ts index 8a6f91e83b..f6e5771c91 100644 --- a/workbench/nextjs-turbopack/app/api/bench/route.ts +++ b/workbench/nextjs-turbopack/app/api/bench/route.ts @@ -1,3 +1,4 @@ +import { trace } from '@opentelemetry/api'; import type { NextRequest } from 'next/server'; import { NextResponse } from 'next/server'; import { start } from 'workflow/api'; @@ -57,7 +58,19 @@ export async function POST(request: NextRequest) { const clientStart = Date.now(); // @ts-expect-error - arbitrary call to a dynamically resolved workflow const run = await start(fn, args); - return NextResponse.json({ runId: run.runId, clientStart }); + // Surface this request's trace id so the runner can log a benchmark run's + // Datadog trace next to its run id, instead of anyone having to hunt for it + // by deployment id / time window. The span is the one @vercel/otel opened + // for this route invocation (see instrumentation.ts). + // + // Under the default WORKFLOW_TRACE_MODE=linked -- which is what this + // deployment runs, since nothing sets the mode -- that trace is NOT the + // whole run: each workflow/step invocation is its own trace root, and this + // one holds the `workflow.start` span plus span links out to those roots. + // So it is an entry point to the run (one hop through the links, which + // Datadog renders), not a single trace containing every step's spans. + const traceId = trace.getActiveSpan()?.spanContext().traceId; + return NextResponse.json({ runId: run.runId, clientStart, traceId }); } catch (error) { return NextResponse.json( {