Skip to content

Performance: avoid debug logging work when debug logs are disabled #770

Description

@berndverst

1. What is the issue?

The worker computes debug-only log arguments on every orchestration and activity completion, regardless of the configured log level.

2. Likely priority

High for workers that process high fan-out orchestrations or large activity inputs and outputs. Debug logging is normally disabled in production, making this pure overhead.

3. Impact on performance

Each orchestration completion can allocate and group all actions to build a display string. Each activity execution and completion scans the full input or output string with Encoding.UTF8.GetByteCount. Large payloads can therefore incur extra full-buffer passes even though the debug message is never emitted.

4. Details and code reference

Action-summary formatting:

static string GetActionsListForLogging(IReadOnlyList<P.OrchestratorAction> actions)
{
if (actions.Count == 0)
{
return string.Empty;
}
else if (actions.Count == 1)
{
return actions[0].OrchestratorActionTypeCase.ToString();
}
else
{
// Returns something like "ScheduleTask x5, CreateTimer x1,..."
return string.Join(", ", actions
.GroupBy(a => a.OrchestratorActionTypeCase)
.Select(group => $"{group.Key} x{group.Count()}"));
}
}

Debug-level orchestration response logging call:

this.Logger.SendingOrchestratorResponse(
name,
response.InstanceId,
response.Actions.Count,
GetActionsListForLogging(response.Actions));

Activity input byte count:

OrchestrationInstance instance = request.OrchestrationInstance.ToCore();
string rawInput = request.Input;
int inputSize = rawInput != null ? Encoding.UTF8.GetByteCount(rawInput) : 0;
this.Logger.ReceivedActivityRequest(request.Name, request.TaskId, instance.InstanceId, inputSize);

Activity output byte count:

int outputSizeInBytes = 0;
if (failureDetails != null)
{
traceActivity?.SetStatus(ActivityStatusCode.Error, failureDetails.ErrorMessage);
outputSizeInBytes = failureDetails.GetApproximateByteCount();
}
else if (output != null)
{
outputSizeInBytes = Encoding.UTF8.GetByteCount(output);
}
string successOrFailure = failureDetails != null ? "failure" : "success";
this.Logger.SendingActivityResponse(
successOrFailure, name, request.TaskId, instance.InstanceId, outputSizeInBytes);

The corresponding messages are Debug-level:

[LoggerMessage(EventId = 10, Level = LogLevel.Debug, Message = "{instanceId}: Received request to run orchestrator '{name}' with {oldEventCount} replay and {newEventCount} new history events.")]
public static partial void ReceivedOrchestratorRequest(this ILogger logger, string name, string instanceId, int oldEventCount, int newEventCount);
[LoggerMessage(EventId = 11, Level = LogLevel.Debug, Message = "{instanceId}: Sending {count} action(s) [{actionsList}] for '{name}' orchestrator.")]
public static partial void SendingOrchestratorResponse(this ILogger logger, string name, string instanceId, int count, string actionsList);
[LoggerMessage(EventId = 12, Level = LogLevel.Warning, Message = "{instanceId}: '{name}' orchestrator failed with an unhandled exception: {details}.")]
public static partial void OrchestratorFailed(this ILogger logger, string name, string instanceId, string details);
[LoggerMessage(EventId = 13, Level = LogLevel.Debug, Message = "{instanceId}: Received request to run activity '{name}#{taskId}' with {sizeInBytes} bytes of input data.")]
public static partial void ReceivedActivityRequest(this ILogger logger, string name, int taskId, string instanceId, int sizeInBytes);
[LoggerMessage(EventId = 14, Level = LogLevel.Debug, Message = "{instanceId}: Sending {successOrFailure} response for '{name}#{taskId}' activity with {sizeInBytes} bytes of output data.")]
public static partial void SendingActivityResponse(this ILogger logger, string successOrFailure, string name, int taskId, string instanceId, int sizeInBytes);

5. Guidance for how to fix

Guard each expensive argument calculation with this.Logger.IsEnabled(LogLevel.Debug). Compute and log the values only inside that branch, preserving identical diagnostics when Debug is enabled and avoiding all additional grouping, allocation, and byte-count scans otherwise. Add tests for the enabled and disabled paths if logging-test infrastructure permits.

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions