From c08340585d74009ee9d11f3fbe5a0dbabdda1928 Mon Sep 17 00:00:00 2001 From: wangbill Date: Wed, 5 Aug 2026 10:31:19 -0700 Subject: [PATCH 01/12] fix: await worker startup readiness Make worker startup await the initial sidecar stream, bound connection setup with a configurable timeout, and cleanly abort failed or stopped attempts. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> --- CHANGELOG.md | 2 + README.md | 4 + .../durabletask-js-azuremanaged/CHANGELOG.md | 2 + .../durabletask-js-azuremanaged/README.md | 4 + .../src/worker-builder.ts | 15 + .../test/unit/worker-builder.spec.ts | 11 + .../src/worker/task-hub-grpc-worker.ts | 245 +++++++++-- .../test/worker-startup.spec.ts | 379 ++++++++++++++++++ .../test/worker-stream-recovery.spec.ts | 9 +- 9 files changed, 637 insertions(+), 34 deletions(-) create mode 100644 packages/durabletask-js/test/worker-startup.spec.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index b4508367..3cea5161 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,8 @@ ### Fixes +- Make `TaskHubGrpcWorker.start()` wait for its initial work-item stream and time out unresponsive sidecar startup connections. + ## v0.4.0 (2026-07-31) ### Changes diff --git a/README.md b/README.md index 9c5b9ef9..86ad56b8 100644 --- a/README.md +++ b/README.md @@ -81,6 +81,10 @@ const state = await client.waitForOrchestrationCompletion(id, true, 60); console.log(`Result: ${state?.serializedOutput}`); ``` +`await worker.start()` resolves only after the initial sidecar handshake succeeds and the +work-item stream is established. Startup times out after 30 seconds by default; use +the worker builder's `.startupTimeout(milliseconds)` method to configure it. + You can find more samples in the [examples/azure-managed](./examples/azure-managed) directory. ### Reusing orchestration instance IDs diff --git a/packages/durabletask-js-azuremanaged/CHANGELOG.md b/packages/durabletask-js-azuremanaged/CHANGELOG.md index 532f5c30..d6876583 100644 --- a/packages/durabletask-js-azuremanaged/CHANGELOG.md +++ b/packages/durabletask-js-azuremanaged/CHANGELOG.md @@ -4,6 +4,8 @@ ### Fixes +- Add `startupTimeout()` to configure the core worker's sidecar connection startup timeout. + ## v0.4.0 (2026-07-31) ### Changes diff --git a/packages/durabletask-js-azuremanaged/README.md b/packages/durabletask-js-azuremanaged/README.md index 029e569b..092c62b6 100644 --- a/packages/durabletask-js-azuremanaged/README.md +++ b/packages/durabletask-js-azuremanaged/README.md @@ -53,6 +53,10 @@ const worker = createAzureManagedWorkerBuilder("https://myservice.durabletask.io await worker.start(); ``` +`start()` resolves after the initial sidecar handshake and work-item stream are established. +The startup timeout defaults to 30 seconds and can be configured with +`.startupTimeout(milliseconds)` on the worker builder. + ## Supported Authentication Types The connection string `Authentication` parameter supports the following values: diff --git a/packages/durabletask-js-azuremanaged/src/worker-builder.ts b/packages/durabletask-js-azuremanaged/src/worker-builder.ts index f749ea79..901e2662 100644 --- a/packages/durabletask-js-azuremanaged/src/worker-builder.ts +++ b/packages/durabletask-js-azuremanaged/src/worker-builder.ts @@ -29,6 +29,7 @@ export class DurableTaskAzureManagedWorkerBuilder { private _entities: { name?: string; factory: EntityFactory }[] = []; private _logger: Logger = new ConsoleLogger(); private _shutdownTimeoutMs?: number; + private _startupTimeoutMs?: number; private _versioning?: VersioningOptions; private _workItemFilters?: WorkItemFilters | "auto"; @@ -236,6 +237,19 @@ export class DurableTaskAzureManagedWorkerBuilder { return this; } + /** + * Sets the startup timeout in milliseconds. + * This is the maximum time to establish the initial sidecar connection. + * Defaults to 30000 (30 seconds). + * + * @param timeoutMs The startup timeout in milliseconds. + * @returns This builder instance. + */ + startupTimeout(timeoutMs: number): DurableTaskAzureManagedWorkerBuilder { + this._startupTimeoutMs = timeoutMs; + return this; + } + /** * Configures versioning options for the worker. * This allows filtering orchestrations by version using different match strategies. @@ -293,6 +307,7 @@ export class DurableTaskAzureManagedWorkerBuilder { metadataGenerator, logger: this._logger, shutdownTimeoutMs: this._shutdownTimeoutMs, + startupTimeoutMs: this._startupTimeoutMs, versioning: this._versioning, workItemFilters: this._workItemFilters, }); diff --git a/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts b/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts index d0f97cb4..577111f4 100644 --- a/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts +++ b/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts @@ -90,4 +90,15 @@ describe("DurableTaskAzureManagedWorkerBuilder", () => { expect(result).toBe(builder); }); }); + + describe("startupTimeout", () => { + it("configures the core worker startup timeout", () => { + const worker = new DurableTaskAzureManagedWorkerBuilder() + .endpoint(ENDPOINT, TASKHUB, null) + .startupTimeout(1234) + .build(); + + expect((worker as any)._startupTimeoutMs).toBe(1234); + }); + }); }); 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 56bad094..a22dd850 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -37,9 +37,14 @@ import { setSpanOk, endSpan, } from "../tracing"; +import { raceWithTimeout } from "../utils/timeout.util"; +import { TimeoutError } from "../exception/timeout-error"; /** Default timeout in milliseconds for graceful shutdown. */ const DEFAULT_SHUTDOWN_TIMEOUT_MS = 30000; +/** Default timeout in milliseconds for establishing the initial worker connection. */ +const DEFAULT_STARTUP_TIMEOUT_MS = 30000; +const MAX_TIMER_DELAY_MS = 2147483647; /** * Options for creating a TaskHubGrpcWorker. @@ -59,6 +64,12 @@ export interface TaskHubGrpcWorkerOptions { logger?: Logger; /** Optional timeout in milliseconds for graceful shutdown. Defaults to 30000. */ shutdownTimeoutMs?: number; + /** + * Optional timeout in milliseconds for establishing the initial sidecar connection, + * including metadata generation, the hello handshake, and work-item stream readiness. + * Defaults to 30000. + */ + startupTimeoutMs?: number; /** Optional versioning options for filtering orchestrations by version. */ versioning?: VersioningOptions; /** @@ -73,6 +84,7 @@ export interface TaskHubGrpcWorkerOptions { export class TaskHubGrpcWorker { private _responseStream: grpc.ClientReadableStream | null; + private _helloCall: grpc.ClientUnaryCall | null; private _registry: Registry; private _hostAddress?: string; private _tls?: boolean; @@ -85,9 +97,12 @@ export class TaskHubGrpcWorker { private _logger: Logger; private _pendingWorkItems: Set>; private _shutdownTimeoutMs: number; + private _startupTimeoutMs: number; private _backoff: ExponentialBackoff; private _versioning?: VersioningOptions; private _workItemFilters?: WorkItemFilters | "auto"; + private _connectionGeneration: number; + private _connectionAbort: { generation: number; abort: (error: Error) => void } | null; /** * Creates a new TaskHubGrpcWorker instance. @@ -134,6 +149,7 @@ export class TaskHubGrpcWorker { let resolvedMetadataGenerator: MetadataGenerator | undefined; let resolvedLogger: Logger | undefined; let resolvedShutdownTimeoutMs: number | undefined; + let resolvedStartupTimeoutMs: number | undefined; let resolvedVersioning: VersioningOptions | undefined; let resolvedWorkItemFilters: WorkItemFilters | "auto" | undefined; @@ -146,6 +162,7 @@ export class TaskHubGrpcWorker { resolvedMetadataGenerator = hostAddressOrOptions.metadataGenerator; resolvedLogger = hostAddressOrOptions.logger; resolvedShutdownTimeoutMs = hostAddressOrOptions.shutdownTimeoutMs; + resolvedStartupTimeoutMs = hostAddressOrOptions.startupTimeoutMs; resolvedVersioning = hostAddressOrOptions.versioning; resolvedWorkItemFilters = hostAddressOrOptions.workItemFilters; } else { @@ -166,12 +183,23 @@ export class TaskHubGrpcWorker { this._grpcChannelCredentials = resolvedCredentials; this._metadataGenerator = resolvedMetadataGenerator; this._responseStream = null; + this._helloCall = null; this._isRunning = false; this._stopWorker = false; this._stub = null; this._logger = resolvedLogger ?? new ConsoleLogger(); this._pendingWorkItems = new Set(); this._shutdownTimeoutMs = resolvedShutdownTimeoutMs ?? DEFAULT_SHUTDOWN_TIMEOUT_MS; + this._startupTimeoutMs = resolvedStartupTimeoutMs ?? DEFAULT_STARTUP_TIMEOUT_MS; + if ( + !Number.isFinite(this._startupTimeoutMs) || + this._startupTimeoutMs < 0 || + this._startupTimeoutMs > MAX_TIMER_DELAY_MS + ) { + throw new RangeError( + `startupTimeoutMs must be a finite number between 0 and ${MAX_TIMER_DELAY_MS}, got ${this._startupTimeoutMs}`, + ); + } this._backoff = new ExponentialBackoff({ initialDelayMs: 1000, maxDelayMs: 30000, @@ -179,6 +207,8 @@ export class TaskHubGrpcWorker { }); this._versioning = resolvedVersioning; this._workItemFilters = resolvedWorkItemFilters; + this._connectionGeneration = 0; + this._connectionAbort = null; } /** @@ -195,13 +225,21 @@ export class TaskHubGrpcWorker { * Creates a new gRPC client and retries the worker. * Properly closes the old client to prevent connection leaks. */ - private async _createNewClientAndRetry(): Promise { + private async _createNewClientAndRetry(generation: number = this._connectionGeneration): Promise { + if (!this._isConnectionAttemptActive(generation)) { + return; + } + // Close the old stub to prevent connection leaks if (this._stub) { this._stub.close(); + this._stub = null; } await this._backoff.wait(); + if (!this._isConnectionAttemptActive(generation)) { + return; + } const newClient = new GrpcClient( this._hostAddress, @@ -212,7 +250,7 @@ export class TaskHubGrpcWorker { this._stub = newClient.stub; // Do not await - run in background - this.internalRunWorker(newClient, true).catch((err) => { + this.internalRunWorker(newClient, true, generation).catch((err) => { if (!this._stopWorker) { WorkerLogs.workerError(this._logger, err); } @@ -382,45 +420,106 @@ export class TaskHubGrpcWorker { /** * In node.js we don't require a new thread as we have a main event loop * Therefore, we open the stream and simply listen through the eventemitter behind the scenes + * + * @remarks Resolves after the sidecar hello handshake succeeds and the initial + * work-item stream is established. Later stream failures reconnect automatically. + * @throws {@link TimeoutError} if the hello handshake exceeds `startupTimeoutMs`. */ async start(): Promise { if (this._isRunning) { throw new Error("The worker is already running."); } + this._isRunning = true; + this._stopWorker = false; + const generation = ++this._connectionGeneration; const client = new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); this._stub = client.stub; - // Run in background but catch any unhandled errors to prevent unhandled rejections - this.internalRunWorker(client).catch((err) => { - // Only log if the worker wasn't stopped intentionally - if (!this._stopWorker) { - WorkerLogs.workerError(this._logger, err); + try { + await this.internalRunWorker(client, false, generation); + this._ensureConnectionAttemptActive(generation); + } catch (err) { + client.stub.close(); + if (this._stub === client.stub) { + this._stub = null; } - }); - - this._isRunning = true; + if (generation === this._connectionGeneration) { + this._responseStream = null; + this._isRunning = false; + } + throw err; + } } - async internalRunWorker(client: GrpcClient, isRetry: boolean = false): Promise { + async internalRunWorker( + client: GrpcClient, + isRetry: boolean = false, + generation: number = this._connectionGeneration, + ): Promise { + let abortConnection: (error: Error) => void; + const connectionAborted = new Promise((_, reject) => { + let aborted = false; + abortConnection = (error: Error) => { + if (!aborted) { + aborted = true; + reject(error); + } + }; + }); + const connectionAbort = { generation, abort: abortConnection! }; + this._connectionAbort = connectionAbort; + const deadline = Date.now() + this._startupTimeoutMs; + const waitForStartup = (promise: Promise, timeoutMessage: string): Promise => + raceWithTimeout( + Promise.race([promise, connectionAborted]), + Math.max(0, deadline - Date.now()), + () => timeoutMessage, + ); + let attemptStream: grpc.ClientReadableStream | null = null; + let streamReady = false; + try { // send a "Hello" message to the sidecar to ensure that it's listening - await callWithMetadata(client.stub.hello.bind(client.stub), new Empty(), this._metadataGenerator); - - // Reset backoff on successful connection - this._backoff.reset(); + const helloMetadata = await waitForStartup( + this._getMetadata(), + `Timed out starting worker after ${this._startupTimeoutMs}ms while generating sidecar metadata`, + ); + await waitForStartup( + this._waitForHello(client, generation, helloMetadata, new Date(deadline)), + `Timed out starting worker after ${this._startupTimeoutMs}ms while waiting for sidecar hello response`, + ); + this._ensureConnectionAttemptActive(generation); // Stream work items from the sidecar (pass metadata for insecure connections) - const metadata = await this._getMetadata(); + const metadata = await waitForStartup( + this._getMetadata(), + `Timed out starting worker after ${this._startupTimeoutMs}ms while generating work-item stream metadata`, + ); + this._ensureConnectionAttemptActive(generation); const request = this._buildGetWorkItemsRequest(); const stream = client.stub.getWorkItems(request, metadata); + attemptStream = stream; this._responseStream = stream; + let resolveStreamReady: () => void; + let rejectStreamReady: (error: Error) => void; + const streamReadyPromise = new Promise((resolve, reject) => { + resolveStreamReady = resolve; + rejectStreamReady = reject; + }); + const markStreamReady = () => { + if (!streamReady) { + streamReady = true; + resolveStreamReady(); + } + }; - WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); + stream.once("metadata", markStreamReady); // Wait for a work item to be received stream.on("data", (workItem: pb.WorkItem) => { + markStreamReady(); const completionToken = workItem.getCompletiontoken(); if (workItem.hasOrchestratorrequest()) { WorkerLogs.workItemReceived( @@ -449,18 +548,20 @@ export class TaskHubGrpcWorker { // Wait for the stream to end or error stream.on("end", () => { + if (!streamReady) { + this._disposeResponseStream(stream); + rejectStreamReady(new Error("The work-item stream ended before the worker connection was established.")); + return; + } if (this._stopWorker) { WorkerLogs.streamEnded(this._logger); - stream.removeAllListeners(); - stream.destroy(); + this._disposeResponseStream(stream); return; } // Stream ended unexpectedly - clean up and retry - stream.removeAllListeners(); - stream.on("error", () => {}); // Prevent unhandled "error" after cleanup - stream.destroy(); + this._disposeResponseStream(stream); WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); - this._createNewClientAndRetry().catch((retryErr) => { + this._createNewClientAndRetry(generation).catch((retryErr) => { if (!this._stopWorker) { WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); } @@ -468,6 +569,11 @@ export class TaskHubGrpcWorker { }); stream.on("error", (err: Error) => { + if (!streamReady) { + this._disposeResponseStream(stream); + rejectStreamReady(err); + return; + } // Ignore cancellation errors when the worker is being stopped intentionally if (this._stopWorker) { return; @@ -478,29 +584,101 @@ export class TaskHubGrpcWorker { // In Node.js, gRPC stream errors (e.g., UNAVAILABLE, transport failures) // may not always be followed by an "end" event. Without recovery here, // the worker would silently stop processing work items. - stream.removeAllListeners(); - stream.on("error", () => {}); // Prevent unhandled "error" after cleanup - stream.destroy(); + this._disposeResponseStream(stream); WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); - this._createNewClientAndRetry().catch((retryErr) => { + this._createNewClientAndRetry(generation).catch((retryErr) => { if (!this._stopWorker) { WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); } }); }); + + await waitForStartup( + streamReadyPromise, + `Timed out starting worker after ${this._startupTimeoutMs}ms while establishing the work-item stream`, + ); + this._ensureConnectionAttemptActive(generation); + this._backoff.reset(); + WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); } catch (err) { - if (this._stopWorker) { - // ignoring the error because the worker has been stopped + const error = err instanceof Error ? err : new Error(String(err)); + if (error instanceof TimeoutError) { + connectionAbort.abort(error); + this._helloCall?.cancel(); + } + if (attemptStream && !streamReady) { + attemptStream.cancel(); + this._disposeResponseStream(attemptStream); + } + if (!this._isConnectionAttemptActive(generation)) { + if (!isRetry) { + throw error; + } return; } - const error = err instanceof Error ? err : new Error(String(err)); WorkerLogs.streamError(this._logger, error); if (!isRetry) { throw error; } WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); - await this._createNewClientAndRetry(); + await this._createNewClientAndRetry(generation); return; + } finally { + if (this._connectionAbort === connectionAbort) { + this._connectionAbort = null; + } + } + } + + private async _waitForHello( + client: GrpcClient, + generation: number, + metadata: grpc.Metadata, + deadline: Date, + ): Promise { + this._ensureConnectionAttemptActive(generation); + const timeoutMessage = `Timed out starting worker after ${this._startupTimeoutMs}ms while waiting for sidecar hello response`; + let call: grpc.ClientUnaryCall | undefined; + + try { + await new Promise((resolve, reject) => { + call = client.stub.hello(new Empty(), metadata, { deadline }, (error) => { + if (error) { + reject(error); + } else { + resolve(); + } + }); + this._helloCall = call; + }); + } catch (err) { + if (err && typeof err === "object" && "code" in err && err.code === grpc.status.DEADLINE_EXCEEDED) { + throw new TimeoutError(timeoutMessage); + } + throw err; + } finally { + if (this._helloCall === call) { + this._helloCall = null; + } + } + } + + private _ensureConnectionAttemptActive(generation: number): void { + if (!this._isConnectionAttemptActive(generation)) { + throw new Error("Worker startup was stopped before the connection was established."); + } + } + + private _isConnectionAttemptActive(generation: number): boolean { + return !this._stopWorker && generation === this._connectionGeneration; + } + + private _disposeResponseStream(stream: grpc.ClientReadableStream): void { + stream.removeAllListeners(); + stream.on("error", () => {}); + stream.destroy(); + if (this._responseStream === stream) { + this._responseStream = null; } } @@ -514,6 +692,9 @@ export class TaskHubGrpcWorker { } this._stopWorker = true; + this._connectionGeneration++; + this._connectionAbort?.abort(new Error("Worker startup was stopped before the connection was established.")); + this._helloCall?.cancel(); // Cancel stream first while error handlers are still attached // This allows the error handler to suppress CANCELLED errors @@ -562,7 +743,9 @@ export class TaskHubGrpcWorker { if (this._stub) { // Close the gRPC client - this is a synchronous operation this._stub.close(); + this._stub = null; } + this._responseStream = null; this._isRunning = false; // Brief pause to allow gRPC cleanup diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts new file mode 100644 index 00000000..d0435974 --- /dev/null +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -0,0 +1,379 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +import { EventEmitter } from "events"; +import * as grpc from "@grpc/grpc-js"; +import { Empty } from "google-protobuf/google/protobuf/empty_pb"; +import { GrpcClient } from "../src/client/client-grpc"; +import { TimeoutError } from "../src/exception/timeout-error"; +import * as stubs from "../src/proto/orchestrator_service_grpc_pb"; +import { NoOpLogger } from "../src/types/logger.type"; +import { TaskHubGrpcWorker } from "../src/worker/task-hub-grpc-worker"; + +type MockStream = EventEmitter & { + cancel: jest.Mock; + destroy: jest.Mock; +}; + +type HelloCallback = (error: Error | null, response: Empty) => void; + +function createMockStream(): MockStream { + const stream = new EventEmitter() as MockStream; + stream.cancel = jest.fn(() => queueMicrotask(() => stream.emit("end"))); + stream.destroy = jest.fn(); + return stream; +} + +function createMockStub( + hello: (...args: any[]) => grpc.ClientUnaryCall, + stream: MockStream = createMockStream(), + autoReady: boolean = true, +): { + stub: stubs.TaskHubSidecarServiceClient; + stream: MockStream; + getWorkItems: jest.Mock; + close: jest.Mock; +} { + const getWorkItems = jest.fn(() => { + if (autoReady) { + queueMicrotask(() => stream.emit("metadata", new grpc.Metadata())); + } + return stream; + }); + const close = jest.fn(); + const stub = { + hello: jest.fn(hello), + getWorkItems, + close, + } as unknown as stubs.TaskHubSidecarServiceClient; + + return { stub, stream, getWorkItems, close }; +} + +function useMockStub(stub: stubs.TaskHubSidecarServiceClient): void { + jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(stub); +} + +function getHelloCallback(args: any[]): HelloCallback { + return args[args.length - 1] as HelloCallback; +} + +function flushAsync(): Promise { + return new Promise((resolve) => setImmediate(resolve)); +} + +async function flushPromises(): Promise { + for (let i = 0; i < 10; i++) { + await Promise.resolve(); + } +} + +describe("TaskHubGrpcWorker startup", () => { + afterEach(() => { + jest.useRealTimers(); + jest.restoreAllMocks(); + }); + + it("waits for the hello handshake and work-item stream before start resolves", async () => { + let completeHello: HelloCallback | undefined; + const { stub, stream, getWorkItems } = createMockStub( + (...args: any[]) => { + completeHello = getHelloCallback(args); + return { cancel: jest.fn() } as any; + }, + undefined, + false, + ); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + + let started = false; + const startPromise = worker.start().then(() => { + started = true; + }); + await flushAsync(); + + expect(started).toBe(false); + expect(getWorkItems).not.toHaveBeenCalled(); + + completeHello!(null, new Empty()); + await flushAsync(); + + expect(getWorkItems).toHaveBeenCalledTimes(1); + expect(started).toBe(false); + + stream.emit("metadata", new grpc.Metadata()); + await startPromise; + + expect((worker as any)._responseStream).not.toBeNull(); + }); + + it("times out and cancels an unresponsive hello handshake", async () => { + const cancel = jest.fn(); + const { stub, close } = createMockStub(() => ({ cancel }) as any); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ + logger: new NoOpLogger(), + startupTimeoutMs: 10, + }); + + const startPromise = worker.start(); + await expect(startPromise).rejects.toThrow(TimeoutError); + await expect(startPromise).rejects.toThrow("Timed out starting worker after 10ms"); + + expect(cancel).toHaveBeenCalled(); + expect(close).toHaveBeenCalled(); + expect((worker as any)._isRunning).toBe(false); + expect((worker as any)._stub).toBeNull(); + expect((worker as any)._responseStream).toBeNull(); + }); + + it("applies the startup timeout while generating metadata", async () => { + const { stub, getWorkItems, close } = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ + logger: new NoOpLogger(), + startupTimeoutMs: 10, + metadataGenerator: () => new Promise(() => {}), + }); + + await expect(worker.start()).rejects.toThrow("while generating sidecar metadata"); + + expect(getWorkItems).not.toHaveBeenCalled(); + expect(close).toHaveBeenCalled(); + expect((worker as any)._isRunning).toBe(false); + }); + + it("times out and cancels a work-item stream that never becomes ready", async () => { + const { stub, stream, close } = createMockStub( + (...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }, + undefined, + false, + ); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ + logger: new NoOpLogger(), + startupTimeoutMs: 10, + }); + + await expect(worker.start()).rejects.toThrow("while establishing the work-item stream"); + + expect(stream.cancel).toHaveBeenCalled(); + expect(stream.destroy).toHaveBeenCalled(); + expect(close).toHaveBeenCalled(); + expect((worker as any)._isRunning).toBe(false); + }); + + it("rejects startup timeouts above the maximum Node.js timer delay", () => { + expect( + () => + new TaskHubGrpcWorker({ + logger: new NoOpLogger(), + startupTimeoutMs: 2147483648, + }), + ).toThrow(RangeError); + }); + + it("cleans up a failed handshake and permits a later start", async () => { + const stream = createMockStream(); + const close = jest.fn(); + let attempt = 0; + const hello = jest.fn((...args: any[]) => { + const callback = getHelloCallback(args); + attempt++; + if (attempt === 1) { + callback(new Error("handshake failed"), new Empty()); + } else { + callback(null, new Empty()); + } + return { cancel: jest.fn() } as any; + }); + const getWorkItems = jest.fn(() => { + queueMicrotask(() => stream.emit("metadata", new grpc.Metadata())); + return stream; + }); + useMockStub({ hello, getWorkItems, close } as unknown as stubs.TaskHubSidecarServiceClient); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + + await expect(worker.start()).rejects.toThrow("handshake failed"); + + expect(close).toHaveBeenCalledTimes(1); + expect((worker as any)._isRunning).toBe(false); + expect((worker as any)._stub).toBeNull(); + + await expect(worker.start()).resolves.toBeUndefined(); + expect(getWorkItems).toHaveBeenCalledTimes(1); + expect((worker as any)._isRunning).toBe(true); + }); + + it("rejects startup when the initial stream fails before becoming ready", async () => { + const { stub, stream, close } = createMockStub( + (...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }, + undefined, + false, + ); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + + const startPromise = worker.start(); + await flushAsync(); + stream.emit("error", new Error("14 UNAVAILABLE during startup")); + + await expect(startPromise).rejects.toThrow("14 UNAVAILABLE during startup"); + expect(close).toHaveBeenCalled(); + expect((worker as any)._isRunning).toBe(false); + expect((worker as any)._responseStream).toBeNull(); + }); + + it("cancels an in-flight hello when stopped during startup", async () => { + jest.useFakeTimers(); + let completeHello: HelloCallback | undefined; + const cancel = jest.fn(() => { + queueMicrotask(() => completeHello!(new Error("1 CANCELLED"), new Empty())); + }); + const { stub, getWorkItems } = createMockStub((...args: any[]) => { + completeHello = getHelloCallback(args); + return { cancel } as any; + }); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + + const startPromise = worker.start(); + const startRejection = expect(startPromise).rejects.toThrow( + "Worker startup was stopped before the connection was established.", + ); + await flushPromises(); + expect(completeHello).toBeDefined(); + const stopPromise = worker.stop(); + await jest.runAllTimersAsync(); + + await startRejection; + await stopPromise; + expect(cancel).toHaveBeenCalled(); + expect(getWorkItems).not.toHaveBeenCalled(); + expect((worker as any)._isRunning).toBe(false); + }); + + it("ignores a late hello callback from a stopped startup attempt", async () => { + jest.useFakeTimers(); + let firstHello: HelloCallback | undefined; + let secondHello: HelloCallback | undefined; + const firstStream = createMockStream(); + const secondStream = createMockStream(); + const first = createMockStub( + (...args: any[]) => { + firstHello = getHelloCallback(args); + return { cancel: jest.fn() } as any; + }, + firstStream, + false, + ); + const second = createMockStub( + (...args: any[]) => { + secondHello = getHelloCallback(args); + return { cancel: jest.fn() } as any; + }, + secondStream, + false, + ); + jest + .spyOn(GrpcClient.prototype as any, "_generateClient") + .mockReturnValueOnce(first.stub) + .mockReturnValueOnce(second.stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger(), startupTimeoutMs: 5000 }); + + const firstStart = worker.start(); + const firstStartRejection = expect(firstStart).rejects.toThrow(); + await flushPromises(); + expect(firstHello).toBeDefined(); + const stopPromise = worker.stop(); + await jest.advanceTimersByTimeAsync(1000); + await stopPromise; + + jest.useRealTimers(); + const secondStart = worker.start(); + await flushAsync(); + firstHello!(null, new Empty()); + await flushAsync(); + + expect(first.getWorkItems).not.toHaveBeenCalled(); + expect(second.getWorkItems).not.toHaveBeenCalled(); + + secondHello!(null, new Empty()); + await flushAsync(); + secondStream.emit("metadata", new grpc.Metadata()); + await secondStart; + await firstStartRejection; + + expect(second.getWorkItems).toHaveBeenCalledTimes(1); + expect((worker as any)._responseStream).toBe(secondStream); + }); + + it("keeps stream recovery active after startup", async () => { + const { stub, stream } = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const retry = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retry; + + await worker.start(); + stream.emit("error", new Error("14 UNAVAILABLE")); + await flushAsync(); + + expect(retry).toHaveBeenCalledTimes(1); + expect(stream.destroy).toHaveBeenCalled(); + }); + + it("retries when a replacement stream never becomes ready", async () => { + const { stub } = createMockStub( + (...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }, + undefined, + false, + ); + const worker = new TaskHubGrpcWorker({ + logger: new NoOpLogger(), + startupTimeoutMs: 10, + }); + const retry = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retry; + + await worker.internalRunWorker({ stub } as GrpcClient, true); + + expect(retry).toHaveBeenCalledTimes(1); + }); + + it("stops and cleans up a stream established by start", async () => { + const { stub, stream, close } = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + useMockStub(stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + + await worker.start(); + jest.useFakeTimers(); + const stopPromise = worker.stop(); + await jest.runAllTimersAsync(); + await stopPromise; + + expect(stream.cancel).toHaveBeenCalled(); + expect(stream.destroy).toHaveBeenCalled(); + expect(close).toHaveBeenCalled(); + expect((worker as any)._isRunning).toBe(false); + }); +}); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index aab4d5e3..dd12eb37 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -32,11 +32,14 @@ function createMockClient(): { mockStream.cancel = jest.fn(); const stub = { - hello: (_req: any, _metadata: any, callback: (err: any, res: any) => void) => { + hello: (_req: any, _metadata: any, _options: any, callback: (err: any, res: any) => void) => { callback(null, {}); - return {} as any; + return { cancel: jest.fn() } as any; }, - getWorkItems: jest.fn().mockReturnValue(mockStream), + getWorkItems: jest.fn(() => { + queueMicrotask(() => mockStream.emit("metadata", {})); + return mockStream; + }), }; const client = { stub } as unknown as GrpcClient; From 62ae45d782c9092d30df446a1cf0c1ebb67c9734 Mon Sep 17 00:00:00 2001 From: wangbill Date: Wed, 5 Aug 2026 11:02:34 -0700 Subject: [PATCH 02/12] fix: resolve startup after stream setup Treat an idle stream as ready once hello succeeds and handlers are attached, preserve retryability after client construction failures, and align the recovery E2E with the startup contract. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 65b88a3f-d79a-4a63-8636-cc41c219db63 --- .../src/worker/task-hub-grpc-worker.ts | 39 +---- .../test/worker-startup.spec.ts | 137 ++++-------------- .../test/worker-stream-recovery.spec.ts | 5 +- .../worker-stream-recovery.spec.ts | 71 +++++---- 4 files changed, 80 insertions(+), 172 deletions(-) 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 a22dd850..93d87779 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -65,8 +65,7 @@ export interface TaskHubGrpcWorkerOptions { /** Optional timeout in milliseconds for graceful shutdown. Defaults to 30000. */ shutdownTimeoutMs?: number; /** - * Optional timeout in milliseconds for establishing the initial sidecar connection, - * including metadata generation, the hello handshake, and work-item stream readiness. + * Optional timeout in milliseconds for initial metadata generation and the sidecar hello handshake. * Defaults to 30000. */ startupTimeoutMs?: number; @@ -430,10 +429,10 @@ export class TaskHubGrpcWorker { throw new Error("The worker is already running."); } + const client = new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); this._isRunning = true; this._stopWorker = false; const generation = ++this._connectionGeneration; - const client = new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); this._stub = client.stub; try { @@ -477,7 +476,7 @@ export class TaskHubGrpcWorker { () => timeoutMessage, ); let attemptStream: grpc.ClientReadableStream | null = null; - let streamReady = false; + let connectionEstablished = false; try { // send a "Hello" message to the sidecar to ensure that it's listening @@ -502,24 +501,9 @@ export class TaskHubGrpcWorker { const stream = client.stub.getWorkItems(request, metadata); attemptStream = stream; this._responseStream = stream; - let resolveStreamReady: () => void; - let rejectStreamReady: (error: Error) => void; - const streamReadyPromise = new Promise((resolve, reject) => { - resolveStreamReady = resolve; - rejectStreamReady = reject; - }); - const markStreamReady = () => { - if (!streamReady) { - streamReady = true; - resolveStreamReady(); - } - }; - - stream.once("metadata", markStreamReady); // Wait for a work item to be received stream.on("data", (workItem: pb.WorkItem) => { - markStreamReady(); const completionToken = workItem.getCompletiontoken(); if (workItem.hasOrchestratorrequest()) { WorkerLogs.workItemReceived( @@ -548,11 +532,6 @@ export class TaskHubGrpcWorker { // Wait for the stream to end or error stream.on("end", () => { - if (!streamReady) { - this._disposeResponseStream(stream); - rejectStreamReady(new Error("The work-item stream ended before the worker connection was established.")); - return; - } if (this._stopWorker) { WorkerLogs.streamEnded(this._logger); this._disposeResponseStream(stream); @@ -569,11 +548,6 @@ export class TaskHubGrpcWorker { }); stream.on("error", (err: Error) => { - if (!streamReady) { - this._disposeResponseStream(stream); - rejectStreamReady(err); - return; - } // Ignore cancellation errors when the worker is being stopped intentionally if (this._stopWorker) { return; @@ -593,11 +567,8 @@ export class TaskHubGrpcWorker { }); }); - await waitForStartup( - streamReadyPromise, - `Timed out starting worker after ${this._startupTimeoutMs}ms while establishing the work-item stream`, - ); this._ensureConnectionAttemptActive(generation); + connectionEstablished = true; this._backoff.reset(); WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); } catch (err) { @@ -606,7 +577,7 @@ export class TaskHubGrpcWorker { connectionAbort.abort(error); this._helloCall?.cancel(); } - if (attemptStream && !streamReady) { + if (attemptStream && !connectionEstablished) { attemptStream.cancel(); this._disposeResponseStream(attemptStream); } diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index d0435974..a6a6df26 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -27,19 +27,13 @@ function createMockStream(): MockStream { function createMockStub( hello: (...args: any[]) => grpc.ClientUnaryCall, stream: MockStream = createMockStream(), - autoReady: boolean = true, ): { stub: stubs.TaskHubSidecarServiceClient; stream: MockStream; getWorkItems: jest.Mock; close: jest.Mock; } { - const getWorkItems = jest.fn(() => { - if (autoReady) { - queueMicrotask(() => stream.emit("metadata", new grpc.Metadata())); - } - return stream; - }); + const getWorkItems = jest.fn().mockReturnValue(stream); const close = jest.fn(); const stub = { hello: jest.fn(hello), @@ -74,16 +68,12 @@ describe("TaskHubGrpcWorker startup", () => { jest.restoreAllMocks(); }); - it("waits for the hello handshake and work-item stream before start resolves", async () => { + it("resolves after hello succeeds and an idle work-item stream is configured", async () => { let completeHello: HelloCallback | undefined; - const { stub, stream, getWorkItems } = createMockStub( - (...args: any[]) => { - completeHello = getHelloCallback(args); - return { cancel: jest.fn() } as any; - }, - undefined, - false, - ); + const { stub, getWorkItems } = createMockStub((...args: any[]) => { + completeHello = getHelloCallback(args); + return { cancel: jest.fn() } as any; + }); useMockStub(stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); @@ -97,14 +87,10 @@ describe("TaskHubGrpcWorker startup", () => { expect(getWorkItems).not.toHaveBeenCalled(); completeHello!(null, new Empty()); - await flushAsync(); - - expect(getWorkItems).toHaveBeenCalledTimes(1); - expect(started).toBe(false); - - stream.emit("metadata", new grpc.Metadata()); await startPromise; + expect(getWorkItems).toHaveBeenCalledTimes(1); + expect(started).toBe(true); expect((worker as any)._responseStream).not.toBeNull(); }); @@ -147,29 +133,6 @@ describe("TaskHubGrpcWorker startup", () => { expect((worker as any)._isRunning).toBe(false); }); - it("times out and cancels a work-item stream that never becomes ready", async () => { - const { stub, stream, close } = createMockStub( - (...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }, - undefined, - false, - ); - useMockStub(stub); - const worker = new TaskHubGrpcWorker({ - logger: new NoOpLogger(), - startupTimeoutMs: 10, - }); - - await expect(worker.start()).rejects.toThrow("while establishing the work-item stream"); - - expect(stream.cancel).toHaveBeenCalled(); - expect(stream.destroy).toHaveBeenCalled(); - expect(close).toHaveBeenCalled(); - expect((worker as any)._isRunning).toBe(false); - }); - it("rejects startup timeouts above the maximum Node.js timer delay", () => { expect( () => @@ -194,10 +157,7 @@ describe("TaskHubGrpcWorker startup", () => { } return { cancel: jest.fn() } as any; }); - const getWorkItems = jest.fn(() => { - queueMicrotask(() => stream.emit("metadata", new grpc.Metadata())); - return stream; - }); + const getWorkItems = jest.fn().mockReturnValue(stream); useMockStub({ hello, getWorkItems, close } as unknown as stubs.TaskHubSidecarServiceClient); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); @@ -212,26 +172,24 @@ describe("TaskHubGrpcWorker startup", () => { expect((worker as any)._isRunning).toBe(true); }); - it("rejects startup when the initial stream fails before becoming ready", async () => { - const { stub, stream, close } = createMockStub( - (...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }, - undefined, - false, - ); - useMockStub(stub); + it("remains retryable after synchronous gRPC client construction fails", async () => { + const { stub, getWorkItems } = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + jest + .spyOn(GrpcClient.prototype as any, "_generateClient") + .mockImplementationOnce(() => { + throw new Error("client construction failed"); + }) + .mockReturnValue(stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const startPromise = worker.start(); - await flushAsync(); - stream.emit("error", new Error("14 UNAVAILABLE during startup")); - - await expect(startPromise).rejects.toThrow("14 UNAVAILABLE during startup"); - expect(close).toHaveBeenCalled(); + await expect(worker.start()).rejects.toThrow("client construction failed"); expect((worker as any)._isRunning).toBe(false); - expect((worker as any)._responseStream).toBeNull(); + + await expect(worker.start()).resolves.toBeUndefined(); + expect(getWorkItems).toHaveBeenCalledTimes(1); }); it("cancels an in-flight hello when stopped during startup", async () => { @@ -269,22 +227,14 @@ describe("TaskHubGrpcWorker startup", () => { let secondHello: HelloCallback | undefined; const firstStream = createMockStream(); const secondStream = createMockStream(); - const first = createMockStub( - (...args: any[]) => { - firstHello = getHelloCallback(args); - return { cancel: jest.fn() } as any; - }, - firstStream, - false, - ); - const second = createMockStub( - (...args: any[]) => { - secondHello = getHelloCallback(args); - return { cancel: jest.fn() } as any; - }, - secondStream, - false, - ); + const first = createMockStub((...args: any[]) => { + firstHello = getHelloCallback(args); + return { cancel: jest.fn() } as any; + }, firstStream); + const second = createMockStub((...args: any[]) => { + secondHello = getHelloCallback(args); + return { cancel: jest.fn() } as any; + }, secondStream); jest .spyOn(GrpcClient.prototype as any, "_generateClient") .mockReturnValueOnce(first.stub) @@ -309,8 +259,6 @@ describe("TaskHubGrpcWorker startup", () => { expect(second.getWorkItems).not.toHaveBeenCalled(); secondHello!(null, new Empty()); - await flushAsync(); - secondStream.emit("metadata", new grpc.Metadata()); await secondStart; await firstStartRejection; @@ -336,27 +284,6 @@ describe("TaskHubGrpcWorker startup", () => { expect(stream.destroy).toHaveBeenCalled(); }); - it("retries when a replacement stream never becomes ready", async () => { - const { stub } = createMockStub( - (...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }, - undefined, - false, - ); - const worker = new TaskHubGrpcWorker({ - logger: new NoOpLogger(), - startupTimeoutMs: 10, - }); - const retry = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retry; - - await worker.internalRunWorker({ stub } as GrpcClient, true); - - expect(retry).toHaveBeenCalledTimes(1); - }); - it("stops and cleans up a stream established by start", async () => { const { stub, stream, close } = createMockStub((...args: any[]) => { getHelloCallback(args)(null, new Empty()); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index dd12eb37..d801bd9f 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -36,10 +36,7 @@ function createMockClient(): { callback(null, {}); return { cancel: jest.fn() } as any; }, - getWorkItems: jest.fn(() => { - queueMicrotask(() => mockStream.emit("metadata", {})); - return mockStream; - }), + getWorkItems: jest.fn().mockReturnValue(mockStream), }; const client = { stub } as unknown as GrpcClient; diff --git a/test/e2e-azuremanaged/worker-stream-recovery.spec.ts b/test/e2e-azuremanaged/worker-stream-recovery.spec.ts index 58cd4497..e8fac511 100644 --- a/test/e2e-azuremanaged/worker-stream-recovery.spec.ts +++ b/test/e2e-azuremanaged/worker-stream-recovery.spec.ts @@ -6,9 +6,10 @@ * * This test verifies the full recovery flow: * 1. Start a worker when the DTS emulator is NOT running - * 2. Verify the worker retries (via structured log capture) - * 3. Start the Docker emulator - * 4. Verify the worker reconnects and can process orchestrations + * 2. Verify initial startup fails within the configured timeout + * 3. Start the Docker emulator and start the worker successfully + * 4. Stop and restart the emulator + * 5. Verify the running worker reconnects and can process orchestrations * * Environment variables: * - ENDPOINT: The endpoint for the DTS emulator (default: localhost:8080) @@ -83,10 +84,9 @@ function stopEmulator(): void { } function startEmulator(): void { - execSync( - `docker run --name ${EMULATOR_CONTAINER} -d --rm -p ${EMULATOR_PORT}:8080 ${EMULATOR_IMAGE}`, - { stdio: "ignore" }, - ); + execSync(`docker run --name ${EMULATOR_CONTAINER} -d --rm -p ${EMULATOR_PORT}:8080 ${EMULATOR_IMAGE}`, { + stdio: "ignore", + }); } /** Poll until a condition is true or timeout. */ @@ -99,10 +99,25 @@ async function waitFor(predicate: () => boolean, timeoutMs: number, intervalMs = return predicate(); } +async function startWorkerWithRetry(worker: { start(): Promise }, timeoutMs: number): Promise { + const deadline = Date.now() + timeoutMs; + let lastError: unknown; + do { + try { + await worker.start(); + return; + } catch (error) { + lastError = error; + await new Promise((resolve) => setTimeout(resolve, 500)); + } + } while (Date.now() < deadline); + + throw lastError; +} + // Log event IDs from packages/durabletask-js/src/worker/logs.ts const EVENT_WORKER_CONNECTED = 700; const EVENT_STREAM_RETRY = 703; -const EVENT_CONNECTION_RETRY = 705; describe("Worker Stream Recovery E2E", () => { const skipReason = !isDockerAvailable() ? "Docker not available" : null; @@ -118,7 +133,7 @@ describe("Worker Stream Recovery E2E", () => { stopEmulator(); }); - it("should retry when sidecar is down, then reconnect and complete an orchestration when sidecar starts", async () => { + it("should fail initial startup when the sidecar is down, then recover a post-start disconnection", async () => { if (skipReason) { console.log(`Skipping stream recovery e2e test: ${skipReason}`); return; @@ -130,6 +145,7 @@ describe("Worker Stream Recovery E2E", () => { const worker = new DurableTaskAzureManagedWorkerBuilder() .endpoint(endpoint, taskHub, null) .logger(logger) + .startupTimeout(5000) .build(); const orchestrator: TOrchestrator = async function recoveryOrchestrator(_: OrchestrationContext) { @@ -137,32 +153,29 @@ describe("Worker Stream Recovery E2E", () => { }; worker.addOrchestrator(orchestrator); - // start() should not throw even though the sidecar is unreachable - await worker.start(); + await expect(worker.start()).rejects.toThrow(); + expect(logger.getByEventId(EVENT_WORKER_CONNECTED)).toHaveLength(0); - // ── Phase 2: Verify retries are happening ─────────────────────────── - const sawRetries = await waitFor(() => { - const retryEvents = logger.getByEventId(EVENT_STREAM_RETRY); - const connRetryEvents = logger.getByEventId(EVENT_CONNECTION_RETRY); - return retryEvents.length + connRetryEvents.length >= 2; - }, 15000); + // ── Phase 2: Start the emulator and retry startup ─────────────────── + startEmulator(); + await startWorkerWithRetry(worker, 30000); + expect(logger.getByEventId(EVENT_WORKER_CONNECTED)).toHaveLength(1); - expect(sawRetries).toBe(true); + // ── Phase 3: Disconnect the successfully started worker ───────────── + logger.clear(); + stopEmulator(); - // ── Phase 3: Start the emulator ───────────────────────────────────── - startEmulator(); + const sawRetry = await waitFor(() => logger.getByEventId(EVENT_STREAM_RETRY).length > 0, 15000); + expect(sawRetry).toBe(true); - // ── Phase 4: Wait for the worker to reconnect ─────────────────────── - const sawConnected = await waitFor(() => { - return logger.getByEventId(EVENT_WORKER_CONNECTED).length > 0; - }, 30000); + // ── Phase 4: Restart the emulator and wait for reconnection ───────── + startEmulator(); + const sawConnected = await waitFor(() => logger.getByEventId(EVENT_WORKER_CONNECTED).length > 0, 30000); expect(sawConnected).toBe(true); - // ── Phase 5: Run an orchestration to prove the worker is functional ─ - const client = new DurableTaskAzureManagedClientBuilder() - .endpoint(endpoint, taskHub, null) - .build(); + // ── Phase 5: Run an orchestration to prove recovery is functional ─── + const client = new DurableTaskAzureManagedClientBuilder().endpoint(endpoint, taskHub, null).build(); const id = await client.scheduleNewOrchestration(orchestrator); const state = await client.waitForOrchestrationCompletion(id, undefined, 30); @@ -174,5 +187,5 @@ describe("Worker Stream Recovery E2E", () => { // ── Cleanup ───────────────────────────────────────────────────────── await worker.stop(); await client.stop(); - }, 90000); + }, 120000); }); From 21a4fda021ab0339ebddead6d12863ae7375d21d Mon Sep 17 00:00:00 2001 From: wangbill Date: Wed, 5 Aug 2026 11:33:36 -0700 Subject: [PATCH 03/12] ci: run worker recovery e2e Add an isolated job that leaves the emulator stopped initially so the worker startup failure and subsequent stream recovery path execute in CI. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 65b88a3f-d79a-4a63-8636-cc41c219db63 --- .github/workflows/dts-e2e-tests.yaml | 28 ++++++++++++++++++++++++++++ 1 file changed, 28 insertions(+) diff --git a/.github/workflows/dts-e2e-tests.yaml b/.github/workflows/dts-e2e-tests.yaml index 67099aaa..2abf5a0b 100644 --- a/.github/workflows/dts-e2e-tests.yaml +++ b/.github/workflows/dts-e2e-tests.yaml @@ -66,3 +66,31 @@ jobs: - name: ✅ Run E2E tests — ${{ matrix.test-group.name }} run: npx jest ${{ matrix.test-group.pattern }} --runInBand --detectOpenHandles timeout-minutes: 15 + + worker-stream-recovery: + name: "e2e (worker-stream-recovery, node 22.x)" + env: + EMULATOR_VERSION: "latest" + TASKHUB: "default" + ENDPOINT: "localhost:8080" + runs-on: ubuntu-latest + + steps: + - name: 📥 Checkout code + uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1 + + - name: 🐳 Pull Docker image + run: docker pull mcr.microsoft.com/dts/dts-emulator:$EMULATOR_VERSION + + - name: ⚙️ NodeJS - Install + uses: actions/setup-node@820762786026740c76f36085b0efc47a31fe5020 # v7.0.0 + with: + node-version: "22.x" + registry-url: "https://registry.npmjs.org" + + - name: ⚙️ Install dependencies + run: npm ci + + - name: ✅ Run worker stream recovery E2E test + run: npx jest test/e2e-azuremanaged/worker-stream-recovery.spec.ts --runInBand --detectOpenHandles + timeout-minutes: 5 From 3482ecbf3bc9d403e66d6ac3dc6b19438266b9c7 Mon Sep 17 00:00:00 2001 From: wangbill Date: Mon, 10 Aug 2026 16:00:36 -0700 Subject: [PATCH 04/12] docs: clarify worker startup contract Document the startup rejection as a breaking change, align timeout API wording, and preserve the orchestration reuse documentation while rebasing onto main. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 65b88a3f-d79a-4a63-8636-cc41c219db63 --- CHANGELOG.md | 21 ++++++++++++++++++- README.md | 13 ++++++------ .../durabletask-js-azuremanaged/CHANGELOG.md | 9 +++++++- .../durabletask-js-azuremanaged/README.md | 8 ++++--- .../src/worker-builder.ts | 3 ++- .../src/worker/task-hub-grpc-worker.ts | 10 +++++---- 6 files changed, 47 insertions(+), 17 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 3cea5161..6aa53db3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,23 @@ ## Upcoming +### Breaking Changes + +- `TaskHubGrpcWorker.start()` now rejects when the sidecar cannot be reached within + `startupTimeoutMs` (30 seconds by default). Previously, `start()` resolved before connecting and + retried forever in the background. Deployments where the worker may start before its sidecar + should either increase `startupTimeoutMs` or retry `start()` from the caller: + + ```typescript + for (;;) { + try { + await worker.start(); + break; + } catch { + await new Promise((resolve) => setTimeout(resolve, 1000)); + } + } + ``` + ### New - Add an optional `newVersion` parameter to `OrchestrationContext.continueAsNew()` for version migrations. @@ -13,7 +31,8 @@ ### Fixes -- Make `TaskHubGrpcWorker.start()` wait for its initial work-item stream and time out unresponsive sidecar startup connections. +- Make `TaskHubGrpcWorker.start()` wait until the sidecar hello handshake succeeds and the initial + work-item stream is created with its handlers attached. ## v0.4.0 (2026-07-31) diff --git a/README.md b/README.md index 86ad56b8..de4f6178 100644 --- a/README.md +++ b/README.md @@ -81,9 +81,11 @@ const state = await client.waitForOrchestrationCompletion(id, true, 60); console.log(`Result: ${state?.serializedOutput}`); ``` -`await worker.start()` resolves only after the initial sidecar handshake succeeds and the -work-item stream is established. Startup times out after 30 seconds by default; use -the worker builder's `.startupTimeout(milliseconds)` method to configure it. +`await worker.start()` resolves only after startup metadata is generated, the initial sidecar +handshake succeeds, and the work-item stream is created with its handlers attached. Metadata +generation and the handshake have a 30-second startup budget by default; use the worker builder's +`.startupTimeout(milliseconds)` method to configure it. If the sidecar is not ready in time, +`start()` rejects; callers that require indefinite startup recovery should retry `start()`. You can find more samples in the [examples/azure-managed](./examples/azure-managed) directory. @@ -180,10 +182,7 @@ Long-running orchestrations can restart with fresh history and optionally move t orchestration version: ```typescript -const eternalOrchestrator: TOrchestrator = async function* ( - ctx: OrchestrationContext, - iteration: number, -): any { +const eternalOrchestrator: TOrchestrator = async function* (ctx: OrchestrationContext, iteration: number): any { yield ctx.callActivity(processIteration, iteration); ctx.continueAsNew(iteration + 1, true, "2.0.0"); }; diff --git a/packages/durabletask-js-azuremanaged/CHANGELOG.md b/packages/durabletask-js-azuremanaged/CHANGELOG.md index d6876583..a7aad3f9 100644 --- a/packages/durabletask-js-azuremanaged/CHANGELOG.md +++ b/packages/durabletask-js-azuremanaged/CHANGELOG.md @@ -1,10 +1,17 @@ ## Upcoming +### Breaking Changes + +- Workers built by `DurableTaskAzureManagedWorkerBuilder` now reject `start()` when the sidecar + cannot be reached within the configured startup timeout. Previously, `start()` resolved before + connecting and retried forever in the background. Use `.startupTimeout(...)` to allow more time, + or retry `start()` from the caller as described in the core package changelog. + ### New ### Fixes -- Add `startupTimeout()` to configure the core worker's sidecar connection startup timeout. +- Add `startupTimeout()` to configure the core worker's metadata and hello-handshake startup budget. ## v0.4.0 (2026-07-31) diff --git a/packages/durabletask-js-azuremanaged/README.md b/packages/durabletask-js-azuremanaged/README.md index 092c62b6..14a48b8e 100644 --- a/packages/durabletask-js-azuremanaged/README.md +++ b/packages/durabletask-js-azuremanaged/README.md @@ -53,9 +53,11 @@ const worker = createAzureManagedWorkerBuilder("https://myservice.durabletask.io await worker.start(); ``` -`start()` resolves after the initial sidecar handshake and work-item stream are established. -The startup timeout defaults to 30 seconds and can be configured with -`.startupTimeout(milliseconds)` on the worker builder. +`start()` resolves after startup metadata is generated, the initial sidecar handshake succeeds, +and the work-item stream is created with its handlers attached. Metadata generation and the +handshake have a 30-second startup budget by default, configurable with +`.startupTimeout(milliseconds)`. If the sidecar is not ready in time, `start()` rejects; retry it +from the caller when the deployment requires indefinite startup recovery. ## Supported Authentication Types diff --git a/packages/durabletask-js-azuremanaged/src/worker-builder.ts b/packages/durabletask-js-azuremanaged/src/worker-builder.ts index 901e2662..28b1c60a 100644 --- a/packages/durabletask-js-azuremanaged/src/worker-builder.ts +++ b/packages/durabletask-js-azuremanaged/src/worker-builder.ts @@ -239,7 +239,8 @@ export class DurableTaskAzureManagedWorkerBuilder { /** * Sets the startup timeout in milliseconds. - * This is the maximum time to establish the initial sidecar connection. + * This is the maximum time for startup metadata generation and the sidecar hello handshake + * before the initial work-item stream is created. * Defaults to 30000 (30 seconds). * * @param timeoutMs The startup timeout in milliseconds. 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 93d87779..c3806128 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -65,7 +65,7 @@ export interface TaskHubGrpcWorkerOptions { /** Optional timeout in milliseconds for graceful shutdown. Defaults to 30000. */ shutdownTimeoutMs?: number; /** - * Optional timeout in milliseconds for initial metadata generation and the sidecar hello handshake. + * Optional timeout in milliseconds for startup metadata generation and the sidecar hello handshake. * Defaults to 30000. */ startupTimeoutMs?: number; @@ -420,9 +420,11 @@ export class TaskHubGrpcWorker { * In node.js we don't require a new thread as we have a main event loop * Therefore, we open the stream and simply listen through the eventemitter behind the scenes * - * @remarks Resolves after the sidecar hello handshake succeeds and the initial - * work-item stream is established. Later stream failures reconnect automatically. - * @throws {@link TimeoutError} if the hello handshake exceeds `startupTimeoutMs`. + * @remarks Resolves after startup metadata is generated, the sidecar hello handshake + * succeeds, and the initial work-item stream is created with its handlers attached. + * Later stream failures reconnect automatically. + * @throws {@link TimeoutError} if metadata generation or the hello handshake exceeds + * the `startupTimeoutMs` startup budget before the initial work-item stream is established. */ async start(): Promise { if (this._isRunning) { From 82e60fd6ce8d6581470fd50d40b98fb8feae66ab Mon Sep 17 00:00:00 2001 From: wangbill Date: Mon, 10 Aug 2026 17:16:19 -0700 Subject: [PATCH 05/12] fix(worker): fence reconnects by lifecycle ownership Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../durabletask-js/src/utils/backoff.util.ts | 25 +- .../src/worker/task-hub-grpc-worker.ts | 291 +++++++++++------- packages/durabletask-js/test/backoff.spec.ts | 24 ++ .../test/worker-startup.spec.ts | 82 +++++ .../test/worker-stream-recovery.spec.ts | 38 ++- 5 files changed, 341 insertions(+), 119 deletions(-) diff --git a/packages/durabletask-js/src/utils/backoff.util.ts b/packages/durabletask-js/src/utils/backoff.util.ts index 7209790b..5a57a46e 100644 --- a/packages/durabletask-js/src/utils/backoff.util.ts +++ b/packages/durabletask-js/src/utils/backoff.util.ts @@ -132,16 +132,29 @@ export class ExponentialBackoff { * * @returns Promise that resolves after the delay. */ - async wait(): Promise { + async wait(signal?: AbortSignal): Promise { const delay = this._calculateDelayWithJitter(); - await new Promise((resolve) => setTimeout(resolve, delay)); + if (signal?.aborted) { + throw signal.reason; + } + + await new Promise((resolve, reject) => { + const timeoutId = setTimeout(() => { + signal?.removeEventListener("abort", onAbort); + resolve(); + }, delay); + const onAbort = () => { + clearTimeout(timeoutId); + signal?.removeEventListener("abort", onAbort); + reject(signal?.reason); + }; + + signal?.addEventListener("abort", onAbort, { once: true }); + }); this._attemptCount++; - this._currentDelayMs = Math.min( - this._currentDelayMs * this._multiplier, - this._maxDelayMs, - ); + this._currentDelayMs = Math.min(this._currentDelayMs * this._multiplier, this._maxDelayMs); } /** 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 c3806128..c7205922 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -45,6 +45,7 @@ const DEFAULT_SHUTDOWN_TIMEOUT_MS = 30000; /** Default timeout in milliseconds for establishing the initial worker connection. */ const DEFAULT_STARTUP_TIMEOUT_MS = 30000; const MAX_TIMER_DELAY_MS = 2147483647; +const WORKER_STARTUP_STOPPED_MESSAGE = "Worker startup was stopped before the connection was established."; /** * Options for creating a TaskHubGrpcWorker. @@ -81,6 +82,12 @@ export interface TaskHubGrpcWorkerOptions { workItemFilters?: WorkItemFilters | "auto"; } +interface WorkerLifecycle { + readonly abortController: AbortController; + readonly connectionTasks: Set>; + stopping: boolean; +} + export class TaskHubGrpcWorker { private _responseStream: grpc.ClientReadableStream | null; private _helloCall: grpc.ClientUnaryCall | null; @@ -91,7 +98,6 @@ export class TaskHubGrpcWorker { private _grpcChannelCredentials?: grpc.ChannelCredentials; private _metadataGenerator?: MetadataGenerator; private _isRunning: boolean; - private _stopWorker: boolean; private _stub: stubs.TaskHubSidecarServiceClient | null; private _logger: Logger; private _pendingWorkItems: Set>; @@ -100,8 +106,7 @@ export class TaskHubGrpcWorker { private _backoff: ExponentialBackoff; private _versioning?: VersioningOptions; private _workItemFilters?: WorkItemFilters | "auto"; - private _connectionGeneration: number; - private _connectionAbort: { generation: number; abort: (error: Error) => void } | null; + private _lifecycle: WorkerLifecycle | null; /** * Creates a new TaskHubGrpcWorker instance. @@ -184,7 +189,6 @@ export class TaskHubGrpcWorker { this._responseStream = null; this._helloCall = null; this._isRunning = false; - this._stopWorker = false; this._stub = null; this._logger = resolvedLogger ?? new ConsoleLogger(); this._pendingWorkItems = new Set(); @@ -206,8 +210,7 @@ export class TaskHubGrpcWorker { }); this._versioning = resolvedVersioning; this._workItemFilters = resolvedWorkItemFilters; - this._connectionGeneration = 0; - this._connectionAbort = null; + this._lifecycle = null; } /** @@ -224,21 +227,20 @@ export class TaskHubGrpcWorker { * Creates a new gRPC client and retries the worker. * Properly closes the old client to prevent connection leaks. */ - private async _createNewClientAndRetry(generation: number = this._connectionGeneration): Promise { - if (!this._isConnectionAttemptActive(generation)) { - return; - } + private async _createNewClientAndRetry( + lifecycle: WorkerLifecycle, + previousStub: stubs.TaskHubSidecarServiceClient, + ): Promise { + this._ensureLifecycleActive(lifecycle); // Close the old stub to prevent connection leaks - if (this._stub) { - this._stub.close(); + previousStub.close(); + if (this._stub === previousStub) { this._stub = null; } - await this._backoff.wait(); - if (!this._isConnectionAttemptActive(generation)) { - return; - } + await this._backoff.wait(lifecycle.abortController.signal); + this._ensureLifecycleActive(lifecycle); const newClient = new GrpcClient( this._hostAddress, @@ -248,12 +250,7 @@ export class TaskHubGrpcWorker { ); this._stub = newClient.stub; - // Do not await - run in background - this.internalRunWorker(newClient, true, generation).catch((err) => { - if (!this._stopWorker) { - WorkerLogs.workerError(this._logger, err); - } - }); + await this.internalRunWorker(newClient, true, lifecycle); } /** @@ -432,51 +429,40 @@ export class TaskHubGrpcWorker { } const client = new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); + const lifecycle = this._createLifecycle(); this._isRunning = true; - this._stopWorker = false; - const generation = ++this._connectionGeneration; + this._lifecycle = lifecycle; this._stub = client.stub; + const startupTask = this._trackConnectionTask(lifecycle, this.internalRunWorker(client, false, lifecycle)); try { - await this.internalRunWorker(client, false, generation); - this._ensureConnectionAttemptActive(generation); + await startupTask; + this._ensureLifecycleActive(lifecycle); } catch (err) { - client.stub.close(); - if (this._stub === client.stub) { - this._stub = null; - } - if (generation === this._connectionGeneration) { - this._responseStream = null; - this._isRunning = false; + if (!lifecycle.stopping) { + const error = err instanceof Error ? err : new Error(String(err)); + lifecycle.abortController.abort(error); + this._helloCall?.cancel(); + await this._awaitConnectionTasks(lifecycle); + if (!lifecycle.stopping && this._lifecycle === lifecycle) { + client.stub.close(); + if (this._stub === client.stub) { + this._stub = null; + } + this._responseStream = null; + this._lifecycle = null; + this._isRunning = false; + } } throw err; } } - async internalRunWorker( - client: GrpcClient, - isRetry: boolean = false, - generation: number = this._connectionGeneration, - ): Promise { - let abortConnection: (error: Error) => void; - const connectionAborted = new Promise((_, reject) => { - let aborted = false; - abortConnection = (error: Error) => { - if (!aborted) { - aborted = true; - reject(error); - } - }; - }); - const connectionAbort = { generation, abort: abortConnection! }; - this._connectionAbort = connectionAbort; + async internalRunWorker(client: GrpcClient, isRetry: boolean = false, lifecycle?: WorkerLifecycle): Promise { + const activeLifecycle = lifecycle ?? this._lifecycle ?? this._createLifecycle(); const deadline = Date.now() + this._startupTimeoutMs; const waitForStartup = (promise: Promise, timeoutMessage: string): Promise => - raceWithTimeout( - Promise.race([promise, connectionAborted]), - Math.max(0, deadline - Date.now()), - () => timeoutMessage, - ); + this._waitForStartupStage(activeLifecycle, promise, deadline, timeoutMessage); let attemptStream: grpc.ClientReadableStream | null = null; let connectionEstablished = false; @@ -486,18 +472,15 @@ export class TaskHubGrpcWorker { this._getMetadata(), `Timed out starting worker after ${this._startupTimeoutMs}ms while generating sidecar metadata`, ); - await waitForStartup( - this._waitForHello(client, generation, helloMetadata, new Date(deadline)), - `Timed out starting worker after ${this._startupTimeoutMs}ms while waiting for sidecar hello response`, - ); - this._ensureConnectionAttemptActive(generation); + await this._waitForHello(client, activeLifecycle, helloMetadata, new Date(deadline)); + this._ensureLifecycleActive(activeLifecycle); // Stream work items from the sidecar (pass metadata for insecure connections) const metadata = await waitForStartup( this._getMetadata(), `Timed out starting worker after ${this._startupTimeoutMs}ms while generating work-item stream metadata`, ); - this._ensureConnectionAttemptActive(generation); + this._ensureLifecycleActive(activeLifecycle); const request = this._buildGetWorkItemsRequest(); const stream = client.stub.getWorkItems(request, metadata); @@ -534,7 +517,7 @@ export class TaskHubGrpcWorker { // Wait for the stream to end or error stream.on("end", () => { - if (this._stopWorker) { + if (activeLifecycle.abortController.signal.aborted) { WorkerLogs.streamEnded(this._logger); this._disposeResponseStream(stream); return; @@ -542,16 +525,12 @@ export class TaskHubGrpcWorker { // Stream ended unexpectedly - clean up and retry this._disposeResponseStream(stream); WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); - this._createNewClientAndRetry(generation).catch((retryErr) => { - if (!this._stopWorker) { - WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); - } - }); + this._scheduleReconnect(activeLifecycle, client.stub); }); stream.on("error", (err: Error) => { // Ignore cancellation errors when the worker is being stopped intentionally - if (this._stopWorker) { + if (activeLifecycle.abortController.signal.aborted) { return; } WorkerLogs.streamErrorInfo(this._logger, err); @@ -562,30 +541,25 @@ export class TaskHubGrpcWorker { // the worker would silently stop processing work items. this._disposeResponseStream(stream); WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); - this._createNewClientAndRetry(generation).catch((retryErr) => { - if (!this._stopWorker) { - WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); - } - }); + this._scheduleReconnect(activeLifecycle, client.stub); }); - this._ensureConnectionAttemptActive(generation); + this._ensureLifecycleActive(activeLifecycle); connectionEstablished = true; this._backoff.reset(); WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); } catch (err) { const error = err instanceof Error ? err : new Error(String(err)); if (error instanceof TimeoutError) { - connectionAbort.abort(error); this._helloCall?.cancel(); } if (attemptStream && !connectionEstablished) { attemptStream.cancel(); this._disposeResponseStream(attemptStream); } - if (!this._isConnectionAttemptActive(generation)) { + if (activeLifecycle.abortController.signal.aborted) { if (!isRetry) { - throw error; + throw this._getLifecycleAbortError(activeLifecycle); } return; } @@ -594,56 +568,146 @@ export class TaskHubGrpcWorker { throw error; } WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); - await this._createNewClientAndRetry(generation); + await this._createNewClientAndRetry(activeLifecycle, client.stub); return; - } finally { - if (this._connectionAbort === connectionAbort) { - this._connectionAbort = null; - } } } private async _waitForHello( client: GrpcClient, - generation: number, + lifecycle: WorkerLifecycle, metadata: grpc.Metadata, deadline: Date, ): Promise { - this._ensureConnectionAttemptActive(generation); + this._ensureLifecycleActive(lifecycle); const timeoutMessage = `Timed out starting worker after ${this._startupTimeoutMs}ms while waiting for sidecar hello response`; let call: grpc.ClientUnaryCall | undefined; + let timeoutId: ReturnType | undefined; + let removeAbortListener: (() => void) | undefined; try { await new Promise((resolve, reject) => { - call = client.stub.hello(new Empty(), metadata, { deadline }, (error) => { + let settled = false; + const finish = (error?: Error) => { + if (settled) { + return; + } + settled = true; + if (timeoutId !== undefined) { + clearTimeout(timeoutId); + } + removeAbortListener?.(); if (error) { reject(error); } else { resolve(); } - }); - this._helloCall = call; + }; + const onAbort = () => { + call?.cancel(); + finish(this._getLifecycleAbortError(lifecycle)); + }; + removeAbortListener = () => lifecycle.abortController.signal.removeEventListener("abort", onAbort); + lifecycle.abortController.signal.addEventListener("abort", onAbort, { once: true }); + timeoutId = setTimeout( + () => { + call?.cancel(); + finish(new TimeoutError(timeoutMessage)); + }, + Math.max(0, deadline.getTime() - Date.now()), + ); + + try { + call = client.stub.hello(new Empty(), metadata, { deadline }, (error) => { + if (error && error.code === grpc.status.DEADLINE_EXCEEDED) { + finish(new TimeoutError(timeoutMessage)); + } else { + finish(error ?? undefined); + } + }); + this._helloCall = call; + } catch (err) { + finish(err instanceof Error ? err : new Error(String(err))); + } }); - } catch (err) { - if (err && typeof err === "object" && "code" in err && err.code === grpc.status.DEADLINE_EXCEEDED) { - throw new TimeoutError(timeoutMessage); - } - throw err; } finally { + if (timeoutId !== undefined) { + clearTimeout(timeoutId); + } + removeAbortListener?.(); if (this._helloCall === call) { this._helloCall = null; } } } - private _ensureConnectionAttemptActive(generation: number): void { - if (!this._isConnectionAttemptActive(generation)) { - throw new Error("Worker startup was stopped before the connection was established."); + private async _waitForStartupStage( + lifecycle: WorkerLifecycle, + promise: Promise, + deadline: number, + timeoutMessage: string, + ): Promise { + this._ensureLifecycleActive(lifecycle); + const signal = lifecycle.abortController.signal; + let abort!: () => void; + const aborted = new Promise((_, reject) => { + abort = () => reject(this._getLifecycleAbortError(lifecycle)); + }); + signal.addEventListener("abort", abort, { once: true }); + + try { + return await raceWithTimeout( + Promise.race([promise, aborted]), + Math.max(0, deadline - Date.now()), + () => timeoutMessage, + ); + } finally { + signal.removeEventListener("abort", abort); + } + } + + private _createLifecycle(): WorkerLifecycle { + return { + abortController: new AbortController(), + connectionTasks: new Set(), + stopping: false, + }; + } + + private _ensureLifecycleActive(lifecycle: WorkerLifecycle): void { + if (lifecycle.abortController.signal.aborted) { + throw this._getLifecycleAbortError(lifecycle); } } - private _isConnectionAttemptActive(generation: number): boolean { - return !this._stopWorker && generation === this._connectionGeneration; + private _getLifecycleAbortError(lifecycle: WorkerLifecycle): Error { + const reason = lifecycle.abortController.signal.reason; + return reason instanceof Error ? reason : new Error(WORKER_STARTUP_STOPPED_MESSAGE); + } + + private _trackConnectionTask(lifecycle: WorkerLifecycle, task: Promise): Promise { + const trackedTask = task.finally(() => lifecycle.connectionTasks.delete(trackedTask)); + lifecycle.connectionTasks.add(trackedTask); + return trackedTask; + } + + private async _awaitConnectionTasks(lifecycle: WorkerLifecycle): Promise { + while (lifecycle.connectionTasks.size > 0) { + await Promise.allSettled([...lifecycle.connectionTasks]); + } + } + + private _scheduleReconnect(lifecycle: WorkerLifecycle, previousStub: stubs.TaskHubSidecarServiceClient): void { + if (lifecycle.abortController.signal.aborted) { + return; + } + + const reconnectTask = this._trackConnectionTask(lifecycle, this._createNewClientAndRetry(lifecycle, previousStub)); + reconnectTask.catch((retryErr) => { + if (!lifecycle.abortController.signal.aborted) { + WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); + } + }); } private _disposeResponseStream(stream: grpc.ClientReadableStream): void { @@ -660,30 +724,30 @@ export class TaskHubGrpcWorker { * Uses a configurable timeout (default 30s) to wait for in-flight work. */ async stop(): Promise { - if (!this._isRunning) { + const lifecycle = this._lifecycle; + if (!this._isRunning || !lifecycle) { throw new Error("The worker is not running."); } - this._stopWorker = true; - this._connectionGeneration++; - this._connectionAbort?.abort(new Error("Worker startup was stopped before the connection was established.")); + lifecycle.stopping = true; + lifecycle.abortController.abort(new Error(WORKER_STARTUP_STOPPED_MESSAGE)); this._helloCall?.cancel(); // Cancel stream first while error handlers are still attached // This allows the error handler to suppress CANCELLED errors - this._responseStream?.cancel(); + const responseStream = this._responseStream; + responseStream?.cancel(); // Wait for the stream to react to cancellation using events rather than a fixed delay. // This avoids race conditions caused by relying on timing alone. - if (this._responseStream) { + if (responseStream) { try { await withTimeout( new Promise((resolve) => { - const stream = this._responseStream!; // Any of these events indicates the stream has processed cancellation / is closing. - stream.once("end", resolve); - stream.once("close", resolve); - stream.once("error", () => resolve()); + responseStream.once("end", resolve); + responseStream.once("close", resolve); + responseStream.once("error", () => resolve()); }), 1000, "Timed out waiting for response stream to close after cancellation", @@ -694,8 +758,11 @@ export class TaskHubGrpcWorker { } // Now safe to remove listeners and destroy - this._responseStream?.removeAllListeners(); - this._responseStream?.destroy(); + if (responseStream) { + this._disposeResponseStream(responseStream); + } + + await this._awaitConnectionTasks(lifecycle); // Wait for pending work items to complete with timeout if (this._pendingWorkItems.size > 0) { @@ -719,11 +786,15 @@ export class TaskHubGrpcWorker { this._stub = null; } this._responseStream = null; - this._isRunning = false; // Brief pause to allow gRPC cleanup // https://github.com/grpc/grpc-node/issues/1563#issuecomment-829483711 await sleep(1000); + + if (this._lifecycle === lifecycle) { + this._lifecycle = null; + this._isRunning = false; + } } /** diff --git a/packages/durabletask-js/test/backoff.spec.ts b/packages/durabletask-js/test/backoff.spec.ts index 63830d56..a24d68e7 100644 --- a/packages/durabletask-js/test/backoff.spec.ts +++ b/packages/durabletask-js/test/backoff.spec.ts @@ -81,6 +81,30 @@ describe("ExponentialBackoff", () => { await backoff.wait(); expect(backoff.currentDelayMs).toBe(100); // 50 * 10 = 500, capped at 100 }); + + it("should not advance after an aborted wait", async () => { + jest.useFakeTimers(); + const backoff = new ExponentialBackoff({ + initialDelayMs: 1000, + multiplier: 2, + jitterFactor: 0, + }); + const controller = new AbortController(); + const abortError = new Error("stopped"); + + try { + const waitPromise = backoff.wait(controller.signal); + controller.abort(abortError); + + await expect(waitPromise).rejects.toBe(abortError); + await jest.runAllTimersAsync(); + + expect(backoff.attemptCount).toBe(0); + expect(backoff.currentDelayMs).toBe(1000); + } finally { + jest.useRealTimers(); + } + }); }); describe("reset", () => { diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index a6a6df26..850e091e 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -172,6 +172,53 @@ describe("TaskHubGrpcWorker startup", () => { expect((worker as any)._isRunning).toBe(true); }); + it("keeps restart blocked when stop claims a failing startup lifecycle", async () => { + jest.useFakeTimers(); + const first = createMockStub((...args: any[]) => { + getHelloCallback(args)(new Error("handshake failed"), new Empty()); + return { cancel: jest.fn() } as any; + }); + const second = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + jest + .spyOn(GrpcClient.prototype as any, "_generateClient") + .mockReturnValueOnce(first.stub) + .mockReturnValueOnce(second.stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const awaitConnectionTasks = (worker as any)._awaitConnectionTasks.bind(worker); + let releaseStartupCleanup!: () => void; + const startupCleanupReleased = new Promise((resolve) => { + releaseStartupCleanup = resolve; + }); + let startupCleanupEntered!: () => void; + const startupCleanupStarted = new Promise((resolve) => { + startupCleanupEntered = resolve; + }); + jest.spyOn(worker as any, "_awaitConnectionTasks").mockImplementation(async (lifecycle: any) => { + if (!lifecycle.stopping) { + startupCleanupEntered(); + await startupCleanupReleased; + } + await awaitConnectionTasks(lifecycle); + }); + + const firstStart = worker.start(); + await startupCleanupStarted; + const stopPromise = worker.stop(); + await flushPromises(); + releaseStartupCleanup(); + await expect(firstStart).rejects.toThrow("handshake failed"); + + await expect(worker.start()).rejects.toThrow("The worker is already running."); + + await jest.advanceTimersByTimeAsync(1000); + await stopPromise; + await expect(worker.start()).resolves.toBeUndefined(); + expect(second.getWorkItems).toHaveBeenCalledTimes(1); + }); + it("remains retryable after synchronous gRPC client construction fails", async () => { const { stub, getWorkItems } = createMockStub((...args: any[]) => { getHelloCallback(args)(null, new Empty()); @@ -266,6 +313,41 @@ describe("TaskHubGrpcWorker startup", () => { expect((worker as any)._responseStream).toBe(secondStream); }); + it("cancels a stopped lifecycle's reconnect backoff before restarting", async () => { + jest.useFakeTimers(); + jest.spyOn(Math, "random").mockReturnValue(1); + const first = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + const second = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + const generateClient = jest + .spyOn(GrpcClient.prototype as any, "_generateClient") + .mockReturnValueOnce(first.stub) + .mockReturnValueOnce(second.stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + + await worker.start(); + first.stream.emit("error", new Error("14 UNAVAILABLE")); + await flushPromises(); + + const stopPromise = worker.stop(); + await jest.advanceTimersByTimeAsync(1000); + await stopPromise; + + await worker.start(); + expect((worker as any)._backoff.currentDelayMs).toBe(1000); + + await jest.advanceTimersByTimeAsync(101); + + expect((worker as any)._backoff.currentDelayMs).toBe(1000); + expect(second.getWorkItems).toHaveBeenCalledTimes(1); + expect(generateClient).toHaveBeenCalledTimes(2); + }); + it("keeps stream recovery active after startup", async () => { const { stub, stream } = createMockStub((...args: any[]) => { getHelloCallback(args)(null, new Empty()); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index d801bd9f..cb24c85d 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -23,6 +23,7 @@ import { GrpcClient } from "../src/client/client-grpc"; function createMockClient(): { client: GrpcClient; mockStream: EventEmitter & { destroy: jest.Mock; cancel: jest.Mock }; + close: jest.Mock; } { const mockStream = new EventEmitter() as EventEmitter & { destroy: jest.Mock; @@ -31,16 +32,18 @@ function createMockClient(): { mockStream.destroy = jest.fn(); mockStream.cancel = jest.fn(); + const close = jest.fn(); const stub = { hello: (_req: any, _metadata: any, _options: any, callback: (err: any, res: any) => void) => { callback(null, {}); return { cancel: jest.fn() } as any; }, getWorkItems: jest.fn().mockReturnValue(mockStream), + close, }; const client = { stub } as unknown as GrpcClient; - return { client, mockStream }; + return { client, mockStream, close }; } /** Flush the microtask / next-tick queue so async event handlers complete. */ @@ -72,14 +75,19 @@ describe("Worker Stream Recovery", () => { it("should not retry when the worker is being stopped", async () => { const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); const { client, mockStream } = createMockClient(); + const lifecycle = { + abortController: new AbortController(), + connectionTasks: new Set>(), + stopping: false, + }; const retryMock = jest.fn().mockResolvedValue(undefined); (worker as any)._createNewClientAndRetry = retryMock; - await worker.internalRunWorker(client); + await worker.internalRunWorker(client, false, lifecycle); // Signal that the worker is shutting down - (worker as any)._stopWorker = true; + lifecycle.abortController.abort(); mockStream.emit("error", new Error("1 CANCELLED")); await flushAsync(); @@ -148,6 +156,30 @@ describe("Worker Stream Recovery", () => { expect(retryMock).toHaveBeenCalledTimes(1); }); + it("should only close the stub that owns a failed stream", async () => { + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream, close } = createMockClient(); + const lifecycle = { + abortController: new AbortController(), + connectionTasks: new Set>(), + stopping: false, + }; + const replacementClose = jest.fn(); + + await worker.internalRunWorker(client, false, lifecycle); + (worker as any)._stub = { close: replacementClose }; + + try { + mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); + + expect(close).toHaveBeenCalledTimes(1); + expect(replacementClose).not.toHaveBeenCalled(); + } finally { + lifecycle.abortController.abort(); + await flushAsync(); + } + }); + it("should not crash if _createNewClientAndRetry rejects during error recovery", async () => { const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); const { client, mockStream } = createMockClient(); From b54936322781315e1c53179a5c126721a67bea51 Mon Sep 17 00:00:00 2001 From: wangbill Date: Mon, 10 Aug 2026 17:46:19 -0700 Subject: [PATCH 06/12] fix(worker): adopt direct-run lifecycle ownership Track direct internal worker runs under the same lifecycle invariants as start and reconnect so stop can drain them and later starts cannot race stale streams. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/worker/task-hub-grpc-worker.ts | 23 +++++++++-- .../test/worker-startup.spec.ts | 40 +++++++++++++++++++ .../test/worker-stream-recovery.spec.ts | 18 ++------- 3 files changed, 63 insertions(+), 18 deletions(-) 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 c7205922..a066119f 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -250,7 +250,7 @@ export class TaskHubGrpcWorker { ); this._stub = newClient.stub; - await this.internalRunWorker(newClient, true, lifecycle); + await this._runWorker(newClient, true, lifecycle); } /** @@ -433,8 +433,11 @@ export class TaskHubGrpcWorker { this._isRunning = true; this._lifecycle = lifecycle; this._stub = client.stub; - const startupTask = this._trackConnectionTask(lifecycle, this.internalRunWorker(client, false, lifecycle)); + await this._runOwnedWorker(client, false, lifecycle); + } + private async _runOwnedWorker(client: GrpcClient, isRetry: boolean, lifecycle: WorkerLifecycle): Promise { + const startupTask = this._trackConnectionTask(lifecycle, this._runWorker(client, isRetry, lifecycle)); try { await startupTask; this._ensureLifecycleActive(lifecycle); @@ -458,8 +461,20 @@ export class TaskHubGrpcWorker { } } - async internalRunWorker(client: GrpcClient, isRetry: boolean = false, lifecycle?: WorkerLifecycle): Promise { - const activeLifecycle = lifecycle ?? this._lifecycle ?? this._createLifecycle(); + async internalRunWorker(client: GrpcClient, isRetry: boolean = false): Promise { + if (this._isRunning || this._lifecycle) { + throw new Error("The worker is already running."); + } + + const lifecycle = this._createLifecycle(); + this._isRunning = true; + this._lifecycle = lifecycle; + this._stub = client.stub; + await this._runOwnedWorker(client, isRetry, lifecycle); + } + + private async _runWorker(client: GrpcClient, isRetry: boolean, lifecycle: WorkerLifecycle): Promise { + const activeLifecycle = lifecycle; const deadline = Date.now() + this._startupTimeoutMs; const waitForStartup = (promise: Promise, timeoutMessage: string): Promise => this._waitForStartupStage(activeLifecycle, promise, deadline, timeoutMessage); diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index 850e091e..455a01f6 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -348,6 +348,46 @@ describe("TaskHubGrpcWorker startup", () => { expect(generateClient).toHaveBeenCalledTimes(2); }); + it("adopts a direct internal run so it cannot race a later start", async () => { + jest.useFakeTimers(); + const direct = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + const restarted = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + const generateClient = jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(restarted.stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const directClient = { stub: direct.stub } as unknown as GrpcClient; + + await worker.internalRunWorker(directClient); + + expect((worker as any)._isRunning).toBe(true); + expect((worker as any)._lifecycle).not.toBeNull(); + expect((worker as any)._stub).toBe(direct.stub); + await expect(worker.start()).rejects.toThrow("The worker is already running."); + expect(generateClient).not.toHaveBeenCalled(); + + const stopPromise = worker.stop(); + await jest.runAllTimersAsync(); + await stopPromise; + + expect(direct.stream.cancel).toHaveBeenCalled(); + expect(direct.close).toHaveBeenCalled(); + expect((worker as any)._isRunning).toBe(false); + expect((worker as any)._lifecycle).toBeNull(); + + await worker.start(); + direct.stream.emit("error", new Error("stale direct-run stream error")); + await flushPromises(); + + expect(generateClient).toHaveBeenCalledTimes(1); + expect((worker as any)._stub).toBe(restarted.stub); + expect((worker as any)._responseStream).toBe(restarted.stream); + }); + it("keeps stream recovery active after startup", async () => { const { stub, stream } = createMockStub((...args: any[]) => { getHelloCallback(args)(null, new Empty()); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index cb24c85d..61345903 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -75,19 +75,14 @@ describe("Worker Stream Recovery", () => { it("should not retry when the worker is being stopped", async () => { const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); const { client, mockStream } = createMockClient(); - const lifecycle = { - abortController: new AbortController(), - connectionTasks: new Set>(), - stopping: false, - }; const retryMock = jest.fn().mockResolvedValue(undefined); (worker as any)._createNewClientAndRetry = retryMock; - await worker.internalRunWorker(client, false, lifecycle); + await worker.internalRunWorker(client); // Signal that the worker is shutting down - lifecycle.abortController.abort(); + (worker as any)._lifecycle.abortController.abort(); mockStream.emit("error", new Error("1 CANCELLED")); await flushAsync(); @@ -159,14 +154,9 @@ describe("Worker Stream Recovery", () => { it("should only close the stub that owns a failed stream", async () => { const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); const { client, mockStream, close } = createMockClient(); - const lifecycle = { - abortController: new AbortController(), - connectionTasks: new Set>(), - stopping: false, - }; const replacementClose = jest.fn(); - await worker.internalRunWorker(client, false, lifecycle); + await worker.internalRunWorker(client); (worker as any)._stub = { close: replacementClose }; try { @@ -175,7 +165,7 @@ describe("Worker Stream Recovery", () => { expect(close).toHaveBeenCalledTimes(1); expect(replacementClose).not.toHaveBeenCalled(); } finally { - lifecycle.abortController.abort(); + (worker as any)._lifecycle.abortController.abort(); await flushAsync(); } }); From 2a8da5dadc78a0a5b0039e1dca301e29caae6651 Mon Sep 17 00:00:00 2001 From: wangbill Date: Mon, 10 Aug 2026 18:03:57 -0700 Subject: [PATCH 07/12] fix(worker): retry replacement client construction Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b --- .../src/worker/task-hub-grpc-worker.ts | 26 +++++++---- .../test/worker-startup.spec.ts | 45 +++++++++++++++++++ 2 files changed, 63 insertions(+), 8 deletions(-) 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 a066119f..76b70268 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -239,15 +239,25 @@ export class TaskHubGrpcWorker { this._stub = null; } - await this._backoff.wait(lifecycle.abortController.signal); - this._ensureLifecycleActive(lifecycle); + let newClient: GrpcClient; + while (true) { + await this._backoff.wait(lifecycle.abortController.signal); + this._ensureLifecycleActive(lifecycle); - const newClient = new GrpcClient( - this._hostAddress, - this._grpcChannelOptions, - this._tls, - this._grpcChannelCredentials, - ); + try { + newClient = new GrpcClient( + this._hostAddress, + this._grpcChannelOptions, + this._tls, + this._grpcChannelCredentials, + ); + break; + } catch (err) { + this._ensureLifecycleActive(lifecycle); + WorkerLogs.workerError(this._logger, err instanceof Error ? err : new Error(String(err))); + WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); + } + } this._stub = newClient.stub; await this._runWorker(newClient, true, lifecycle); diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index 455a01f6..b62ad0dd 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -388,6 +388,51 @@ describe("TaskHubGrpcWorker startup", () => { expect((worker as any)._responseStream).toBe(restarted.stream); }); + it("continues reconnecting when a replacement client cannot be constructed", async () => { + jest.useFakeTimers(); + const first = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + const recovered = createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as any; + }); + const generateClient = jest + .spyOn(GrpcClient.prototype as any, "_generateClient") + .mockReturnValueOnce(first.stub) + .mockImplementationOnce(() => { + throw new Error("client construction failed"); + }) + .mockReturnValueOnce(recovered.stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + + await worker.start(); + first.stream.emit("error", new Error("14 UNAVAILABLE")); + + await jest.runOnlyPendingTimersAsync(); + const trackedWhileRetryPending = (worker as any)._lifecycle.connectionTasks.size; + + await jest.runOnlyPendingTimersAsync(); + const recoveredStream = (worker as any)._responseStream; + const recoveredStub = (worker as any)._stub; + + const stopPromise = worker.stop(); + await jest.runAllTimersAsync(); + await stopPromise; + + expect(trackedWhileRetryPending).toBe(1); + expect(generateClient).toHaveBeenCalledTimes(3); + expect(recovered.getWorkItems).toHaveBeenCalledTimes(1); + expect(recoveredStream).toBe(recovered.stream); + expect(recoveredStub).toBe(recovered.stub); + expect(first.close).toHaveBeenCalledTimes(1); + expect(recovered.stream.cancel).toHaveBeenCalledTimes(1); + expect(recovered.close).toHaveBeenCalledTimes(1); + expect((worker as any)._isRunning).toBe(false); + expect((worker as any)._lifecycle).toBeNull(); + }); + it("keeps stream recovery active after startup", async () => { const { stub, stream } = createMockStub((...args: any[]) => { getHelloCallback(args)(null, new Empty()); From ca539eec5fcf0665668372ddd8bfefb314ba1117 Mon Sep 17 00:00:00 2001 From: wangbill Date: Thu, 13 Aug 2026 09:38:17 -0700 Subject: [PATCH 08/12] fix(worker): bound and drain connection retries Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b --- .github/workflows/dts-e2e-tests.yaml | 28 - CHANGELOG.md | 22 +- README.md | 11 +- .../durabletask-js-azuremanaged/CHANGELOG.md | 9 - .../durabletask-js-azuremanaged/README.md | 6 - .../src/worker-builder.ts | 16 - .../test/unit/worker-builder.spec.ts | 11 - .../durabletask-js/src/utils/backoff.util.ts | 11 +- .../src/worker/task-hub-grpc-worker.ts | 544 ++++++------------ packages/durabletask-js/test/backoff.spec.ts | 5 +- .../test/worker-startup.spec.ts | 475 +++++---------- .../test/worker-stream-recovery.spec.ts | 272 +++------ .../worker-stream-recovery.spec.ts | 71 +-- 13 files changed, 445 insertions(+), 1036 deletions(-) diff --git a/.github/workflows/dts-e2e-tests.yaml b/.github/workflows/dts-e2e-tests.yaml index 2abf5a0b..67099aaa 100644 --- a/.github/workflows/dts-e2e-tests.yaml +++ b/.github/workflows/dts-e2e-tests.yaml @@ -66,31 +66,3 @@ jobs: - name: ✅ Run E2E tests — ${{ matrix.test-group.name }} run: npx jest ${{ matrix.test-group.pattern }} --runInBand --detectOpenHandles timeout-minutes: 15 - - worker-stream-recovery: - name: "e2e (worker-stream-recovery, node 22.x)" - env: - EMULATOR_VERSION: "latest" - TASKHUB: "default" - ENDPOINT: "localhost:8080" - runs-on: ubuntu-latest - - steps: - - name: 📥 Checkout code - uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1 - - - name: 🐳 Pull Docker image - run: docker pull mcr.microsoft.com/dts/dts-emulator:$EMULATOR_VERSION - - - name: ⚙️ NodeJS - Install - uses: actions/setup-node@820762786026740c76f36085b0efc47a31fe5020 # v7.0.0 - with: - node-version: "22.x" - registry-url: "https://registry.npmjs.org" - - - name: ⚙️ Install dependencies - run: npm ci - - - name: ✅ Run worker stream recovery E2E test - run: npx jest test/e2e-azuremanaged/worker-stream-recovery.spec.ts --runInBand --detectOpenHandles - timeout-minutes: 5 diff --git a/CHANGELOG.md b/CHANGELOG.md index 6aa53db3..683f3c07 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,23 +1,5 @@ ## Upcoming -### Breaking Changes - -- `TaskHubGrpcWorker.start()` now rejects when the sidecar cannot be reached within - `startupTimeoutMs` (30 seconds by default). Previously, `start()` resolved before connecting and - retried forever in the background. Deployments where the worker may start before its sidecar - should either increase `startupTimeoutMs` or retry `start()` from the caller: - - ```typescript - for (;;) { - try { - await worker.start(); - break; - } catch { - await new Promise((resolve) => setTimeout(resolve, 1000)); - } - } - ``` - ### New - Add an optional `newVersion` parameter to `OrchestrationContext.continueAsNew()` for version migrations. @@ -31,8 +13,8 @@ ### Fixes -- Make `TaskHubGrpcWorker.start()` wait until the sidecar hello handshake succeeds and the initial - work-item stream is created with its handlers attached. +- Bound each worker sidecar hello attempt to 30 seconds while preserving background connection + retries, and make worker shutdown cancel and drain the connection loop. ## v0.4.0 (2026-07-31) diff --git a/README.md b/README.md index de4f6178..9c5b9ef9 100644 --- a/README.md +++ b/README.md @@ -81,12 +81,6 @@ const state = await client.waitForOrchestrationCompletion(id, true, 60); console.log(`Result: ${state?.serializedOutput}`); ``` -`await worker.start()` resolves only after startup metadata is generated, the initial sidecar -handshake succeeds, and the work-item stream is created with its handlers attached. Metadata -generation and the handshake have a 30-second startup budget by default; use the worker builder's -`.startupTimeout(milliseconds)` method to configure it. If the sidecar is not ready in time, -`start()` rejects; callers that require indefinite startup recovery should retry `start()`. - You can find more samples in the [examples/azure-managed](./examples/azure-managed) directory. ### Reusing orchestration instance IDs @@ -182,7 +176,10 @@ Long-running orchestrations can restart with fresh history and optionally move t orchestration version: ```typescript -const eternalOrchestrator: TOrchestrator = async function* (ctx: OrchestrationContext, iteration: number): any { +const eternalOrchestrator: TOrchestrator = async function* ( + ctx: OrchestrationContext, + iteration: number, +): any { yield ctx.callActivity(processIteration, iteration); ctx.continueAsNew(iteration + 1, true, "2.0.0"); }; diff --git a/packages/durabletask-js-azuremanaged/CHANGELOG.md b/packages/durabletask-js-azuremanaged/CHANGELOG.md index a7aad3f9..532f5c30 100644 --- a/packages/durabletask-js-azuremanaged/CHANGELOG.md +++ b/packages/durabletask-js-azuremanaged/CHANGELOG.md @@ -1,18 +1,9 @@ ## Upcoming -### Breaking Changes - -- Workers built by `DurableTaskAzureManagedWorkerBuilder` now reject `start()` when the sidecar - cannot be reached within the configured startup timeout. Previously, `start()` resolved before - connecting and retried forever in the background. Use `.startupTimeout(...)` to allow more time, - or retry `start()` from the caller as described in the core package changelog. - ### New ### Fixes -- Add `startupTimeout()` to configure the core worker's metadata and hello-handshake startup budget. - ## v0.4.0 (2026-07-31) ### Changes diff --git a/packages/durabletask-js-azuremanaged/README.md b/packages/durabletask-js-azuremanaged/README.md index 14a48b8e..029e569b 100644 --- a/packages/durabletask-js-azuremanaged/README.md +++ b/packages/durabletask-js-azuremanaged/README.md @@ -53,12 +53,6 @@ const worker = createAzureManagedWorkerBuilder("https://myservice.durabletask.io await worker.start(); ``` -`start()` resolves after startup metadata is generated, the initial sidecar handshake succeeds, -and the work-item stream is created with its handlers attached. Metadata generation and the -handshake have a 30-second startup budget by default, configurable with -`.startupTimeout(milliseconds)`. If the sidecar is not ready in time, `start()` rejects; retry it -from the caller when the deployment requires indefinite startup recovery. - ## Supported Authentication Types The connection string `Authentication` parameter supports the following values: diff --git a/packages/durabletask-js-azuremanaged/src/worker-builder.ts b/packages/durabletask-js-azuremanaged/src/worker-builder.ts index 28b1c60a..f749ea79 100644 --- a/packages/durabletask-js-azuremanaged/src/worker-builder.ts +++ b/packages/durabletask-js-azuremanaged/src/worker-builder.ts @@ -29,7 +29,6 @@ export class DurableTaskAzureManagedWorkerBuilder { private _entities: { name?: string; factory: EntityFactory }[] = []; private _logger: Logger = new ConsoleLogger(); private _shutdownTimeoutMs?: number; - private _startupTimeoutMs?: number; private _versioning?: VersioningOptions; private _workItemFilters?: WorkItemFilters | "auto"; @@ -237,20 +236,6 @@ export class DurableTaskAzureManagedWorkerBuilder { return this; } - /** - * Sets the startup timeout in milliseconds. - * This is the maximum time for startup metadata generation and the sidecar hello handshake - * before the initial work-item stream is created. - * Defaults to 30000 (30 seconds). - * - * @param timeoutMs The startup timeout in milliseconds. - * @returns This builder instance. - */ - startupTimeout(timeoutMs: number): DurableTaskAzureManagedWorkerBuilder { - this._startupTimeoutMs = timeoutMs; - return this; - } - /** * Configures versioning options for the worker. * This allows filtering orchestrations by version using different match strategies. @@ -308,7 +293,6 @@ export class DurableTaskAzureManagedWorkerBuilder { metadataGenerator, logger: this._logger, shutdownTimeoutMs: this._shutdownTimeoutMs, - startupTimeoutMs: this._startupTimeoutMs, versioning: this._versioning, workItemFilters: this._workItemFilters, }); diff --git a/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts b/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts index 577111f4..d0f97cb4 100644 --- a/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts +++ b/packages/durabletask-js-azuremanaged/test/unit/worker-builder.spec.ts @@ -90,15 +90,4 @@ describe("DurableTaskAzureManagedWorkerBuilder", () => { expect(result).toBe(builder); }); }); - - describe("startupTimeout", () => { - it("configures the core worker startup timeout", () => { - const worker = new DurableTaskAzureManagedWorkerBuilder() - .endpoint(ENDPOINT, TASKHUB, null) - .startupTimeout(1234) - .build(); - - expect((worker as any)._startupTimeoutMs).toBe(1234); - }); - }); }); diff --git a/packages/durabletask-js/src/utils/backoff.util.ts b/packages/durabletask-js/src/utils/backoff.util.ts index 5a57a46e..c5fa45a6 100644 --- a/packages/durabletask-js/src/utils/backoff.util.ts +++ b/packages/durabletask-js/src/utils/backoff.util.ts @@ -130,7 +130,8 @@ export class ExponentialBackoff { * Waits for the current backoff delay, then increments the attempt count * and calculates the next delay. * - * @returns Promise that resolves after the delay. + * @param signal Optional signal that cancels the pending delay. + * @returns Promise that resolves after the delay or rejects when aborted. */ async wait(signal?: AbortSignal): Promise { const delay = this._calculateDelayWithJitter(); @@ -140,15 +141,15 @@ export class ExponentialBackoff { } await new Promise((resolve, reject) => { - const timeoutId = setTimeout(() => { - signal?.removeEventListener("abort", onAbort); - resolve(); - }, delay); const onAbort = () => { clearTimeout(timeoutId); signal?.removeEventListener("abort", onAbort); reject(signal?.reason); }; + const timeoutId = setTimeout(() => { + signal?.removeEventListener("abort", onAbort); + resolve(); + }, delay); signal?.addEventListener("abort", onAbort, { once: true }); }); 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 76b70268..d39ba689 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -20,7 +20,8 @@ import { EntityInstanceId } from "../entities/entity-instance-id"; import { EntityFactory } from "../entities/task-entity"; import { StringValue } from "google-protobuf/google/protobuf/wrappers_pb"; import { Logger, ConsoleLogger } from "../types/logger.type"; -import { ExponentialBackoff, sleep, withTimeout } from "../utils/backoff.util"; +import { ExponentialBackoff, withTimeout } from "../utils/backoff.util"; +import { TimeoutError } from "../exception/timeout-error"; import { VersioningOptions, VersionMatchStrategy, VersionFailureStrategy } from "./versioning-options"; import { WorkItemFilters, generateWorkItemFiltersFromRegistry, toGrpcWorkItemFilters } from "./work-item-filters"; import { compareVersions } from "../utils/versioning.util"; @@ -37,15 +38,19 @@ import { setSpanOk, endSpan, } from "../tracing"; -import { raceWithTimeout } from "../utils/timeout.util"; -import { TimeoutError } from "../exception/timeout-error"; /** Default timeout in milliseconds for graceful shutdown. */ const DEFAULT_SHUTDOWN_TIMEOUT_MS = 30000; -/** Default timeout in milliseconds for establishing the initial worker connection. */ -const DEFAULT_STARTUP_TIMEOUT_MS = 30000; -const MAX_TIMER_DELAY_MS = 2147483647; -const WORKER_STARTUP_STOPPED_MESSAGE = "Worker startup was stopped before the connection was established."; +/** Timeout applied to each sidecar hello attempt. */ +const HELLO_TIMEOUT_MS = 30000; + +interface WorkerLifecycle { + readonly abortController: AbortController; + runPromise: Promise; + stub: stubs.TaskHubSidecarServiceClient | null; + helloCall: grpc.ClientUnaryCall | null; + responseStream: grpc.ClientReadableStream | null; +} /** * Options for creating a TaskHubGrpcWorker. @@ -65,11 +70,6 @@ export interface TaskHubGrpcWorkerOptions { logger?: Logger; /** Optional timeout in milliseconds for graceful shutdown. Defaults to 30000. */ shutdownTimeoutMs?: number; - /** - * Optional timeout in milliseconds for startup metadata generation and the sidecar hello handshake. - * Defaults to 30000. - */ - startupTimeoutMs?: number; /** Optional versioning options for filtering orchestrations by version. */ versioning?: VersioningOptions; /** @@ -82,15 +82,7 @@ export interface TaskHubGrpcWorkerOptions { workItemFilters?: WorkItemFilters | "auto"; } -interface WorkerLifecycle { - readonly abortController: AbortController; - readonly connectionTasks: Set>; - stopping: boolean; -} - export class TaskHubGrpcWorker { - private _responseStream: grpc.ClientReadableStream | null; - private _helloCall: grpc.ClientUnaryCall | null; private _registry: Registry; private _hostAddress?: string; private _tls?: boolean; @@ -98,12 +90,9 @@ export class TaskHubGrpcWorker { private _grpcChannelCredentials?: grpc.ChannelCredentials; private _metadataGenerator?: MetadataGenerator; private _isRunning: boolean; - private _stub: stubs.TaskHubSidecarServiceClient | null; private _logger: Logger; private _pendingWorkItems: Set>; private _shutdownTimeoutMs: number; - private _startupTimeoutMs: number; - private _backoff: ExponentialBackoff; private _versioning?: VersioningOptions; private _workItemFilters?: WorkItemFilters | "auto"; private _lifecycle: WorkerLifecycle | null; @@ -153,7 +142,6 @@ export class TaskHubGrpcWorker { let resolvedMetadataGenerator: MetadataGenerator | undefined; let resolvedLogger: Logger | undefined; let resolvedShutdownTimeoutMs: number | undefined; - let resolvedStartupTimeoutMs: number | undefined; let resolvedVersioning: VersioningOptions | undefined; let resolvedWorkItemFilters: WorkItemFilters | "auto" | undefined; @@ -166,7 +154,6 @@ export class TaskHubGrpcWorker { resolvedMetadataGenerator = hostAddressOrOptions.metadataGenerator; resolvedLogger = hostAddressOrOptions.logger; resolvedShutdownTimeoutMs = hostAddressOrOptions.shutdownTimeoutMs; - resolvedStartupTimeoutMs = hostAddressOrOptions.startupTimeoutMs; resolvedVersioning = hostAddressOrOptions.versioning; resolvedWorkItemFilters = hostAddressOrOptions.workItemFilters; } else { @@ -186,28 +173,10 @@ export class TaskHubGrpcWorker { this._grpcChannelOptions = resolvedOptions; this._grpcChannelCredentials = resolvedCredentials; this._metadataGenerator = resolvedMetadataGenerator; - this._responseStream = null; - this._helloCall = null; this._isRunning = false; - this._stub = null; this._logger = resolvedLogger ?? new ConsoleLogger(); this._pendingWorkItems = new Set(); this._shutdownTimeoutMs = resolvedShutdownTimeoutMs ?? DEFAULT_SHUTDOWN_TIMEOUT_MS; - this._startupTimeoutMs = resolvedStartupTimeoutMs ?? DEFAULT_STARTUP_TIMEOUT_MS; - if ( - !Number.isFinite(this._startupTimeoutMs) || - this._startupTimeoutMs < 0 || - this._startupTimeoutMs > MAX_TIMER_DELAY_MS - ) { - throw new RangeError( - `startupTimeoutMs must be a finite number between 0 and ${MAX_TIMER_DELAY_MS}, got ${this._startupTimeoutMs}`, - ); - } - this._backoff = new ExponentialBackoff({ - initialDelayMs: 1000, - maxDelayMs: 30000, - multiplier: 2, - }); this._versioning = resolvedVersioning; this._workItemFilters = resolvedWorkItemFilters; this._lifecycle = null; @@ -223,46 +192,6 @@ export class TaskHubGrpcWorker { return new grpc.Metadata(); } - /** - * Creates a new gRPC client and retries the worker. - * Properly closes the old client to prevent connection leaks. - */ - private async _createNewClientAndRetry( - lifecycle: WorkerLifecycle, - previousStub: stubs.TaskHubSidecarServiceClient, - ): Promise { - this._ensureLifecycleActive(lifecycle); - - // Close the old stub to prevent connection leaks - previousStub.close(); - if (this._stub === previousStub) { - this._stub = null; - } - - let newClient: GrpcClient; - while (true) { - await this._backoff.wait(lifecycle.abortController.signal); - this._ensureLifecycleActive(lifecycle); - - try { - newClient = new GrpcClient( - this._hostAddress, - this._grpcChannelOptions, - this._tls, - this._grpcChannelCredentials, - ); - break; - } catch (err) { - this._ensureLifecycleActive(lifecycle); - WorkerLogs.workerError(this._logger, err instanceof Error ? err : new Error(String(err))); - WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); - } - } - this._stub = newClient.stub; - - await this._runWorker(newClient, true, lifecycle); - } - /** * Registers an orchestrator function with the worker. * @@ -427,185 +356,155 @@ export class TaskHubGrpcWorker { * In node.js we don't require a new thread as we have a main event loop * Therefore, we open the stream and simply listen through the eventemitter behind the scenes * - * @remarks Resolves after startup metadata is generated, the sidecar hello handshake - * succeeds, and the initial work-item stream is created with its handlers attached. - * Later stream failures reconnect automatically. - * @throws {@link TimeoutError} if metadata generation or the hello handshake exceeds - * the `startupTimeoutMs` startup budget before the initial work-item stream is established. + * @remarks Resolves after launching the background connection loop. Connection failures + * are logged and retried while the worker remains running. */ async start(): Promise { - if (this._isRunning) { - throw new Error("The worker is already running."); - } - - const client = new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); - const lifecycle = this._createLifecycle(); - this._isRunning = true; - this._lifecycle = lifecycle; - this._stub = client.stub; - await this._runOwnedWorker(client, false, lifecycle); + this._startConnectionLoop(); } - private async _runOwnedWorker(client: GrpcClient, isRetry: boolean, lifecycle: WorkerLifecycle): Promise { - const startupTask = this._trackConnectionTask(lifecycle, this._runWorker(client, isRetry, lifecycle)); - try { - await startupTask; - this._ensureLifecycleActive(lifecycle); - } catch (err) { - if (!lifecycle.stopping) { - const error = err instanceof Error ? err : new Error(String(err)); - lifecycle.abortController.abort(error); - this._helloCall?.cancel(); - await this._awaitConnectionTasks(lifecycle); - if (!lifecycle.stopping && this._lifecycle === lifecycle) { - client.stub.close(); - if (this._stub === client.stub) { - this._stub = null; - } - this._responseStream = null; - this._lifecycle = null; - this._isRunning = false; - } - } - throw err; - } + async internalRunWorker(client: GrpcClient, _isRetry: boolean = false): Promise { + this._startConnectionLoop(client); } - async internalRunWorker(client: GrpcClient, isRetry: boolean = false): Promise { + private _startConnectionLoop(initialClient?: GrpcClient): void { if (this._isRunning || this._lifecycle) { throw new Error("The worker is already running."); } - const lifecycle = this._createLifecycle(); + const lifecycle: WorkerLifecycle = { + abortController: new AbortController(), + runPromise: Promise.resolve(), + stub: null, + helloCall: null, + responseStream: null, + }; this._isRunning = true; this._lifecycle = lifecycle; - this._stub = client.stub; - await this._runOwnedWorker(client, isRetry, lifecycle); + lifecycle.runPromise = this._runConnectionLoop(lifecycle, initialClient).catch((err) => { + if (!lifecycle.abortController.signal.aborted) { + WorkerLogs.workerError(this._logger, err instanceof Error ? err : new Error(String(err))); + } + }); } - private async _runWorker(client: GrpcClient, isRetry: boolean, lifecycle: WorkerLifecycle): Promise { - const activeLifecycle = lifecycle; - const deadline = Date.now() + this._startupTimeoutMs; - const waitForStartup = (promise: Promise, timeoutMessage: string): Promise => - this._waitForStartupStage(activeLifecycle, promise, deadline, timeoutMessage); - let attemptStream: grpc.ClientReadableStream | null = null; - let connectionEstablished = false; - - try { - // send a "Hello" message to the sidecar to ensure that it's listening - const helloMetadata = await waitForStartup( - this._getMetadata(), - `Timed out starting worker after ${this._startupTimeoutMs}ms while generating sidecar metadata`, - ); - await this._waitForHello(client, activeLifecycle, helloMetadata, new Date(deadline)); - this._ensureLifecycleActive(activeLifecycle); + private async _runConnectionLoop(lifecycle: WorkerLifecycle, initialClient?: GrpcClient): Promise { + const signal = lifecycle.abortController.signal; + const backoff = new ExponentialBackoff({ + initialDelayMs: 1000, + maxDelayMs: 30000, + multiplier: 2, + }); + let nextClient = initialClient; - // Stream work items from the sidecar (pass metadata for insecure connections) - const metadata = await waitForStartup( - this._getMetadata(), - `Timed out starting worker after ${this._startupTimeoutMs}ms while generating work-item stream metadata`, - ); - this._ensureLifecycleActive(activeLifecycle); - const request = this._buildGetWorkItemsRequest(); - - const stream = client.stub.getWorkItems(request, metadata); - attemptStream = stream; - this._responseStream = stream; - - // Wait for a work item to be received - stream.on("data", (workItem: pb.WorkItem) => { - const completionToken = workItem.getCompletiontoken(); - if (workItem.hasOrchestratorrequest()) { - WorkerLogs.workItemReceived( - this._logger, - "Orchestrator Request", - workItem?.getOrchestratorrequest()?.getInstanceid(), - ); - this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, client.stub); - } else if (workItem.hasActivityrequest()) { - WorkerLogs.workItemReceived(this._logger, "Activity Request"); - this._executeActivity(workItem.getActivityrequest() as any, completionToken, client.stub); - } else if (workItem.hasEntityrequest()) { - const entityRequest = workItem.getEntityrequest() as pb.EntityBatchRequest; - WorkerLogs.entityRequestReceived(this._logger, entityRequest.getInstanceid(), "Entity Request"); - this._executeEntity(entityRequest, completionToken, client.stub); - } else if (workItem.hasEntityrequestv2()) { - const entityRequestV2 = workItem.getEntityrequestv2() as pb.EntityRequest; - WorkerLogs.entityRequestReceived(this._logger, entityRequestV2.getInstanceid(), "Entity Request V2"); - this._executeEntityV2(entityRequestV2, completionToken, client.stub); - } else if (workItem.hasHealthping()) { - // Health ping - no-op, just a keep-alive message from the server - } else { - WorkerLogs.unknownWorkItem(this._logger); - } - }); + while (!signal.aborted) { + let stub: stubs.TaskHubSidecarServiceClient | null = null; + let stream: grpc.ClientReadableStream | null = null; - // Wait for the stream to end or error - stream.on("end", () => { - if (activeLifecycle.abortController.signal.aborted) { + try { + const client = + nextClient ?? + new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); + nextClient = undefined; + stub = client.stub; + lifecycle.stub = stub; + + const helloMetadata = await this._waitForAbortable(this._getMetadata(), lifecycle); + await this._waitForHello(stub, helloMetadata, lifecycle); + + const metadata = await this._waitForAbortable(this._getMetadata(), lifecycle); + const request = this._buildGetWorkItemsRequest(); + stream = stub.getWorkItems(request, metadata); + lifecycle.responseStream = stream; + this._listenForWorkItems(stream, stub); + + backoff.reset(); + WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); + + const streamError = await this._waitForStreamEnd(stream, lifecycle); + if (signal.aborted) { WorkerLogs.streamEnded(this._logger); - this._disposeResponseStream(stream); - return; + break; } - // Stream ended unexpectedly - clean up and retry - this._disposeResponseStream(stream); - WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); - this._scheduleReconnect(activeLifecycle, client.stub); - }); - - stream.on("error", (err: Error) => { - // Ignore cancellation errors when the worker is being stopped intentionally - if (activeLifecycle.abortController.signal.aborted) { - return; + if (streamError) { + WorkerLogs.streamErrorInfo(this._logger, streamError); + } + WorkerLogs.streamRetry(this._logger, backoff.peekNextDelay()); + } catch (err) { + if (signal.aborted) { + break; + } + const error = err instanceof Error ? err : new Error(String(err)); + WorkerLogs.streamError(this._logger, error); + WorkerLogs.connectionRetry(this._logger, backoff.peekNextDelay()); + } finally { + if (stream) { + this._disposeResponseStream(stream, lifecycle); + } + if (stub && !signal.aborted) { + stub.close(); + if (lifecycle.stub === stub) { + lifecycle.stub = null; + } } - WorkerLogs.streamErrorInfo(this._logger, err); - - // Clean up the errored stream and retry the connection. - // In Node.js, gRPC stream errors (e.g., UNAVAILABLE, transport failures) - // may not always be followed by an "end" event. Without recovery here, - // the worker would silently stop processing work items. - this._disposeResponseStream(stream); - WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); - this._scheduleReconnect(activeLifecycle, client.stub); - }); - - this._ensureLifecycleActive(activeLifecycle); - connectionEstablished = true; - this._backoff.reset(); - WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); - } catch (err) { - const error = err instanceof Error ? err : new Error(String(err)); - if (error instanceof TimeoutError) { - this._helloCall?.cancel(); } - if (attemptStream && !connectionEstablished) { - attemptStream.cancel(); - this._disposeResponseStream(attemptStream); + + if (signal.aborted) { + break; } - if (activeLifecycle.abortController.signal.aborted) { - if (!isRetry) { - throw this._getLifecycleAbortError(activeLifecycle); + + try { + await backoff.wait(signal); + } catch (err) { + if (!signal.aborted) { + throw err; } - return; - } - WorkerLogs.streamError(this._logger, error); - if (!isRetry) { - throw error; } - WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); - await this._createNewClientAndRetry(activeLifecycle, client.stub); - return; } } + private _listenForWorkItems( + stream: grpc.ClientReadableStream, + stub: stubs.TaskHubSidecarServiceClient, + ): void { + stream.on("data", (workItem: pb.WorkItem) => { + const completionToken = workItem.getCompletiontoken(); + if (workItem.hasOrchestratorrequest()) { + WorkerLogs.workItemReceived( + this._logger, + "Orchestrator Request", + workItem?.getOrchestratorrequest()?.getInstanceid(), + ); + this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, stub); + } else if (workItem.hasActivityrequest()) { + WorkerLogs.workItemReceived(this._logger, "Activity Request"); + this._executeActivity(workItem.getActivityrequest() as any, completionToken, stub); + } else if (workItem.hasEntityrequest()) { + const entityRequest = workItem.getEntityrequest() as pb.EntityBatchRequest; + WorkerLogs.entityRequestReceived(this._logger, entityRequest.getInstanceid(), "Entity Request"); + this._executeEntity(entityRequest, completionToken, stub); + } else if (workItem.hasEntityrequestv2()) { + const entityRequestV2 = workItem.getEntityrequestv2() as pb.EntityRequest; + WorkerLogs.entityRequestReceived(this._logger, entityRequestV2.getInstanceid(), "Entity Request V2"); + this._executeEntityV2(entityRequestV2, completionToken, stub); + } else if (workItem.hasHealthping()) { + // Health ping - no-op, just a keep-alive message from the server + } else { + WorkerLogs.unknownWorkItem(this._logger); + } + }); + } + private async _waitForHello( - client: GrpcClient, - lifecycle: WorkerLifecycle, + stub: stubs.TaskHubSidecarServiceClient, metadata: grpc.Metadata, - deadline: Date, + lifecycle: WorkerLifecycle, ): Promise { - this._ensureLifecycleActive(lifecycle); - const timeoutMessage = `Timed out starting worker after ${this._startupTimeoutMs}ms while waiting for sidecar hello response`; + const signal = lifecycle.abortController.signal; + if (signal.aborted) { + throw this._getLifecycleAbortError(lifecycle); + } + let call: grpc.ClientUnaryCall | undefined; let timeoutId: ReturnType | undefined; let removeAbortListener: (() => void) | undefined; @@ -628,29 +527,20 @@ export class TaskHubGrpcWorker { resolve(); } }; - const onAbort = () => { + const onAbort = () => finish(this._getLifecycleAbortError(lifecycle)); + removeAbortListener = () => signal.removeEventListener("abort", onAbort); + signal.addEventListener("abort", onAbort, { once: true }); + + timeoutId = setTimeout(() => { + finish(new TimeoutError(`Sidecar hello did not respond within ${HELLO_TIMEOUT_MS}ms.`)); call?.cancel(); - finish(this._getLifecycleAbortError(lifecycle)); - }; - removeAbortListener = () => lifecycle.abortController.signal.removeEventListener("abort", onAbort); - lifecycle.abortController.signal.addEventListener("abort", onAbort, { once: true }); - timeoutId = setTimeout( - () => { - call?.cancel(); - finish(new TimeoutError(timeoutMessage)); - }, - Math.max(0, deadline.getTime() - Date.now()), - ); + }, HELLO_TIMEOUT_MS); try { - call = client.stub.hello(new Empty(), metadata, { deadline }, (error) => { - if (error && error.code === grpc.status.DEADLINE_EXCEEDED) { - finish(new TimeoutError(timeoutMessage)); - } else { - finish(error ?? undefined); - } - }); - this._helloCall = call; + call = stub.hello(new Empty(), metadata, { deadline: new Date(Date.now() + HELLO_TIMEOUT_MS) }, (error) => + finish(error ?? undefined), + ); + lifecycle.helloCall = call; } catch (err) { finish(err instanceof Error ? err : new Error(String(err))); } @@ -660,87 +550,70 @@ export class TaskHubGrpcWorker { clearTimeout(timeoutId); } removeAbortListener?.(); - if (this._helloCall === call) { - this._helloCall = null; + if (lifecycle.helloCall === call) { + lifecycle.helloCall = null; } } } - private async _waitForStartupStage( - lifecycle: WorkerLifecycle, - promise: Promise, - deadline: number, - timeoutMessage: string, - ): Promise { - this._ensureLifecycleActive(lifecycle); + private async _waitForAbortable(promise: Promise, lifecycle: WorkerLifecycle): Promise { const signal = lifecycle.abortController.signal; - let abort!: () => void; + if (signal.aborted) { + throw this._getLifecycleAbortError(lifecycle); + } + + let onAbort!: () => void; const aborted = new Promise((_, reject) => { - abort = () => reject(this._getLifecycleAbortError(lifecycle)); + onAbort = () => reject(this._getLifecycleAbortError(lifecycle)); + signal.addEventListener("abort", onAbort, { once: true }); }); - signal.addEventListener("abort", abort, { once: true }); try { - return await raceWithTimeout( - Promise.race([promise, aborted]), - Math.max(0, deadline - Date.now()), - () => timeoutMessage, - ); + return await Promise.race([promise, aborted]); } finally { - signal.removeEventListener("abort", abort); + signal.removeEventListener("abort", onAbort); } } - private _createLifecycle(): WorkerLifecycle { - return { - abortController: new AbortController(), - connectionTasks: new Set(), - stopping: false, - }; - } - - private _ensureLifecycleActive(lifecycle: WorkerLifecycle): void { - if (lifecycle.abortController.signal.aborted) { - throw this._getLifecycleAbortError(lifecycle); + private _waitForStreamEnd( + stream: grpc.ClientReadableStream, + lifecycle: WorkerLifecycle, + ): Promise { + const signal = lifecycle.abortController.signal; + if (signal.aborted) { + return Promise.resolve(undefined); } + + return new Promise((resolve) => { + let settled = false; + const finish = (error?: Error) => { + if (settled) { + return; + } + settled = true; + signal.removeEventListener("abort", onAbort); + resolve(error); + }; + const onAbort = () => finish(); + + signal.addEventListener("abort", onAbort, { once: true }); + stream.once("end", () => finish()); + // Keep handling duplicate errors until the loop disposes the stream. + stream.on("error", (error: Error) => finish(error)); + }); } private _getLifecycleAbortError(lifecycle: WorkerLifecycle): Error { const reason = lifecycle.abortController.signal.reason; - return reason instanceof Error ? reason : new Error(WORKER_STARTUP_STOPPED_MESSAGE); - } - - private _trackConnectionTask(lifecycle: WorkerLifecycle, task: Promise): Promise { - const trackedTask = task.finally(() => lifecycle.connectionTasks.delete(trackedTask)); - lifecycle.connectionTasks.add(trackedTask); - return trackedTask; + return reason instanceof Error ? reason : new Error("The worker was stopped."); } - private async _awaitConnectionTasks(lifecycle: WorkerLifecycle): Promise { - while (lifecycle.connectionTasks.size > 0) { - await Promise.allSettled([...lifecycle.connectionTasks]); - } - } - - private _scheduleReconnect(lifecycle: WorkerLifecycle, previousStub: stubs.TaskHubSidecarServiceClient): void { - if (lifecycle.abortController.signal.aborted) { - return; - } - - const reconnectTask = this._trackConnectionTask(lifecycle, this._createNewClientAndRetry(lifecycle, previousStub)); - reconnectTask.catch((retryErr) => { - if (!lifecycle.abortController.signal.aborted) { - WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); - } - }); - } - - private _disposeResponseStream(stream: grpc.ClientReadableStream): void { + private _disposeResponseStream(stream: grpc.ClientReadableStream, lifecycle: WorkerLifecycle): void { stream.removeAllListeners(); stream.on("error", () => {}); stream.destroy(); - if (this._responseStream === stream) { - this._responseStream = null; + if (lifecycle.responseStream === stream) { + lifecycle.responseStream = null; } } @@ -754,40 +627,10 @@ export class TaskHubGrpcWorker { throw new Error("The worker is not running."); } - lifecycle.stopping = true; - lifecycle.abortController.abort(new Error(WORKER_STARTUP_STOPPED_MESSAGE)); - this._helloCall?.cancel(); - - // Cancel stream first while error handlers are still attached - // This allows the error handler to suppress CANCELLED errors - const responseStream = this._responseStream; - responseStream?.cancel(); - - // Wait for the stream to react to cancellation using events rather than a fixed delay. - // This avoids race conditions caused by relying on timing alone. - if (responseStream) { - try { - await withTimeout( - new Promise((resolve) => { - // Any of these events indicates the stream has processed cancellation / is closing. - responseStream.once("end", resolve); - responseStream.once("close", resolve); - responseStream.once("error", () => resolve()); - }), - 1000, - "Timed out waiting for response stream to close after cancellation", - ); - } catch { - // If we time out waiting for the stream to close, proceed with forced cleanup below. - } - } - - // Now safe to remove listeners and destroy - if (responseStream) { - this._disposeResponseStream(responseStream); - } - - await this._awaitConnectionTasks(lifecycle); + lifecycle.abortController.abort(new Error("The worker was stopped.")); + lifecycle.helloCall?.cancel(); + lifecycle.responseStream?.cancel(); + await lifecycle.runPromise; // Wait for pending work items to complete with timeout if (this._pendingWorkItems.size > 0) { @@ -805,16 +648,11 @@ export class TaskHubGrpcWorker { } } - if (this._stub) { + if (lifecycle.stub) { // Close the gRPC client - this is a synchronous operation - this._stub.close(); - this._stub = null; + lifecycle.stub.close(); + lifecycle.stub = null; } - this._responseStream = null; - - // Brief pause to allow gRPC cleanup - // https://github.com/grpc/grpc-node/issues/1563#issuecomment-829483711 - await sleep(1000); if (this._lifecycle === lifecycle) { this._lifecycle = null; diff --git a/packages/durabletask-js/test/backoff.spec.ts b/packages/durabletask-js/test/backoff.spec.ts index a24d68e7..24aeaae8 100644 --- a/packages/durabletask-js/test/backoff.spec.ts +++ b/packages/durabletask-js/test/backoff.spec.ts @@ -82,7 +82,7 @@ describe("ExponentialBackoff", () => { expect(backoff.currentDelayMs).toBe(100); // 50 * 10 = 500, capped at 100 }); - it("should not advance after an aborted wait", async () => { + it("should abort without advancing the backoff state", async () => { jest.useFakeTimers(); const backoff = new ExponentialBackoff({ initialDelayMs: 1000, @@ -97,10 +97,9 @@ describe("ExponentialBackoff", () => { controller.abort(abortError); await expect(waitPromise).rejects.toBe(abortError); - await jest.runAllTimersAsync(); - expect(backoff.attemptCount).toBe(0); expect(backoff.currentDelayMs).toBe(1000); + expect(jest.getTimerCount()).toBe(0); } finally { jest.useRealTimers(); } diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index b62ad0dd..0c74da41 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -5,9 +5,8 @@ import { EventEmitter } from "events"; import * as grpc from "@grpc/grpc-js"; import { Empty } from "google-protobuf/google/protobuf/empty_pb"; import { GrpcClient } from "../src/client/client-grpc"; -import { TimeoutError } from "../src/exception/timeout-error"; import * as stubs from "../src/proto/orchestrator_service_grpc_pb"; -import { NoOpLogger } from "../src/types/logger.type"; +import { Logger, NoOpLogger } from "../src/types/logger.type"; import { TaskHubGrpcWorker } from "../src/worker/task-hub-grpc-worker"; type MockStream = EventEmitter & { @@ -15,11 +14,11 @@ type MockStream = EventEmitter & { destroy: jest.Mock; }; -type HelloCallback = (error: Error | null, response: Empty) => void; +type HelloCallback = (error: grpc.ServiceError | null, response: Empty) => void; function createMockStream(): MockStream { const stream = new EventEmitter() as MockStream; - stream.cancel = jest.fn(() => queueMicrotask(() => stream.emit("end"))); + stream.cancel = jest.fn(); stream.destroy = jest.fn(); return stream; } @@ -30,30 +29,47 @@ function createMockStub( ): { stub: stubs.TaskHubSidecarServiceClient; stream: MockStream; + hello: jest.Mock; getWorkItems: jest.Mock; close: jest.Mock; } { + const helloMock = jest.fn(hello); const getWorkItems = jest.fn().mockReturnValue(stream); const close = jest.fn(); const stub = { - hello: jest.fn(hello), + hello: helloMock, getWorkItems, close, } as unknown as stubs.TaskHubSidecarServiceClient; - - return { stub, stream, getWorkItems, close }; + return { stub, stream, hello: helloMock, getWorkItems, close }; } -function useMockStub(stub: stubs.TaskHubSidecarServiceClient): void { - jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(stub); +function successfulStub(stream = createMockStream()) { + return createMockStub((...args: any[]) => { + getHelloCallback(args)(null, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; + }, stream); } function getHelloCallback(args: any[]): HelloCallback { return args[args.length - 1] as HelloCallback; } -function flushAsync(): Promise { - return new Promise((resolve) => setImmediate(resolve)); +function useStubs(...stubSequence: stubs.TaskHubSidecarServiceClient[]): jest.SpyInstance { + const generateClient = jest.spyOn(GrpcClient.prototype as any, "_generateClient"); + for (const stub of stubSequence) { + generateClient.mockReturnValueOnce(stub); + } + return generateClient; +} + +function createLogger(): Logger & { error: jest.Mock } { + return { + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + }; } async function flushPromises(): Promise { @@ -62,412 +78,187 @@ async function flushPromises(): Promise { } } -describe("TaskHubGrpcWorker startup", () => { +describe("TaskHubGrpcWorker connection lifecycle", () => { afterEach(() => { jest.useRealTimers(); jest.restoreAllMocks(); }); - it("resolves after hello succeeds and an idle work-item stream is configured", async () => { - let completeHello: HelloCallback | undefined; - const { stub, getWorkItems } = createMockStub((...args: any[]) => { - completeHello = getHelloCallback(args); - return { cancel: jest.fn() } as any; - }); - useMockStub(stub); + it("starts promptly while hello is unavailable and cancels hello on stop", async () => { + const cancel = jest.fn(); + const pending = createMockStub(() => ({ cancel }) as unknown as grpc.ClientUnaryCall); + useStubs(pending.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - let started = false; - const startPromise = worker.start().then(() => { - started = true; - }); - await flushAsync(); - - expect(started).toBe(false); - expect(getWorkItems).not.toHaveBeenCalled(); - - completeHello!(null, new Empty()); - await startPromise; + await expect(worker.start()).resolves.toBeUndefined(); + await flushPromises(); - expect(getWorkItems).toHaveBeenCalledTimes(1); - expect(started).toBe(true); - expect((worker as any)._responseStream).not.toBeNull(); - }); + expect(pending.hello).toHaveBeenCalledTimes(1); + expect(pending.getWorkItems).not.toHaveBeenCalled(); - it("times out and cancels an unresponsive hello handshake", async () => { - const cancel = jest.fn(); - const { stub, close } = createMockStub(() => ({ cancel }) as any); - useMockStub(stub); - const worker = new TaskHubGrpcWorker({ - logger: new NoOpLogger(), - startupTimeoutMs: 10, - }); + await worker.stop(); - const startPromise = worker.start(); - await expect(startPromise).rejects.toThrow(TimeoutError); - await expect(startPromise).rejects.toThrow("Timed out starting worker after 10ms"); - - expect(cancel).toHaveBeenCalled(); - expect(close).toHaveBeenCalled(); + expect(cancel).toHaveBeenCalledTimes(1); + expect((worker as any)._lifecycle).toBeNull(); expect((worker as any)._isRunning).toBe(false); - expect((worker as any)._stub).toBeNull(); - expect((worker as any)._responseStream).toBeNull(); }); - it("applies the startup timeout while generating metadata", async () => { - const { stub, getWorkItems, close } = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - useMockStub(stub); - const worker = new TaskHubGrpcWorker({ - logger: new NoOpLogger(), - startupTimeoutMs: 10, - metadataGenerator: () => new Promise(() => {}), + it("times out each hung hello attempt and retries inside the owned loop", async () => { + jest.useFakeTimers(); + jest.setSystemTime(new Date("2026-01-01T00:00:00Z")); + const calls: jest.Mock[] = []; + const logger = createLogger(); + const pending = createMockStub(() => { + const cancel = jest.fn(); + calls.push(cancel); + return { cancel } as unknown as grpc.ClientUnaryCall; }); + useStubs(pending.stub, pending.stub); + const worker = new TaskHubGrpcWorker({ logger }); - await expect(worker.start()).rejects.toThrow("while generating sidecar metadata"); - - expect(getWorkItems).not.toHaveBeenCalled(); - expect(close).toHaveBeenCalled(); - expect((worker as any)._isRunning).toBe(false); - }); - - it("rejects startup timeouts above the maximum Node.js timer delay", () => { - expect( - () => - new TaskHubGrpcWorker({ - logger: new NoOpLogger(), - startupTimeoutMs: 2147483648, - }), - ).toThrow(RangeError); - }); + await worker.start(); + await flushPromises(); - it("cleans up a failed handshake and permits a later start", async () => { - const stream = createMockStream(); - const close = jest.fn(); - let attempt = 0; - const hello = jest.fn((...args: any[]) => { - const callback = getHelloCallback(args); - attempt++; - if (attempt === 1) { - callback(new Error("handshake failed"), new Empty()); - } else { - callback(null, new Empty()); - } - return { cancel: jest.fn() } as any; - }); - const getWorkItems = jest.fn().mockReturnValue(stream); - useMockStub({ hello, getWorkItems, close } as unknown as stubs.TaskHubSidecarServiceClient); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const callOptions = pending.hello.mock.calls[0][2] as grpc.CallOptions; + expect(callOptions.deadline).toEqual(new Date("2026-01-01T00:00:30Z")); - await expect(worker.start()).rejects.toThrow("handshake failed"); + await jest.advanceTimersByTimeAsync(30000); + expect(calls[0]).toHaveBeenCalledTimes(1); + expect(logger.error).toHaveBeenCalled(); - expect(close).toHaveBeenCalledTimes(1); - expect((worker as any)._isRunning).toBe(false); - expect((worker as any)._stub).toBeNull(); + // Advance past any jittered first retry delay without assuming its exact value. + await jest.advanceTimersByTimeAsync(2000); + expect(pending.hello).toHaveBeenCalledTimes(2); - await expect(worker.start()).resolves.toBeUndefined(); - expect(getWorkItems).toHaveBeenCalledTimes(1); - expect((worker as any)._isRunning).toBe(true); + await worker.stop(); + expect(calls[1]).toHaveBeenCalledTimes(1); + expect(jest.getTimerCount()).toBe(0); }); - it("keeps restart blocked when stop claims a failing startup lifecycle", async () => { + it("logs initial client construction failures and retries until connected", async () => { jest.useFakeTimers(); - const first = createMockStub((...args: any[]) => { - getHelloCallback(args)(new Error("handshake failed"), new Empty()); - return { cancel: jest.fn() } as any; - }); - const second = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - jest - .spyOn(GrpcClient.prototype as any, "_generateClient") - .mockReturnValueOnce(first.stub) - .mockReturnValueOnce(second.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const awaitConnectionTasks = (worker as any)._awaitConnectionTasks.bind(worker); - let releaseStartupCleanup!: () => void; - const startupCleanupReleased = new Promise((resolve) => { - releaseStartupCleanup = resolve; - }); - let startupCleanupEntered!: () => void; - const startupCleanupStarted = new Promise((resolve) => { - startupCleanupEntered = resolve; - }); - jest.spyOn(worker as any, "_awaitConnectionTasks").mockImplementation(async (lifecycle: any) => { - if (!lifecycle.stopping) { - startupCleanupEntered(); - await startupCleanupReleased; - } - await awaitConnectionTasks(lifecycle); - }); - - const firstStart = worker.start(); - await startupCleanupStarted; - const stopPromise = worker.stop(); - await flushPromises(); - releaseStartupCleanup(); - await expect(firstStart).rejects.toThrow("handshake failed"); - - await expect(worker.start()).rejects.toThrow("The worker is already running."); - - await jest.advanceTimersByTimeAsync(1000); - await stopPromise; - await expect(worker.start()).resolves.toBeUndefined(); - expect(second.getWorkItems).toHaveBeenCalledTimes(1); - }); - - it("remains retryable after synchronous gRPC client construction fails", async () => { - const { stub, getWorkItems } = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - jest + const connected = successfulStub(); + const logger = createLogger(); + const generateClient = jest .spyOn(GrpcClient.prototype as any, "_generateClient") .mockImplementationOnce(() => { - throw new Error("client construction failed"); + throw new Error("first construction failure"); }) - .mockReturnValue(stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - - await expect(worker.start()).rejects.toThrow("client construction failed"); - expect((worker as any)._isRunning).toBe(false); + .mockImplementationOnce(() => { + throw new Error("second construction failure"); + }) + .mockReturnValueOnce(connected.stub); + const worker = new TaskHubGrpcWorker({ logger }); await expect(worker.start()).resolves.toBeUndefined(); - expect(getWorkItems).toHaveBeenCalledTimes(1); + await jest.advanceTimersByTimeAsync(4000); + + expect(generateClient).toHaveBeenCalledTimes(3); + expect(connected.getWorkItems).toHaveBeenCalledTimes(1); + expect(logger.error).toHaveBeenCalledTimes(2); + + await worker.stop(); }); - it("cancels an in-flight hello when stopped during startup", async () => { + it("aborts a pending reconnect delay and drains the loop on stop", async () => { jest.useFakeTimers(); - let completeHello: HelloCallback | undefined; - const cancel = jest.fn(() => { - queueMicrotask(() => completeHello!(new Error("1 CANCELLED"), new Empty())); - }); - const { stub, getWorkItems } = createMockStub((...args: any[]) => { - completeHello = getHelloCallback(args); - return { cancel } as any; + const unavailable = createMockStub((...args: any[]) => { + getHelloCallback(args)(new Error("sidecar unavailable") as grpc.ServiceError, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }); - useMockStub(stub); + useStubs(unavailable.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const startPromise = worker.start(); - const startRejection = expect(startPromise).rejects.toThrow( - "Worker startup was stopped before the connection was established.", - ); + await worker.start(); await flushPromises(); - expect(completeHello).toBeDefined(); - const stopPromise = worker.stop(); - await jest.runAllTimersAsync(); + expect(jest.getTimerCount()).toBeGreaterThan(0); + const loopPromise = (worker as any)._lifecycle.runPromise as Promise; - await startRejection; - await stopPromise; - expect(cancel).toHaveBeenCalled(); - expect(getWorkItems).not.toHaveBeenCalled(); - expect((worker as any)._isRunning).toBe(false); + await worker.stop(); + + await expect(loopPromise).resolves.toBeUndefined(); + expect(jest.getTimerCount()).toBe(0); + expect((worker as any)._lifecycle).toBeNull(); }); - it("ignores a late hello callback from a stopped startup attempt", async () => { - jest.useFakeTimers(); + it("rejects start during stop, allows restart, and ignores a late hello callback", async () => { let firstHello: HelloCallback | undefined; - let secondHello: HelloCallback | undefined; - const firstStream = createMockStream(); - const secondStream = createMockStream(); const first = createMockStub((...args: any[]) => { firstHello = getHelloCallback(args); - return { cancel: jest.fn() } as any; - }, firstStream); - const second = createMockStub((...args: any[]) => { - secondHello = getHelloCallback(args); - return { cancel: jest.fn() } as any; - }, secondStream); - jest - .spyOn(GrpcClient.prototype as any, "_generateClient") - .mockReturnValueOnce(first.stub) - .mockReturnValueOnce(second.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger(), startupTimeoutMs: 5000 }); - - const firstStart = worker.start(); - const firstStartRejection = expect(firstStart).rejects.toThrow(); - await flushPromises(); - expect(firstHello).toBeDefined(); - const stopPromise = worker.stop(); - await jest.advanceTimersByTimeAsync(1000); - await stopPromise; - - jest.useRealTimers(); - const secondStart = worker.start(); - await flushAsync(); - firstHello!(null, new Empty()); - await flushAsync(); - - expect(first.getWorkItems).not.toHaveBeenCalled(); - expect(second.getWorkItems).not.toHaveBeenCalled(); - - secondHello!(null, new Empty()); - await secondStart; - await firstStartRejection; - - expect(second.getWorkItems).toHaveBeenCalledTimes(1); - expect((worker as any)._responseStream).toBe(secondStream); - }); - - it("cancels a stopped lifecycle's reconnect backoff before restarting", async () => { - jest.useFakeTimers(); - jest.spyOn(Math, "random").mockReturnValue(1); - const first = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - const second = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }); - const generateClient = jest - .spyOn(GrpcClient.prototype as any, "_generateClient") - .mockReturnValueOnce(first.stub) - .mockReturnValueOnce(second.stub); + const restarted = successfulStub(); + useStubs(first.stub, restarted.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); await worker.start(); - first.stream.emit("error", new Error("14 UNAVAILABLE")); await flushPromises(); - const stopPromise = worker.stop(); - await jest.advanceTimersByTimeAsync(1000); - await stopPromise; - await worker.start(); - expect((worker as any)._backoff.currentDelayMs).toBe(1000); - - await jest.advanceTimersByTimeAsync(101); - - expect((worker as any)._backoff.currentDelayMs).toBe(1000); - expect(second.getWorkItems).toHaveBeenCalledTimes(1); - expect(generateClient).toHaveBeenCalledTimes(2); - }); - - it("adopts a direct internal run so it cannot race a later start", async () => { - jest.useFakeTimers(); - const direct = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - const restarted = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - const generateClient = jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(restarted.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const directClient = { stub: direct.stub } as unknown as GrpcClient; - - await worker.internalRunWorker(directClient); - - expect((worker as any)._isRunning).toBe(true); - expect((worker as any)._lifecycle).not.toBeNull(); - expect((worker as any)._stub).toBe(direct.stub); await expect(worker.start()).rejects.toThrow("The worker is already running."); - expect(generateClient).not.toHaveBeenCalled(); - - const stopPromise = worker.stop(); - await jest.runAllTimersAsync(); await stopPromise; - expect(direct.stream.cancel).toHaveBeenCalled(); - expect(direct.close).toHaveBeenCalled(); - expect((worker as any)._isRunning).toBe(false); - expect((worker as any)._lifecycle).toBeNull(); - await worker.start(); - direct.stream.emit("error", new Error("stale direct-run stream error")); + await flushPromises(); + firstHello!(null, new Empty()); await flushPromises(); - expect(generateClient).toHaveBeenCalledTimes(1); - expect((worker as any)._stub).toBe(restarted.stub); - expect((worker as any)._responseStream).toBe(restarted.stream); + expect(first.getWorkItems).not.toHaveBeenCalled(); + expect(restarted.getWorkItems).toHaveBeenCalledTimes(1); + expect((worker as any)._lifecycle.responseStream).toBe(restarted.stream); + + await worker.stop(); }); - it("continues reconnecting when a replacement client cannot be constructed", async () => { + it("recovers from runtime disconnect and replacement client construction failure", async () => { jest.useFakeTimers(); - const first = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - const recovered = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); + const first = successfulStub(); + const recovered = successfulStub(); + const logger = createLogger(); const generateClient = jest .spyOn(GrpcClient.prototype as any, "_generateClient") .mockReturnValueOnce(first.stub) .mockImplementationOnce(() => { - throw new Error("client construction failed"); + throw new Error("replacement construction failure"); }) .mockReturnValueOnce(recovered.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const worker = new TaskHubGrpcWorker({ logger }); await worker.start(); + await flushPromises(); first.stream.emit("error", new Error("14 UNAVAILABLE")); + await jest.advanceTimersByTimeAsync(4000); - await jest.runOnlyPendingTimersAsync(); - const trackedWhileRetryPending = (worker as any)._lifecycle.connectionTasks.size; - - await jest.runOnlyPendingTimersAsync(); - const recoveredStream = (worker as any)._responseStream; - const recoveredStub = (worker as any)._stub; - - const stopPromise = worker.stop(); - await jest.runAllTimersAsync(); - await stopPromise; - - expect(trackedWhileRetryPending).toBe(1); expect(generateClient).toHaveBeenCalledTimes(3); - expect(recovered.getWorkItems).toHaveBeenCalledTimes(1); - expect(recoveredStream).toBe(recovered.stream); - expect(recoveredStub).toBe(recovered.stub); expect(first.close).toHaveBeenCalledTimes(1); - expect(recovered.stream.cancel).toHaveBeenCalledTimes(1); - expect(recovered.close).toHaveBeenCalledTimes(1); - expect((worker as any)._isRunning).toBe(false); - expect((worker as any)._lifecycle).toBeNull(); + expect(recovered.getWorkItems).toHaveBeenCalledTimes(1); + expect(logger.error).toHaveBeenCalled(); + + await worker.stop(); }); - it("keeps stream recovery active after startup", async () => { - const { stub, stream } = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - useMockStub(stub); + it("gives direct internal runs lifecycle ownership and fences stopped streams", async () => { + const direct = successfulStub(); + const restarted = successfulStub(); + useStubs(restarted.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const retry = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retry; - - await worker.start(); - stream.emit("error", new Error("14 UNAVAILABLE")); - await flushAsync(); + const directClient = { stub: direct.stub } as unknown as GrpcClient; - expect(retry).toHaveBeenCalledTimes(1); - expect(stream.destroy).toHaveBeenCalled(); - }); + await worker.internalRunWorker(directClient); + await flushPromises(); - it("stops and cleans up a stream established by start", async () => { - const { stub, stream, close } = createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as any; - }); - useMockStub(stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + expect((worker as any)._lifecycle.stub).toBe(direct.stub); + await expect(worker.start()).rejects.toThrow("The worker is already running."); + await worker.stop(); await worker.start(); - jest.useFakeTimers(); - const stopPromise = worker.stop(); - await jest.runAllTimersAsync(); - await stopPromise; + await flushPromises(); + direct.stream.emit("error", new Error("stale stream error")); + await flushPromises(); - expect(stream.cancel).toHaveBeenCalled(); - expect(stream.destroy).toHaveBeenCalled(); - expect(close).toHaveBeenCalled(); - expect((worker as any)._isRunning).toBe(false); + expect((worker as any)._lifecycle.stub).toBe(restarted.stub); + expect((worker as any)._lifecycle.responseStream).toBe(restarted.stream); + + await worker.stop(); }); }); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index 61345903..2bfff10f 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -1,230 +1,114 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. -/** - * Tests that the TaskHubGrpcWorker correctly recovers when the gRPC work-item - * stream emits an "error" event without a subsequent "end" event. - * - * This validates the fix for a bug where the stream "error" handler only logged - * the error but did not clean up the stream or retry the connection — causing - * the worker to silently stop processing work items after transport-level - * failures (e.g., UNAVAILABLE, network disconnections). - */ - import { EventEmitter } from "events"; -import { TaskHubGrpcWorker } from "../src/worker/task-hub-grpc-worker"; -import { NoOpLogger } from "../src/types/logger.type"; +import * as grpc from "@grpc/grpc-js"; +import { Empty } from "google-protobuf/google/protobuf/empty_pb"; import { GrpcClient } from "../src/client/client-grpc"; +import * as stubs from "../src/proto/orchestrator_service_grpc_pb"; +import { NoOpLogger } from "../src/types/logger.type"; +import { TaskHubGrpcWorker } from "../src/worker/task-hub-grpc-worker"; + +type MockStream = EventEmitter & { + cancel: jest.Mock; + destroy: jest.Mock; +}; + +function createMockStream(): MockStream { + const stream = new EventEmitter() as MockStream; + stream.cancel = jest.fn(); + stream.destroy = jest.fn(); + return stream; +} -/** - * Creates a mock GrpcClient whose `hello` call succeeds immediately - * and whose `getWorkItems` returns a controllable EventEmitter stream. - */ -function createMockClient(): { +function createMockClient(stream: MockStream = createMockStream()): { client: GrpcClient; - mockStream: EventEmitter & { destroy: jest.Mock; cancel: jest.Mock }; + stream: MockStream; + stub: stubs.TaskHubSidecarServiceClient; + getWorkItems: jest.Mock; close: jest.Mock; } { - const mockStream = new EventEmitter() as EventEmitter & { - destroy: jest.Mock; - cancel: jest.Mock; - }; - mockStream.destroy = jest.fn(); - mockStream.cancel = jest.fn(); - + const getWorkItems = jest.fn().mockReturnValue(stream); const close = jest.fn(); const stub = { - hello: (_req: any, _metadata: any, _options: any, callback: (err: any, res: any) => void) => { - callback(null, {}); - return { cancel: jest.fn() } as any; + hello: ( + _request: Empty, + _metadata: grpc.Metadata, + _options: grpc.CallOptions, + callback: (error: grpc.ServiceError | null, response: Empty) => void, + ) => { + callback(null, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }, - getWorkItems: jest.fn().mockReturnValue(mockStream), + getWorkItems, close, - }; + } as unknown as stubs.TaskHubSidecarServiceClient; - const client = { stub } as unknown as GrpcClient; - return { client, mockStream, close }; + return { + client: { stub } as unknown as GrpcClient, + stream, + stub, + getWorkItems, + close, + }; } -/** Flush the microtask / next-tick queue so async event handlers complete. */ -function flushAsync(): Promise { - return new Promise((resolve) => setImmediate(resolve)); +async function flushPromises(): Promise { + for (let i = 0; i < 10; i++) { + await Promise.resolve(); + } } -describe("Worker Stream Recovery", () => { - it("should retry connection after a stream error event", async () => { - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - - // Prevent actual reconnection — just record that it was attempted - const retryMock = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retryMock; - - // Start the worker's internal run (sets up stream event handlers) - await worker.internalRunWorker(client); - - // Simulate a transport-level error with no subsequent "end" event - mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); - await flushAsync(); - - // The worker must clean up the stream and attempt to reconnect - expect(mockStream.destroy).toHaveBeenCalled(); - expect(retryMock).toHaveBeenCalledTimes(1); - }); - - it("should not retry when the worker is being stopped", async () => { - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - - const retryMock = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retryMock; - - await worker.internalRunWorker(client); - - // Signal that the worker is shutting down - (worker as any)._lifecycle.abortController.abort(); - - mockStream.emit("error", new Error("1 CANCELLED")); - await flushAsync(); - - // During shutdown, errors are silently ignored — no retry - expect(retryMock).not.toHaveBeenCalled(); - expect(mockStream.destroy).not.toHaveBeenCalled(); - }); - - it("should remove all stream listeners during error recovery", async () => { - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - - const retryMock = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retryMock; - - await worker.internalRunWorker(client); - - // Capture listener counts before error - const dataListenersBefore = mockStream.listenerCount("data"); - expect(dataListenersBefore).toBeGreaterThan(0); - - mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); - await flushAsync(); - - // After recovery, all original listeners should be removed - // (only a no-op error guard remains) - expect(mockStream.listenerCount("data")).toBe(0); - expect(mockStream.listenerCount("end")).toBe(0); - }); - - it("should not crash if a stale error event fires after recovery cleanup", async () => { - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - - const retryMock = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retryMock; - - await worker.internalRunWorker(client); - - // First error triggers recovery - mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); - await flushAsync(); - - // A stale/duplicate error event must not throw (no-op handler remains) - expect(() => { - mockStream.emit("error", new Error("Stale error after cleanup")); - }).not.toThrow(); - }); - - it("should recover via the end handler when end fires without error", async () => { - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - - const retryMock = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retryMock; - - await worker.internalRunWorker(client); - - // Simulate a clean stream end (no error) - mockStream.emit("end"); - await flushAsync(); - - // The "end" handler should also trigger recovery - expect(mockStream.destroy).toHaveBeenCalled(); - expect(retryMock).toHaveBeenCalledTimes(1); +describe("Worker stream recovery", () => { + beforeEach(() => { + jest.useFakeTimers(); }); - it("should only close the stub that owns a failed stream", async () => { - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream, close } = createMockClient(); - const replacementClose = jest.fn(); - - await worker.internalRunWorker(client); - (worker as any)._stub = { close: replacementClose }; - - try { - mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); - - expect(close).toHaveBeenCalledTimes(1); - expect(replacementClose).not.toHaveBeenCalled(); - } finally { - (worker as any)._lifecycle.abortController.abort(); - await flushAsync(); - } + afterEach(() => { + jest.useRealTimers(); + jest.restoreAllMocks(); }); - it("should not crash if _createNewClientAndRetry rejects during error recovery", async () => { + it("replaces a failed stream within the owned connection loop", async () => { + const initial = createMockClient(); + const replacement = createMockClient(); + jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(replacement.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - // Simulate a retry that throws — must not become an unhandled rejection - const retryMock = jest.fn().mockRejectedValue(new Error("Retry failed")); - (worker as any)._createNewClientAndRetry = retryMock; + await worker.internalRunWorker(initial.client); + await flushPromises(); + initial.stream.emit("error", new Error("14 UNAVAILABLE")); + expect(() => initial.stream.emit("error", new Error("duplicate error"))).not.toThrow(); + await flushPromises(); - await worker.internalRunWorker(client); + expect(initial.stream.destroy).toHaveBeenCalledTimes(1); + expect(initial.close).toHaveBeenCalledTimes(1); - // Should not throw or cause unhandled promise rejection - mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); - await flushAsync(); + await jest.advanceTimersByTimeAsync(2000); + await flushPromises(); - expect(retryMock).toHaveBeenCalledTimes(1); - expect(mockStream.destroy).toHaveBeenCalled(); - }); + expect(replacement.getWorkItems).toHaveBeenCalledTimes(1); + expect((worker as any)._lifecycle.responseStream).toBe(replacement.stream); - it("should not crash if _createNewClientAndRetry rejects during end recovery", async () => { - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - - // Simulate a retry that throws — must not become an unhandled rejection - const retryMock = jest.fn().mockRejectedValue(new Error("Retry failed")); - (worker as any)._createNewClientAndRetry = retryMock; - - await worker.internalRunWorker(client); - - // Should not throw or cause unhandled promise rejection - mockStream.emit("end"); - await flushAsync(); - - expect(retryMock).toHaveBeenCalledTimes(1); - expect(mockStream.destroy).toHaveBeenCalled(); + await worker.stop(); }); - it("should also add no-op error guard in end handler to prevent crashes after cleanup", async () => { + it("does not reconnect or react to stale stream errors after stop", async () => { + const initial = createMockClient(); + const generateClient = jest.spyOn(GrpcClient.prototype as any, "_generateClient"); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const { client, mockStream } = createMockClient(); - - const retryMock = jest.fn().mockResolvedValue(undefined); - (worker as any)._createNewClientAndRetry = retryMock; - - await worker.internalRunWorker(client); - // End fires → cleanup removes all listeners - mockStream.emit("end"); - await flushAsync(); + await worker.internalRunWorker(initial.client); + await flushPromises(); + await worker.stop(); - // A stale error after end cleanup must not crash - expect(() => { - mockStream.emit("error", new Error("Stale error after end cleanup")); - }).not.toThrow(); + expect(initial.stream.cancel).toHaveBeenCalledTimes(1); + expect(initial.stream.destroy).toHaveBeenCalledTimes(1); + expect(initial.close).toHaveBeenCalledTimes(1); + expect(generateClient).not.toHaveBeenCalled(); + expect(() => initial.stream.emit("error", new Error("stale error"))).not.toThrow(); - // The no-op guard should remain - expect(mockStream.listenerCount("error")).toBe(1); + await jest.advanceTimersByTimeAsync(30000); + expect(generateClient).not.toHaveBeenCalled(); }); }); diff --git a/test/e2e-azuremanaged/worker-stream-recovery.spec.ts b/test/e2e-azuremanaged/worker-stream-recovery.spec.ts index e8fac511..58cd4497 100644 --- a/test/e2e-azuremanaged/worker-stream-recovery.spec.ts +++ b/test/e2e-azuremanaged/worker-stream-recovery.spec.ts @@ -6,10 +6,9 @@ * * This test verifies the full recovery flow: * 1. Start a worker when the DTS emulator is NOT running - * 2. Verify initial startup fails within the configured timeout - * 3. Start the Docker emulator and start the worker successfully - * 4. Stop and restart the emulator - * 5. Verify the running worker reconnects and can process orchestrations + * 2. Verify the worker retries (via structured log capture) + * 3. Start the Docker emulator + * 4. Verify the worker reconnects and can process orchestrations * * Environment variables: * - ENDPOINT: The endpoint for the DTS emulator (default: localhost:8080) @@ -84,9 +83,10 @@ function stopEmulator(): void { } function startEmulator(): void { - execSync(`docker run --name ${EMULATOR_CONTAINER} -d --rm -p ${EMULATOR_PORT}:8080 ${EMULATOR_IMAGE}`, { - stdio: "ignore", - }); + execSync( + `docker run --name ${EMULATOR_CONTAINER} -d --rm -p ${EMULATOR_PORT}:8080 ${EMULATOR_IMAGE}`, + { stdio: "ignore" }, + ); } /** Poll until a condition is true or timeout. */ @@ -99,25 +99,10 @@ async function waitFor(predicate: () => boolean, timeoutMs: number, intervalMs = return predicate(); } -async function startWorkerWithRetry(worker: { start(): Promise }, timeoutMs: number): Promise { - const deadline = Date.now() + timeoutMs; - let lastError: unknown; - do { - try { - await worker.start(); - return; - } catch (error) { - lastError = error; - await new Promise((resolve) => setTimeout(resolve, 500)); - } - } while (Date.now() < deadline); - - throw lastError; -} - // Log event IDs from packages/durabletask-js/src/worker/logs.ts const EVENT_WORKER_CONNECTED = 700; const EVENT_STREAM_RETRY = 703; +const EVENT_CONNECTION_RETRY = 705; describe("Worker Stream Recovery E2E", () => { const skipReason = !isDockerAvailable() ? "Docker not available" : null; @@ -133,7 +118,7 @@ describe("Worker Stream Recovery E2E", () => { stopEmulator(); }); - it("should fail initial startup when the sidecar is down, then recover a post-start disconnection", async () => { + it("should retry when sidecar is down, then reconnect and complete an orchestration when sidecar starts", async () => { if (skipReason) { console.log(`Skipping stream recovery e2e test: ${skipReason}`); return; @@ -145,7 +130,6 @@ describe("Worker Stream Recovery E2E", () => { const worker = new DurableTaskAzureManagedWorkerBuilder() .endpoint(endpoint, taskHub, null) .logger(logger) - .startupTimeout(5000) .build(); const orchestrator: TOrchestrator = async function recoveryOrchestrator(_: OrchestrationContext) { @@ -153,29 +137,32 @@ describe("Worker Stream Recovery E2E", () => { }; worker.addOrchestrator(orchestrator); - await expect(worker.start()).rejects.toThrow(); - expect(logger.getByEventId(EVENT_WORKER_CONNECTED)).toHaveLength(0); + // start() should not throw even though the sidecar is unreachable + await worker.start(); - // ── Phase 2: Start the emulator and retry startup ─────────────────── - startEmulator(); - await startWorkerWithRetry(worker, 30000); - expect(logger.getByEventId(EVENT_WORKER_CONNECTED)).toHaveLength(1); - - // ── Phase 3: Disconnect the successfully started worker ───────────── - logger.clear(); - stopEmulator(); + // ── Phase 2: Verify retries are happening ─────────────────────────── + const sawRetries = await waitFor(() => { + const retryEvents = logger.getByEventId(EVENT_STREAM_RETRY); + const connRetryEvents = logger.getByEventId(EVENT_CONNECTION_RETRY); + return retryEvents.length + connRetryEvents.length >= 2; + }, 15000); - const sawRetry = await waitFor(() => logger.getByEventId(EVENT_STREAM_RETRY).length > 0, 15000); - expect(sawRetry).toBe(true); + expect(sawRetries).toBe(true); - // ── Phase 4: Restart the emulator and wait for reconnection ───────── + // ── Phase 3: Start the emulator ───────────────────────────────────── startEmulator(); - const sawConnected = await waitFor(() => logger.getByEventId(EVENT_WORKER_CONNECTED).length > 0, 30000); + + // ── Phase 4: Wait for the worker to reconnect ─────────────────────── + const sawConnected = await waitFor(() => { + return logger.getByEventId(EVENT_WORKER_CONNECTED).length > 0; + }, 30000); expect(sawConnected).toBe(true); - // ── Phase 5: Run an orchestration to prove recovery is functional ─── - const client = new DurableTaskAzureManagedClientBuilder().endpoint(endpoint, taskHub, null).build(); + // ── Phase 5: Run an orchestration to prove the worker is functional ─ + const client = new DurableTaskAzureManagedClientBuilder() + .endpoint(endpoint, taskHub, null) + .build(); const id = await client.scheduleNewOrchestration(orchestrator); const state = await client.waitForOrchestrationCompletion(id, undefined, 30); @@ -187,5 +174,5 @@ describe("Worker Stream Recovery E2E", () => { // ── Cleanup ───────────────────────────────────────────────────────── await worker.stop(); await client.stop(); - }, 120000); + }, 90000); }); From 4fff764845f88ea3d175316991186363e6758c83 Mon Sep 17 00:00:00 2001 From: wangbill Date: Thu, 13 Aug 2026 14:16:10 -0700 Subject: [PATCH 09/12] refactor(worker): simplify connection lifecycle Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b --- .../src/worker/task-hub-grpc-worker.ts | 239 ++++++++---------- .../test/worker-startup.spec.ts | 225 ++++++----------- .../test/worker-stream-recovery.spec.ts | 2 +- 3 files changed, 179 insertions(+), 287 deletions(-) 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 d39ba689..3e054c46 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -21,7 +21,6 @@ import { EntityFactory } from "../entities/task-entity"; import { StringValue } from "google-protobuf/google/protobuf/wrappers_pb"; import { Logger, ConsoleLogger } from "../types/logger.type"; import { ExponentialBackoff, withTimeout } from "../utils/backoff.util"; -import { TimeoutError } from "../exception/timeout-error"; import { VersioningOptions, VersionMatchStrategy, VersionFailureStrategy } from "./versioning-options"; import { WorkItemFilters, generateWorkItemFiltersFromRegistry, toGrpcWorkItemFilters } from "./work-item-filters"; import { compareVersions } from "../utils/versioning.util"; @@ -44,14 +43,6 @@ const DEFAULT_SHUTDOWN_TIMEOUT_MS = 30000; /** Timeout applied to each sidecar hello attempt. */ const HELLO_TIMEOUT_MS = 30000; -interface WorkerLifecycle { - readonly abortController: AbortController; - runPromise: Promise; - stub: stubs.TaskHubSidecarServiceClient | null; - helloCall: grpc.ClientUnaryCall | null; - responseStream: grpc.ClientReadableStream | null; -} - /** * Options for creating a TaskHubGrpcWorker. */ @@ -90,12 +81,17 @@ export class TaskHubGrpcWorker { private _grpcChannelCredentials?: grpc.ChannelCredentials; private _metadataGenerator?: MetadataGenerator; private _isRunning: boolean; + private _stub: stubs.TaskHubSidecarServiceClient | null; + private _responseStream: grpc.ClientReadableStream | null; private _logger: Logger; private _pendingWorkItems: Set>; private _shutdownTimeoutMs: number; + private _backoff: ExponentialBackoff; private _versioning?: VersioningOptions; private _workItemFilters?: WorkItemFilters | "auto"; - private _lifecycle: WorkerLifecycle | null; + private _abortController: AbortController | null; + private _runPromise: Promise | null; + private _helloCall: grpc.ClientUnaryCall | null; /** * Creates a new TaskHubGrpcWorker instance. @@ -174,12 +170,21 @@ export class TaskHubGrpcWorker { this._grpcChannelCredentials = resolvedCredentials; this._metadataGenerator = resolvedMetadataGenerator; this._isRunning = false; + this._stub = null; + this._responseStream = null; this._logger = resolvedLogger ?? new ConsoleLogger(); this._pendingWorkItems = new Set(); this._shutdownTimeoutMs = resolvedShutdownTimeoutMs ?? DEFAULT_SHUTDOWN_TIMEOUT_MS; + this._backoff = new ExponentialBackoff({ + initialDelayMs: 1000, + maxDelayMs: 30000, + multiplier: 2, + }); this._versioning = resolvedVersioning; this._workItemFilters = resolvedWorkItemFilters; - this._lifecycle = null; + this._abortController = null; + this._runPromise = null; + this._helloCall = null; } /** @@ -368,33 +373,22 @@ export class TaskHubGrpcWorker { } private _startConnectionLoop(initialClient?: GrpcClient): void { - if (this._isRunning || this._lifecycle) { + if (this._isRunning) { throw new Error("The worker is already running."); } - const lifecycle: WorkerLifecycle = { - abortController: new AbortController(), - runPromise: Promise.resolve(), - stub: null, - helloCall: null, - responseStream: null, - }; this._isRunning = true; - this._lifecycle = lifecycle; - lifecycle.runPromise = this._runConnectionLoop(lifecycle, initialClient).catch((err) => { - if (!lifecycle.abortController.signal.aborted) { + this._abortController = new AbortController(); + this._backoff.reset(); + const signal = this._abortController.signal; + this._runPromise = this._runConnectionLoop(signal, initialClient).catch((err) => { + if (!signal.aborted) { WorkerLogs.workerError(this._logger, err instanceof Error ? err : new Error(String(err))); } }); } - private async _runConnectionLoop(lifecycle: WorkerLifecycle, initialClient?: GrpcClient): Promise { - const signal = lifecycle.abortController.signal; - const backoff = new ExponentialBackoff({ - initialDelayMs: 1000, - maxDelayMs: 30000, - multiplier: 2, - }); + private async _runConnectionLoop(signal: AbortSignal, initialClient?: GrpcClient): Promise { let nextClient = initialClient; while (!signal.aborted) { @@ -406,22 +400,58 @@ export class TaskHubGrpcWorker { nextClient ?? new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); nextClient = undefined; - stub = client.stub; - lifecycle.stub = stub; + const activeStub = client.stub; + stub = activeStub; + this._stub = activeStub; - const helloMetadata = await this._waitForAbortable(this._getMetadata(), lifecycle); - await this._waitForHello(stub, helloMetadata, lifecycle); + const helloMetadata = await this._getMetadata(); + if (signal.aborted) { + break; + } + await this._waitForHello(activeStub, helloMetadata, signal); - const metadata = await this._waitForAbortable(this._getMetadata(), lifecycle); + const metadata = await this._getMetadata(); + if (signal.aborted) { + break; + } const request = this._buildGetWorkItemsRequest(); - stream = stub.getWorkItems(request, metadata); - lifecycle.responseStream = stream; - this._listenForWorkItems(stream, stub); + stream = activeStub.getWorkItems(request, metadata); + this._responseStream = stream; + + stream.on("data", (workItem: pb.WorkItem) => { + if (signal.aborted) { + return; + } + const completionToken = workItem.getCompletiontoken(); + if (workItem.hasOrchestratorrequest()) { + WorkerLogs.workItemReceived( + this._logger, + "Orchestrator Request", + workItem?.getOrchestratorrequest()?.getInstanceid(), + ); + this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, activeStub); + } else if (workItem.hasActivityrequest()) { + WorkerLogs.workItemReceived(this._logger, "Activity Request"); + this._executeActivity(workItem.getActivityrequest() as any, completionToken, activeStub); + } else if (workItem.hasEntityrequest()) { + const entityRequest = workItem.getEntityrequest() as pb.EntityBatchRequest; + WorkerLogs.entityRequestReceived(this._logger, entityRequest.getInstanceid(), "Entity Request"); + this._executeEntity(entityRequest, completionToken, activeStub); + } else if (workItem.hasEntityrequestv2()) { + const entityRequestV2 = workItem.getEntityrequestv2() as pb.EntityRequest; + WorkerLogs.entityRequestReceived(this._logger, entityRequestV2.getInstanceid(), "Entity Request V2"); + this._executeEntityV2(entityRequestV2, completionToken, activeStub); + } else if (workItem.hasHealthping()) { + // Health ping - no-op, just a keep-alive message from the server + } else { + WorkerLogs.unknownWorkItem(this._logger); + } + }); - backoff.reset(); + this._backoff.reset(); WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); - const streamError = await this._waitForStreamEnd(stream, lifecycle); + const streamError = await this._waitForStreamEnd(stream, signal); if (signal.aborted) { WorkerLogs.streamEnded(this._logger); break; @@ -429,22 +459,22 @@ export class TaskHubGrpcWorker { if (streamError) { WorkerLogs.streamErrorInfo(this._logger, streamError); } - WorkerLogs.streamRetry(this._logger, backoff.peekNextDelay()); + WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); } catch (err) { if (signal.aborted) { break; } const error = err instanceof Error ? err : new Error(String(err)); WorkerLogs.streamError(this._logger, error); - WorkerLogs.connectionRetry(this._logger, backoff.peekNextDelay()); + WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); } finally { if (stream) { - this._disposeResponseStream(stream, lifecycle); + this._disposeResponseStream(stream); } if (stub && !signal.aborted) { stub.close(); - if (lifecycle.stub === stub) { - lifecycle.stub = null; + if (this._stub === stub) { + this._stub = null; } } } @@ -454,7 +484,7 @@ export class TaskHubGrpcWorker { } try { - await backoff.wait(signal); + await this._backoff.wait(signal); } catch (err) { if (!signal.aborted) { throw err; @@ -463,50 +493,16 @@ export class TaskHubGrpcWorker { } } - private _listenForWorkItems( - stream: grpc.ClientReadableStream, - stub: stubs.TaskHubSidecarServiceClient, - ): void { - stream.on("data", (workItem: pb.WorkItem) => { - const completionToken = workItem.getCompletiontoken(); - if (workItem.hasOrchestratorrequest()) { - WorkerLogs.workItemReceived( - this._logger, - "Orchestrator Request", - workItem?.getOrchestratorrequest()?.getInstanceid(), - ); - this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, stub); - } else if (workItem.hasActivityrequest()) { - WorkerLogs.workItemReceived(this._logger, "Activity Request"); - this._executeActivity(workItem.getActivityrequest() as any, completionToken, stub); - } else if (workItem.hasEntityrequest()) { - const entityRequest = workItem.getEntityrequest() as pb.EntityBatchRequest; - WorkerLogs.entityRequestReceived(this._logger, entityRequest.getInstanceid(), "Entity Request"); - this._executeEntity(entityRequest, completionToken, stub); - } else if (workItem.hasEntityrequestv2()) { - const entityRequestV2 = workItem.getEntityrequestv2() as pb.EntityRequest; - WorkerLogs.entityRequestReceived(this._logger, entityRequestV2.getInstanceid(), "Entity Request V2"); - this._executeEntityV2(entityRequestV2, completionToken, stub); - } else if (workItem.hasHealthping()) { - // Health ping - no-op, just a keep-alive message from the server - } else { - WorkerLogs.unknownWorkItem(this._logger); - } - }); - } - private async _waitForHello( stub: stubs.TaskHubSidecarServiceClient, metadata: grpc.Metadata, - lifecycle: WorkerLifecycle, + signal: AbortSignal, ): Promise { - const signal = lifecycle.abortController.signal; if (signal.aborted) { - throw this._getLifecycleAbortError(lifecycle); + throw this._getAbortError(signal); } let call: grpc.ClientUnaryCall | undefined; - let timeoutId: ReturnType | undefined; let removeAbortListener: (() => void) | undefined; try { @@ -517,9 +513,6 @@ export class TaskHubGrpcWorker { return; } settled = true; - if (timeoutId !== undefined) { - clearTimeout(timeoutId); - } removeAbortListener?.(); if (error) { reject(error); @@ -527,59 +520,31 @@ export class TaskHubGrpcWorker { resolve(); } }; - const onAbort = () => finish(this._getLifecycleAbortError(lifecycle)); + const onAbort = () => finish(this._getAbortError(signal)); removeAbortListener = () => signal.removeEventListener("abort", onAbort); signal.addEventListener("abort", onAbort, { once: true }); - timeoutId = setTimeout(() => { - finish(new TimeoutError(`Sidecar hello did not respond within ${HELLO_TIMEOUT_MS}ms.`)); - call?.cancel(); - }, HELLO_TIMEOUT_MS); - try { call = stub.hello(new Empty(), metadata, { deadline: new Date(Date.now() + HELLO_TIMEOUT_MS) }, (error) => finish(error ?? undefined), ); - lifecycle.helloCall = call; + this._helloCall = call; } catch (err) { finish(err instanceof Error ? err : new Error(String(err))); } }); } finally { - if (timeoutId !== undefined) { - clearTimeout(timeoutId); - } removeAbortListener?.(); - if (lifecycle.helloCall === call) { - lifecycle.helloCall = null; + if (this._helloCall === call) { + this._helloCall = null; } } } - private async _waitForAbortable(promise: Promise, lifecycle: WorkerLifecycle): Promise { - const signal = lifecycle.abortController.signal; - if (signal.aborted) { - throw this._getLifecycleAbortError(lifecycle); - } - - let onAbort!: () => void; - const aborted = new Promise((_, reject) => { - onAbort = () => reject(this._getLifecycleAbortError(lifecycle)); - signal.addEventListener("abort", onAbort, { once: true }); - }); - - try { - return await Promise.race([promise, aborted]); - } finally { - signal.removeEventListener("abort", onAbort); - } - } - private _waitForStreamEnd( stream: grpc.ClientReadableStream, - lifecycle: WorkerLifecycle, + signal: AbortSignal, ): Promise { - const signal = lifecycle.abortController.signal; if (signal.aborted) { return Promise.resolve(undefined); } @@ -603,17 +568,17 @@ export class TaskHubGrpcWorker { }); } - private _getLifecycleAbortError(lifecycle: WorkerLifecycle): Error { - const reason = lifecycle.abortController.signal.reason; + private _getAbortError(signal: AbortSignal): Error { + const reason = signal.reason; return reason instanceof Error ? reason : new Error("The worker was stopped."); } - private _disposeResponseStream(stream: grpc.ClientReadableStream, lifecycle: WorkerLifecycle): void { + private _disposeResponseStream(stream: grpc.ClientReadableStream): void { stream.removeAllListeners(); stream.on("error", () => {}); stream.destroy(); - if (lifecycle.responseStream === stream) { - lifecycle.responseStream = null; + if (this._responseStream === stream) { + this._responseStream = null; } } @@ -622,15 +587,16 @@ export class TaskHubGrpcWorker { * Uses a configurable timeout (default 30s) to wait for in-flight work. */ async stop(): Promise { - const lifecycle = this._lifecycle; - if (!this._isRunning || !lifecycle) { + const abortController = this._abortController; + const runPromise = this._runPromise; + if (!this._isRunning || !abortController || !runPromise || abortController.signal.aborted) { throw new Error("The worker is not running."); } - lifecycle.abortController.abort(new Error("The worker was stopped.")); - lifecycle.helloCall?.cancel(); - lifecycle.responseStream?.cancel(); - await lifecycle.runPromise; + abortController.abort(new Error("The worker was stopped.")); + this._helloCall?.cancel(); + this._responseStream?.cancel(); + await runPromise; // Wait for pending work items to complete with timeout if (this._pendingWorkItems.size > 0) { @@ -648,16 +614,13 @@ export class TaskHubGrpcWorker { } } - if (lifecycle.stub) { - // Close the gRPC client - this is a synchronous operation - lifecycle.stub.close(); - lifecycle.stub = null; - } - - if (this._lifecycle === lifecycle) { - this._lifecycle = null; - this._isRunning = false; - } + this._stub?.close(); + this._abortController = null; + this._runPromise = null; + this._helloCall = null; + this._responseStream = null; + this._stub = null; + this._isRunning = false; } /** diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index 0c74da41..bffa70dc 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -9,67 +9,46 @@ import * as stubs from "../src/proto/orchestrator_service_grpc_pb"; import { Logger, NoOpLogger } from "../src/types/logger.type"; import { TaskHubGrpcWorker } from "../src/worker/task-hub-grpc-worker"; -type MockStream = EventEmitter & { - cancel: jest.Mock; - destroy: jest.Mock; -}; - +type MockStream = EventEmitter & { cancel: jest.Mock; destroy: jest.Mock }; type HelloCallback = (error: grpc.ServiceError | null, response: Empty) => void; -function createMockStream(): MockStream { +function createStream(): MockStream { const stream = new EventEmitter() as MockStream; stream.cancel = jest.fn(); stream.destroy = jest.fn(); return stream; } -function createMockStub( - hello: (...args: any[]) => grpc.ClientUnaryCall, - stream: MockStream = createMockStream(), -): { - stub: stubs.TaskHubSidecarServiceClient; - stream: MockStream; - hello: jest.Mock; - getWorkItems: jest.Mock; - close: jest.Mock; -} { - const helloMock = jest.fn(hello); - const getWorkItems = jest.fn().mockReturnValue(stream); - const close = jest.fn(); +function createStub(hello: (...args: any[]) => grpc.ClientUnaryCall, stream = createStream()) { const stub = { - hello: helloMock, - getWorkItems, - close, + hello: jest.fn(hello), + getWorkItems: jest.fn().mockReturnValue(stream), + close: jest.fn(), } as unknown as stubs.TaskHubSidecarServiceClient; - return { stub, stream, hello: helloMock, getWorkItems, close }; + return { stub, stream }; } -function successfulStub(stream = createMockStream()) { - return createMockStub((...args: any[]) => { +function successfulStub() { + return createStub((...args: any[]) => { getHelloCallback(args)(null, new Empty()); return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; - }, stream); + }); } function getHelloCallback(args: any[]): HelloCallback { return args[args.length - 1] as HelloCallback; } -function useStubs(...stubSequence: stubs.TaskHubSidecarServiceClient[]): jest.SpyInstance { +function useStubs(...stubsToUse: stubs.TaskHubSidecarServiceClient[]): jest.SpyInstance { const generateClient = jest.spyOn(GrpcClient.prototype as any, "_generateClient"); - for (const stub of stubSequence) { + for (const stub of stubsToUse) { generateClient.mockReturnValueOnce(stub); } return generateClient; } function createLogger(): Logger & { error: jest.Mock } { - return { - error: jest.fn(), - warn: jest.fn(), - info: jest.fn(), - debug: jest.fn(), - }; + return { error: jest.fn(), warn: jest.fn(), info: jest.fn(), debug: jest.fn() }; } async function flushPromises(): Promise { @@ -84,108 +63,60 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { jest.restoreAllMocks(); }); - it("starts promptly while hello is unavailable and cancels hello on stop", async () => { - const cancel = jest.fn(); - const pending = createMockStub(() => ({ cancel }) as unknown as grpc.ClientUnaryCall); - useStubs(pending.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - - await expect(worker.start()).resolves.toBeUndefined(); - await flushPromises(); - - expect(pending.hello).toHaveBeenCalledTimes(1); - expect(pending.getWorkItems).not.toHaveBeenCalled(); - - await worker.stop(); - - expect(cancel).toHaveBeenCalledTimes(1); - expect((worker as any)._lifecycle).toBeNull(); - expect((worker as any)._isRunning).toBe(false); - }); - - it("times out each hung hello attempt and retries inside the owned loop", async () => { + it("starts promptly, gives each hello a 30-second deadline, and retries errors", async () => { jest.useFakeTimers(); jest.setSystemTime(new Date("2026-01-01T00:00:00Z")); - const calls: jest.Mock[] = []; - const logger = createLogger(); - const pending = createMockStub(() => { - const cancel = jest.fn(); - calls.push(cancel); - return { cancel } as unknown as grpc.ClientUnaryCall; + const deadlineError = Object.assign(new Error("deadline exceeded"), { + code: grpc.status.DEADLINE_EXCEEDED, + }) as grpc.ServiceError; + const first = createStub((...args: any[]) => { + getHelloCallback(args)(deadlineError, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }); - useStubs(pending.stub, pending.stub); - const worker = new TaskHubGrpcWorker({ logger }); + const connected = successfulStub(); + useStubs(first.stub, connected.stub); + const worker = new TaskHubGrpcWorker({ logger: createLogger() }); - await worker.start(); + await expect(worker.start()).resolves.toBeUndefined(); await flushPromises(); - const callOptions = pending.hello.mock.calls[0][2] as grpc.CallOptions; - expect(callOptions.deadline).toEqual(new Date("2026-01-01T00:00:30Z")); - - await jest.advanceTimersByTimeAsync(30000); - expect(calls[0]).toHaveBeenCalledTimes(1); - expect(logger.error).toHaveBeenCalled(); + expect((first.stub.hello as jest.Mock).mock.calls[0][2].deadline).toEqual(new Date("2026-01-01T00:00:30Z")); + expect(connected.stub.getWorkItems).not.toHaveBeenCalled(); - // Advance past any jittered first retry delay without assuming its exact value. await jest.advanceTimersByTimeAsync(2000); - expect(pending.hello).toHaveBeenCalledTimes(2); + expect(connected.stub.getWorkItems).toHaveBeenCalledTimes(1); await worker.stop(); - expect(calls[1]).toHaveBeenCalledTimes(1); - expect(jest.getTimerCount()).toBe(0); }); - it("logs initial client construction failures and retries until connected", async () => { + it("retries synchronous client construction failures", async () => { jest.useFakeTimers(); const connected = successfulStub(); - const logger = createLogger(); const generateClient = jest .spyOn(GrpcClient.prototype as any, "_generateClient") .mockImplementationOnce(() => { - throw new Error("first construction failure"); - }) - .mockImplementationOnce(() => { - throw new Error("second construction failure"); + throw new Error("client construction failed"); }) .mockReturnValueOnce(connected.stub); + const logger = createLogger(); const worker = new TaskHubGrpcWorker({ logger }); - await expect(worker.start()).resolves.toBeUndefined(); - await jest.advanceTimersByTimeAsync(4000); - - expect(generateClient).toHaveBeenCalledTimes(3); - expect(connected.getWorkItems).toHaveBeenCalledTimes(1); - expect(logger.error).toHaveBeenCalledTimes(2); - - await worker.stop(); - }); - - it("aborts a pending reconnect delay and drains the loop on stop", async () => { - jest.useFakeTimers(); - const unavailable = createMockStub((...args: any[]) => { - getHelloCallback(args)(new Error("sidecar unavailable") as grpc.ServiceError, new Empty()); - return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; - }); - useStubs(unavailable.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - await worker.start(); - await flushPromises(); - expect(jest.getTimerCount()).toBeGreaterThan(0); - const loopPromise = (worker as any)._lifecycle.runPromise as Promise; + await jest.advanceTimersByTimeAsync(2000); - await worker.stop(); + expect(generateClient).toHaveBeenCalledTimes(2); + expect(logger.error).toHaveBeenCalledWith(expect.stringContaining("client construction failed")); + expect(connected.stub.getWorkItems).toHaveBeenCalledTimes(1); - await expect(loopPromise).resolves.toBeUndefined(); - expect(jest.getTimerCount()).toBe(0); - expect((worker as any)._lifecycle).toBeNull(); + await worker.stop(); }); - it("rejects start during stop, allows restart, and ignores a late hello callback", async () => { - let firstHello: HelloCallback | undefined; - const first = createMockStub((...args: any[]) => { - firstHello = getHelloCallback(args); - return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; + it("cancels hello, drains the loop, and fences its late callback before restart", async () => { + let staleHello: HelloCallback | undefined; + const cancel = jest.fn(); + const first = createStub((...args: any[]) => { + staleHello = getHelloCallback(args); + return { cancel } as unknown as grpc.ClientUnaryCall; }); const restarted = successfulStub(); useStubs(first.stub, restarted.stub); @@ -193,72 +124,70 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { await worker.start(); await flushPromises(); + const runPromise = (worker as any)._runPromise as Promise; const stopPromise = worker.stop(); await expect(worker.start()).rejects.toThrow("The worker is already running."); await stopPromise; + await expect(runPromise).resolves.toBeUndefined(); + expect(cancel).toHaveBeenCalledTimes(1); await worker.start(); await flushPromises(); - firstHello!(null, new Empty()); + staleHello!(null, new Empty()); await flushPromises(); - expect(first.getWorkItems).not.toHaveBeenCalled(); - expect(restarted.getWorkItems).toHaveBeenCalledTimes(1); - expect((worker as any)._lifecycle.responseStream).toBe(restarted.stream); + expect(first.stub.getWorkItems).not.toHaveBeenCalled(); + expect(restarted.stub.getWorkItems).toHaveBeenCalledTimes(1); + expect((worker as any)._responseStream).toBe(restarted.stream); await worker.stop(); }); - it("recovers from runtime disconnect and replacement client construction failure", async () => { + it("cancels reconnect backoff and permits restart after stop", async () => { jest.useFakeTimers(); - const first = successfulStub(); - const recovered = successfulStub(); - const logger = createLogger(); - const generateClient = jest - .spyOn(GrpcClient.prototype as any, "_generateClient") - .mockReturnValueOnce(first.stub) - .mockImplementationOnce(() => { - throw new Error("replacement construction failure"); - }) - .mockReturnValueOnce(recovered.stub); - const worker = new TaskHubGrpcWorker({ logger }); + const unavailable = createStub((...args: any[]) => { + getHelloCallback(args)(new Error("unavailable") as grpc.ServiceError, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; + }); + const restarted = successfulStub(); + useStubs(unavailable.stub, restarted.stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); await worker.start(); await flushPromises(); - first.stream.emit("error", new Error("14 UNAVAILABLE")); - await jest.advanceTimersByTimeAsync(4000); + expect(jest.getTimerCount()).toBeGreaterThan(0); + + await worker.stop(); + expect(jest.getTimerCount()).toBe(0); - expect(generateClient).toHaveBeenCalledTimes(3); - expect(first.close).toHaveBeenCalledTimes(1); - expect(recovered.getWorkItems).toHaveBeenCalledTimes(1); - expect(logger.error).toHaveBeenCalled(); + await worker.start(); + await flushPromises(); + expect(restarted.stub.getWorkItems).toHaveBeenCalledTimes(1); await worker.stop(); }); - it("gives direct internal runs lifecycle ownership and fences stopped streams", async () => { + it("keeps direct internal runs owned by stop", async () => { const direct = successfulStub(); - const restarted = successfulStub(); - useStubs(restarted.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const directClient = { stub: direct.stub } as unknown as GrpcClient; - - await worker.internalRunWorker(directClient); - await flushPromises(); - - expect((worker as any)._lifecycle.stub).toBe(direct.stub); - await expect(worker.start()).rejects.toThrow("The worker is already running."); + let finishWorkItem!: () => void; + const pendingWorkItem = new Promise((resolve) => { + finishWorkItem = resolve; + }); - await worker.stop(); - await worker.start(); + await worker.internalRunWorker({ stub: direct.stub } as unknown as GrpcClient); await flushPromises(); - direct.stream.emit("error", new Error("stale stream error")); + (worker as any)._pendingWorkItems.add(pendingWorkItem); + const stopPromise = worker.stop(); await flushPromises(); - expect((worker as any)._lifecycle.stub).toBe(restarted.stub); - expect((worker as any)._lifecycle.responseStream).toBe(restarted.stream); + await expect(worker.start()).rejects.toThrow("The worker is already running."); + expect(direct.stub.close).not.toHaveBeenCalled(); + finishWorkItem(); + await stopPromise; - await worker.stop(); + expect(direct.stream.cancel).toHaveBeenCalledTimes(1); + expect(direct.stub.close).toHaveBeenCalledTimes(1); }); }); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index 2bfff10f..1346b14c 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -88,7 +88,7 @@ describe("Worker stream recovery", () => { await flushPromises(); expect(replacement.getWorkItems).toHaveBeenCalledTimes(1); - expect((worker as any)._lifecycle.responseStream).toBe(replacement.stream); + expect((worker as any)._responseStream).toBe(replacement.stream); await worker.stop(); }); From f4c0d230762590af80e11756928271dfedf567b9 Mon Sep 17 00:00:00 2001 From: wangbill Date: Thu, 13 Aug 2026 14:22:05 -0700 Subject: [PATCH 10/12] refactor(worker): simplify connection lifecycle Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b --- .../src/worker/task-hub-grpc-worker.ts | 167 +++++++----------- .../test/worker-startup.spec.ts | 146 +++++++-------- .../test/worker-stream-recovery.spec.ts | 4 +- 3 files changed, 133 insertions(+), 184 deletions(-) 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 3e054c46..559af275 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -74,6 +74,7 @@ export interface TaskHubGrpcWorkerOptions { } export class TaskHubGrpcWorker { + private _responseStream: grpc.ClientReadableStream | null; private _registry: Registry; private _hostAddress?: string; private _tls?: boolean; @@ -82,7 +83,6 @@ export class TaskHubGrpcWorker { private _metadataGenerator?: MetadataGenerator; private _isRunning: boolean; private _stub: stubs.TaskHubSidecarServiceClient | null; - private _responseStream: grpc.ClientReadableStream | null; private _logger: Logger; private _pendingWorkItems: Set>; private _shutdownTimeoutMs: number; @@ -169,9 +169,9 @@ export class TaskHubGrpcWorker { this._grpcChannelOptions = resolvedOptions; this._grpcChannelCredentials = resolvedCredentials; this._metadataGenerator = resolvedMetadataGenerator; + this._responseStream = null; this._isRunning = false; this._stub = null; - this._responseStream = null; this._logger = resolvedLogger ?? new ConsoleLogger(); this._pendingWorkItems = new Set(); this._shutdownTimeoutMs = resolvedShutdownTimeoutMs ?? DEFAULT_SHUTDOWN_TIMEOUT_MS; @@ -377,12 +377,12 @@ export class TaskHubGrpcWorker { throw new Error("The worker is already running."); } + const abortController = new AbortController(); + this._abortController = abortController; this._isRunning = true; - this._abortController = new AbortController(); this._backoff.reset(); - const signal = this._abortController.signal; - this._runPromise = this._runConnectionLoop(signal, initialClient).catch((err) => { - if (!signal.aborted) { + this._runPromise = this._runConnectionLoop(abortController.signal, initialClient).catch((err) => { + if (!abortController.signal.aborted) { WorkerLogs.workerError(this._logger, err instanceof Error ? err : new Error(String(err))); } }); @@ -400,28 +400,22 @@ export class TaskHubGrpcWorker { nextClient ?? new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); nextClient = undefined; - const activeStub = client.stub; - stub = activeStub; - this._stub = activeStub; + stub = client.stub; + this._stub = stub; const helloMetadata = await this._getMetadata(); - if (signal.aborted) { - break; - } - await this._waitForHello(activeStub, helloMetadata, signal); + await this._waitForHello(stub, helloMetadata, signal); const metadata = await this._getMetadata(); if (signal.aborted) { break; } const request = this._buildGetWorkItemsRequest(); - stream = activeStub.getWorkItems(request, metadata); + stream = stub.getWorkItems(request, metadata); this._responseStream = stream; + // Wait for a work item to be received stream.on("data", (workItem: pb.WorkItem) => { - if (signal.aborted) { - return; - } const completionToken = workItem.getCompletiontoken(); if (workItem.hasOrchestratorrequest()) { WorkerLogs.workItemReceived( @@ -429,18 +423,18 @@ export class TaskHubGrpcWorker { "Orchestrator Request", workItem?.getOrchestratorrequest()?.getInstanceid(), ); - this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, activeStub); + this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, client.stub); } else if (workItem.hasActivityrequest()) { WorkerLogs.workItemReceived(this._logger, "Activity Request"); - this._executeActivity(workItem.getActivityrequest() as any, completionToken, activeStub); + this._executeActivity(workItem.getActivityrequest() as any, completionToken, client.stub); } else if (workItem.hasEntityrequest()) { const entityRequest = workItem.getEntityrequest() as pb.EntityBatchRequest; WorkerLogs.entityRequestReceived(this._logger, entityRequest.getInstanceid(), "Entity Request"); - this._executeEntity(entityRequest, completionToken, activeStub); + this._executeEntity(entityRequest, completionToken, client.stub); } else if (workItem.hasEntityrequestv2()) { const entityRequestV2 = workItem.getEntityrequestv2() as pb.EntityRequest; WorkerLogs.entityRequestReceived(this._logger, entityRequestV2.getInstanceid(), "Entity Request V2"); - this._executeEntityV2(entityRequestV2, completionToken, activeStub); + this._executeEntityV2(entityRequestV2, completionToken, client.stub); } else if (workItem.hasHealthping()) { // Health ping - no-op, just a keep-alive message from the server } else { @@ -451,7 +445,14 @@ export class TaskHubGrpcWorker { this._backoff.reset(); WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); - const streamError = await this._waitForStreamEnd(stream, signal); + let onAbort!: () => void; + const streamError = await new Promise((resolve) => { + onAbort = () => resolve(undefined); + signal.addEventListener("abort", onAbort, { once: true }); + stream!.once("end", () => resolve(undefined)); + // Keep handling duplicate errors until the loop disposes the stream. + stream!.on("error", resolve); + }).finally(() => signal.removeEventListener("abort", onAbort)); if (signal.aborted) { WorkerLogs.streamEnded(this._logger); break; @@ -469,9 +470,14 @@ export class TaskHubGrpcWorker { WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); } finally { if (stream) { - this._disposeResponseStream(stream); + stream.removeAllListeners(); + stream.on("error", () => {}); + stream.destroy(); + if (this._responseStream === stream) { + this._responseStream = null; + } } - if (stub && !signal.aborted) { + if (stub) { stub.close(); if (this._stub === stub) { this._stub = null; @@ -499,57 +505,11 @@ export class TaskHubGrpcWorker { signal: AbortSignal, ): Promise { if (signal.aborted) { - throw this._getAbortError(signal); + throw signal.reason; } - let call: grpc.ClientUnaryCall | undefined; - let removeAbortListener: (() => void) | undefined; - - try { - await new Promise((resolve, reject) => { - let settled = false; - const finish = (error?: Error) => { - if (settled) { - return; - } - settled = true; - removeAbortListener?.(); - if (error) { - reject(error); - } else { - resolve(); - } - }; - const onAbort = () => finish(this._getAbortError(signal)); - removeAbortListener = () => signal.removeEventListener("abort", onAbort); - signal.addEventListener("abort", onAbort, { once: true }); - - try { - call = stub.hello(new Empty(), metadata, { deadline: new Date(Date.now() + HELLO_TIMEOUT_MS) }, (error) => - finish(error ?? undefined), - ); - this._helloCall = call; - } catch (err) { - finish(err instanceof Error ? err : new Error(String(err))); - } - }); - } finally { - removeAbortListener?.(); - if (this._helloCall === call) { - this._helloCall = null; - } - } - } - - private _waitForStreamEnd( - stream: grpc.ClientReadableStream, - signal: AbortSignal, - ): Promise { - if (signal.aborted) { - return Promise.resolve(undefined); - } - - return new Promise((resolve) => { + await new Promise((resolve, reject) => { + let call: grpc.ClientUnaryCall | undefined; let settled = false; const finish = (error?: Error) => { if (settled) { @@ -557,29 +517,30 @@ export class TaskHubGrpcWorker { } settled = true; signal.removeEventListener("abort", onAbort); - resolve(error); + if (this._helloCall === call) { + this._helloCall = null; + } + if (error) { + reject(error); + } else { + resolve(); + } }; - const onAbort = () => finish(); - + const onAbort = () => + finish(signal.reason instanceof Error ? signal.reason : new Error("The worker was stopped.")); signal.addEventListener("abort", onAbort, { once: true }); - stream.once("end", () => finish()); - // Keep handling duplicate errors until the loop disposes the stream. - stream.on("error", (error: Error) => finish(error)); - }); - } - - private _getAbortError(signal: AbortSignal): Error { - const reason = signal.reason; - return reason instanceof Error ? reason : new Error("The worker was stopped."); - } - private _disposeResponseStream(stream: grpc.ClientReadableStream): void { - stream.removeAllListeners(); - stream.on("error", () => {}); - stream.destroy(); - if (this._responseStream === stream) { - this._responseStream = null; - } + try { + call = stub.hello(new Empty(), metadata, { deadline: new Date(Date.now() + HELLO_TIMEOUT_MS) }, (error) => + finish(error ?? undefined), + ); + if (!settled) { + this._helloCall = call; + } + } catch (err) { + finish(err instanceof Error ? err : new Error(String(err))); + } + }); } /** @@ -589,13 +550,15 @@ export class TaskHubGrpcWorker { async stop(): Promise { const abortController = this._abortController; const runPromise = this._runPromise; - if (!this._isRunning || !abortController || !runPromise || abortController.signal.aborted) { + if (!this._isRunning || !abortController || !runPromise) { throw new Error("The worker is not running."); } + const helloCall = this._helloCall; + const responseStream = this._responseStream; abortController.abort(new Error("The worker was stopped.")); - this._helloCall?.cancel(); - this._responseStream?.cancel(); + helloCall?.cancel(); + responseStream?.cancel(); await runPromise; // Wait for pending work items to complete with timeout @@ -614,12 +577,16 @@ export class TaskHubGrpcWorker { } } - this._stub?.close(); + if (this._stub) { + // Close the gRPC client - this is a synchronous operation + this._stub.close(); + } + + this._stub = null; + this._responseStream = null; + this._helloCall = null; this._abortController = null; this._runPromise = null; - this._helloCall = null; - this._responseStream = null; - this._stub = null; this._isRunning = false; } diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index bffa70dc..d392a2f2 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -63,131 +63,113 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { jest.restoreAllMocks(); }); - it("starts promptly, gives each hello a 30-second deadline, and retries errors", async () => { + it("starts promptly and retries hello deadline errors with a deadline on every call", async () => { jest.useFakeTimers(); jest.setSystemTime(new Date("2026-01-01T00:00:00Z")); - const deadlineError = Object.assign(new Error("deadline exceeded"), { - code: grpc.status.DEADLINE_EXCEEDED, - }) as grpc.ServiceError; - const first = createStub((...args: any[]) => { - getHelloCallback(args)(deadlineError, new Empty()); + const callbacks: HelloCallback[] = []; + const helloTimes: number[] = []; + const logger = createLogger(); + const pending = createMockStub((...args: any[]) => { + helloTimes.push(Date.now()); + callbacks.push(getHelloCallback(args)); return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }); - const connected = successfulStub(); - useStubs(first.stub, connected.stub); - const worker = new TaskHubGrpcWorker({ logger: createLogger() }); + useStubs(pending.stub, pending.stub); + const worker = new TaskHubGrpcWorker({ logger }); await expect(worker.start()).resolves.toBeUndefined(); await flushPromises(); - expect((first.stub.hello as jest.Mock).mock.calls[0][2].deadline).toEqual(new Date("2026-01-01T00:00:30Z")); - expect(connected.stub.getWorkItems).not.toHaveBeenCalled(); - + callbacks[0](new Error("4 DEADLINE_EXCEEDED") as grpc.ServiceError, new Empty()); + await flushPromises(); + expect(logger.error).toHaveBeenCalled(); await jest.advanceTimersByTimeAsync(2000); - expect(connected.stub.getWorkItems).toHaveBeenCalledTimes(1); + expect(pending.hello).toHaveBeenCalledTimes(2); + for (const [index, call] of pending.hello.mock.calls.entries()) { + expect((call[2] as grpc.CallOptions).deadline).toEqual(new Date(helloTimes[index] + 30000)); + } await worker.stop(); }); - it("retries synchronous client construction failures", async () => { - jest.useFakeTimers(); - const connected = successfulStub(); - const generateClient = jest - .spyOn(GrpcClient.prototype as any, "_generateClient") - .mockImplementationOnce(() => { - throw new Error("client construction failed"); - }) - .mockReturnValueOnce(connected.stub); - const logger = createLogger(); - const worker = new TaskHubGrpcWorker({ logger }); + it("cancels a pending hello and drains the connection loop on stop", async () => { + const cancel = jest.fn(); + const pending = createMockStub(() => ({ cancel }) as unknown as grpc.ClientUnaryCall); + useStubs(pending.stub); + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); await worker.start(); - await jest.advanceTimersByTimeAsync(2000); - - expect(generateClient).toHaveBeenCalledTimes(2); - expect(logger.error).toHaveBeenCalledWith(expect.stringContaining("client construction failed")); - expect(connected.stub.getWorkItems).toHaveBeenCalledTimes(1); + await flushPromises(); + const loopPromise = (worker as any)._runPromise as Promise; await worker.stop(); + + expect(cancel).toHaveBeenCalledTimes(1); + await expect(loopPromise).resolves.toBeUndefined(); + expect((worker as any)._runPromise).toBeNull(); + expect((worker as any)._isRunning).toBe(false); }); - it("cancels hello, drains the loop, and fences its late callback before restart", async () => { - let staleHello: HelloCallback | undefined; - const cancel = jest.fn(); - const first = createStub((...args: any[]) => { - staleHello = getHelloCallback(args); - return { cancel } as unknown as grpc.ClientUnaryCall; + it("aborts a pending reconnect delay on stop", async () => { + jest.useFakeTimers(); + const unavailable = createMockStub((...args: any[]) => { + getHelloCallback(args)(new Error("sidecar unavailable") as grpc.ServiceError, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }); - const restarted = successfulStub(); - useStubs(first.stub, restarted.stub); + useStubs(unavailable.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); await worker.start(); await flushPromises(); - const runPromise = (worker as any)._runPromise as Promise; - const stopPromise = worker.stop(); - - await expect(worker.start()).rejects.toThrow("The worker is already running."); - await stopPromise; - await expect(runPromise).resolves.toBeUndefined(); - expect(cancel).toHaveBeenCalledTimes(1); - - await worker.start(); - await flushPromises(); - staleHello!(null, new Empty()); - await flushPromises(); - - expect(first.stub.getWorkItems).not.toHaveBeenCalled(); - expect(restarted.stub.getWorkItems).toHaveBeenCalledTimes(1); - expect((worker as any)._responseStream).toBe(restarted.stream); + expect(jest.getTimerCount()).toBe(1); await worker.stop(); + + expect(jest.getTimerCount()).toBe(0); }); - it("cancels reconnect backoff and permits restart after stop", async () => { - jest.useFakeTimers(); - const unavailable = createStub((...args: any[]) => { - getHelloCallback(args)(new Error("unavailable") as grpc.ServiceError, new Empty()); - return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; - }); + it("rejects start while stopping and restarts after stop drains", async () => { + const first = successfulStub(); const restarted = successfulStub(); - useStubs(unavailable.stub, restarted.stub); + useStubs(first.stub, restarted.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); await worker.start(); await flushPromises(); - expect(jest.getTimerCount()).toBeGreaterThan(0); + const stopPromise = worker.stop(); - await worker.stop(); - expect(jest.getTimerCount()).toBe(0); + await expect(worker.start()).rejects.toThrow("The worker is already running."); + await stopPromise; await worker.start(); await flushPromises(); - expect(restarted.stub.getWorkItems).toHaveBeenCalledTimes(1); + + expect(first.stream.cancel).toHaveBeenCalledTimes(1); + expect(restarted.getWorkItems).toHaveBeenCalledTimes(1); + expect((worker as any)._responseStream).toBe(restarted.stream); await worker.stop(); }); - it("keeps direct internal runs owned by stop", async () => { - const direct = successfulStub(); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - let finishWorkItem!: () => void; - const pendingWorkItem = new Promise((resolve) => { - finishWorkItem = resolve; - }); + it("logs client construction failures and retries until connected", async () => { + jest.useFakeTimers(); + const connected = successfulStub(); + const generateClient = jest + .spyOn(GrpcClient.prototype as any, "_generateClient") + .mockImplementationOnce(() => { + throw new Error("client construction failed"); + }) + .mockReturnValueOnce(connected.stub); + const logger = createLogger(); + const worker = new TaskHubGrpcWorker({ logger }); - await worker.internalRunWorker({ stub: direct.stub } as unknown as GrpcClient); - await flushPromises(); - (worker as any)._pendingWorkItems.add(pendingWorkItem); - const stopPromise = worker.stop(); - await flushPromises(); + await expect(worker.start()).resolves.toBeUndefined(); + await jest.advanceTimersByTimeAsync(4000); - await expect(worker.start()).rejects.toThrow("The worker is already running."); - expect(direct.stub.close).not.toHaveBeenCalled(); - finishWorkItem(); - await stopPromise; + expect(generateClient).toHaveBeenCalledTimes(3); + expect(connected.getWorkItems).toHaveBeenCalledTimes(1); + expect(logger.error).toHaveBeenCalledTimes(2); - expect(direct.stream.cancel).toHaveBeenCalledTimes(1); - expect(direct.stub.close).toHaveBeenCalledTimes(1); + await worker.stop(); }); }); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index 1346b14c..c96346eb 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -69,7 +69,7 @@ describe("Worker stream recovery", () => { jest.restoreAllMocks(); }); - it("replaces a failed stream within the owned connection loop", async () => { + it.each(["error", "end"] as const)("replaces a stream after %s", async (event) => { const initial = createMockClient(); const replacement = createMockClient(); jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(replacement.stub); @@ -77,7 +77,7 @@ describe("Worker stream recovery", () => { await worker.internalRunWorker(initial.client); await flushPromises(); - initial.stream.emit("error", new Error("14 UNAVAILABLE")); + initial.stream.emit(event, ...(event === "error" ? [new Error("14 UNAVAILABLE")] : [])); expect(() => initial.stream.emit("error", new Error("duplicate error"))).not.toThrow(); await flushPromises(); From d7900bb6934e4f50df043b70045f2a06ebfd6e38 Mon Sep 17 00:00:00 2001 From: wangbill Date: Thu, 13 Aug 2026 14:24:55 -0700 Subject: [PATCH 11/12] test(worker): align simplified startup mocks Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b --- .../durabletask-js/test/worker-startup.spec.ts | 18 +++++++++--------- 1 file changed, 9 insertions(+), 9 deletions(-) diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index d392a2f2..62c179a0 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -69,7 +69,7 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { const callbacks: HelloCallback[] = []; const helloTimes: number[] = []; const logger = createLogger(); - const pending = createMockStub((...args: any[]) => { + const pending = createStub((...args: any[]) => { helloTimes.push(Date.now()); callbacks.push(getHelloCallback(args)); return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; @@ -84,8 +84,8 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { await flushPromises(); expect(logger.error).toHaveBeenCalled(); await jest.advanceTimersByTimeAsync(2000); - expect(pending.hello).toHaveBeenCalledTimes(2); - for (const [index, call] of pending.hello.mock.calls.entries()) { + expect(pending.stub.hello).toHaveBeenCalledTimes(2); + for (const [index, call] of (pending.stub.hello as jest.Mock).mock.calls.entries()) { expect((call[2] as grpc.CallOptions).deadline).toEqual(new Date(helloTimes[index] + 30000)); } @@ -94,7 +94,7 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { it("cancels a pending hello and drains the connection loop on stop", async () => { const cancel = jest.fn(); - const pending = createMockStub(() => ({ cancel }) as unknown as grpc.ClientUnaryCall); + const pending = createStub(() => ({ cancel }) as unknown as grpc.ClientUnaryCall); useStubs(pending.stub); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); @@ -112,7 +112,7 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { it("aborts a pending reconnect delay on stop", async () => { jest.useFakeTimers(); - const unavailable = createMockStub((...args: any[]) => { + const unavailable = createStub((...args: any[]) => { getHelloCallback(args)(new Error("sidecar unavailable") as grpc.ServiceError, new Empty()); return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }); @@ -145,7 +145,7 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { await flushPromises(); expect(first.stream.cancel).toHaveBeenCalledTimes(1); - expect(restarted.getWorkItems).toHaveBeenCalledTimes(1); + expect(restarted.stub.getWorkItems).toHaveBeenCalledTimes(1); expect((worker as any)._responseStream).toBe(restarted.stream); await worker.stop(); @@ -166,9 +166,9 @@ describe("TaskHubGrpcWorker connection lifecycle", () => { await expect(worker.start()).resolves.toBeUndefined(); await jest.advanceTimersByTimeAsync(4000); - expect(generateClient).toHaveBeenCalledTimes(3); - expect(connected.getWorkItems).toHaveBeenCalledTimes(1); - expect(logger.error).toHaveBeenCalledTimes(2); + expect(generateClient).toHaveBeenCalledTimes(2); + expect(connected.stub.getWorkItems).toHaveBeenCalledTimes(1); + expect(logger.error).toHaveBeenCalledTimes(1); await worker.stop(); }); From f7454f85ec9342589152faa356852d9a9670eecb Mon Sep 17 00:00:00 2001 From: wangbill Date: Thu, 13 Aug 2026 14:46:51 -0700 Subject: [PATCH 12/12] refactor(worker): minimize connection retry fix Restores the existing event-driven worker structure while keeping per-Hello deadline and stop cancellation. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: d491ec0d-9ce9-421b-9953-7d179d53625b --- CHANGELOG.md | 4 +- .../src/worker/task-hub-grpc-worker.ts | 493 +++++++++--------- .../test/worker-startup.spec.ts | 270 +++------- .../test/worker-stream-recovery.spec.ts | 256 ++++++--- 4 files changed, 487 insertions(+), 536 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 683f3c07..3b61866b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,8 +13,8 @@ ### Fixes -- Bound each worker sidecar hello attempt to 30 seconds while preserving background connection - retries, and make worker shutdown cancel and drain the connection loop. +- Bound each worker sidecar hello attempt to 30 seconds, retry failed connections, and cancel + pending hello calls and reconnect delays when the worker stops. ## v0.4.0 (2026-07-31) 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 d39ba689..6adf399b 100644 --- a/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts +++ b/packages/durabletask-js/src/worker/task-hub-grpc-worker.ts @@ -20,8 +20,7 @@ import { EntityInstanceId } from "../entities/entity-instance-id"; import { EntityFactory } from "../entities/task-entity"; import { StringValue } from "google-protobuf/google/protobuf/wrappers_pb"; import { Logger, ConsoleLogger } from "../types/logger.type"; -import { ExponentialBackoff, withTimeout } from "../utils/backoff.util"; -import { TimeoutError } from "../exception/timeout-error"; +import { ExponentialBackoff, sleep, withTimeout } from "../utils/backoff.util"; import { VersioningOptions, VersionMatchStrategy, VersionFailureStrategy } from "./versioning-options"; import { WorkItemFilters, generateWorkItemFiltersFromRegistry, toGrpcWorkItemFilters } from "./work-item-filters"; import { compareVersions } from "../utils/versioning.util"; @@ -41,17 +40,8 @@ import { /** Default timeout in milliseconds for graceful shutdown. */ const DEFAULT_SHUTDOWN_TIMEOUT_MS = 30000; -/** Timeout applied to each sidecar hello attempt. */ const HELLO_TIMEOUT_MS = 30000; -interface WorkerLifecycle { - readonly abortController: AbortController; - runPromise: Promise; - stub: stubs.TaskHubSidecarServiceClient | null; - helloCall: grpc.ClientUnaryCall | null; - responseStream: grpc.ClientReadableStream | null; -} - /** * Options for creating a TaskHubGrpcWorker. */ @@ -83,6 +73,7 @@ export interface TaskHubGrpcWorkerOptions { } export class TaskHubGrpcWorker { + private _responseStream: grpc.ClientReadableStream | null; private _registry: Registry; private _hostAddress?: string; private _tls?: boolean; @@ -90,12 +81,16 @@ export class TaskHubGrpcWorker { private _grpcChannelCredentials?: grpc.ChannelCredentials; private _metadataGenerator?: MetadataGenerator; private _isRunning: boolean; + private _stopWorker: boolean; + private _stub: stubs.TaskHubSidecarServiceClient | null; private _logger: Logger; private _pendingWorkItems: Set>; private _shutdownTimeoutMs: number; + private _backoff: ExponentialBackoff; private _versioning?: VersioningOptions; private _workItemFilters?: WorkItemFilters | "auto"; - private _lifecycle: WorkerLifecycle | null; + private _abortController: AbortController | null; + private _helloCall: grpc.ClientUnaryCall | null; /** * Creates a new TaskHubGrpcWorker instance. @@ -173,13 +168,22 @@ export class TaskHubGrpcWorker { this._grpcChannelOptions = resolvedOptions; this._grpcChannelCredentials = resolvedCredentials; this._metadataGenerator = resolvedMetadataGenerator; + this._responseStream = null; this._isRunning = false; + this._stopWorker = false; + this._stub = null; this._logger = resolvedLogger ?? new ConsoleLogger(); this._pendingWorkItems = new Set(); this._shutdownTimeoutMs = resolvedShutdownTimeoutMs ?? DEFAULT_SHUTDOWN_TIMEOUT_MS; + this._backoff = new ExponentialBackoff({ + initialDelayMs: 1000, + maxDelayMs: 30000, + multiplier: 2, + }); this._versioning = resolvedVersioning; this._workItemFilters = resolvedWorkItemFilters; - this._lifecycle = null; + this._abortController = null; + this._helloCall = null; } /** @@ -192,6 +196,49 @@ export class TaskHubGrpcWorker { return new grpc.Metadata(); } + /** + * Creates a new gRPC client and retries the worker. + * Properly closes the old client to prevent connection leaks. + */ + private async _createNewClientAndRetry(signal?: AbortSignal): Promise { + if (signal?.aborted) { + return; + } + + // Close the old stub to prevent connection leaks + if (this._stub) { + this._stub.close(); + } + + try { + await this._backoff.wait(signal); + } catch (err) { + if (signal?.aborted) { + return; + } + throw err; + } + + if (signal?.aborted) { + return; + } + + const newClient = new GrpcClient( + this._hostAddress, + this._grpcChannelOptions, + this._tls, + this._grpcChannelCredentials, + ); + this._stub = newClient.stub; + + // Do not await - run in background + this.internalRunWorker(newClient, true, signal).catch((err) => { + if (!signal?.aborted && !this._stopWorker) { + WorkerLogs.workerError(this._logger, err); + } + }); + } + /** * Registers an orchestrator function with the worker. * @@ -355,265 +402,168 @@ export class TaskHubGrpcWorker { /** * In node.js we don't require a new thread as we have a main event loop * Therefore, we open the stream and simply listen through the eventemitter behind the scenes - * - * @remarks Resolves after launching the background connection loop. Connection failures - * are logged and retried while the worker remains running. */ async start(): Promise { - this._startConnectionLoop(); - } - - async internalRunWorker(client: GrpcClient, _isRetry: boolean = false): Promise { - this._startConnectionLoop(client); - } - - private _startConnectionLoop(initialClient?: GrpcClient): void { - if (this._isRunning || this._lifecycle) { + if (this._isRunning) { throw new Error("The worker is already running."); } - const lifecycle: WorkerLifecycle = { - abortController: new AbortController(), - runPromise: Promise.resolve(), - stub: null, - helloCall: null, - responseStream: null, - }; - this._isRunning = true; - this._lifecycle = lifecycle; - lifecycle.runPromise = this._runConnectionLoop(lifecycle, initialClient).catch((err) => { - if (!lifecycle.abortController.signal.aborted) { - WorkerLogs.workerError(this._logger, err instanceof Error ? err : new Error(String(err))); + this._stopWorker = false; + this._backoff.reset(); + const abortController = new AbortController(); + this._abortController = abortController; + const client = new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); + this._stub = client.stub; + + // Run in background but catch any unhandled errors to prevent unhandled rejections + this.internalRunWorker(client, false, abortController.signal).catch((err) => { + // Only log if the worker wasn't stopped intentionally + if (!abortController.signal.aborted) { + WorkerLogs.workerError(this._logger, err); } }); - } - - private async _runConnectionLoop(lifecycle: WorkerLifecycle, initialClient?: GrpcClient): Promise { - const signal = lifecycle.abortController.signal; - const backoff = new ExponentialBackoff({ - initialDelayMs: 1000, - maxDelayMs: 30000, - multiplier: 2, - }); - let nextClient = initialClient; - - while (!signal.aborted) { - let stub: stubs.TaskHubSidecarServiceClient | null = null; - let stream: grpc.ClientReadableStream | null = null; - try { - const client = - nextClient ?? - new GrpcClient(this._hostAddress, this._grpcChannelOptions, this._tls, this._grpcChannelCredentials); - nextClient = undefined; - stub = client.stub; - lifecycle.stub = stub; - - const helloMetadata = await this._waitForAbortable(this._getMetadata(), lifecycle); - await this._waitForHello(stub, helloMetadata, lifecycle); - - const metadata = await this._waitForAbortable(this._getMetadata(), lifecycle); - const request = this._buildGetWorkItemsRequest(); - stream = stub.getWorkItems(request, metadata); - lifecycle.responseStream = stream; - this._listenForWorkItems(stream, stub); - - backoff.reset(); - WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); - - const streamError = await this._waitForStreamEnd(stream, lifecycle); - if (signal.aborted) { - WorkerLogs.streamEnded(this._logger); - break; - } - if (streamError) { - WorkerLogs.streamErrorInfo(this._logger, streamError); - } - WorkerLogs.streamRetry(this._logger, backoff.peekNextDelay()); - } catch (err) { - if (signal.aborted) { - break; - } - const error = err instanceof Error ? err : new Error(String(err)); - WorkerLogs.streamError(this._logger, error); - WorkerLogs.connectionRetry(this._logger, backoff.peekNextDelay()); - } finally { - if (stream) { - this._disposeResponseStream(stream, lifecycle); - } - if (stub && !signal.aborted) { - stub.close(); - if (lifecycle.stub === stub) { - lifecycle.stub = null; - } - } - } - - if (signal.aborted) { - break; - } - - try { - await backoff.wait(signal); - } catch (err) { - if (!signal.aborted) { - throw err; - } - } - } - } - - private _listenForWorkItems( - stream: grpc.ClientReadableStream, - stub: stubs.TaskHubSidecarServiceClient, - ): void { - stream.on("data", (workItem: pb.WorkItem) => { - const completionToken = workItem.getCompletiontoken(); - if (workItem.hasOrchestratorrequest()) { - WorkerLogs.workItemReceived( - this._logger, - "Orchestrator Request", - workItem?.getOrchestratorrequest()?.getInstanceid(), - ); - this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, stub); - } else if (workItem.hasActivityrequest()) { - WorkerLogs.workItemReceived(this._logger, "Activity Request"); - this._executeActivity(workItem.getActivityrequest() as any, completionToken, stub); - } else if (workItem.hasEntityrequest()) { - const entityRequest = workItem.getEntityrequest() as pb.EntityBatchRequest; - WorkerLogs.entityRequestReceived(this._logger, entityRequest.getInstanceid(), "Entity Request"); - this._executeEntity(entityRequest, completionToken, stub); - } else if (workItem.hasEntityrequestv2()) { - const entityRequestV2 = workItem.getEntityrequestv2() as pb.EntityRequest; - WorkerLogs.entityRequestReceived(this._logger, entityRequestV2.getInstanceid(), "Entity Request V2"); - this._executeEntityV2(entityRequestV2, completionToken, stub); - } else if (workItem.hasHealthping()) { - // Health ping - no-op, just a keep-alive message from the server - } else { - WorkerLogs.unknownWorkItem(this._logger); - } - }); + this._isRunning = true; } - private async _waitForHello( - stub: stubs.TaskHubSidecarServiceClient, - metadata: grpc.Metadata, - lifecycle: WorkerLifecycle, - ): Promise { - const signal = lifecycle.abortController.signal; - if (signal.aborted) { - throw this._getLifecycleAbortError(lifecycle); - } - - let call: grpc.ClientUnaryCall | undefined; - let timeoutId: ReturnType | undefined; - let removeAbortListener: (() => void) | undefined; - + async internalRunWorker(client: GrpcClient, _isRetry: boolean = false, signal?: AbortSignal): Promise { try { + // send a "Hello" message to the sidecar to ensure that it's listening + const helloMetadata = await this._getMetadata(); + if (signal?.aborted) { + return; + } await new Promise((resolve, reject) => { + let helloCall: grpc.ClientUnaryCall | undefined = undefined; let settled = false; - const finish = (error?: Error) => { - if (settled) { - return; - } + const finish = (err?: Error) => { + if (settled) return; settled = true; - if (timeoutId !== undefined) { - clearTimeout(timeoutId); + signal?.removeEventListener("abort", onAbort); + if (this._helloCall === helloCall) { + this._helloCall = null; } - removeAbortListener?.(); - if (error) { - reject(error); + if (err) { + reject(err); } else { resolve(); } }; - const onAbort = () => finish(this._getLifecycleAbortError(lifecycle)); - removeAbortListener = () => signal.removeEventListener("abort", onAbort); - signal.addEventListener("abort", onAbort, { once: true }); - - timeoutId = setTimeout(() => { - finish(new TimeoutError(`Sidecar hello did not respond within ${HELLO_TIMEOUT_MS}ms.`)); - call?.cancel(); - }, HELLO_TIMEOUT_MS); - + const onAbort = () => { + helloCall?.cancel(); + finish(signal?.reason); + }; + signal?.addEventListener("abort", onAbort, { once: true }); try { - call = stub.hello(new Empty(), metadata, { deadline: new Date(Date.now() + HELLO_TIMEOUT_MS) }, (error) => - finish(error ?? undefined), + helloCall = client.stub.hello( + new Empty(), + helloMetadata, + { deadline: new Date(Date.now() + HELLO_TIMEOUT_MS) }, + (err) => finish(err ?? undefined), ); - lifecycle.helloCall = call; + if (!settled) { + this._helloCall = helloCall; + } } catch (err) { - finish(err instanceof Error ? err : new Error(String(err))); + const normalizedError = err instanceof Error ? err : new Error(String(err)); + finish(normalizedError); } }); - } finally { - if (timeoutId !== undefined) { - clearTimeout(timeoutId); - } - removeAbortListener?.(); - if (lifecycle.helloCall === call) { - lifecycle.helloCall = null; - } - } - } - private async _waitForAbortable(promise: Promise, lifecycle: WorkerLifecycle): Promise { - const signal = lifecycle.abortController.signal; - if (signal.aborted) { - throw this._getLifecycleAbortError(lifecycle); - } + // Reset backoff on successful connection + this._backoff.reset(); - let onAbort!: () => void; - const aborted = new Promise((_, reject) => { - onAbort = () => reject(this._getLifecycleAbortError(lifecycle)); - signal.addEventListener("abort", onAbort, { once: true }); - }); + // Stream work items from the sidecar (pass metadata for insecure connections) + const metadata = await this._getMetadata(); + if (signal?.aborted) { + return; + } + const request = this._buildGetWorkItemsRequest(); - try { - return await Promise.race([promise, aborted]); - } finally { - signal.removeEventListener("abort", onAbort); - } - } + const stream = client.stub.getWorkItems(request, metadata); + this._responseStream = stream; - private _waitForStreamEnd( - stream: grpc.ClientReadableStream, - lifecycle: WorkerLifecycle, - ): Promise { - const signal = lifecycle.abortController.signal; - if (signal.aborted) { - return Promise.resolve(undefined); - } + WorkerLogs.workerConnected(this._logger, this._hostAddress ?? "localhost:4001"); - return new Promise((resolve) => { - let settled = false; - const finish = (error?: Error) => { - if (settled) { - return; + // Wait for a work item to be received + stream.on("data", (workItem: pb.WorkItem) => { + const completionToken = workItem.getCompletiontoken(); + if (workItem.hasOrchestratorrequest()) { + WorkerLogs.workItemReceived( + this._logger, + "Orchestrator Request", + workItem?.getOrchestratorrequest()?.getInstanceid(), + ); + this._executeOrchestrator(workItem.getOrchestratorrequest() as any, completionToken, client.stub); + } else if (workItem.hasActivityrequest()) { + WorkerLogs.workItemReceived(this._logger, "Activity Request"); + this._executeActivity(workItem.getActivityrequest() as any, completionToken, client.stub); + } else if (workItem.hasEntityrequest()) { + const entityRequest = workItem.getEntityrequest() as pb.EntityBatchRequest; + WorkerLogs.entityRequestReceived(this._logger, entityRequest.getInstanceid(), "Entity Request"); + this._executeEntity(entityRequest, completionToken, client.stub); + } else if (workItem.hasEntityrequestv2()) { + const entityRequestV2 = workItem.getEntityrequestv2() as pb.EntityRequest; + WorkerLogs.entityRequestReceived(this._logger, entityRequestV2.getInstanceid(), "Entity Request V2"); + this._executeEntityV2(entityRequestV2, completionToken, client.stub); + } else if (workItem.hasHealthping()) { + // Health ping - no-op, just a keep-alive message from the server + } else { + WorkerLogs.unknownWorkItem(this._logger); } - settled = true; - signal.removeEventListener("abort", onAbort); - resolve(error); - }; - const onAbort = () => finish(); - - signal.addEventListener("abort", onAbort, { once: true }); - stream.once("end", () => finish()); - // Keep handling duplicate errors until the loop disposes the stream. - stream.on("error", (error: Error) => finish(error)); - }); - } + }); - private _getLifecycleAbortError(lifecycle: WorkerLifecycle): Error { - const reason = lifecycle.abortController.signal.reason; - return reason instanceof Error ? reason : new Error("The worker was stopped."); - } + // Wait for the stream to end or error + stream.on("end", () => { + if (signal?.aborted || this._stopWorker) { + WorkerLogs.streamEnded(this._logger); + stream.removeAllListeners(); + stream.destroy(); + return; + } + // Stream ended unexpectedly - clean up and retry + stream.removeAllListeners(); + stream.on("error", () => {}); // Prevent unhandled "error" after cleanup + stream.destroy(); + WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); + this._createNewClientAndRetry(signal).catch((retryErr) => { + if (!signal?.aborted && !this._stopWorker) { + WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); + } + }); + }); - private _disposeResponseStream(stream: grpc.ClientReadableStream, lifecycle: WorkerLifecycle): void { - stream.removeAllListeners(); - stream.on("error", () => {}); - stream.destroy(); - if (lifecycle.responseStream === stream) { - lifecycle.responseStream = null; + stream.on("error", (err: Error) => { + // Ignore cancellation errors when the worker is being stopped intentionally + if (signal?.aborted || this._stopWorker) { + return; + } + WorkerLogs.streamErrorInfo(this._logger, err); + + // Clean up the errored stream and retry the connection. + // In Node.js, gRPC stream errors (e.g., UNAVAILABLE, transport failures) + // may not always be followed by an "end" event. Without recovery here, + // the worker would silently stop processing work items. + stream.removeAllListeners(); + stream.on("error", () => {}); // Prevent unhandled "error" after cleanup + stream.destroy(); + WorkerLogs.streamRetry(this._logger, this._backoff.peekNextDelay()); + this._createNewClientAndRetry(signal).catch((retryErr) => { + if (!signal?.aborted && !this._stopWorker) { + WorkerLogs.workerError(this._logger, retryErr instanceof Error ? retryErr : new Error(String(retryErr))); + } + }); + }); + } catch (err) { + if (signal?.aborted || this._stopWorker) { + // ignoring the error because the worker has been stopped + return; + } + const error = err instanceof Error ? err : new Error(String(err)); + WorkerLogs.streamError(this._logger, error); + WorkerLogs.connectionRetry(this._logger, this._backoff.peekNextDelay()); + await this._createNewClientAndRetry(signal); + return; } } @@ -622,15 +572,50 @@ export class TaskHubGrpcWorker { * Uses a configurable timeout (default 30s) to wait for in-flight work. */ async stop(): Promise { - const lifecycle = this._lifecycle; - if (!this._isRunning || !lifecycle) { + if (!this._isRunning) { throw new Error("The worker is not running."); } - lifecycle.abortController.abort(new Error("The worker was stopped.")); - lifecycle.helloCall?.cancel(); - lifecycle.responseStream?.cancel(); - await lifecycle.runPromise; + const abortController = this._abortController; + const helloCall = this._helloCall; + const responseStream = this._responseStream; + this._stopWorker = true; + abortController?.abort(); + if (this._helloCall === helloCall) { + helloCall?.cancel(); + this._helloCall = null; + } + + // Cancel stream first while error handlers are still attached + // This allows the error handler to suppress CANCELLED errors + responseStream?.cancel(); + + // Wait for the stream to react to cancellation using events rather than a fixed delay. + // This avoids race conditions caused by relying on timing alone. + if (responseStream) { + try { + await withTimeout( + new Promise((resolve) => { + const stream = responseStream; + // Any of these events indicates the stream has processed cancellation / is closing. + stream.once("end", resolve); + stream.once("close", resolve); + stream.once("error", () => resolve()); + }), + 1000, + "Timed out waiting for response stream to close after cancellation", + ); + } catch { + // If we time out waiting for the stream to close, proceed with forced cleanup below. + } + } + + // Now safe to remove listeners and destroy + responseStream?.removeAllListeners(); + responseStream?.destroy(); + if (this._responseStream === responseStream) { + this._responseStream = null; + } // Wait for pending work items to complete with timeout if (this._pendingWorkItems.size > 0) { @@ -648,16 +633,18 @@ export class TaskHubGrpcWorker { } } - if (lifecycle.stub) { + if (this._stub) { // Close the gRPC client - this is a synchronous operation - lifecycle.stub.close(); - lifecycle.stub = null; + this._stub.close(); } - - if (this._lifecycle === lifecycle) { - this._lifecycle = null; - this._isRunning = false; + this._isRunning = false; + if (this._abortController === abortController) { + this._abortController = null; } + + // Brief pause to allow gRPC cleanup + // https://github.com/grpc/grpc-node/issues/1563#issuecomment-829483711 + await sleep(1000); } /** diff --git a/packages/durabletask-js/test/worker-startup.spec.ts b/packages/durabletask-js/test/worker-startup.spec.ts index 0c74da41..cf55cbbf 100644 --- a/packages/durabletask-js/test/worker-startup.spec.ts +++ b/packages/durabletask-js/test/worker-startup.spec.ts @@ -1,7 +1,6 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. -import { EventEmitter } from "events"; import * as grpc from "@grpc/grpc-js"; import { Empty } from "google-protobuf/google/protobuf/empty_pb"; import { GrpcClient } from "../src/client/client-grpc"; @@ -9,256 +8,127 @@ import * as stubs from "../src/proto/orchestrator_service_grpc_pb"; import { Logger, NoOpLogger } from "../src/types/logger.type"; import { TaskHubGrpcWorker } from "../src/worker/task-hub-grpc-worker"; -type MockStream = EventEmitter & { - cancel: jest.Mock; - destroy: jest.Mock; -}; - type HelloCallback = (error: grpc.ServiceError | null, response: Empty) => void; -function createMockStream(): MockStream { - const stream = new EventEmitter() as MockStream; - stream.cancel = jest.fn(); - stream.destroy = jest.fn(); - return stream; -} - -function createMockStub( - hello: (...args: any[]) => grpc.ClientUnaryCall, - stream: MockStream = createMockStream(), -): { - stub: stubs.TaskHubSidecarServiceClient; - stream: MockStream; - hello: jest.Mock; - getWorkItems: jest.Mock; - close: jest.Mock; -} { - const helloMock = jest.fn(hello); - const getWorkItems = jest.fn().mockReturnValue(stream); - const close = jest.fn(); +function useStub(hello: jest.Mock): jest.SpyInstance { const stub = { - hello: helloMock, - getWorkItems, - close, + hello, + getWorkItems: jest.fn(), + close: jest.fn(), } as unknown as stubs.TaskHubSidecarServiceClient; - return { stub, stream, hello: helloMock, getWorkItems, close }; + return jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(stub); } -function successfulStub(stream = createMockStream()) { - return createMockStub((...args: any[]) => { - getHelloCallback(args)(null, new Empty()); - return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; - }, stream); -} - -function getHelloCallback(args: any[]): HelloCallback { +function getCallback(args: any[]): HelloCallback { return args[args.length - 1] as HelloCallback; } -function useStubs(...stubSequence: stubs.TaskHubSidecarServiceClient[]): jest.SpyInstance { - const generateClient = jest.spyOn(GrpcClient.prototype as any, "_generateClient"); - for (const stub of stubSequence) { - generateClient.mockReturnValueOnce(stub); +async function flushPromises(): Promise { + for (let i = 0; i < 5; i++) { + await Promise.resolve(); } - return generateClient; } -function createLogger(): Logger & { error: jest.Mock } { - return { - error: jest.fn(), - warn: jest.fn(), - info: jest.fn(), - debug: jest.fn(), - }; +async function stopWorker(worker: TaskHubGrpcWorker): Promise { + const stop = worker.stop(); + await jest.advanceTimersByTimeAsync(1000); + await stop; } -async function flushPromises(): Promise { - for (let i = 0; i < 10; i++) { - await Promise.resolve(); - } -} +describe("TaskHubGrpcWorker startup", () => { + beforeEach(() => { + jest.useFakeTimers(); + }); -describe("TaskHubGrpcWorker connection lifecycle", () => { afterEach(() => { jest.useRealTimers(); jest.restoreAllMocks(); }); - it("starts promptly while hello is unavailable and cancels hello on stop", async () => { - const cancel = jest.fn(); - const pending = createMockStub(() => ({ cancel }) as unknown as grpc.ClientUnaryCall); - useStubs(pending.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - - await expect(worker.start()).resolves.toBeUndefined(); - await flushPromises(); - - expect(pending.hello).toHaveBeenCalledTimes(1); - expect(pending.getWorkItems).not.toHaveBeenCalled(); - - await worker.stop(); - - expect(cancel).toHaveBeenCalledTimes(1); - expect((worker as any)._lifecycle).toBeNull(); - expect((worker as any)._isRunning).toBe(false); - }); - - it("times out each hung hello attempt and retries inside the owned loop", async () => { - jest.useFakeTimers(); - jest.setSystemTime(new Date("2026-01-01T00:00:00Z")); - const calls: jest.Mock[] = []; - const logger = createLogger(); - const pending = createMockStub(() => { - const cancel = jest.fn(); - calls.push(cancel); - return { cancel } as unknown as grpc.ClientUnaryCall; + it("sets a 30-second deadline on every hello and retries an initial failure", async () => { + const deadlines: number[] = []; + const hello = jest.fn((...args: any[]) => { + deadlines.push((args[2] as grpc.CallOptions).deadline!.valueOf() - Date.now()); + getCallback(args)(new Error("unavailable") as grpc.ServiceError, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; }); - useStubs(pending.stub, pending.stub); + const logger = { + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + } satisfies Logger; + useStub(hello); const worker = new TaskHubGrpcWorker({ logger }); - await worker.start(); + await expect(worker.start()).resolves.toBeUndefined(); await flushPromises(); + await jest.advanceTimersByTimeAsync(2000); - const callOptions = pending.hello.mock.calls[0][2] as grpc.CallOptions; - expect(callOptions.deadline).toEqual(new Date("2026-01-01T00:00:30Z")); - - await jest.advanceTimersByTimeAsync(30000); - expect(calls[0]).toHaveBeenCalledTimes(1); + expect(hello).toHaveBeenCalledTimes(2); + expect(deadlines).toEqual([30000, 30000]); expect(logger.error).toHaveBeenCalled(); - // Advance past any jittered first retry delay without assuming its exact value. - await jest.advanceTimersByTimeAsync(2000); - expect(pending.hello).toHaveBeenCalledTimes(2); - - await worker.stop(); - expect(calls[1]).toHaveBeenCalledTimes(1); - expect(jest.getTimerCount()).toBe(0); + await stopWorker(worker); }); - it("logs initial client construction failures and retries until connected", async () => { - jest.useFakeTimers(); - const connected = successfulStub(); - const logger = createLogger(); - const generateClient = jest - .spyOn(GrpcClient.prototype as any, "_generateClient") - .mockImplementationOnce(() => { - throw new Error("first construction failure"); - }) + it("logs and retries when hello throws synchronously", async () => { + const hello = jest + .fn() .mockImplementationOnce(() => { - throw new Error("second construction failure"); + throw new Error("synchronous hello failure"); }) - .mockReturnValueOnce(connected.stub); + .mockImplementation(() => ({ cancel: jest.fn() }) as unknown as grpc.ClientUnaryCall); + const logger = { + error: jest.fn(), + warn: jest.fn(), + info: jest.fn(), + debug: jest.fn(), + } satisfies Logger; + useStub(hello); const worker = new TaskHubGrpcWorker({ logger }); - await expect(worker.start()).resolves.toBeUndefined(); - await jest.advanceTimersByTimeAsync(4000); - - expect(generateClient).toHaveBeenCalledTimes(3); - expect(connected.getWorkItems).toHaveBeenCalledTimes(1); - expect(logger.error).toHaveBeenCalledTimes(2); - - await worker.stop(); - }); - - it("aborts a pending reconnect delay and drains the loop on stop", async () => { - jest.useFakeTimers(); - const unavailable = createMockStub((...args: any[]) => { - getHelloCallback(args)(new Error("sidecar unavailable") as grpc.ServiceError, new Empty()); - return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; - }); - useStubs(unavailable.stub); - const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - await worker.start(); await flushPromises(); - expect(jest.getTimerCount()).toBeGreaterThan(0); - const loopPromise = (worker as any)._lifecycle.runPromise as Promise; + await jest.advanceTimersByTimeAsync(2000); - await worker.stop(); + expect(logger.error).toHaveBeenCalled(); + expect(hello).toHaveBeenCalledTimes(2); - await expect(loopPromise).resolves.toBeUndefined(); - expect(jest.getTimerCount()).toBe(0); - expect((worker as any)._lifecycle).toBeNull(); + await stopWorker(worker); }); - it("rejects start during stop, allows restart, and ignores a late hello callback", async () => { - let firstHello: HelloCallback | undefined; - const first = createMockStub((...args: any[]) => { - firstHello = getHelloCallback(args); - return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; - }); - const restarted = successfulStub(); - useStubs(first.stub, restarted.stub); + it("cancels a pending hello when stopped", async () => { + const cancel = jest.fn(); + const hello = jest.fn(() => ({ cancel }) as unknown as grpc.ClientUnaryCall); + useStub(hello); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); await worker.start(); await flushPromises(); - const stopPromise = worker.stop(); - - await expect(worker.start()).rejects.toThrow("The worker is already running."); - await stopPromise; - - await worker.start(); - await flushPromises(); - firstHello!(null, new Empty()); - await flushPromises(); - - expect(first.getWorkItems).not.toHaveBeenCalled(); - expect(restarted.getWorkItems).toHaveBeenCalledTimes(1); - expect((worker as any)._lifecycle.responseStream).toBe(restarted.stream); - - await worker.stop(); - }); + await stopWorker(worker); - it("recovers from runtime disconnect and replacement client construction failure", async () => { - jest.useFakeTimers(); - const first = successfulStub(); - const recovered = successfulStub(); - const logger = createLogger(); - const generateClient = jest - .spyOn(GrpcClient.prototype as any, "_generateClient") - .mockReturnValueOnce(first.stub) - .mockImplementationOnce(() => { - throw new Error("replacement construction failure"); - }) - .mockReturnValueOnce(recovered.stub); - const worker = new TaskHubGrpcWorker({ logger }); - - await worker.start(); - await flushPromises(); - first.stream.emit("error", new Error("14 UNAVAILABLE")); - await jest.advanceTimersByTimeAsync(4000); - - expect(generateClient).toHaveBeenCalledTimes(3); - expect(first.close).toHaveBeenCalledTimes(1); - expect(recovered.getWorkItems).toHaveBeenCalledTimes(1); - expect(logger.error).toHaveBeenCalled(); - - await worker.stop(); + expect(cancel).toHaveBeenCalledTimes(1); + expect((worker as any)._isRunning).toBe(false); }); - it("gives direct internal runs lifecycle ownership and fences stopped streams", async () => { - const direct = successfulStub(); - const restarted = successfulStub(); - useStubs(restarted.stub); + it("cancels reconnect backoff and prevents a stopped run from reconnecting", async () => { + const hello = jest.fn((...args: any[]) => { + getCallback(args)(new Error("unavailable") as grpc.ServiceError, new Empty()); + return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; + }); + const generateClient = useStub(hello); const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); - const directClient = { stub: direct.stub } as unknown as GrpcClient; - - await worker.internalRunWorker(directClient); - await flushPromises(); - - expect((worker as any)._lifecycle.stub).toBe(direct.stub); - await expect(worker.start()).rejects.toThrow("The worker is already running."); - await worker.stop(); await worker.start(); await flushPromises(); - direct.stream.emit("error", new Error("stale stream error")); - await flushPromises(); + expect(jest.getTimerCount()).toBeGreaterThan(0); - expect((worker as any)._lifecycle.stub).toBe(restarted.stub); - expect((worker as any)._lifecycle.responseStream).toBe(restarted.stream); + await stopWorker(worker); + await jest.advanceTimersByTimeAsync(60000); - await worker.stop(); + expect(generateClient).toHaveBeenCalledTimes(1); + expect(hello).toHaveBeenCalledTimes(1); + expect(jest.getTimerCount()).toBe(0); }); }); diff --git a/packages/durabletask-js/test/worker-stream-recovery.spec.ts b/packages/durabletask-js/test/worker-stream-recovery.spec.ts index 2bfff10f..a1e205ca 100644 --- a/packages/durabletask-js/test/worker-stream-recovery.spec.ts +++ b/packages/durabletask-js/test/worker-stream-recovery.spec.ts @@ -1,114 +1,208 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. +/** + * Tests that the TaskHubGrpcWorker correctly recovers when the gRPC work-item + * stream emits an "error" event without a subsequent "end" event. + * + * This validates the fix for a bug where the stream "error" handler only logged + * the error but did not clean up the stream or retry the connection — causing + * the worker to silently stop processing work items after transport-level + * failures (e.g., UNAVAILABLE, network disconnections). + */ + import { EventEmitter } from "events"; -import * as grpc from "@grpc/grpc-js"; -import { Empty } from "google-protobuf/google/protobuf/empty_pb"; -import { GrpcClient } from "../src/client/client-grpc"; -import * as stubs from "../src/proto/orchestrator_service_grpc_pb"; -import { NoOpLogger } from "../src/types/logger.type"; import { TaskHubGrpcWorker } from "../src/worker/task-hub-grpc-worker"; +import { NoOpLogger } from "../src/types/logger.type"; +import { GrpcClient } from "../src/client/client-grpc"; -type MockStream = EventEmitter & { - cancel: jest.Mock; - destroy: jest.Mock; -}; - -function createMockStream(): MockStream { - const stream = new EventEmitter() as MockStream; - stream.cancel = jest.fn(); - stream.destroy = jest.fn(); - return stream; -} - -function createMockClient(stream: MockStream = createMockStream()): { +/** + * Creates a mock GrpcClient whose `hello` call succeeds immediately + * and whose `getWorkItems` returns a controllable EventEmitter stream. + */ +function createMockClient(): { client: GrpcClient; - stream: MockStream; - stub: stubs.TaskHubSidecarServiceClient; - getWorkItems: jest.Mock; - close: jest.Mock; + mockStream: EventEmitter & { destroy: jest.Mock; cancel: jest.Mock }; } { - const getWorkItems = jest.fn().mockReturnValue(stream); - const close = jest.fn(); + const mockStream = new EventEmitter() as EventEmitter & { + destroy: jest.Mock; + cancel: jest.Mock; + }; + mockStream.destroy = jest.fn(); + mockStream.cancel = jest.fn(); + const stub = { - hello: ( - _request: Empty, - _metadata: grpc.Metadata, - _options: grpc.CallOptions, - callback: (error: grpc.ServiceError | null, response: Empty) => void, - ) => { - callback(null, new Empty()); - return { cancel: jest.fn() } as unknown as grpc.ClientUnaryCall; + hello: (_req: any, _metadata: any, _options: any, callback: (err: any, res: any) => void) => { + callback(null, {}); + return {} as any; }, - getWorkItems, - close, - } as unknown as stubs.TaskHubSidecarServiceClient; - - return { - client: { stub } as unknown as GrpcClient, - stream, - stub, - getWorkItems, - close, + getWorkItems: jest.fn().mockReturnValue(mockStream), }; + + const client = { stub } as unknown as GrpcClient; + return { client, mockStream }; } -async function flushPromises(): Promise { - for (let i = 0; i < 10; i++) { - await Promise.resolve(); - } +/** Flush the microtask / next-tick queue so async event handlers complete. */ +function flushAsync(): Promise { + return new Promise((resolve) => setImmediate(resolve)); } -describe("Worker stream recovery", () => { - beforeEach(() => { - jest.useFakeTimers(); +describe("Worker Stream Recovery", () => { + it("should retry connection after a stream error event", async () => { + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); + + // Prevent actual reconnection — just record that it was attempted + const retryMock = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retryMock; + + // Start the worker's internal run (sets up stream event handlers) + await worker.internalRunWorker(client); + + // Simulate a transport-level error with no subsequent "end" event + mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); + await flushAsync(); + + // The worker must clean up the stream and attempt to reconnect + expect(mockStream.destroy).toHaveBeenCalled(); + expect(retryMock).toHaveBeenCalledTimes(1); + }); + + it("should not retry when the worker is being stopped", async () => { + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); + + const retryMock = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retryMock; + + await worker.internalRunWorker(client); + + // Signal that the worker is shutting down + (worker as any)._stopWorker = true; + + mockStream.emit("error", new Error("1 CANCELLED")); + await flushAsync(); + + // During shutdown, errors are silently ignored — no retry + expect(retryMock).not.toHaveBeenCalled(); + expect(mockStream.destroy).not.toHaveBeenCalled(); + }); + + it("should remove all stream listeners during error recovery", async () => { + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); + + const retryMock = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retryMock; + + await worker.internalRunWorker(client); + + // Capture listener counts before error + const dataListenersBefore = mockStream.listenerCount("data"); + expect(dataListenersBefore).toBeGreaterThan(0); + + mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); + await flushAsync(); + + // After recovery, all original listeners should be removed + // (only a no-op error guard remains) + expect(mockStream.listenerCount("data")).toBe(0); + expect(mockStream.listenerCount("end")).toBe(0); + }); + + it("should not crash if a stale error event fires after recovery cleanup", async () => { + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); + + const retryMock = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retryMock; + + await worker.internalRunWorker(client); + + // First error triggers recovery + mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); + await flushAsync(); + + // A stale/duplicate error event must not throw (no-op handler remains) + expect(() => { + mockStream.emit("error", new Error("Stale error after cleanup")); + }).not.toThrow(); }); - afterEach(() => { - jest.useRealTimers(); - jest.restoreAllMocks(); + it("should recover via the end handler when end fires without error", async () => { + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); + + const retryMock = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retryMock; + + await worker.internalRunWorker(client); + + // Simulate a clean stream end (no error) + mockStream.emit("end"); + await flushAsync(); + + // The "end" handler should also trigger recovery + expect(mockStream.destroy).toHaveBeenCalled(); + expect(retryMock).toHaveBeenCalledTimes(1); }); - it("replaces a failed stream within the owned connection loop", async () => { - const initial = createMockClient(); - const replacement = createMockClient(); - jest.spyOn(GrpcClient.prototype as any, "_generateClient").mockReturnValue(replacement.stub); + it("should not crash if _createNewClientAndRetry rejects during error recovery", async () => { const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); - await worker.internalRunWorker(initial.client); - await flushPromises(); - initial.stream.emit("error", new Error("14 UNAVAILABLE")); - expect(() => initial.stream.emit("error", new Error("duplicate error"))).not.toThrow(); - await flushPromises(); + // Simulate a retry that throws — must not become an unhandled rejection + const retryMock = jest.fn().mockRejectedValue(new Error("Retry failed")); + (worker as any)._createNewClientAndRetry = retryMock; - expect(initial.stream.destroy).toHaveBeenCalledTimes(1); - expect(initial.close).toHaveBeenCalledTimes(1); + await worker.internalRunWorker(client); - await jest.advanceTimersByTimeAsync(2000); - await flushPromises(); + // Should not throw or cause unhandled promise rejection + mockStream.emit("error", new Error("14 UNAVAILABLE: Connection lost")); + await flushAsync(); - expect(replacement.getWorkItems).toHaveBeenCalledTimes(1); - expect((worker as any)._lifecycle.responseStream).toBe(replacement.stream); + expect(retryMock).toHaveBeenCalledTimes(1); + expect(mockStream.destroy).toHaveBeenCalled(); + }); - await worker.stop(); + it("should not crash if _createNewClientAndRetry rejects during end recovery", async () => { + const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); + + // Simulate a retry that throws — must not become an unhandled rejection + const retryMock = jest.fn().mockRejectedValue(new Error("Retry failed")); + (worker as any)._createNewClientAndRetry = retryMock; + + await worker.internalRunWorker(client); + + // Should not throw or cause unhandled promise rejection + mockStream.emit("end"); + await flushAsync(); + + expect(retryMock).toHaveBeenCalledTimes(1); + expect(mockStream.destroy).toHaveBeenCalled(); }); - it("does not reconnect or react to stale stream errors after stop", async () => { - const initial = createMockClient(); - const generateClient = jest.spyOn(GrpcClient.prototype as any, "_generateClient"); + it("should also add no-op error guard in end handler to prevent crashes after cleanup", async () => { const worker = new TaskHubGrpcWorker({ logger: new NoOpLogger() }); + const { client, mockStream } = createMockClient(); + + const retryMock = jest.fn().mockResolvedValue(undefined); + (worker as any)._createNewClientAndRetry = retryMock; + + await worker.internalRunWorker(client); - await worker.internalRunWorker(initial.client); - await flushPromises(); - await worker.stop(); + // End fires → cleanup removes all listeners + mockStream.emit("end"); + await flushAsync(); - expect(initial.stream.cancel).toHaveBeenCalledTimes(1); - expect(initial.stream.destroy).toHaveBeenCalledTimes(1); - expect(initial.close).toHaveBeenCalledTimes(1); - expect(generateClient).not.toHaveBeenCalled(); - expect(() => initial.stream.emit("error", new Error("stale error"))).not.toThrow(); + // A stale error after end cleanup must not crash + expect(() => { + mockStream.emit("error", new Error("Stale error after end cleanup")); + }).not.toThrow(); - await jest.advanceTimersByTimeAsync(30000); - expect(generateClient).not.toHaveBeenCalled(); + // The no-op guard should remain + expect(mockStream.listenerCount("error")).toBe(1); }); });