Skip to content

Commit 8ea5363

Browse files
torosentCopilot
andcommitted
fix(tracing): fix sub-orchestration client span timing
Use the dispatch start time (OrchestratorStartedEvent) for sub-orchestration client span start instead of SubOrchestrationInstanceCreatedEvent timestamp. The created event is a server confirmation whose timestamp can be AFTER the sub-orchestration's ExecutionStartedEvent, causing the client span to visually start after the server span in Jaeger. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
1 parent 7bf3f06 commit 8ea5363

File tree

2 files changed

+11
-5
lines changed

2 files changed

+11
-5
lines changed

client/src/main/java/com/microsoft/durabletask/TaskOrchestrationExecutor.java

Lines changed: 11 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -561,7 +561,10 @@ private void handleTaskScheduled(HistoryEvent e) {
561561
taskScheduled.getParentTraceContext().getTraceParent());
562562
}
563563

564-
storeSchedulingMetadata(taskId, taskScheduled.getName(), TracingHelper.TYPE_ACTIVITY, e, clientSpanId);
564+
Instant activityScheduledTime = e.hasTimestamp()
565+
? DataConverter.getInstantFromTimestamp(e.getTimestamp()) : null;
566+
storeSchedulingMetadata(taskId, taskScheduled.getName(), TracingHelper.TYPE_ACTIVITY,
567+
activityScheduledTime, clientSpanId);
565568

566569
// The history shows that this orchestrator created a durable task in a previous execution.
567570
// We can therefore remove it from the map of pending actions. If we can't find the pending
@@ -790,8 +793,13 @@ private void handleSubOrchestrationCreated(HistoryEvent e) {
790793
subOrchestrationInstanceCreated.getParentTraceContext().getTraceParent());
791794
}
792795

796+
// Use the dispatch start time (OrchestratorStartedEvent) instead of the
797+
// SubOrchestrationInstanceCreatedEvent timestamp. The created event is a server
798+
// confirmation whose timestamp can be AFTER the sub-orchestration's
799+
// ExecutionStartedEvent, causing the client span to visually start after the
800+
// server span.
793801
storeSchedulingMetadata(taskId, subOrchestrationInstanceCreated.getName(),
794-
TracingHelper.TYPE_ORCHESTRATION, e, clientSpanId);
802+
TracingHelper.TYPE_ORCHESTRATION, this.getCurrentInstant(), clientSpanId);
795803

796804
OrchestratorAction taskAction = this.pendingActions.remove(taskId);
797805
if (taskAction == null) {
@@ -1089,9 +1097,7 @@ private void emitClientSpanIfTracked(int taskId) {
10891097
* Stores scheduling metadata for a task so a retroactive client span can be emitted at completion time.
10901098
*/
10911099
private void storeSchedulingMetadata(int taskId, String taskName, String spanType,
1092-
HistoryEvent e, String clientSpanId) {
1093-
Instant scheduledTime = e.hasTimestamp()
1094-
? DataConverter.getInstantFromTimestamp(e.getTimestamp()) : null;
1100+
Instant scheduledTime, String clientSpanId) {
10951101
TraceContext spanParent = this.orchestrationSpanContext != null
10961102
? this.orchestrationSpanContext : this.parentTraceContext;
10971103
this.scheduledTaskInfoMap.put(taskId, new ScheduledTaskInfo(
6.42 KB
Loading

0 commit comments

Comments
 (0)