Fix history replayer #990

Quinn-With-Two-Ns · 2022-12-30T20:56:12Z

Fix a few bugs causing false positives and false negatives when replay histories

Remove protobuf json binary comparisons because they are not deterministic
Check history during a replay even if the workflow is complete
Remove dead code around strictMode

Note on backwards compatibility: This PR will cause some histories to fail the replayer that didn't use to, but they always should have so I don't consider this a breaking change, just a bug. It could also cause some histories to pass that used to fail if the non determinism was from the workflow execution complete payload. I tried hard to preserve the error message of any workflow that would have failed before

resolves: #983, #876 and #978

Quinn-With-Two-Ns · 2022-12-30T23:14:48Z

internal/internal_task_handlers.go

@@ -1197,8 +1203,16 @@ func skipDeterministicCheckForEvent(e *historypb.HistoryEvent) bool {
 		if markerName == versionMarkerName || markerName == mutableSideEffectMarkerName {
 			return true
 		}
-		// case enumspb.EVENT_TYPE_WORKFLOW_TASK_STARTED:
-		//	return true
+	case enumspb.EVENT_TYPE_WORKFLOW_EXECUTION_COMPLETED:


These result of a workflow execution is handled after we check the history so these will never be in the replayed history. The replayer already checks for for completed and continue as new outside the state machine.

Hrmm, so before this was never called for these events anyways because we never did deterministic checks at the completed stage? How does "activity task timed out" play into this? I can't think of any harm in skipping more so this seems safe to me.

Yeah we would never check these before.

How does "activity task timed out" play into this

Oh that shouldn't, should be workflow task time out

Quinn-With-Two-Ns · 2022-12-30T23:15:12Z

internal/internal_task_handlers.go

@@ -1273,7 +1287,7 @@ func lastPartOfName(name string) string {
 	return name[lastDotIdx+1:]
 }

-func isCommandMatchEvent(d *commandpb.Command, e *historypb.HistoryEvent, strictMode bool) bool {
+func isCommandMatchEvent(d *commandpb.Command, e *historypb.HistoryEvent) bool {


This strictMode flag was never used and wouldn't work if the go version was changed

Quinn-With-Two-Ns · 2022-12-30T23:19:39Z

internal/internal_worker_test.go

@@ -1308,49 +1300,6 @@ func (s *internalWorkerTestSuite) TestReplayWorkflowHistory_CancelWorkflowWhileS
 	require.NoError(s.T(), err)
 }

-func (s *internalWorkerTestSuite) TestReplayWorkflowHistory_LocalActivity_Result_Mismatch() {


A different payload will no longer cause the history to be non deterministic

Hrmm, so we are removing functionality? Can you give some background here?

Quinn-With-Two-Ns · 2023-01-02T18:34:41Z

test/fixtures/activity.cancel.sm.repro.json

-        "workflowTaskTimeout": "1s",
-        "identity": "97228@samar-C02XG22GJGH6@"
-      }
+ "events": [


Regenerated this history because it failed the replayer for two reasons

The activities name are wrong, this just seems like an issue with the history

The history was missing multiple events, I think because the history came from a WF that timed out. Unclear if that was intentional. Even if it was intentional it is not obvious this history should pass the replayer since the replayed history will not match the history file.

cretz · 2023-01-03T16:55:26Z

internal/internal_task_handlers.go

@@ -877,7 +883,7 @@ ProcessEvents:
 				if err != nil {
 					return nil, err
 				}
-				if w.isWorkflowCompleted {
+				if w.isWorkflowCompleted && !shouldForceReplayCheck() {


What is the harm of breaking out of the events here always? Why do we need to continue to process events after workflow completed? Wouldn't the presence/absence of a "completed command" in history vs not be enough trigger the non-determinism check?

not sure what you mean by a "completed command" can you elaborate?

The problem with breaking out is described here #983, basically if we break we skip populating the replayCommands list and that is a important part of checking if a replay was deterministic.

Hrmm, ok. I was expecting that if we skip populating replay commands then this workflow would add a workflow completed command and inside the replayer that would mismatch with the next event not being a complete command. But I think this works too. And we're pretty sure it's isolated only to the replayer.

But if this change is only for replayer and only applies to a completed workflow, I think we're good.

The break would also causes false negatives if activities are removed from a workflow because we would break before processing the event. I made a test for this called TestBadEmptyWorkflow that is an extreme case.

I was expecting that if we skip populating replay commands then this workflow would add a workflow completed command and inside the replayer that would mismatch with the next event not being a complete command

Ah here is the thing, where would it mismatch with the next event? In the replayer (I assume you mean WorkflowReplayer ) we only check the last event in the history is a workflow completed event

cretz · 2023-01-03T17:18:54Z

internal/internal_task_handlers.go

@@ -1197,8 +1203,16 @@ func skipDeterministicCheckForEvent(e *historypb.HistoryEvent) bool {
 		if markerName == versionMarkerName || markerName == mutableSideEffectMarkerName {
 			return true
 		}
-		// case enumspb.EVENT_TYPE_WORKFLOW_TASK_STARTED:
-		//	return true
+	case enumspb.EVENT_TYPE_WORKFLOW_EXECUTION_COMPLETED:


Hrmm, so before this was never called for these events anyways because we never did deterministic checks at the completed stage? How does "activity task timed out" play into this? I can't think of any harm in skipping more so this seems safe to me.

cretz · 2023-01-03T18:01:33Z

internal/internal_worker.go

@@ -1286,20 +1289,12 @@ func (aw *WorkflowReplayer) replayWorkflowHistory(logger log.Logger, service wor
 			for _, d := range completeReq.Commands {
 				if d.GetCommandType() == enumspb.COMMAND_TYPE_CONTINUE_AS_NEW_WORKFLOW_EXECUTION {
 					if last.GetEventType() == enumspb.EVENT_TYPE_WORKFLOW_EXECUTION_CONTINUED_AS_NEW {
-						inputA := d.GetContinueAsNewWorkflowExecutionCommandAttributes().GetInput()


Can you help me understand this removal? Before we didn't return if not equal, now we always do?

I removed it based on the conversation we had here #978 we said

"we need to stop using payload comparison anyways. I don't believe we need to check input/output data"

Hrmm, I may have been thinking more activities and child workflows and such inside the workflow replay check instead of the replayer. But this might be ok. Let me bring it up in Slack to get others' opinions.

We can try to keep this, but we can't leave it in its current form because the binary comparison is not reliable.

Conferred, good to remove!

cretz · 2023-01-03T18:02:26Z

internal/internal_worker_test.go

@@ -1308,49 +1300,6 @@ func (s *internalWorkerTestSuite) TestReplayWorkflowHistory_CancelWorkflowWhileS
 	require.NoError(s.T(), err)
 }

-func (s *internalWorkerTestSuite) TestReplayWorkflowHistory_LocalActivity_Result_Mismatch() {


Hrmm, so we are removing functionality? Can you give some background here?

cretz

LGTM. I can't find anything that would break workflows today, only replayers. That's the biggest concern to check for I think.

Sushisource · 2023-01-04T17:38:15Z

internal/internal_task_handlers.go

+	shouldForceReplayCheck := func() bool {
+		isInReplayer := IsReplayNamespace(w.wth.namespace)
+		// If we are in the replayer we should always check the history replay, even if the workflow is completed
+		// Skip if the workflow paniced to avoid potentially breaking old histories


Suggested change

// Skip if the workflow paniced to avoid potentially breaking old histories

// Skip if the workflow panicked to avoid potentially breaking old histories

Sushisource

This makes sense to me. 🙏 for the day we can move this to be on top of core.

* Remove protobuf binary comparisons because they are not deterministic * Check histroy during a replay even if the workflow is complete * Remove dead code around strictMode

change to EVENT_TYPE_WORKFLOW_EXECUTION_TIMED_OUT

Quinn-With-Two-Ns force-pushed the replayer branch from 923a027 to 64701b9 Compare December 30, 2022 21:55

Quinn-With-Two-Ns commented Dec 30, 2022

View reviewed changes

Quinn-With-Two-Ns marked this pull request as ready for review December 30, 2022 23:21

Quinn-With-Two-Ns requested a review from a team as a code owner December 30, 2022 23:21

Quinn-With-Two-Ns commented Jan 2, 2023

View reviewed changes

Quinn-With-Two-Ns requested review from bergundy and cretz January 3, 2023 15:38

cretz reviewed Jan 3, 2023

View reviewed changes

cretz approved these changes Jan 3, 2023

View reviewed changes

Sushisource reviewed Jan 4, 2023

View reviewed changes

Sushisource approved these changes Jan 4, 2023

View reviewed changes

Quinn-With-Two-Ns added 3 commits January 4, 2023 13:12

Fix history replayer

4830b27

* Remove protobuf binary comparisons because they are not deterministic * Check histroy during a replay even if the workflow is complete * Remove dead code around strictMode

Fix skipDeterministicCheckForEvent

1691ead

change to EVENT_TYPE_WORKFLOW_EXECUTION_TIMED_OUT

Fix comment

4bcd0d3

Quinn-With-Two-Ns force-pushed the replayer branch from a00a0b8 to 4bcd0d3 Compare January 4, 2023 21:12

Quinn-With-Two-Ns merged commit 6f4d14f into temporalio:master Jan 4, 2023

Quinn-With-Two-Ns mentioned this pull request Jan 30, 2023

Replay results inconsistent between Go versions #978

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix history replayer #990

Fix history replayer #990

Quinn-With-Two-Ns commented Dec 30, 2022 •

edited

Loading

Quinn-With-Two-Ns Dec 30, 2022

cretz Jan 3, 2023

Quinn-With-Two-Ns Jan 3, 2023

Quinn-With-Two-Ns Dec 30, 2022

Quinn-With-Two-Ns Dec 30, 2022

cretz Jan 3, 2023

Quinn-With-Two-Ns Jan 2, 2023 •

edited

Loading

cretz Jan 3, 2023

Quinn-With-Two-Ns Jan 3, 2023

cretz Jan 3, 2023

Quinn-With-Two-Ns Jan 3, 2023

Quinn-With-Two-Ns Jan 3, 2023

cretz Jan 3, 2023

cretz Jan 3, 2023

Quinn-With-Two-Ns Jan 3, 2023

cretz Jan 3, 2023

Quinn-With-Two-Ns Jan 3, 2023

cretz Jan 3, 2023

cretz Jan 3, 2023

cretz left a comment

Sushisource Jan 4, 2023

Sushisource left a comment

	// Skip if the workflow paniced to avoid potentially breaking old histories
	// Skip if the workflow panicked to avoid potentially breaking old histories

Fix history replayer #990

Fix history replayer #990

Conversation

Quinn-With-Two-Ns commented Dec 30, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Quinn-With-Two-Ns Jan 2, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

cretz left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Sushisource left a comment

Choose a reason for hiding this comment

Quinn-With-Two-Ns commented Dec 30, 2022 •

edited

Loading

Quinn-With-Two-Ns Jan 2, 2023 •

edited

Loading