Repository navigation
Performance: avoid repeated orchestration-history scans for tracing #769
Description
1. What is the issue?
The worker scans the full orchestration history to locate scheduling events for every relevant new completion event, even when no OpenTelemetry listener is active.
2. Likely priority
High for long-running orchestrations with large histories and fan-in batches.
3. Impact on performance
For a work item with N new completion events and M past events, tracing work can become O(N x M). The scans and LINQ iterator allocations occur before ActivitySource.StartActivity determines that tracing is disabled, so the cost is paid in the normal no-listener case.
4. Details and code reference
Relevant worker path:
durabletask-dotnet/src/Worker/Grpc/GrpcDurableTaskWorker.Processor.cs
Lines 589 to 689 in 883211a
| var executionStartedEvent = | |
| request | |
| .NewEvents | |
| .Concat(request.PastEvents) | |
| .Where(e => e.EventTypeCase == P.HistoryEvent.EventTypeOneofCase.ExecutionStarted) | |
| .Select(e => e.ExecutionStarted) | |
| .FirstOrDefault(); | |
| Activity? traceActivity = TraceHelper.StartTraceActivityForOrchestrationExecution( | |
| executionStartedEvent, | |
| request.OrchestrationTraceContext); | |
| if (executionStartedEvent is not null) | |
| { | |
| P.HistoryEvent? GetSuborchestrationInstanceCreatedEvent(int eventId) | |
| { | |
| var subOrchestrationEvent = | |
| request | |
| .PastEvents | |
| .Where(x => x.EventTypeCase == P.HistoryEvent.EventTypeOneofCase.SubOrchestrationInstanceCreated) | |
| .FirstOrDefault(x => x.EventId == eventId); | |
| return subOrchestrationEvent; | |
| } | |
| P.HistoryEvent? GetTaskScheduledEvent(int eventId) | |
| { | |
| var taskScheduledEvent = | |
| request | |
| .PastEvents | |
| .Where(x => x.EventTypeCase == P.HistoryEvent.EventTypeOneofCase.TaskScheduled) | |
| .LastOrDefault(x => x.EventId == eventId); | |
| return taskScheduledEvent; | |
| } | |
| foreach (var newEvent in request.NewEvents) | |
| { | |
| switch (newEvent.EventTypeCase) | |
| { | |
| case P.HistoryEvent.EventTypeOneofCase.SubOrchestrationInstanceCompleted: | |
| { | |
| P.HistoryEvent? subOrchestrationInstanceCreatedEvent = | |
| GetSuborchestrationInstanceCreatedEvent( | |
| newEvent.SubOrchestrationInstanceCompleted.TaskScheduledId); | |
| TraceHelper.EmitTraceActivityForSubOrchestrationCompleted( | |
| request.InstanceId, | |
| subOrchestrationInstanceCreatedEvent, | |
| subOrchestrationInstanceCreatedEvent?.SubOrchestrationInstanceCreated); | |
| break; | |
| } | |
| case P.HistoryEvent.EventTypeOneofCase.SubOrchestrationInstanceFailed: | |
| { | |
| P.HistoryEvent? subOrchestrationInstanceCreatedEvent = | |
| GetSuborchestrationInstanceCreatedEvent( | |
| newEvent.SubOrchestrationInstanceFailed.TaskScheduledId); | |
| TraceHelper.EmitTraceActivityForSubOrchestrationFailed( | |
| request.InstanceId, | |
| subOrchestrationInstanceCreatedEvent, | |
| subOrchestrationInstanceCreatedEvent?.SubOrchestrationInstanceCreated, | |
| newEvent.SubOrchestrationInstanceFailed); | |
| break; | |
| } | |
| case P.HistoryEvent.EventTypeOneofCase.TaskCompleted: | |
| { | |
| P.HistoryEvent? taskScheduledEvent = | |
| GetTaskScheduledEvent(newEvent.TaskCompleted.TaskScheduledId); | |
| TraceHelper.EmitTraceActivityForTaskCompleted( | |
| request.InstanceId, | |
| taskScheduledEvent, | |
| taskScheduledEvent?.TaskScheduled); | |
| break; | |
| } | |
| case P.HistoryEvent.EventTypeOneofCase.TaskFailed: | |
| { | |
| P.HistoryEvent? taskScheduledEvent = | |
| GetTaskScheduledEvent(newEvent.TaskFailed.TaskScheduledId); | |
| TraceHelper.EmitTraceActivityForTaskFailed( | |
| request.InstanceId, | |
| taskScheduledEvent, | |
| taskScheduledEvent?.TaskScheduled, | |
| newEvent.TaskFailed); | |
| break; | |
| } | |
| case P.HistoryEvent.EventTypeOneofCase.TimerFired: | |
| TraceHelper.EmitTraceActivityForTimer( | |
| request.InstanceId, | |
| executionStartedEvent.Name, | |
| newEvent.Timestamp.ToDateTime(), | |
| newEvent.TimerFired); | |
| break; | |
| } | |
| } |
OnRunOrchestratorAsync scans PastEvents from local lookup functions invoked inside the NewEvents loop. It also scans NewEvents.Concat(PastEvents) to find ExecutionStarted before starting the tracing activity.
Relevant tracing helper:
durabletask-dotnet/src/Shared/Grpc/Tracing/TraceHelper.cs
Lines 67 to 114 in 883211a
| public static Activity? StartTraceActivityForOrchestrationExecution( | |
| P.ExecutionStartedEvent? startEvent, | |
| P.OrchestrationTraceContext? orchestrationTraceContext) | |
| { | |
| if (startEvent == null) | |
| { | |
| return null; | |
| } | |
| if (startEvent.ParentTraceContext is null | |
| || !ActivityContext.TryParse( | |
| startEvent.ParentTraceContext.TraceParent, | |
| startEvent.ParentTraceContext.TraceState, | |
| out ActivityContext activityContext)) | |
| { | |
| return null; | |
| } | |
| string activityName = CreateSpanName(TraceActivityConstants.Orchestration, startEvent.Name, startEvent.Version); | |
| ActivityKind activityKind = ActivityKind.Server; | |
| DateTimeOffset startTime = orchestrationTraceContext?.SpanStartTime?.ToDateTimeOffset() ?? default; | |
| Activity? activity = ActivityTraceSource.StartActivity( | |
| activityName, | |
| kind: activityKind, | |
| parentContext: activityContext, | |
| startTime: startTime); | |
| if (activity == null) | |
| { | |
| return null; | |
| } | |
| activity.SetTag(Schema.Task.Type, TraceActivityConstants.Orchestration); | |
| activity.SetTag(Schema.Task.Name, startEvent.Name); | |
| activity.SetTag(Schema.Task.InstanceId, startEvent.OrchestrationInstance.InstanceId); | |
| if (!string.IsNullOrEmpty(startEvent.Version)) | |
| { | |
| activity.SetTag(Schema.Task.Version, startEvent.Version); | |
| } | |
| if (orchestrationTraceContext?.SpanID != null) | |
| { | |
| activity.SetSpanId(orchestrationTraceContext.SpanID!); | |
| } | |
| return activity; |
The tracing helper only discovers whether an activity can be created after these lookups.
5. Guidance for how to fix
Expose a cheap tracing-listener check from TraceHelper and skip all trace-event lookup work when no listener is registered. When tracing is enabled, build indexes once per work item for task-scheduled and sub-orchestration-created events, preserving the current first/last lookup semantics, rather than rescanning history for each new event. Add coverage for duplicate IDs, ordering semantics, and no-listener behavior.
Activity