Skipped mutableSideEffect leaks an empty RecordMarker command after a full replay, and the workflow task fails on every retry #3163

Expected Behavior

A Workflow.mutableSideEffect call whose comparator says "unchanged" records nothing. Replaying a history that contains such a call produces the same commands as the original execution.

Actual Behavior

After a full replay, the worker can send a COMMAND_TYPE_RECORD_MARKER whose RecordMarkerCommandAttributes are completely empty: no marker_name and no details. The server rejects that completion:

• Test server (temporal-testing 1.40.0): INVALID_ARGUMENT: marker name is required, from TestWorkflowMutableStateImpl.processRecordMarker.
• Real server (temporal server start-dev, CLI 1.8.3, server 1.31.2): the workflow task fails with
  WORKFLOW_TASK_FAILED_CAUSE_BAD_RECORD_MARKER_ATTRIBUTES, "BadRecordMarkerAttributes: MarkerName is not set on
  RecordMarkerCommand." The validator is CommandAttrValidator.ValidateRecordMarkerAttributes.

Every retry is again a full replay of the same history, so it produces the same bad command. Against the dev server, 30 seconds after the first failure the execution was still running and the pending workflow task was on attempt 4, every attempt failing the same way. On the time-skipping test server time also stops advancing, so tests hang instead of failing.

These are the commands from a captured rejected RespondWorkflowTaskCompletedRequest. The second one is the accept for an update the task was delivering:

commands {
  command_type: COMMAND_TYPE_RECORD_MARKER
  record_marker_command_attributes {
  }
}
commands {
  command_type: COMMAND_TYPE_PROTOCOL_MESSAGE
  protocol_message_command_attributes {
    message_id: "edc1dddd-.../request/accept"
  }
}

Root cause (as far as we can tell from the 1.40.0 source)

io.temporal.internal.statemachines.MutableSideEffectStateMachine.InvocationStateMachine behaves differently while executing and while replaying:

• Executing. createMarker() sees that the function returned empty (a skip). It adds StateMachineCommandUtils.RECORD_MARKER_FAKE_COMMAND, which is RecordMarkerCommandAttributes.getDefaultInstance(), and moves to SKIPPED. When WorkflowStateMachines.prepareImpl() handles the command, SKIPPED --RECORD_MARKER--> SKIPPED_NOTIFIED calls cancelCommandNotifyCachedResult(). The fake is cancelled immediately and never sent.
• Replaying. createFakeCommand() adds the same fake command. On the RECORD_MARKER command handling it moves MARKER_COMMAND_CREATED_REPLAYING -> RESULT_NOTIFIED_REPLAYING, which is not cancelled. From there it is cancelled only by NON_MATCHING_EVENT, inside handleEvent(), and handleEvent() is reached only from WorkflowStateMachines.handleCommandEvent() when a later command event is matched against the queue head.

A skipped call writes no marker. So if the workflow task that made the skipped call emitted no other commands, history after its WorkflowTaskCompleted has no command events. Nothing ever calls handleEvent() on the fake, and it stays uncancelled in WorkflowStateMachines.commands, which is only drained by handleCommandEvent.

Replay then reaches the current task, replaying becomes false, and WorkflowStateMachines.takeCommands() returns every uncancelled entry, the leaked fake included. It goes out ahead of the task's real commands.

The trigger needs all of these:

1. A full replay: sticky cache miss, eviction, or worker restart.
2. The last completed workflow task before the current one called mutableSideEffect with an unchanged value.
3. That task produced no commands. For example: a loop pass that reads a setting and then blocks in Workflow.await(condition) with no timer.

Any later command event cancels the fake, which is why this is easy to miss. Only the last completed task matters.

A possible fix

WorkflowTaskCommandsListener.workflowTaskStarted already calls handleWorkflowTaskStarted() on every queued command. During replay it fires from WorkflowTaskStateMachine.handleCompleted(), at the next task's WorkflowTaskCompleted, so by then every command event of the previous task has been applied. A mutableSideEffect fake still in RESULT_NOTIFIED_REPLAYING at that point can only belong to a skipped call.

In that state the cached result has not been delivered yet either, so the fix has to notify as well as cancel. The existing NON_MATCHING_EVENT transition does both:

// MutableSideEffectStateMachine.InvocationStateMachine
@Override
public void handleWorkflowTaskStarted() {
  if (getState() == State.RESULT_NOTIFIED_REPLAYING) {
    explicitEvent(ExplicitEvent.NON_MATCHING_EVENT);
  }
}

We tried this locally by putting a patched copy of the class on the test classpath:

• the repro below passes;
• our own workflow's test suite passes with the patch and with skipping comparators.

We have not run the SDK's own test suite against it.

Steps to Reproduce the Problem

The test fails every time on the time-skipping test server. The same workflow fails against a real dev server too, pointed at it with setUseExternalService(true) and setTarget(...). A cache eviction stands in for a worker restart, and the eviction goes through reflection because WorkerFactory.getCache() is package-private.

@WorkflowInterface
public interface ProbeWorkflow {
  @WorkflowMethod
  long run();

  @SignalMethod
  void poke();
}

public static class ProbeWorkflowImpl implements ProbeWorkflow {
  private long pokes;

  @Override
  public long run() {
    long seen = 0;
    while (seen < 2) {
      // Same value every time: recorded on the first call, skipped afterwards.
      Workflow.mutableSideEffect("k", Long.class, (a, b) -> !a.equals(b), () -> 1L);
      long s = seen;
      Workflow.await(() -> pokes != s); // no timer: this task emits no commands
      seen = pokes;
    }
    return seen;
  }

  @Override
  public void poke() {
    pokes++;
  }
}

@Test
public void skippedMutableSideEffectSurvivesFullReplay() throws Exception {
  TestWorkflowEnvironment env = TestWorkflowEnvironment.newInstance();
  try {
    env.newWorker("probe").registerWorkflowImplementationTypes(ProbeWorkflowImpl.class);
    env.start();
    ProbeWorkflow stub =
        env.getWorkflowClient()
            .newWorkflowStub(
                ProbeWorkflow.class,
                WorkflowOptions.newBuilder().setTaskQueue("probe").setWorkflowId("probe").build());
    WorkflowClient.start(stub::run);
    Thread.sleep(500);
    stub.poke(); // task 2: mutableSideEffect skipped, no commands
    Thread.sleep(500);

    // Simulate a worker restart: the next task is a full replay.
    Method getCache = WorkerFactory.class.getDeclaredMethod("getCache");
    getCache.setAccessible(true);
    Object cache = getCache.invoke(env.getWorkerFactory());
    cache.getClass().getMethod("invalidateAll").invoke(cache);

    stub.poke(); // task 3: replay leaks task 2's fake marker
    long result =
        WorkflowStub.fromTyped(stub).getResultAsync(Long.class).get(10, TimeUnit.SECONDS);
    assertEquals(2L, result); // TimeoutException; the worker logs "marker name is required"
  } finally {
    env.close();
  }
}

The worker logs:

WARN  i.t.internal.worker.WorkflowWorker - Failure while reporting workflow progress to the server. ...
io.grpc.StatusRuntimeException: INVALID_ARGUMENT: marker name is required
	at ...WorkflowServiceBlockingStub.respondWorkflowTaskCompleted(...)

Two cheap ways to confirm the cause:

• Return a value from the function so the call never skips, for example comparator (a, b) -> true. The test then passes.
• Add a timer (Workflow.await(Duration, condition)), so the task has a command event to cancel the fake. The test also passes.

Workaround

Never let mutableSideEffect skip: pass an updated comparator that always returns true, so every call records a marker. In replay mode the comparator is not consulted, so this is replay-compatible in both directions with histories written while values were skipped. We checked this with WorkflowReplayer. The cost is one MarkerRecorded event per call.

This does not help an execution whose last completed task was written by code that skipped. Such an execution still fails on its next full replay.

Related

• Subsequent MutableSideEffect calls inside one Workflow Task may explode with non-determinism on replay #1668: "Subsequent MutableSideEffect calls inside one Workflow Task may explode with non-determinism on replay". It is the same state machine, and the same skipped-versus-recorded asymmetry during replay. The symptom differs: there, a recorded marker is matched to the wrong call (non-determinism); here, a skipped call's fake command is never matched at all.

Specifications

• Version: temporal-sdk / temporal-testing 1.40.0, the latest release. Nothing since v1.40.0 on main touches MutableSideEffectStateMachine.
• Platform: macOS, OpenJDK 21.0.12. Our workflow is Kotlin 2.4.10; the repro above is plain Java.
• How we found it: an intermittent hang in a full test suite on the time-skipping test server. We saw full replays there both after UnhandledCommand rejections and without one.