[BUG] `execute_event_loop_cycle` spans all share the same OTel end_time

[Di-Is]

Checks

• I have updated to the lastest minor and patch version of Strands
• I have checked the documentation and this is not expected behavior
• I have searched ./issues and there are no duplicates of my issue

Strands Version

1.30.0 (regression since 1.24.0)

Python Version

3.13

Operating System

macOS

Installation Method

pip

Steps to Reproduce

1. Install strands-agents>=1.24.0 and opentelemetry-sdk
2. Configure an OTLP exporter (e.g., Langfuse self-hosted via OTLP HTTP)
3. Run a Strands Agent with a tool that triggers multiple execute_event_loop_cycle iterations:

uv run repro_span_endtime.py

repro_span_endtime.py — minimal reproduction script (requires OPENAI_API_KEY)

# /// script
# requires-python = ">=3.12"
# dependencies = ["strands-agents[otel]==1.30.0", "openai>=1.0"]
# ///
"""Reproduce: execute_event_loop_cycle spans all share the same OTel end_time.

Requires OPENAI_API_KEY (and optionally OPENAI_BASE_URL).
Run: uv run repro_span_endtime.py
"""

from __future__ import annotations

import asyncio

from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import SimpleSpanProcessor
from opentelemetry.sdk.trace.export.in_memory_span_exporter import InMemorySpanExporter

from strands import Agent, tool
from strands.models.openai import OpenAIModel

_exporter = InMemorySpanExporter()
_provider = TracerProvider()
_provider.add_span_processor(SimpleSpanProcessor(_exporter))
trace.set_tracer_provider(_provider)


@tool
def add(a: int, b: int) -> str:
    """Add two numbers."""
    return str(a + b)


async def _main() -> None:
    agent = Agent(
        model=OpenAIModel(model_id="gpt-5-mini"),
        tools=[add],
        system_prompt="Use the add tool for every calculation. Do not calculate in your head.",
        callback_handler=None,
        load_tools_from_directory=False,
    )

    await agent.invoke_async("Compute 1+2, then 3+4, then 5+6. Report each result.")
    _provider.force_flush()

    spans = _exporter.get_finished_spans()
    cycles = sorted(
        [s for s in spans if s.name == "execute_event_loop_cycle"],
        key=lambda s: s.start_time,
    )

    if not cycles:
        print("ERROR: no execute_event_loop_cycle spans found")
        return

    base = min(s.start_time for s in spans)
    print(f"\n  Found {len(cycles)} execute_event_loop_cycle spans:")
    print(f"  {'cycle':>8s}  {'start':>8s}  {'end':>8s}  {'duration':>10s}")
    print(f"  {'-' * 40}")
    for i, s in enumerate(cycles, 1):
        st = (s.start_time - base) / 1e6
        en = (s.end_time - base) / 1e6
        dur = (s.end_time - s.start_time) / 1e6
        print(f"  {'#' + str(i):>8s}  {st:>6.0f}ms  {en:>6.0f}ms  {dur:>8.0f}ms")

    ends = [s.end_time for s in cycles]
    spread_ms = (max(ends) - min(ends)) / 1e6
    print(f"\n  end_time spread: {spread_ms:.2f}ms")
    if spread_ms < 10:
        print("  ^^^ All cycle spans end at the same time (BUG)")
    else:
        print("  ^^^ Cycle spans have distinct end times (OK)")

    _provider.shutdown()


if __name__ == "__main__":
    asyncio.run(_main())

Change the version in PEP 723 metadata to compare across versions.

4. Inspect the exported traces — all execute_event_loop_cycle spans share the same endTimeUnixNano

Expected Behavior

Each execute_event_loop_cycle span should have its native OTel end_time set when the cycle actually completes, not when the entire agent invocation finishes.

v1.23.0 (correct):
cycle_1: 0ms → 6137ms  (dur=6137ms)
cycle_2:       6137ms → 8094ms (dur=1957ms)
                ^^^^ distinct end_times per cycle

Actual Behavior

All execute_event_loop_cycle spans have identical OTel end_time values equal to the agent's overall completion time. Earlier cycles show inflated durations in observability backends (Langfuse, Jaeger, etc.).

v1.24.0+ (bug):
cycle_1: 0ms    → 6120ms  (dur=6120ms)
cycle_2: 4604ms → 6120ms (dur=1516ms)
                   ^^^^ same end_time — all spans end together

Version	PR #1293 included	spans end_time spread	Result
1.23.0	No	1956.68ms	OK — spans end at correct per-cycle times
1.24.0	Yes	0.01ms	NG — all spans share the same end_time
1.30.0	Yes	0.01ms	NG — same

Additional Context

Root Cause

Regression introduced in v1.24.0 by PR #1293 — chore: refactor use_span to be closed automatically.

event_loop_cycle() is an async generator. The refactor wrapped its body in use_span(cycle_span, end_on_exit=True) and removed explicit span.end() / end_span_with_error() calls.

The problem: yield inside the with block passes events to the caller without exiting the context manager. Recursive cycles (recurse_event_loop → event_loop_cycle) create a nested yield chain where all with blocks remain open until the entire chain unwinds at agent completion — at which point all span.end() calls fire simultaneously.

Before PR #1293 (correct — v1.23.0)

# No use_span wrapper — spans were explicitly ended
tracer.end_event_loop_cycle_span(span=cycle_span, message=message)  # called span.end() internally

# Exception paths
except EventLoopException as e:
    tracer.end_span_with_error(cycle_span, str(e), e)  # called span.end()

After PR #1293 (current — v1.24.0+)

with trace_api.use_span(cycle_span, end_on_exit=True):
    async for tool_event in tool_events:
        yield tool_event  # keeps the with block open

    tracer.end_event_loop_cycle_span(cycle_span, message)  # sets attributes only, NO span.end()

except EventLoopException:
    raise  # end_span_with_error() was removed

end_event_loop_cycle_span() sets gen_ai.event.end_time as a span attribute at the correct time, but backends use the native OTel endTimeUnixNano (from span.end()).

Possible Solution

Switch end_on_exit=True to end_on_exit=False (preserving context attach/detach) and explicitly call span.end() in end_event_loop_cycle_span(), restoring end_span_with_error() in exception paths. This reverts the span lifecycle portion of PR #1293 while keeping use_span context propagation.

Related Issues

• PR #1293 — chore: refactor use_span to be closed automatically (regression source)

[Di-Is]

Closing as duplicate of #1930 — same root cause (PR #1293 use_span(end_on_exit=True) in async generator). Will add findings as a comment there.