diff --git a/.github/workflows/codeql.yml b/.github/workflows/codeql.yml deleted file mode 100644 index 80d3671..0000000 --- a/.github/workflows/codeql.yml +++ /dev/null @@ -1,66 +0,0 @@ -# This workflow generates weekly CodeQL reports for this repo, a security requirements. -# The workflow is adapted from the following reference: https://github.com/Azure-Samples/azure-functions-python-stream-openai/pull/2/files -# Generic comments on how to modify these file are left intactfor future maintenance. - -name: "CodeQL" - -on: - push: - branches: [ "main" ] - pull_request: - branches: [ "main" ] - schedule: - - cron: '0 0 * * 1' # Weekly Monday run, needed for weekly reports - workflow_call: # allows to be invoked as part of a larger workflow - workflow_dispatch: # allows for the workflow to run manually see: https://docs.github.com/en/actions/using-workflows/manually-running-a-workflow - -jobs: - - analyze: - name: Analyze - runs-on: ubuntu-latest - permissions: - actions: read - contents: read - security-events: write - defaults: - run: - shell: bash - - strategy: - fail-fast: false - matrix: - language: ['typescript'] - # CodeQL supports [ 'cpp', 'csharp', 'go', 'java', 'javascript', 'python', 'ruby' ] - # Learn more about CodeQL language support at https://aka.ms/codeql-docs/language-support - - steps: - # Checkout must be first - - name: Checkout repository - uses: actions/checkout@v4 - - # Initializes the CodeQL tools for scanning. - - name: Initialize CodeQL - uses: github/codeql-action/init@v3 - with: - languages: ${{ matrix.language }} - # If you wish to specify custom queries, you can do so here or in a config file. - # By default, queries listed here will override any specified in a config file. - # Prefix the list here with "+" to use these queries and those in the config file. - - - # Details on CodeQL's query packs refer to : https://docs.github.com/en/code-security/code-scanning/automatically-scanning-your-code-for-vulnerabilities-and-errors/configuring-code-scanning#using-queries-in-ql-packs - # queries: security-extended,security-and-quality - - # Autobuild attempts to build any compiled languages (C/C++, C#, Go, or Java). - # If this step fails, then you should remove it and run the build manually (see below) - - name: Autobuild - uses: github/codeql-action/autobuild@v3 - - # Run CodeQL analysis - - name: Perform CodeQL Analysis - uses: github/codeql-action/analyze@v3 - with: - category: "/language:${{matrix.language}}" - - category: "/language:${{matrix.language}}" diff --git a/examples/azure-managed-dts.ts b/examples/azure-managed-dts.ts index 305b5fc..302991c 100644 --- a/examples/azure-managed-dts.ts +++ b/examples/azure-managed-dts.ts @@ -35,23 +35,23 @@ import { Task } from "../src/task/task"; // These values should be set as environment variables const endpoint = process.env.AZURE_DTS_ENDPOINT; const taskHubName = process.env.AZURE_DTS_TASKHUB; - const connectionString = process.env.AZURE_DTS_CONNECTION_STRING; + const connectionString = process.env.DURABLE_TASK_SCHEDULER_CONNECTION_STRING; // Validate configuration if (!connectionString && (!endpoint || !taskHubName)) { logger.error( - "Error: Either AZURE_DTS_CONNECTION_STRING or both AZURE_DTS_ENDPOINT and AZURE_DTS_TASKHUB must be set.", + "Error: Either DURABLE_TASK_SCHEDULER_CONNECTION_STRING or both AZURE_DTS_ENDPOINT and AZURE_DTS_TASKHUB must be set.", ); logger.info("\nUsage:"); logger.info(" Option 1: Create a .env file in the examples directory (recommended):"); logger.info( - " AZURE_DTS_CONNECTION_STRING=Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub", + " DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub", ); logger.info(" or"); logger.info(" AZURE_DTS_ENDPOINT=https://myservice.durabletask.io"); logger.info(" AZURE_DTS_TASKHUB=myTaskHub"); logger.info("\n Option 2: Set environment variables directly"); - logger.info(" export AZURE_DTS_CONNECTION_STRING=..."); + logger.info(" export DURABLE_TASK_SCHEDULER_CONNECTION_STRING=..."); process.exit(1); } diff --git a/examples/azure-managed/.env.emulator b/examples/azure-managed/.env.emulator new file mode 100644 index 0000000..979bcc9 --- /dev/null +++ b/examples/azure-managed/.env.emulator @@ -0,0 +1,8 @@ +# Configuration for running with the local DTS Emulator + Jaeger +# Copy this file to .env: cp .env.emulator .env + +# DTS Emulator connection string (no authentication required) +DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=http://localhost:8080;Authentication=None;TaskHub=default + +# OTLP endpoint for trace export (Jaeger's OTLP HTTP receiver) +OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318 diff --git a/examples/azure-managed/.env.example b/examples/azure-managed/.env.example index 78fe892..a9fd951 100644 --- a/examples/azure-managed/.env.example +++ b/examples/azure-managed/.env.example @@ -3,8 +3,8 @@ # Option 1: Using connection string (recommended) # Supported authentication types: DefaultAzure, ManagedIdentity, WorkloadIdentity, # Environment, AzureCli, AzurePowerShell, VisualStudioCode, InteractiveBrowser, None -AZURE_DTS_CONNECTION_STRING=Endpoint=https://your-scheduler.eastus.durabletask.io;Authentication=DefaultAzure;TaskHub=your-taskhub +DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=https://your-scheduler.eastus.durabletask.io;Authentication=DefaultAzure;TaskHub=your-taskhub # Option 2: Using explicit parameters (uses DefaultAzureCredential) -# Uncomment these lines and comment out AZURE_DTS_CONNECTION_STRING above +# Uncomment these lines and comment out DURABLE_TASK_SCHEDULER_CONNECTION_STRING above # AZURE_DTS_ENDPOINT=https://your-scheduler.eastus.durabletask.io # AZURE_DTS_TASKHUB=your-taskhub \ No newline at end of file diff --git a/examples/azure-managed/README.md b/examples/azure-managed/README.md new file mode 100644 index 0000000..4045a13 --- /dev/null +++ b/examples/azure-managed/README.md @@ -0,0 +1,252 @@ +# Distributed Tracing with Azure Managed Durable Task Scheduler + +This example demonstrates **OpenTelemetry distributed tracing** with the Durable Task JavaScript SDK and Azure Managed Durable Task Scheduler (DTS). Traces are exported to [Jaeger](https://www.jaegertracing.io/) so you can visualize the full orchestration lifecycle as connected spans. + +## What You'll See + +When you run this example, the SDK automatically produces [W3C Trace Context](https://www.w3.org/TR/trace-context/) spans for every stage of a durable orchestration: + +| Span | Kind | Description | +|------|------|-------------| +| `create_orchestration:` | PRODUCER | Client scheduling a new orchestration | +| `orchestration:` | SERVER | Worker executing the orchestration | +| `activity:` (scheduling) | CLIENT | Orchestrator scheduling an activity | +| `activity:` (execution) | SERVER | Worker executing the activity | +| `timer:` | INTERNAL | Timer created inside an orchestration | +| `orchestration_event:` | PRODUCER | Event raised to another orchestration | + +All spans are linked via `traceparent` propagation, giving you a single end-to-end trace from the client all the way through parallel activity fan-out and back. + +### Sample Trace in Jaeger + +``` +create_orchestration:dataPipelineOrchestrator (PRODUCER) + └─ orchestration:dataPipelineOrchestrator (SERVER) + ├─ activity:getDataSources (CLIENT → SERVER) + ├─ activity:fetchData ×4 (CLIENT → SERVER, parallel) + ├─ activity:transformData ×4 (CLIENT → SERVER, parallel) + └─ activity:saveResults (CLIENT → SERVER) +``` + +--- + +## Prerequisites + +- **Node.js ≥ 22** (required by the monorepo) +- **Docker** (for the DTS Emulator and Jaeger) +- **npm** (for installing dependencies) + +--- + +## Quick Start (Local with DTS Emulator) + +### 1. Start the DTS Emulator and Jaeger + +A `docker-compose.yml` is provided that starts both services: + +```bash +cd examples/azure-managed +docker compose up -d +``` + +This starts: + +| Service | Port | Purpose | +|---------|------|---------| +| **DTS Emulator** | `8080` | Local gRPC endpoint (no authentication) | +| **Jaeger UI** | `16686` | Trace visualization dashboard | +| **Jaeger OTLP (HTTP)** | `4318` | OpenTelemetry trace receiver | +| **Jaeger OTLP (gRPC)** | `4317` | OpenTelemetry trace receiver (gRPC) | + +> **Tip:** You can also run just the DTS Emulator standalone: +> ```bash +> docker run -d --name dts-emulator -p 8080:8080 -p 8082:8082 \ +> mcr.microsoft.com/dts/dts-emulator:latest +> ``` + +### 2. Configure Environment Variables + +Copy the provided emulator configuration: + +```bash +cp .env.emulator .env +``` + +This sets: + +```env +DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=http://localhost:8080;Authentication=None;TaskHub=default +OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318 +``` + +### 3. Install OpenTelemetry Dependencies + +From the **repository root**, install the required OTel packages: + +```bash +npm install --no-save \ + @opentelemetry/api \ + @opentelemetry/sdk-node \ + @opentelemetry/sdk-trace-base \ + @opentelemetry/exporter-trace-otlp-http \ + @opentelemetry/resources \ + @opentelemetry/semantic-conventions +``` + +> **Note:** `@opentelemetry/api` is an optional peer dependency of `@microsoft/durabletask-js`. When it's installed, the SDK automatically produces distributed tracing spans — no code changes needed in your orchestrations or activities. + +### 4. Build the SDK (if not already built) + +```bash +npm run build +``` + +### 5. Run the Example + +```bash +npm run example -- ./examples/azure-managed/distributed-tracing.ts +``` + +You should see output like: + +``` +OpenTelemetry SDK started – exporting traces to http://localhost:4318 + +=== Sequence Orchestration === +Scheduled: abc123 +Completed – result: ["Hello, Tokyo!","Hello, Seattle!","Hello, London!"] + +=== Data Pipeline Orchestration === +Scheduled: def456 +Completed – result: {"sourcesProcessed":4,"resultsSaved":4,"data":["transformed(data-from-users-api)",...]} + +=== All orchestrations completed! === +Open Jaeger UI at http://localhost:16686 and search for service "durabletask-js-tracing-example" to view traces. +``` + +### 6. View Traces in Jaeger + +1. Open [http://localhost:16686](http://localhost:16686) in your browser. +2. Select the service **`durabletask-js-tracing-example`** from the dropdown. +3. Click **Find Traces**. +4. Click on a trace to explore the span waterfall. + +--- + +## Running Against Azure Managed DTS (Cloud) + +To run this example against a real Azure Managed Durable Task Scheduler endpoint instead of the local emulator: + +### 1. Create a `.env` file + +```env +# Option A: Connection string +DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=https://your-scheduler.eastus.durabletask.io;Authentication=DefaultAzure;TaskHub=your-taskhub + +# Option B: Explicit parameters (uses DefaultAzureCredential) +# AZURE_DTS_ENDPOINT=https://your-scheduler.eastus.durabletask.io +# AZURE_DTS_TASKHUB=your-taskhub + +# OTLP endpoint (Jaeger, Azure Monitor, Aspire Dashboard, etc.) +OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318 +``` + +### 2. Authenticate + +Make sure you're logged in via Azure CLI: + +```bash +az login +``` + +### 3. Run + +```bash +npm run example -- ./examples/azure-managed/distributed-tracing.ts +``` + +--- + +## Using Azure Monitor / Application Insights + +To export traces to **Azure Monitor** instead of Jaeger, replace the OTLP exporter with the Azure Monitor exporter: + +```bash +npm install --no-save @azure/monitor-opentelemetry-exporter +``` + +Then modify the OpenTelemetry setup in `distributed-tracing.ts`: + +```typescript +import { AzureMonitorTraceExporter } from "@azure/monitor-opentelemetry-exporter"; + +const traceExporter = new AzureMonitorTraceExporter({ + connectionString: process.env.APPLICATIONINSIGHTS_CONNECTION_STRING, +}); +``` + +--- + +## DTS Emulator Docker Image Reference + +| Property | Value | +|----------|-------| +| **Image** | `should be mcr.microsoft.com/dts/dts-emulator:latest` | +| **gRPC Port** | `8080` | +| **Dashboard Port** | `8082` | +| **Authentication** | `None` (no credentials required) | +| **Connection String** | `Endpoint=http://localhost:8080;Authentication=None;TaskHub=default` | + +### Running the Emulator Standalone + +```bash +docker run -d \ + --name dts-emulator \ + -p 8080:8080 \ + -p 8082:8082 \ + should be mcr.microsoft.com/dts/dts-emulator:latest +``` + +### Stopping the Emulator + +```bash +docker stop dts-emulator && docker rm dts-emulator +``` + +--- + +## How Distributed Tracing Works + +The Durable Task JavaScript SDK uses OpenTelemetry as an **optional peer dependency**. When `@opentelemetry/api` is installed and a `TracerProvider` is registered, the SDK automatically: + +1. **Creates spans** for orchestration scheduling, execution, activity scheduling/execution, timers, and events. +2. **Propagates W3C `traceparent`** through the gRPC protocol so that spans from the client, orchestrator, and activities are all linked in a single trace. +3. **Handles replay correctly** – on orchestration replay, the SDK carries forward the original span ID so all replay iterations correlate to the same logical orchestration execution. + +The tracer is registered under the name **`Microsoft.DurableTask`**, and spans include semantic attributes like: + +- `durabletask.type` – `orchestration`, `activity`, `timer`, `event`, etc. +- `durabletask.task.name` – The function name. +- `durabletask.task.instance_id` – The orchestration instance ID. +- `durabletask.task.task_id` – The sequential task ID within an orchestration. + +--- + +## Cleanup + +```bash +cd examples/azure-managed +docker compose down +``` + +--- + +## Files in This Example + +| File | Description | +|------|-------------| +| `distributed-tracing.ts` | Main example – OTel setup + orchestrations | +| `docker-compose.yml` | DTS Emulator + Jaeger stack | +| `.env.emulator` | Pre-configured env vars for the local emulator | +| `.env.example` | Template for Azure Managed DTS (cloud) | +| `index.ts` | Basic example (no tracing) | diff --git a/examples/azure-managed/distributed-tracing.ts b/examples/azure-managed/distributed-tracing.ts new file mode 100644 index 0000000..dd3f76f --- /dev/null +++ b/examples/azure-managed/distributed-tracing.ts @@ -0,0 +1,246 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +// This sample demonstrates how to enable OpenTelemetry distributed tracing with +// the Azure Managed Durable Task Scheduler (DTS). Traces are exported to a local +// Jaeger or OTLP-compatible collector so you can visualize the full orchestration +// lifecycle – scheduling, orchestrator execution, activity execution, sub-orchestrations, +// timers, and more – as linked spans in a single trace. + +// -------------------------------------------------------------------------- +// 1. OpenTelemetry SDK bootstrap – MUST run before any other imports so the +// global TracerProvider is registered before the Durable Task SDK loads. +// -------------------------------------------------------------------------- +import { NodeSDK } from "@opentelemetry/sdk-node"; +import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http"; +import { SimpleSpanProcessor } from "@opentelemetry/sdk-trace-base"; +import { resourceFromAttributes } from "@opentelemetry/resources"; +import { ATTR_SERVICE_NAME } from "@opentelemetry/semantic-conventions"; + +// Load environment variables from .env file +import * as dotenv from "dotenv"; +import * as path from "path"; +dotenv.config({ path: path.join(__dirname, ".env") }); + +// Read the OTLP endpoint from the environment (defaults to Jaeger's OTLP HTTP port) +const otlpEndpoint = process.env.OTEL_EXPORTER_OTLP_ENDPOINT || "http://localhost:4318"; + +const traceExporter = new OTLPTraceExporter({ + url: `${otlpEndpoint}/v1/traces`, +}); + +const sdk = new NodeSDK({ + resource: resourceFromAttributes({ + [ATTR_SERVICE_NAME]: "durabletask-js-tracing-example", + }), + spanProcessors: [new SimpleSpanProcessor(traceExporter)], +}); + +sdk.start(); +console.log(`OpenTelemetry SDK started – exporting traces to ${otlpEndpoint}`); + +// -------------------------------------------------------------------------- +// 2. Durable Task imports (after OTel is initialised) +// -------------------------------------------------------------------------- +import { + DurableTaskAzureManagedClientBuilder, + DurableTaskAzureManagedWorkerBuilder, +} from "@microsoft/durabletask-js-azuremanaged"; +import { ConsoleLogger } from "@microsoft/durabletask-js"; +import { ActivityContext } from "@microsoft/durabletask-js/dist/task/context/activity-context"; +import { OrchestrationContext } from "@microsoft/durabletask-js/dist/task/context/orchestration-context"; +import { TOrchestrator } from "@microsoft/durabletask-js/dist/types/orchestrator.type"; +import { whenAll } from "@microsoft/durabletask-js/dist/task"; + +// -------------------------------------------------------------------------- +// 3. Application code +// -------------------------------------------------------------------------- +(async () => { + // Use ConsoleLogger so structured log events (with event IDs and categories) are + // printed to the console by default, similar to .NET's default ILogger output. + // For production, consider using createAzureLogger() which integrates with @azure/logger + // and respects the AZURE_LOG_LEVEL environment variable. + const sdkLogger = new ConsoleLogger(); + + // --- Configuration --- + const connectionString = process.env.DURABLE_TASK_SCHEDULER_CONNECTION_STRING; + const endpoint = process.env.AZURE_DTS_ENDPOINT; + const taskHubName = process.env.AZURE_DTS_TASKHUB; + + if (!connectionString && (!endpoint || !taskHubName)) { + console.error( + "Error: Either DURABLE_TASK_SCHEDULER_CONNECTION_STRING or both AZURE_DTS_ENDPOINT and AZURE_DTS_TASKHUB must be set.", + ); + console.log("\nFor the DTS emulator, set:"); + console.log( + ' DURABLE_TASK_SCHEDULER_CONNECTION_STRING="Endpoint=http://localhost:8080;Authentication=None;TaskHub=default"', + ); + process.exit(1); + } + + // --- Activity definitions --- + + /** Simulates fetching data from an external service. */ + const fetchData = async (_ctx: ActivityContext, source: string): Promise => { + console.log(` [fetchData] Fetching data from "${source}"...`); + // Simulate network latency + await new Promise((r) => setTimeout(r, 300 + Math.random() * 200)); + return `data-from-${source}`; + }; + + /** Simulates transforming a piece of data. */ + const transformData = async (_ctx: ActivityContext, input: string): Promise => { + console.log(` [transformData] Transforming "${input}"...`); + await new Promise((r) => setTimeout(r, 200)); + return `transformed(${input})`; + }; + + /** Simulates persisting results to a database. */ + const saveResults = async (_ctx: ActivityContext, results: string[]): Promise => { + console.log(` [saveResults] Saving ${results.length} results...`); + await new Promise((r) => setTimeout(r, 150)); + return results.length; + }; + + // --- Orchestrator: data pipeline (chaining + fan-out/fan-in) --- + + /** + * Demonstrates a realistic data-processing pipeline that produces a rich + * distributed trace: + * + * 1. Fan-out – fetch data from multiple sources in parallel. + * 2. Fan-out – transform each result in parallel. + * 3. Chain – save all transformed results. + * + * The resulting trace will show: + * create_orchestration → orchestration (server) + * ├─ activity:fetchData (×N, parallel) + * ├─ activity:transformData (×N, parallel) + * └─ activity:saveResults + */ + const dataPipelineOrchestrator: TOrchestrator = async function* ( + ctx: OrchestrationContext, + ): any { + const sources: string[] = yield ctx.callActivity(getDataSources); + + // Step 1 – fan-out: fetch from all sources in parallel + const fetchTasks = []; + for (const source of sources) { + fetchTasks.push(ctx.callActivity(fetchData, source)); + } + const rawData: string[] = yield whenAll(fetchTasks); + + // Step 2 – fan-out: transform all fetched data in parallel + const transformTasks = []; + for (const raw of rawData) { + transformTasks.push(ctx.callActivity(transformData, raw)); + } + const transformed: string[] = yield whenAll(transformTasks); + + // Step 3 – chain: save all results + const savedCount: number = yield ctx.callActivity(saveResults, transformed); + + return { + sourcesProcessed: sources.length, + resultsSaved: savedCount, + data: transformed, + }; + }; + + /** Returns the list of data sources to process. */ + const getDataSources = async (_ctx: ActivityContext): Promise => { + return ["users-api", "orders-api", "inventory-api", "analytics-api"]; + }; + + // --- Orchestrator: simple sequence (for a cleaner trace comparison) --- + + const sequenceOrchestrator: TOrchestrator = async function* ( + ctx: OrchestrationContext, + ): any { + const cities = ["Tokyo", "Seattle", "London"]; + const greetings: string[] = []; + for (const city of cities) { + const greeting: string = yield ctx.callActivity(greetCity, city); + greetings.push(greeting); + } + return greetings; + }; + + const greetCity = async (_ctx: ActivityContext, city: string): Promise => { + console.log(` [greetCity] Greeting ${city}`); + await new Promise((r) => setTimeout(r, 100)); + return `Hello, ${city}!`; + }; + + // --- Create client & worker --- + + let client; + let worker; + + try { + const clientBuilder = new DurableTaskAzureManagedClientBuilder().logger(sdkLogger); + const workerBuilder = new DurableTaskAzureManagedWorkerBuilder().logger(sdkLogger); + + if (connectionString) { + clientBuilder.connectionString(connectionString); + workerBuilder.connectionString(connectionString); + } else { + const { DefaultAzureCredential } = await import("@azure/identity"); + const credential = new DefaultAzureCredential(); + clientBuilder.endpoint(endpoint!, taskHubName!, credential); + workerBuilder.endpoint(endpoint!, taskHubName!, credential); + } + + client = clientBuilder.build(); + worker = workerBuilder + .addOrchestrator(dataPipelineOrchestrator) + .addOrchestrator(sequenceOrchestrator) + .addActivity(fetchData) + .addActivity(transformData) + .addActivity(saveResults) + .addActivity(getDataSources) + .addActivity(greetCity) + .build(); + + // --- Start worker --- + console.log("Starting worker..."); + await worker.start(); + // Allow the worker time to establish the gRPC stream with the scheduler. + // worker.start() returns before the connection is fully established. + await new Promise((r) => setTimeout(r, 2000)); + console.log("Worker started."); + + // --- Run orchestrations --- + + // 1) Sequence orchestration + console.log("\n=== Sequence Orchestration ==="); + const seqId = await client.scheduleNewOrchestration(sequenceOrchestrator); + console.log(`Scheduled: ${seqId}`); + const seqState = await client.waitForOrchestrationCompletion(seqId, true, 60); + console.log(`Completed – result: ${seqState?.serializedOutput}`); + + // 2) Data pipeline orchestration (fan-out/fan-in) + console.log("\n=== Data Pipeline Orchestration ==="); + const pipelineId = await client.scheduleNewOrchestration(dataPipelineOrchestrator); + console.log(`Scheduled: ${pipelineId}`); + const pipelineState = await client.waitForOrchestrationCompletion(pipelineId, true, 60); + console.log(`Completed – result: ${pipelineState?.serializedOutput}`); + + console.log("\n=== All orchestrations completed! ==="); + console.log( + `Open Jaeger UI at http://localhost:16686 and search for service "durabletask-js-tracing-example" to view traces.`, + ); + } catch (error) { + console.error("Error:", error); + process.exit(1); + } finally { + console.log("\nShutting down..."); + if (worker) await worker.stop(); + if (client) await client.stop(); + + // Flush remaining spans before exit + await sdk.shutdown(); + console.log("Done."); + process.exit(0); + } +})(); diff --git a/examples/azure-managed/docker-compose.yml b/examples/azure-managed/docker-compose.yml new file mode 100644 index 0000000..8627ac1 --- /dev/null +++ b/examples/azure-managed/docker-compose.yml @@ -0,0 +1,39 @@ +version: "3.8" + +# Docker Compose stack for running the distributed tracing example locally. +# Starts the DTS Emulator (Durable Task Scheduler) and Jaeger (trace collector + UI). +# +# Usage: +# docker compose up -d +# # Run the example ... +# docker compose down + +services: + # --------------------------------------------------------------------------- + # Durable Task Scheduler (DTS) Emulator + # Provides a local gRPC endpoint compatible with Azure Managed DTS. + # No Azure subscription required – perfect for development and testing. + # --------------------------------------------------------------------------- + dts-emulator: + image: mcr.microsoft.com/dts/dts-emulator:latest + container_name: dts-emulator + ports: + - "8080:8080" # gRPC endpoint + - "8082:8082" # HTTP dashboard (if available) + environment: + - ASPNETCORE_URLS=http://+:8080;http://+:8082 + + # --------------------------------------------------------------------------- + # Jaeger – distributed tracing backend & UI + # Receives traces via OTLP (HTTP on 4318, gRPC on 4317) and exposes a web UI + # on port 16686 for exploring traces. + # --------------------------------------------------------------------------- + jaeger: + image: jaegertracing/jaeger:latest + container_name: jaeger + ports: + - "4317:4317" # OTLP gRPC receiver + - "4318:4318" # OTLP HTTP receiver (used by this example) + - "16686:16686" # Jaeger UI + environment: + - COLLECTOR_OTLP_ENABLED=true diff --git a/examples/azure-managed/index.ts b/examples/azure-managed/index.ts index abd19d5..8bebec5 100644 --- a/examples/azure-managed/index.ts +++ b/examples/azure-managed/index.ts @@ -23,7 +23,6 @@ import { ActivityContext } from "@microsoft/durabletask-js/dist/task/context/act import { OrchestrationContext } from "@microsoft/durabletask-js/dist/task/context/orchestration-context"; import { TOrchestrator } from "@microsoft/durabletask-js/dist/types/orchestrator.type"; import { whenAll } from "@microsoft/durabletask-js/dist/task"; -import { Task } from "@microsoft/durabletask-js/dist/task/task"; // Wrap the entire code in an immediately-invoked async function (async () => { @@ -35,23 +34,23 @@ import { Task } from "@microsoft/durabletask-js/dist/task/task"; // These values should be set as environment variables const endpoint = process.env.AZURE_DTS_ENDPOINT; const taskHubName = process.env.AZURE_DTS_TASKHUB; - const connectionString = process.env.AZURE_DTS_CONNECTION_STRING; + const connectionString = process.env.DURABLE_TASK_SCHEDULER_CONNECTION_STRING; // Validate configuration if (!connectionString && (!endpoint || !taskHubName)) { logger.error( - "Error: Either AZURE_DTS_CONNECTION_STRING or both AZURE_DTS_ENDPOINT and AZURE_DTS_TASKHUB must be set.", + "Error: Either DURABLE_TASK_SCHEDULER_CONNECTION_STRING or both AZURE_DTS_ENDPOINT and AZURE_DTS_TASKHUB must be set.", ); logger.info("\nUsage:"); logger.info(" Option 1: Create a .env file in the examples directory (recommended):"); logger.info( - " AZURE_DTS_CONNECTION_STRING=Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub", + " DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub", ); logger.info(" or"); logger.info(" AZURE_DTS_ENDPOINT=https://myservice.durabletask.io"); logger.info(" AZURE_DTS_TASKHUB=myTaskHub"); logger.info("\n Option 2: Set environment variables directly"); - logger.info(" export AZURE_DTS_CONNECTION_STRING=..."); + logger.info(" export DURABLE_TASK_SCHEDULER_CONNECTION_STRING=..."); process.exit(1); } @@ -87,7 +86,7 @@ import { Task } from "@microsoft/durabletask-js/dist/task/task"; const workItems = ["item-1", "item-2", "item-3", "item-4", "item-5"]; // Fan-out: schedule all activities in parallel - const tasks: Task[] = []; + const tasks = []; for (const item of workItems) { tasks.push(ctx.callActivity(processWorkItem, item)); } @@ -129,6 +128,9 @@ import { Task } from "@microsoft/durabletask-js/dist/task/task"; // Start the worker logger.info("Starting worker..."); await worker.start(); + // Allow the worker time to establish the gRPC stream with the scheduler. + // worker.start() returns before the connection is fully established. + await new Promise((resolve) => setTimeout(resolve, 2000)); logger.info("Worker started successfully!"); // Run the sequence orchestrator @@ -136,7 +138,7 @@ import { Task } from "@microsoft/durabletask-js/dist/task/task"; const sequenceId = await client.scheduleNewOrchestration(sequenceOrchestrator); logger.info(`Orchestration scheduled with ID: ${sequenceId}`); - const sequenceState = await client.waitForOrchestrationCompletion(sequenceId, undefined, 60); + const sequenceState = await client.waitForOrchestrationCompletion(sequenceId, true, 60); logger.info(`Sequence orchestration completed!`); logger.info(`Result: ${sequenceState?.serializedOutput}`); @@ -145,7 +147,7 @@ import { Task } from "@microsoft/durabletask-js/dist/task/task"; const fanOutId = await client.scheduleNewOrchestration(fanOutFanInOrchestrator); logger.info(`Orchestration scheduled with ID: ${fanOutId}`); - const fanOutState = await client.waitForOrchestrationCompletion(fanOutId, undefined, 60); + const fanOutState = await client.waitForOrchestrationCompletion(fanOutId, true, 60); logger.info(`Fan-out/fan-in orchestration completed!`); logger.info(`Result: ${fanOutState?.serializedOutput}`); diff --git a/examples/hello-world/README.md b/examples/hello-world/README.md index 4b8d04a..e2f0f9f 100644 --- a/examples/hello-world/README.md +++ b/examples/hello-world/README.md @@ -47,7 +47,7 @@ Create a `.env` file in the `examples` directory with your configuration: ```env # Using connection string -AZURE_DTS_CONNECTION_STRING=Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub +DURABLE_TASK_SCHEDULER_CONNECTION_STRING=Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub # Or using explicit parameters (uses DefaultAzureCredential) # AZURE_DTS_ENDPOINT=https://myservice.durabletask.io @@ -65,7 +65,7 @@ npm run example ./examples/azure-managed-dts.ts ### Option 2: Using environment variables directly ```sh -export AZURE_DTS_CONNECTION_STRING="Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub" +export DURABLE_TASK_SCHEDULER_CONNECTION_STRING="Endpoint=https://myservice.durabletask.io;Authentication=DefaultAzure;TaskHub=myTaskHub" npm run example ./examples/azure-managed-dts.ts ``` diff --git a/package-lock.json b/package-lock.json index 16ba5eb..3007de4 100644 --- a/package-lock.json +++ b/package-lock.json @@ -16,7 +16,7 @@ "@swc/core": "^1.3.55", "@swc/helpers": "^0.5.1", "@types/jest": "^29.5.1", - "@types/node": "^18.16.1", + "@types/node": "^22.0.0", "dotenv": "^17.2.3", "eslint": "^9.39.2", "globals": "^16.2.0", @@ -226,7 +226,6 @@ "integrity": "sha512-H3mcG6ZDLTlYfaSNi0iOKkigqMFvkTKlGUYlD8GW7nNOYRrevuA46iTypPyv+06V3fEmvvazfntkBU34L0azAw==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@babel/code-frame": "^7.28.6", "@babel/generator": "^7.28.6", @@ -898,7 +897,6 @@ "resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.14.3.tgz", "integrity": "sha512-Iq8QQQ/7X3Sac15oB6p0FmUg/klxQvXLeileoqrTRGJYLV+/9tubbr9ipz0GKHjmXVsgFPo/+W+2cA8eNcR+XA==", "license": "Apache-2.0", - "peer": true, "dependencies": { "@grpc/proto-loader": "^0.8.0", "@js-sdsl/ordered-map": "^4.4.2" @@ -1489,6 +1487,77 @@ "resolved": "packages/durabletask-js-azuremanaged", "link": true }, + "node_modules/@opentelemetry/api": { + "version": "1.9.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/api/-/api-1.9.0.tgz", + "integrity": "sha512-3giAOQvZiH5F9bMlMiv8+GSPMeqg0dbaeo58/0SlA9sxSqZhnUtxzX9/2FzyhS9sWQf5S0GJE0AKBrFqjpeYcg==", + "dev": true, + "license": "Apache-2.0", + "engines": { + "node": ">=8.0.0" + } + }, + "node_modules/@opentelemetry/core": { + "version": "1.30.1", + "resolved": "https://registry.npmjs.org/@opentelemetry/core/-/core-1.30.1.tgz", + "integrity": "sha512-OOCM2C/QIURhJMuKaekP3TRBxBKxG/TWWA0TL2J6nXUtDnuCtccy49LUJF8xPFXMX+0LMcxFpCo8M9cGY1W6rQ==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/semantic-conventions": "1.28.0" + }, + "engines": { + "node": ">=14" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.0.0 <1.10.0" + } + }, + "node_modules/@opentelemetry/resources": { + "version": "1.30.1", + "resolved": "https://registry.npmjs.org/@opentelemetry/resources/-/resources-1.30.1.tgz", + "integrity": "sha512-5UxZqiAgLYGFjS4s9qm5mBVo433u+dSPUFWVWXmLAD4wB65oMCoXaJP1KJa9DIYYMeHu3z4BZcStG3LC593cWA==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/core": "1.30.1", + "@opentelemetry/semantic-conventions": "1.28.0" + }, + "engines": { + "node": ">=14" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.0.0 <1.10.0" + } + }, + "node_modules/@opentelemetry/sdk-trace-base": { + "version": "1.30.1", + "resolved": "https://registry.npmjs.org/@opentelemetry/sdk-trace-base/-/sdk-trace-base-1.30.1.tgz", + "integrity": "sha512-jVPgBbH1gCy2Lb7X0AVQ8XAfgg0pJ4nvl8/IiQA6nxOsPvS+0zMJaFSs2ltXe0J6C8dqjcnpyqINDJmU30+uOg==", + "dev": true, + "license": "Apache-2.0", + "dependencies": { + "@opentelemetry/core": "1.30.1", + "@opentelemetry/resources": "1.30.1", + "@opentelemetry/semantic-conventions": "1.28.0" + }, + "engines": { + "node": ">=14" + }, + "peerDependencies": { + "@opentelemetry/api": ">=1.0.0 <1.10.0" + } + }, + "node_modules/@opentelemetry/semantic-conventions": { + "version": "1.28.0", + "resolved": "https://registry.npmjs.org/@opentelemetry/semantic-conventions/-/semantic-conventions-1.28.0.tgz", + "integrity": "sha512-lp4qAiMTD4sNWW4DbKLBkfiMZ4jbAboJIGOQr5DvciMRI494OapieI9qiODpOt0XBr1LjIDy1xAGAnVs5supTA==", + "dev": true, + "license": "Apache-2.0", + "engines": { + "node": ">=14" + } + }, "node_modules/@pkgr/core": { "version": "0.2.9", "resolved": "https://registry.npmjs.org/@pkgr/core/-/core-0.2.9.tgz", @@ -1600,7 +1669,6 @@ "dev": true, "hasInstallScript": true, "license": "Apache-2.0", - "peer": true, "dependencies": { "@swc/counter": "^0.1.3", "@swc/types": "^0.1.25" @@ -1816,7 +1884,6 @@ "integrity": "sha512-TXTnIcNJQEKwThMMqBXsZ4VGAza6bvN4pa41Rkqoio6QBKMvo+5lexeTMScGCIxtzgQJzElcvIltani+adC5PQ==", "dev": true, "license": "Apache-2.0", - "peer": true, "dependencies": { "tslib": "^2.8.0" } @@ -1974,13 +2041,12 @@ "license": "MIT" }, "node_modules/@types/node": { - "version": "18.19.130", - "resolved": "https://registry.npmjs.org/@types/node/-/node-18.19.130.tgz", - "integrity": "sha512-GRaXQx6jGfL8sKfaIDD6OupbIHBr9jv7Jnaml9tB7l4v068PAOXqfcujMMo5PhbIs6ggR1XODELqahT2R8v0fg==", + "version": "22.19.9", + "resolved": "https://registry.npmjs.org/@types/node/-/node-22.19.9.tgz", + "integrity": "sha512-PD03/U8g1F9T9MI+1OBisaIARhSzeidsUjQaf51fOxrfjeiKN9bLVO06lHuHYjxdnqLWJijJHfqXPSJri2EM2A==", "license": "MIT", - "peer": true, "dependencies": { - "undici-types": "~5.26.4" + "undici-types": "~6.21.0" } }, "node_modules/@types/stack-utils": { @@ -2052,7 +2118,6 @@ "integrity": "sha512-BtE0k6cjwjLZoZixN0t5AKP0kSzlGu7FctRXYuPAm//aaiZhmfq1JwdYpYr1brzEspYyFeF+8XF5j2VK6oalrA==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@typescript-eslint/scope-manager": "8.54.0", "@typescript-eslint/types": "8.54.0", @@ -2294,7 +2359,6 @@ "integrity": "sha512-NZyJarBfL7nWwIq+FDL6Zp/yHEhePMNnnJ0y3qfieCrmNvYct8uvtiV41UvlSe6apAfk0fY1FbWx+NwfmpvtTg==", "dev": true, "license": "MIT", - "peer": true, "bin": { "acorn": "bin/acorn" }, @@ -2619,7 +2683,6 @@ } ], "license": "MIT", - "peer": true, "dependencies": { "baseline-browser-mapping": "^2.9.0", "caniuse-lite": "^1.0.30001759", @@ -3267,7 +3330,6 @@ "integrity": "sha512-LEyamqS7W5HB3ujJyvi0HQK/dtVINZvd5mAAp9eT5S/ujByGjiZLCzPcHVzuXbpJDJF/cxwHlfceVUDZ2lnSTw==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@eslint-community/eslint-utils": "^4.8.0", "@eslint-community/regexpp": "^4.12.1", @@ -4183,7 +4245,6 @@ "integrity": "sha512-NIy3oAFp9shda19hy4HK0HRTWKtPJmGdnvywu01nOqNC2vZg+Z+fvJDxpMQA88eb2I9EcafcdjYgsDthnYTvGw==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@jest/core": "^29.7.0", "@jest/types": "^29.6.3", @@ -5930,7 +5991,6 @@ "integrity": "sha512-UOnG6LftzbdaHZcKoPFtOcCKztrQ57WkHDeRD9t/PTQtmT0NHSeWWepj6pS0z/N7+08BHFDQVUrfmfMRcZwbMg==", "dev": true, "license": "MIT", - "peer": true, "bin": { "prettier": "bin/prettier.cjs" }, @@ -6655,7 +6715,6 @@ "integrity": "sha512-5gTmgEY/sqK6gFXLIsQNH19lWb4ebPDLA4SdLP7dsWkIXHWlG66oPuVvXSGFPppYZz8ZDZq0dYYrbHfBCVUb1Q==", "dev": true, "license": "MIT", - "peer": true, "engines": { "node": ">=12" }, @@ -6807,7 +6866,6 @@ "integrity": "sha512-f0FFpIdcHgn8zcPSbf1dRevwt047YMnaiJM3u2w2RewrB+fob/zePZcrOyQoLMMO7aBIddLcQIEK5dYjkLnGrQ==", "dev": true, "license": "MIT", - "peer": true, "dependencies": { "@cspotcode/source-map-support": "^0.8.0", "@tsconfig/node10": "^1.0.7", @@ -6894,7 +6952,6 @@ "integrity": "sha512-jl1vZzPDinLr9eUt3J/t7V6FgNEw9QjvBPdysz9KfQDD41fQrC2Y4vKQdiaUpFT4bXlb1RHhLpp8wtm6M5TgSw==", "dev": true, "license": "Apache-2.0", - "peer": true, "bin": { "tsc": "bin/tsc", "tsserver": "bin/tsserver" @@ -6949,9 +7006,9 @@ "license": "MIT" }, "node_modules/undici-types": { - "version": "5.26.5", - "resolved": "https://registry.npmjs.org/undici-types/-/undici-types-5.26.5.tgz", - "integrity": "sha512-JlCMO+ehdEIKqlFxk6IfVoAUVmgz7cU7zD/h9XZ0qzeosSHmUJVOzSQvvYSYWXkFXC+IfLKSIffhv0sVZup6pA==", + "version": "6.21.0", + "resolved": "https://registry.npmjs.org/undici-types/-/undici-types-6.21.0.tgz", + "integrity": "sha512-iwDZqg0QAGrg9Rav5H4n0M64c3mkR59cJ6wQp+7C4nI0gsmExaedaYLNO44eT4AtBBwjbTiGPMlt2Md0T9H9JQ==", "license": "MIT" }, "node_modules/update-browserslist-db": { @@ -7303,6 +7360,8 @@ "google-protobuf": "^3.21.2" }, "devDependencies": { + "@opentelemetry/api": "^1.9.0", + "@opentelemetry/sdk-trace-base": "^1.25.0", "@types/google-protobuf": "^3.15.6", "@types/jest": "^29.5.1", "@types/node": "^18.16.1", @@ -7312,6 +7371,14 @@ }, "engines": { "node": ">=22.0.0" + }, + "peerDependencies": { + "@opentelemetry/api": "^1.4.0" + }, + "peerDependenciesMeta": { + "@opentelemetry/api": { + "optional": true + } } }, "packages/durabletask-js-azuremanaged": { @@ -7337,11 +7404,45 @@ "@microsoft/durabletask-js": ">=0.1.0-alpha.2" } }, + "packages/durabletask-js-azuremanaged/node_modules/@types/node": { + "version": "18.19.130", + "resolved": "https://registry.npmjs.org/@types/node/-/node-18.19.130.tgz", + "integrity": "sha512-GRaXQx6jGfL8sKfaIDD6OupbIHBr9jv7Jnaml9tB7l4v068PAOXqfcujMMo5PhbIs6ggR1XODELqahT2R8v0fg==", + "dev": true, + "license": "MIT", + "dependencies": { + "undici-types": "~5.26.4" + } + }, + "packages/durabletask-js-azuremanaged/node_modules/undici-types": { + "version": "5.26.5", + "resolved": "https://registry.npmjs.org/undici-types/-/undici-types-5.26.5.tgz", + "integrity": "sha512-JlCMO+ehdEIKqlFxk6IfVoAUVmgz7cU7zD/h9XZ0qzeosSHmUJVOzSQvvYSYWXkFXC+IfLKSIffhv0sVZup6pA==", + "dev": true, + "license": "MIT" + }, + "packages/durabletask-js/node_modules/@types/node": { + "version": "18.19.130", + "resolved": "https://registry.npmjs.org/@types/node/-/node-18.19.130.tgz", + "integrity": "sha512-GRaXQx6jGfL8sKfaIDD6OupbIHBr9jv7Jnaml9tB7l4v068PAOXqfcujMMo5PhbIs6ggR1XODELqahT2R8v0fg==", + "dev": true, + "license": "MIT", + "dependencies": { + "undici-types": "~5.26.4" + } + }, "packages/durabletask-js/node_modules/google-protobuf": { "version": "3.21.4", "resolved": "https://registry.npmjs.org/google-protobuf/-/google-protobuf-3.21.4.tgz", "integrity": "sha512-MnG7N936zcKTco4Jd2PX2U96Kf9PxygAPKBug+74LHzmHXmceN16MmRcdgZv+DGef/S9YvQAfRsNCn4cjf9yyQ==", "license": "(BSD-3-Clause AND Apache-2.0)" + }, + "packages/durabletask-js/node_modules/undici-types": { + "version": "5.26.5", + "resolved": "https://registry.npmjs.org/undici-types/-/undici-types-5.26.5.tgz", + "integrity": "sha512-JlCMO+ehdEIKqlFxk6IfVoAUVmgz7cU7zD/h9XZ0qzeosSHmUJVOzSQvvYSYWXkFXC+IfLKSIffhv0sVZup6pA==", + "dev": true, + "license": "MIT" } } } diff --git a/package.json b/package.json index bff15ea..5f5d7c8 100644 --- a/package.json +++ b/package.json @@ -42,7 +42,7 @@ "@swc/core": "^1.3.55", "@swc/helpers": "^0.5.1", "@types/jest": "^29.5.1", - "@types/node": "^18.16.1", + "@types/node": "^22.0.0", "dotenv": "^17.2.3", "eslint": "^9.39.2", "globals": "^16.2.0", diff --git a/packages/durabletask-js-azuremanaged/jest.config.js b/packages/durabletask-js-azuremanaged/jest.config.js index 1ce1b53..a830572 100644 --- a/packages/durabletask-js-azuremanaged/jest.config.js +++ b/packages/durabletask-js-azuremanaged/jest.config.js @@ -6,4 +6,7 @@ module.exports = { transform: { "^.+\\.ts$": "ts-jest", }, + moduleNameMapper: { + "^@microsoft/durabletask-js$": "/../durabletask-js/src/index.ts", + }, }; diff --git a/packages/durabletask-js-azuremanaged/src/azure-logger-adapter.ts b/packages/durabletask-js-azuremanaged/src/azure-logger-adapter.ts index f96fa35..a6e85c0 100644 --- a/packages/durabletask-js-azuremanaged/src/azure-logger-adapter.ts +++ b/packages/durabletask-js-azuremanaged/src/azure-logger-adapter.ts @@ -2,7 +2,7 @@ // Licensed under the MIT License. import { createClientLogger, AzureLogger } from "@azure/logger"; -import { Logger } from "@microsoft/durabletask-js"; +import { StructuredLogger, createLogEventHandler } from "@microsoft/durabletask-js"; /** * Pre-configured logger adapter that uses the default "durabletask" namespace. @@ -29,19 +29,22 @@ import { Logger } from "@microsoft/durabletask-js"; * .build(); * ``` */ -export const AzureLoggerAdapter: Logger = createAzureLogger(); +export const AzureLoggerAdapter: StructuredLogger = createAzureLogger(); /** - * Creates a Logger instance that integrates with Azure SDK's logging infrastructure. + * Creates a StructuredLogger instance that integrates with Azure SDK's logging infrastructure. * * The created logger uses `@azure/logger` under the hood, which means: * - Log output can be controlled via the `AZURE_LOG_LEVEL` environment variable * - Log output can be redirected using `setLogLevel()` from `@azure/logger` * - Logs are prefixed with the namespace for easy filtering * + * When structured log events are emitted, the event ID and category are included in the + * log message prefix for easy filtering and correlation. + * * @param namespace - Optional sub-namespace to append to "durabletask". * For example, "client" results in "durabletask:client". - * @returns A Logger instance configured for the specified namespace. + * @returns A StructuredLogger instance configured for the specified namespace. * * @example * ```typescript @@ -58,7 +61,7 @@ export const AzureLoggerAdapter: Logger = createAzureLogger(); * // Logs will be prefixed with "durabletask" * ``` */ -export function createAzureLogger(namespace?: string): Logger { +export function createAzureLogger(namespace?: string): StructuredLogger { const fullNamespace = namespace ? `durabletask:${namespace}` : "durabletask"; const azureLogger: AzureLogger = createClientLogger(fullNamespace); @@ -75,5 +78,11 @@ export function createAzureLogger(namespace?: string): Logger { debug: (message: string, ...args: unknown[]): void => { azureLogger.verbose(message, ...args); }, + logEvent: createLogEventHandler({ + error: azureLogger.error.bind(azureLogger), + warn: azureLogger.warning.bind(azureLogger), + info: azureLogger.info.bind(azureLogger), + debug: azureLogger.verbose.bind(azureLogger), + }), }; } diff --git a/packages/durabletask-js/package.json b/packages/durabletask-js/package.json index d2e3f9f..493ecc3 100644 --- a/packages/durabletask-js/package.json +++ b/packages/durabletask-js/package.json @@ -42,11 +42,21 @@ "google-protobuf": "^3.21.2" }, "devDependencies": { + "@opentelemetry/api": "^1.9.0", + "@opentelemetry/sdk-trace-base": "^1.25.0", "@types/google-protobuf": "^3.15.6", "@types/jest": "^29.5.1", "@types/node": "^18.16.1", "jest": "^29.5.0", "ts-jest": "^29.1.0", "typescript": "^5.0.4" + }, + "peerDependencies": { + "@opentelemetry/api": "^1.4.0" + }, + "peerDependenciesMeta": { + "@opentelemetry/api": { + "optional": true + } } -} +} \ No newline at end of file diff --git a/packages/durabletask-js/src/client/client-grpc.ts b/packages/durabletask-js/src/client/client-grpc.ts index 35debf3..8faccf8 100644 --- a/packages/durabletask-js/src/client/client-grpc.ts +++ b/packages/durabletask-js/src/client/client-grpc.ts @@ -55,8 +55,8 @@ export class GrpcClient { "grpc.primary_user_agent": "durabletask-js", }; return { - ...options, ...defaultOptions, + ...options, }; } } diff --git a/packages/durabletask-js/src/client/client.ts b/packages/durabletask-js/src/client/client.ts index bdb4fad..5640441 100644 --- a/packages/durabletask-js/src/client/client.ts +++ b/packages/durabletask-js/src/client/client.ts @@ -14,7 +14,7 @@ import { newOrchestrationState } from "../orchestration"; import { OrchestrationState } from "../orchestration/orchestration-state"; import { GrpcClient } from "./client-grpc"; import { OrchestrationStatus, toProtobuf, fromProtobuf } from "../orchestration/enum/orchestration-status.enum"; -import { TimeoutError } from "../exception/timeout-error"; +import { raceWithTimeout } from "../utils/timeout.util"; import { PurgeResult } from "../orchestration/orchestration-purge-result"; import { PurgeInstanceCriteria } from "../orchestration/orchestration-purge-criteria"; import { PurgeInstanceOptions } from "../orchestration/orchestration-purge-options"; @@ -29,6 +29,14 @@ import { Logger, ConsoleLogger } from "../types/logger.type"; import { StartOrchestrationOptions } from "../task/options"; import { mapToRecord } from "../utils/tags.util"; import { populateTagsMap } from "../utils/pb-helper.util"; +import * as ClientLogs from "./logs"; +import { + startSpanForNewOrchestration, + startSpanForEventRaisedFromClient, + setSpanError, + setSpanOk, + endSpan, +} from "../tracing"; // Re-export MetadataGenerator for backward compatibility export { MetadataGenerator } from "../utils/grpc-helper.util"; @@ -218,15 +226,28 @@ export class TaskHubGrpcClient { populateTagsMap(req.getTagsMap(), tags); - this._logger.info(`Starting new ${name} instance with ID = ${req.getInstanceid()}${effectiveVersion ? ` (version: ${effectiveVersion})` : ""}`); + // Create a tracing span for the new orchestration (if OTEL is available) + const span = startSpanForNewOrchestration(req); - const res = await callWithMetadata( - this._stub.startInstance.bind(this._stub), - req, - this._metadataGenerator, - ); + const serializedInput = i.getValue() ?? ""; + const inputSizeInBytes = Buffer.byteLength(serializedInput, "utf8"); + ClientLogs.schedulingOrchestration(this._logger, req.getInstanceid(), name, inputSizeInBytes); - return res.getInstanceid(); + try { + const res = await callWithMetadata( + this._stub.startInstance.bind(this._stub), + req, + this._metadataGenerator, + ); + + setSpanOk(span); + return res.getInstanceid(); + } catch (e: unknown) { + setSpanError(span, e); + throw e; + } finally { + endSpan(span); + } } /** @@ -288,10 +309,11 @@ export class TaskHubGrpcClient { ); // Execute the request and wait for the first response or timeout - const res = (await Promise.race([ + const res = await raceWithTimeout( callPromise, - new Promise((_, reject) => setTimeout(() => reject(new TimeoutError()), timeout * 1000)), - ])) as pb.GetInstanceResponse; + timeout * 1000, + () => `Timed out waiting for orchestration '${instanceId}' to start after ${timeout}s`, + ); return newOrchestrationState(req.getInstanceid(), res); } @@ -322,7 +344,7 @@ export class TaskHubGrpcClient { req.setInstanceid(instanceId); req.setGetinputsandoutputs(fetchPayloads); - this._logger.info(`Waiting ${timeout} seconds for instance ${instanceId} to complete...`); + ClientLogs.waitingForInstanceCompletion(this._logger, instanceId); const callPromise = callWithMetadata( this._stub.waitForInstanceCompletion.bind(this._stub), @@ -331,10 +353,11 @@ export class TaskHubGrpcClient { ); // Execute the request and wait for the first response or timeout - const res = (await Promise.race([ + const res = await raceWithTimeout( callPromise, - new Promise((_, reject) => setTimeout(() => reject(new TimeoutError()), timeout * 1000)), - ])) as pb.GetInstanceResponse; + timeout * 1000, + () => `Timed out waiting for orchestration '${instanceId}' to complete after ${timeout}s`, + ); const state = newOrchestrationState(req.getInstanceid(), res); @@ -346,11 +369,11 @@ export class TaskHubGrpcClient { if (state.runtimeStatus === OrchestrationStatus.FAILED && state.failureDetails) { details = state.failureDetails; - this._logger.info(`Instance ${instanceId} failed: [${details.errorType}] ${details.message}`); + ClientLogs.instanceFailed(this._logger, instanceId, details.errorType, details.message); } else if (state.runtimeStatus === OrchestrationStatus.TERMINATED) { - this._logger.info(`Instance ${instanceId} was terminated`); + ClientLogs.instanceTerminated(this._logger, instanceId); } else if (state.runtimeStatus === OrchestrationStatus.COMPLETED) { - this._logger.info(`Instance ${instanceId} completed`); + ClientLogs.instanceCompleted(this._logger, instanceId); } return state; @@ -367,6 +390,13 @@ export class TaskHubGrpcClient { * @param {any} [data] - An optional serializable data payload to include with the event. */ async raiseOrchestrationEvent(instanceId: string, eventName: string, data: any = null): Promise { + if (!instanceId) { + throw new Error("raiseOrchestrationEvent: 'instanceId' is required."); + } + + if (!eventName) { + throw new Error("raiseOrchestrationEvent: 'eventName' is required and cannot be empty."); + } const req = new pb.RaiseEventRequest(); req.setInstanceid(instanceId); req.setName(eventName); @@ -376,13 +406,25 @@ export class TaskHubGrpcClient { req.setInput(i); - this._logger.info(`Raising event '${eventName}' for instance '${instanceId}'`); + // Create a tracing span for the raised event (if OTEL is available) + const span = startSpanForEventRaisedFromClient(eventName, instanceId); - await callWithMetadata( - this._stub.raiseEvent.bind(this._stub), - req, - this._metadataGenerator, - ); + ClientLogs.raisingEvent(this._logger, instanceId, eventName); + + try { + await callWithMetadata( + this._stub.raiseEvent.bind(this._stub), + req, + this._metadataGenerator, + ); + + setSpanOk(span); + } catch (e: unknown) { + setSpanError(span, e); + throw e; + } finally { + endSpan(span); + } } /** @@ -410,6 +452,10 @@ export class TaskHubGrpcClient { instanceId: string, outputOrOptions: any | TerminateInstanceOptions = null, ): Promise { + if (!instanceId) { + throw new Error("instanceId is required"); + } + const req = new pb.TerminateRequest(); req.setInstanceid(instanceId); @@ -431,7 +477,7 @@ export class TaskHubGrpcClient { req.setOutput(i); req.setRecursive(recursive); - this._logger.info(`Terminating '${instanceId}'${recursive ? ' (recursive)' : ''}`); + ClientLogs.terminatingInstance(this._logger, instanceId); await callWithMetadata( this._stub.terminateInstance.bind(this._stub), @@ -441,10 +487,14 @@ export class TaskHubGrpcClient { } async suspendOrchestration(instanceId: string): Promise { + if (!instanceId) { + throw new Error("instanceId is required"); + } + const req = new pb.SuspendRequest(); req.setInstanceid(instanceId); - this._logger.info(`Suspending '${instanceId}'`); + ClientLogs.suspendingInstance(this._logger, instanceId); await callWithMetadata( this._stub.suspendInstance.bind(this._stub), @@ -454,10 +504,14 @@ export class TaskHubGrpcClient { } async resumeOrchestration(instanceId: string): Promise { + if (!instanceId) { + throw new Error("instanceId is required"); + } + const req = new pb.ResumeRequest(); req.setInstanceid(instanceId); - this._logger.info(`Resuming '${instanceId}'`); + ClientLogs.resumingInstance(this._logger, instanceId); await callWithMetadata( this._stub.resumeInstance.bind(this._stub), @@ -495,7 +549,7 @@ export class TaskHubGrpcClient { req.setReason(reasonValue); } - this._logger.info(`Rewinding '${instanceId}' with reason: ${reason}`); + ClientLogs.rewindingInstance(this._logger, instanceId, reason); try { await callWithMetadata( @@ -552,7 +606,7 @@ export class TaskHubGrpcClient { req.setInstanceid(instanceId); req.setRestartwithnewinstanceid(restartWithNewInstanceId); - this._logger.info(`Restarting '${instanceId}' with restartWithNewInstanceId=${restartWithNewInstanceId}`); + ClientLogs.restartingInstance(this._logger, instanceId, restartWithNewInstanceId); try { const res = await callWithMetadata( @@ -607,7 +661,7 @@ export class TaskHubGrpcClient { req.setInstanceid(instanceId); req.setRecursive(options?.recursive ?? false); - this._logger.info(`Purging Instance '${instanceId}'${options?.recursive ? ' (recursive)' : ''}`); + ClientLogs.purgingInstanceMetadata(this._logger, instanceId); res = await callWithMetadata( this._stub.purgeInstances.bind(this._stub), @@ -638,7 +692,7 @@ export class TaskHubGrpcClient { req.setRecursive(options?.recursive ?? false); const timeout = purgeInstanceCriteria.getTimeout(); - this._logger.info(`Purging Instances using purging criteria${options?.recursive ? " (recursive)" : ""}`); + ClientLogs.purgingInstances(this._logger, createdTimeFrom, createdTimeTo, runtimeStatusList.map(String).join(", ")); const callPromise = callWithMetadata( this._stub.purgeInstances.bind(this._stub), @@ -646,10 +700,11 @@ export class TaskHubGrpcClient { this._metadataGenerator, ); // Execute the request and wait for the first response or timeout - res = (await Promise.race([ + res = await raceWithTimeout( callPromise, - new Promise((_, reject) => setTimeout(() => reject(new TimeoutError()), timeout)), - ])) as pb.PurgeInstancesResponse; + timeout, + () => `Timed out waiting for purge operation after ${timeout}ms`, + ); } if (!res) { return; diff --git a/packages/durabletask-js/src/client/logs.ts b/packages/durabletask-js/src/client/logs.ts new file mode 100644 index 0000000..2d0455b --- /dev/null +++ b/packages/durabletask-js/src/client/logs.ts @@ -0,0 +1,204 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +/** + * Centralized log definitions for the Durable Task Client. + * + * Event IDs and message templates are aligned with the .NET Durable Task SDK + * (see: https://github.com/microsoft/durabletask-dotnet/blob/main/src/Client/Grpc/Logs.cs). + * + * Event ID ranges: + * - 40–46: Client operations (from .NET) + * - 100–199: JS-specific client operations + */ + +import { Logger } from "../types/logger.type"; +import { emitLog } from "../utils/emit-log"; + +// ── Logger category ────────────────────────────────────────────────────────── + +/** Category for client-related logs. */ +const CATEGORY_CLIENT = "Microsoft.DurableTask.Client"; + +// ── Event IDs (matching .NET) ──────────────────────────────────────────────── + +/** @internal */ export const EVENT_SCHEDULING_ORCHESTRATION = 40; +/** @internal */ export const EVENT_WAITING_FOR_INSTANCE_START = 42; +/** @internal */ export const EVENT_WAITING_FOR_INSTANCE_COMPLETION = 43; +/** @internal */ export const EVENT_TERMINATING_INSTANCE = 44; +/** @internal */ export const EVENT_PURGING_INSTANCE_METADATA = 45; +/** @internal */ export const EVENT_PURGING_INSTANCES = 46; + +// ── JS-specific Event IDs (start at 100 to leave buffer for .NET additions) ── + +/** @internal */ export const EVENT_RAISING_EVENT = 100; +/** @internal */ export const EVENT_SUSPENDING_INSTANCE = 101; +/** @internal */ export const EVENT_RESUMING_INSTANCE = 102; +/** @internal */ export const EVENT_REWINDING_INSTANCE = 103; +/** @internal */ export const EVENT_RESTARTING_INSTANCE = 104; +/** @internal */ export const EVENT_INSTANCE_COMPLETED = 105; +/** @internal */ export const EVENT_INSTANCE_FAILED = 106; +/** @internal */ export const EVENT_INSTANCE_TERMINATED = 107; + +// ═══════════════════════════════════════════════════════════════════════════════ +// Client Operation Logs (Event IDs 40–46, matching .NET) +// ═══════════════════════════════════════════════════════════════════════════════ + +/** + * Logs that a new orchestration is being scheduled. + * Matches .NET EventId 40: "Scheduling new {name} orchestration with instance ID '{instanceId}' and {sizeInBytes} bytes of input data." + */ +export function schedulingOrchestration( + logger: Logger, + instanceId: string, + name: string, + sizeInBytes: number, +): void { + emitLog(logger, "info", { + eventId: EVENT_SCHEDULING_ORCHESTRATION, + category: CATEGORY_CLIENT, + properties: { instanceId, name, sizeInBytes }, + }, `Scheduling new ${name} orchestration with instance ID '${instanceId}' and ${sizeInBytes} bytes of input data.`); +} + +/** + * Logs that the client is waiting for an instance to start. + * Matches .NET EventId 42: "Waiting for instance '{instanceId}' to start." + */ +export function waitingForInstanceStart(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_WAITING_FOR_INSTANCE_START, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Waiting for instance '${instanceId}' to start.`); +} + +/** + * Logs that the client is waiting for an instance to complete, fail, or terminate. + * Matches .NET EventId 43: "Waiting for instance '{instanceId}' to complete, fail, or terminate." + */ +export function waitingForInstanceCompletion(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_WAITING_FOR_INSTANCE_COMPLETION, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Waiting for instance '${instanceId}' to complete, fail, or terminate.`); +} + +/** + * Logs that an instance is being terminated. + * Matches .NET EventId 44: "Terminating instance '{instanceId}'." + */ +export function terminatingInstance(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_TERMINATING_INSTANCE, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Terminating instance '${instanceId}'.`); +} + +/** + * Logs that instance metadata is being purged. + * Matches .NET EventId 45: "Purging instance metadata '{instanceId}'." + */ +export function purgingInstanceMetadata(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_PURGING_INSTANCE_METADATA, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Purging instance metadata '${instanceId}'.`); +} + +/** + * Logs that instances are being purged with filter criteria. + * Matches .NET EventId 46: "Purging instances with filter: { CreatedFrom = {createdFrom}, CreatedTo = {createdTo}, Statuses = {statuses} }" + */ +export function purgingInstances( + logger: Logger, + createdFrom?: Date, + createdTo?: Date, + statuses?: string, +): void { + emitLog(logger, "info", { + eventId: EVENT_PURGING_INSTANCES, + category: CATEGORY_CLIENT, + properties: { createdFrom: createdFrom?.toISOString(), createdTo: createdTo?.toISOString(), statuses }, + }, `Purging instances with filter: { CreatedFrom = ${createdFrom?.toISOString() ?? "N/A"}, CreatedTo = ${createdTo?.toISOString() ?? "N/A"}, Statuses = ${statuses ?? "N/A"} }`); +} + +// ═══════════════════════════════════════════════════════════════════════════════ +// JS-specific Client Logs (Event IDs 100+) +// ═══════════════════════════════════════════════════════════════════════════════ + +export function raisingEvent(logger: Logger, instanceId: string, eventName: string): void { + emitLog(logger, "info", { + eventId: EVENT_RAISING_EVENT, + category: CATEGORY_CLIENT, + properties: { instanceId, eventName }, + }, `Raising event '${eventName}' for instance '${instanceId}'.`); +} + +export function suspendingInstance(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_SUSPENDING_INSTANCE, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Suspending instance '${instanceId}'.`); +} + +export function resumingInstance(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_RESUMING_INSTANCE, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Resuming instance '${instanceId}'.`); +} + +export function rewindingInstance(logger: Logger, instanceId: string, reason: string): void { + emitLog(logger, "info", { + eventId: EVENT_REWINDING_INSTANCE, + category: CATEGORY_CLIENT, + properties: { instanceId, reason }, + }, `Rewinding instance '${instanceId}' with reason: ${reason}.`); +} + +export function restartingInstance( + logger: Logger, + instanceId: string, + restartWithNewInstanceId: boolean, +): void { + emitLog(logger, "info", { + eventId: EVENT_RESTARTING_INSTANCE, + category: CATEGORY_CLIENT, + properties: { instanceId, restartWithNewInstanceId }, + }, `Restarting instance '${instanceId}' with restartWithNewInstanceId=${restartWithNewInstanceId}.`); +} + +export function instanceCompleted(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_INSTANCE_COMPLETED, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Instance '${instanceId}' completed.`); +} + +export function instanceFailed( + logger: Logger, + instanceId: string, + errorType: string, + errorMessage: string, +): void { + emitLog(logger, "error", { + eventId: EVENT_INSTANCE_FAILED, + category: CATEGORY_CLIENT, + properties: { instanceId, errorType, errorMessage }, + }, `Instance '${instanceId}' failed: [${errorType}] ${errorMessage}`); +} + +export function instanceTerminated(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_INSTANCE_TERMINATED, + category: CATEGORY_CLIENT, + properties: { instanceId }, + }, `Instance '${instanceId}' was terminated.`); +} diff --git a/packages/durabletask-js/src/exception/timeout-error.ts b/packages/durabletask-js/src/exception/timeout-error.ts index 87c57f4..abbe095 100644 --- a/packages/durabletask-js/src/exception/timeout-error.ts +++ b/packages/durabletask-js/src/exception/timeout-error.ts @@ -2,7 +2,8 @@ // Licensed under the MIT License. export class TimeoutError extends Error { - constructor() { - super("TimeoutError"); + constructor(message: string = "The operation timed out.") { + super(message); + this.name = "TimeoutError"; } } diff --git a/packages/durabletask-js/src/index.ts b/packages/durabletask-js/src/index.ts index 9c41cd2..96d7bc9 100644 --- a/packages/durabletask-js/src/index.ts +++ b/packages/durabletask-js/src/index.ts @@ -87,8 +87,17 @@ export { InMemoryOrchestrationBackend, TestOrchestrationClient, TestOrchestratio export { ParentOrchestrationInstance } from "./types/parent-orchestration-instance.type"; // Logger -export { Logger, ConsoleLogger, NoOpLogger } from "./types/logger.type"; +export { Logger, ConsoleLogger, NoOpLogger, StructuredLogger, LogEvent, isStructuredLogger, createLogEventHandler } from "./types/logger.type"; export { ReplaySafeLogger, ReplayContext } from "./types/replay-safe-logger"; // Versioning utilities export { compareVersions } from "./utils/versioning.util"; + +// Distributed Tracing (OpenTelemetry) +export { + TRACER_NAME, + DurableTaskAttributes, + TaskType, + createSpanName, + createTimerSpanName, +} from "./tracing"; diff --git a/packages/durabletask-js/src/orchestration/enum/orchestration-status.enum.ts b/packages/durabletask-js/src/orchestration/enum/orchestration-status.enum.ts index db418db..64aff91 100644 --- a/packages/durabletask-js/src/orchestration/enum/orchestration-status.enum.ts +++ b/packages/durabletask-js/src/orchestration/enum/orchestration-status.enum.ts @@ -3,22 +3,25 @@ import * as pb from "../../proto/orchestrator_service_pb"; -export function fromProtobuf(val: pb.OrchestrationStatus): OrchestrationStatus { - const values = Object.values(OrchestrationStatus); - const valIdx = values.findIndex((v) => v == (val as number)); +// Pre-built reverse maps for efficient O(1) conversions +const protoToClient = new Map(); +const clientToProto = new Map(); + - // Return the entry of the OrchestrationStatus enum at index - const entries = Object.entries(OrchestrationStatus); - return entries[valIdx][1] as OrchestrationStatus; +export function fromProtobuf(val: pb.OrchestrationStatus): OrchestrationStatus { + const result = protoToClient.get(val); + if (result === undefined) { + throw new Error(`Unknown protobuf OrchestrationStatus value: ${val}`); + } + return result; } export function toProtobuf(val: OrchestrationStatus): pb.OrchestrationStatus { - const values = Object.values(pb.OrchestrationStatus); - const valIdx = values.findIndex((v) => v == (val as number)); - - // Return the entry of the OrchestrationStatus enum at index - const entries = Object.entries(pb.OrchestrationStatus); - return entries[valIdx][1] as pb.OrchestrationStatus; + const result = clientToProto.get(val); + if (result === undefined) { + throw new Error(`Unknown OrchestrationStatus value: ${val}`); + } + return result; } export enum OrchestrationStatus { @@ -30,3 +33,23 @@ export enum OrchestrationStatus { PENDING = pb.OrchestrationStatus.ORCHESTRATION_STATUS_PENDING, SUSPENDED = pb.OrchestrationStatus.ORCHESTRATION_STATUS_SUSPENDED, } + +// Initialize the reverse maps now that both enums are defined. +// Both enums share the same numeric values; cast through number to satisfy TypeScript. +// An invariant check guards against silent drift between the two enums. +for (const [name, value] of Object.entries(OrchestrationStatus)) { + if (typeof value === "number") { + const numValue = value as number; + const expectedProtoKey = `ORCHESTRATION_STATUS_${name}`; + // Verify the proto enum has this key with the same numeric value (plain object, no reverse mapping) + const protoValue = (pb.OrchestrationStatus as unknown as Record)[expectedProtoKey]; + if (protoValue !== numValue) { + throw new Error( + `Enum drift detected: OrchestrationStatus.${name} (${numValue}) does not match ` + + `pb.OrchestrationStatus.${expectedProtoKey} (${protoValue}).`, + ); + } + protoToClient.set(numValue as pb.OrchestrationStatus, numValue as OrchestrationStatus); + clientToProto.set(numValue as OrchestrationStatus, numValue as pb.OrchestrationStatus); + } +} diff --git a/packages/durabletask-js/src/orchestration/exception/orchestration-failed-error.ts b/packages/durabletask-js/src/orchestration/exception/orchestration-failed-error.ts index ad85850..eaf7388 100644 --- a/packages/durabletask-js/src/orchestration/exception/orchestration-failed-error.ts +++ b/packages/durabletask-js/src/orchestration/exception/orchestration-failed-error.ts @@ -8,6 +8,7 @@ export class OrchestrationFailedError extends Error { constructor(message: string, details: FailureDetails) { super(message); + this.name = "OrchestrationFailedError"; this._failureDetails = details; } diff --git a/packages/durabletask-js/src/orchestration/history-event.ts b/packages/durabletask-js/src/orchestration/history-event.ts index d660116..bd3d508 100644 --- a/packages/durabletask-js/src/orchestration/history-event.ts +++ b/packages/durabletask-js/src/orchestration/history-event.ts @@ -89,6 +89,10 @@ export interface ExecutionStartedEvent extends HistoryEventBase { parentInstance?: ParentInstanceInfo; scheduledStartTimestamp?: Date; tags?: Record; + /** The parent trace context for distributed tracing (W3C Trace Context). */ + parentTraceContext?: TraceContext; + /** The span ID assigned to this orchestration execution for replay continuity. */ + orchestrationSpanId?: string; } /** @@ -151,6 +155,8 @@ export interface TaskScheduledEvent extends HistoryEventBase { version?: string; input?: string; tags?: Record; + /** The parent trace context for distributed tracing (W3C Trace Context). */ + parentTraceContext?: TraceContext; } /** @@ -181,6 +187,8 @@ export interface SubOrchestrationInstanceCreatedEvent extends HistoryEventBase { instanceId?: string; input?: string; tags?: Record; + /** The parent trace context for distributed tracing (W3C Trace Context). */ + parentTraceContext?: TraceContext; } /** diff --git a/packages/durabletask-js/src/orchestration/index.ts b/packages/durabletask-js/src/orchestration/index.ts index 571aade..74cea61 100644 --- a/packages/durabletask-js/src/orchestration/index.ts +++ b/packages/durabletask-js/src/orchestration/index.ts @@ -52,9 +52,9 @@ export function newOrchestrationState( fromProtobuf(state?.getOrchestrationstatus() ?? 0), new Date(tsCreatedParsed), new Date(tsUpdatedParsed), - state?.getInput()?.toString(), - state?.getOutput()?.toString(), - state?.getCustomstatus()?.toString(), + state?.getInput()?.getValue(), + state?.getOutput()?.getValue(), + state?.getCustomstatus()?.getValue(), failureDetails, tags, ); diff --git a/packages/durabletask-js/src/task/exception/orchestration-state-error.ts b/packages/durabletask-js/src/task/exception/orchestration-state-error.ts index b9ff92d..ae33b9f 100644 --- a/packages/durabletask-js/src/task/exception/orchestration-state-error.ts +++ b/packages/durabletask-js/src/task/exception/orchestration-state-error.ts @@ -4,5 +4,6 @@ export class OrchestrationStateError extends Error { constructor(message: string) { super(message); + this.name = "OrchestrationStateError"; } } diff --git a/packages/durabletask-js/src/testing/in-memory-backend.ts b/packages/durabletask-js/src/testing/in-memory-backend.ts index a32a649..3f65e98 100644 --- a/packages/durabletask-js/src/testing/in-memory-backend.ts +++ b/packages/durabletask-js/src/testing/in-memory-backend.ts @@ -61,6 +61,7 @@ export class InMemoryOrchestrationBackend { private readonly orchestrationQueueSet: Set = new Set(); private readonly activityQueue: ActivityWorkItem[] = []; private readonly stateWaiters: Map = new Map(); + private readonly pendingTimers: Set> = new Set(); private nextCompletionToken: number = 1; private readonly maxHistorySize: number; @@ -388,6 +389,10 @@ export class InMemoryOrchestrationBackend { } } this.stateWaiters.clear(); + for (const timer of this.pendingTimers) { + clearTimeout(timer); + } + this.pendingTimers.clear(); } /** @@ -450,7 +455,10 @@ export class InMemoryOrchestrationBackend { this.processSendEventAction(action.getSendevent()!); break; default: - console.warn(`Unknown action type: ${actionType}`); + throw new Error( + `Unknown orchestrator action type '${actionType}' for orchestration '${instance.instanceId}'. ` + + `This likely means the in-memory backend needs to be updated to handle a newly introduced action type.`, + ); } } @@ -531,7 +539,8 @@ export class InMemoryOrchestrationBackend { const now = new Date(); const delay = Math.max(0, fireAt.getTime() - now.getTime()); - setTimeout(() => { + const timerHandle = setTimeout(() => { + this.pendingTimers.delete(timerHandle); const currentInstance = this.instances.get(instance.instanceId); if (currentInstance && !this.isTerminalStatus(currentInstance.status)) { const timerFiredEvent = pbh.newTimerFiredEvent(timerId, fireAt); @@ -540,6 +549,7 @@ export class InMemoryOrchestrationBackend { this.enqueueOrchestration(instance.instanceId); } }, delay); + this.pendingTimers.add(timerHandle); } private processCreateSubOrchestrationAction(instance: OrchestrationInstance, action: pb.OrchestratorAction): void { @@ -564,9 +574,10 @@ export class InMemoryOrchestrationBackend { // Watch for sub-orchestration completion this.watchSubOrchestration(instance.instanceId, subInstanceId, taskId); - } catch (error: any) { + } catch (error: unknown) { // Sub-orchestration creation failed - const failedEvent = pbh.newSubOrchestrationFailedEvent(taskId, error); + const err = error instanceof Error ? error : new Error(String(error)); + const failedEvent = pbh.newSubOrchestrationFailedEvent(taskId, err); instance.pendingEvents.push(failedEvent); this.enqueueOrchestration(instance.instanceId); } diff --git a/packages/durabletask-js/src/testing/test-worker.ts b/packages/durabletask-js/src/testing/test-worker.ts index 3b85c57..09855c6 100644 --- a/packages/durabletask-js/src/testing/test-worker.ts +++ b/packages/durabletask-js/src/testing/test-worker.ts @@ -145,9 +145,7 @@ export class TestOrchestrationWorker { const result = await executor.execute(instanceId, instance.history, instance.pendingEvents); this.backend.completeOrchestration(instanceId, completionToken, result.actions, result.customStatus); - } catch (error: any) { - console.error(`Error executing orchestration '${instanceId}':`, error); - + } catch (error: unknown) { // Create a failure action const failureDetails = pbh.newFailureDetails(error); const failAction = pbh.newCompleteOrchestrationAction( @@ -171,9 +169,9 @@ export class TestOrchestrationWorker { const executor = new ActivityExecutor(this.registry); const result = await executor.execute(instanceId, name, taskId, input); this.backend.completeActivity(instanceId, taskId, result); - } catch (error: any) { - console.error(`Error executing activity '${name}':`, error); - this.backend.completeActivity(instanceId, taskId, undefined, error); + } catch (error: unknown) { + const err = error instanceof Error ? error : new Error(String(error)); + this.backend.completeActivity(instanceId, taskId, undefined, err); } } diff --git a/packages/durabletask-js/src/tracing/constants.ts b/packages/durabletask-js/src/tracing/constants.ts new file mode 100644 index 0000000..c892934 --- /dev/null +++ b/packages/durabletask-js/src/tracing/constants.ts @@ -0,0 +1,88 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +/** + * The name of the OpenTelemetry tracer used by the Durable Task SDK. + * This is consistent across all language SDKs for cross-language trace correlation. + */ +export const TRACER_NAME = "Microsoft.DurableTask"; + +/** + * Semantic attribute keys for Durable Task spans. + * These follow the conventions established by the .NET SDK for cross-language consistency. + */ +export const DurableTaskAttributes = { + /** The type of durable task (e.g., "orchestration", "activity"). */ + TYPE: "durabletask.type", + /** The name of the task (orchestration or activity name). */ + TASK_NAME: "durabletask.task.name", + /** The version of the task. */ + TASK_VERSION: "durabletask.task.version", + /** The instance ID of the orchestration. */ + TASK_INSTANCE_ID: "durabletask.task.instance_id", + /** The execution ID of the orchestration. */ + TASK_EXECUTION_ID: "durabletask.task.execution_id", + /** The status of the orchestration (e.g., "COMPLETED", "FAILED"). */ + TASK_STATUS: "durabletask.task.status", + /** The sequential task ID within an orchestration. */ + TASK_TASK_ID: "durabletask.task.task_id", + /** The target instance ID for event operations. */ + EVENT_TARGET_INSTANCE_ID: "durabletask.event.target_instance_id", + /** The fire-at time for timer operations. */ + FIRE_AT: "durabletask.fire_at", + /** + * The DurableTask replay span ID. This is the OTEL span ID from the first + * execution of an orchestration, carried forward across replays for correlation. + * It may differ from the current OTEL span's spanId on replay invocations. + */ + REPLAY_SPAN_ID: "durabletask.task.replay_span_id", + /** + * The original start time of the orchestration from its first execution, + * carried forward across replays for correlation. This is stored as an + * ISO-8601 string attribute so that replay spans can start at the current + * time (avoiding artificially long span durations) while still preserving + * a reference to the original execution start. + */ + REPLAY_START_TIME: "durabletask.task.replay_start_time", +} as const; + +/** + * Task type values used in the `durabletask.type` attribute. + */ +export const TaskType = { + ORCHESTRATION: "orchestration", + ACTIVITY: "activity", + EVENT: "event", + TIMER: "timer", + CREATE_ORCHESTRATION: "create_orchestration", + ORCHESTRATION_EVENT: "orchestration_event", +} as const; + +/** + * Creates a span name following the Durable Task naming convention. + * + * Format: "{type}:{name}" or "{type}:{name}@({version})" + * + * @param type - The task type (e.g., "orchestration", "activity"). + * @param name - The task name. + * @param version - An optional task version. + * @returns The formatted span name. + */ +export function createSpanName(type: string, name: string, version?: string): string { + if (version) { + return `${type}:${name}@(${version})`; + } + return `${type}:${name}`; +} + +/** + * Creates a timer span name following the Durable Task naming convention. + * + * Format: "timer:{orchName}" + * + * @param orchestrationName - The name of the parent orchestration. + * @returns The formatted timer span name. + */ +export function createTimerSpanName(orchestrationName: string): string { + return `${TaskType.TIMER}:${orchestrationName}`; +} diff --git a/packages/durabletask-js/src/tracing/index.ts b/packages/durabletask-js/src/tracing/index.ts new file mode 100644 index 0000000..d3df6ad --- /dev/null +++ b/packages/durabletask-js/src/tracing/index.ts @@ -0,0 +1,35 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +export { TRACER_NAME, DurableTaskAttributes, TaskType, createSpanName, createTimerSpanName } from "./constants"; + +export { + parseTraceparent, + createTraceparent, + generateSpanId, + createPbTraceContext, + extractTraceparentFromSpan, + createParentContextFromPb, +} from "./trace-context-utils"; + +// Internal-only exports (not re-exported from package index.ts): +// getOtelApi, getTracer, OrchestrationSpanInfo, startSpanForEventRaisedFromClient +export { getOtelApi } from "./trace-context-utils"; + +export { + getTracer, + OrchestrationSpanInfo, + startSpanForNewOrchestration, + startSpanForOrchestrationExecution, + startSpanForSchedulingTask, + startSpanForTaskExecution, + startSpanForSchedulingSubOrchestration, + emitSpanForTimer, + emitSpanForEventSent, + startSpanForEventRaisedFromClient, + setSpanError, + setSpanOk, + endSpan, + createOrchestrationTraceContextPb, + processActionsForTracing, +} from "./trace-helper"; diff --git a/packages/durabletask-js/src/tracing/trace-context-utils.ts b/packages/durabletask-js/src/tracing/trace-context-utils.ts new file mode 100644 index 0000000..87001e7 --- /dev/null +++ b/packages/durabletask-js/src/tracing/trace-context-utils.ts @@ -0,0 +1,169 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import * as pb from "../proto/orchestrator_service_pb"; +import { StringValue } from "google-protobuf/google/protobuf/wrappers_pb"; +import { randomBytes } from "crypto"; +import type { Span, Context, SpanContext, TraceState } from "@opentelemetry/api"; + +/** + * Regex pattern for validating W3C traceparent format. + * Format: "00-{traceId32hex}-{spanId16hex}-{flags2hex}" + */ +const TRACEPARENT_REGEX = /^00-([0-9a-f]{32})-([0-9a-f]{16})-([0-9a-f]{2})$/; + +/** + * Parses a W3C traceparent string into its components. + * + * @param traceparent - A W3C traceparent string (e.g., "00-TRACEID-SPANID-FLAGS"). + * @returns The parsed components, or undefined if the string is invalid. + */ +export function parseTraceparent( + traceparent: string, +): { traceId: string; spanId: string; traceFlags: number } | undefined { + const match = traceparent.match(TRACEPARENT_REGEX); + if (!match) { + return undefined; + } + return { + traceId: match[1], + spanId: match[2], + traceFlags: parseInt(match[3], 16), + }; +} + +/** + * Creates a W3C traceparent string from its components. + * + * @param traceId - The 32-character hex trace ID. + * @param spanId - The 16-character hex span ID. + * @param traceFlags - The trace flags byte (0-255). + * @returns The formatted traceparent string. + * @throws {Error} If traceId or spanId have invalid format. + */ +export function createTraceparent(traceId: string, spanId: string, traceFlags: number = 1): string { + if (!/^[0-9a-fA-F]{32}$/.test(traceId)) { + throw new Error(`Invalid traceId: expected 32 hex characters, got '${traceId}'`); + } + if (!/^[0-9a-fA-F]{16}$/.test(spanId)) { + throw new Error(`Invalid spanId: expected 16 hex characters, got '${spanId}'`); + } + const normalizedTraceId = traceId.toLowerCase(); + const normalizedSpanId = spanId.toLowerCase(); + const flagsByte = traceFlags & 0xff; + const flags = flagsByte.toString(16).padStart(2, "0"); + return `00-${normalizedTraceId}-${normalizedSpanId}-${flags}`; +} + +/** + * Generates a random 16-character hex span ID. + */ +export function generateSpanId(): string { + return randomBytes(8).toString("hex"); +} + +/** + * Creates a protobuf TraceContext from a traceparent and optional tracestate. + * + * @param traceparent - The W3C traceparent string. + * @param tracestate - The optional W3C tracestate string. + * @returns A new protobuf TraceContext. + */ +export function createPbTraceContext(traceparent: string, tracestate?: string): pb.TraceContext { + const ctx = new pb.TraceContext(); + ctx.setTraceparent(traceparent); + + // Extract the span ID from the traceparent + const parsed = parseTraceparent(traceparent); + if (parsed) { + ctx.setSpanid(parsed.spanId); + } + + if (tracestate) { + const sv = new StringValue(); + sv.setValue(tracestate); + ctx.setTracestate(sv); + } + + return ctx; +} + +/** + * Attempts to load the OpenTelemetry API module. + * Returns undefined if the module is not installed (it's an optional peer dependency). + * + * Note: Uses synchronous `require()` because the result is cached and callers + * throughout the tracing layer depend on synchronous access. The compiled output + * targets CommonJS, so `require()` is safe. If the project migrates to ESM output + * in the future, this should be changed to an async initialization pattern. + */ +let _otelApi: typeof import("@opentelemetry/api") | undefined; +let _otelApiLoaded = false; + +export function getOtelApi(): typeof import("@opentelemetry/api") | undefined { + if (!_otelApiLoaded) { + _otelApiLoaded = true; + try { + _otelApi = require("@opentelemetry/api"); + } catch { + _otelApi = undefined; + } + } + return _otelApi; +} + +/** + * Extracts traceparent and tracestate from a span's SpanContext. + * Returns undefined if OTEL is not available or span is not valid. + */ +export function extractTraceparentFromSpan(span: Span | undefined | null): { traceparent: string; tracestate?: string } | undefined { + const otel = getOtelApi(); + if (!otel) return undefined; + + const spanContext = span?.spanContext?.(); + if (!spanContext || !otel.isSpanContextValid(spanContext)) { + return undefined; + } + + const traceparent = createTraceparent(spanContext.traceId, spanContext.spanId, spanContext.traceFlags ?? 1); + const tracestate = spanContext.traceState?.serialize(); + return { traceparent, tracestate }; +} + +/** + * Creates an OTEL Context with a remote parent span from a protobuf TraceContext. + * Returns undefined if OTEL is not available or the pbTraceContext is not provided. + * Returns ROOT_CONTEXT if the traceparent is missing or invalid. + */ +export function createParentContextFromPb(pbTraceContext: pb.TraceContext | undefined): Context | undefined { + const otel = getOtelApi(); + if (!otel || !pbTraceContext) { + return undefined; + } + + const traceparent = pbTraceContext.getTraceparent(); + if (!traceparent) { + return otel.ROOT_CONTEXT; + } + + const parsed = parseTraceparent(traceparent); + if (!parsed) { + return otel.ROOT_CONTEXT; + } + + let traceState: TraceState | undefined; + const traceStateStr = pbTraceContext.getTracestate()?.getValue(); + if (traceStateStr) { + traceState = otel.createTraceState(traceStateStr); + } + + const spanContext: SpanContext = { + traceId: parsed.traceId, + spanId: parsed.spanId, + traceFlags: parsed.traceFlags, + isRemote: true, + traceState, + }; + + return otel.trace.setSpanContext(otel.ROOT_CONTEXT, spanContext); +} diff --git a/packages/durabletask-js/src/tracing/trace-helper.ts b/packages/durabletask-js/src/tracing/trace-helper.ts new file mode 100644 index 0000000..e88dc1b --- /dev/null +++ b/packages/durabletask-js/src/tracing/trace-helper.ts @@ -0,0 +1,486 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import * as pb from "../proto/orchestrator_service_pb"; +import { StringValue } from "google-protobuf/google/protobuf/wrappers_pb"; +import { Timestamp } from "google-protobuf/google/protobuf/timestamp_pb"; +import { TRACER_NAME, DurableTaskAttributes, TaskType, createSpanName, createTimerSpanName } from "./constants"; +import { + getOtelApi, + extractTraceparentFromSpan, + createPbTraceContext, + createParentContextFromPb, +} from "./trace-context-utils"; +import type { Span, Tracer } from "@opentelemetry/api"; + +/** + * Gets the Durable Task tracer from the OpenTelemetry API. + * Returns undefined if OpenTelemetry is not installed. + */ +export function getTracer(): Tracer | undefined { + const otel = getOtelApi(); + if (!otel) return undefined; + return otel.trace.getTracer(TRACER_NAME); +} + +/** + * Information about an orchestration span for replay continuity. + * + * `spanId` is a DurableTask-specific replay correlation identifier. On the first + * execution it equals the actual OTEL span ID. On replays, it is carried forward + * from the first execution so all replay iterations share a stable identifier, + * even though each replay creates a new OTEL span with its own spanId. + */ +export interface OrchestrationSpanInfo { + spanId: string; + /** + * The start time from the first execution, persisted across replays in + * OrchestrationTraceContext. On replay invocations this is the original + * first-execution time, which may differ from the OTEL span's actual + * startTime (which is always the current wall-clock time). + */ + startTime: Date; +} + +/** + * Creates a Producer span for scheduling a new orchestration (client-side). + * Injects the W3C trace context into the CreateInstanceRequest. + * + * @param req - The CreateInstanceRequest to inject trace context into. + * @returns The span (or undefined if OTEL is not available). Caller must end it. + */ +export function startSpanForNewOrchestration(req: pb.CreateInstanceRequest): Span | undefined { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return undefined; + + const name = req.getName(); + const version = req.getVersion()?.getValue(); + const instanceId = req.getInstanceid(); + const spanName = createSpanName(TaskType.CREATE_ORCHESTRATION, name, version); + + const span = tracer.startSpan(spanName, { + kind: otel.SpanKind.PRODUCER, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.CREATE_ORCHESTRATION, + [DurableTaskAttributes.TASK_NAME]: name, + [DurableTaskAttributes.TASK_INSTANCE_ID]: instanceId, + ...(version ? { [DurableTaskAttributes.TASK_VERSION]: version } : {}), + }, + }); + + // Inject trace context into the proto request + const traceInfo = extractTraceparentFromSpan(span); + if (traceInfo) { + const pbCtx = createPbTraceContext(traceInfo.traceparent, traceInfo.tracestate); + req.setParenttracecontext(pbCtx); + } + + return span; +} + +/** + * Creates a Server span for orchestration execution. + * Handles replay by reusing the same span identity across multiple invocations. + * + * @param executionStartedEvent - The proto ExecutionStartedEvent. + * @param orchestrationTraceContext - The OrchestrationTraceContext from the request (for replay). + * @param instanceId - The orchestration instance ID. + * @returns An object with the span and span info for the response, or undefined if OTEL is not available. + */ +export function startSpanForOrchestrationExecution( + executionStartedEvent: pb.ExecutionStartedEvent, + orchestrationTraceContext: pb.OrchestrationTraceContext | undefined, + instanceId: string, +): { span: Span; spanInfo: OrchestrationSpanInfo } | undefined { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return undefined; + + const name = executionStartedEvent.getName(); + const version = executionStartedEvent.getVersion()?.getValue(); + const spanName = createSpanName(TaskType.ORCHESTRATION, name, version); + + // Determine the parent context from the ExecutionStartedEvent's parentTraceContext + const parentPbCtx = executionStartedEvent.getParenttracecontext(); + const parentContext = createParentContextFromPb(parentPbCtx); + + // Check if we have an OrchestrationTraceContext from a previous replay + const existingSpanId = orchestrationTraceContext?.getSpanid()?.getValue(); + const existingStartTime = orchestrationTraceContext?.getSpanstarttime()?.toDate(); + const isReplay = !!(existingSpanId && existingStartTime); + + // Always use the current time for the OTEL span start so that replay spans + // don't appear artificially long (the original start may be days/months ago). + const spanStartTime = new Date(); + + // The persisted startTime in OrchestrationSpanInfo keeps the original + // first-execution time for storage in OrchestrationTraceContext. + const persistedStartTime = isReplay ? existingStartTime! : spanStartTime; + + const span = tracer.startSpan( + spanName, + { + kind: otel.SpanKind.SERVER, + startTime: spanStartTime, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.ORCHESTRATION, + [DurableTaskAttributes.TASK_NAME]: name, + [DurableTaskAttributes.TASK_INSTANCE_ID]: instanceId, + ...(version ? { [DurableTaskAttributes.TASK_VERSION]: version } : {}), + }, + }, + parentContext, + ); + + let spanId: string; + if (isReplay) { + // Replay: carry forward the original span ID as a correlation identifier. + // The OTEL span gets its own new spanId (we cannot override it), so we + // store the original as an attribute for cross-replay correlation. + spanId = existingSpanId!; + span.setAttribute(DurableTaskAttributes.REPLAY_SPAN_ID, spanId); + // Record the original execution start time as an attribute for correlation, + // since the OTEL span itself starts at the current time. + span.setAttribute(DurableTaskAttributes.REPLAY_START_TIME, existingStartTime!.toISOString()); + } else { + // First execution: use the actual OTEL span ID so the stored identifier + // matches the real span that appears in traces. + spanId = span.spanContext().spanId; + } + + return { + span, + spanInfo: { spanId, startTime: persistedStartTime }, + }; +} + +/** + * Creates a Client span for scheduling an activity task (worker-side, within orchestration execution). + * Injects trace context into the ScheduleTaskAction. + * + * @param orchestrationSpan - The parent orchestration span. + * @param action - The ScheduleTaskAction to inject trace context into. + * @param taskId - The sequential task ID. + */ +export function startSpanForSchedulingTask( + orchestrationSpan: Span, + action: pb.ScheduleTaskAction, + taskId: number, +): void { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return; + + const name = action.getName(); + const version = action.getVersion()?.getValue(); + const spanName = createSpanName(TaskType.ACTIVITY, name, version); + + // Create a context with the orchestration span as parent + const parentContext = otel.trace.setSpan(otel.context.active(), orchestrationSpan); + + const span = tracer.startSpan( + spanName, + { + kind: otel.SpanKind.CLIENT, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.ACTIVITY, + [DurableTaskAttributes.TASK_NAME]: name, + [DurableTaskAttributes.TASK_TASK_ID]: taskId, + ...(version ? { [DurableTaskAttributes.TASK_VERSION]: version } : {}), + }, + }, + parentContext, + ); + + // Inject trace context into the action + const traceInfo = extractTraceparentFromSpan(span); + if (traceInfo) { + const pbCtx = createPbTraceContext(traceInfo.traceparent, traceInfo.tracestate); + action.setParenttracecontext(pbCtx); + } + + // End the span immediately - it represents the act of scheduling, not execution + span.end(); +} + +/** + * Creates a Server span for activity task execution (worker-side). + * + * @param req - The ActivityRequest containing the parent trace context. + * @returns The span (or undefined if OTEL is not available). Caller must end it. + */ +export function startSpanForTaskExecution(req: pb.ActivityRequest): Span | undefined { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return undefined; + + const name = req.getName(); + const spanName = createSpanName(TaskType.ACTIVITY, name); + + const parentPbCtx = req.getParenttracecontext(); + const parentContext = createParentContextFromPb(parentPbCtx); + + const instanceId = req.getOrchestrationinstance()?.getInstanceid() ?? ""; + + const span = tracer.startSpan( + spanName, + { + kind: otel.SpanKind.SERVER, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.ACTIVITY, + [DurableTaskAttributes.TASK_NAME]: name, + [DurableTaskAttributes.TASK_INSTANCE_ID]: instanceId, + [DurableTaskAttributes.TASK_TASK_ID]: req.getTaskid(), + }, + }, + parentContext, + ); + + return span; +} + +/** + * Creates a Client span for scheduling a sub-orchestration (worker-side, within orchestration execution). + * Injects trace context into the CreateSubOrchestrationAction. + * + * @param orchestrationSpan - The parent orchestration span. + * @param action - The CreateSubOrchestrationAction to inject trace context into. + * @param taskId - The sequential task ID. + */ +export function startSpanForSchedulingSubOrchestration( + orchestrationSpan: Span, + action: pb.CreateSubOrchestrationAction, + taskId: number, +): void { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return; + + const name = action.getName(); + const version = action.getVersion()?.getValue(); + const instanceId = action.getInstanceid(); + const spanName = createSpanName(TaskType.CREATE_ORCHESTRATION, name, version); + + const parentContext = otel.trace.setSpan(otel.context.active(), orchestrationSpan); + + const span = tracer.startSpan( + spanName, + { + kind: otel.SpanKind.CLIENT, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.CREATE_ORCHESTRATION, + [DurableTaskAttributes.TASK_NAME]: name, + [DurableTaskAttributes.TASK_INSTANCE_ID]: instanceId, + [DurableTaskAttributes.TASK_TASK_ID]: taskId, + ...(version ? { [DurableTaskAttributes.TASK_VERSION]: version } : {}), + }, + }, + parentContext, + ); + + // Inject trace context into the action + const traceInfo = extractTraceparentFromSpan(span); + if (traceInfo) { + const pbCtx = createPbTraceContext(traceInfo.traceparent, traceInfo.tracestate); + action.setParenttracecontext(pbCtx); + } + + // End the span immediately - it represents the act of scheduling + span.end(); +} + +/** + * Emits a span for a timer being created within an orchestration. + * + * @param orchestrationSpan - The parent orchestration span. + * @param orchestrationName - The name of the parent orchestration. + * @param fireAt - When the timer fires. + * @param timerId - The timer's sequential ID. + */ +export function emitSpanForTimer( + orchestrationSpan: Span, + orchestrationName: string, + fireAt: Date, + timerId: number, +): void { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return; + + const spanName = createTimerSpanName(orchestrationName); + const parentContext = otel.trace.setSpan(otel.context.active(), orchestrationSpan); + + const span = tracer.startSpan( + spanName, + { + kind: otel.SpanKind.INTERNAL, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.TIMER, + [DurableTaskAttributes.TASK_TASK_ID]: timerId, + [DurableTaskAttributes.FIRE_AT]: fireAt.toISOString(), + }, + }, + parentContext, + ); + + span.end(); +} + +/** + * Emits a span for sending an event to another orchestration. + * + * @param orchestrationSpan - The parent orchestration span. + * @param eventName - The name of the event. + * @param targetInstanceId - The target orchestration instance ID. + */ +export function emitSpanForEventSent( + orchestrationSpan: Span, + eventName: string, + targetInstanceId?: string, +): void { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return; + + const spanName = createSpanName(TaskType.ORCHESTRATION_EVENT, eventName); + const parentContext = otel.trace.setSpan(otel.context.active(), orchestrationSpan); + + const span = tracer.startSpan( + spanName, + { + kind: otel.SpanKind.PRODUCER, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.ORCHESTRATION_EVENT, + [DurableTaskAttributes.TASK_NAME]: eventName, + ...(targetInstanceId ? { [DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID]: targetInstanceId } : {}), + }, + }, + parentContext, + ); + + span.end(); +} + +/** + * Creates a Producer span for raising an event from the client. + * + * @param eventName - The name of the event. + * @param instanceId - The target orchestration instance ID. + * @returns The span (or undefined if OTEL is not available). Caller must end it. + */ +export function startSpanForEventRaisedFromClient(eventName: string, instanceId: string): Span | undefined { + const otel = getOtelApi(); + const tracer = getTracer(); + if (!otel || !tracer) return undefined; + + const spanName = createSpanName(TaskType.ORCHESTRATION_EVENT, eventName); + + const span = tracer.startSpan(spanName, { + kind: otel.SpanKind.PRODUCER, + attributes: { + [DurableTaskAttributes.TYPE]: TaskType.ORCHESTRATION_EVENT, + [DurableTaskAttributes.TASK_NAME]: eventName, + [DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID]: instanceId, + }, + }); + + return span; +} + +/** + * Sets span status to error and records the error. + * + * @param span - The span to set error status on. + * @param error - The error to record. + */ +export function setSpanError(span: Span | undefined | null, error: unknown): void { + const otel = getOtelApi(); + if (!otel || !span) return; + + const message = + typeof error === "string" ? error : error instanceof Error ? error.message : String(error); + span.setStatus({ code: otel.SpanStatusCode.ERROR, message }); + if (error instanceof Error) { + span.recordException(error); + } +} + +/** + * Sets span status to OK. + * + * @param span - The span to set OK status on. + */ +export function setSpanOk(span: Span | undefined | null): void { + const otel = getOtelApi(); + if (!otel || !span) return; + + span.setStatus({ code: otel.SpanStatusCode.OK }); +} + +/** + * Safely ends a span, ignoring errors. + * + * @param span - The span to end. + */ +export function endSpan(span: Span | undefined | null): void { + if (!span) return; + try { + span.end(); + } catch { + // Ignore errors when ending spans + } +} + +/** + * Creates an OrchestrationTraceContext protobuf message for the orchestrator response. + * + * @param spanInfo - The span info to encode. + * @returns The OrchestrationTraceContext protobuf message. + */ +export function createOrchestrationTraceContextPb(spanInfo: OrchestrationSpanInfo): pb.OrchestrationTraceContext { + const orchTraceCtx = new pb.OrchestrationTraceContext(); + + const spanIdValue = new StringValue(); + spanIdValue.setValue(spanInfo.spanId); + orchTraceCtx.setSpanid(spanIdValue); + + const startTimestamp = new Timestamp(); + startTimestamp.fromDate(spanInfo.startTime); + orchTraceCtx.setSpanstarttime(startTimestamp); + + return orchTraceCtx; +} + +/** + * Processes orchestrator actions to inject trace context for distributed tracing. + * This is called after the orchestration executor returns its actions. + * + * @param orchestrationSpan - The orchestration span (parent for action spans). + * @param actions - The OrchestratorAction list to process. + * @param orchestrationName - The name of the orchestration (for timer spans). + */ +export function processActionsForTracing( + orchestrationSpan: Span | undefined | null, + actions: pb.OrchestratorAction[], + orchestrationName: string, +): void { + if (!orchestrationSpan) return; + + for (const action of actions) { + if (action.hasScheduletask()) { + const scheduleTask = action.getScheduletask()!; + startSpanForSchedulingTask(orchestrationSpan, scheduleTask, action.getId()); + } else if (action.hasCreatesuborchestration()) { + const createSubOrch = action.getCreatesuborchestration()!; + startSpanForSchedulingSubOrchestration(orchestrationSpan, createSubOrch, action.getId()); + } else if (action.hasCreatetimer()) { + const createTimer = action.getCreatetimer()!; + const fireAt = createTimer.getFireat()?.toDate() ?? new Date(); + emitSpanForTimer(orchestrationSpan, orchestrationName, fireAt, action.getId()); + } else if (action.hasSendevent()) { + const sendEvent = action.getSendevent()!; + emitSpanForEventSent(orchestrationSpan, sendEvent.getName(), sendEvent.getInstance()?.getInstanceid()); + } + } +} diff --git a/packages/durabletask-js/src/types/logger.type.ts b/packages/durabletask-js/src/types/logger.type.ts index 7b6690c..55be420 100644 --- a/packages/durabletask-js/src/types/logger.type.ts +++ b/packages/durabletask-js/src/types/logger.type.ts @@ -1,9 +1,33 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. +/** + * Structured log event metadata, matching the .NET Durable Task SDK logging pattern. + * + * Each log message in the SDK is associated with a unique event ID and a category, + * consistent with the `[LoggerMessage]` pattern used in the .NET SDK. + * + * @example + * ```typescript + * const event: LogEvent = { + * eventId: 600, + * category: "Microsoft.DurableTask.Worker.Orchestrations", + * properties: { instanceId: "abc123", name: "MyOrchestrator" }, + * }; + * ``` + */ +export interface LogEvent { + /** Unique numeric event ID matching the .NET SDK event IDs for cross-SDK log correlation. */ + eventId: number; + /** Hierarchical logger category (e.g., "Microsoft.DurableTask.Worker.Orchestrations"). */ + category: string; + /** Structured properties captured as key-value pairs for log filtering and analysis. */ + properties?: Record; +} + /** * Logger interface for the Durable Task SDK. - * + * * Users can implement this interface to integrate their own logging framework * (e.g., Winston, Pino, Azure Logger) with the SDK. */ @@ -37,12 +61,92 @@ export interface Logger { debug(message: string, ...args: unknown[]): void; } +/** + * Extended logger interface that supports structured log events with event IDs, + * categories, and structured properties. + * + * This interface extends the base {@link Logger} to provide structured logging + * capabilities matching the .NET Durable Task SDK pattern. Consumers that implement + * only the base {@link Logger} interface will continue to work — the SDK's centralized + * log functions detect `StructuredLogger` support at runtime and fall back to + * plain string logging when structured logging is unavailable. + * + * @example + * ```typescript + * class MyStructuredLogger implements StructuredLogger { + * error(message: string, ...args: unknown[]): void { ... } + * warn(message: string, ...args: unknown[]): void { ... } + * info(message: string, ...args: unknown[]): void { ... } + * debug(message: string, ...args: unknown[]): void { ... } + * logEvent(level: "error" | "warn" | "info" | "debug", event: LogEvent, message: string): void { + * // Forward to your structured logging backend + * } + * } + * ``` + */ +export interface StructuredLogger extends Logger { + /** + * Logs a message with structured event metadata. + * + * @param level - The log level ("error", "warn", "info", "debug"). + * @param event - Structured event metadata including eventId, category, and properties. + * @param message - The formatted log message string. + */ + logEvent(level: "error" | "warn" | "info" | "debug", event: LogEvent, message: string): void; +} + +/** + * Type guard to check if a Logger instance supports structured logging. + * + * @param logger - The logger to check. + * @returns `true` if the logger implements {@link StructuredLogger}. + */ +export function isStructuredLogger(logger: Logger): logger is StructuredLogger { + return typeof (logger as StructuredLogger).logEvent === "function"; +} + +/** + * Creates a `logEvent` handler that formats structured log events with a + * `[eventId] [category]` prefix and dispatches to the provided log functions. + * + * This allows different logging backends (Console, Azure Logger, etc.) to share + * the same formatting and dispatch logic without duplication. + * + * @param logFns - A map of log-level names to their corresponding output functions. + * @returns A function with the same signature as {@link StructuredLogger.logEvent}. + */ +export function createLogEventHandler( + logFns: Record<"error" | "warn" | "info" | "debug", (message: string, ...args: unknown[]) => void>, +): (level: "error" | "warn" | "info" | "debug", event: LogEvent, message: string) => void { + return (level, event, message) => { + const prefix = `[${event.eventId}] [${event.category}]`; + const fullMessage = `${prefix} ${message}`; + const logFn = logFns[level]; + if (event.properties != null && Object.keys(event.properties).length > 0) { + logFn(fullMessage, event.properties); + } else { + logFn(fullMessage); + } + }; +} + /** * Default logger implementation that delegates to the console. - * + * * This is the default logger used by the SDK when no custom logger is provided. + * It implements {@link StructuredLogger} to support structured log output. + * + * When structured log events are emitted, the console output includes the event ID + * and category prefix for easy filtering, matching the .NET SDK's output pattern. */ -export class ConsoleLogger implements Logger { +export class ConsoleLogger implements StructuredLogger { + private _logEventHandler = createLogEventHandler({ + error: (msg: string, ...args: unknown[]) => console.error(msg, ...args), + warn: (msg: string, ...args: unknown[]) => console.warn(msg, ...args), + info: (msg: string, ...args: unknown[]) => console.info(msg, ...args), + debug: (msg: string, ...args: unknown[]) => console.debug(msg, ...args), + }); + error(message: string, ...args: unknown[]): void { console.error(message, ...args); } @@ -58,14 +162,18 @@ export class ConsoleLogger implements Logger { debug(message: string, ...args: unknown[]): void { console.debug(message, ...args); } + + logEvent(level: "error" | "warn" | "info" | "debug", event: LogEvent, message: string): void { + this._logEventHandler(level, event, message); + } } /** * A no-op logger that silently discards all log messages. - * + * * Useful for testing or when logging should be disabled. */ -export class NoOpLogger implements Logger { +export class NoOpLogger implements StructuredLogger { error(_message: string, ..._args: unknown[]): void { // No-op } @@ -81,4 +189,12 @@ export class NoOpLogger implements Logger { debug(_message: string, ..._args: unknown[]): void { // No-op } + + logEvent( + _level: "error" | "warn" | "info" | "debug", + _event: LogEvent, + _message: string, + ): void { + // No-op + } } diff --git a/packages/durabletask-js/src/types/replay-safe-logger.ts b/packages/durabletask-js/src/types/replay-safe-logger.ts index af3b31d..2c16be8 100644 --- a/packages/durabletask-js/src/types/replay-safe-logger.ts +++ b/packages/durabletask-js/src/types/replay-safe-logger.ts @@ -1,7 +1,7 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. -import { Logger } from "./logger.type"; +import { Logger, StructuredLogger, LogEvent, isStructuredLogger } from "./logger.type"; /** * Interface representing a context that can determine if replay is occurring. @@ -22,6 +22,9 @@ export interface ReplayContext { * wraps an existing logger and automatically suppresses log output during replay, * ensuring that logs are only written once when the orchestration is making forward progress. * + * If the wrapped logger implements {@link StructuredLogger}, structured log events + * will also be forwarded (and suppressed during replay). + * * @example * ```typescript * // Inside an orchestrator function: @@ -29,7 +32,7 @@ export interface ReplayContext { * logger.info("This will only be logged once, not during replay"); * ``` */ -export class ReplaySafeLogger implements Logger { +export class ReplaySafeLogger implements StructuredLogger { private readonly context: ReplayContext; private readonly innerLogger: Logger; @@ -93,4 +96,23 @@ export class ReplaySafeLogger implements Logger { this.innerLogger.debug(message, ...args); } } + + /** + * Logs a structured event if not replaying. + * If the inner logger supports structured logging, delegates to its `logEvent` method. + * Otherwise, falls back to the appropriate plain log method. + * + * @param level - The log level. + * @param event - Structured event metadata. + * @param message - The formatted log message. + */ + logEvent(level: "error" | "warn" | "info" | "debug", event: LogEvent, message: string): void { + if (!this.context.isReplaying) { + if (isStructuredLogger(this.innerLogger)) { + this.innerLogger.logEvent(level, event, message); + } else { + this.innerLogger[level](message); + } + } + } } diff --git a/packages/durabletask-js/src/utils/emit-log.ts b/packages/durabletask-js/src/utils/emit-log.ts new file mode 100644 index 0000000..44575f8 --- /dev/null +++ b/packages/durabletask-js/src/utils/emit-log.ts @@ -0,0 +1,31 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import { Logger, LogEvent, isStructuredLogger } from "../types/logger.type"; + +/** + * Emits a log message, using structured logging when the logger supports it. + * + * If the logger implements {@link StructuredLogger}, the event metadata (eventId, + * category, properties) is forwarded via `logEvent()`. Otherwise, the message is + * logged via the plain `Logger` method for the given level. + * + * @param logger - The logger instance. + * @param level - The log level. + * @param event - Structured event metadata. + * @param message - The formatted log message string. + * + * @internal + */ +export function emitLog( + logger: Logger, + level: "error" | "warn" | "info" | "debug", + event: LogEvent, + message: string, +): void { + if (isStructuredLogger(logger)) { + logger.logEvent(level, event, message); + } else { + logger[level](message); + } +} diff --git a/packages/durabletask-js/src/utils/error.util.ts b/packages/durabletask-js/src/utils/error.util.ts new file mode 100644 index 0000000..3d700be --- /dev/null +++ b/packages/durabletask-js/src/utils/error.util.ts @@ -0,0 +1,34 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +/** + * Safely extracts a human-readable message from an unknown error value. + * + * This utility eliminates the repeated `error instanceof Error ? error.message : String(error)` + * pattern used throughout the codebase for safe error-to-string conversion. + * + * @param error - The error value to extract a message from (may be an Error, string, or any other type). + * @returns The error message string. + */ +export function toErrorMessage(error: unknown): string { + if (error instanceof Error) { + return error.message; + } + + if (typeof error === "string") { + return error; + } + + if (error && typeof error === "object") { + try { + const json = JSON.stringify(error); + if (json) { + return json; + } + } catch { + // Ignore JSON serialization errors and fall through to the generic fallback below. + } + } + + return String(error); +} diff --git a/packages/durabletask-js/src/utils/history-event-converter.ts b/packages/durabletask-js/src/utils/history-event-converter.ts index 73a74f9..f89a1e6 100644 --- a/packages/durabletask-js/src/utils/history-event-converter.ts +++ b/packages/durabletask-js/src/utils/history-event-converter.ts @@ -46,6 +46,7 @@ export function convertProtoHistoryEvent(protoEvent: pb.HistoryEvent): HistoryEv const parentInfo = event.getParentinstance(); const scheduledTime = event.getScheduledstarttimestamp(); const tagsMap = event.getTagsMap(); + const traceCtx = event.getParenttracecontext(); return { eventId, @@ -58,6 +59,8 @@ export function convertProtoHistoryEvent(protoEvent: pb.HistoryEvent): HistoryEv parentInstance: parentInfo ? convertParentInstanceInfo(parentInfo) : undefined, scheduledStartTimestamp: scheduledTime ? scheduledTime.toDate() : undefined, tags: tagsMap ? convertTagsMap(tagsMap) : undefined, + parentTraceContext: traceCtx ? convertTraceContext(traceCtx) : undefined, + orchestrationSpanId: event.getOrchestrationspanid()?.getValue(), }; } @@ -141,6 +144,7 @@ export function convertProtoHistoryEvent(protoEvent: pb.HistoryEvent): HistoryEv if (!event) return undefined; const tagsMap = event.getTagsMap(); + const traceCtx = event.getParenttracecontext(); return { eventId, @@ -150,6 +154,7 @@ export function convertProtoHistoryEvent(protoEvent: pb.HistoryEvent): HistoryEv version: event.getVersion()?.getValue(), input: event.getInput()?.getValue(), tags: tagsMap ? convertTagsMap(tagsMap) : undefined, + parentTraceContext: traceCtx ? convertTraceContext(traceCtx) : undefined, }; } @@ -184,6 +189,7 @@ export function convertProtoHistoryEvent(protoEvent: pb.HistoryEvent): HistoryEv if (!event) return undefined; const tagsMap = event.getTagsMap(); + const traceCtx = event.getParenttracecontext(); return { eventId, @@ -194,6 +200,7 @@ export function convertProtoHistoryEvent(protoEvent: pb.HistoryEvent): HistoryEv instanceId: event.getInstanceid(), input: event.getInput()?.getValue(), tags: tagsMap ? convertTagsMap(tagsMap) : undefined, + parentTraceContext: traceCtx ? convertTraceContext(traceCtx) : undefined, }; } diff --git a/packages/durabletask-js/src/utils/pb-helper.util.ts b/packages/durabletask-js/src/utils/pb-helper.util.ts index 731d04f..1b9303f 100644 --- a/packages/durabletask-js/src/utils/pb-helper.util.ts +++ b/packages/durabletask-js/src/utils/pb-helper.util.ts @@ -181,15 +181,21 @@ export function newSubOrchestrationFailedEvent(eventId: number, ex: Error): pb.H return event; } -export function newFailureDetails(e: any): pb.TaskFailureDetails { +export function newFailureDetails(e: unknown): pb.TaskFailureDetails { const failure = new pb.TaskFailureDetails(); - failure.setErrortype(e.constructor.name); - failure.setErrormessage(e.message); - // Construct a google_protobuf_wrappers_pb.StringValue - const stringValueStackTrace = new StringValue(); - stringValueStackTrace.setValue(e.stack?.toString() ?? ""); - failure.setStacktrace(stringValueStackTrace); + const errorType = e instanceof Error ? e.constructor.name : "UnknownError"; + const errorMessage = e instanceof Error ? e.message : String(e); + const stack = e instanceof Error ? e.stack : undefined; + + failure.setErrortype(errorType); + failure.setErrormessage(errorMessage); + + if (stack !== undefined) { + const sv = new StringValue(); + sv.setValue(stack); + failure.setStacktrace(sv); + } return failure; } @@ -407,19 +413,20 @@ export function isEmpty(v?: StringValue | null): boolean { return v == null || v.getValue() === ""; } +// Pre-built reverse map for O(1) orchestration status string lookups +const orchestrationStatusStrMap = new Map(); +for (const [name, value] of Object.entries(pb.OrchestrationStatus)) { + if (typeof value === "number" && name.startsWith("ORCHESTRATION_STATUS_")) { + orchestrationStatusStrMap.set(value, name.slice("ORCHESTRATION_STATUS_".length)); + } +} + /** - * Get the orchstration status by the enum value of the status + * Get the orchestration status string by the enum value of the status * * @param status * @returns */ export function getOrchestrationStatusStr(status: number): string { - const idx = Object.values(pb.OrchestrationStatus).indexOf(status); - const name = Object.keys(pb.OrchestrationStatus)[idx]; - - if (name?.startsWith("ORCHESTRATION_STATUS_")) { - return name.slice("ORCHESTRATION_STATUS_".length); - } - - return "UNKNOWN"; + return orchestrationStatusStrMap.get(status) ?? "UNKNOWN"; } diff --git a/packages/durabletask-js/src/utils/promise.util.ts b/packages/durabletask-js/src/utils/promise.util.ts deleted file mode 100644 index a98364c..0000000 --- a/packages/durabletask-js/src/utils/promise.util.ts +++ /dev/null @@ -1,6 +0,0 @@ -// Copyright (c) Microsoft Corporation. All rights reserved. -// Licensed under the MIT License. - -export function isPromise(fn: any): boolean { - return fn && typeof fn?.then === "function"; -} diff --git a/packages/durabletask-js/src/utils/timeout.util.ts b/packages/durabletask-js/src/utils/timeout.util.ts new file mode 100644 index 0000000..c2453da --- /dev/null +++ b/packages/durabletask-js/src/utils/timeout.util.ts @@ -0,0 +1,46 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import { TimeoutError } from "../exception/timeout-error"; + +/** + * Races a promise against a timeout, throwing a {@link TimeoutError} if the + * timeout expires first. The timer is always cleaned up regardless of outcome. + * + * @param promise - The promise to race against the timeout. + * @param timeoutMs - The timeout duration in milliseconds. + * @param makeErrorMessage - A function that returns the error message for the TimeoutError. + * @returns The resolved value of the promise if it settles before the timeout. + */ +export async function raceWithTimeout( + promise: Promise, + timeoutMs: number, + makeErrorMessage: () => string, +): Promise { + if (!Number.isFinite(timeoutMs) || timeoutMs < 0) { + throw new RangeError(`timeoutMs must be a finite number >= 0, got ${timeoutMs}`); + } + + let timer: ReturnType | undefined; + + try { + return await (Promise.race([ + promise, + new Promise((_, reject) => { + timer = setTimeout(() => { + let message: string; + try { + message = makeErrorMessage(); + } catch { + message = `Operation timed out after ${timeoutMs}ms`; + } + reject(new TimeoutError(message)); + }, timeoutMs); + }), + ]) as Promise); + } finally { + if (timer) { + clearTimeout(timer); + } + } +} diff --git a/packages/durabletask-js/src/worker/activity-executor.ts b/packages/durabletask-js/src/worker/activity-executor.ts index 399ca94..079b9a0 100644 --- a/packages/durabletask-js/src/worker/activity-executor.ts +++ b/packages/durabletask-js/src/worker/activity-executor.ts @@ -6,6 +6,7 @@ import { ActivityContext } from "../task/context/activity-context"; import { Logger, ConsoleLogger } from "../types/logger.type"; import { ActivityNotRegisteredError } from "./exception/activity-not-registered-error"; import { Registry } from "./registry"; +import * as WorkerLogs from "./logs"; export class ActivityExecutor { private _registry: Registry; @@ -28,21 +29,32 @@ export class ActivityExecutor { throw new ActivityNotRegisteredError(name); } + // Log activity start (EventId 603) + WorkerLogs.activityStarted(this._logger, orchestrationId, name); + const activityInput = encodedInput ? JSON.parse(encodedInput) : undefined; const ctx = new ActivityContext(orchestrationId, taskId); - // Execute the activity function - let activityOutput = fn(ctx, activityInput); + try { + // Execute the activity function + let activityOutput = fn(ctx, activityInput); - if (isPromise(activityOutput)) { - activityOutput = await activityOutput; - } + if (isPromise(activityOutput)) { + activityOutput = await activityOutput; + } - // Return the output - const encodedOutput = activityOutput ? JSON.stringify(activityOutput) : undefined; - const chars = encodedOutput ? encodedOutput.length : 0; - this._logger.info(`Activity ${name} completed (${chars} chars)`); + // Return the output + const encodedOutput = activityOutput ? JSON.stringify(activityOutput) : undefined; - return encodedOutput; + // Log activity completion (EventId 604) + WorkerLogs.activityCompleted(this._logger, orchestrationId, name); + + return encodedOutput; + } catch (e: unknown) { + const err = e instanceof Error ? e : new Error(String(e)); + // Log activity failure (EventId 605) + WorkerLogs.activityFailed(this._logger, orchestrationId, name, err); + throw err; + } } } diff --git a/packages/durabletask-js/src/worker/logs.ts b/packages/durabletask-js/src/worker/logs.ts new file mode 100644 index 0000000..a8aa0fb --- /dev/null +++ b/packages/durabletask-js/src/worker/logs.ts @@ -0,0 +1,466 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +/** + * Centralized log definitions for the Durable Task Worker. + * + * Event IDs and message templates are aligned with the .NET Durable Task SDK + * (see: https://github.com/microsoft/durabletask-dotnet/blob/main/src/Worker/Core/Logs.cs). + * + * Event ID ranges: + * - 15: Entity operation errors (from .NET) + * - 55: Retry handler evaluation (from .NET) + * - 600–605: Core orchestration/activity lifecycle (from .NET) + * - 700–799: JS-specific worker lifecycle events + */ + +import { Logger } from "../types/logger.type"; +import { emitLog } from "../utils/emit-log"; +import { toErrorMessage } from "../utils/error.util"; + +// ── Logger categories (matching .NET: Microsoft.DurableTask.Worker.*) ──────── + +/** Category for orchestration-related logs. */ +const CATEGORY_ORCHESTRATIONS = "Microsoft.DurableTask.Worker.Orchestrations"; + +/** Category for activity-related logs. */ +const CATEGORY_ACTIVITIES = "Microsoft.DurableTask.Worker.Activities"; + +/** Category for general worker logs. */ +const CATEGORY_WORKER = "Microsoft.DurableTask.Worker"; + +// ── Event IDs (matching .NET) ──────────────────────────────────────────────── + +/** @internal */ export const EVENT_RETRYING_TASK = 55; +/** @internal */ export const EVENT_ORCHESTRATION_STARTED = 600; +/** @internal */ export const EVENT_ORCHESTRATION_COMPLETED = 601; +/** @internal */ export const EVENT_ORCHESTRATION_FAILED = 602; +/** @internal */ export const EVENT_ACTIVITY_STARTED = 603; +/** @internal */ export const EVENT_ACTIVITY_COMPLETED = 604; +/** @internal */ export const EVENT_ACTIVITY_FAILED = 605; + +// ── JS-specific Event IDs (700+ range) ────────────────────────────────────── + +/** @internal */ export const EVENT_WORKER_CONNECTED = 700; +/** @internal */ export const EVENT_WORKER_ERROR = 701; +/** @internal */ export const EVENT_STREAM_ENDED = 702; +/** @internal */ export const EVENT_STREAM_RETRY = 703; +/** @internal */ export const EVENT_STREAM_ERROR = 704; +/** @internal */ export const EVENT_WORK_ITEM_RECEIVED = 705; +/** @internal */ export const EVENT_SHUTDOWN_WAITING = 706; +/** @internal */ export const EVENT_SHUTDOWN_COMPLETED = 707; +/** @internal */ export const EVENT_SHUTDOWN_TIMEOUT = 708; +/** @internal */ export const EVENT_CONNECTION_RETRY = 709; +/** @internal */ export const EVENT_ORCHESTRATION_REBUILDING = 710; +/** @internal */ export const EVENT_ORCHESTRATION_PROCESSING = 711; +/** @internal */ export const EVENT_ORCHESTRATION_WAITING = 712; +/** @internal */ export const EVENT_ORCHESTRATION_RETURNING_ACTIONS = 713; +/** @internal */ export const EVENT_ORCHESTRATION_SUSPENDED = 714; +/** @internal */ export const EVENT_ORCHESTRATION_TERMINATED = 715; +/** @internal */ export const EVENT_ORCHESTRATION_EVENT_RAISED = 716; +/** @internal */ export const EVENT_ORCHESTRATION_EVENT_BUFFERED = 717; +/** @internal */ export const EVENT_ORCHESTRATION_NO_TASKS = 718; +/** @internal */ export const EVENT_ORCHESTRATION_PROCESSING_EVENT = 719; +/** @internal */ export const EVENT_ORCHESTRATION_SUSPENDED_BUFFERING = 720; +/** @internal */ export const EVENT_ORCHESTRATION_UNKNOWN_EVENT = 721; +/** @internal */ export const EVENT_ORCHESTRATION_EVENT_ERROR = 722; +/** @internal */ export const EVENT_ORCHESTRATION_UNEXPECTED_EVENT = 723; +/** @internal */ export const EVENT_UNKNOWN_WORK_ITEM = 724; +/** @internal */ export const EVENT_VERSION_MISMATCH_FAIL = 730; +/** @internal */ export const EVENT_VERSION_MISMATCH_ABANDON = 731; +/** @internal */ export const EVENT_EXECUTION_ERROR = 732; +/** @internal */ export const EVENT_COMPLETION_ERROR = 733; +/** @internal */ export const EVENT_ACTIVITY_EXECUTION_ERROR = 734; +/** @internal */ export const EVENT_ACTIVITY_RESPONSE_ERROR = 735; +/** @internal */ export const EVENT_STREAM_ERROR_INFO = 736; + +// ═══════════════════════════════════════════════════════════════════════════════ +// Orchestration Lifecycle Logs (Event IDs 600–602, matching .NET) +// ═══════════════════════════════════════════════════════════════════════════════ + +/** + * Logs that an orchestration has started execution. + * Matches .NET EventId 600: "'{Name}' orchestration with ID '{InstanceId}' started." + */ +export function orchestrationStarted(logger: Logger, instanceId: string, name: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_STARTED, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, name }, + }, `'${name}' orchestration with ID '${instanceId}' started.`); +} + +/** + * Logs that an orchestration has completed execution. + * Matches .NET EventId 601: "'{Name}' orchestration with ID '{InstanceId}' completed." + */ +export function orchestrationCompleted(logger: Logger, instanceId: string, name: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_COMPLETED, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, name }, + }, `'${name}' orchestration with ID '${instanceId}' completed.`); +} + +/** + * Logs that an orchestration has failed. + * Matches .NET EventId 602: "'{Name}' orchestration with ID '{InstanceId}' failed." + */ +export function orchestrationFailed(logger: Logger, instanceId: string, name: string, error?: Error): void { + emitLog(logger, "error", { + eventId: EVENT_ORCHESTRATION_FAILED, + category: CATEGORY_ORCHESTRATIONS, + properties: { + instanceId, + name, + error: error?.message, + ...(error instanceof Error && error.stack ? { stack: error.stack } : {}), + }, + }, `'${name}' orchestration with ID '${instanceId}' failed.`); +} + +// ═══════════════════════════════════════════════════════════════════════════════ +// Activity Lifecycle Logs (Event IDs 603–605, matching .NET) +// ═══════════════════════════════════════════════════════════════════════════════ + +/** + * Logs that an activity has started execution. + * Matches .NET EventId 603: "'{Name}' activity of orchestration ID '{InstanceId}' started." + */ +export function activityStarted(logger: Logger, instanceId: string, name: string): void { + emitLog(logger, "info", { + eventId: EVENT_ACTIVITY_STARTED, + category: CATEGORY_ACTIVITIES, + properties: { instanceId, name }, + }, `'${name}' activity of orchestration ID '${instanceId}' started.`); +} + +/** + * Logs that an activity has completed execution. + * Matches .NET EventId 604: "'{Name}' activity of orchestration ID '{InstanceId}' completed." + */ +export function activityCompleted(logger: Logger, instanceId: string, name: string): void { + emitLog(logger, "info", { + eventId: EVENT_ACTIVITY_COMPLETED, + category: CATEGORY_ACTIVITIES, + properties: { instanceId, name }, + }, `'${name}' activity of orchestration ID '${instanceId}' completed.`); +} + +/** + * Logs that an activity has failed. + * Matches .NET EventId 605: "'{Name}' activity of orchestration ID '{InstanceId}' failed." + */ +export function activityFailed(logger: Logger, instanceId: string, name: string, error?: Error): void { + emitLog(logger, "error", { + eventId: EVENT_ACTIVITY_FAILED, + category: CATEGORY_ACTIVITIES, + properties: { + instanceId, + name, + error: error?.message, + errorDetails: error ? toErrorMessage(error) : undefined, + errorStack: error?.stack, + }, + }, `'${name}' activity of orchestration ID '${instanceId}' failed.`); +} + +// ═══════════════════════════════════════════════════════════════════════════════ +// Retry Logs (Event ID 55, matching .NET) +// ═══════════════════════════════════════════════════════════════════════════════ + +/** + * Logs that a failed task is being retried. + * Matches .NET EventId 55: "{instanceId}: Evaluating custom retry handler for failed '{name}' task. Attempt = {attempt}." + */ +export function retryingTask(logger: Logger, instanceId: string, name: string, attempt: number): void { + emitLog(logger, "info", { + eventId: EVENT_RETRYING_TASK, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, name, attempt }, + }, `${instanceId}: Evaluating custom retry handler for failed '${name}' task. Attempt = ${attempt}.`); +} + +// ═══════════════════════════════════════════════════════════════════════════════ +// JS-specific Worker Lifecycle Logs (Event IDs 700+) +// ═══════════════════════════════════════════════════════════════════════════════ + +export function workerConnected(logger: Logger, hostAddress: string): void { + emitLog(logger, "info", { + eventId: EVENT_WORKER_CONNECTED, + category: CATEGORY_WORKER, + properties: { hostAddress }, + }, `Successfully connected to ${hostAddress}. Waiting for work items...`); +} + +export function workerError(logger: Logger, error: unknown): void { + const msg = toErrorMessage(error); + emitLog(logger, "error", { + eventId: EVENT_WORKER_ERROR, + category: CATEGORY_WORKER, + properties: { error: msg }, + }, `Worker error: ${msg}`); +} + +export function streamEnded(logger: Logger): void { + emitLog(logger, "info", { + eventId: EVENT_STREAM_ENDED, + category: CATEGORY_WORKER, + }, "Stream ended"); +} + +export function streamRetry(logger: Logger, delayMs: number): void { + emitLog(logger, "info", { + eventId: EVENT_STREAM_RETRY, + category: CATEGORY_WORKER, + properties: { delayMs }, + }, `Stream abruptly closed, will retry in ${delayMs}ms...`); +} + +export function streamError(logger: Logger, error: unknown): void { + const msg = toErrorMessage(error); + emitLog(logger, "error", { + eventId: EVENT_STREAM_ERROR, + category: CATEGORY_WORKER, + properties: { error: msg }, + }, `Error on grpc stream: ${msg}`); +} + +export function connectionRetry(logger: Logger, delayMs: number): void { + emitLog(logger, "info", { + eventId: EVENT_CONNECTION_RETRY, + category: CATEGORY_WORKER, + properties: { delayMs }, + }, `Connection will be retried in ${delayMs}ms...`); +} + +export function workItemReceived(logger: Logger, type: string, instanceId?: string): void { + const msg = instanceId + ? `Received "${type}" work item with instance id '${instanceId}'` + : `Received "${type}" work item`; + emitLog(logger, "info", { + eventId: EVENT_WORK_ITEM_RECEIVED, + category: CATEGORY_WORKER, + properties: { type, instanceId }, + }, msg); +} + +export function unknownWorkItem(logger: Logger): void { + emitLog(logger, "info", { + eventId: EVENT_UNKNOWN_WORK_ITEM, + category: CATEGORY_WORKER, + properties: { type: "Unknown" }, + }, "Received unknown type of work item"); +} + +export function shutdownWaiting(logger: Logger, pendingCount: number): void { + emitLog(logger, "info", { + eventId: EVENT_SHUTDOWN_WAITING, + category: CATEGORY_WORKER, + properties: { pendingCount }, + }, `Waiting for ${pendingCount} pending work item(s) to complete...`); +} + +export function shutdownCompleted(logger: Logger): void { + emitLog(logger, "info", { + eventId: EVENT_SHUTDOWN_COMPLETED, + category: CATEGORY_WORKER, + }, "All pending work items completed."); +} + +export function shutdownTimeout(logger: Logger, message: string): void { + emitLog(logger, "warn", { + eventId: EVENT_SHUTDOWN_TIMEOUT, + category: CATEGORY_WORKER, + properties: { message }, + }, `${message}. Forcing shutdown.`); +} + +export function versionMismatchFail(logger: Logger, instanceId: string, errorType: string, errorMessage: string): void { + emitLog(logger, "warn", { + eventId: EVENT_VERSION_MISMATCH_FAIL, + category: CATEGORY_WORKER, + properties: { instanceId, errorType, errorMessage }, + }, `${errorType} for instance '${instanceId}': ${errorMessage}. Failing orchestration.`); +} + +export function versionMismatchAbandon(logger: Logger, instanceId: string, errorType: string, errorMessage: string): void { + emitLog(logger, "info", { + eventId: EVENT_VERSION_MISMATCH_ABANDON, + category: CATEGORY_WORKER, + properties: { instanceId, errorType, errorMessage }, + }, `${errorType} for instance '${instanceId}': ${errorMessage}. Abandoning work item.`); +} + +export function executionError(logger: Logger, instanceId: string, error: unknown): void { + const msg = toErrorMessage(error); + emitLog(logger, "error", { + eventId: EVENT_EXECUTION_ERROR, + category: CATEGORY_WORKER, + properties: { instanceId, error: msg }, + }, `An error occurred while trying to execute instance '${instanceId}': ${msg}`); +} + +export function completionError(logger: Logger, instanceId: string, error: unknown): void { + const msg = toErrorMessage(error); + emitLog(logger, "error", { + eventId: EVENT_COMPLETION_ERROR, + category: CATEGORY_WORKER, + properties: { instanceId, error: msg }, + }, `An error occurred while trying to complete instance '${instanceId}': ${msg}`); +} + +export function activityExecutionError(logger: Logger, activityName: string, error: unknown): void { + const msg = toErrorMessage(error); + emitLog(logger, "error", { + eventId: EVENT_ACTIVITY_EXECUTION_ERROR, + category: CATEGORY_ACTIVITIES, + properties: { activityName, error: msg }, + }, `An error occurred while trying to execute activity '${activityName}': ${msg}`); +} + +export function activityResponseError( + logger: Logger, + activityName: string, + taskId: number, + instanceId: string, + error: unknown, +): void { + const msg = toErrorMessage(error); + emitLog(logger, "error", { + eventId: EVENT_ACTIVITY_RESPONSE_ERROR, + category: CATEGORY_ACTIVITIES, + properties: { activityName, taskId, instanceId, error: msg }, + }, `Failed to deliver activity response for '${activityName}#${taskId}' of orchestration ID '${instanceId}' to sidecar: ${msg}`); +} + +// ── Orchestration Executor internal logs ───────────────────────────────────── + +export function orchestrationRebuilding(logger: Logger, instanceId: string, eventCount: number): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_REBUILDING, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, eventCount }, + }, `${instanceId}: Rebuilding local state with ${eventCount} history event...`); +} + +export function orchestrationProcessing(logger: Logger, instanceId: string, eventCount: number, summary: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_PROCESSING, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, eventCount, summary }, + }, `${instanceId}: Processing ${eventCount} new history event(s): ${summary}`); +} + +export function orchestrationWaiting(logger: Logger, instanceId: string, taskCount: number, eventCount: number): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_WAITING, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, taskCount, eventCount }, + }, `${instanceId}: Waiting for ${taskCount} task(s) and ${eventCount} event(s) to complete...`); +} + +export function orchestrationReturningActions(logger: Logger, instanceId: string, actionCount: number): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_RETURNING_ACTIONS, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, actionCount }, + }, `${instanceId}: Returning ${actionCount} action(s)`); +} + +export function orchestrationSuspended(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_SUSPENDED, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId }, + }, `${instanceId}: Execution suspended`); +} + +export function orchestrationTerminated(logger: Logger, instanceId: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_TERMINATED, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId }, + }, `${instanceId}: Execution terminated`); +} + +export function orchestrationEventRaised(logger: Logger, instanceId: string, eventName: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_EVENT_RAISED, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, eventName }, + }, `${instanceId}: Event raised: ${eventName}`); +} + +export function orchestrationEventBuffered(logger: Logger, instanceId: string, eventName: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_EVENT_BUFFERED, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, eventName }, + }, `${instanceId}: Event ${eventName} has been buffered as there are no tasks waiting for it.`); +} + +export function orchestrationNoTasks(logger: Logger, resultType: string): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_NO_TASKS, + category: CATEGORY_ORCHESTRATIONS, + properties: { resultType }, + }, `An orchestrator was returned that doesn't schedule any tasks (type = ${resultType})`); +} + +export function orchestrationProcessingEvent(logger: Logger, eventTypeName: string, eventType: number): void { + emitLog(logger, "debug", { + eventId: EVENT_ORCHESTRATION_PROCESSING_EVENT, + category: CATEGORY_ORCHESTRATIONS, + properties: { eventTypeName, eventType }, + }, `Processing event type ${eventTypeName} (${eventType})`); +} + +export function orchestrationSuspendedBuffering(logger: Logger): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_SUSPENDED_BUFFERING, + category: CATEGORY_ORCHESTRATIONS, + }, "Suspended, buffering event"); +} + +export function orchestrationUnknownEvent(logger: Logger, eventTypeName: string, eventType: number): void { + emitLog(logger, "info", { + eventId: EVENT_ORCHESTRATION_UNKNOWN_EVENT, + category: CATEGORY_ORCHESTRATIONS, + properties: { eventTypeName, eventType }, + }, `Unknown history event type: ${eventTypeName} (value: ${eventType}), skipping...`); +} + +export function orchestrationEventError(logger: Logger, eventTypeName: string, error: unknown): void { + const msg = toErrorMessage(error); + emitLog(logger, "error", { + eventId: EVENT_ORCHESTRATION_EVENT_ERROR, + category: CATEGORY_ORCHESTRATIONS, + properties: { eventTypeName, error: msg }, + }, `Could not process the event ${eventTypeName} due to error ${msg}`); +} + +export function orchestrationUnexpectedEvent( + logger: Logger, + instanceId: string, + eventType: string, + eventId?: number, +): void { + const msg = eventId !== undefined + ? `${instanceId}: Ignoring unexpected ${eventType} event with ID = ${eventId}` + : `${instanceId}: Ignoring ${eventType} event with undefined ID`; + emitLog(logger, "warn", { + eventId: EVENT_ORCHESTRATION_UNEXPECTED_EVENT, + category: CATEGORY_ORCHESTRATIONS, + properties: { instanceId, eventType, eventId }, + }, msg); +} + +export function streamErrorInfo(logger: Logger, error: unknown): void { + const msg = toErrorMessage(error); + emitLog(logger, "info", { + eventId: EVENT_STREAM_ERROR_INFO, + category: CATEGORY_WORKER, + properties: { error: msg }, + }, `Stream error: ${msg}`); +} diff --git a/packages/durabletask-js/src/worker/orchestration-executor.ts b/packages/durabletask-js/src/worker/orchestration-executor.ts index c90d660..7c2823a 100644 --- a/packages/durabletask-js/src/worker/orchestration-executor.ts +++ b/packages/durabletask-js/src/worker/orchestration-executor.ts @@ -11,12 +11,13 @@ import { import * as pb from "../proto/orchestrator_service_pb"; import { Logger, ConsoleLogger } from "../types/logger.type"; import { getName } from "../task"; +import * as WorkerLogs from "./logs"; import { OrchestrationStateError } from "../task/exception/orchestration-state-error"; import { RetryableTask } from "../task/retryable-task"; import { RetryTimerTask } from "../task/retry-timer-task"; import { TOrchestrator } from "../types/orchestrator.type"; import { enumValueToKey } from "../utils/enum.util"; -import { getOrchestrationStatusStr, isEmpty } from "../utils/pb-helper.util"; +import { isEmpty } from "../utils/pb-helper.util"; import { OrchestratorNotRegisteredError } from "./exception/orchestrator-not-registered-error"; import { StopIterationError } from "./exception/stop-iteration-error"; import { Registry } from "./registry"; @@ -36,6 +37,7 @@ export class OrchestrationExecutor { private _isSuspended: boolean; private _suspendedEvents: pb.HistoryEvent[]; private _logger: Logger; + private _orchestratorName: string; constructor(registry: Registry, logger?: Logger) { this._registry = registry; @@ -43,6 +45,7 @@ export class OrchestrationExecutor { this._isSuspended = false; this._suspendedEvents = []; this._logger = logger ?? new ConsoleLogger(); + this._orchestratorName = "(unknown)"; } async execute( @@ -58,7 +61,7 @@ export class OrchestrationExecutor { try { // Rebuild the local state by replaying the history events into the orchestrator function - this._logger.info(`${instanceId}: Rebuilding local state with ${oldEvents.length} history event...`); + WorkerLogs.orchestrationRebuilding(this._logger, instanceId, oldEvents.length); ctx._isReplaying = true; for (const oldEvent of oldEvents) { @@ -67,30 +70,35 @@ export class OrchestrationExecutor { // Get new actions by executing newly received events into the orchestrator function const summary = getNewEventSummary(newEvents); - this._logger.info(`${instanceId}: Processing ${newEvents.length} new history event(s): ${summary}`); + WorkerLogs.orchestrationProcessing(this._logger, instanceId, newEvents.length, summary); ctx._isReplaying = false; for (const newEvent of newEvents) { await this.processEvent(ctx, newEvent); } - } catch (e: any) { - ctx.setFailed(e); + } catch (e: unknown) { + ctx.setFailed(e instanceof Error ? e : new Error(String(e))); } if (!ctx._isComplete) { const taskCount = Object.keys(ctx._pendingTasks).length; const eventCount = Object.keys(ctx._pendingEvents).length; - this._logger.info(`${instanceId}: Waiting for ${taskCount} task(s) and ${eventCount} event(s) to complete...`); + WorkerLogs.orchestrationWaiting(this._logger, instanceId, taskCount, eventCount); } else if ( ctx._completionStatus && ctx._completionStatus !== pb.OrchestrationStatus.ORCHESTRATION_STATUS_CONTINUED_AS_NEW ) { - const completionStatusStr = getOrchestrationStatusStr(ctx._completionStatus); - this._logger.info(`${instanceId}: Orchestration completed with status ${completionStatusStr}`); + if (ctx._completionStatus === pb.OrchestrationStatus.ORCHESTRATION_STATUS_FAILED) { + WorkerLogs.orchestrationFailed(this._logger, instanceId, this._orchestratorName); + } else if (ctx._completionStatus === pb.OrchestrationStatus.ORCHESTRATION_STATUS_TERMINATED) { + WorkerLogs.orchestrationTerminated(this._logger, instanceId); + } else { + WorkerLogs.orchestrationCompleted(this._logger, instanceId, this._orchestratorName); + } } const actions = ctx.getActions(); - this._logger.info(`${instanceId}: Returning ${actions.length} action(s)`); + WorkerLogs.orchestrationReturningActions(this._logger, instanceId, actions.length); return { actions, @@ -101,15 +109,15 @@ export class OrchestrationExecutor { private async processEvent(ctx: RuntimeOrchestrationContext, event: pb.HistoryEvent): Promise { // Check if we are suspended to see if we need to buffer the event until we are resumed if (this._isSuspended && isSuspendable(event)) { - this._logger.info("Suspended, buffering event"); + WorkerLogs.orchestrationSuspendedBuffering(this._logger); this._suspendedEvents.push(event); return; } const eventType = event.getEventtypeCase(); - const eventTypeName = enumValueToKey(pb.HistoryEvent.EventtypeCase, eventType); + const eventTypeName = enumValueToKey(pb.HistoryEvent.EventtypeCase, eventType) ?? "Unknown"; - this._logger.debug(`Processing event type ${eventTypeName} (${event.getEventtypeCase()})`); + WorkerLogs.orchestrationProcessingEvent(this._logger, eventTypeName, event.getEventtypeCase()); // Process the event type try { @@ -129,6 +137,12 @@ export class OrchestrationExecutor { throw new OrchestratorNotRegisteredError(executionStartedEvent?.getName()); } + // Track the orchestrator name for lifecycle logs + this._orchestratorName = executionStartedEvent?.getName() ?? "(unknown)"; + + // Log orchestration start (EventId 600) + WorkerLogs.orchestrationStarted(this._logger, ctx._instanceId, this._orchestratorName); + // Set the version from the execution started event ctx._version = executionStartedEvent?.getVersion()?.getValue() ?? ""; @@ -160,7 +174,7 @@ export class OrchestrationExecutor { await ctx.run(result); } else { const resultType = Object.prototype.toString.call(result); - this._logger.info(`An orchestrator was returned that doesn't schedule any tasks (type = ${resultType})`); + WorkerLogs.orchestrationNoTasks(this._logger, resultType); // This is an orchestrator that doesn't schedule any tasks ctx.setComplete(result, pb.OrchestrationStatus.ORCHESTRATION_STATUS_COMPLETED); @@ -193,7 +207,7 @@ export class OrchestrationExecutor { if (timerId === undefined) { if (!ctx._isReplaying) { - this._logger.warn(`${ctx._instanceId}: Ignoring timerFired event with undefined ID`); + WorkerLogs.orchestrationUnexpectedEvent(this._logger, ctx._instanceId, "timerFired"); } return; } @@ -204,7 +218,7 @@ export class OrchestrationExecutor { if (!timerTask) { // TODO: Should this be an error? When would it ever happen? if (!ctx._isReplaying) { - this._logger.warn(`${ctx._instanceId}: Ignoring unexpected timerFired event with ID = ${timerId}`); + WorkerLogs.orchestrationUnexpectedEvent(this._logger, ctx._instanceId, "timerFired", timerId); } return; } @@ -264,7 +278,7 @@ export class OrchestrationExecutor { if (!activityTask) { // TODO: Should this be an error? When would it ever happen? if (!ctx._isReplaying) { - this._logger.warn(`${ctx._instanceId}: Ignoring unexpected taskCompleted event with ID = ${taskId}`); + WorkerLogs.orchestrationUnexpectedEvent(this._logger, ctx._instanceId, "taskCompleted", taskId); } return; @@ -287,7 +301,7 @@ export class OrchestrationExecutor { if (taskId === undefined) { if (!ctx._isReplaying) { - this._logger.warn(`${ctx._instanceId}: Ignoring taskFailed event with undefined ID`); + WorkerLogs.orchestrationUnexpectedEvent(this._logger, ctx._instanceId, "taskFailed"); } return; } @@ -300,7 +314,7 @@ export class OrchestrationExecutor { if (!activityTask) { if (!ctx._isReplaying) { - this._logger.warn(`${ctx._instanceId}: Ignoring unexpected taskFailed event with ID = ${taskId}`); + WorkerLogs.orchestrationUnexpectedEvent(this._logger, ctx._instanceId, "taskFailed", taskId); } return; } @@ -351,7 +365,7 @@ export class OrchestrationExecutor { throw getWrongActionNameError( taskId, getName(ctx.callSubOrchestrator), - action.getCreatesuborchestration()?.getName(), + event.getSuborchestrationinstancecreated()?.getName(), action.getCreatesuborchestration()?.getName(), ); } @@ -393,7 +407,7 @@ export class OrchestrationExecutor { if (taskId === undefined) { if (!ctx._isReplaying) { - this._logger.warn(`${ctx._instanceId}: Ignoring subOrchestrationInstanceFailed event with undefined ID`); + WorkerLogs.orchestrationUnexpectedEvent(this._logger, ctx._instanceId, "subOrchestrationInstanceFailed"); } return; } @@ -406,8 +420,8 @@ export class OrchestrationExecutor { if (!subOrchTask) { if (!ctx._isReplaying) { - this._logger.warn( - `${ctx._instanceId}: Ignoring unexpected subOrchestrationInstanceFailed event with ID = ${taskId}`, + WorkerLogs.orchestrationUnexpectedEvent( + this._logger, ctx._instanceId, "subOrchestrationInstanceFailed", taskId, ); } return; @@ -445,7 +459,7 @@ export class OrchestrationExecutor { const eventName = event.getEventraised()?.getName()?.toLowerCase(); if (!ctx._isReplaying) { - this._logger.info(`${ctx._instanceId}: Event raised: ${eventName}`); + WorkerLogs.orchestrationEventRaised(this._logger, ctx._instanceId, eventName!); } let taskList; @@ -467,7 +481,7 @@ export class OrchestrationExecutor { eventTask.complete(decodedResult); } - if (!taskList && eventName) { + if ((taskList?.length ?? 0) === 0 && eventName) { delete ctx._pendingEvents[eventName]; } @@ -492,9 +506,7 @@ export class OrchestrationExecutor { eventList?.push(decodedResult); if (!ctx._isReplaying) { - this._logger.info( - `${ctx._instanceId}: Event ${eventName} has been buffered as there are no tasks waiting for it.`, - ); + WorkerLogs.orchestrationEventBuffered(this._logger, ctx._instanceId, eventName!); } } } @@ -502,7 +514,7 @@ export class OrchestrationExecutor { case pb.HistoryEvent.EventtypeCase.EXECUTIONSUSPENDED: { if (!this._isSuspended && !ctx._isReplaying) { - this._logger.info(`${ctx._instanceId}: Execution suspended`); + WorkerLogs.orchestrationSuspended(this._logger, ctx._instanceId); } this._isSuspended = true; @@ -523,7 +535,7 @@ export class OrchestrationExecutor { break; case pb.HistoryEvent.EventtypeCase.EXECUTIONTERMINATED: { if (!ctx._isReplaying) { - this._logger.info(`${ctx._instanceId}: Execution terminated`); + WorkerLogs.orchestrationTerminated(this._logger, ctx._instanceId); } let encodedOutput; @@ -536,10 +548,10 @@ export class OrchestrationExecutor { break; } default: - this._logger.info(`Unknown history event type: ${eventTypeName} (value: ${eventType}), skipping...`); + WorkerLogs.orchestrationUnknownEvent(this._logger, eventTypeName, eventType); // throw new OrchestrationStateError(`Unknown history event type: ${eventTypeName} (value: ${eventType})`); } - } catch (e: any) { + } catch (e: unknown) { // StopIteration is thrown when the generator is finished and didn't return a task as its next action if (e instanceof StopIterationError) { ctx.setComplete(e.value, pb.OrchestrationStatus.ORCHESTRATION_STATUS_COMPLETED); @@ -548,7 +560,7 @@ export class OrchestrationExecutor { // For the rest we don't do anything // Else we throw it upwards - this._logger.error(`Could not process the event ${eventTypeName} due to error ${e}`); + WorkerLogs.orchestrationEventError(this._logger, eventTypeName, e); throw e; } } diff --git a/packages/durabletask-js/src/worker/runtime-orchestration-context.ts b/packages/durabletask-js/src/worker/runtime-orchestration-context.ts index 8439886..595feef 100644 --- a/packages/durabletask-js/src/worker/runtime-orchestration-context.ts +++ b/packages/durabletask-js/src/worker/runtime-orchestration-context.ts @@ -499,11 +499,11 @@ export class RuntimeOrchestrationContext extends OrchestrationContext { * Formats a GUID byte buffer as a string in standard GUID format (xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx). */ private formatGuidBytes(bytes: Buffer): string { - const data1 = bytes.slice(0, 4).reverse().toString("hex"); - const data2 = bytes.slice(4, 6).reverse().toString("hex"); - const data3 = bytes.slice(6, 8).reverse().toString("hex"); - const data4 = bytes.slice(8, 10).toString("hex"); - const data5 = bytes.slice(10, 16).toString("hex"); + const data1 = Buffer.from(bytes.subarray(0, 4)).reverse().toString("hex"); + const data2 = Buffer.from(bytes.subarray(4, 6)).reverse().toString("hex"); + const data3 = Buffer.from(bytes.subarray(6, 8)).reverse().toString("hex"); + const data4 = bytes.subarray(8, 10).toString("hex"); + const data5 = bytes.subarray(10, 16).toString("hex"); return `${data1}-${data2}-${data3}-${data4}-${data5}`; } diff --git a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts index 2a35123..c9e57c7 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -20,6 +20,16 @@ import { Logger, ConsoleLogger } from "../types/logger.type"; import { ExponentialBackoff, sleep, withTimeout } from "../utils/backoff.util"; import { VersioningOptions, VersionMatchStrategy, VersionFailureStrategy } from "./versioning-options"; import { compareVersions } from "../utils/versioning.util"; +import * as WorkerLogs from "./logs"; +import { + startSpanForOrchestrationExecution, + startSpanForTaskExecution, + processActionsForTracing, + createOrchestrationTraceContextPb, + setSpanError, + setSpanOk, + endSpan, +} from "../tracing"; /** Default timeout in milliseconds for graceful shutdown. */ const DEFAULT_SHUTDOWN_TIMEOUT_MS = 30000; @@ -185,7 +195,7 @@ export class TaskHubGrpcWorker { // Do not await - run in background this.internalRunWorker(newClient, true).catch((err) => { if (!this._stopWorker) { - this._logger.error("Worker error:", err); + WorkerLogs.workerError(this._logger, err); } }); } @@ -264,7 +274,7 @@ export class TaskHubGrpcWorker { this.internalRunWorker(client).catch((err) => { // Only log if the worker wasn't stopped intentionally if (!this._stopWorker) { - this._logger.error("Worker error:", err); + WorkerLogs.workerError(this._logger, err); } }); @@ -284,32 +294,32 @@ export class TaskHubGrpcWorker { const stream = client.stub.getWorkItems(new pb.GetWorkItemsRequest(), metadata); this._responseStream = stream; - this._logger.info(`Successfully connected to ${this._hostAddress}. Waiting for work items...`); + WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); // Wait for a work item to be received stream.on("data", (workItem: pb.WorkItem) => { const completionToken = workItem.getCompletiontoken(); if (workItem.hasOrchestratorrequest()) { - this._logger.info( - `Received "Orchestrator Request" work item with instance id '${workItem - ?.getOrchestratorrequest() - ?.getInstanceid()}'`, + WorkerLogs.workItemReceived( + this._logger, + "Orchestrator Request", + workItem?.getOrchestratorrequest()?.getInstanceid(), ); this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, client.stub); } else if (workItem.hasActivityrequest()) { - this._logger.info(`Received "Activity Request" work item`); + WorkerLogs.workItemReceived(this._logger, "Activity Request"); this._executeActivity(workItem.getActivityrequest() as any, completionToken, client.stub); } else if (workItem.hasHealthping()) { // Health ping - no-op, just a keep-alive message from the server } else { - this._logger.info(`Received unknown type of work item `); + WorkerLogs.unknownWorkItem(this._logger); } }); // Wait for the stream to end or error stream.on("end", async () => { if (this._stopWorker) { - this._logger.info("Stream ended"); + WorkerLogs.streamEnded(this._logger); stream.removeAllListeners(); stream.destroy(); return; @@ -317,7 +327,7 @@ export class TaskHubGrpcWorker { // Stream ended unexpectedly - clean up and retry stream.removeAllListeners(); stream.destroy(); - this._logger.info(`Stream abruptly closed, will retry in ${this._backoff.peekNextDelay()}ms...`); + WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); await this._createNewClientAndRetry(); }); @@ -326,18 +336,19 @@ export class TaskHubGrpcWorker { if (this._stopWorker) { return; } - this._logger.info("Stream error", err); + WorkerLogs.streamErrorInfo(this._logger, err); }); } catch (err) { if (this._stopWorker) { // ignoring the error because the worker has been stopped return; } - this._logger.error(`Error on grpc stream: ${err}`); + const error = err instanceof Error ? err : new Error(String(err)); + WorkerLogs.streamError(this._logger, error); if (!isRetry) { - throw err; + throw error; } - this._logger.info(`Connection will be retried in ${this._backoff.peekNextDelay()}ms...`); + WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); await this._createNewClientAndRetry(); return; } @@ -384,16 +395,17 @@ export class TaskHubGrpcWorker { // Wait for pending work items to complete with timeout if (this._pendingWorkItems.size > 0) { - this._logger.info(`Waiting for ${this._pendingWorkItems.size} pending work item(s) to complete...`); + WorkerLogs.shutdownWaiting(this._logger, this._pendingWorkItems.size); try { await withTimeout( Promise.all(this._pendingWorkItems), this._shutdownTimeoutMs, `Shutdown timed out after ${this._shutdownTimeoutMs}ms waiting for pending work items`, ); - this._logger.info("All pending work items completed."); + WorkerLogs.shutdownCompleted(this._logger); } catch (e) { - this._logger.warn(`${(e as Error).message}. Forcing shutdown.`); + const error = e instanceof Error ? e : new Error(String(e)); + WorkerLogs.shutdownTimeout(this._logger, error.message); } } @@ -524,8 +536,11 @@ export class TaskHubGrpcWorker { if (!versionCheckResult.compatible) { if (versionCheckResult.shouldFail) { // Fail the orchestration with version mismatch error - this._logger.warn( - `${versionCheckResult.errorType} for instance '${instanceId}': ${versionCheckResult.errorMessage}. Failing orchestration.`, + WorkerLogs.versionMismatchFail( + this._logger, + instanceId, + versionCheckResult.errorType!, + versionCheckResult.errorMessage!, ); const failureDetails = pbh.newVersionMismatchFailureDetails( @@ -549,33 +564,60 @@ export class TaskHubGrpcWorker { try { await callWithMetadata(stub.completeOrchestratorTask.bind(stub), res, this._metadataGenerator); - } catch (e: any) { - this._logger.error(`An error occurred while trying to complete instance '${instanceId}': ${e?.message}`); + } catch (e: unknown) { + const error = e instanceof Error ? e : new Error(String(e)); + WorkerLogs.completionError(this._logger, instanceId, error); } return; } else { // Reject the work item - explicitly abandon it so it can be picked up by another worker - this._logger.info( - `${versionCheckResult.errorType} for instance '${instanceId}': ${versionCheckResult.errorMessage}. Abandoning work item.`, + WorkerLogs.versionMismatchAbandon( + this._logger, + instanceId, + versionCheckResult.errorType!, + versionCheckResult.errorMessage!, ); try { const abandonRequest = new pb.AbandonOrchestrationTaskRequest(); abandonRequest.setCompletiontoken(completionToken); await callWithMetadata(stub.abandonTaskOrchestratorWorkItem.bind(stub), abandonRequest, this._metadataGenerator); - } catch (e: any) { - this._logger.error(`An error occurred while trying to abandon work item for instance '${instanceId}': ${e?.message}`); + } catch (e: unknown) { + const error = e instanceof Error ? e : new Error(String(e)); + WorkerLogs.completionError(this._logger, instanceId, error); } return; } } + // Find the ExecutionStartedEvent from either past or new events for tracing + const allProtoEvents = [...req.getPasteventsList(), ...req.getNeweventsList()]; + let executionStartedProtoEvent: pb.ExecutionStartedEvent | undefined; + for (const protoEvent of allProtoEvents) { + if (protoEvent.hasExecutionstarted()) { + executionStartedProtoEvent = protoEvent.getExecutionstarted()!; + break; + } + } + + // Start the orchestration span BEFORE execution so failures are traced + const orchTraceContext = req.getOrchestrationtracecontext(); + const tracingResult = executionStartedProtoEvent + ? startSpanForOrchestrationExecution(executionStartedProtoEvent, orchTraceContext, instanceId) + : undefined; + let res; try { const executor = new OrchestrationExecutor(this._registry, this._logger); const result = await executor.execute(req.getInstanceid(), req.getPasteventsList(), req.getNeweventsList()); + // Process actions to inject trace context into scheduled tasks, sub-orchestrations, etc. + if (tracingResult) { + const orchName = executionStartedProtoEvent?.getName() ?? ""; + processActionsForTracing(tracingResult.span, result.actions, orchName); + } + res = new pb.OrchestratorResponse(); res.setInstanceid(req.getInstanceid()); res.setCompletiontoken(completionToken); @@ -583,19 +625,31 @@ export class TaskHubGrpcWorker { if (result.customStatus !== undefined) { res.setCustomstatus(pbh.getStringValue(result.customStatus)); } - } catch (e: any) { - this._logger.error( - `An error occurred while trying to execute instance '${req.getInstanceid()}':`, - e, - ); - const failureDetails = pbh.newFailureDetails(e); + // Set the OrchestrationTraceContext on the response for replay continuity + if (tracingResult) { + const orchTraceCtxPb = createOrchestrationTraceContextPb(tracingResult.spanInfo); + res.setOrchestrationtracecontext(orchTraceCtxPb); + + setSpanOk(tracingResult.span); + } + } catch (e: unknown) { + const error = e instanceof Error ? e : new Error(String(e)); + WorkerLogs.executionError(this._logger, req.getInstanceid(), error); + + // Record the failure on the tracing span + if (tracingResult) { + setSpanError(tracingResult.span, error); + } + + const failureDetails = pbh.newFailureDetails(error); const actions = [ pbh.newCompleteOrchestrationAction( -1, pb.OrchestrationStatus.ORCHESTRATION_STATUS_FAILED, - failureDetails?.toString(), + undefined, + failureDetails, ), ]; @@ -603,12 +657,17 @@ export class TaskHubGrpcWorker { res.setInstanceid(req.getInstanceid()); res.setCompletiontoken(completionToken); res.setActionsList(actions); + } finally { + // Always end the orchestration span, regardless of success or failure. + // Status (OK/Error) is set in the respective try/catch branches above. + endSpan(tracingResult?.span); } try { await callWithMetadata(stub.completeOrchestratorTask.bind(stub), res, this._metadataGenerator); - } catch (e: any) { - this._logger.error(`An error occurred while trying to complete instance '${req.getInstanceid()}': ${e?.message}`); + } catch (e: unknown) { + const error = e instanceof Error ? e : new Error(String(e)); + WorkerLogs.completionError(this._logger, req.getInstanceid(), error); } } @@ -643,6 +702,9 @@ export class TaskHubGrpcWorker { let res; + // Start the activity span for distributed tracing + const activitySpan = startSpanForTaskExecution(req); + try { const executor = new ActivityExecutor(this._registry, this._logger); const result = await executor.execute( @@ -660,25 +722,33 @@ export class TaskHubGrpcWorker { res.setTaskid(req.getTaskid()); res.setCompletiontoken(completionToken); res.setResult(s); - } catch (e: any) { - this._logger.error(`An error occurred while trying to execute activity '${req.getName()}':`, e); - const failureDetails = pbh.newFailureDetails(e); + setSpanOk(activitySpan); + } catch (e: unknown) { + const error = e instanceof Error ? e : new Error(String(e)); + WorkerLogs.activityExecutionError(this._logger, req.getName(), error); + + setSpanError(activitySpan, error); + + const failureDetails = pbh.newFailureDetails(error); res = new pb.ActivityResponse(); res.setTaskid(req.getTaskid()); res.setCompletiontoken(completionToken); res.setFailuredetails(failureDetails); + } finally { + // End the activity span BEFORE the gRPC completion call. + // This ensures the span duration reflects only the activity execution time, + // not the network latency of reporting back to the sidecar. + // Status (OK/Error) is set in the respective try/catch branches above. + endSpan(activitySpan); } try { await callWithMetadata(stub.completeActivityTask.bind(stub), res, this._metadataGenerator); - } catch (e: any) { - this._logger.error( - `Failed to deliver activity response for '${req.getName()}#${req.getTaskid()}' of orchestration ID '${instanceId}' to sidecar: ${ - e?.message - }`, - ); + } catch (e: unknown) { + const error = e instanceof Error ? e : new Error(String(e)); + WorkerLogs.activityResponseError(this._logger, req.getName(), req.getTaskid(), instanceId!, error); } } } diff --git a/packages/durabletask-js/test/console-logger.spec.ts b/packages/durabletask-js/test/console-logger.spec.ts index d0b0d14..6df0d09 100644 --- a/packages/durabletask-js/test/console-logger.spec.ts +++ b/packages/durabletask-js/test/console-logger.spec.ts @@ -1,7 +1,7 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. -import { ConsoleLogger } from "../src/types/logger.type"; +import { ConsoleLogger, isStructuredLogger, LogEvent } from "../src/types/logger.type"; describe("ConsoleLogger", () => { let logger: ConsoleLogger; @@ -86,6 +86,74 @@ describe("ConsoleLogger", () => { }); }); + describe("logEvent (StructuredLogger)", () => { + it("should be recognized as a StructuredLogger", () => { + expect(isStructuredLogger(logger)).toBe(true); + }); + + it("should call console.info with formatted prefix for info level", () => { + const spy = jest.spyOn(console, "info").mockImplementation(); + const event: LogEvent = { + eventId: 600, + category: "Microsoft.DurableTask.Worker.Orchestrations", + properties: { instanceId: "abc123", name: "MyOrch" }, + }; + + logger.logEvent("info", event, "'MyOrch' orchestration with ID 'abc123' started."); + + expect(spy).toHaveBeenCalledWith( + "[600] [Microsoft.DurableTask.Worker.Orchestrations] 'MyOrch' orchestration with ID 'abc123' started.", + { instanceId: "abc123", name: "MyOrch" }, + ); + }); + + it("should call console.error with formatted prefix for error level", () => { + const spy = jest.spyOn(console, "error").mockImplementation(); + const event: LogEvent = { + eventId: 602, + category: "Microsoft.DurableTask.Worker.Orchestrations", + properties: { instanceId: "abc123" }, + }; + + logger.logEvent("error", event, "Orchestration failed."); + + expect(spy).toHaveBeenCalledWith( + "[602] [Microsoft.DurableTask.Worker.Orchestrations] Orchestration failed.", + { instanceId: "abc123" }, + ); + }); + + it("should call console.warn for warn level", () => { + const spy = jest.spyOn(console, "warn").mockImplementation(); + const event: LogEvent = { + eventId: 730, + category: "Microsoft.DurableTask.Worker", + }; + + logger.logEvent("warn", event, "Version mismatch."); + + expect(spy).toHaveBeenCalledWith( + "[730] [Microsoft.DurableTask.Worker] Version mismatch.", + ); + }); + + it("should call console.debug for debug level", () => { + const spy = jest.spyOn(console, "debug").mockImplementation(); + const event: LogEvent = { + eventId: 719, + category: "Microsoft.DurableTask.Worker.Orchestrations", + properties: { eventTypeName: "TaskCompleted" }, + }; + + logger.logEvent("debug", event, "Processing event."); + + expect(spy).toHaveBeenCalledWith( + "[719] [Microsoft.DurableTask.Worker.Orchestrations] Processing event.", + { eventTypeName: "TaskCompleted" }, + ); + }); + }); + describe("Logger interface", () => { it("should implement Logger interface correctly", () => { expect(typeof logger.error).toBe("function"); @@ -93,5 +161,9 @@ describe("ConsoleLogger", () => { expect(typeof logger.info).toBe("function"); expect(typeof logger.debug).toBe("function"); }); + + it("should implement StructuredLogger interface correctly", () => { + expect(typeof logger.logEvent).toBe("function"); + }); }); }); diff --git a/packages/durabletask-js/test/emit-log.spec.ts b/packages/durabletask-js/test/emit-log.spec.ts new file mode 100644 index 0000000..2c27a42 --- /dev/null +++ b/packages/durabletask-js/test/emit-log.spec.ts @@ -0,0 +1,70 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import { emitLog } from "../src/utils/emit-log"; +import { Logger, StructuredLogger, LogEvent } from "../src/types/logger.type"; + +describe("emitLog", () => { + const event: LogEvent = { + eventId: 600, + category: "Microsoft.DurableTask.Worker.Orchestrations", + properties: { instanceId: "abc123", name: "MyOrch" }, + }; + + const message = "Test message"; + + describe("with StructuredLogger", () => { + let logger: StructuredLogger; + + beforeEach(() => { + logger = { + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + logEvent: jest.fn(), + }; + }); + + it.each(["error", "warn", "info", "debug"] as const)( + "should call logEvent for %s level", + (level) => { + emitLog(logger, level, event, message); + + expect(logger.logEvent).toHaveBeenCalledWith(level, event, message); + expect(logger[level]).not.toHaveBeenCalled(); + }, + ); + }); + + describe("with plain Logger", () => { + let logger: Logger; + + beforeEach(() => { + logger = { + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + }; + }); + + it.each(["error", "warn", "info", "debug"] as const)( + "should fall back to plain %s method", + (level) => { + emitLog(logger, level, event, message); + + expect(logger[level]).toHaveBeenCalledWith(message); + }, + ); + + it("should not call other log levels", () => { + emitLog(logger, "error", event, message); + + expect(logger.error).toHaveBeenCalledTimes(1); + expect(logger.warn).not.toHaveBeenCalled(); + expect(logger.info).not.toHaveBeenCalled(); + expect(logger.debug).not.toHaveBeenCalled(); + }); + }); +}); diff --git a/packages/durabletask-js/test/error-util.spec.ts b/packages/durabletask-js/test/error-util.spec.ts new file mode 100644 index 0000000..f409d32 --- /dev/null +++ b/packages/durabletask-js/test/error-util.spec.ts @@ -0,0 +1,65 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import { toErrorMessage } from "../src/utils/error.util"; + +describe("toErrorMessage", () => { + it("should extract message from Error instance", () => { + const error = new Error("something went wrong"); + expect(toErrorMessage(error)).toBe("something went wrong"); + }); + + it("should extract message from Error subclass", () => { + const error = new TypeError("invalid type"); + expect(toErrorMessage(error)).toBe("invalid type"); + }); + + it("should return string errors as-is", () => { + expect(toErrorMessage("raw error string")).toBe("raw error string"); + }); + + it("should return empty string for empty string error", () => { + expect(toErrorMessage("")).toBe(""); + }); + + it("should JSON-stringify plain objects", () => { + const obj = { code: 404, reason: "not found" }; + expect(toErrorMessage(obj)).toBe(JSON.stringify(obj)); + }); + + it("should JSON-stringify arrays", () => { + const arr = ["error1", "error2"]; + expect(toErrorMessage(arr)).toBe(JSON.stringify(arr)); + }); + + it("should handle objects with circular references gracefully", () => { + const obj: Record = { name: "circular" }; + obj.self = obj; + // JSON.stringify will throw, so it should fall through to String() + expect(toErrorMessage(obj)).toBe("[object Object]"); + }); + + it("should convert null to string", () => { + expect(toErrorMessage(null)).toBe("null"); + }); + + it("should convert undefined to string", () => { + expect(toErrorMessage(undefined)).toBe("undefined"); + }); + + it("should convert number to string", () => { + expect(toErrorMessage(42)).toBe("42"); + }); + + it("should convert boolean to string", () => { + expect(toErrorMessage(false)).toBe("false"); + }); + + it("should convert symbol to string", () => { + expect(toErrorMessage(Symbol("test"))).toBe("Symbol(test)"); + }); + + it("should handle BigInt", () => { + expect(toErrorMessage(BigInt(123))).toBe("123"); + }); +}); diff --git a/packages/durabletask-js/test/noop-logger.spec.ts b/packages/durabletask-js/test/noop-logger.spec.ts index c2a1cc0..a7089c8 100644 --- a/packages/durabletask-js/test/noop-logger.spec.ts +++ b/packages/durabletask-js/test/noop-logger.spec.ts @@ -1,7 +1,7 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. -import { NoOpLogger } from "../src/types/logger.type"; +import { NoOpLogger, isStructuredLogger, LogEvent } from "../src/types/logger.type"; describe("NoOpLogger", () => { let logger: NoOpLogger; @@ -70,6 +70,44 @@ describe("NoOpLogger", () => { }); }); + describe("logEvent (StructuredLogger)", () => { + it("should be recognized as a StructuredLogger", () => { + expect(isStructuredLogger(logger)).toBe(true); + }); + + it("should not throw when called", () => { + const event: LogEvent = { + eventId: 600, + category: "Microsoft.DurableTask.Worker.Orchestrations", + properties: { instanceId: "abc123" }, + }; + + expect(() => logger.logEvent("info", event, "test message")).not.toThrow(); + }); + + it("should not call any console methods", () => { + const infoSpy = jest.spyOn(console, "info").mockImplementation(); + const errorSpy = jest.spyOn(console, "error").mockImplementation(); + const warnSpy = jest.spyOn(console, "warn").mockImplementation(); + const debugSpy = jest.spyOn(console, "debug").mockImplementation(); + + const event: LogEvent = { + eventId: 600, + category: "Microsoft.DurableTask.Worker.Orchestrations", + }; + + logger.logEvent("info", event, "test"); + logger.logEvent("error", event, "test"); + logger.logEvent("warn", event, "test"); + logger.logEvent("debug", event, "test"); + + expect(infoSpy).not.toHaveBeenCalled(); + expect(errorSpy).not.toHaveBeenCalled(); + expect(warnSpy).not.toHaveBeenCalled(); + expect(debugSpy).not.toHaveBeenCalled(); + }); + }); + describe("Logger interface", () => { it("should implement Logger interface correctly", () => { expect(typeof logger.error).toBe("function"); @@ -77,6 +115,10 @@ describe("NoOpLogger", () => { expect(typeof logger.info).toBe("function"); expect(typeof logger.debug).toBe("function"); }); + + it("should implement StructuredLogger interface correctly", () => { + expect(typeof logger.logEvent).toBe("function"); + }); }); describe("use case", () => { @@ -88,6 +130,7 @@ describe("NoOpLogger", () => { silentLogger.warn("This warning is silently discarded"); silentLogger.info("This info is silently discarded"); silentLogger.debug("This debug is silently discarded"); + silentLogger.logEvent("info", { eventId: 600, category: "Test" }, "discarded"); // If we got here, the test passes expect(true).toBe(true); diff --git a/packages/durabletask-js/test/orchestration_executor.spec.ts b/packages/durabletask-js/test/orchestration_executor.spec.ts index 2dd43cb..dd22084 100644 --- a/packages/durabletask-js/test/orchestration_executor.spec.ts +++ b/packages/durabletask-js/test/orchestration_executor.spec.ts @@ -193,7 +193,7 @@ describe("Orchestration Executor", () => { expect(completeAction?.getOrchestrationstatus()).toEqual(pb.OrchestrationStatus.ORCHESTRATION_STATUS_COMPLETED); expect(completeAction?.getResult()?.getValue()).toEqual(encodedOutput); }); - it("should test the successful completion of an activity task", async () => { + it("should test the successful completion of an activity task (additional case)", async () => { const dummyActivity = async (_: ActivityContext) => { // do nothing }; diff --git a/packages/durabletask-js/test/replay-safe-logger.spec.ts b/packages/durabletask-js/test/replay-safe-logger.spec.ts index 8050346..0194296 100644 --- a/packages/durabletask-js/test/replay-safe-logger.spec.ts +++ b/packages/durabletask-js/test/replay-safe-logger.spec.ts @@ -2,10 +2,11 @@ // Licensed under the MIT License. import { ReplaySafeLogger, ReplayContext } from "../src/types/replay-safe-logger"; -import { Logger } from "../src/types/logger.type"; +import { Logger, StructuredLogger, LogEvent, isStructuredLogger } from "../src/types/logger.type"; describe("ReplaySafeLogger", () => { let mockLogger: jest.Mocked; + let mockStructuredLogger: jest.Mocked; let mockContext: ReplayContext; beforeEach(() => { @@ -15,6 +16,13 @@ describe("ReplaySafeLogger", () => { info: jest.fn(), debug: jest.fn(), }; + mockStructuredLogger = { + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + logEvent: jest.fn(), + }; }); afterEach(() => { @@ -123,6 +131,62 @@ describe("ReplaySafeLogger", () => { }); }); + describe("logEvent (StructuredLogger)", () => { + const testEvent: LogEvent = { + eventId: 600, + category: "Microsoft.DurableTask.Worker.Orchestrations", + properties: { instanceId: "abc123", name: "MyOrch" }, + }; + + it("should be recognized as a StructuredLogger", () => { + mockContext = { isReplaying: false }; + const logger = new ReplaySafeLogger(mockContext, mockLogger); + expect(isStructuredLogger(logger)).toBe(true); + }); + + it("should delegate logEvent to inner StructuredLogger when not replaying", () => { + mockContext = { isReplaying: false }; + const logger = new ReplaySafeLogger(mockContext, mockStructuredLogger); + + logger.logEvent("info", testEvent, "test structured message"); + + expect(mockStructuredLogger.logEvent).toHaveBeenCalledWith("info", testEvent, "test structured message"); + }); + + it("should NOT delegate logEvent when replaying", () => { + mockContext = { isReplaying: true }; + const logger = new ReplaySafeLogger(mockContext, mockStructuredLogger); + + logger.logEvent("info", testEvent, "test structured message"); + + expect(mockStructuredLogger.logEvent).not.toHaveBeenCalled(); + }); + + it("should fall back to plain log method if inner logger is not a StructuredLogger", () => { + mockContext = { isReplaying: false }; + const logger = new ReplaySafeLogger(mockContext, mockLogger); + + logger.logEvent("info", testEvent, "test fallback message"); + + // Should call the plain info method on the non-structured logger + expect(mockLogger.info).toHaveBeenCalledWith("test fallback message"); + }); + + it("should fall back to correct level for each log level", () => { + mockContext = { isReplaying: false }; + const logger = new ReplaySafeLogger(mockContext, mockLogger); + + logger.logEvent("error", testEvent, "error msg"); + expect(mockLogger.error).toHaveBeenCalledWith("error msg"); + + logger.logEvent("warn", testEvent, "warn msg"); + expect(mockLogger.warn).toHaveBeenCalledWith("warn msg"); + + logger.logEvent("debug", testEvent, "debug msg"); + expect(mockLogger.debug).toHaveBeenCalledWith("debug msg"); + }); + }); + describe("dynamic replay state changes", () => { it("should respect changes in isReplaying state", () => { // Start with replaying = true @@ -152,5 +216,12 @@ describe("ReplaySafeLogger", () => { expect(typeof logger.info).toBe("function"); expect(typeof logger.debug).toBe("function"); }); + + it("should implement StructuredLogger interface correctly", () => { + mockContext = { isReplaying: false }; + const logger = new ReplaySafeLogger(mockContext, mockLogger); + + expect(typeof logger.logEvent).toBe("function"); + }); }); }); diff --git a/packages/durabletask-js/test/timeout-util.spec.ts b/packages/durabletask-js/test/timeout-util.spec.ts new file mode 100644 index 0000000..bae0ad1 --- /dev/null +++ b/packages/durabletask-js/test/timeout-util.spec.ts @@ -0,0 +1,59 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import { raceWithTimeout } from "../src/utils/timeout.util"; +import { TimeoutError } from "../src/exception/timeout-error"; + +describe("raceWithTimeout", () => { + describe("input validation", () => { + const dummyPromise = new Promise(() => {}); + const dummyMessage = () => "timeout"; + + it("throws RangeError for negative timeoutMs", async () => { + await expect(raceWithTimeout(dummyPromise, -1, dummyMessage)).rejects.toThrow(RangeError); + }); + + it("throws RangeError for NaN timeoutMs", async () => { + await expect(raceWithTimeout(dummyPromise, NaN, dummyMessage)).rejects.toThrow(RangeError); + }); + + it("throws RangeError for Infinity timeoutMs", async () => { + await expect(raceWithTimeout(dummyPromise, Infinity, dummyMessage)).rejects.toThrow(RangeError); + }); + + it("throws RangeError for -Infinity timeoutMs", async () => { + await expect(raceWithTimeout(dummyPromise, -Infinity, dummyMessage)).rejects.toThrow(RangeError); + }); + + it("accepts zero as a valid timeoutMs", async () => { + await expect(raceWithTimeout(Promise.resolve("ok"), 0, dummyMessage)).resolves.toBe("ok"); + }); + }); + + describe("makeErrorMessage guard", () => { + it("produces a TimeoutError with fallback message when makeErrorMessage throws", async () => { + const neverResolve = new Promise(() => {}); + const throwingMessage = () => { + throw new Error("boom"); + }; + + await expect(raceWithTimeout(neverResolve, 1, throwingMessage)).rejects.toThrow(TimeoutError); + await expect(raceWithTimeout(neverResolve, 1, throwingMessage)).rejects.toThrow( + "Operation timed out after 1ms", + ); + }); + }); + + describe("core behavior", () => { + it("resolves with the promise value when it settles before timeout", async () => { + const result = await raceWithTimeout(Promise.resolve(42), 1000, () => "timeout"); + expect(result).toBe(42); + }); + + it("throws TimeoutError when the promise does not settle in time", async () => { + const neverResolve = new Promise(() => {}); + await expect(raceWithTimeout(neverResolve, 1, () => "too slow")).rejects.toThrow(TimeoutError); + await expect(raceWithTimeout(neverResolve, 1, () => "too slow")).rejects.toThrow("too slow"); + }); + }); +}); diff --git a/packages/durabletask-js/test/tracing.spec.ts b/packages/durabletask-js/test/tracing.spec.ts new file mode 100644 index 0000000..a02efbd --- /dev/null +++ b/packages/durabletask-js/test/tracing.spec.ts @@ -0,0 +1,894 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import { + parseTraceparent, + createTraceparent, + generateSpanId, + TRACER_NAME, + DurableTaskAttributes, + TaskType, + createSpanName, + createTimerSpanName, +} from "../src/tracing/index"; + +import { + createPbTraceContext, + getOtelApi, + extractTraceparentFromSpan, + createParentContextFromPb, +} from "../src/tracing/trace-context-utils"; + +import { + startSpanForNewOrchestration, + startSpanForOrchestrationExecution, + startSpanForTaskExecution, + startSpanForEventRaisedFromClient, + emitSpanForTimer, + emitSpanForEventSent, + processActionsForTracing, + createOrchestrationTraceContextPb, + setSpanError, + setSpanOk, + endSpan, +} from "../src/tracing/trace-helper"; + +import * as pb from "../src/proto/orchestrator_service_pb"; +import { StringValue } from "google-protobuf/google/protobuf/wrappers_pb"; +import { Timestamp } from "google-protobuf/google/protobuf/timestamp_pb"; + +// Import OTEL packages once at module level +import * as otel from "@opentelemetry/api"; +import { BasicTracerProvider, SimpleSpanProcessor, InMemorySpanExporter } from "@opentelemetry/sdk-trace-base"; + +// Shared test infrastructure - single provider for the entire test file +let exporter: InMemorySpanExporter; +let provider: BasicTracerProvider; +let previousTracerProvider: otel.TracerProvider | undefined; + +beforeAll(() => { + exporter = new InMemorySpanExporter(); + provider = new BasicTracerProvider(); + provider.addSpanProcessor(new SimpleSpanProcessor(exporter)); + + // Save the current global tracer provider to restore it after this suite + previousTracerProvider = otel.trace.getTracerProvider(); + + // Register this test-specific provider as the global tracer provider + provider.register(); +}); + +afterAll(async () => { + await provider.shutdown(); + + // Restore the previous global tracer provider to avoid leaking state to other tests + if (previousTracerProvider) { + otel.trace.setGlobalTracerProvider(previousTracerProvider); + } +}); + +beforeEach(() => { + exporter.reset(); +}); + +describe("Tracing Constants", () => { + it("should have the correct tracer name", () => { + expect(TRACER_NAME).toBe("Microsoft.DurableTask"); + }); + + it("should have all expected attribute keys", () => { + expect(DurableTaskAttributes.TYPE).toBe("durabletask.type"); + expect(DurableTaskAttributes.TASK_NAME).toBe("durabletask.task.name"); + expect(DurableTaskAttributes.TASK_INSTANCE_ID).toBe("durabletask.task.instance_id"); + expect(DurableTaskAttributes.TASK_VERSION).toBe("durabletask.task.version"); + expect(DurableTaskAttributes.TASK_TASK_ID).toBe("durabletask.task.task_id"); + expect(DurableTaskAttributes.FIRE_AT).toBe("durabletask.fire_at"); + expect(DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID).toBe("durabletask.event.target_instance_id"); + }); + + it("should have all expected task types", () => { + expect(TaskType.ORCHESTRATION).toBe("orchestration"); + expect(TaskType.ACTIVITY).toBe("activity"); + expect(TaskType.TIMER).toBe("timer"); + expect(TaskType.ORCHESTRATION_EVENT).toBe("orchestration_event"); + expect(TaskType.CREATE_ORCHESTRATION).toBe("create_orchestration"); + }); +}); + +describe("createSpanName", () => { + it("should create a span name without version", () => { + expect(createSpanName("orchestration", "MyOrch")).toBe("orchestration:MyOrch"); + }); + + it("should create a span name with version", () => { + expect(createSpanName("orchestration", "MyOrch", "1.0.0")).toBe("orchestration:MyOrch@(1.0.0)"); + }); + + it("should handle empty version string", () => { + expect(createSpanName("activity", "MyActivity", "")).toBe("activity:MyActivity"); + }); +}); + +describe("createTimerSpanName", () => { + it("should create a timer span name", () => { + expect(createTimerSpanName("MyOrch")).toBe("timer:MyOrch"); + }); +}); + +describe("parseTraceparent", () => { + it("should parse a valid traceparent string", () => { + const result = parseTraceparent("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"); + expect(result).toBeDefined(); + expect(result!.traceId).toBe("0af7651916cd43dd8448eb211c80319c"); + expect(result!.spanId).toBe("b7ad6b7169203331"); + expect(result!.traceFlags).toBe(1); + }); + + it("should parse traceparent with traceFlags 00", () => { + const result = parseTraceparent("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-00"); + expect(result).toBeDefined(); + expect(result!.traceFlags).toBe(0); + }); + + it("should return undefined for invalid traceparent", () => { + expect(parseTraceparent("invalid")).toBeUndefined(); + expect(parseTraceparent("")).toBeUndefined(); + expect(parseTraceparent("00-123-456-01")).toBeUndefined(); + }); + + it("should return undefined for traceparent with wrong number of parts", () => { + expect(parseTraceparent("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331")).toBeUndefined(); + expect(parseTraceparent("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01-extra")).toBeUndefined(); + }); +}); + +describe("createTraceparent", () => { + it("should create a valid traceparent string", () => { + const result = createTraceparent("0af7651916cd43dd8448eb211c80319c", "b7ad6b7169203331", 1); + expect(result).toBe("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"); + }); + + it("should create traceparent with traceFlags 0", () => { + const result = createTraceparent("0af7651916cd43dd8448eb211c80319c", "b7ad6b7169203331", 0); + expect(result).toBe("00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-00"); + }); + + it("should round-trip with parseTraceparent", () => { + const original = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + const parsed = parseTraceparent(original)!; + const recreated = createTraceparent(parsed.traceId, parsed.spanId, parsed.traceFlags); + expect(recreated).toBe(original); + }); +}); + +describe("generateSpanId", () => { + it("should generate a 16-character hex string", () => { + const spanId = generateSpanId(); + expect(spanId).toMatch(/^[0-9a-f]{16}$/); + }); + + it("should generate unique span IDs", () => { + const ids = new Set(); + for (let i = 0; i < 100; i++) { + ids.add(generateSpanId()); + } + // With 100 random 8-byte values, collisions should be astronomically unlikely + expect(ids.size).toBe(100); + }); +}); + +describe("createPbTraceContext", () => { + it("should create a protobuf TraceContext with traceparent only", () => { + const traceparent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + const pbCtx = createPbTraceContext(traceparent); + + expect(pbCtx).toBeInstanceOf(pb.TraceContext); + expect(pbCtx.getTraceparent()).toBe(traceparent); + expect(pbCtx.getTracestate()).toBeUndefined(); + }); + + it("should create a protobuf TraceContext with tracestate", () => { + const traceparent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + const tracestate = "congo=ucfJifl5GOE,rojo=00f067aa0ba902b7"; + const pbCtx = createPbTraceContext(traceparent, tracestate); + + expect(pbCtx.getTraceparent()).toBe(traceparent); + expect(pbCtx.getTracestate()?.getValue()).toBe(tracestate); + }); +}); + +describe("getOtelApi", () => { + it("should return the OpenTelemetry API when available", () => { + const otel = getOtelApi(); + // @opentelemetry/api is a devDependency, so it should be available + expect(otel).toBeDefined(); + expect(otel!.trace).toBeDefined(); + expect(otel!.context).toBeDefined(); + expect(otel!.SpanKind).toBeDefined(); + expect(otel!.SpanStatusCode).toBeDefined(); + }); +}); + +describe("Trace Helper Integration", () => { + it("should create spans via the tracer", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("test-span"); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + expect(spans[0].name).toBe("test-span"); + }); + + it("should extract traceparent from an active span", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("extract-test"); + + const result = extractTraceparentFromSpan(span); + expect(result).toBeDefined(); + expect(result!.traceparent).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-0[01]$/); + + span.end(); + }); + + it("should create parent context from protobuf TraceContext", () => { + const traceparent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + const pbCtx = createPbTraceContext(traceparent); + + const parentContext = createParentContextFromPb(pbCtx); + expect(parentContext).toBeDefined(); + + // Verify we can create a child span from the context + const tracer = otel.trace.getTracer(TRACER_NAME); + const childSpan = tracer.startSpan("child-span", {}, parentContext!); + childSpan.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + expect(spans[0].name).toBe("child-span"); + // The child span should have the parent's trace ID + expect(spans[0].spanContext().traceId).toBe("0af7651916cd43dd8448eb211c80319c"); + }); + + it("should return undefined for createParentContextFromPb with no input", () => { + const result = createParentContextFromPb(undefined); + expect(result).toBeUndefined(); + }); +}); + +describe("Trace Helper - startSpanForNewOrchestration", () => { + it("should create a Producer span for a new orchestration", () => { + const req = new pb.CreateInstanceRequest(); + req.setName("MyOrchestration"); + req.setInstanceid("test-instance-123"); + + const span = startSpanForNewOrchestration(req); + expect(span).toBeDefined(); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + expect(spans[0].name).toBe("create_orchestration:MyOrchestration"); + expect(spans[0].kind).toBe(otel.SpanKind.PRODUCER); + expect(spans[0].attributes[DurableTaskAttributes.TYPE]).toBe(TaskType.CREATE_ORCHESTRATION); + expect(spans[0].attributes[DurableTaskAttributes.TASK_NAME]).toBe("MyOrchestration"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_INSTANCE_ID]).toBe("test-instance-123"); + }); + + it("should inject trace context into the CreateInstanceRequest", () => { + const req = new pb.CreateInstanceRequest(); + req.setName("MyOrchestration"); + req.setInstanceid("test-instance-456"); + + const span = startSpanForNewOrchestration(req); + span!.end(); + + // The parenttracecontext should be set on the request + const traceCtx = req.getParenttracecontext(); + expect(traceCtx).toBeDefined(); + expect(traceCtx!.getTraceparent()).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-0[01]$/); + }); + + it("should include version in span name and attributes when provided", () => { + const req = new pb.CreateInstanceRequest(); + req.setName("MyOrchestration"); + req.setInstanceid("test-instance-789"); + const versionValue = new StringValue(); + versionValue.setValue("2.0.0"); + req.setVersion(versionValue); + + const span = startSpanForNewOrchestration(req); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].name).toBe("create_orchestration:MyOrchestration@(2.0.0)"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_VERSION]).toBe("2.0.0"); + }); +}); + +describe("Trace Helper - error paths", () => { + it("startSpanForNewOrchestration should handle request with no version gracefully", () => { + const req = new pb.CreateInstanceRequest(); + req.setName("NoVersionOrch"); + req.setInstanceid("no-version-instance"); + + const span = startSpanForNewOrchestration(req); + expect(span).toBeDefined(); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].name).toBe("create_orchestration:NoVersionOrch"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_VERSION]).toBeUndefined(); + }); + + it("startSpanForNewOrchestration should handle empty name", () => { + const req = new pb.CreateInstanceRequest(); + req.setName(""); + req.setInstanceid("empty-name-instance"); + + const span = startSpanForNewOrchestration(req); + expect(span).toBeDefined(); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].name).toBe("create_orchestration:"); + }); + + it("startSpanForOrchestrationExecution should handle event with no parent trace context", () => { + const event = new pb.ExecutionStartedEvent(); + event.setName("NoParentCtxOrch"); + + const result = startSpanForOrchestrationExecution(event, undefined, "no-ctx-instance"); + expect(result).toBeDefined(); + result!.span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].name).toBe("orchestration:NoParentCtxOrch"); + expect(spans[0].kind).toBe(otel.SpanKind.SERVER); + }); + + it("startSpanForOrchestrationExecution should handle OrchestrationTraceContext with missing spanId", () => { + const event = new pb.ExecutionStartedEvent(); + event.setName("MissingSpanIdOrch"); + + // OrchestrationTraceContext with start time but no spanId + const orchTraceCtx = new pb.OrchestrationTraceContext(); + const startTimestamp = new Timestamp(); + startTimestamp.fromDate(new Date("2025-06-15T10:00:00Z")); + orchTraceCtx.setSpanstarttime(startTimestamp); + // Deliberately not setting spanId + + const result = startSpanForOrchestrationExecution(event, orchTraceCtx, "missing-spanid-instance"); + expect(result).toBeDefined(); + result!.span.end(); + + const spans = exporter.getFinishedSpans(); + // Should treat as first execution (not replay) since spanId is missing + expect(result!.spanInfo.spanId).toBe(spans[0].spanContext().spanId); + expect(spans[0].attributes[DurableTaskAttributes.REPLAY_SPAN_ID]).toBeUndefined(); + }); + + it("startSpanForOrchestrationExecution should handle OrchestrationTraceContext with missing startTime", () => { + const event = new pb.ExecutionStartedEvent(); + event.setName("MissingStartTimeOrch"); + + // OrchestrationTraceContext with spanId but no start time + const orchTraceCtx = new pb.OrchestrationTraceContext(); + const spanIdValue = new StringValue(); + spanIdValue.setValue("aabbccdd11223344"); + orchTraceCtx.setSpanid(spanIdValue); + // Deliberately not setting spanstarttime + + const result = startSpanForOrchestrationExecution(event, orchTraceCtx, "missing-starttime-instance"); + expect(result).toBeDefined(); + result!.span.end(); + + const spans = exporter.getFinishedSpans(); + // Should treat as first execution (not replay) since startTime is missing + expect(result!.spanInfo.spanId).toBe(spans[0].spanContext().spanId); + expect(spans[0].attributes[DurableTaskAttributes.REPLAY_SPAN_ID]).toBeUndefined(); + }); + + it("startSpanForTaskExecution should handle request with no parent trace context", () => { + const req = new pb.ActivityRequest(); + req.setName("NoCtxActivity"); + req.setTaskid(1); + + const orchInstance = new pb.OrchestrationInstance(); + orchInstance.setInstanceid("parent-orch"); + req.setOrchestrationinstance(orchInstance); + + const span = startSpanForTaskExecution(req); + expect(span).toBeDefined(); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].name).toBe("activity:NoCtxActivity"); + // Should still create a valid span, just without a parent + expect(spans[0].kind).toBe(otel.SpanKind.SERVER); + }); + + it("startSpanForTaskExecution should handle request with no orchestration instance", () => { + const req = new pb.ActivityRequest(); + req.setName("NoInstanceActivity"); + req.setTaskid(2); + // Deliberately not setting orchestration instance + + const span = startSpanForTaskExecution(req); + expect(span).toBeDefined(); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].name).toBe("activity:NoInstanceActivity"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_INSTANCE_ID]).toBe(""); + }); + + it("setSpanError should record exception for Error instances", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("error-exception-test"); + + const error = new Error("test error with stack"); + setSpanError(span, error); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].status.code).toBe(otel.SpanStatusCode.ERROR); + expect(spans[0].status.message).toBe("test error with stack"); + // Should have recorded the exception event + expect(spans[0].events.length).toBeGreaterThanOrEqual(1); + expect(spans[0].events[0].name).toBe("exception"); + }); + + it("setSpanError should not record exception for non-Error types", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("non-error-exception-test"); + + setSpanError(span, "string error"); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].status.code).toBe(otel.SpanStatusCode.ERROR); + // Should not have recorded an exception event for string errors + expect(spans[0].events.length).toBe(0); + }); + + it("endSpan should not throw when span.end() throws", () => { + const mockSpan = { + end: () => { + throw new Error("span already ended"); + }, + } as unknown as import("@opentelemetry/api").Span; + + expect(() => endSpan(mockSpan)).not.toThrow(); + }); +}); + +describe("Trace Helper - startSpanForTaskExecution", () => { + it("should create a Server span for activity execution", () => { + const req = new pb.ActivityRequest(); + req.setName("MyActivity"); + req.setTaskid(42); + + const orchInstance = new pb.OrchestrationInstance(); + orchInstance.setInstanceid("parent-orch-id"); + req.setOrchestrationinstance(orchInstance); + + const span = startSpanForTaskExecution(req); + expect(span).toBeDefined(); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + expect(spans[0].name).toBe("activity:MyActivity"); + expect(spans[0].kind).toBe(otel.SpanKind.SERVER); + expect(spans[0].attributes[DurableTaskAttributes.TYPE]).toBe(TaskType.ACTIVITY); + expect(spans[0].attributes[DurableTaskAttributes.TASK_NAME]).toBe("MyActivity"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_INSTANCE_ID]).toBe("parent-orch-id"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_TASK_ID]).toBe(42); + }); + + it("should parent span to trace context from ActivityRequest", () => { + const parentTraceparent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + + const req = new pb.ActivityRequest(); + req.setName("MyActivity"); + req.setTaskid(1); + + const parentCtx = createPbTraceContext(parentTraceparent); + req.setParenttracecontext(parentCtx); + + const orchInstance = new pb.OrchestrationInstance(); + orchInstance.setInstanceid("parent-orch-id"); + req.setOrchestrationinstance(orchInstance); + + const span = startSpanForTaskExecution(req); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + // The span should be parented to the given trace ID + expect(spans[0].spanContext().traceId).toBe("0af7651916cd43dd8448eb211c80319c"); + }); +}); + +describe("Trace Helper - setSpanError and setSpanOk", () => { + it("should set span status to ERROR with message", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("error-test"); + + setSpanError(span, new Error("Something went wrong")); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].status.code).toBe(otel.SpanStatusCode.ERROR); + expect(spans[0].status.message).toBe("Something went wrong"); + }); + + it("should set span status to OK", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("ok-test"); + + setSpanOk(span); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].status.code).toBe(otel.SpanStatusCode.OK); + }); + + it("should safely handle null/undefined span", () => { + expect(() => setSpanError(undefined, new Error("test"))).not.toThrow(); + expect(() => setSpanOk(undefined)).not.toThrow(); + expect(() => endSpan(undefined)).not.toThrow(); + expect(() => endSpan(null)).not.toThrow(); + }); +}); + +describe("Trace Helper - processActionsForTracing", () => { + it("should create spans for ScheduleTaskAction", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch"); + + const scheduleTask = new pb.ScheduleTaskAction(); + scheduleTask.setName("MyActivity"); + + const action = new pb.OrchestratorAction(); + action.setId(1); + action.setScheduletask(scheduleTask); + + processActionsForTracing(parentSpan, [action], "MyOrchestration"); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + // Should have parent + child (schedule task) + expect(spans.length).toBe(2); + + const childSpan = spans.find((s: any) => s.name === "activity:MyActivity"); + expect(childSpan).toBeDefined(); + expect(childSpan!.kind).toBe(otel.SpanKind.CLIENT); + + // Trace context should have been injected into the action + const traceCtx = scheduleTask.getParenttracecontext(); + expect(traceCtx).toBeDefined(); + expect(traceCtx!.getTraceparent()).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-0[01]$/); + }); + + it("should create spans for CreateSubOrchestrationAction", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch"); + + const createSubOrch = new pb.CreateSubOrchestrationAction(); + createSubOrch.setName("SubOrch"); + createSubOrch.setInstanceid("sub-orch-id"); + + const action = new pb.OrchestratorAction(); + action.setId(2); + action.setCreatesuborchestration(createSubOrch); + + processActionsForTracing(parentSpan, [action], "MyOrchestration"); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + const childSpan = spans.find((s: any) => s.name === "create_orchestration:SubOrch"); + expect(childSpan).toBeDefined(); + expect(childSpan!.kind).toBe(otel.SpanKind.CLIENT); + }); + + it("should create spans for CreateTimerAction", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch"); + + const fireAt = new Timestamp(); + fireAt.fromDate(new Date("2025-01-01T00:00:00Z")); + + const createTimer = new pb.CreateTimerAction(); + createTimer.setFireat(fireAt); + + const action = new pb.OrchestratorAction(); + action.setId(3); + action.setCreatetimer(createTimer); + + processActionsForTracing(parentSpan, [action], "MyOrchestration"); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + const timerSpan = spans.find((s: any) => s.name === "timer:MyOrchestration"); + expect(timerSpan).toBeDefined(); + expect(timerSpan!.kind).toBe(otel.SpanKind.INTERNAL); + }); + + it("should create spans for SendEventAction", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch"); + + const sendEvent = new pb.SendEventAction(); + sendEvent.setName("ApprovalEvent"); + const targetInstance = new pb.OrchestrationInstance(); + targetInstance.setInstanceid("target-instance-1"); + sendEvent.setInstance(targetInstance); + + const action = new pb.OrchestratorAction(); + action.setId(4); + action.setSendevent(sendEvent); + + processActionsForTracing(parentSpan, [action], "MyOrchestration"); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + const eventSpan = spans.find((s: any) => s.name === "orchestration_event:ApprovalEvent"); + expect(eventSpan).toBeDefined(); + expect(eventSpan!.kind).toBe(otel.SpanKind.PRODUCER); + expect(eventSpan!.attributes[DurableTaskAttributes.TYPE]).toBe(TaskType.ORCHESTRATION_EVENT); + expect(eventSpan!.attributes[DurableTaskAttributes.TASK_NAME]).toBe("ApprovalEvent"); + expect(eventSpan!.attributes[DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID]).toBe("target-instance-1"); + }); + + it("should create spans for SendEventAction without target instance", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch"); + + const sendEvent = new pb.SendEventAction(); + sendEvent.setName("EventNoTarget"); + + const action = new pb.OrchestratorAction(); + action.setId(5); + action.setSendevent(sendEvent); + + processActionsForTracing(parentSpan, [action], "MyOrchestration"); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + const eventSpan = spans.find((s: any) => s.name === "orchestration_event:EventNoTarget"); + expect(eventSpan).toBeDefined(); + expect(eventSpan!.kind).toBe(otel.SpanKind.PRODUCER); + expect(eventSpan!.attributes[DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID]).toBeUndefined(); + }); + + it("should not throw when orchestrationSpan is null or undefined", () => { + expect(() => processActionsForTracing(null, [], "test")).not.toThrow(); + expect(() => processActionsForTracing(undefined, [], "test")).not.toThrow(); + }); +}); + +describe("Trace Helper - createOrchestrationTraceContextPb", () => { + it("should create an OrchestrationTraceContext protobuf message", () => { + const spanInfo = { + spanId: "b7ad6b7169203331", + startTime: new Date("2025-01-01T12:00:00Z"), + }; + + const pbCtx = createOrchestrationTraceContextPb(spanInfo); + + expect(pbCtx).toBeInstanceOf(pb.OrchestrationTraceContext); + expect(pbCtx.getSpanid()?.getValue()).toBe("b7ad6b7169203331"); + expect(pbCtx.getSpanstarttime()?.toDate()).toEqual(new Date("2025-01-01T12:00:00Z")); + }); +}); + +describe("Trace Helper - startSpanForOrchestrationExecution", () => { + it("should create a Server span for first orchestration execution", () => { + const event = new pb.ExecutionStartedEvent(); + event.setName("MyOrchestration"); + const parentTraceparent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + const parentCtx = createPbTraceContext(parentTraceparent); + event.setParenttracecontext(parentCtx); + + const result = startSpanForOrchestrationExecution(event, undefined, "test-instance-1"); + expect(result).toBeDefined(); + expect(result!.span).toBeDefined(); + expect(result!.spanInfo.startTime).toBeInstanceOf(Date); + + result!.span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + + // On first execution, spanInfo.spanId should equal the actual OTEL span ID + expect(result!.spanInfo.spanId).toBe(spans[0].spanContext().spanId); + + expect(spans[0].name).toBe("orchestration:MyOrchestration"); + expect(spans[0].kind).toBe(otel.SpanKind.SERVER); + expect(spans[0].attributes[DurableTaskAttributes.TYPE]).toBe(TaskType.ORCHESTRATION); + expect(spans[0].attributes[DurableTaskAttributes.TASK_NAME]).toBe("MyOrchestration"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_INSTANCE_ID]).toBe("test-instance-1"); + // No REPLAY_SPAN_ID or REPLAY_START_TIME attribute on first execution + expect(spans[0].attributes[DurableTaskAttributes.REPLAY_SPAN_ID]).toBeUndefined(); + expect(spans[0].attributes[DurableTaskAttributes.REPLAY_START_TIME]).toBeUndefined(); + // The span should be parented to the given trace ID + expect(spans[0].spanContext().traceId).toBe("0af7651916cd43dd8448eb211c80319c"); + }); + + it("should reuse span identity on replay (existing OrchestrationTraceContext)", () => { + const event = new pb.ExecutionStartedEvent(); + event.setName("ReplayOrch"); + + // Simulate an OrchestrationTraceContext from a previous execution + const orchTraceCtx = new pb.OrchestrationTraceContext(); + const spanIdValue = new StringValue(); + spanIdValue.setValue("aabbccdd11223344"); + orchTraceCtx.setSpanid(spanIdValue); + const startTimestamp = new Timestamp(); + startTimestamp.fromDate(new Date("2025-06-15T10:00:00Z")); + orchTraceCtx.setSpanstarttime(startTimestamp); + + const result = startSpanForOrchestrationExecution(event, orchTraceCtx, "replay-instance"); + expect(result).toBeDefined(); + + // SpanInfo should carry forward the original span ID from the first execution + expect(result!.spanInfo.spanId).toBe("aabbccdd11223344"); + expect(result!.spanInfo.startTime).toEqual(new Date("2025-06-15T10:00:00Z")); + + result!.span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + expect(spans[0].name).toBe("orchestration:ReplayOrch"); + expect(spans[0].kind).toBe(otel.SpanKind.SERVER); + + // The OTEL span has its own spanId (different from the stored replay correlation ID) + expect(spans[0].spanContext().spanId).not.toBe("aabbccdd11223344"); + // The original span ID is stored as a REPLAY_SPAN_ID attribute for correlation + expect(spans[0].attributes[DurableTaskAttributes.REPLAY_SPAN_ID]).toBe("aabbccdd11223344"); + // The original start time is stored as a REPLAY_START_TIME attribute + expect(spans[0].attributes[DurableTaskAttributes.REPLAY_START_TIME]).toBe("2025-06-15T10:00:00.000Z"); + + // The OTEL span itself should start near the current time, not the original replay time + const spanStartMs = spans[0].startTime[0] * 1000 + spans[0].startTime[1] / 1e6; + const nowMs = Date.now(); + expect(nowMs - spanStartMs).toBeLessThan(5000); // within 5 seconds of now + }); + + it("should generate new span ID on first execution (no OrchestrationTraceContext)", () => { + const event = new pb.ExecutionStartedEvent(); + event.setName("FirstRunOrch"); + + const result = startSpanForOrchestrationExecution(event, undefined, "first-run-instance"); + expect(result).toBeDefined(); + + result!.span.end(); + + const spans = exporter.getFinishedSpans(); + // SpanInfo.spanId should equal the actual OTEL span ID on first execution + expect(result!.spanInfo.spanId).toBe(spans[0].spanContext().spanId); + expect(result!.spanInfo.startTime).toBeInstanceOf(Date); + }); + + it("should include version in span name and attributes when provided", () => { + const event = new pb.ExecutionStartedEvent(); + event.setName("VersionedOrch"); + const versionValue = new StringValue(); + versionValue.setValue("3.0.0"); + event.setVersion(versionValue); + + const result = startSpanForOrchestrationExecution(event, undefined, "versioned-instance"); + expect(result).toBeDefined(); + result!.span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].name).toBe("orchestration:VersionedOrch@(3.0.0)"); + expect(spans[0].attributes[DurableTaskAttributes.TASK_VERSION]).toBe("3.0.0"); + }); +}); + +describe("Trace Helper - emitSpanForTimer", () => { + it("should create an Internal span for a timer", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch-timer"); + const fireAt = new Date("2025-07-01T12:00:00Z"); + + emitSpanForTimer(parentSpan, "TimerOrch", fireAt, 5); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + const timerSpan = spans.find((s: any) => s.name === "timer:TimerOrch"); + expect(timerSpan).toBeDefined(); + expect(timerSpan!.kind).toBe(otel.SpanKind.INTERNAL); + expect(timerSpan!.attributes[DurableTaskAttributes.TYPE]).toBe(TaskType.TIMER); + expect(timerSpan!.attributes[DurableTaskAttributes.TASK_TASK_ID]).toBe(5); + expect(timerSpan!.attributes[DurableTaskAttributes.FIRE_AT]).toBe("2025-07-01T12:00:00.000Z"); + }); +}); + +describe("Trace Helper - emitSpanForEventSent", () => { + it("should create a Producer span for sending an event", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch-event"); + + emitSpanForEventSent(parentSpan, "ApprovalEvent", "target-instance-1"); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + const eventSpan = spans.find((s: any) => s.name === "orchestration_event:ApprovalEvent"); + expect(eventSpan).toBeDefined(); + expect(eventSpan!.kind).toBe(otel.SpanKind.PRODUCER); + expect(eventSpan!.attributes[DurableTaskAttributes.TYPE]).toBe(TaskType.ORCHESTRATION_EVENT); + expect(eventSpan!.attributes[DurableTaskAttributes.TASK_NAME]).toBe("ApprovalEvent"); + expect(eventSpan!.attributes[DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID]).toBe("target-instance-1"); + }); + + it("should handle missing target instance ID", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const parentSpan = tracer.startSpan("parent-orch-event2"); + + emitSpanForEventSent(parentSpan, "EventNoTarget"); + parentSpan.end(); + + const spans = exporter.getFinishedSpans(); + const eventSpan = spans.find((s: any) => s.name === "orchestration_event:EventNoTarget"); + expect(eventSpan).toBeDefined(); + expect(eventSpan!.attributes[DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID]).toBeUndefined(); + }); +}); + +describe("Trace Helper - startSpanForEventRaisedFromClient", () => { + it("should create a Producer span for raising an event from the client", () => { + const span = startSpanForEventRaisedFromClient("MyEvent", "target-instance-42"); + expect(span).toBeDefined(); + span!.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans.length).toBe(1); + expect(spans[0].name).toBe("orchestration_event:MyEvent"); + expect(spans[0].kind).toBe(otel.SpanKind.PRODUCER); + expect(spans[0].attributes[DurableTaskAttributes.TYPE]).toBe(TaskType.ORCHESTRATION_EVENT); + expect(spans[0].attributes[DurableTaskAttributes.TASK_NAME]).toBe("MyEvent"); + expect(spans[0].attributes[DurableTaskAttributes.EVENT_TARGET_INSTANCE_ID]).toBe("target-instance-42"); + }); +}); + +describe("Trace Helper - setSpanError with unknown types", () => { + it("should handle string error", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("string-error-test"); + + setSpanError(span, "plain string error"); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].status.code).toBe(otel.SpanStatusCode.ERROR); + expect(spans[0].status.message).toBe("plain string error"); + }); + + it("should handle non-Error non-string error (unknown type)", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("unknown-error-test"); + + setSpanError(span, 42); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].status.code).toBe(otel.SpanStatusCode.ERROR); + expect(spans[0].status.message).toBe("42"); + }); + + it("should handle null/undefined error gracefully", () => { + const tracer = otel.trace.getTracer(TRACER_NAME); + const span = tracer.startSpan("null-error-test"); + + setSpanError(span, null); + span.end(); + + const spans = exporter.getFinishedSpans(); + expect(spans[0].status.code).toBe(otel.SpanStatusCode.ERROR); + expect(spans[0].status.message).toBe("null"); + }); +}); diff --git a/packages/durabletask-js/test/worker-tracing.spec.ts b/packages/durabletask-js/test/worker-tracing.spec.ts new file mode 100644 index 0000000..8982df6 --- /dev/null +++ b/packages/durabletask-js/test/worker-tracing.spec.ts @@ -0,0 +1,436 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +/** + * Tests for the tracing integration in the worker execution flow. + * + * These tests validate the tracing behavior that the TaskHubGrpcWorker + * relies on during orchestration and activity execution, specifically: + * 1. Orchestration span is ended in both success and exception paths + * 2. OrchestratorResponse.orchestrationtracecontext is set when tracing is enabled + * 3. Scheduled actions get parenttracecontext injected + */ + +import * as pb from "../src/proto/orchestrator_service_pb"; +import { + newOrchestratorStartedEvent, + newExecutionStartedEvent, +} from "../src/utils/pb-helper.util"; +import { OrchestrationExecutor } from "../src/worker/orchestration-executor"; +import { Registry } from "../src/worker/registry"; +import { NoOpLogger } from "../src/types/logger.type"; +import { TOrchestrator } from "../src/types/orchestrator.type"; +import { OrchestrationContext } from "../src/task/context/orchestration-context"; +import { ActivityContext } from "../src/task/context/activity-context"; + +import { + startSpanForOrchestrationExecution, + startSpanForTaskExecution, + processActionsForTracing, + createOrchestrationTraceContextPb, + setSpanError, + setSpanOk, + endSpan, + DurableTaskAttributes, + TaskType, + createPbTraceContext, +} from "../src/tracing"; + +import * as otel from "@opentelemetry/api"; +import { + BasicTracerProvider, + SimpleSpanProcessor, + InMemorySpanExporter, +} from "@opentelemetry/sdk-trace-base"; + +const testLogger = new NoOpLogger(); +const TEST_INSTANCE_ID = "worker-tracing-test-instance"; + +let exporter: InMemorySpanExporter; +let provider: BasicTracerProvider; +let previousTracerProvider: otel.TracerProvider | undefined; + +beforeAll(() => { + exporter = new InMemorySpanExporter(); + provider = new BasicTracerProvider(); + provider.addSpanProcessor(new SimpleSpanProcessor(exporter)); + + previousTracerProvider = otel.trace.getTracerProvider(); + provider.register(); +}); + +afterAll(async () => { + await provider.shutdown(); + + if (previousTracerProvider) { + otel.trace.setGlobalTracerProvider(previousTracerProvider); + } +}); + +beforeEach(() => { + exporter.reset(); +}); + +/** + * Helper that mirrors the worker's _executeOrchestratorInternal tracing flow. + * This replicates the exact sequence of tracing calls made by the worker so + * we can validate the tracing behavior without needing a gRPC stub. + */ +async function executeOrchestrationWithTracing( + registry: Registry, + instanceId: string, + pastEvents: pb.HistoryEvent[], + newEvents: pb.HistoryEvent[], +): Promise<{ response: pb.OrchestratorResponse; error?: Error }> { + // Find the ExecutionStartedEvent (mirrors worker logic) + const allProtoEvents = [...pastEvents, ...newEvents]; + let executionStartedProtoEvent: pb.ExecutionStartedEvent | undefined; + for (const protoEvent of allProtoEvents) { + if (protoEvent.hasExecutionstarted()) { + executionStartedProtoEvent = protoEvent.getExecutionstarted()!; + break; + } + } + + // Start the orchestration span (mirrors worker logic) + const tracingResult = executionStartedProtoEvent + ? startSpanForOrchestrationExecution(executionStartedProtoEvent, undefined, instanceId) + : undefined; + + let res: pb.OrchestratorResponse; + let caughtError: Error | undefined; + + try { + const executor = new OrchestrationExecutor(registry, testLogger); + const result = await executor.execute(instanceId, pastEvents, newEvents); + + // Process actions for tracing (mirrors worker logic) + if (tracingResult) { + const orchName = executionStartedProtoEvent?.getName() ?? ""; + processActionsForTracing(tracingResult.span, result.actions, orchName); + } + + res = new pb.OrchestratorResponse(); + res.setInstanceid(instanceId); + res.setActionsList(result.actions); + + // Set orchestration trace context on the response (mirrors worker logic) + if (tracingResult) { + const orchTraceCtxPb = createOrchestrationTraceContextPb(tracingResult.spanInfo); + res.setOrchestrationtracecontext(orchTraceCtxPb); + setSpanOk(tracingResult.span); + } + } catch (e: any) { + caughtError = e; + + if (tracingResult) { + setSpanError(tracingResult.span, e); + } + + res = new pb.OrchestratorResponse(); + res.setInstanceid(instanceId); + } finally { + // Always end the span (mirrors worker's finally block) + endSpan(tracingResult?.span); + } + + return { response: res!, error: caughtError }; +} + +describe("Worker Tracing - Orchestration Span Lifecycle", () => { + it("should end the orchestration span with OK status on success", async () => { + const orchestrator: TOrchestrator = async (_: OrchestrationContext) => { + return "success"; + }; + + const registry = new Registry(); + const name = registry.addOrchestrator(orchestrator); + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, JSON.stringify("input")), + ]; + + await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + const spans = exporter.getFinishedSpans(); + // Should have exactly 1 orchestration span + const orchSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ORCHESTRATION, + ); + expect(orchSpan).toBeDefined(); + expect(orchSpan!.status.code).toBe(otel.SpanStatusCode.OK); + // Span should be ended (it appears in finished spans) + expect(orchSpan!.endTime).toBeDefined(); + }); + + it("should end the orchestration span with ERROR status on executor failure", async () => { + // Use an unregistered orchestrator name to force a failure + const registry = new Registry(); + const name = "UnregisteredOrchestrator"; + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, undefined), + ]; + + await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + const spans = exporter.getFinishedSpans(); + const orchSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ORCHESTRATION, + ); + expect(orchSpan).toBeDefined(); + // Unregistered orchestrator results in a FAILED completion action (not a thrown error), + // so the span should still be ended with OK status since the executor handles it gracefully + expect(orchSpan!.endTime).toBeDefined(); + }); + + it("should end the orchestration span even when executor throws", async () => { + // Create an orchestrator that throws during execution + const throwingOrchestrator: TOrchestrator = async (_: OrchestrationContext) => { + throw new Error("Orchestrator crashed"); + }; + + const registry = new Registry(); + const name = registry.addOrchestrator(throwingOrchestrator); + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, undefined), + ]; + + const { error: _error } = await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + const spans = exporter.getFinishedSpans(); + const orchSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ORCHESTRATION, + ); + expect(orchSpan).toBeDefined(); + // The span should always be ended, even on error + expect(orchSpan!.endTime).toBeDefined(); + + // Note: the OrchestrationExecutor catches orchestrator errors internally and + // returns a FAILED action. If the error propagated out, the span should have ERROR status. + }); +}); + +describe("Worker Tracing - OrchestratorResponse.orchestrationtracecontext", () => { + it("should set orchestrationtracecontext on the response", async () => { + const orchestrator: TOrchestrator = async (_: OrchestrationContext) => { + return "done"; + }; + + const registry = new Registry(); + const name = registry.addOrchestrator(orchestrator); + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, undefined), + ]; + + const { response } = await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + const traceCtx = response.getOrchestrationtracecontext(); + expect(traceCtx).toBeDefined(); + // The span ID should be set for replay continuity + expect(traceCtx!.getSpanid()?.getValue()).toBeDefined(); + expect(traceCtx!.getSpanid()!.getValue().length).toBe(16); // 16 hex chars + // The start time should be set + expect(traceCtx!.getSpanstarttime()).toBeDefined(); + }); + + it("should have matching spanId between trace context and finished span on first execution", async () => { + const orchestrator: TOrchestrator = async (_: OrchestrationContext) => { + return "done"; + }; + + const registry = new Registry(); + const name = registry.addOrchestrator(orchestrator); + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, undefined), + ]; + + const { response } = await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + const traceCtx = response.getOrchestrationtracecontext(); + const spans = exporter.getFinishedSpans(); + const orchSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ORCHESTRATION, + ); + + // On first execution, the stored spanId should match the actual OTEL span ID + expect(traceCtx!.getSpanid()!.getValue()).toBe(orchSpan!.spanContext().spanId); + }); +}); + +describe("Worker Tracing - Scheduled Actions Trace Context Injection", () => { + it("should inject parenttracecontext into ScheduleTaskAction", async () => { + const myActivity = async (_: ActivityContext, input: number) => input + 1; + + const orchestrator: TOrchestrator = async function* (ctx: OrchestrationContext): any { + yield ctx.callActivity(myActivity, 1); + return "done"; + }; + + const registry = new Registry(); + const name = registry.addOrchestrator(orchestrator); + registry.addActivity(myActivity); + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, undefined), + ]; + + const { response } = await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + // Find the ScheduleTaskAction in the response actions + const actions = response.getActionsList(); + const scheduleTaskAction = actions.find((a) => a.hasScheduletask()); + expect(scheduleTaskAction).toBeDefined(); + + const scheduleTask = scheduleTaskAction!.getScheduletask()!; + const traceCtx = scheduleTask.getParenttracecontext(); + expect(traceCtx).toBeDefined(); + // Should have a valid traceparent + expect(traceCtx!.getTraceparent()).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-0[01]$/); + + // Verify OTEL spans were created: orchestration span + scheduling span + const spans = exporter.getFinishedSpans(); + const orchSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ORCHESTRATION, + ); + const activityScheduleSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ACTIVITY, + ); + expect(orchSpan).toBeDefined(); + expect(activityScheduleSpan).toBeDefined(); + // The schedule span should be a CLIENT span (act of scheduling) + expect(activityScheduleSpan!.kind).toBe(otel.SpanKind.CLIENT); + }); + + it("should inject parenttracecontext into CreateSubOrchestrationAction", async () => { + const childOrchestrator: TOrchestrator = async (_: OrchestrationContext) => "child done"; + + const parentOrchestrator: TOrchestrator = async function* (ctx: OrchestrationContext): any { + yield ctx.callSubOrchestrator(childOrchestrator); + return "parent done"; + }; + + const registry = new Registry(); + const name = registry.addOrchestrator(parentOrchestrator); + registry.addOrchestrator(childOrchestrator); + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, undefined), + ]; + + const { response } = await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + // Find the CreateSubOrchestrationAction in the response actions + const actions = response.getActionsList(); + const subOrchAction = actions.find((a) => a.hasCreatesuborchestration()); + expect(subOrchAction).toBeDefined(); + + const createSubOrch = subOrchAction!.getCreatesuborchestration()!; + const traceCtx = createSubOrch.getParenttracecontext(); + expect(traceCtx).toBeDefined(); + // Should have a valid traceparent + expect(traceCtx!.getTraceparent()).toMatch(/^00-[0-9a-f]{32}-[0-9a-f]{16}-0[01]$/); + + // Verify the scheduling span was created + const spans = exporter.getFinishedSpans(); + const subOrchScheduleSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.CREATE_ORCHESTRATION, + ); + expect(subOrchScheduleSpan).toBeDefined(); + expect(subOrchScheduleSpan!.kind).toBe(otel.SpanKind.CLIENT); + }); + + it("should inject parenttracecontext with trace ID from parent span", async () => { + const myActivity = async (_: ActivityContext, input: number) => input + 1; + + const orchestrator: TOrchestrator = async function* (ctx: OrchestrationContext): any { + yield ctx.callActivity(myActivity, 1); + return "done"; + }; + + const registry = new Registry(); + const name = registry.addOrchestrator(orchestrator); + registry.addActivity(myActivity); + const newEvents = [ + newOrchestratorStartedEvent(new Date()), + newExecutionStartedEvent(name, TEST_INSTANCE_ID, undefined), + ]; + + const { response } = await executeOrchestrationWithTracing(registry, TEST_INSTANCE_ID, [], newEvents); + + // Get the orchestration span's trace ID + const spans = exporter.getFinishedSpans(); + const orchSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ORCHESTRATION, + ); + const orchTraceId = orchSpan!.spanContext().traceId; + + // The injected traceparent should carry the same trace ID + const actions = response.getActionsList(); + const scheduleTaskAction = actions.find((a) => a.hasScheduletask()); + const traceparent = scheduleTaskAction!.getScheduletask()!.getParenttracecontext()!.getTraceparent(); + expect(traceparent).toContain(orchTraceId); + }); +}); + +describe("Worker Tracing - Activity Span Lifecycle", () => { + it("should end the activity span with OK status on success", () => { + // Create an ActivityRequest with parent trace context + const req = new pb.ActivityRequest(); + req.setName("TestActivity"); + req.setTaskid(1); + const orchInstance = new pb.OrchestrationInstance(); + orchInstance.setInstanceid(TEST_INSTANCE_ID); + req.setOrchestrationinstance(orchInstance); + + const parentTraceparent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"; + const parentCtx = createPbTraceContext(parentTraceparent); + req.setParenttracecontext(parentCtx); + + // Mirror the worker's activity tracing flow + const activitySpan = startSpanForTaskExecution(req); + expect(activitySpan).toBeDefined(); + + // Simulate success + setSpanOk(activitySpan); + endSpan(activitySpan); + + const spans = exporter.getFinishedSpans(); + const actSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ACTIVITY, + ); + expect(actSpan).toBeDefined(); + expect(actSpan!.status.code).toBe(otel.SpanStatusCode.OK); + expect(actSpan!.endTime).toBeDefined(); + expect(actSpan!.kind).toBe(otel.SpanKind.SERVER); + }); + + it("should end the activity span with ERROR status on failure", () => { + const req = new pb.ActivityRequest(); + req.setName("FailingActivity"); + req.setTaskid(2); + const orchInstance = new pb.OrchestrationInstance(); + orchInstance.setInstanceid(TEST_INSTANCE_ID); + req.setOrchestrationinstance(orchInstance); + + const activitySpan = startSpanForTaskExecution(req); + expect(activitySpan).toBeDefined(); + + // Simulate failure + const error = new Error("Activity failed"); + setSpanError(activitySpan, error); + endSpan(activitySpan); + + const spans = exporter.getFinishedSpans(); + const actSpan = spans.find( + (s) => s.attributes[DurableTaskAttributes.TYPE] === TaskType.ACTIVITY, + ); + expect(actSpan).toBeDefined(); + expect(actSpan!.status.code).toBe(otel.SpanStatusCode.ERROR); + expect(actSpan!.status.message).toBe("Activity failed"); + expect(actSpan!.endTime).toBeDefined(); + }); +}); diff --git a/test/e2e-azuremanaged/query-apis.spec.ts b/test/e2e-azuremanaged/query-apis.spec.ts index 0630329..6b85452 100644 --- a/test/e2e-azuremanaged/query-apis.spec.ts +++ b/test/e2e-azuremanaged/query-apis.spec.ts @@ -6,14 +6,14 @@ * * NOTE: These tests can run against either: * 1. DTS emulator - set ENDPOINT and TASKHUB environment variables - * 2. Real Azure DTS - set AZURE_DTS_CONNECTION_STRING environment variable + * 2. Real Azure DTS - set DURABLE_TASK_SCHEDULER_CONNECTION_STRING environment variable * * Example for emulator: * docker run -i -p 8080:8080 -d mcr.microsoft.com/dts/dts-emulator:latest * ENDPOINT=localhost:8080 TASKHUB=default npx jest query-apis.spec.ts * * Example for real DTS: - * AZURE_DTS_CONNECTION_STRING="Endpoint=https://...;Authentication=DefaultAzure;TaskHub=th3" npx jest query-apis.spec.ts + * DURABLE_TASK_SCHEDULER_CONNECTION_STRING="Endpoint=https://...;Authentication=DefaultAzure;TaskHub=th3" npx jest query-apis.spec.ts */ import { @@ -32,7 +32,7 @@ import { } from "@microsoft/durabletask-js-azuremanaged"; // Read environment variables - support both connection string and endpoint/taskhub -const connectionString = process.env.AZURE_DTS_CONNECTION_STRING; +const connectionString = process.env.DURABLE_TASK_SCHEDULER_CONNECTION_STRING; const endpoint = process.env.ENDPOINT || "localhost:8080"; const taskHub = process.env.TASKHUB || "default"; diff --git a/test/e2e-azuremanaged/restart.spec.ts b/test/e2e-azuremanaged/restart.spec.ts index 352e433..2cf0cf0 100644 --- a/test/e2e-azuremanaged/restart.spec.ts +++ b/test/e2e-azuremanaged/restart.spec.ts @@ -10,7 +10,7 @@ * Environment variables: * - ENDPOINT: The endpoint for the DTS emulator (default: localhost:8080) * - TASKHUB: The task hub name (default: default) - * - AZURE_DTS_CONNECTION_STRING: Optional connection string for real Azure DTS + * - DURABLE_TASK_SCHEDULER_CONNECTION_STRING: Optional connection string for real Azure DTS */ import { @@ -29,7 +29,7 @@ import { DefaultAzureCredential } from "@azure/identity"; // Read environment variables const endpoint = process.env.ENDPOINT || "localhost:8080"; const taskHub = process.env.TASKHUB || "default"; -const connectionString = process.env.AZURE_DTS_CONNECTION_STRING; +const connectionString = process.env.DURABLE_TASK_SCHEDULER_CONNECTION_STRING; /** * Helper to create a client that works with both emulator and real Azure DTS diff --git a/test/e2e-azuremanaged/rewind.spec.ts b/test/e2e-azuremanaged/rewind.spec.ts index f49e1dc..8f696ee 100644 --- a/test/e2e-azuremanaged/rewind.spec.ts +++ b/test/e2e-azuremanaged/rewind.spec.ts @@ -6,14 +6,14 @@ * * NOTE: These tests can run against either: * 1. DTS emulator - set ENDPOINT and TASKHUB environment variables - * 2. Real Azure DTS - set AZURE_DTS_CONNECTION_STRING environment variable + * 2. Real Azure DTS - set DURABLE_TASK_SCHEDULER_CONNECTION_STRING environment variable * * Example for emulator: * docker run -i -p 8080:8080 -d mcr.microsoft.com/dts/dts-emulator:latest * ENDPOINT=localhost:8080 TASKHUB=default npx jest rewind.spec.ts * * Example for real DTS: - * AZURE_DTS_CONNECTION_STRING="Endpoint=https://...;Authentication=DefaultAzure;TaskHub=th3" npx jest rewind.spec.ts + * DURABLE_TASK_SCHEDULER_CONNECTION_STRING="Endpoint=https://...;Authentication=DefaultAzure;TaskHub=th3" npx jest rewind.spec.ts */ import { @@ -29,7 +29,7 @@ import { } from "@microsoft/durabletask-js-azuremanaged"; // Read environment variables - support both connection string and endpoint/taskhub -const connectionString = process.env.AZURE_DTS_CONNECTION_STRING; +const connectionString = process.env.DURABLE_TASK_SCHEDULER_CONNECTION_STRING; const endpoint = process.env.ENDPOINT || "localhost:8080"; const taskHub = process.env.TASKHUB || "default";