diff --git a/src/DurableTask.Core/Logging/LogEvents.cs b/src/DurableTask.Core/Logging/LogEvents.cs index 612e2664f..fd626d3be 100644 --- a/src/DurableTask.Core/Logging/LogEvents.cs +++ b/src/DurableTask.Core/Logging/LogEvents.cs @@ -632,7 +632,7 @@ void IEventSourceEvent.WriteEventSource() => StructuredEventSource.Log.TerminatingInstance( this.InstanceId, this.ExecutionId, - this.Details, + Details: $"(Redacted {this.Details?.Length ?? 0} characters)", // User-provided details may contain sensitive data, so we don't log it. Utils.AppName, Utils.PackageVersion); } @@ -668,7 +668,7 @@ void IEventSourceEvent.WriteEventSource() => StructuredEventSource.Log.SuspendingInstance( this.InstanceId, this.ExecutionId, - this.Details, + Details: $"(Redacted {this.Details?.Length ?? 0} characters)", // User-provided details may contain sensitive data, so we don't log it. Utils.AppName, Utils.PackageVersion); } @@ -704,7 +704,7 @@ void IEventSourceEvent.WriteEventSource() => StructuredEventSource.Log.ResumingInstance( this.InstanceId, this.ExecutionId, - this.Details, + Details: $"(Redacted {this.Details?.Length ?? 0} characters)", // User-provided details may contain sensitive data, so we don't log it. Utils.AppName, Utils.PackageVersion); } @@ -1045,15 +1045,21 @@ void IEventSourceEvent.WriteEventSource() => /// internal class OrchestrationCompleted : StructuredLogEvent, IEventSourceEvent { +#nullable enable + readonly Exception? exception; + public OrchestrationCompleted( OrchestrationRuntimeState runtimeState, OrchestrationCompleteOrchestratorAction action) { - this.InstanceId = runtimeState.OrchestrationInstance.InstanceId; + this.InstanceId = runtimeState.OrchestrationInstance!.InstanceId; this.ExecutionId = runtimeState.OrchestrationInstance.ExecutionId; this.RuntimeStatus = action.OrchestrationStatus.ToString(); - this.Details = action.Details; this.SizeInBytes = Encoding.UTF8.GetByteCount(action.Result ?? string.Empty); + + Exception? exception = runtimeState.Exception; + this.exception = exception; + this.Details = action.Details ?? string.Empty; } [StructuredLogField] @@ -1085,11 +1091,12 @@ void IEventSourceEvent.WriteEventSource() => this.InstanceId, this.ExecutionId, this.RuntimeStatus, - this.Details, + this.exception != null ? LogHelper.GetRedactedExceptionDetails(this.exception) : string.Empty, this.SizeInBytes, Utils.AppName, Utils.PackageVersion); } +#nullable disable /// /// Log event representing an orchestration aborted event, which can happen if the host is shutting down. @@ -1494,6 +1501,7 @@ void IEventSourceEvent.WriteEventSource() => internal class TaskActivityFailure : StructuredLogEvent, IEventSourceEvent { +#nullable enable readonly Exception exception; public TaskActivityFailure( @@ -1506,8 +1514,8 @@ public TaskActivityFailure( this.ExecutionId = instance.ExecutionId; this.Name = name; this.TaskEventId = taskEvent.EventId; - this.Details = exception.ToString(); this.exception = exception; + this.Details = exception.ToString(); } [StructuredLogField] @@ -1540,10 +1548,11 @@ void IEventSourceEvent.WriteEventSource() => this.ExecutionId, this.Name, this.TaskEventId, - Utils.RedactUserCodeExceptions ? LogHelper.GetRedactedExceptionDetails(this.exception) : this.Details, // We have to be extra guarded about logging user exceptions to EventSource (ETW) + LogHelper.GetRedactedExceptionDetails(this.exception), Utils.AppName, Utils.PackageVersion); } +#nullable disable internal class TaskActivityAborted : StructuredLogEvent, IEventSourceEvent { diff --git a/src/DurableTask.Core/OrchestrationRuntimeState.cs b/src/DurableTask.Core/OrchestrationRuntimeState.cs index f4e61afd4..494071dbd 100644 --- a/src/DurableTask.Core/OrchestrationRuntimeState.cs +++ b/src/DurableTask.Core/OrchestrationRuntimeState.cs @@ -134,6 +134,14 @@ public ExecutionStartedEvent? ExecutionStartedEvent /// public FailureDetails? FailureDetails => ExecutionCompletedEvent?.FailureDetails; + /// + /// Failure that caused an orchestrator to complete, if any. + /// + /// + /// This property was introduced to sanitize exceptions during logging. See it's usage in . + /// + internal Exception? Exception { get; set; } + /// /// Gets the orchestration name from the ExecutionStartedEvent /// diff --git a/src/DurableTask.Core/TaskOrchestrationContext.cs b/src/DurableTask.Core/TaskOrchestrationContext.cs index 3b2d5a797..8a48cbe93 100644 --- a/src/DurableTask.Core/TaskOrchestrationContext.cs +++ b/src/DurableTask.Core/TaskOrchestrationContext.cs @@ -203,7 +203,7 @@ public override void SendEvent(OrchestrationInstance orchestrationInstance, stri int id = this.idCounter++; - string serializedEventData = this.MessageDataConverter.SerializeInternal(eventData); + string serializedEventData = this.MessageDataConverter.SerializeInternal(eventData); var action = new SendEventOrchestratorAction { @@ -503,7 +503,7 @@ public void HandleSubOrchestrationInstanceFailedEvent(SubOrchestrationInstanceFa // When using ErrorPropagationMode.UseFailureDetails we instead use FailureDetails to convey // error information, which doesn't involve any serialization at all. Exception cause = this.ErrorPropagationMode == ErrorPropagationMode.SerializeExceptions ? - Utils.RetrieveCause(failedEvent.Details, this.ErrorDataConverter) + Utils.RetrieveCause(failedEvent.Details, this.ErrorDataConverter) : null; var failedException = new SubOrchestrationFailedException(failedEvent.EventId, taskId, info.Name, @@ -593,7 +593,7 @@ public void HandleExecutionResumedEvent(ExecutionResumedEvent resumedEvent, Acti // Add the actions stored in the suspendedActionsMap before back to orchestratorActionsMap to ensure proper sequencing. if (this.suspendedActionsMap.Any()) { - foreach(var pair in this.suspendedActionsMap) + foreach (var pair in this.suspendedActionsMap) { this.orchestratorActionsMap.Add(pair.Key, pair.Value); } @@ -606,7 +606,7 @@ public void HandleExecutionResumedEvent(ExecutionResumedEvent resumedEvent, Acti } } - public void FailOrchestration(Exception failure) + public void FailOrchestration(Exception failure, OrchestrationRuntimeState runtimeState) { if (failure == null) { @@ -656,6 +656,8 @@ public void FailOrchestration(Exception failure) } } + // save exception so it can be retrieved and sanitized during logging. See LogEvents.OrchestrationCompleted for more details + runtimeState.Exception = failure; CompleteOrchestration(reason, details, OrchestrationStatus.Failed, failureDetails); } diff --git a/src/DurableTask.Core/TaskOrchestrationExecutor.cs b/src/DurableTask.Core/TaskOrchestrationExecutor.cs index 81ea37778..c5e100a2f 100644 --- a/src/DurableTask.Core/TaskOrchestrationExecutor.cs +++ b/src/DurableTask.Core/TaskOrchestrationExecutor.cs @@ -165,7 +165,7 @@ void ProcessEvents(IEnumerable events) ExceptionDispatchInfo.Capture(exception).Throw(); } - this.context.FailOrchestration(exception); + this.context.FailOrchestration(exception, this.orchestrationRuntimeState); } else { @@ -179,7 +179,7 @@ void ProcessEvents(IEnumerable events) } catch (NonDeterministicOrchestrationException exception) { - this.context.FailOrchestration(exception); + this.context.FailOrchestration(exception, this.orchestrationRuntimeState); } return new OrchestratorExecutionResult