Skip to content

Commit 610690e

Browse files
Ayushi Ahjoliaayushiahjolia
authored andcommitted
fix(otel): end recording spans on non-terminal
1 parent 91f84fd commit 610690e

4 files changed

Lines changed: 278 additions & 61 deletions

File tree

packages/aws-durable-execution-sdk-python-otel/src/aws_durable_execution_sdk_python_otel/execution_plugin.py

Lines changed: 77 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -133,6 +133,7 @@ def __init__(self, config: OtelPluginConfig | None = None) -> None:
133133
# Per-invocation state.
134134
self._execution_arn = ""
135135
self._execution_trace_id: int | None = None
136+
self._execution_start_time: datetime.datetime | None = None
136137
self._extracted_context: ExtractedContext | None = None
137138
self._execution_trace_context: ExecutionTraceContext | None = None
138139
self._sampling_intent: DurableSamplingIntent | None = None
@@ -346,6 +347,7 @@ def on_invocation_start(self, info: InvocationStartInfo) -> None:
346347
)
347348
self._tracing_enabled = False
348349
return
350+
self._execution_start_time = info.execution_start_time
349351
self._extracted_context = _ensure_extracted_context(
350352
self._context_extractor(info)
351353
)
@@ -393,11 +395,40 @@ def on_invocation_start(self, info: InvocationStartInfo) -> None:
393395
)
394396

395397
def _start_workflow_span(self, info: InvocationStartInfo) -> None:
398+
"""Install a non-recording placeholder for the execution-scoped Workflow span.
399+
400+
The Workflow span spans the whole durable execution and is exported once,
401+
on the terminal invocation. During every invocation the plugin only needs
402+
its deterministic SpanContext -- to parent operation spans, to keep the
403+
Workflow current so auto-instrumented spans join the execution trace, and
404+
for log correlation. A non-recording placeholder fills that role so a
405+
non-terminal invocation never abandons a recording span. The recording
406+
span is created and ended once by :meth:`_export_workflow_span`.
407+
"""
396408
if not self._execution_arn:
397409
logger.warning("No execution ARN; skipping Workflow span creation")
398410
return
399411
if self._execution_trace_context is None:
400412
return
413+
workflow_span_context = SpanContext(
414+
trace_id=self._execution_trace_context.trace_id,
415+
span_id=derive_workflow_span_id(self._execution_arn),
416+
is_remote=False,
417+
trace_flags=self._execution_trace_context.trace_flags,
418+
trace_state=self._execution_trace_context.execution_ancestor.trace_state,
419+
)
420+
self._workflow_span = NonRecordingSpan(workflow_span_context)
421+
422+
def _export_workflow_span(self, info: InvocationEndInfo) -> None:
423+
"""Create and end the recording Workflow span once, on a terminal status.
424+
425+
Uses the same deterministic span ID as the placeholder and the shared
426+
execution ancestor as its parent, so the exported Workflow span stays on
427+
the execution trace and correlates with every operation span across all
428+
invocations. Anchored at the execution start time.
429+
"""
430+
if not self._execution_arn or self._execution_trace_context is None:
431+
return
401432
parent_context = self._with_sampling(
402433
trace.set_span_in_context(
403434
NonRecordingSpan(self._execution_trace_context.execution_ancestor),
@@ -408,13 +439,41 @@ def _start_workflow_span(self, info: InvocationStartInfo) -> None:
408439
trace_id=None,
409440
span_id=derive_workflow_span_id(self._execution_arn),
410441
):
411-
self._workflow_span = self._tracer.start_span(
442+
workflow_span = self._tracer.start_span(
412443
name=self._workflow_span_name,
413444
kind=SpanKind.INTERNAL,
414-
attributes={"durable.execution.arn": self._execution_arn},
415-
start_time=_to_otel_timestamp(info.execution_start_time),
445+
attributes={
446+
"durable.execution.arn": self._execution_arn,
447+
"durable.execution.status": (
448+
info.status.value if info.status else ""
449+
),
450+
},
451+
start_time=_to_otel_timestamp(self._execution_start_time),
416452
context=parent_context,
417453
)
454+
if info.status is InvocationStatus.FAILED:
455+
workflow_span.set_status(
456+
StatusCode.ERROR, info.error.message if info.error else ""
457+
)
458+
elif info.status is InvocationStatus.SUCCEEDED:
459+
workflow_span.set_status(StatusCode.OK)
460+
workflow_span.end()
461+
462+
def _end_open_operation_spans(self) -> None:
463+
"""End every operation span still open at invocation end (except invocation).
464+
465+
Spans are registered parent-first, so ending them in reverse keeps each
466+
child contained within its parent. The invocation span is ended
467+
separately by the caller.
468+
"""
469+
with self._lock:
470+
keys = list(reversed(self._operation_spans))
471+
for key in keys:
472+
if key == _INVOCATION_KEY:
473+
continue
474+
popped = self._pop_span(key)
475+
if popped is not None:
476+
popped.end()
418477

419478
def _start_invocation_span(self, info: InvocationStartInfo) -> None:
420479
self._invocation_span = self._tracer.start_span(
@@ -434,12 +493,6 @@ def on_invocation_end(self, info: InvocationEndInfo) -> None:
434493
self._reset_state()
435494
return
436495

437-
# Operation spans still open here belong to operations that suspended
438-
# (e.g. PENDING/RETRYING) rather than completed this invocation. They are
439-
# ended only by on_operation_end; drop the references without ending them
440-
# so they are not exported as if completed. _reset_state
441-
# clears the span map below.
442-
443496
# End the invocation span regardless of terminal status. Record the
444497
# invocation status and map it to a span status:
445498
# SUCCEEDED/PENDING -> OK (this invocation did its work, whether it
@@ -462,23 +515,20 @@ def on_invocation_end(self, info: InvocationEndInfo) -> None:
462515
)
463516
self._invocation_span.end()
464517

465-
# The Workflow span (execution view) is exported only on a terminal
466-
# status; otherwise its reference is dropped without ending it. Its span
467-
# status reflects the execution outcome: SUCCEEDED -> OK, FAILED -> ERROR
468-
# (RETRY/PENDING are non-terminal and never reach here -> UNSET).
469-
if self._workflow_span is not None:
470-
if info.status in _TERMINAL_INVOCATION_STATUSES:
471-
self._workflow_span.set_attribute(
472-
"durable.execution.status",
473-
info.status.value if info.status else "",
474-
)
475-
if info.status is InvocationStatus.FAILED:
476-
self._workflow_span.set_status(
477-
StatusCode.ERROR, info.error.message if info.error else ""
478-
)
479-
elif info.status is InvocationStatus.SUCCEEDED:
480-
self._workflow_span.set_status(StatusCode.OK)
481-
self._workflow_span.end()
518+
# Operation spans still open here belong to operations that suspended
519+
# (e.g. PENDING/RETRYING) rather than completed this invocation. End them
520+
# so no recording span is abandoned; the authoritative span for an
521+
# operation that resumes in a later invocation is created and ended by
522+
# on_operation_end at that time.
523+
self._end_open_operation_spans()
524+
525+
# The Workflow span (execution view) is a non-recording placeholder
526+
# during the invocation, so only a terminal status materializes and ends
527+
# the recording span. Its span status reflects the execution outcome:
528+
# SUCCEEDED -> OK, FAILED -> ERROR (RETRY/PENDING are non-terminal and
529+
# leave the Workflow span unexported until a later terminal invocation).
530+
if info.status in _TERMINAL_INVOCATION_STATUSES:
531+
self._export_workflow_span(info)
482532

483533
self._reset_state()
484534

@@ -495,6 +545,7 @@ def _reset_state(self) -> None:
495545
self._extracted_context = None
496546
self._execution_trace_context = None
497547
self._sampling_intent = None
548+
self._execution_start_time = None
498549
self._workflow_span = None
499550
self._invocation_span = None
500551
with self._lock:

packages/aws-durable-execution-sdk-python-otel/src/aws_durable_execution_sdk_python_otel/invocation_plugin.py

Lines changed: 50 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -137,6 +137,7 @@ def __init__(self, config: OtelPluginConfig | None = None) -> None:
137137
# per invocation status:
138138
self._execution_arn = ""
139139
self._execution_trace_id: int | None = None
140+
self._execution_start_time: datetime.datetime | None = None
140141
self._extracted_context: ExtractedContext | None = None
141142
self._execution_trace_context: ExecutionTraceContext | None = None
142143
self._sampling_intent: DurableSamplingIntent | None = None
@@ -511,6 +512,7 @@ def on_invocation_start(self, info: InvocationStartInfo) -> None:
511512
)
512513
self._tracing_enabled = False
513514
return
515+
self._execution_start_time = info.execution_start_time
514516
self._extracted_context = _ensure_extracted_context(
515517
self._context_extractor(info)
516518
)
@@ -550,20 +552,41 @@ def on_invocation_start(self, info: InvocationStartInfo) -> None:
550552
)
551553

552554
def _start_workflow_span(self, info: InvocationStartInfo) -> None:
553-
"""Create the deterministic, execution-scoped Workflow span.
555+
"""Install a non-recording placeholder for the execution-scoped Workflow span.
554556
555557
The Workflow span is keyed to a deterministic span ID derived from the
556558
execution ARN, so every invocation of the same durable execution
557-
contributes to one Workflow span. It is parented to the shared execution
558-
ancestor and exported once, on a terminal invocation. Operation and
559-
attempt spans link to it while remaining parented to the invocation
560-
span.
559+
contributes to one Workflow span. During each invocation the plugin only
560+
needs its deterministic SpanContext so operation and attempt spans can
561+
link to it while remaining parented to the invocation span; a
562+
non-recording placeholder fills that role so a non-terminal invocation
563+
never abandons a recording span. The recording span is created and ended
564+
once, on a terminal status, by :meth:`_export_workflow_span`.
561565
"""
562566
if not self._execution_arn:
563567
logger.warning("No execution ARN; skipping Workflow span creation")
564568
return
565569
if self._execution_trace_context is None:
566570
return
571+
workflow_span_context = SpanContext(
572+
trace_id=self._execution_trace_context.trace_id,
573+
span_id=derive_workflow_span_id(self._execution_arn),
574+
is_remote=False,
575+
trace_flags=self._execution_trace_context.trace_flags,
576+
trace_state=self._execution_trace_context.execution_ancestor.trace_state,
577+
)
578+
self._workflow_span = NonRecordingSpan(workflow_span_context)
579+
580+
def _export_workflow_span(self, info: InvocationEndInfo) -> None:
581+
"""Create and end the recording Workflow span once, on a terminal status.
582+
583+
Uses the same deterministic span ID as the placeholder and the shared
584+
execution ancestor as its parent, so the exported Workflow span stays on
585+
the execution trace and correlates with every operation span across all
586+
invocations. Anchored at the execution start time.
587+
"""
588+
if not self._execution_arn or self._execution_trace_context is None:
589+
return
567590
parent_context = self._with_sampling(
568591
trace.set_span_in_context(
569592
NonRecordingSpan(self._execution_trace_context.execution_ancestor),
@@ -574,13 +597,25 @@ def _start_workflow_span(self, info: InvocationStartInfo) -> None:
574597
trace_id=None,
575598
span_id=derive_workflow_span_id(self._execution_arn),
576599
):
577-
self._workflow_span = self._tracer.start_span(
600+
workflow_span = self._tracer.start_span(
578601
name=self._workflow_span_name,
579602
kind=SpanKind.INTERNAL,
580-
attributes={"durable.execution.arn": self._execution_arn},
581-
start_time=_to_otel_timestamp(info.execution_start_time),
603+
attributes={
604+
"durable.execution.arn": self._execution_arn,
605+
"durable.execution.status": (
606+
info.status.value if info.status else ""
607+
),
608+
},
609+
start_time=_to_otel_timestamp(self._execution_start_time),
582610
context=parent_context,
583611
)
612+
if info.status is InvocationStatus.FAILED:
613+
workflow_span.set_status(
614+
StatusCode.ERROR, info.error.message if info.error else ""
615+
)
616+
elif info.status is InvocationStatus.SUCCEEDED:
617+
workflow_span.set_status(StatusCode.OK)
618+
workflow_span.end()
584619

585620
def on_invocation_end(self, info: InvocationEndInfo) -> None:
586621
"""Called at the end of each invocation. Ends the invocation span and flushes."""
@@ -617,23 +652,12 @@ def on_invocation_end(self, info: InvocationEndInfo) -> None:
617652
# end the invocation span
618653
self._end_span(None)
619654

620-
# The Workflow span (execution view) is exported only on a terminal
621-
# status; on non-terminal statuses its reference is dropped without
622-
# ending it (so it is not exported yet). SUCCEEDED -> OK, FAILED -> ERROR;
623-
# RETRY/PENDING are non-terminal and leave it unexported.
624-
if self._workflow_span is not None:
625-
if info.status in _TERMINAL_INVOCATION_STATUSES:
626-
self._workflow_span.set_attribute(
627-
"durable.execution.status",
628-
info.status.value if info.status else "",
629-
)
630-
if info.status is InvocationStatus.FAILED:
631-
self._workflow_span.set_status(
632-
StatusCode.ERROR, info.error.message if info.error else ""
633-
)
634-
elif info.status is InvocationStatus.SUCCEEDED:
635-
self._workflow_span.set_status(StatusCode.OK)
636-
self._workflow_span.end()
655+
# The Workflow span (execution view) is a non-recording placeholder
656+
# during the invocation, so only a terminal status materializes and ends
657+
# the recording span. SUCCEEDED -> OK, FAILED -> ERROR; RETRY/PENDING are
658+
# non-terminal and leave it unexported until a later terminal invocation.
659+
if info.status in _TERMINAL_INVOCATION_STATUSES:
660+
self._export_workflow_span(info)
637661

638662
self._reset_state()
639663

@@ -649,6 +673,7 @@ def _reset_state(self) -> None:
649673
self._extracted_context = None
650674
self._execution_trace_context = None
651675
self._sampling_intent = None
676+
self._execution_start_time = None
652677
self._workflow_span = None
653678
self._span_time_floor_ns = None
654679
with self._operation_spans_lock:

0 commit comments

Comments
 (0)