Random Non-Deterministic exception

[TurakKatase]

While executing a certain orchestration, the following error will randomly appear:

Unhandled exception while executing orchestration: DurableTask.Core.Exceptions.NonDeterministicOrchestrationException: Non-Deterministic workflow detected: A previous execution of this orchestration scheduled a timer task with sequence number 2 named but the current orchestration replay instead produced a ScheduleTaskOrchestratorAction action with this sequence number. Was a change made to the orchestrator code after this instance had already started running?

The code isn't changing during execution. It shouldn't even be triggering a timer. No timers are created in this orchestration. Yet they're being created for unknown reasons. I've attached an export from the history table for the orchestration in question. I've replaced the return values from ConfirmAssetMetadata since it contains sensitive information.

TaskHubSlot2History.csv

This history doesn't make any sense to me. ConfirmAssetMetadata should only fire once, then move on to GetWriterConfig. I could see timers being created if ConfirmAssetMetadata failed, but the result column value is valid.

Any suggestions on how to debug this issue? I've never been able to reproduce it locally, but it happens in prod frequently enough to be a problem.

[TurakKatase]

Also, sometimes it's the other way around, where a later run tries to create a timer when it shouldn't:

Unhandled exception while executing orchestration: DurableTask.Core.Exceptions.NonDeterministicOrchestrationException: Non-Deterministic workflow detected: A previous execution of this orchestration scheduled an activity task with sequence number 2 named 'GetWriterConfig', but the current orchestration replay instead produced a CreateTimerOrchestratorAction action with this sequence number. Was a change made to the orchestrator code after this instance had already started running?

Second example.csv

But the one thing is that it's consistently sequence number 2.

[TurakKatase]

I found the root cause after accidently reproducing the issue. It was indeed a non deterministic error, but a stranger one than I suspect the authors of durable functions anticipated.

The problem occurs when durable functions is unable to deserialize the json response from an activity. The reason this happens and appeared to be random is that a dll needed to deserialize the response isn't loaded properly at the time of playback if the orchestration is the first to run in a new process. It's dynamically loaded earlier in the flow, making the entire thing technically non-deterministic. I'll need to take find a better way to ensure the needed dlls are all loaded in time for the orchestration.

So my main feedback for the team would be that it would be nice if the non-deterministic errors could have some different phrasing when implicit timers via retries are involved. The only reason I knew to look at failures and retries was another issue or discussion I found while looking for help.

[davidmrdavid]

Hi @TurakKatase, thanks for reaching out. Hmm, this is a strange one. Can you please provide me with more details and/or evidence of this dll-loading issue? Is this a dll that your app is providing, or is this something internal to Durable Functions? The more detail, the better! Thank you :)

[TurakKatase]

This is a dll that my app provides. These dlls are loaded dynamically when needed in various activities. They then stay loaded for the lifetime of the application.

The problem here is that the return type for an activity is contained within that dll that's loaded at runtime. So if it hasn't been loaded yet, an exception occurs when the orchstration playback tries to deserialize the previously run activity. There are a large number of activities and orchestrations, most of which can ensure the needed dll is loaded before trying to use it.

From what I can tell, the non-deterministic error comes from the fact that the playback mechanism expected the activity to succeed, meaning that the next task in the sequence is the next activity.

Original run:
Activity 1
Activity 2
Activity 3
Activity 4 (Orchestration was unloaded from memory at this point, application was restarted, etc)

Orchestration playback later starts in new process (after restart, scale out occured, etc):
Playback Activity 1
Playback Activity 2 (Fails to deserialize previous result, triggering a retry)
Schedule Timer activity for retry (Throws non-deterministic exception because it expected Activity 3)

My current plan is to ensure that the type from the dynamically loaded dll isn't used as a return value from an activity. The orchestration must be deterministic and the use of a type from a dynamically loaded dll is very non-deterministic.

[davidmrdavid]

Thanks @TurakKatase, that gives me the context I needed. Indeed, dynamically loading dlls isn't determinism safe as it is a kind of IO operation, and IO is generally forbidden in orchestrators.

I'll think about ways to improve this error message, although it's difficult to track the notion of "implicit" retries at the level where this exception is thrown. In any case, glad to hear you found the root cause, and I'll keep this case in mind when reviewing our error messages.