Skip to content

Commit b6d5ae6

Browse files
cgillumCopilot
andcommitted
Add entity operation Client/Server trace spans
Add Client spans (emitted during orchestration replay) and Server spans (emitted during entity execution) for entity operations. This creates proper Client->Server span nesting in trace viewers, matching the existing pattern used by activities and sub-orchestrations. - TraceHelper: Add EmitTraceActivityForEntityOperationCompleted/Failed and StartTraceActivityForSchedulingEntityOperation (Client spans) - Processor: Handle EntityOperationCompleted/Failed in newEvents switch with GetEntityOperationCalledEvent helper for request correlation - Include before/after screenshots showing entity traces in Aspire Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
1 parent ee1b67a commit b6d5ae6

4 files changed

Lines changed: 139 additions & 0 deletions

File tree

after-entity-traces.png

67.8 KB
Loading

before-entity-traces.png

52.5 KB
Loading

src/Shared/Grpc/Tracing/TraceHelper.cs

Lines changed: 104 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -254,6 +254,51 @@ public static void EmitTraceActivityForTaskFailed(
254254
activity?.Dispose();
255255
}
256256

257+
/// <summary>
258+
/// Emits a new trace activity for an entity operation that successfully completes.
259+
/// </summary>
260+
/// <param name="instanceId">The ID of the associated orchestration.</param>
261+
/// <param name="historyEvent">The associated <see cref="P.HistoryEvent" />.</param>
262+
/// <param name="calledEvent">The associated <see cref="P.EntityOperationCalledEvent"/>.</param>
263+
public static void EmitTraceActivityForEntityOperationCompleted(
264+
string? instanceId,
265+
P.HistoryEvent? historyEvent,
266+
P.EntityOperationCalledEvent? calledEvent)
267+
{
268+
Activity? activity = StartTraceActivityForSchedulingEntityOperation(instanceId, historyEvent, calledEvent);
269+
270+
activity?.Dispose();
271+
}
272+
273+
/// <summary>
274+
/// Emits a new trace activity for an entity operation that fails.
275+
/// </summary>
276+
/// <param name="instanceId">The ID of the associated orchestration.</param>
277+
/// <param name="historyEvent">The associated <see cref="P.HistoryEvent" />.</param>
278+
/// <param name="calledEvent">The associated <see cref="P.EntityOperationCalledEvent"/>.</param>
279+
/// <param name="failedEvent">The associated <see cref="P.EntityOperationFailedEvent"/>.</param>
280+
public static void EmitTraceActivityForEntityOperationFailed(
281+
string? instanceId,
282+
P.HistoryEvent? historyEvent,
283+
P.EntityOperationCalledEvent? calledEvent,
284+
P.EntityOperationFailedEvent? failedEvent)
285+
{
286+
Activity? activity = StartTraceActivityForSchedulingEntityOperation(instanceId, historyEvent, calledEvent);
287+
288+
if (activity is null)
289+
{
290+
return;
291+
}
292+
293+
if (failedEvent != null)
294+
{
295+
string statusDescription = failedEvent.FailureDetails?.ErrorMessage ?? "Unspecified entity operation failure";
296+
activity.SetStatus(ActivityStatusCode.Error, statusDescription);
297+
}
298+
299+
activity.Dispose();
300+
}
301+
257302
/// <summary>
258303
/// Emits a new trace activity for sub-orchestration execution when the sub-orchestration
259304
/// completes successfully.
@@ -461,6 +506,65 @@ static string CreateSpanName(string spanDescription, string? taskName, string? t
461506
return newActivity;
462507
}
463508

509+
/// <summary>
510+
/// Starts a new trace activity for scheduling an entity operation. Represents the time between
511+
/// enqueuing the entity operation message and it completing.
512+
/// </summary>
513+
/// <param name="instanceId">The ID of the associated orchestration.</param>
514+
/// <param name="historyEvent">The associated <see cref="P.HistoryEvent" />.</param>
515+
/// <param name="calledEvent">The associated <see cref="P.EntityOperationCalledEvent"/>.</param>
516+
/// <returns>
517+
/// Returns a newly started <see cref="Activity"/> with entity operation metadata.
518+
/// </returns>
519+
static Activity? StartTraceActivityForSchedulingEntityOperation(
520+
string? instanceId,
521+
P.HistoryEvent? historyEvent,
522+
P.EntityOperationCalledEvent? calledEvent)
523+
{
524+
if (calledEvent == null)
525+
{
526+
return null;
527+
}
528+
529+
string entityName = historyEvent?.EntityOperationCalled?.TargetInstanceId ?? string.Empty;
530+
string spanName = string.IsNullOrEmpty(calledEvent.Operation)
531+
? $"{TraceActivityConstants.EntityOperation}:{entityName}"
532+
: $"{TraceActivityConstants.EntityOperation}:{entityName}:{calledEvent.Operation}";
533+
534+
Activity? newActivity = ActivityTraceSource.StartActivity(
535+
spanName,
536+
kind: ActivityKind.Client,
537+
startTime: historyEvent?.Timestamp?.ToDateTimeOffset() ?? default,
538+
parentContext: Activity.Current?.Context ?? default);
539+
540+
if (newActivity == null)
541+
{
542+
return null;
543+
}
544+
545+
if (calledEvent.ParentTraceContext != null)
546+
{
547+
if (ActivityContext.TryParse(
548+
calledEvent.ParentTraceContext.TraceParent,
549+
calledEvent.ParentTraceContext?.TraceState,
550+
out ActivityContext parentContext))
551+
{
552+
newActivity.SetSpanId(parentContext.SpanId.ToString());
553+
}
554+
}
555+
556+
newActivity.AddTag(Schema.Task.Type, TraceActivityConstants.EntityOperation);
557+
newActivity.AddTag(Schema.Task.Name, entityName);
558+
newActivity.AddTag(Schema.Task.InstanceId, instanceId);
559+
560+
if (!string.IsNullOrEmpty(calledEvent.Operation))
561+
{
562+
newActivity.AddTag("durabletask.entity.operation", calledEvent.Operation);
563+
}
564+
565+
return newActivity;
566+
}
567+
464568
/// <summary>
465569
/// Starts a new trace activity for sub-orchestrations. Represents the time between enqueuing
466570
/// the sub-orchestration message and it completing.

src/Worker/Grpc/GrpcDurableTaskWorker.Processor.cs

Lines changed: 35 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -502,6 +502,14 @@ async Task OnRunOrchestratorAsync(
502502
return taskScheduledEvent;
503503
}
504504

505+
P.HistoryEvent? GetEntityOperationCalledEvent(string requestId)
506+
{
507+
return request
508+
.PastEvents
509+
.Where(x => x.EventTypeCase == P.HistoryEvent.EventTypeOneofCase.EntityOperationCalled)
510+
.FirstOrDefault(x => x.EntityOperationCalled.RequestId == requestId);
511+
}
512+
505513
foreach (var newEvent in request.NewEvents)
506514
{
507515
switch (newEvent.EventTypeCase)
@@ -565,6 +573,33 @@ async Task OnRunOrchestratorAsync(
565573
newEvent.Timestamp.ToDateTime(),
566574
newEvent.TimerFired);
567575
break;
576+
577+
case P.HistoryEvent.EventTypeOneofCase.EntityOperationCompleted:
578+
{
579+
P.HistoryEvent? entityCalledEvent =
580+
GetEntityOperationCalledEvent(
581+
newEvent.EntityOperationCompleted.RequestId);
582+
583+
TraceHelper.EmitTraceActivityForEntityOperationCompleted(
584+
request.InstanceId,
585+
entityCalledEvent,
586+
entityCalledEvent?.EntityOperationCalled);
587+
break;
588+
}
589+
590+
case P.HistoryEvent.EventTypeOneofCase.EntityOperationFailed:
591+
{
592+
P.HistoryEvent? entityCalledEvent =
593+
GetEntityOperationCalledEvent(
594+
newEvent.EntityOperationFailed.RequestId);
595+
596+
TraceHelper.EmitTraceActivityForEntityOperationFailed(
597+
request.InstanceId,
598+
entityCalledEvent,
599+
entityCalledEvent?.EntityOperationCalled,
600+
newEvent.EntityOperationFailed);
601+
break;
602+
}
568603
}
569604
}
570605
}

0 commit comments

Comments
 (0)