From 0287155aa9c7dd02da0e9fc52c5a16c9b594a201 Mon Sep 17 00:00:00 2001 From: "vercel[bot]" <35613825+vercel[bot]@users.noreply.github.com> Date: Thu, 13 Aug 2026 20:33:36 +0000 Subject: [PATCH] [core] Record step execution duration metric Co-Authored-By: Shalabh Chaturvedi <7066873+shalabhc@users.noreply.github.com> --- packages/core/src/runtime/step-executor.ts | 10 ++++++- packages/core/src/telemetry-metrics.test.ts | 30 +++++++++++++++++++++ packages/core/src/telemetry.ts | 25 +++++++++++++++++ 3 files changed, 64 insertions(+), 1 deletion(-) create mode 100644 packages/core/src/telemetry-metrics.test.ts diff --git a/packages/core/src/runtime/step-executor.ts b/packages/core/src/runtime/step-executor.ts index 390e315889..45b13f5a91 100644 --- a/packages/core/src/runtime/step-executor.ts +++ b/packages/core/src/runtime/step-executor.ts @@ -39,7 +39,7 @@ import { } from '../serialization.js'; import { contextStorage } from '../step/context-storage.js'; import * as Attribute from '../telemetry/semantic-conventions.js'; -import { trace } from '../telemetry.js'; +import { recordStepExecutionDuration, trace } from '../telemetry.js'; import { getErrorName, getErrorStack, @@ -967,6 +967,8 @@ export async function executeStep( span?.setAttributes(attributes); }; + let stepExecutionStatus: 'ok' | 'error' = 'ok'; + const stepExecutionStartTime = performance.now(); try { result = await trace('step.execute', {}, async () => { return await contextStorage.run( @@ -1006,8 +1008,14 @@ export async function executeStep( ); }); } catch (err) { + stepExecutionStatus = 'error'; userCodeError = err; userCodeFailed = true; + } finally { + void recordStepExecutionDuration( + performance.now() - stepExecutionStartTime, + stepExecutionStatus + ); } const executionTimeMs = Date.now() - executionStartTime; diff --git a/packages/core/src/telemetry-metrics.test.ts b/packages/core/src/telemetry-metrics.test.ts new file mode 100644 index 0000000000..be5cfdf2db --- /dev/null +++ b/packages/core/src/telemetry-metrics.test.ts @@ -0,0 +1,30 @@ +import { metrics as otelMetrics } from '@opentelemetry/api'; +import { afterAll, describe, expect, it, vi } from 'vitest'; +import { recordStepExecutionDuration } from './telemetry.js'; + +const histogram = { record: vi.fn() }; +const meter = { createHistogram: vi.fn(() => histogram) }; +const provider = { getMeter: vi.fn(() => meter) }; + +otelMetrics.setGlobalMeterProvider(provider as any); + +afterAll(() => { + otelMetrics.disable(); +}); + +describe('recordStepExecutionDuration', () => { + it('records a millisecond histogram with only a bounded status dimension', async () => { + await recordStepExecutionDuration(125, 'ok'); + + expect(meter.createHistogram).toHaveBeenCalledWith( + 'workflow.step.execute.duration', + { + description: 'Duration of user step execution', + unit: 'ms', + } + ); + expect(histogram.record).toHaveBeenCalledWith(125, { + 'workflow.step.status': 'ok', + }); + }); +}); diff --git a/packages/core/src/telemetry.ts b/packages/core/src/telemetry.ts index fd126abb3e..1ae00dc7e9 100644 --- a/packages/core/src/telemetry.ts +++ b/packages/core/src/telemetry.ts @@ -180,6 +180,18 @@ const Tracer = once(async () => { return tracer; }); +const StepExecutionDurationHistogram = once(async () => { + const otel = await OtelApi.value; + if (!otel) return null; + // service.name is a resource attribute, applied by the configured provider. + return otel.metrics + .getMeter('workflow') + .createHistogram('workflow.step.execute.duration', { + description: 'Duration of user step execution', + unit: 'ms', + }); +}); + /** * One-shot runtime diagnostic (DEBUG=workflow:* only), same shape as the one * world-vercel emits tagged `world-vercel`: prints how this module instance @@ -278,6 +290,19 @@ export async function recordElapsedSpan( tracer.startSpan(spanName, { ...opts, startTime: startEpochMs }).end(); } +/** + * Records the same user-code interval as the inner `step.execute` span. The + * configured OpenTelemetry meter provider attaches resource dimensions such as + * service.name, so this avoids accepting a caller-controlled service tag. + */ +export async function recordStepExecutionDuration( + durationMs: number, + status: 'ok' | 'error' +): Promise { + const histogram = await StepExecutionDurationHistogram.value; + histogram?.record(durationMs, { 'workflow.step.status': status }); +} + /** * Applies the workflow suspension algebraic effect to an active span. */