From 71db02cfa428035ed980e9bba0194384e2c25049 Mon Sep 17 00:00:00 2001 From: Copilot <223556219+Copilot@users.noreply.github.com> Date: Thu, 12 Mar 2026 19:32:50 +0000 Subject: [PATCH 1/2] fix: guard sub-orchestration completion handler against missing pending tasks Refactor handleSubOrchestrationCompleted to delegate to handleCompletedTask, matching the pattern used by handleSubOrchestrationFailed -> handleFailedTask and handleTaskCompleted -> handleCompletedTask. Before this fix, handleSubOrchestrationCompleted called ctx.resume() unconditionally, even when no matching pending task was found. This differs from handleCompletedTask (the activity completion handler), which correctly returns early with a warning log when no matching task exists. The unconditional resume() could advance the generator incorrectly if _previousTask happens to be complete from an unrelated event. Additionally, orphaned sub-orchestration completion events were silently dropped without any diagnostic logging, unlike the activity handler. This change: - Adds the missing guard clause (returns early when no task found) - Adds warning logging for unexpected events (via WorkerLogs) - Adds isEmpty normalization for empty results (consistent with activity handler) - Reduces code duplication by reusing handleCompletedTask Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/worker/orchestration-executor.ts | 24 ++++------------- .../test/orchestration_executor.spec.ts | 27 +++++++++++++++++++ 2 files changed, 32 insertions(+), 19 deletions(-) diff --git a/packages/durabletask-js/src/worker/orchestration-executor.ts b/packages/durabletask-js/src/worker/orchestration-executor.ts index 789d3e1..3d17d76 100644 --- a/packages/durabletask-js/src/worker/orchestration-executor.ts +++ b/packages/durabletask-js/src/worker/orchestration-executor.ts @@ -386,25 +386,11 @@ export class OrchestrationExecutor { } private async handleSubOrchestrationCompleted(ctx: RuntimeOrchestrationContext, event: pb.HistoryEvent): Promise { - const subOrchestrationInstanceCompletedEvent = event.getSuborchestrationinstancecompleted(); - const taskId = subOrchestrationInstanceCompletedEvent - ? subOrchestrationInstanceCompletedEvent.getTaskscheduledid() - : undefined; - - let subOrchTask; - - if (taskId !== undefined) { - subOrchTask = ctx._pendingTasks[taskId]; - delete ctx._pendingTasks[taskId]; - } - - const result = parseJsonField(subOrchestrationInstanceCompletedEvent?.getResult()); - - if (subOrchTask) { - subOrchTask.complete(result); - } - - await ctx.resume(); + const completedEvent = event.getSuborchestrationinstancecompleted(); + const taskId = completedEvent ? completedEvent.getTaskscheduledid() : undefined; + const result = completedEvent?.getResult(); + const normalizedResult = isEmpty(result) ? undefined : result; + await this.handleCompletedTask(ctx, taskId, normalizedResult, "subOrchestrationInstanceCompleted"); } private async handleSubOrchestrationFailed(ctx: RuntimeOrchestrationContext, event: pb.HistoryEvent): Promise { diff --git a/packages/durabletask-js/test/orchestration_executor.spec.ts b/packages/durabletask-js/test/orchestration_executor.spec.ts index 2783750..0ca29b6 100644 --- a/packages/durabletask-js/test/orchestration_executor.spec.ts +++ b/packages/durabletask-js/test/orchestration_executor.spec.ts @@ -570,6 +570,33 @@ describe("Orchestration Executor", () => { // assert user_code_statement in complete_action.failureDetails.stackTrace.value }); + it("should not advance the generator when a sub-orchestration completion event has no matching pending task", async () => { + const subOrchestrator = async (_: OrchestrationContext) => { + // do nothing + }; + const orchestrator: TOrchestrator = async function* (ctx: OrchestrationContext, _: any): any { + const res = yield ctx.callSubOrchestrator(subOrchestrator); + return res; + }; + const registry = new Registry(); + const subOrchestratorName = registry.addOrchestrator(subOrchestrator); + const orchestratorName = registry.addOrchestrator(orchestrator); + const oldEvents = [ + newOrchestratorStartedEvent(), + newExecutionStartedEvent(orchestratorName, TEST_INSTANCE_ID, undefined), + newSubOrchestrationCreatedEvent(1, subOrchestratorName, "sub-orch-123"), + ]; + // Send a completion event with a taskId (999) that does not match any pending task. + // Before the fix, this would call resume() unconditionally. After the fix, it returns + // early without advancing the generator, consistent with handleCompletedTask behavior. + const newEvents = [newSubOrchestrationCompletedEvent(999, JSON.stringify("unexpected"))]; + const executor = new OrchestrationExecutor(registry, testLogger); + const result = await executor.execute(TEST_INSTANCE_ID, oldEvents, newEvents); + // The orchestration should still be waiting for the real sub-orchestration to complete. + // No complete action should be produced. + expect(result.actions.length).toEqual(0); + }); + it("should test that an orchestration can wait for and process an external event sent by a client", async () => { const orchestrator: TOrchestrator = async function* (ctx: OrchestrationContext, _: any): any { const res = yield ctx.waitForExternalEvent("my_event"); From 95ceb0173289e1cc18daa9cd33028c8b390e136a Mon Sep 17 00:00:00 2001 From: wangbill Date: Mon, 16 Mar 2026 15:39:11 -0700 Subject: [PATCH 2/2] test: improve sub-orchestration guard test with structured log assertion Address Copilot review feedback: the previous test only checked that no actions were produced, which would pass with or without the fix since resume() is a no-op when _previousTask is incomplete. Now the test: - Uses a spy StructuredLogger to capture log events - Verifies orchestrationUnexpectedEvent (EVENT_ID 723) is emitted - Asserts the logged eventType and eventId match the orphan event - Renamed to accurately describe what is being verified This makes the test a meaningful validation of the guard clause path rather than just an assertion on a side effect that was already safe. --- .../test/orchestration_executor.spec.ts | 32 +++++++++++++++---- 1 file changed, 26 insertions(+), 6 deletions(-) diff --git a/packages/durabletask-js/test/orchestration_executor.spec.ts b/packages/durabletask-js/test/orchestration_executor.spec.ts index 0ca29b6..f1f0dba 100644 --- a/packages/durabletask-js/test/orchestration_executor.spec.ts +++ b/packages/durabletask-js/test/orchestration_executor.spec.ts @@ -23,7 +23,8 @@ import { OrchestrationExecutor, OrchestrationExecutionResult } from "../src/work import * as pb from "../src/proto/orchestrator_service_pb"; import { Registry } from "../src/worker/registry"; import { TOrchestrator } from "../src/types/orchestrator.type"; -import { NoOpLogger } from "../src/types/logger.type"; +import { NoOpLogger, StructuredLogger, LogEvent } from "../src/types/logger.type"; +import { EVENT_ORCHESTRATION_UNEXPECTED_EVENT } from "../src/worker/logs"; import { ActivityContext } from "../src/task/context/activity-context"; import { CompletableTask } from "../src/task/completable-task"; import { Task } from "../src/task/task"; @@ -570,7 +571,7 @@ describe("Orchestration Executor", () => { // assert user_code_statement in complete_action.failureDetails.stackTrace.value }); - it("should not advance the generator when a sub-orchestration completion event has no matching pending task", async () => { + it("should produce no actions and log a warning when sub-orchestration completion has unmatched taskId", async () => { const subOrchestrator = async (_: OrchestrationContext) => { // do nothing }; @@ -587,14 +588,33 @@ describe("Orchestration Executor", () => { newSubOrchestrationCreatedEvent(1, subOrchestratorName, "sub-orch-123"), ]; // Send a completion event with a taskId (999) that does not match any pending task. - // Before the fix, this would call resume() unconditionally. After the fix, it returns - // early without advancing the generator, consistent with handleCompletedTask behavior. const newEvents = [newSubOrchestrationCompletedEvent(999, JSON.stringify("unexpected"))]; - const executor = new OrchestrationExecutor(registry, testLogger); + + // Use a spy logger to verify the warning log is emitted via handleCompletedTask's guard clause + const loggedEvents: LogEvent[] = []; + const spyLogger: StructuredLogger = { + error: () => {}, + warn: () => {}, + info: () => {}, + debug: () => {}, + logEvent: (_level, event, _message) => { + loggedEvents.push(event); + }, + }; + + const executor = new OrchestrationExecutor(registry, spyLogger); const result = await executor.execute(TEST_INSTANCE_ID, oldEvents, newEvents); + // The orchestration should still be waiting for the real sub-orchestration to complete. - // No complete action should be produced. expect(result.actions.length).toEqual(0); + + // Verify the unexpected event warning was logged (proves the guard clause was hit) + const unexpectedEvents = loggedEvents.filter( + (e) => e.eventId === EVENT_ORCHESTRATION_UNEXPECTED_EVENT, + ); + expect(unexpectedEvents.length).toEqual(1); + expect(unexpectedEvents[0].properties?.eventType).toEqual("subOrchestrationInstanceCompleted"); + expect(unexpectedEvents[0].properties?.eventId).toEqual(999); }); it("should test that an orchestration can wait for and process an external event sent by a client", async () => {