Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Remove user-provided details from various logs #1100

Merged
merged 16 commits into from
Jun 10, 2024
Merged

Remove user-provided details from various logs #1100

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
16 commits
Select commit Hold shift + click to select a range
b90578d
remove user-provided details from various logs
davidmrdavid May 23, 2024
addb781
add regex-based sanitizer
davidmrdavid Jun 1, 2024
2ffd677
improve docs
davidmrdavid Jun 1, 2024
cea9990
use TaskFailureDetails for sanitization
davidmrdavid Jun 4, 2024
2d67676
remove sanitizer class
davidmrdavid Jun 4, 2024
67c1a75
uniform naming
davidmrdavid Jun 4, 2024
3de7889
add comments in TaskOrchestrationcontext
davidmrdavid Jun 4, 2024
352181b
simplify implementation
davidmrdavid Jun 7, 2024
ed3ecc5
add docs
davidmrdavid Jun 7, 2024
72e5d87
simplify further
davidmrdavid Jun 7, 2024
431c00d
improve comemnts
davidmrdavid Jun 7, 2024
11fec32
incorporate feedback
davidmrdavid Jun 10, 2024
ede84df
Update src/DurableTask.Core/Logging/LogEvents.cs
davidmrdavid Jun 10, 2024
afc3d91
Merge branch 'dajusto/remove-details-from-telemetry' of https://githu…
davidmrdavid Jun 10, 2024
532c60f
add character-length info in details
davidmrdavid Jun 10, 2024
5fd20e3
remove whitespace
davidmrdavid Jun 10, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 17 additions & 8 deletions src/DurableTask.Core/Logging/LogEvents.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
Expand Down Expand Up @@ -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);
}
Expand Down Expand Up @@ -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);
}
Expand Down Expand Up @@ -1045,15 +1045,21 @@ void IEventSourceEvent.WriteEventSource() =>
/// </summary>
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]
Expand Down Expand Up @@ -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

/// <summary>
/// Log event representing an orchestration aborted event, which can happen if the host is shutting down.
Expand Down Expand Up @@ -1494,6 +1501,7 @@ void IEventSourceEvent.WriteEventSource() =>

internal class TaskActivityFailure : StructuredLogEvent, IEventSourceEvent
{
#nullable enable
readonly Exception exception;

public TaskActivityFailure(
Expand All @@ -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();
jviau marked this conversation as resolved.
Show resolved Hide resolved
}

[StructuredLogField]
Expand Down Expand Up @@ -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
{
Expand Down
8 changes: 8 additions & 0 deletions src/DurableTask.Core/OrchestrationRuntimeState.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -134,6 +134,14 @@ public ExecutionStartedEvent? ExecutionStartedEvent
/// </remarks>
public FailureDetails? FailureDetails => ExecutionCompletedEvent?.FailureDetails;

/// <summary>
/// Failure that caused an orchestrator to complete, if any.
/// </summary>
/// <remarks>
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nit: <remarks> is a sibling to <summary>, not a nested child. See the FailureDetails property above for an example of how to correctly use <remarks>.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for pointing this out. I wish Visual Studio had flagged this somehow. Im sure there's a way to set that up, but I'll leave that to another day due to time :)

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will be fixed in next commit

/// This property was introduced to sanitize exceptions during logging. See it's usage in <see cref="LogEvents.OrchestrationCompleted"/>.
/// </remarks>
internal Exception? Exception { get; set; }

/// <summary>
/// Gets the orchestration name from the ExecutionStartedEvent
/// </summary>
Expand Down
10 changes: 6 additions & 4 deletions src/DurableTask.Core/TaskOrchestrationContext.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
{
Expand Down Expand Up @@ -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,
Expand Down Expand Up @@ -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);
}
Expand All @@ -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)
{
Expand Down Expand Up @@ -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);
}

Expand Down
4 changes: 2 additions & 2 deletions src/DurableTask.Core/TaskOrchestrationExecutor.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -165,7 +165,7 @@ void ProcessEvents(IEnumerable<HistoryEvent> events)
ExceptionDispatchInfo.Capture(exception).Throw();
}

this.context.FailOrchestration(exception);
this.context.FailOrchestration(exception, this.orchestrationRuntimeState);
}
else
{
Expand All @@ -179,7 +179,7 @@ void ProcessEvents(IEnumerable<HistoryEvent> events)
}
catch (NonDeterministicOrchestrationException exception)
{
this.context.FailOrchestration(exception);
this.context.FailOrchestration(exception, this.orchestrationRuntimeState);
}

return new OrchestratorExecutionResult
Expand Down