Test server: refused CancelTimer leaves the workflow task complete in memory but STARTED in history, so it is never timed out or redelivered

[mjlodge]

Expected Behavior

When RespondWorkflowTaskCompleted is refused because a command is invalid, the workflow task should be failed (WorkflowTaskFailed in history) and rescheduled, so the worker can replay and continue, which is what the real Temporal server does (for a cancel of an unknown timer it fails the task with BAD_CANCEL_TIMER_ATTRIBUTES; for a cancel of a timer whose TimerFired is still buffered, it drops the buffered fire and records TimerCanceled).

At minimum, a refused completion should leave the task in a state its own start-to-close timeout can act on.

Actual Behavior

A completion carrying a CancelTimer for a timer id the server no longer holds in its in-memory timers map is refused by TestWorkflowMutableStateImpl.processCancelTimer with:

code: INVALID_ARGUMENT, message: "invalid history builder state for action"

After that refusal the run never receives another workflow task. History ends

... TimerStarted -> WorkflowExecutionSignaled -> WorkflowTaskScheduled -> WorkflowTaskStarted

and stays there: no WorkflowTaskFailed, no WorkflowTaskTimedOut (the workflow's workflowTaskTimeout was 60 s; we observed 88 s with no event), no redelivery. sdk-core logs WARN Error while completing workflow activation and evicts the run; its subsequent polls return nothing. The workflow stays RUNNING forever.

From the source, the cause is the order of operations inside completeWorkflowTask's update(...):

workflowTaskStateMachine.action(StateMachines.Action.COMPLETE, ctx, request, 0);
for (Command command : commands) { processCommand(...); }

StateMachine.action assigns state immediately. When processCancelTimer throws, update rethrows and the RequestContext is discarded, but the state machine stays at NONE; nothing rolls it back. timeoutWorkflowTask then returns early on workflowTaskStateMachine.getState() == State.NONE, so the start-to-close timeout never produces WorkflowTaskTimedOut, and nothing schedules a new task. The same non-transactional pattern exists in fireTimer (timers.remove(timerId) inside the update lambda) and in processCancelTimer itself.

We could not establish from our side why the timer id was missing: it had been started by the immediately preceding completion 16 ms earlier, was one hour long, and the server's clock (read via getCurrentTime at the end of the test) had not jumped. The server cannot tell us either: the bundled binary carries no slf4j binding (logback-classic is testRuntimeOnly in temporal-test-server/build.gradle), so log.error("Failure firing a timer") and friends go to the NOP logger and nothing reaches stderr.

Related: #2127 (signal handling around the first WFT on the test server), #1377 (predictable log output from the test server).

Steps to Reproduce the Problem

We do not have a deterministic reproduction; it recurs at a low rate in CI. The shape that triggers it:

1. Start the time-skipping test server (TestWorkflowEnvironment.createTimeSkipping from the TypeScript SDK) and a workflow whose loop re-arms a condition(..., timeout) timer on every turn (workflow task timeout 60 s).
2. From the test, unlockTimeSkippingWithSleep for 2 days; the run processes ~48 hourly timers during the skip, sends a message via an activity, and its next dMarker x5, StartTimer(50)]`.
3. Immediately after that completion (history shows TimerStarted -> WorkflowExecutionSignaled +1ms), signal the workflow. The worker answers the signal's taskelTimer(50), RecordMarker,ScheduleActivityTask, ScheduleActivityTask]`.
4. The server refuses it as above; the run is stranded.

sdk-core DEBUG trace from the failing run (comevent ids, e.g. the refused task wasHistoryUpdate(previous_started_event_id: 646, started_id: 656, length: 10)) is available on request.

Suggested fixes:

1. Perform the workflow-task state-machine transition after the commands validate, or roll it back when a completion is refused, so a refused task stays STARTED and its timeout (or a WorkflowTaskFailed) redelivers it.
2. Treat CancelTimer for an already-fired-but-unseen timer the way the real server does (drop the buffered TimerFired, record TimerCanceled).
3. Ship a logging binding in the test-server binary, or route the test service's log.error to stderr, so a refused completion is diagnosable.

Specifications

• Version: temporal-test-server-sdk-typescrnloaded by @temporalio/testing1.16.1); the code paths above are unchanged onmaster` as of 2026-09-17
• Platform: observed on GitHub Actions `ubun; the same sequence passes 25/25 locally on macOS 15 (Apple Silicon), so it is timing-dependent
• Client: TypeScript SDK 1.16.1 (sdk-core),

[mjlodge]

Reporting a second hang we hit in the same area, on the chance it shares a root cause with this one. It is not this bug — no rejected completion is involved and nothing throws — but it is the same "state mutated before the operation is known to have succeeded" shape, so it may be worth one investigation rather than two. Happy to open it separately if you'd rather keep this issue narrow.

Environment: @temporalio/testing 1.24.0, bundled time-skipping test server, TypeScript SDK.

Shape

await workflow.terminate("...");   // a run with a WFT *and* an activity in flight
await testEnv.sleep("6 hours");    // test-environment skip, not a workflow timer

Observed. The skip succeeds — it is not a wedge — but consumes real time roughly proportional to the amount skipped:
clock: virtual +21691171ms, real +359494ms, asked +21600000ms, unexplained -268323ms
The full six hours of virtual time advanced, ~359s of wall clock elapsed, and the server's own clock lost ~268s that neither accounts for. Two core WARNs land at the terminate, both the worker answering for the run just killed: Activity not found on completion … Completed workflow and Task not found when completing … Completed workflow.

What rules out #3088's path. No invalid history builder state for action (grepped explicitly, zero across three sightings), no Error while completing workflow activation, no eviction — and the run doesn't hang forever; virtual time reaches the target and the test proceeds if the timeout is raised. That's the opposite of this issue's signature.

Hypothesis (unverified). Terminating a run with a WFT and activity in flight leaves a time-skipping lock unreleased, or the unlock-with-sleep RPC blocks behind the mutable-state lock for the terminated run, so time skipping silently degrades to real time until the in-flight work drains. The suspected shared root is the ordering property, not the symptom.

Frequency. ~1 run in 5 locally (182s vs a normal 10–15s), so below our timeout and invisible except under CI's slower workers — three failures in three days on unrelated changes, clearing on rerun each time.

[anthony-bennett]

We have been encountering a very similar issue - it looks like @mjlodge has taken it further down to the actual cause. Our issue occurs within RequestCancelActivityTask, and results in the same impact - the test server wedges, and the entire test server will hang.

Environment: We have replicated 1.24.0 of sdk-python, running on both MacOS arm64 and Linux containers (x86_64).