Skip to content

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

Description

@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),

Activity

  1. mjlodge commented on Sep 20, 2026

    @mjlodge
    Author

    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.

  2. anthony-bennett commented on Sep 21, 2026

    @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).

  3. Sushisource commented on Sep 30, 2026

    @Sushisource
    Member

    We're focusing right now on providing proper time skipping support built-in to the real server, and as a result we're not prioritizing work on the Java test server. You can expect this functionality to be released within the next few months, at which point we'll deprecate the Java server.

  4. mjlodge commented on Oct 1, 2026

    @mjlodge
    Author

    Thanks for the candid update. Obviously was hoping for something sooner (we have quarantined the failing time-skipping tests because they cause too many deploy failures), but good to know that time skipping is coming to the real server.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    test serverRelated to the test server

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions