diff --git a/src/DurableTask.Core/Common/Utils.cs b/src/DurableTask.Core/Common/Utils.cs index 84df26783..2d63eb895 100644 --- a/src/DurableTask.Core/Common/Utils.cs +++ b/src/DurableTask.Core/Common/Utils.cs @@ -10,13 +10,12 @@ // See the License for the specific language governing permissions and // limitations under the License. // ---------------------------------------------------------------------------------- - +#nullable enable namespace DurableTask.Core.Common { using System; using System.Collections.Generic; using System.Diagnostics; - using System.Dynamic; using System.IO; using System.IO.Compression; using System.Linq; @@ -158,6 +157,31 @@ public static object DeserializeFromJson(JsonSerializer serializer, string jsonS Environment.GetEnvironmentVariable("DTFX_APP_NAME") ?? string.Empty; + /// + /// Gets or sets a value indicating whether to redact user code exceptions from log output. + /// + /// + /// This value defaults to true if the WEBSITE_SITE_NAME is set to a non-empty value, which is always + /// the case in hosted Azure environments where log telemetry is automatically captured. This value can be also + /// be set explicitly by assigning the DTFX_REDACT_USER_CODE_EXCEPTIONS environment variable to "1" or "true". + /// + public static bool RedactUserCodeExceptions { get; set; } = GetRedactUserCodeExceptionsDefaultValue(); + + static bool GetRedactUserCodeExceptionsDefaultValue() + { + string? configuredValue = Environment.GetEnvironmentVariable("DTFX_REDACT_USER_CODE_EXCEPTIONS")?.Trim(); + if (configuredValue != null) + { + return configuredValue == "1" || configuredValue.Equals("true", StringComparison.OrdinalIgnoreCase); + } + else + { + // Fallback case when DTFX_REDACT_USER_CODE_EXCEPTIONS is not defined is to automatically redact + // any time we appear to be in a hosted Azure environment. + return Environment.GetEnvironmentVariable("WEBSITE_SITE_NAME") != null; + } + } + /// /// NoOp utility method /// @@ -223,7 +247,7 @@ public static Stream WriteStringToStream(string input, bool compress, out long o if (compress) { - Stream compressedStream = GetCompressedStream(resultStream); + Stream compressedStream = GetCompressedStream(resultStream)!; resultStream.Dispose(); resultStream = compressedStream; } @@ -295,7 +319,7 @@ public static bool IsGzipStream(Stream stream) /// /// /// - public static Stream GetCompressedStream(Stream input) + public static Stream? GetCompressedStream(Stream input) { if (input == null) { @@ -319,7 +343,7 @@ public static Stream GetCompressedStream(Stream input) /// /// /// - public static async Task GetDecompressedStreamAsync(Stream input) + public static async Task GetDecompressedStreamAsync(Stream input) { if (input == null) { @@ -377,7 +401,7 @@ public static async Task ExecuteWithRetries(Func retryAction, string sessi } int retryCount = numberOfAttempts; - ExceptionDispatchInfo lastException = null; + ExceptionDispatchInfo? lastException = null; while (retryCount-- > 0) { try @@ -405,7 +429,7 @@ public static async Task ExecuteWithRetries(Func retryAction, string sessi /// /// Executes the supplied action until successful or the supplied number of attempts is reached /// - public static async Task ExecuteWithRetries(Func> retryAction, string sessionId, string operation, + public static async Task ExecuteWithRetries(Func> retryAction, string sessionId, string operation, int numberOfAttempts, int delayInAttemptsSecs) { if (numberOfAttempts == 0) @@ -415,7 +439,7 @@ public static async Task ExecuteWithRetries(Func> retryAction, str } int retryCount = numberOfAttempts; - ExceptionDispatchInfo lastException = null; + ExceptionDispatchInfo? lastException = null; while (retryCount-- > 0) { try @@ -477,14 +501,14 @@ public static string SerializeCause(Exception originalException, DataConverter c /// /// Retrieves the exception from a previously serialized exception /// - public static Exception RetrieveCause(string details, DataConverter converter) + public static Exception? RetrieveCause(string details, DataConverter converter) { if (converter == null) { throw new ArgumentNullException(nameof(converter)); } - Exception cause = null; + Exception? cause = null; try { if (!string.IsNullOrWhiteSpace(details)) @@ -683,9 +707,9 @@ internal static Type ConvertFromGenericType(Type[] genericParameters, Type[] gen internal sealed class TypeMetadata { - public string AssemblyName { get; set; } + public string? AssemblyName { get; set; } - public string FullyQualifiedTypeName { get; set; } + public string? FullyQualifiedTypeName { get; set; } } } } diff --git a/src/DurableTask.Core/Logging/LogEvents.cs b/src/DurableTask.Core/Logging/LogEvents.cs index c819aea68..d34cc5fcb 100644 --- a/src/DurableTask.Core/Logging/LogEvents.cs +++ b/src/DurableTask.Core/Logging/LogEvents.cs @@ -1275,6 +1275,8 @@ void IEventSourceEvent.WriteEventSource() => internal class TaskActivityFailure : StructuredLogEvent, IEventSourceEvent { + readonly Exception exception; + public TaskActivityFailure( OrchestrationInstance instance, string name, @@ -1286,6 +1288,7 @@ public TaskActivityFailure( this.Name = name; this.TaskEventId = taskEvent.EventId; this.Details = exception.ToString(); + this.exception = exception; } [StructuredLogField] @@ -1318,7 +1321,7 @@ void IEventSourceEvent.WriteEventSource() => this.ExecutionId, this.Name, this.TaskEventId, - this.Details, + Utils.RedactUserCodeExceptions ? LogHelper.GetRedactedExceptionDetails(this.exception) : this.Details, // We have to be extra guarded about logging user exceptions to EventSource (ETW) Utils.AppName, Utils.PackageVersion); } diff --git a/src/DurableTask.Core/Logging/LogHelper.cs b/src/DurableTask.Core/Logging/LogHelper.cs index 73aaf6cb0..30615360f 100644 --- a/src/DurableTask.Core/Logging/LogHelper.cs +++ b/src/DurableTask.Core/Logging/LogHelper.cs @@ -10,20 +10,22 @@ // See the License for the specific language governing permissions and // limitations under the License. // ---------------------------------------------------------------------------------- - +#nullable enable namespace DurableTask.Core.Logging { using System; using System.Collections.Generic; + using System.Text; using DurableTask.Core.Command; + using DurableTask.Core.Common; using DurableTask.Core.History; using Microsoft.Extensions.Logging; class LogHelper { - readonly ILogger log; + readonly ILogger? log; - public LogHelper(ILogger log) + public LogHelper(ILogger? log) { // null is okay this.log = log; @@ -93,7 +95,6 @@ internal void DispatcherStarting(WorkItemDispatcherContext context) } } - /// /// Logs that a work item dispatcher has stopped running. /// @@ -360,7 +361,7 @@ internal void WaitingForInstance(OrchestrationInstance instance, TimeSpan timeou /// /// The ID of the instance. /// The execution ID of the instance, if applicable. - internal void FetchingInstanceState(string instanceId, string executionId = null) + internal void FetchingInstanceState(string instanceId, string? executionId = null) { if (this.IsStructuredLoggingEnabled) { @@ -639,9 +640,43 @@ internal void RenewActivityMessageFailed(TaskActivityWorkItem workItem, Exceptio } #endregion - void WriteStructuredLog(ILogEvent logEvent, Exception exception = null) + void WriteStructuredLog(ILogEvent logEvent, Exception? exception = null) { this.log?.LogDurableEvent(logEvent, exception); } + + internal static string GetRedactedExceptionDetails(Exception? exception) + { + if (exception == null) + { + return string.Empty; + } + + // Redact the exception message since its possible to contain sensitive information (PII, secrets, etc.) + // Exception.ToString() code: https://referencesource.microsoft.com/#mscorlib/system/exception.cs,e2e19f4ed8da81aa + // Example output for a method chain of Foo() --> Bar() --> Baz() --> (exception): + // System.ApplicationException: [Redacted] + // ---> System.Exception: [Redacted] + // ---> System.InvalidOperationException: [Redacted] + // at UserQuery.
g__Baz|4_3() in C:\Users\xxx\AppData\Local\Temp\LINQPad7\_wrmpjfpn\hjvskp\LINQPadQuery:line 68 + // at UserQuery.
g__Bar|4_2() in C:\Users\xxx\AppData\Local\Temp\LINQPad7\_wrmpjfpn\hjvskp\LINQPadQuery:line 58 + // --- End of inner exception stack trace --- + // at UserQuery.
g__Bar|4_2() in C:\Users\xxx\AppData\Local\Temp\LINQPad7\_wrmpjfpn\hjvskp\LINQPadQuery:line 62 + // at UserQuery.
g__Foo|4_1() in C:\Users\xxx\AppData\Local\Temp\LINQPad7\_wrmpjfpn\hjvskp\LINQPadQuery:line 46 + // --- End of inner exception stack trace --- + // at UserQuery.
g__Foo|4_1() in C:\Users\xxx\AppData\Local\Temp\LINQPad7\_wrmpjfpn\hjvskp\LINQPadQuery:line 50 + // at UserQuery.Main() in C:\Users\xxx\AppData\Local\Temp\LINQPad7\_wrmpjfpn\hjvskp\LINQPadQuery:line 4 + var sb = new StringBuilder(capacity: 1024); + sb.Append(exception.GetType().FullName).Append(": ").Append("[Redacted]"); + if (exception.InnerException != null) + { + // Recursive + sb.AppendLine().Append(" ---> ").AppendLine(GetRedactedExceptionDetails(exception.InnerException)); + sb.Append(" --- End of inner exception stack trace ---"); + } + + sb.AppendLine().Append(exception.StackTrace); + return sb.ToString(); + } } } diff --git a/src/DurableTask.Core/TaskActivityDispatcher.cs b/src/DurableTask.Core/TaskActivityDispatcher.cs index c0429b0df..9c83fccce 100644 --- a/src/DurableTask.Core/TaskActivityDispatcher.cs +++ b/src/DurableTask.Core/TaskActivityDispatcher.cs @@ -102,7 +102,7 @@ async Task OnProcessWorkItemAsync(TaskActivityWorkItem workItem) Activity? diagnosticActivity = null; try { - if (string.IsNullOrWhiteSpace(orchestrationInstance?.InstanceId)) + if (orchestrationInstance == null || string.IsNullOrWhiteSpace(orchestrationInstance.InstanceId)) { this.logHelper.TaskActivityDispatcherError( workItem, @@ -242,7 +242,7 @@ await this.dispatchPipeline.RunAsync(dispatchContext, async _ => catch (SessionAbortedException e) { // The activity aborted its execution - this.logHelper.TaskActivityAborted(orchestrationInstance, scheduledEvent, e.Message); + this.logHelper.TaskActivityAborted(orchestrationInstance, scheduledEvent!, e.Message); TraceHelper.TraceInstance(TraceEventType.Warning, "TaskActivityDispatcher-ExecutionAborted", orchestrationInstance, "{0}: {1}", scheduledEvent?.Name, e.Message); await this.orchestrationService.AbandonTaskActivityWorkItemAsync(workItem); } diff --git a/src/DurableTask.Core/TaskOrchestrationDispatcher.cs b/src/DurableTask.Core/TaskOrchestrationDispatcher.cs index 835408204..3e4db2efb 100644 --- a/src/DurableTask.Core/TaskOrchestrationDispatcher.cs +++ b/src/DurableTask.Core/TaskOrchestrationDispatcher.cs @@ -323,7 +323,7 @@ protected async Task OnProcessWorkItemAsync(TaskOrchestrationWorkItem work continuedAsNew = false; continuedAsNewMessage = null; - this.logHelper.OrchestrationExecuting(runtimeState.OrchestrationInstance, runtimeState.Name); + this.logHelper.OrchestrationExecuting(runtimeState.OrchestrationInstance!, runtimeState.Name); TraceHelper.TraceInstance( TraceEventType.Verbose, "TaskOrchestrationDispatcher-ExecuteUserOrchestration-Begin", @@ -343,7 +343,7 @@ protected async Task OnProcessWorkItemAsync(TaskOrchestrationWorkItem work IReadOnlyList decisions = workItem.Cursor.LatestDecisions.ToList(); this.logHelper.OrchestrationExecuted( - runtimeState.OrchestrationInstance, + runtimeState.OrchestrationInstance!, runtimeState.Name, decisions); TraceHelper.TraceInstance( @@ -852,7 +852,7 @@ TaskMessage ProcessScheduleTaskDecision( } this.logHelper.SchedulingActivity( - runtimeState.OrchestrationInstance, + runtimeState.OrchestrationInstance!, scheduledEvent); runtimeState.AddEvent(scheduledEvent); @@ -880,7 +880,7 @@ TaskMessage ProcessCreateTimerDecision( }; this.logHelper.CreatingTimer( - runtimeState.OrchestrationInstance, + runtimeState.OrchestrationInstance!, timerCreatedEvent, isInternal); @@ -949,7 +949,7 @@ TaskMessage ProcessSendEventDecision( runtimeState.AddEvent(historyEvent); - this.logHelper.RaisingEvent(runtimeState.OrchestrationInstance, historyEvent); + this.logHelper.RaisingEvent(runtimeState.OrchestrationInstance!, historyEvent); return new TaskMessage { diff --git a/src/DurableTask.Core/TaskOrchestrationExecutor.cs b/src/DurableTask.Core/TaskOrchestrationExecutor.cs index 9320db5de..b0ca99976 100644 --- a/src/DurableTask.Core/TaskOrchestrationExecutor.cs +++ b/src/DurableTask.Core/TaskOrchestrationExecutor.cs @@ -139,7 +139,7 @@ void ProcessEvents(IEnumerable events) Exception? exception = this.result.Exception?.InnerExceptions.FirstOrDefault(); Debug.Assert(exception != null); - if (Utils.IsExecutionAborting(exception)) + if (Utils.IsExecutionAborting(exception!)) { // Let this exception propagate out to be handled by the dispatcher ExceptionDispatchInfo.Capture(exception).Throw();