diff --git a/A365_DOCUMENTATION.md b/A365_DOCUMENTATION.md index d3fbaed9..d102fa75 100644 --- a/A365_DOCUMENTATION.md +++ b/A365_DOCUMENTATION.md @@ -42,6 +42,8 @@ use_microsoft_opentelemetry( | `a365_scheduled_delay_ms` | `int` | `5000` | — | Delay between A365 export batches in milliseconds. | | `a365_exporter_timeout_ms` | `int` | `30000` | — | Timeout for a single A365 export operation in milliseconds. | | `a365_max_export_batch_size` | `int` | `512` | — | Maximum batch size for a single A365 export operation. | +| `a365_exporter_disable_offline_storage` | `bool` | `False` | — | Disable durable offline storage. When `True`, failed exports are not persisted to disk and at-least-once delivery is not guaranteed. Defaults to `False` (storage enabled). | +| `a365_exporter_storage_directory` | `str` | `None` | — | Custom directory for durable offline storage. When `None`, a platform default path is used. Choose a path that only the current user or service account can read, because stored OTLP payloads may contain prompts or completions when sensitive-data capture is enabled. | ### Resource / Service Name @@ -83,6 +85,52 @@ use_microsoft_opentelemetry( ) ``` +### Durable Delivery (Offline Storage) + +When `a365_enable_observability_exporter=True`, the A365 exporter persists failed export payloads to disk and replays them once connectivity is restored — providing **at-least-once delivery** semantics. + +Key defaults and limits: + +| Property | Value | +|---|---| +| Enabled by default | Yes (when exporter is active) | +| Retention window | 2 days | +| Maximum storage size | 50 MB | +| Storage path | Platform default (see below) | + +The default path is a sub-directory of the platform's local app data folder, +derived from the user, executable, and working directory. Processes for the +same application can share the SQLite queue; leases coordinate replay across +those processes. + +**Replay behavior:** + +- Each queued record stores only its identity (tenant, agent, agentic user, S2S flag) and payload — not a fixed URL. On replay, the exporter reconstructs the export endpoint from the exporter's *current* configuration and re-resolves a fresh bearer token, so records queued before an endpoint or credential change are still delivered correctly, and any endpoint that would not resolve to HTTPS is rejected rather than replayed. +- Records that are permanently rejected by the service (e.g. `400 Bad Request`) or that fail internal validation (unsupported schema version, blank tenant/agent id, or blank payload — "poison" records) are discarded from the durable queue instead of being retried forever. +- `shutdown()` is drain-safe: it signals the background replay loop to stop and blocks until any in-flight replay send actually finishes before closing the durable store and HTTP session, so an in-progress send is never left holding a closed resource and no accepted span is dropped mid-flight. Concurrent `shutdown()` callers all wait for that same cleanup to complete. + +**To disable durable storage** (no disk writes, best-effort delivery only): + +```python +use_microsoft_opentelemetry( + enable_a365=True, + a365_enable_observability_exporter=True, + a365_exporter_disable_offline_storage=True, +) +``` + +**To specify a custom storage directory:** + +```python +use_microsoft_opentelemetry( + enable_a365=True, + a365_enable_observability_exporter=True, + a365_exporter_storage_directory="/var/lib/my-agent/telemetry", +) +``` + +> **Security note:** Stored OTLP payloads are unencrypted. When sensitive-data capture is enabled (`enable_sensitive_data=True`), payloads may include prompts, completions, or tool arguments. Restrict the storage directory to the service account running the agent (e.g., `chmod 700`). + ## Auto-Instrumented Libraries It auto-discovers and activates supported instrumentors via OpenTelemetry entry points. No manual `instrument()` calls are needed. diff --git a/CHANGELOG.md b/CHANGELOG.md index 8198becd..943086da 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,18 @@ ### Features Added - Add support for agent identity propagation for compiled agents in nested graph ([#245](https://github.com/microsoft/opentelemetry-distro-python/pull/245)) +- Expose A365 offline storage options: `a365_exporter_disable_offline_storage` (default `False`) + and `a365_exporter_storage_directory` (default `None`) on `use_microsoft_opentelemetry`, + `Agent365ExporterOptions`, and `create_a365_components`. + When `a365_enable_observability_exporter=True`, the exporter provides at-least-once delivery + by persisting failed payloads to disk (up to 2 days / 50 MB) and replaying them on recovery. + Set `a365_exporter_disable_offline_storage=True` to opt out. + Stored payloads are unencrypted; restrict the storage path to the service account, especially + when `enable_sensitive_data=True` (payloads may contain prompts or completions). + Replay reconstructs the current HTTPS export endpoint and bearer token at send time rather + than reusing a stale URL, permanently-rejected or malformed ("poison") records are discarded + instead of retried forever, and `shutdown()` is drain-safe: it waits for any in-flight replay + send to finish before closing the durable store and HTTP session (parity with `.NET` PR #137). # 1.3.7 (2026-08-05) ### Features Added diff --git a/README.md b/README.md index 0397deb9..883eb5aa 100644 --- a/README.md +++ b/README.md @@ -117,6 +117,8 @@ See the [A365 guide](https://github.com/microsoft/opentelemetry-distro-python/bl | `a365_scheduled_delay_ms` | `int` | `5000` | Delay between A365 export batches (ms). | | `a365_exporter_timeout_ms` | `int` | `30000` | Timeout for a single A365 export operation (ms). | | `a365_max_export_batch_size` | `int` | `512` | Maximum batch size for a single A365 export operation. | +| `a365_exporter_disable_offline_storage` | `bool` | `False` | Disable durable offline storage. When `True`, failed exports are not persisted to disk. | +| `a365_exporter_storage_directory` | `str` | `None` | Custom directory for durable offline storage. Restrict to the service account; payloads may contain prompts or completions when sensitive-data capture is enabled. | > For A365 token resolver patterns, baggage, and scope classes, see the [A365 guide](https://github.com/microsoft/opentelemetry-distro-python/blob/main/A365_DOCUMENTATION.md). diff --git a/docs/superpowers/plans/2026-08-12-a365-durable-delivery.md b/docs/superpowers/plans/2026-08-12-a365-durable-delivery.md new file mode 100644 index 00000000..512b5657 --- /dev/null +++ b/docs/superpowers/plans/2026-08-12-a365-durable-delivery.md @@ -0,0 +1,449 @@ +# Agent365 Durable Delivery Implementation Plan + +> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking. + +**Goal:** Add secure, standard-library durable store-and-forward delivery to the Python Agent365 exporter so retryable telemetry survives throttling, outages, and process restarts. + +**Architecture:** A per-identity transmission gate classifies whether live or replay sends may proceed. A SQLite queue stores serialized request envelopes atomically, and one exporter-owned daemon replay thread resolves fresh tokens and retries leased records. The existing OpenTelemetry `BatchSpanProcessor` remains unchanged. + +**Tech Stack:** Python 3.10+, `sqlite3`, `threading`, `pathlib`, `tempfile`, `hashlib`, `json`, `requests`, `pytest`/`unittest`. + +## Global Constraints + +- Use only the Python standard library for persistence and replay. +- Persistence is enabled by default; `disable_offline_storage=True` opts out. +- Default retention is two days and default capacity is 50 MB. +- POSIX storage directories must be mode `0700`; the database must be mode `0600`. +- Gate state is partitioned by `(tenant_id, agent_id, agentic_user_id, use_s2s_endpoint)`. +- Retryable outcomes are HTTP 401, 408, 429, 5xx, transport errors, and timeouts. +- HTTP 403 and other 4xx outcomes are permanent. +- `SpanExportResult.SUCCESS` means every chunk was delivered or durably stored. +- Do not replace or reimplement OpenTelemetry's `BatchSpanProcessor`. + +--- + +### Task 1: Delivery dispositions and per-identity gate + +**Files:** +- Create: `src/microsoft/opentelemetry/a365/core/exporters/durable_delivery.py` +- Create: `tests/a365/test_durable_delivery.py` + +**Interfaces:** +- Produces: `DeliveryDisposition`, `DeliveryResult`, `IdentityKey`, and `TransmissionGate`. +- `TransmissionGate.try_acquire(key: IdentityKey) -> bool` +- `TransmissionGate.record_success(key: IdentityKey) -> None` +- `TransmissionGate.record_retryable_failure(key: IdentityKey, retry_after: float | None) -> None` +- `TransmissionGate.release_probe(key: IdentityKey) -> None` + +- [ ] **Step 1: Write failing gate tests** + +```python +def test_gate_isolates_identities(): + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + first = IdentityKey("t1", "a1", None, False) + second = IdentityKey("t2", "a2", None, False) + gate.record_retryable_failure(first, retry_after=30) + assert not gate.try_acquire(first) + assert gate.try_acquire(second) + + +def test_gate_allows_only_one_half_open_probe(): + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + gate.record_retryable_failure(key, retry_after=10) + clock.advance(10) + assert gate.try_acquire(key) + assert not gate.try_acquire(key) +``` + +- [ ] **Step 2: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_durable_delivery.py -q` + +Expected: collection fails because `durable_delivery` does not exist. + +- [ ] **Step 3: Implement delivery types and gate** + +```python +class DeliveryDisposition(Enum): + DELIVERED = "delivered" + RETRYABLE = "retryable" + PERMANENT = "permanent" + + +@dataclass(frozen=True) +class DeliveryResult: + disposition: DeliveryDisposition + retry_after: float | None = None + + +@dataclass(frozen=True) +class IdentityKey: + tenant_id: str + agent_id: str + agentic_user_id: str | None + use_s2s_endpoint: bool +``` + +Implement a lock-protected dictionary of `_GateState` values. Use +`time.monotonic` and `random.random` as injectable callables. Clamp explicit +`Retry-After` to `[10, 3600]`; otherwise compute full jitter over an exponential +window with a 10-second floor and one-hour cap. + +- [ ] **Step 4: Run gate tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_durable_delivery.py -q` + +Expected: PASS. + +- [ ] **Step 5: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\durable_delivery.py tests\a365\test_durable_delivery.py +git commit -m "Add A365 transmission gate" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 2: Secure SQLite durable queue + +**Files:** +- Create: `src/microsoft/opentelemetry/a365/core/exporters/persistent_storage.py` +- Create: `tests/a365/test_persistent_storage.py` + +**Interfaces:** +- Consumes: `IdentityKey`. +- Produces: `DurableRecord` and `PersistentStorage`. +- `PersistentStorage.store(record: DurableRecord) -> bool` +- `PersistentStorage.claim(limit: int, lease_seconds: float) -> list[DurableRecord]` +- `PersistentStorage.delete(record_id: int) -> bool` +- `PersistentStorage.release(record_id: int) -> bool` +- `PersistentStorage.close() -> None` + +- [ ] **Step 1: Write failing storage tests** + +```python +def test_store_claim_delete_round_trip(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + record = DurableRecord.new(KEY, "https://example.test", '{"resourceSpans":[]}') + assert storage.store(record) + claimed = storage.claim(limit=10, lease_seconds=30) + assert [item.payload for item in claimed] == [record.payload] + assert storage.delete(claimed[0].record_id) + assert storage.claim(limit=10, lease_seconds=30) == [] + + +@pytest.mark.skipif(os.name == "nt", reason="POSIX permissions") +def test_storage_permissions_are_private(tmp_path): + storage = PersistentStorage(tmp_path / "queue") + assert stat.S_IMODE((tmp_path / "queue").stat().st_mode) == 0o700 + assert stat.S_IMODE(storage.database_path.stat().st_mode) == 0o600 +``` + +Add tests for expired-record cleanup, capacity rejection, lease release, and +pre-existing POSIX directories owned by another UID using mocked `Path.stat`. + +- [ ] **Step 2: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_persistent_storage.py -q` + +Expected: collection fails because `persistent_storage` does not exist. + +- [ ] **Step 3: Implement storage** + +Use one SQLite connection with `check_same_thread=False`, guarded by +`threading.RLock`. Create this schema: + +```sql +CREATE TABLE IF NOT EXISTS durable_records ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + schema_version INTEGER NOT NULL, + tenant_id TEXT NOT NULL, + agent_id TEXT NOT NULL, + agentic_user_id TEXT, + use_s2s_endpoint INTEGER NOT NULL, + url TEXT NOT NULL, + payload TEXT NOT NULL, + created_at REAL NOT NULL, + lease_until REAL, + retry_count INTEGER NOT NULL DEFAULT 0 +) +``` + +Use `BEGIN IMMEDIATE` when claiming records. Select unleased rows ordered by +`created_at`, update their `lease_until`, then commit. Before inserts, delete +expired rows and reject the insert when `page_count * page_size + payload bytes` +would exceed capacity. Return `False` and log on `sqlite3.Error`; do not swallow +the error as success. + +Default directory resolution hashes `getpass.getuser()`, `sys.executable`, and +`Path.cwd()` with SHA-256. Prefer `%LOCALAPPDATA%` on Windows and +`$XDG_STATE_HOME`/`~/.local/state` elsewhere, with `tempfile.gettempdir()` as +the final fallback. + +- [ ] **Step 4: Run storage tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_persistent_storage.py -q` + +Expected: PASS. + +- [ ] **Step 5: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\persistent_storage.py tests\a365\test_persistent_storage.py +git commit -m "Add secure A365 persistent storage" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 3: Replay coordinator + +**Files:** +- Create: `src/microsoft/opentelemetry/a365/core/exporters/replay_coordinator.py` +- Create: `tests/a365/test_replay_coordinator.py` + +**Interfaces:** +- Consumes: `PersistentStorage`, `TransmissionGate`, `DeliveryResult`, + `Callable[[DurableRecord], DeliveryResult]`. +- Produces: `ReplayCoordinator.start()`, `wake()`, and + `shutdown(timeout_seconds: float) -> bool`. + +- [ ] **Step 1: Write failing replay tests** + +```python +def test_replay_deletes_delivered_record(): + storage = FakeStorage([RECORD]) + coordinator = ReplayCoordinator(storage, GATE, send=lambda record: DeliveryResult(DELIVERED)) + coordinator.run_once() + assert storage.deleted == [RECORD.record_id] + + +def test_replay_retains_retryable_record_and_updates_gate(): + storage = FakeStorage([RECORD]) + gate = MagicMock() + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(RETRYABLE, retry_after=45), + ) + coordinator.run_once() + assert storage.released == [RECORD.record_id] + gate.record_retryable_failure.assert_called_once_with(RECORD.identity, 45) +``` + +Also test permanent deletion, token resolver exceptions retaining records, +wake-up behavior, and idempotent bounded shutdown. + +- [ ] **Step 2: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_replay_coordinator.py -q` + +Expected: collection fails because `replay_coordinator` does not exist. + +- [ ] **Step 3: Implement coordinator** + +Use one daemon `threading.Thread`, a stop `Event`, and a wake `Event`. +`run_once()` claims at most ten records. On delivered/permanent results, delete +the record. On retryable results or exceptions, release the record. Stop the +current pass after a retryable network result so the gate controls subsequent +work, but continue after an identity-specific token resolution exception. + +- [ ] **Step 4: Run replay tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_replay_coordinator.py -q` + +Expected: PASS. + +- [ ] **Step 5: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\replay_coordinator.py tests\a365\test_replay_coordinator.py +git commit -m "Add A365 durable replay coordinator" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 4: Integrate durable delivery into the exporter + +**Files:** +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py` +- Modify: `tests/a365/test_exporter.py` +- Modify: `tests/a365/test_circuit_breaker.py` +- Create: `tests/a365/test_durable_restart.py` + +**Interfaces:** +- Consumes all components from Tasks 1-3. +- `_post_once(url, body, headers) -> DeliveryResult` +- `_persist(identity, url, body) -> bool` +- `_replay_record(record: DurableRecord) -> DeliveryResult` + +- [ ] **Step 1: Write failing exporter behavior tests** + +```python +def test_retryable_failure_returns_success_when_payload_is_stored(): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=DeliveryResult(RETRYABLE, 30)) + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + assert exporter.export([_make_span()]) is SpanExportResult.SUCCESS + + +def test_permanent_failure_is_not_stored(): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=DeliveryResult(PERMANENT)) + exporter._storage = MagicMock() + assert exporter.export([_make_span()]) is SpanExportResult.FAILURE + exporter._storage.store.assert_not_called() + + +def test_token_resolver_exception_is_stored_but_empty_token_is_permanent(): + # Use separate exporters to assert exception => stored SUCCESS and None => FAILURE. +``` + +Add a restart test that stores with exporter A, shuts it down, creates exporter +B on the same storage directory, resolves a fresh token, replays, and empties +the queue. + +- [ ] **Step 2: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_exporter.py tests\a365\test_durable_restart.py -q` + +Expected: FAIL because exporter construction and HTTP results do not support +durable storage. + +- [ ] **Step 3: Replace boolean HTTP helper with classified single-send** + +Keep existing logging and SDKStats calls. Return delivered for 2xx, retryable +for 401/408/429/5xx and `requests.RequestException`, and permanent for other +responses. Parse `Retry-After` without sleeping. Remove `_CircuitBreaker` after +moving its half-open behavior to `TransmissionGate`; update its dedicated tests +to cover `TransmissionGate` instead. + +- [ ] **Step 4: Wire storage and replay into export** + +Build `IdentityKey` from each group, including the first span's +`GEN_AI_AGENT_AUID_KEY`. If the gate rejects a send, persist immediately. If a +send is retryable, update the gate and persist. Wake replay after successful +persistence. Start replay lazily and make `shutdown()` idempotently stop replay, +close storage, and close the requests session. + +- [ ] **Step 5: Run exporter and restart tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_exporter.py tests\a365\test_durable_delivery.py tests\a365\test_persistent_storage.py tests\a365\test_replay_coordinator.py tests\a365\test_durable_restart.py -q` + +Expected: PASS. + +- [ ] **Step 6: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\agent365_exporter.py tests\a365 +git commit -m "Add durable delivery to A365 exporter" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 5: Wire public options and configuration + +**Files:** +- Modify: `src/microsoft/opentelemetry/_constants.py` +- Modify: `src/microsoft/opentelemetry/_distro.py` +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter_options.py` +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/utils.py` +- Modify: `tests/test_distro.py` +- Modify: `tests/a365/test_handler.py` +- Modify: `README.md` +- Modify: `A365_DOCUMENTATION.md` +- Modify: `CHANGELOG.md` + +**Interfaces:** +- Produces public kwargs `a365_exporter_disable_offline_storage` and + `a365_exporter_storage_directory`. +- Extends `_Agent365Exporter.__init__` with `disable_offline_storage: bool = False` + and `storage_directory: str | None = None`. + +- [ ] **Step 1: Write failing option-forwarding tests** + +```python +use_microsoft_opentelemetry( + enable_a365=True, + a365_exporter_disable_offline_storage=True, + a365_exporter_storage_directory="C:\\telemetry", +) +assert kwargs["disable_offline_storage"] is True +assert kwargs["storage_directory"] == "C:\\telemetry" +``` + +Add equivalent assertions for `Agent365ExporterOptions` and +`create_a365_components`. + +- [ ] **Step 2: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\test_distro.py tests\a365\test_handler.py -q` + +Expected: FAIL because the kwargs are not parsed or forwarded. + +- [ ] **Step 3: Implement option propagation** + +Add constants, pop the kwargs in `use_microsoft_opentelemetry`, forward them to +`_append_a365_components`, and pass them to `_Agent365Exporter`. Extend +`Agent365ExporterOptions` and `create_a365_components` with the same defaults. + +- [ ] **Step 4: Document behavior and sensitive-data implications** + +Document default persistence, secure path selection, the two new options, +at-least-once replay, the two-day/50-MB limits, and that stored OTLP payloads may +contain prompts or responses when sensitive-data capture is enabled. + +- [ ] **Step 5: Run configuration tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\test_distro.py tests\a365\test_handler.py -q` + +Expected: PASS. + +- [ ] **Step 6: Commit** + +```powershell +git add src\microsoft\opentelemetry\_constants.py src\microsoft\opentelemetry\_distro.py src\microsoft\opentelemetry\a365\core\exporters tests\test_distro.py tests\a365\test_handler.py README.md A365_DOCUMENTATION.md CHANGELOG.md +git commit -m "Expose A365 offline storage options" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 6: Full validation + +**Files:** +- Modify only files needed to fix failures introduced by Tasks 1-5. + +**Interfaces:** +- Produces a release-ready feature with no new dependency. + +- [ ] **Step 1: Run focused A365 tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365 tests\test_distro.py -q` + +Expected: PASS. + +- [ ] **Step 2: Run static checks used by the repository** + +Run: `.venv\Scripts\python.exe -m black --check src tests` + +Expected: PASS. + +Run: `.venv\Scripts\python.exe -m pylint src\microsoft\opentelemetry\a365 src\microsoft\opentelemetry\_distro.py` + +Expected: PASS. + +Run: `.venv\Scripts\python.exe -m mypy src\microsoft\opentelemetry\a365` + +Expected: PASS. + +- [ ] **Step 3: Run the complete test suite** + +Run: `.venv\Scripts\python.exe -m pytest -q` + +Expected: PASS. + +- [ ] **Step 4: Confirm no dependency was added** + +Run: `git --no-pager diff HEAD~5 -- pyproject.toml uv.lock` + +Expected: no changes. + +- [ ] **Step 5: Commit any validation fixes** + +```powershell +git add src tests README.md A365_DOCUMENTATION.md CHANGELOG.md +git commit -m "Validate A365 durable delivery" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` diff --git a/docs/superpowers/plans/2026-08-14-a365-durable-delivery-hardening.md b/docs/superpowers/plans/2026-08-14-a365-durable-delivery-hardening.md new file mode 100644 index 00000000..7f4e7adf --- /dev/null +++ b/docs/superpowers/plans/2026-08-14-a365-durable-delivery-hardening.md @@ -0,0 +1,442 @@ +# Agent365 Durable Delivery Hardening Implementation Plan + +> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking. + +**Goal:** Align Python Agent365 durable delivery with the hardened behavioral guarantees in `microsoft/opentelemetry-distro-dotnet#137`. + +**Architecture:** Retain the Python SQLite queue and exporter structure, but strengthen their contracts. Add an Agent365-owned batch worker for atomic producer capacity and deterministic lifecycle, persist identity rather than URLs, reconstruct validated HTTPS endpoints during replay, and make retry/replay outcomes explicit and testable. + +**Tech Stack:** Python 3.10+, `threading`, `collections.deque`, `sqlite3`, `email.utils`, `requests`, OpenTelemetry SDK, pytest/unittest. + +## Global Constraints + +- Keep persistence dependency-free and SQLite-backed. +- Preserve the public Agent365 option names and defaults. +- Healthy closed-state sends remain concurrent; only half-open probes are exclusive. +- Positive `Retry-After` values are honored exactly up to 3600 seconds. +- Durable replay never sends credentials over plaintext HTTP. +- `SpanExportResult.SUCCESS` still means every chunk was delivered or durably stored. +- Shutdown must not close exporter resources underneath active export or replay work. +- Every regression begins with a test that fails against commit `822b544`. + +--- + +### Task 1: Retry Timing and Gate State + +**Files:** +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/durable_delivery.py` +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/utils.py` +- Test: `tests/a365/test_durable_delivery.py` +- Test: `tests/a365/test_circuit_breaker.py` +- Test: `tests/a365/test_utils.py` + +**Interfaces:** +- Produces: `parse_retry_after(headers, now=None) -> float | None`. +- Produces: `TransmissionGate.try_acquire(key) -> bool` where closed-state calls are unrestricted and only an expired backoff grants one probe. + +- [ ] **Step 1: Add failing retry parsing tests** + +```python +def test_parse_retry_after_http_date(): + now = datetime(2026, 8, 14, 18, 0, tzinfo=timezone.utc) + headers = {"Retry-After": "Fri, 14 Aug 2026 18:00:42 GMT"} + assert parse_retry_after(headers, now=lambda: now) == 42.0 + + +def test_parse_retry_after_past_date_returns_non_positive(): + now = datetime(2026, 8, 14, 18, 1, tzinfo=timezone.utc) + headers = {"Retry-After": "Fri, 14 Aug 2026 18:00:42 GMT"} + assert parse_retry_after(headers, now=lambda: now) == -18.0 +``` + +- [ ] **Step 2: Add failing gate tests** + +```python +def test_closed_gate_allows_concurrent_sends(): + gate = TransmissionGate() + assert gate.try_acquire(KEY) + assert gate.try_acquire(KEY) + + +def test_positive_retry_after_is_honored_without_flooring(): + clock = FakeClock() + gate = TransmissionGate(clock=clock) + gate.record_retryable_failure(KEY, 1.5) + clock.advance(1.49) + assert not gate.try_acquire(KEY) + clock.advance(0.01) + assert gate.try_acquire(KEY) + + +def test_non_positive_retry_after_uses_jitter(): + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + gate.record_retryable_failure(KEY, 0) + clock.advance(9.99) + assert not gate.try_acquire(KEY) +``` + +- [ ] **Step 3: Run the focused tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_utils.py tests\a365\test_durable_delivery.py tests\a365\test_circuit_breaker.py -q` + +Expected: HTTP-date, closed concurrency, exact positive delay, and non-positive fallback tests fail. + +- [ ] **Step 4: Implement date parsing and explicit gate phases** + +Use `email.utils.parsedate_to_datetime`. Represent gate state with `blocked_until`, `failure_count`, and `probe_acquired`; do not create state on a healthy `try_acquire`. When `blocked_until == 0`, return `True`. When backoff expires, atomically set `probe_acquired=True`. In `_resolve_retry_delay`, use explicit delay only when `retry_after > 0`; cap it with `min(retry_after, 3600.0)`, otherwise call `_full_jitter_backoff`. + +- [ ] **Step 5: Run the focused tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_utils.py tests\a365\test_durable_delivery.py tests\a365\test_circuit_breaker.py -q` + +Expected: PASS. + +- [ ] **Step 6: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\durable_delivery.py src\microsoft\opentelemetry\a365\core\exporters\utils.py tests\a365\test_utils.py tests\a365\test_durable_delivery.py tests\a365\test_circuit_breaker.py +git commit -m "Harden A365 retry timing and transmission gate" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 2: Validated Identity-Only Durable Records + +**Files:** +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/persistent_storage.py` +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py` +- Test: `tests/a365/test_persistent_storage.py` +- Test: `tests/a365/test_durable_restart.py` +- Test: `tests/a365/test_exporter.py` + +**Interfaces:** +- Changes: `DurableRecord.new(key: IdentityKey, payload: str) -> DurableRecord`. +- Removes: persisted `url`. +- Produces: `PersistentStorage.claim()` that deletes invalid records and returns only schema-valid records. + +- [ ] **Step 1: Add failing schema and poison-record tests** + +```python +@pytest.mark.parametrize("column,value", [ + ("schema_version", 999), + ("tenant_id", ""), + ("agent_id", ""), + ("payload", ""), +]) +def test_claim_deletes_invalid_records_and_continues(storage, column, value): + invalid_id = insert_raw_record(storage, **{column: value}) + valid = DurableRecord.new(KEY, '{"resourceSpans":[]}') + assert storage.store(valid) + claimed = storage.claim(limit=10, lease_seconds=30) + assert [record.payload for record in claimed] == [valid.payload] + assert not raw_record_exists(storage, invalid_id) +``` + +- [ ] **Step 2: Add failing endpoint reconstruction tests** + +```python +def test_replay_builds_endpoint_from_record_identity(exporter): + record = DurableRecord.new(KEY, '{"resourceSpans":[]}') + exporter._post_once = MagicMock(return_value=DELIVERED_RESULT) + exporter._replay_record(record) + sent_url = exporter._post_once.call_args.args[0] + assert "/tenants/tenant/otlp/agents/agent/traces" in sent_url + + +def test_plaintext_replay_retains_record_without_sending(exporter, monkeypatch): + monkeypatch.setattr(exporter, "_domain_override", "http://example.test") + exporter._post_once = MagicMock() + with pytest.raises(ReplayEndpointError): + exporter._replay_record(DurableRecord.new(KEY, "{}")) + exporter._post_once.assert_not_called() +``` + +- [ ] **Step 3: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_persistent_storage.py tests\a365\test_durable_restart.py tests\a365\test_exporter.py -q` + +Expected: invalid rows are returned, records require URLs, and replay uses persisted URLs. + +- [ ] **Step 4: Migrate the SQLite schema safely** + +Create schema version 2 without `url`. On initialization, inspect `PRAGMA table_info(durable_records)`; if the legacy `url` column exists, create `durable_records_v2`, copy identity/payload/timestamps, drop the old table, and rename the new table in one `BEGIN IMMEDIATE` transaction. Validate supported schema and non-blank tenant, agent, and payload during `claim`; delete invalid rows in the same transaction. + +- [ ] **Step 5: Reconstruct and validate replay endpoints** + +Add `ReplayEndpointError` as a retryable replay-stop condition. Build the URL from current `_domain_override or DEFAULT_ENDPOINT_URL` plus record identity. Reject any parsed scheme other than `https` before resolving or attaching the token. Persist only identity and payload. + +- [ ] **Step 6: Run tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_persistent_storage.py tests\a365\test_durable_restart.py tests\a365\test_exporter.py -q` + +Expected: PASS. + +- [ ] **Step 7: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\persistent_storage.py src\microsoft\opentelemetry\a365\core\exporters\agent365_exporter.py tests\a365\test_persistent_storage.py tests\a365\test_durable_restart.py tests\a365\test_exporter.py +git commit -m "Validate A365 durable records and replay endpoints" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 3: Replay Terminal-State Accounting + +**Files:** +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/replay_coordinator.py` +- Test: `tests/a365/test_replay_coordinator.py` + +**Interfaces:** +- Produces: `_delete_record(record, reason) -> bool`. +- Consumes: `ReplayIdentityError` and `ReplayEndpointError` as record-retaining conditions. + +- [ ] **Step 1: Add failing deletion and endpoint tests** + +```python +def test_delete_failure_after_success_logs_duplicate_risk(caplog): + storage = FakeStorage([RECORD], delete_result=False) + coordinator = ReplayCoordinator(storage, GATE, send=lambda _: DELIVERED_RESULT) + coordinator.run_once() + assert "duplicate delivery" in caplog.text.lower() + + +def test_endpoint_error_retains_record_and_stops_pass(): + storage = FakeStorage([RECORD, SECOND_RECORD]) + coordinator = ReplayCoordinator(storage, GATE, send=raise_endpoint_error) + assert not coordinator.run_once() + assert storage.released == [RECORD.record_id, SECOND_RECORD.record_id] +``` + +- [ ] **Step 2: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_replay_coordinator.py -q` + +Expected: delete failure is counted as terminal and endpoint errors use the unexpected-error path. + +- [ ] **Step 3: Implement explicit terminal accounting** + +Return the result of `storage.delete`. Increment `deleted_count` only on success. Log record ID and duplicate risk after delivered-delete failure. For permanent-delete failure, log that the poison record may recur. Catch `ReplayEndpointError`, release current and remaining records, release the gate probe, and stop the pass. + +- [ ] **Step 4: Run tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_replay_coordinator.py -q` + +Expected: PASS. + +- [ ] **Step 5: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\replay_coordinator.py tests\a365\test_replay_coordinator.py +git commit -m "Harden A365 replay terminal accounting" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 4: Export Isolation and Configuration Validation + +**Files:** +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py` +- Modify: `src/microsoft/opentelemetry/_distro.py` +- Test: `tests/a365/test_exporter.py` +- Test: `tests/test_distro.py` + +**Interfaces:** +- Produces: permanent failure breaks only the current identity's chunk loop. +- Produces: `_validate_a365_batch_options(...) -> None`, called before the broad component-construction handler. + +- [ ] **Step 1: Add failing permanent-chunk test** + +```python +def test_permanent_first_chunk_stops_identity_but_other_identity_continues(exporter): + exporter._post_once.side_effect = [PERMANENT_RESULT, DELIVERED_RESULT] + result = exporter.export(spans_for_two_identities(first_identity_has_two_chunks=True)) + assert result is SpanExportResult.FAILURE + assert exporter._post_once.call_count == 2 +``` + +- [ ] **Step 2: Add failing public validation tests** + +```python +@pytest.mark.parametrize("kwargs", [ + {"max_queue_size": 0}, + {"scheduled_delay_ms": 0}, + {"max_export_batch_size": 0}, + {"max_queue_size": 10, "max_export_batch_size": 11}, +]) +def test_invalid_a365_batch_configuration_raises(kwargs): + with pytest.raises(ValueError): + _append_a365_components(True, {"span_processors": []}, enable_observability_exporter=True, **kwargs) +``` + +- [ ] **Step 3: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_exporter.py tests\test_distro.py -q` + +Expected: later chunks are sent and invalid configuration is swallowed. + +- [ ] **Step 4: Implement isolation and validation** + +Break the chunk loop after a permanent disposition. Continue the outer identity loop. Validate queue size and delay are at least 1, batch size is at least 1, and batch size does not exceed queue size. Run validation before entering the existing broad `try`. + +- [ ] **Step 5: Run tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_exporter.py tests\test_distro.py -q` + +Expected: PASS. + +- [ ] **Step 6: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\agent365_exporter.py src\microsoft\opentelemetry\_distro.py tests\a365\test_exporter.py tests\test_distro.py +git commit -m "Isolate A365 permanent failures and validate batching" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 5: Atomic Agent365 Batch Processor + +**Files:** +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/enriching_span_processor.py` +- Test: `tests/a365/test_enriching_span_processor.py` + +**Interfaces:** +- Keeps: `_EnrichingBatchSpanProcessor(exporter, max_queue_size, schedule_delay_millis, export_timeout_millis, max_export_batch_size, suppress_invoke_agent_input)`. +- Produces: atomic acceptance, drain-safe shutdown, idempotent exporter shutdown, and force-flush completion accounting. + +- [ ] **Step 1: Add failing concurrent capacity test** + +Create a blocking fake exporter and use a barrier to call `on_end` from more threads than queue capacity. Assert accepted spans equal exported spans plus explicitly rejected spans; no accepted span is silently evicted. + +- [ ] **Step 2: Add failing lifecycle tests** + +Add tests named: + +```python +def test_shutdown_drains_every_accepted_span(): ... +def test_shutdown_waits_for_active_export_before_exporter_shutdown(): ... +def test_shutdown_timeout_leaves_worker_owning_cleanup(): ... +def test_concurrent_shutdown_calls_exporter_shutdown_once(): ... +def test_on_end_racing_shutdown_never_strands_or_throws(): ... +``` + +- [ ] **Step 3: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_enriching_span_processor.py -q` + +Expected: standard SDK processor silently evicts under the capacity race and does not satisfy lifecycle ordering. + +- [ ] **Step 4: Implement the owned worker** + +Replace inheritance from SDK `BatchSpanProcessor` with a `SpanProcessor` implementation backed by `deque`, one `Condition`, and explicit counters for queued and active exports. Reserve capacity and enqueue under the same lock. The worker drains up to `max_export_batch_size`, exports outside the lock, then signals flush/shutdown waiters. Shutdown sets `accepting=False`, wakes the worker, and waits; only the worker calls exporter shutdown after queue and active export are empty. Multiple shutdown callers wait on the same completion event. Preserve current enrichment and suppression before atomic enqueue. + +- [ ] **Step 5: Run processor tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_enriching_span_processor.py -q` + +Expected: PASS. + +- [ ] **Step 6: Run distro construction tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\test_distro.py -q` + +Expected: PASS with the same constructor surface. + +- [ ] **Step 7: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\enriching_span_processor.py tests\a365\test_enriching_span_processor.py tests\test_distro.py +git commit -m "Add drain-safe A365 batch processing" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 6: Exporter and Replay Shutdown Ownership + +**Files:** +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py` +- Modify: `src/microsoft/opentelemetry/a365/core/exporters/replay_coordinator.py` +- Test: `tests/a365/test_exporter.py` +- Test: `tests/a365/test_replay_coordinator.py` +- Test: `tests/a365/test_durable_restart.py` + +**Interfaces:** +- Produces: `ReplayCoordinator.shutdown(timeout_seconds: float | None = None) -> bool`. +- Produces: exporter resources close only after replay termination and exactly once. + +- [ ] **Step 1: Add failing active-replay shutdown tests** + +Use events to block replay inside `_send`. Call exporter shutdown concurrently and assert storage/session remain open until `_send` exits. Add two concurrent shutdown callers and assert storage/session close once. + +- [ ] **Step 2: Run tests and verify failure** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_exporter.py tests\a365\test_replay_coordinator.py tests\a365\test_durable_restart.py -q` + +Expected: exporter closes resources after the fixed five-second join even when replay remains active. + +- [ ] **Step 3: Implement cleanup ownership** + +Make the processor worker's exporter shutdown unbounded after accepted work drains. Inside exporter shutdown, signal replay and wait until it exits before closing storage/session. Preserve idempotence with a completion event and a single cleanup owner; concurrent callers wait for that event. Do not close resources when a bounded replay wait reports the thread is alive. + +- [ ] **Step 4: Run tests** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365\test_exporter.py tests\a365\test_replay_coordinator.py tests\a365\test_durable_restart.py -q` + +Expected: PASS. + +- [ ] **Step 5: Commit** + +```powershell +git add src\microsoft\opentelemetry\a365\core\exporters\agent365_exporter.py src\microsoft\opentelemetry\a365\core\exporters\replay_coordinator.py tests\a365\test_exporter.py tests\a365\test_replay_coordinator.py tests\a365\test_durable_restart.py +git commit -m "Make A365 exporter shutdown deterministic" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +### Task 7: Validation, Documentation, and PR + +**Files:** +- Modify if needed: `README.md` +- Modify if needed: `A365_DOCUMENTATION.md` +- Modify if needed: `CHANGELOG.md` + +**Interfaces:** +- Produces: a pushable branch and GitHub PR with parity evidence. + +- [ ] **Step 1: Run the affected suite** + +Run: `.venv\Scripts\python.exe -m pytest tests\a365 tests\test_distro.py -q` + +Expected: PASS, including the Windows retention regression. + +- [ ] **Step 2: Run formatting, lint, and typing** + +```powershell +.venv\Scripts\python.exe -m black --check src tests +.venv\Scripts\python.exe -m pylint src\microsoft\opentelemetry\a365 src\microsoft\opentelemetry\_distro.py +.venv\Scripts\python.exe -m mypy src\microsoft\opentelemetry\a365 +``` + +Expected: all commands exit 0. + +- [ ] **Step 3: Run the complete suite** + +Run: `.venv\Scripts\python.exe -m pytest -q` + +Expected: PASS. + +- [ ] **Step 4: Review the complete branch diff** + +Run: `git --no-pager diff --check origin/main...HEAD` + +Expected: no whitespace errors. + +Run a fresh code review against `origin/main...HEAD`; resolve all blocking and should-fix findings. + +- [ ] **Step 5: Update documentation if behavior changed** + +Document that replay reconstructs current HTTPS endpoints, poison records are discarded, and shutdown drains accepted spans. + +- [ ] **Step 6: Commit validation fixes** + +```powershell +git add src tests README.md A365_DOCUMENTATION.md CHANGELOG.md +git commit -m "Validate A365 durable delivery hardening" -m "Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>" +``` + +- [ ] **Step 7: Push and create the PR** + +```powershell +git push -u origin copilot/a365-durable-delivery +gh pr create --repo microsoft/opentelemetry-distro-python --base main --head copilot/a365-durable-delivery --title "Add retry resilience to Agent365 exporter" --body-file +``` + +The PR body must link `.NET PR #137`, enumerate the parity guarantees, call out SQLite as the intentional implementation difference, and include exact test/lint/type-check results. diff --git a/docs/superpowers/specs/2026-08-12-a365-durable-delivery-design.md b/docs/superpowers/specs/2026-08-12-a365-durable-delivery-design.md new file mode 100644 index 00000000..625be4ef --- /dev/null +++ b/docs/superpowers/specs/2026-08-12-a365-durable-delivery-design.md @@ -0,0 +1,129 @@ +# Agent365 Durable Delivery Design + +## Decision + +Add durable store-and-forward delivery to the Python Agent365 exporter using only +the Python standard library. Persistence is enabled by default and can be +disabled explicitly. The implementation uses SQLite rather than file-per-record +blobs because SQLite provides atomic claims, deletion, retention, and capacity +accounting without an additional dependency. + +The existing OpenTelemetry `BatchSpanProcessor` remains responsible for queueing, +force flush, and shutdown. Python does not need the custom processor state machine +introduced by the .NET change. + +## Alternatives considered + +1. **SQLite durable queue (selected).** Atomic transactions make replay leases and + concurrent exporter access reliable. The trade-off is a small amount of schema + and migration code. +2. **One JSON file per payload.** This is easy to inspect but requires custom + atomic-rename, leasing, cleanup, capacity, and corruption handling. +3. **Memory-only retry queue.** This avoids sensitive disk persistence but loses + telemetry on process exit and does not solve the failure mode addressed by the + .NET feature. + +## Public configuration + +Extend `Agent365ExporterOptions` and the distro configuration surface with: + +- `disable_offline_storage: bool = False` +- `storage_directory: str | None = None` + +When no directory is supplied, use a private application-specific directory: + +- Windows: `%LOCALAPPDATA%\Microsoft\Agent365\OpenTelemetry\` +- Other platforms: `$XDG_STATE_HOME/microsoft/agent365/opentelemetry/` + or `~/.local/state/microsoft/agent365/opentelemetry/` +- If no home/state directory is usable, fall back to + `tempfile.gettempdir()/microsoft-agent365-opentelemetry/` + +On POSIX, directories are forced to mode `0700` and the database to `0600`. +Existing paths that are not owned by the current user are rejected. + +## Components + +### Delivery result + +Replace the HTTP helper's boolean result internally with a disposition containing: + +- delivered +- retryable failure, including an optional retry-after delay +- permanent failure + +HTTP 401, 408, 429, 5xx, transport errors, and timeouts are retryable. HTTP 403 +and other 4xx responses are permanent. A token resolver exception is retryable; +an empty token is permanent. + +### Per-identity transmission gate + +Maintain gate state per `(tenant_id, agent_id, agentic_user_id, endpoint mode)` so +one throttled identity cannot block healthy identities. + +Each gate has: + +- closed: sends proceed +- backoff: payloads are persisted without attempting the network +- half-open: one probe may proceed + +`Retry-After` is honored when present. Otherwise use full-jitter exponential +backoff with a 10-second floor and one-hour cap. `time.monotonic()` drives +in-process deadlines. + +### SQLite durable queue + +Persist the complete serialized request plus identity and endpoint metadata. +Records include a schema version, creation time, lease deadline, and retry count. + +The queue: + +- is capped at 50 MB +- retains records for two days +- atomically leases records before replay +- deletes permanent/invalid records +- retains retryable and token-resolution failures +- tolerates duplicate delivery if deletion fails + +Storage initialization or write failures are logged and cause the affected export +to return failure; they are never represented as successful persistence. + +### Replay coordinator + +A single daemon thread starts lazily after the first exporter use. It wakes on +new persisted work and periodically: + +1. Claims up to ten records. +2. Resolves a fresh token for each identity. +3. Checks the identity gate. +4. Sends the stored payload. +5. Deletes delivered or permanent records. +6. Releases retryable records and updates gate backoff. + +Shutdown signals the thread, waits within the caller's timeout where available, +then closes storage and the HTTP session exactly once. The resolver call cannot +be forcibly cancelled because the public resolver API is synchronous; this is +documented and the replay thread is daemonized so it cannot prevent interpreter +exit. + +## Export semantics + +`SpanExportResult.SUCCESS` means each generated chunk was delivered or durably +stored. `FAILURE` means at least one chunk was dropped, could not be stored, had +an invalid/empty token, or received a permanent response. + +The exporter no longer sleeps through long server backoff windows. Retryable +failures are persisted and replayed instead, reducing pressure on the +`BatchSpanProcessor` worker. + +## Testing + +Tests cover: + +- HTTP status and exception classification, including 401 and `Retry-After` +- per-identity gate isolation and single half-open probes +- SQLite round trips, leases, retention, capacity, corruption, and permissions +- export success when persistence succeeds and failure when it does not +- replay with a fresh token after restart +- permanent failures deleting stored records +- idempotent shutdown and replay-thread termination +- option propagation through both distro and helper construction paths diff --git a/docs/superpowers/specs/2026-08-14-a365-durable-delivery-hardening-design.md b/docs/superpowers/specs/2026-08-14-a365-durable-delivery-hardening-design.md new file mode 100644 index 00000000..268297c8 --- /dev/null +++ b/docs/superpowers/specs/2026-08-14-a365-durable-delivery-hardening-design.md @@ -0,0 +1,97 @@ +# Agent365 Durable Delivery Hardening Design + +## Decision + +Harden the Python durable-delivery implementation to match the behavioral +guarantees in `microsoft/opentelemetry-distro-dotnet#137`. Keep SQLite as the +Python persistence mechanism, but treat the merged .NET tests as the contract +for retry timing, endpoint reconstruction, poison-record handling, producer +capacity, replay lifecycle, and deterministic shutdown. + +## Alternatives considered + +1. **Parity-first hardening (selected).** Port each observable .NET guarantee + while retaining Python-appropriate storage and synchronization primitives. + This minimizes cross-language behavior drift without copying implementation + details that do not fit Python. +2. **Patch only the known review findings.** Smaller initially, but leaves + behavior dependent on incidental implementation details and risks missing + related .NET tests. +3. **Replace the exporter and storage architecture wholesale.** Could mirror + .NET structure more literally, but creates unnecessary migration and + compatibility risk. + +## Durable record contract + +Durable records store identity and payload, not a complete destination URL. +The supported schema version and all required fields are validated when records +are claimed. Unsupported, incomplete, or malformed records are poison records: +they are deleted and replay continues with later records. + +Replay reconstructs the endpoint from the persisted identity and current +exporter configuration. It never sends a bearer token to a plaintext endpoint. +If the reconstructed endpoint is not HTTPS, the record is retained, the replay +pass stops, and an actionable diagnostic is emitted. + +## Transmission gate and retry timing + +Healthy closed-state traffic remains concurrent. Exclusive ownership applies +only when a backoff period expires and one half-open probe is selected. + +`Retry-After` accepts both delta-seconds and HTTP-date syntax. Positive delays +are honored exactly up to the one-hour cap. Invalid, zero, or negative values +fall back to full-jitter exponential backoff. Backoff exponent growth remains +saturated to avoid overflow. + +## Live export behavior + +Permanent failure stops subsequent chunks for the same identity but does not +prevent unrelated identities from exporting. Retryable failures enter backoff +and are successful only when the payload is durably stored. + +Batch configuration is validated before component-construction error handling. +Invalid queue size, schedule delay, or batch size raises a configuration error +instead of silently omitting the Agent365 exporter. + +## Batch processor lifecycle + +Introduce an Agent365-owned batch processor rather than relying on the standard +SDK processor's shutdown and capacity behavior. The processor uses atomic +capacity reservation so concurrent producers cannot silently evict accepted +spans. Shutdown stops new acceptance, drains every accepted span, waits for an +active export before exporter shutdown, and performs exporter shutdown exactly +once. + +A caller timeout may stop waiting, but it must not make active worker cleanup +unsafe. The worker retains ownership of final exporter shutdown and disposal. +Force flush uses the same completion accounting and never races exporter +cleanup. + +## Replay and resource lifecycle + +Replay deletion results are checked. A failed deletion after successful delivery +logs duplicate-delivery risk and is not counted as removed. Retryable records +are released and stop the current pass; permanent and poison records are deleted +without blocking unrelated records. + +Exporter shutdown signals replay and waits for it to finish before closing +storage or the HTTP session. If a bounded caller wait expires, cleanup ownership +stays with the replay/export worker; resources are not closed underneath active +work. Concurrent shutdown calls are idempotent. + +## Testing + +Add regression tests corresponding to the hardened .NET cases: + +- closed-state concurrency and one half-open probe +- delta and date `Retry-After`, positive exact delays, and invalid fallback +- unsupported/incomplete/corrupt record deletion without queue blockage +- endpoint reconstruction and plaintext replay refusal +- deletion-failure duplicate-risk diagnostics +- permanent first-chunk isolation by identity +- atomic producer capacity under concurrency +- shutdown draining, active-export ordering, timeout ownership, and idempotence +- invalid batch configuration raising at the public API + +Existing durable-delivery, restart, exporter, distro, formatting, lint, typing, +and full test suites remain required before the branch is pushed. diff --git a/src/microsoft/opentelemetry/_constants.py b/src/microsoft/opentelemetry/_constants.py index 6511dcf4..8d4ee085 100644 --- a/src/microsoft/opentelemetry/_constants.py +++ b/src/microsoft/opentelemetry/_constants.py @@ -113,6 +113,8 @@ A365_SCHEDULED_DELAY_MS_ARG = "a365_scheduled_delay_ms" A365_EXPORTER_TIMEOUT_MS_ARG = "a365_exporter_timeout_ms" A365_MAX_EXPORT_BATCH_SIZE_ARG = "a365_max_export_batch_size" +A365_EXPORTER_DISABLE_OFFLINE_STORAGE_ARG = "a365_exporter_disable_offline_storage" +A365_EXPORTER_STORAGE_DIRECTORY_ARG = "a365_exporter_storage_directory" # --- GenAI Main Agent Constants --- diff --git a/src/microsoft/opentelemetry/_distro.py b/src/microsoft/opentelemetry/_distro.py index 79b2336c..f71a30c4 100644 --- a/src/microsoft/opentelemetry/_distro.py +++ b/src/microsoft/opentelemetry/_distro.py @@ -53,6 +53,8 @@ A365_SCHEDULED_DELAY_MS_ARG, A365_EXPORTER_TIMEOUT_MS_ARG, A365_MAX_EXPORT_BATCH_SIZE_ARG, + A365_EXPORTER_DISABLE_OFFLINE_STORAGE_ARG, + A365_EXPORTER_STORAGE_DIRECTORY_ARG, ENABLE_AZURE_MONITOR_ARG, ENABLE_CONSOLE_ARG, INSTRUMENTATION_OPTIONS_ARG, @@ -201,6 +203,15 @@ def use_microsoft_opentelemetry(**kwargs: object) -> None: # pylint: disable=to :keyword int a365_max_export_batch_size: Maximum batch size for a single A365 export operation. Defaults to 512 when omitted (BatchSpanProcessor default). + :keyword bool a365_exporter_disable_offline_storage: + Disable durable offline storage for the A365 exporter. When ``True``, + failed export payloads are not persisted to disk and at-least-once + delivery is not guaranteed. Defaults to ``False`` (storage enabled). + :keyword str a365_exporter_storage_directory: + Custom directory for durable offline storage. When ``None``, a + platform default path is used. Stored payloads are unencrypted; choose + a path that only the service account can read, especially when + sensitive-data capture is enabled. :keyword bool enable_console: Enable console exporter for traces, metrics, and logs (development only). Mirrors ``ExportTarget.Console`` from the .NET distro. @@ -242,6 +253,8 @@ def use_microsoft_opentelemetry(**kwargs: object) -> None: # pylint: disable=to a365_scheduled_delay_ms = kwargs.pop(A365_SCHEDULED_DELAY_MS_ARG, None) a365_exporter_timeout_ms = kwargs.pop(A365_EXPORTER_TIMEOUT_MS_ARG, None) a365_max_export_batch_size = kwargs.pop(A365_MAX_EXPORT_BATCH_SIZE_ARG, None) + a365_exporter_disable_offline_storage: bool = bool(kwargs.pop(A365_EXPORTER_DISABLE_OFFLINE_STORAGE_ARG, False)) + a365_exporter_storage_directory = kwargs.pop(A365_EXPORTER_STORAGE_DIRECTORY_ARG, None) enable_spectra: bool = bool(kwargs.pop(ENABLE_SPECTRA_ARG, False)) spectra_endpoint = kwargs.pop(SPECTRA_ENDPOINT_ARG, None) @@ -321,6 +334,8 @@ def use_microsoft_opentelemetry(**kwargs: object) -> None: # pylint: disable=to scheduled_delay_ms=a365_scheduled_delay_ms, exporter_timeout_ms=a365_exporter_timeout_ms, max_export_batch_size=a365_max_export_batch_size, + disable_offline_storage=a365_exporter_disable_offline_storage, + storage_directory=a365_exporter_storage_directory, ) # ---- Console exporters (dev-only, mirrors ExportTarget.Console) ---- @@ -477,6 +492,8 @@ def _append_a365_components( scheduled_delay_ms: Any = None, exporter_timeout_ms: Any = None, max_export_batch_size: Any = None, + disable_offline_storage: bool = False, + storage_directory: Any = None, ) -> None: """Build and append Agent365 span processors to ``otel_kwargs``. @@ -510,10 +527,23 @@ def _append_a365_components( from microsoft.opentelemetry.a365.core.exporters.agent365_exporter import _Agent365Exporter from microsoft.opentelemetry.a365.core.exporters.enriching_span_processor import ( _EnrichingBatchSpanProcessor, + _resolve_batch_options, ) from microsoft.opentelemetry.a365.core.exporters.span_processor import A365SpanProcessor from microsoft.opentelemetry.a365.core.exporters.utils import ( _create_default_token_resolver, + coerce_storage_directory, + ) + + # Validate/normalize the storage directory up front so an explicitly empty + # value raises ValueError instead of being swallowed by the broad handler + # below (which would silently fall back to the platform default path). + storage_directory_path = coerce_storage_directory(storage_directory) + _resolve_batch_options( + max_queue_size=max_queue_size, + schedule_delay_millis=scheduled_delay_ms, + max_export_batch_size=max_export_batch_size, + export_timeout_millis=exporter_timeout_ms, ) try: @@ -565,6 +595,8 @@ def _append_a365_components( contextual_token_resolver=contextual_token_resolver, cluster_category=resolved_cluster_category, use_s2s_endpoint=resolved_use_s2s, + enable_durable_delivery=not disable_offline_storage, + storage_directory=storage_directory_path, ) # Enriching batch processor wrapping the exporter. diff --git a/src/microsoft/opentelemetry/a365/core/exporters/__init__.py b/src/microsoft/opentelemetry/a365/core/exporters/__init__.py index 59e481eb..7416ac2f 100644 --- a/src/microsoft/opentelemetry/a365/core/exporters/__init__.py +++ b/src/microsoft/opentelemetry/a365/core/exporters/__init__.py @@ -1,2 +1,18 @@ # Copyright (c) Microsoft Corporation. # Licensed under the MIT License. + +"""Exporter helpers for durable delivery.""" + +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, + TransmissionGate, +) + +__all__ = [ + "DeliveryDisposition", + "DeliveryResult", + "IdentityKey", + "TransmissionGate", +] diff --git a/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py b/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py index 7b877482..6cc909ea 100644 --- a/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py +++ b/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter.py @@ -15,10 +15,14 @@ import base64 import json import logging +import os import threading import time +import weakref from collections.abc import Callable, Sequence +from pathlib import Path from typing import Any, Optional, final +from urllib.parse import urlparse import requests from opentelemetry.sdk.trace import ReadableSpan @@ -26,6 +30,21 @@ from opentelemetry.trace import StatusCode from microsoft.opentelemetry._sdkstats import is_sdkstats_enabled +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, + TransmissionGate, +) +from microsoft.opentelemetry.a365.core.exporters.persistent_storage import ( + DurableRecord, + PersistentStorage, +) +from microsoft.opentelemetry.a365.core.exporters.replay_coordinator import ( + ReplayCoordinator, + ReplayEndpointError, + ReplayIdentityError, +) from microsoft.opentelemetry.a365.core.exporters.token_resolver_context import ( AgentIdentity, TokenResolverContext, @@ -50,124 +69,14 @@ # Hardcoded constants - not configurable DEFAULT_HTTP_TIMEOUT_SECONDS = A365_HTTP_TIMEOUT_SECONDS -DEFAULT_MAX_RETRIES = 3 DEFAULT_ENDPOINT_URL = "https://agent365.svc.cloud.microsoft" _403_DOCS_URL = "https://aka.ms/a365-403" _403_FOUNDRY_URL = "https://aka.ms/foundry-grant-agent-365-permissions" -# Circuit breaker defaults -DEFAULT_CB_FAILURE_THRESHOLD = 5 -DEFAULT_CB_RECOVERY_TIMEOUT = 30.0 # seconds - logger = logging.getLogger(__name__) -class _CircuitBreaker: - """Lightweight circuit breaker for the A365 exporter HTTP path. - - States: - CLOSED – normal operation; requests flow through. - OPEN – failures exceeded threshold; requests are rejected immediately. - HALF_OPEN – recovery window elapsed; one probe request is allowed. - - Thread-safe via an internal lock. - """ - - CLOSED = "closed" - OPEN = "open" - HALF_OPEN = "half_open" - - def __init__( - self, - failure_threshold: int = DEFAULT_CB_FAILURE_THRESHOLD, - recovery_timeout: float = DEFAULT_CB_RECOVERY_TIMEOUT, - ): - self._failure_threshold = failure_threshold - self._recovery_timeout = recovery_timeout - self._lock = threading.Lock() - self._state = self.CLOSED - self._consecutive_failures = 0 - self._last_failure_time: float | None = None - self._total_rejected = 0 - self._probe_in_flight = False - - # -- query -- - - @property - def state(self) -> str: - with self._lock: - self._maybe_transition_to_half_open() - return self._state - - @property - def total_rejected(self) -> int: - with self._lock: - return self._total_rejected - - def allow_request(self) -> bool: - """Return True if a request should be attempted.""" - with self._lock: - self._maybe_transition_to_half_open() - if self._state == self.CLOSED: - return True - if self._state == self.HALF_OPEN and not self._probe_in_flight: - self._probe_in_flight = True - return True # allow exactly one probe - # OPEN or HALF_OPEN with probe already in flight - self._total_rejected += 1 - return False - - # -- feedback -- - - def record_success(self) -> None: - with self._lock: - if self._state != self.CLOSED: - logger.warning( - "Circuit breaker CLOSED (recovered). %d requests were rejected while the circuit was open.", - self._total_rejected, - ) - self._state = self.CLOSED - self._consecutive_failures = 0 - self._last_failure_time = None - self._total_rejected = 0 - self._probe_in_flight = False - - def record_failure(self) -> None: - with self._lock: - self._consecutive_failures += 1 - self._last_failure_time = time.monotonic() - self._probe_in_flight = False - if self._state == self.HALF_OPEN: - # Probe failed — re-open - self._state = self.OPEN - logger.warning( - "Circuit breaker re-OPENED after failed probe. Will retry after %.0fs.", - self._recovery_timeout, - ) - elif self._state == self.CLOSED and self._consecutive_failures >= self._failure_threshold: - self._state = self.OPEN - logger.warning( - "Circuit breaker OPENED after %d consecutive failures. " - "Requests will be rejected for %.0fs to avoid silent telemetry loss.", - self._consecutive_failures, - self._recovery_timeout, - ) - - # -- internal -- - - def _maybe_transition_to_half_open(self) -> None: - """Must be called with self._lock held.""" - if ( - self._state == self.OPEN - and self._last_failure_time is not None - and (time.monotonic() - self._last_failure_time) >= self._recovery_timeout - ): - self._state = self.HALF_OPEN - self._probe_in_flight = False - logger.warning("Circuit breaker entering HALF_OPEN state; allowing one probe request.") - - @final # pylint: disable=broad-exception-caught class _Agent365Exporter(SpanExporter): @@ -187,6 +96,8 @@ def __init__( cluster_category: str = "prod", use_s2s_endpoint: bool = False, max_payload_bytes: int = DEFAULT_MAX_PAYLOAD_BYTES, + storage_directory: Optional[Path] = None, + enable_durable_delivery: bool = True, ): if token_resolver is None and contextual_token_resolver is None: raise ValueError("token_resolver or contextual_token_resolver must be provided.") @@ -195,15 +106,94 @@ def __init__( self._session = requests.Session() self._closed = False self._lock = threading.Lock() + # Set once the single shutdown owner finishes closing storage/session. + # Concurrent shutdown() callers wait on this instead of returning + # early, so every caller sees resources closed before it returns. + self._shutdown_complete = threading.Event() self._token_resolver = token_resolver self._contextual_token_resolver = contextual_token_resolver self._cluster_category = cluster_category self._use_s2s_endpoint = use_s2s_endpoint self._max_payload_bytes = max_payload_bytes self._domain_override = get_validated_domain_override() - self._circuit_breaker = _CircuitBreaker() self.record_sdkstats = is_sdkstats_enabled() + # Durable delivery: a per-identity gate throttles retries, a persistent + # queue holds undelivered payloads, and a replay coordinator drains the + # queue on a background daemon thread. Storage and the coordinator are + # created lazily on first export so merely constructing an exporter does + # not touch the filesystem or spawn a thread. + self._gate = TransmissionGate() + self._enable_durable_delivery = enable_durable_delivery + self._storage_directory = storage_directory + self._storage: Optional[PersistentStorage] = None + self._replay: Optional[ReplayCoordinator] = None + self._replay_started = False + self._pid = os.getpid() + self._fork_reinit_lock = threading.Lock() + self._fork_abandoned_resources: list[object] = [] + if hasattr(os, "register_at_fork"): + weak_reinit = weakref.WeakMethod(self._at_fork_reinit) + + def reinit_after_fork() -> None: + callback = weak_reinit() + if callback is not None: + callback() + + os.register_at_fork(after_in_child=reinit_after_fork) + + # ------------- Durable delivery lifecycle ------------- + + def _at_fork_reinit(self) -> None: + """Reset process-local resources in a forked child.""" + inherited = (self._session, self._storage, self._replay) + self._fork_abandoned_resources.extend(resource for resource in inherited if resource is not None) + self._session = requests.Session() + self._lock = threading.Lock() + self._fork_reinit_lock = threading.Lock() + self._shutdown_complete = threading.Event() + self._closed = False + self._gate = TransmissionGate() + self._storage = None + self._replay = None + self._replay_started = False + self._pid = os.getpid() + + def _check_fork_reinit(self) -> None: + if self._pid == os.getpid(): + return + with self._fork_reinit_lock: + if self._pid != os.getpid(): + self._at_fork_reinit() + + def _ensure_durable_initialized(self) -> None: + """Create the durable queue and replay coordinator once, on demand.""" + self._check_fork_reinit() + if not self._enable_durable_delivery: + return + with self._lock: + if self._closed or self._storage is not None: + return + try: + storage = PersistentStorage(directory=self._storage_directory) + except Exception as e: + logger.error("Durable delivery disabled: failed to initialize persistent storage: %s", e) + self._enable_durable_delivery = False + return + self._storage = storage + self._replay = ReplayCoordinator(storage, self._gate, self._replay_record) + + def _ensure_replay_started(self) -> None: + """Start the replay thread once so it drains any queued payloads.""" + replay = self._replay + if replay is None: + return + with self._lock: + if self._replay_started or self._closed: + return + self._replay_started = True + replay.start() + # ------------- SpanExporter API ----------------- def _resolve_token(self, agent_id: str, tenant_id: str, activities: list[ReadableSpan]) -> Optional[str]: @@ -222,10 +212,42 @@ def _resolve_token(self, agent_id: str, tenant_id: str, activities: list[Readabl assert self._token_resolver is not None return self._token_resolver(agent_id, tenant_id) - def export(self, spans: Sequence[ReadableSpan]) -> SpanExportResult: + def _resolve_token_for_replay(self, record: DurableRecord) -> Optional[str]: + """Resolve an auth token for a queued record using its stored identity.""" + if self._contextual_token_resolver is not None: + identity = AgentIdentity(record.agent_id, record.agentic_user_id) + context = TokenResolverContext(identity, record.tenant_id) + return self._contextual_token_resolver(context) + assert self._token_resolver is not None + return self._token_resolver(record.agent_id, record.tenant_id) + + def _identity_key(self, tenant_id: str, agent_id: str, activities: Sequence[ReadableSpan]) -> IdentityKey: + """Build the durable-delivery identity for a partitioned span group.""" + agentic_user_id: Optional[str] = None + if activities: + first_attrs = activities[0].attributes or {} + raw_auid = first_attrs.get(GEN_AI_AGENT_AUID_KEY) + if raw_auid is not None: + agentic_user_id = str(raw_auid) + return IdentityKey(tenant_id, agent_id, agentic_user_id, self._use_s2s_endpoint) + + def _build_export_url(self, tenant_id: str, agent_id: str, use_s2s_endpoint: bool) -> str: + endpoint = self._domain_override or DEFAULT_ENDPOINT_URL + return build_export_url(endpoint, agent_id, tenant_id, use_s2s_endpoint) + + @staticmethod + def _ensure_https_replay_url(url: str) -> None: + if urlparse(url).scheme.lower() != "https": + raise ReplayEndpointError(f"Replay endpoint must use HTTPS before resolving a bearer token: {url}") + + def export(self, spans: Sequence[ReadableSpan]) -> SpanExportResult: # pylint: disable=too-many-statements + self._check_fork_reinit() if self._closed: return SpanExportResult.FAILURE + self._ensure_durable_initialized() + self._ensure_replay_started() + try: groups = filter_and_partition_by_identity(spans) if not groups: @@ -240,8 +262,12 @@ def export(self, spans: Sequence[ReadableSpan]) -> SpanExportResult: total_spans, ) - any_failure = False + all_delivered_or_stored = True + persisted_any = False + for (tenant_id, agent_id), activities in groups.items(): + identity = self._identity_key(tenant_id, agent_id, activities) + # Map and truncate spans first, then chunk by estimated byte size mapped_spans = self._map_and_truncate_spans(activities) resource_attrs = self._get_resource_attributes(activities) @@ -260,8 +286,7 @@ def export(self, spans: Sequence[ReadableSpan]) -> SpanExportResult: agent_id, ) - endpoint = self._domain_override or DEFAULT_ENDPOINT_URL - url = build_export_url(endpoint, agent_id, tenant_id, self._use_s2s_endpoint) + url = self._build_export_url(tenant_id, agent_id, self._use_s2s_endpoint) logger.debug( "Exporting %d spans to endpoint: %s (tenant: %s, agent: %s)", @@ -271,19 +296,11 @@ def export(self, spans: Sequence[ReadableSpan]) -> SpanExportResult: agent_id, ) - headers: dict[str, str | bytes] = {"content-type": "application/json"} + # Resolve auth once per identity group. + token: Optional[str] = None + token_resolution_failed = False try: token = self._resolve_token(agent_id, tenant_id, activities) - if token: - if not url.lower().startswith("https://"): - logger.warning( - "Bearer token is being sent over a non-HTTPS connection. " - "This may expose credentials in transit." - ) - headers["authorization"] = f"Bearer {token}" - logger.debug("Token resolved successfully for agent %s", agent_id) - else: - logger.debug("No token returned for agent %s", agent_id) except Exception as e: logger.error( "Token resolution failed for agent %s, tenant %s: %s", @@ -291,71 +308,155 @@ def export(self, spans: Sequence[ReadableSpan]) -> SpanExportResult: tenant_id, e, ) - any_failure = True - continue + token_resolution_failed = True - # Send each chunk (all-or-nothing: fail group on first chunk failure) - group_failed = False for i, chunk in enumerate(chunks): - payload = self._build_envelope(chunk, resource_attrs) - body = json.dumps(payload, separators=(",", ":"), ensure_ascii=False) - body_bytes = len(body.encode("utf-8")) - logger.debug( - "Sending chunk %d of %d (%d spans, %d bytes)", - i + 1, - len(chunks), - len(chunk), - body_bytes, - ) - # Defensive check: the estimator covers per-span content but not - # envelope overhead (resource attributes, scope wrappers). Warn if - # the assembled body exceeds the configured limit so operators can - # observe estimator drift before the server starts rejecting requests. - if body_bytes > self._max_payload_bytes: - logger.warning( - "Chunk %d of %d body size (%d bytes) exceeds max_payload_bytes (%d); " - "estimator may be under-counting envelope overhead. " - "Tenant: %s, agent: %s, spans: %d.", + body = self._serialize_chunk(chunk, resource_attrs, i, len(chunks), tenant_id, agent_id) + + # Token resolver raised: persist so a later replay can retry + # once credentials recover. A successful store counts as success. + if token_resolution_failed: + if self._persist(identity, body): + persisted_any = True + else: + all_delivered_or_stored = False + continue + + # Empty token is a permanent condition: never send, never store. + if not token: + logger.error( + "No token resolved for agent %s, tenant %s; dropping chunk %d of %d.", + agent_id, + tenant_id, i + 1, len(chunks), - body_bytes, - self._max_payload_bytes, - tenant_id, - agent_id, - len(chunk), ) + all_delivered_or_stored = False + continue + + if not url.lower().startswith("https://"): + logger.warning( + "The authorization token is being sent over a non-HTTPS connection. " + "This may expose credentials in transit." + ) + headers: dict[str, str | bytes] = { + "content-type": "application/json", + "authorization": f"Bearer {token}", + } - ok = self._post_with_retries(url, body, headers) - if not ok: + # The gate rejects sends for an identity in a retry cooldown; + # persist directly rather than hammering the endpoint. + if not self._gate.try_acquire(identity): + if self._persist(identity, body): + persisted_any = True + else: + all_delivered_or_stored = False + continue + + try: + result = self._post_once(url, body, headers) + except Exception as post_exc: # pylint: disable=broad-except + # _post_once classifies transport errors internally, so + # reaching here means an unexpected failure. Release the + # half-open probe we just acquired so the identity is not + # permanently gated, then persist the payload for replay. logger.error( - "Chunk %d of %d failed for tenant %s, agent %s", - i + 1, - len(chunks), + "Unexpected error sending telemetry for tenant %s, agent %s: %s", tenant_id, agent_id, + post_exc, ) - any_failure = True - group_failed = True + self._gate.release_probe(identity) + if self._persist(identity, body): + persisted_any = True + else: + all_delivered_or_stored = False + continue + + if result.disposition is DeliveryDisposition.DELIVERED: + self._gate.record_success(identity) + elif result.disposition is DeliveryDisposition.RETRYABLE: + self._gate.record_retryable_failure(identity, result.retry_after) + if self._persist(identity, body): + persisted_any = True + else: + all_delivered_or_stored = False + else: + # Permanent: the endpoint answered definitively. The + # identity itself is healthy, so reset the gate; only this + # payload is undeliverable and is dropped. + self._gate.record_success(identity) + all_delivered_or_stored = False break - if group_failed: - continue + if persisted_any and self._replay is not None: + self._replay.wake() - return SpanExportResult.FAILURE if any_failure else SpanExportResult.SUCCESS + return SpanExportResult.SUCCESS if all_delivered_or_stored else SpanExportResult.FAILURE except Exception as e: logger.error("Export failed with exception: %s", e) return SpanExportResult.FAILURE def shutdown(self) -> None: + """Stop durable delivery and close storage/session exactly once. + + The first caller becomes the single cleanup owner: it signals the + replay coordinator to stop and -- critically -- waits (unbounded) + until the replay thread has actually exited before closing storage + or the HTTP session, so an in-flight replay send can never observe a + closed resource. Concurrent callers (including a caller that arrives + after ownership was already claimed) wait on the same completion + event instead of returning early, so every ``shutdown()`` call only + returns once cleanup has actually finished. + """ + self._check_fork_reinit() + owner = False + replay: Optional[ReplayCoordinator] = None + storage: Optional[PersistentStorage] = None with self._lock: if self._closed: - return - self._closed = True + pass + else: + self._closed = True + owner = True + replay = self._replay + storage = self._storage + + if not owner: + self._shutdown_complete.wait() + return + + # Everything below runs outside self._lock, both so a concurrent + # export() cannot deadlock against the joining replay thread and so + # the (possibly long) replay join is never done while holding a lock + # other callers need merely to observe self._closed. + try: + if replay is not None: + try: + if not replay.shutdown(None): + # Only reachable if shutdown() were somehow invoked from + # the replay thread itself; a thread can never join + # itself. Log it -- this indicates a reentrant call, not + # a timeout -- and fall through to close resources since + # there is no safe way to wait further here. + logger.warning( + "A365 replay coordinator could not be joined from its own thread " + "during shutdown(); proceeding to close durable storage." + ) + except Exception as e: + logger.error("Error shutting down replay coordinator: %s", e) + if storage is not None: + try: + storage.close() + except Exception as e: + logger.error("Error closing durable storage: %s", e) try: self._session.close() except Exception: pass + finally: + self._shutdown_complete.set() def force_flush(self, timeout_millis: int = 30000) -> bool: return True @@ -395,20 +496,111 @@ def _extract_token_identity(headers: dict[str, str | bytes]) -> dict[str, str]: except Exception: # pylint: disable=broad-except return {} - def _post_with_retries( # pylint: disable=too-many-statements - self, url: str, body: str, headers: dict[str, str | bytes] - ) -> bool: - if not self._circuit_breaker.allow_request(): + def _serialize_chunk( + self, + chunk: Sequence[tuple[dict[str, Any], str, str | None]], + resource_attrs: dict[str, Any], + index: int, + total: int, + tenant_id: str, + agent_id: str, + ) -> str: + """Build the JSON request body for one chunk and warn on size drift.""" + payload = self._build_envelope(chunk, resource_attrs) + body = json.dumps(payload, separators=(",", ":"), ensure_ascii=False) + body_bytes = len(body.encode("utf-8")) + logger.debug( + "Prepared chunk %d of %d (%d spans, %d bytes)", + index + 1, + total, + len(chunk), + body_bytes, + ) + # Defensive check: the estimator covers per-span content but not envelope + # overhead (resource attributes, scope wrappers). Warn if the assembled + # body exceeds the configured limit so operators can observe estimator + # drift before the server starts rejecting requests. + if body_bytes > self._max_payload_bytes: logger.warning( - "Circuit breaker is OPEN \u2014 skipping POST to %s. %d total requests rejected so far.", - url, - self._circuit_breaker.total_rejected, + "Chunk %d of %d body size (%d bytes) exceeds max_payload_bytes (%d); " + "estimator may be under-counting envelope overhead. " + "Tenant: %s, agent: %s, spans: %d.", + index + 1, + total, + body_bytes, + self._max_payload_bytes, + tenant_id, + agent_id, + len(chunk), + ) + return body + + def _persist(self, identity: IdentityKey, body: str) -> bool: + """Persist one payload to the durable queue. Returns False on failure.""" + storage = self._storage + if storage is None: + logger.warning( + "Durable storage unavailable; telemetry for tenant %s, agent %s could not be " + "persisted and will be dropped.", + identity.tenant_id, + identity.agent_id, ) return False + stored = storage.store(DurableRecord.new(identity, body)) + if not stored: + logger.error( + "Durable storage rejected telemetry for tenant %s, agent %s.", + identity.tenant_id, + identity.agent_id, + ) + return stored + + def _replay_record(self, record: DurableRecord) -> DeliveryResult: + """Replay a queued record, rebuilding auth from its stored identity. + + A token-resolution failure (exception or empty token) is surfaced as + :class:`ReplayIdentityError` so the coordinator releases the record for a + future attempt instead of dropping it. + """ + url = self._build_export_url( + record.tenant_id, + record.agent_id, + record.use_s2s_endpoint, + ) + self._ensure_https_replay_url(url) + try: + token = self._resolve_token_for_replay(record) + except Exception as e: + raise ReplayIdentityError( + f"Token resolution failed during replay for agent {record.agent_id}, " f"tenant {record.tenant_id}: {e}" + ) from e + if not token: + raise ReplayIdentityError( + f"No token resolved during replay for agent {record.agent_id}, " f"tenant {record.tenant_id}." + ) + headers: dict[str, str | bytes] = { + "content-type": "application/json", + "authorization": "Bearer " + token, + } + return self._post_once(url, record.payload, headers) + def _post_once( # pylint: disable=too-many-statements,too-many-branches + self, url: str, body: str, headers: dict[str, str | bytes] + ) -> DeliveryResult: + """Perform a single classified HTTP send. No retries, no sleeping. + + Returns a :class:`DeliveryResult`: + + * ``DELIVERED`` for 2xx responses. + * ``RETRYABLE`` for 401/408/429, all 5xx, and transport-level errors + (``requests.RequestException``, which includes connect/read timeouts). + * ``PERMANENT`` for 403 and all other 4xx responses. + + Any ``Retry-After`` header is parsed and returned on the result but is + never slept on; the transmission gate applies the delay asynchronously. + """ # Local imports to avoid pulling sdkstats into the exporter module's # import graph for consumers that don't use this package. - from urllib.parse import urlparse from microsoft.opentelemetry._sdkstats._constants import ENDPOINT_A365 from microsoft.opentelemetry._sdkstats._utils import ( THROTTLE_STATUS_CODES, @@ -422,114 +614,101 @@ def _post_with_retries( # pylint: disable=too-many-statements host = urlparse(url).hostname or url record_a365_sdkstats = self.record_sdkstats + start_time = time.time() + try: + resp = self._session.post( + url, + data=body.encode("utf-8"), + headers=headers, + timeout=DEFAULT_HTTP_TIMEOUT_SECONDS, + ) - for attempt in range(DEFAULT_MAX_RETRIES + 1): - start_time = time.time() - try: - resp = self._session.post( - url, - data=body.encode("utf-8"), - headers=headers, - timeout=DEFAULT_HTTP_TIMEOUT_SECONDS, + correlation_id = resp.headers.get("x-ms-correlation-id") or resp.headers.get("request-id") or "N/A" + status_code = resp.status_code + + if 200 <= status_code < 300: + if record_a365_sdkstats: + record_success(ENDPOINT_A365, host) + logger.debug( + "HTTP %d success. Correlation ID: %s. Response: %s", + status_code, + correlation_id, + self._truncate_text(resp.text, 200), ) + return DeliveryResult(DeliveryDisposition.DELIVERED) - correlation_id = resp.headers.get("x-ms-correlation-id") or resp.headers.get("request-id") or "N/A" + response_text = self._truncate_text(resp.text, 500) + retry_after = parse_retry_after(resp.headers) - if 200 <= resp.status_code < 300: - if record_a365_sdkstats: - record_success(ENDPOINT_A365, host) - logger.debug( - "HTTP %d success on attempt %d. Correlation ID: %s. Response: %s", - resp.status_code, - attempt + 1, - correlation_id, - self._truncate_text(resp.text, 200), - ) - self._circuit_breaker.record_success() - return True - - response_text = self._truncate_text(resp.text, 500) - - if resp.status_code in (408, 429) or 500 <= resp.status_code < 600: - retry_after = parse_retry_after(resp.headers) - if attempt < DEFAULT_MAX_RETRIES: - if record_a365_sdkstats: - record_retry(ENDPOINT_A365, host, resp.status_code) - if retry_after is not None: - time.sleep(min(retry_after, 60.0)) - else: - time.sleep(0.5 * (2**attempt)) - continue - if record_a365_sdkstats: - if resp.status_code in THROTTLE_STATUS_CODES: - record_throttle(ENDPOINT_A365, host, resp.status_code) - else: - record_failure(ENDPOINT_A365, host, resp.status_code) - logger.error( - "HTTP %d final failure after %d attempts. Correlation ID: %s. Response: %s", - resp.status_code, - DEFAULT_MAX_RETRIES + 1, - correlation_id, - response_text, - ) - self._circuit_breaker.record_failure() - else: - if record_a365_sdkstats: - if resp.status_code in THROTTLE_STATUS_CODES: - record_throttle(ENDPOINT_A365, host, resp.status_code) - else: - record_failure(ENDPOINT_A365, host, resp.status_code) - www_auth = resp.headers.get("www-authenticate", "") - if resp.status_code == 403 and "insufficient_scope" in www_auth: - sp = self._extract_token_identity(headers) - if sp: - sp_parts = [ - f"{label}: {sp[key]}" - for key, label in (("app_id", "app ID"), ("object_id", "object ID")) - if sp.get(key) - ] - sp_str = f" service principal ({', '.join(sp_parts)})" - else: - sp_str = " your application's service principal" - logger.error( - "HTTP 403 authorization error: the token is missing the required " - "'Agent365.Observability.OtelWrite' app role. " - "Grant the 'Agent365.Observability.OtelWrite' role to%s " - "and ensure admin consent has been granted. " - "| Setup instructions: %s " - "| For Foundry: %s " - "| Correlation ID: %s.", - sp_str, - _403_DOCS_URL, - _403_FOUNDRY_URL, - correlation_id, - ) + # Retryable: transient auth (401), request timeout (408), throttling + # (429), and all 5xx server errors. + if status_code in (401, 408, 429) or 500 <= status_code < 600: + if record_a365_sdkstats: + if status_code in THROTTLE_STATUS_CODES: + record_throttle(ENDPOINT_A365, host, status_code) else: - logger.error( - "HTTP %d non-retryable error. Correlation ID: %s. Response: %s. " - "WWW-Authenticate: %s. Response headers: %s", - resp.status_code, - correlation_id, - response_text, - www_auth or "N/A", - dict(resp.headers), - ) - return False + record_retry(ENDPOINT_A365, host, status_code) + logger.warning( + "HTTP %d retryable error; payload will be queued for durable retry. " + "Correlation ID: %s. Response: %s. Retry-After: %s.", + status_code, + correlation_id, + response_text, + retry_after if retry_after is not None else "N/A", + ) + return DeliveryResult(DeliveryDisposition.RETRYABLE, retry_after) - except requests.RequestException as e: - if record_a365_sdkstats: - record_exception(ENDPOINT_A365, host, type(e).__name__) - if attempt < DEFAULT_MAX_RETRIES: - time.sleep(0.5 * (2**attempt)) - continue - logger.error("Request failed after %d attempts: %s", DEFAULT_MAX_RETRIES + 1, e) - self._circuit_breaker.record_failure() - return False - finally: - # Record duration for every status - if record_a365_sdkstats: - record_duration(ENDPOINT_A365, host, time.time() - start_time) - return False # pragma: no cover + # Permanent: 403 and all other 4xx responses. + if record_a365_sdkstats: + if status_code in THROTTLE_STATUS_CODES: + record_throttle(ENDPOINT_A365, host, status_code) + else: + record_failure(ENDPOINT_A365, host, status_code) + www_auth = resp.headers.get("www-authenticate", "") + if status_code == 403 and "insufficient_scope" in www_auth: + sp = self._extract_token_identity(headers) + if sp: + sp_parts = [ + f"{label}: {sp[key]}" + for key, label in (("app_id", "app ID"), ("object_id", "object ID")) + if sp.get(key) + ] + sp_str = f" service principal ({', '.join(sp_parts)})" + else: + sp_str = " your application's service principal" + logger.error( + "HTTP 403 authorization error: the token is missing the required " + "'Agent365.Observability.OtelWrite' app role. " + "Grant the 'Agent365.Observability.OtelWrite' role to%s " + "and ensure admin consent has been granted. " + "| Setup instructions: %s " + "| For Foundry: %s " + "| Correlation ID: %s.", + sp_str, + _403_DOCS_URL, + _403_FOUNDRY_URL, + correlation_id, + ) + else: + logger.error( + "HTTP %d non-retryable error. Correlation ID: %s. Response: %s. " + "WWW-Authenticate: %s. Response headers: %s", + status_code, + correlation_id, + response_text, + www_auth or "N/A", + dict(resp.headers), + ) + return DeliveryResult(DeliveryDisposition.PERMANENT) + + except requests.RequestException as e: + if record_a365_sdkstats: + record_exception(ENDPOINT_A365, host, type(e).__name__) + logger.error("Request to %s failed: %s", url, e) + return DeliveryResult(DeliveryDisposition.RETRYABLE) + finally: + if record_a365_sdkstats: + record_duration(ENDPOINT_A365, host, time.time() - start_time) # ------------- Payload mapping ------------------ diff --git a/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter_options.py b/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter_options.py index a61c6bb6..c6e87bd2 100644 --- a/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter_options.py +++ b/src/microsoft/opentelemetry/a365/core/exporters/agent365_exporter_options.py @@ -38,6 +38,8 @@ def __init__( exporter_timeout_ms: int = 30000, max_export_batch_size: int = 512, max_payload_bytes: int = DEFAULT_MAX_PAYLOAD_BYTES, + disable_offline_storage: bool = False, + storage_directory: Optional[str] = None, ): """ Args: @@ -57,7 +59,17 @@ def __init__( splits per-identity batches into sub-batches whose estimated size stays under this limit, providing headroom under the A365 1 MB server limit. Default is 900_000 (~100 KB headroom for estimator error and JSON envelope overhead). + disable_offline_storage: When True, disables durable delivery (no disk writes or + replay). Defaults to False (storage enabled). + storage_directory: Custom directory for durable offline storage. When None, a + platform default path is used. An explicitly empty or whitespace-only string + is rejected with ``ValueError``. Defaults to None. + + Raises: + ValueError: If ``storage_directory`` is an empty or whitespace-only string. """ + if storage_directory is not None and not str(storage_directory).strip(): + raise ValueError("storage_directory must be a non-empty path or None") self.cluster_category = cluster_category self.token_resolver = token_resolver self.contextual_token_resolver = contextual_token_resolver @@ -67,3 +79,5 @@ def __init__( self.exporter_timeout_ms = exporter_timeout_ms self.max_export_batch_size = max_export_batch_size self.max_payload_bytes = max_payload_bytes + self.disable_offline_storage = disable_offline_storage + self.storage_directory = storage_directory diff --git a/src/microsoft/opentelemetry/a365/core/exporters/durable_delivery.py b/src/microsoft/opentelemetry/a365/core/exporters/durable_delivery.py new file mode 100644 index 00000000..d032fa2f --- /dev/null +++ b/src/microsoft/opentelemetry/a365/core/exporters/durable_delivery.py @@ -0,0 +1,155 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Durable delivery dispositions and per-identity transmission gating.""" + +from __future__ import annotations + +import math +import random +import time +from collections.abc import Callable +from dataclasses import dataclass +from enum import Enum +from threading import RLock + +_RETRY_AFTER_FLOOR_SECONDS = 10.0 +_RETRY_AFTER_CAP_SECONDS = 3600.0 + +# Maximum useful exponent for the exponential backoff calculation. Beyond this +# value, floor * 2^n already equals or exceeds the cap, so further growth adds +# nothing and would eventually cause OverflowError on Python floats (C doubles). +# Derived directly from the floor/cap constants: +# floor * 2^n >= cap => n >= log2(cap / floor) +# We take the ceiling so that at exactly this exponent the window is already at +# or above the cap and gets clamped there. +_MAX_BACKOFF_EXPONENT: int = math.ceil(math.log2(_RETRY_AFTER_CAP_SECONDS / _RETRY_AFTER_FLOOR_SECONDS)) + + +class DeliveryDisposition(Enum): + """The outcome of a delivery attempt.""" + + DELIVERED = "delivered" + RETRYABLE = "retryable" + PERMANENT = "permanent" + + +@dataclass(frozen=True) +class DeliveryResult: + """Delivery outcome and optional retry delay.""" + + disposition: DeliveryDisposition + retry_after: float | None = None + + +@dataclass(frozen=True) +class IdentityKey: + """Identity tuple used to isolate durable delivery state.""" + + tenant_id: str + agent_id: str + agentic_user_id: str | None + use_s2s_endpoint: bool + + +@dataclass +class _GateState: + """Mutable gate state tracked per identity.""" + + blocked_until: float = 0.0 + probe_acquired: bool = False + failure_count: int = 0 + + +class TransmissionGate: + """Gate retries per identity and allows only one half-open probe.""" + + def __init__( + self, + clock: Callable[[], float] | None = None, + random_fn: Callable[[], float] | None = None, + ) -> None: + self._clock = clock or time.monotonic + self._random_fn = random_fn or random.random + self._lock = RLock() + self._states: dict[IdentityKey, _GateState] = {} + + def try_acquire(self, key: IdentityKey) -> bool: + """Acquire the probe token for an identity if it is available.""" + with self._lock: + state = self._states.get(key) + if state is None: + return True + if state.blocked_until == 0.0: + return True + + if self._clock() < state.blocked_until: + return False + if state.probe_acquired: + return False + + state.probe_acquired = True + return True + + def record_success(self, key: IdentityKey) -> None: + """Reset durable delivery state after a successful attempt.""" + with self._lock: + self._states.pop(key, None) + + def record_retryable_failure(self, key: IdentityKey, retry_after: float | None) -> None: + """Block the identity until the retry window expires.""" + with self._lock: + state = self._states.setdefault(key, _GateState()) + delay = self._resolve_retry_delay(state.failure_count, retry_after) + # Saturate failure_count at _MAX_BACKOFF_EXPONENT: beyond that the + # backoff is already capped at _RETRY_AFTER_CAP_SECONDS and further + # growth would only risk overflow in future calls. + state.failure_count = min(state.failure_count + 1, _MAX_BACKOFF_EXPONENT) + state.blocked_until = self._clock() + delay + state.probe_acquired = False + + def release_probe(self, key: IdentityKey) -> None: + """Release an acquired probe token without changing the retry window.""" + with self._lock: + state = self._states.get(key) + if state is not None: + state.probe_acquired = False + + def _resolve_retry_delay(self, failure_count: int, retry_after: float | None) -> float: + if retry_after is not None and retry_after > 0.0: + return self._cap_retry_after(retry_after) + return self._full_jitter_backoff(failure_count) + + def _full_jitter_backoff(self, failure_count: int) -> float: + # Clamp the exponent to prevent OverflowError: at _MAX_BACKOFF_EXPONENT + # the window already reaches or exceeds the cap, so higher values are + # equivalent but safe. + exponent = min(failure_count, _MAX_BACKOFF_EXPONENT) + window = _RETRY_AFTER_FLOOR_SECONDS * (2.0**exponent) + window = min(_RETRY_AFTER_CAP_SECONDS, window) + if window <= _RETRY_AFTER_FLOOR_SECONDS: + return _RETRY_AFTER_FLOOR_SECONDS + + fraction = self._random_fraction() + return _RETRY_AFTER_FLOOR_SECONDS + fraction * (window - _RETRY_AFTER_FLOOR_SECONDS) + + def _random_fraction(self) -> float: + fraction = self._random_fn() + if fraction < 0.0: + return 0.0 + if fraction > 1.0: + return 1.0 + return fraction + + def _cap_retry_after(self, retry_after: float) -> float: + if retry_after > _RETRY_AFTER_CAP_SECONDS: + return _RETRY_AFTER_CAP_SECONDS + return retry_after + + +__all__ = [ + "DeliveryDisposition", + "DeliveryResult", + "IdentityKey", + "TransmissionGate", +] diff --git a/src/microsoft/opentelemetry/a365/core/exporters/enriching_span_processor.py b/src/microsoft/opentelemetry/a365/core/exporters/enriching_span_processor.py index 91b3fbbb..4aa3371c 100644 --- a/src/microsoft/opentelemetry/a365/core/exporters/enriching_span_processor.py +++ b/src/microsoft/opentelemetry/a365/core/exporters/enriching_span_processor.py @@ -13,13 +13,24 @@ from __future__ import annotations +import collections import logging +import os import threading +import time +import weakref from collections.abc import Callable -from typing import Optional +from typing import Deque, Dict, List, Optional -from opentelemetry.sdk.trace import ReadableSpan -from opentelemetry.sdk.trace.export import BatchSpanProcessor +from opentelemetry.context import _SUPPRESS_INSTRUMENTATION_KEY, Context, attach, detach, set_value +from opentelemetry.sdk.environment_variables import ( + OTEL_BSP_EXPORT_TIMEOUT, + OTEL_BSP_MAX_EXPORT_BATCH_SIZE, + OTEL_BSP_MAX_QUEUE_SIZE, + OTEL_BSP_SCHEDULE_DELAY, +) +from opentelemetry.sdk.trace import ReadableSpan, Span, SpanProcessor +from opentelemetry.sdk.trace.export import SpanExporter from microsoft.opentelemetry.a365.constants import ( GEN_AI_INPUT_MESSAGES_KEY, @@ -30,6 +41,37 @@ logger = logging.getLogger(__name__) +# Mirrors opentelemetry.sdk.trace.export.BatchSpanProcessor's own defaults so +# behavior is unchanged for callers that omit these options. +_DEFAULT_MAX_QUEUE_SIZE = 2048 +_DEFAULT_SCHEDULE_DELAY_MILLIS = 5000 +_DEFAULT_MAX_EXPORT_BATCH_SIZE = 512 +_DEFAULT_EXPORT_TIMEOUT_MILLIS = 30000 +_DEFAULT_SHUTDOWN_TIMEOUT_MILLIS = 30000 + +# How long a repeated drop reason (queue full / shutting down) stays +# suppressed after being logged once, so a sustained drop condition cannot +# turn into a log storm. +_DROP_LOG_INTERVAL_SECONDS = 10.0 + +_ENV_VAR_INT_VALUE_ERROR_MESSAGE = "Unable to parse value for %s as an integer; using default of %s." + + +def _int_env_default(env_var: str, default: int) -> int: + """Resolve an integer option from an environment variable, falling back + to ``default`` both when the variable is unset and when it holds a + value that cannot be parsed as an integer -- mirroring + BatchSpanProcessor's own ``_default_*()`` helpers (arg wins over env + var, env var wins over the hardcoded default, invalid values are + logged and never raise). + """ + try: + return int(os.environ.get(env_var, default)) + except ValueError: + logger.exception(_ENV_VAR_INT_VALUE_ERROR_MESSAGE, env_var, default) + return default + + # Single span enricher - only one platform instrumentor should be active at a time _span_enricher: Optional[Callable[[ReadableSpan], ReadableSpan]] = None _enricher_lock = threading.Lock() @@ -69,20 +111,206 @@ def get_span_enricher() -> Optional[Callable[[ReadableSpan], ReadableSpan]]: return _span_enricher -class _EnrichingBatchSpanProcessor(BatchSpanProcessor): - """BatchSpanProcessor that applies the registered enricher before batching.""" +def _validate_batch_options(max_queue_size: int, schedule_delay_millis: float, max_export_batch_size: int) -> None: + """Validate batching options, mirroring BatchSpanProcessor's own guard rails.""" + if max_queue_size <= 0: + raise ValueError("max_queue_size must be a positive integer.") + if schedule_delay_millis <= 0: + raise ValueError("schedule_delay_millis must be positive.") + if max_export_batch_size <= 0: + raise ValueError("max_export_batch_size must be a positive integer.") + if max_export_batch_size > max_queue_size: + raise ValueError("max_export_batch_size must be less than or equal to max_queue_size.") + + +def _resolve_batch_options( + max_queue_size: Optional[int] = None, + schedule_delay_millis: Optional[float] = None, + max_export_batch_size: Optional[int] = None, + export_timeout_millis: Optional[float] = None, +) -> tuple[int, float, int, float]: + """Resolve effective batch options and validate their combined values.""" + resolved_max_queue_size = ( + max_queue_size + if max_queue_size is not None + else _int_env_default(OTEL_BSP_MAX_QUEUE_SIZE, _DEFAULT_MAX_QUEUE_SIZE) + ) + resolved_schedule_delay_millis = ( + schedule_delay_millis + if schedule_delay_millis is not None + else _int_env_default(OTEL_BSP_SCHEDULE_DELAY, _DEFAULT_SCHEDULE_DELAY_MILLIS) + ) + resolved_max_export_batch_size = ( + max_export_batch_size + if max_export_batch_size is not None + else _int_env_default(OTEL_BSP_MAX_EXPORT_BATCH_SIZE, _DEFAULT_MAX_EXPORT_BATCH_SIZE) + ) + resolved_export_timeout_millis = ( + export_timeout_millis + if export_timeout_millis is not None + else _int_env_default(OTEL_BSP_EXPORT_TIMEOUT, _DEFAULT_EXPORT_TIMEOUT_MILLIS) + ) + _validate_batch_options( + resolved_max_queue_size, + resolved_schedule_delay_millis, + resolved_max_export_batch_size, + ) + return ( + resolved_max_queue_size, + resolved_schedule_delay_millis, + resolved_max_export_batch_size, + resolved_export_timeout_millis, + ) + + +class _EnrichingBatchSpanProcessor(SpanProcessor): + """SpanProcessor that enriches spans, then atomically batches and exports them. + + This owns a dedicated worker thread backed by a bounded ``deque`` and a + single ``Condition``. Capacity is reserved and the span is enqueued + atomically under that lock, so producers racing on a full queue are + explicitly rejected rather than silently evicting an already-accepted + span. Enqueuing a span that brings the queue to ``max_export_batch_size`` + wakes the worker immediately instead of waiting for the schedule delay, + matching upstream's threshold-wake behavior. ``shutdown()`` stops new + acceptance, wakes the worker, and waits; only the worker thread drains + the remaining queue, waits out any in-flight export, and performs the + single ``exporter.shutdown()`` call. Concurrent ``shutdown()`` callers + all wait on that same completion signal, so exporter shutdown always + happens exactly once. + + Fork safety mirrors upstream's BatchSpanProcessor: an ``os.register_at_fork`` + hook (held via a weakref so it never keeps this processor alive) and a + PID guard checked on every enqueue both reinitialize the condition, + queue, and worker thread after a fork, since only the calling thread + survives ``os.fork()`` and the old worker/lock state would otherwise be + silently abandoned or, worse, deadlocked in the child. + """ def __init__( self, - *args: object, + span_exporter: SpanExporter, + max_queue_size: Optional[int] = None, + schedule_delay_millis: Optional[float] = None, + max_export_batch_size: Optional[int] = None, + export_timeout_millis: Optional[float] = None, + *, suppress_invoke_agent_input: bool = False, - **kwargs: object, - ): - super().__init__(*args, **kwargs) # type: ignore[arg-type] + ) -> None: + self._exporter = span_exporter self._suppress_invoke_agent_input = suppress_invoke_agent_input + ( + max_queue_size, + schedule_delay_millis, + max_export_batch_size, + export_timeout_millis, + ) = _resolve_batch_options( + max_queue_size=max_queue_size, + schedule_delay_millis=schedule_delay_millis, + max_export_batch_size=max_export_batch_size, + export_timeout_millis=export_timeout_millis, + ) + + self._max_queue_size = max_queue_size + self._schedule_delay_seconds = schedule_delay_millis / 1000.0 + self._max_export_batch_size = max_export_batch_size + # Retained for interface/configuration parity with BatchSpanProcessor; + # there is no way to pass a per-call timeout through to + # SpanExporter.export() today. + self._export_timeout_millis = export_timeout_millis + + # Guards the PID-guard fallback in _check_fork_reinit() so a fork + # racing concurrently with an in-flight enqueue reinitializes state + # exactly once. Deliberately not recreated in _at_fork_reinit(): it + # protects the reinit itself, not the state being reinitialized. + self._fork_reinit_lock = threading.Lock() + + # Declared here for static analysis; _init_state_after_fork resets + # these values both now and whenever a child process is initialized. + self._accepting = False + self._shutdown_requested = False + self._shutdown_complete = False + self._wake_requested = False + self._init_state_after_fork() + + self._pid = os.getpid() + if hasattr(os, "register_at_fork"): + # A bound-method strong reference here would be kept alive + # forever by the process-wide fork registry (there is no + # unregister API), leaking this processor. A weakref lets the + # hook become a no-op once nothing else references us. + weak_at_fork_reinit = weakref.WeakMethod(self._at_fork_reinit) + + def _after_fork_in_child() -> None: + reinit = weak_at_fork_reinit() + if reinit is not None: + reinit() + + os.register_at_fork(after_in_child=_after_fork_in_child) + + def _init_state_after_fork(self) -> None: + """(Re)initialize all per-process mutable state and start a fresh + worker thread. Used both by __init__ and by _at_fork_reinit().""" + # Single lock/condition guards all mutable state below. The worker + # releases it only while an export (or the final exporter.shutdown()) + # call is actually in flight. + self._condition = threading.Condition() + self._queue: Deque[ReadableSpan] = collections.deque() + self._active_exports = 0 + self._accepting = True + self._shutdown_requested = False + self._shutdown_complete = False + self._wake_requested = False + self._enqueued_total = 0 + self._completed_total = 0 + self._dropped_count = 0 + + # Guards the per-reason drop-log throttle state below. Deliberately + # separate from self._condition so a slow/blocking log handler can + # never be reached while the main condition is held, and so a + # throttle check can never itself be blocked by another thread's + # in-flight (slow) logging call. + self._drop_log_lock = threading.Lock() + self._last_drop_log_time: Dict[str, float] = {} + self._suppressed_drop_count: Dict[str, int] = {} + + self._worker_thread = threading.Thread( + name="A365EnrichingBatchSpanProcessor", + target=self._worker, + daemon=True, + ) + self._worker_thread.start() + + def _check_fork_reinit(self) -> None: + """Defense-in-depth PID guard for enqueue, covering platforms or + call paths where the os.register_at_fork hook above did not fire. + Mirrors BatchProcessor.emit()'s own pid check.""" + if self._pid == os.getpid(): + return + with self._fork_reinit_lock: + if self._pid == os.getpid(): + return + self._at_fork_reinit() + + def _at_fork_reinit(self) -> None: + """Recreate all per-process state after os.fork(). Only the calling + thread survives a fork: the old worker thread, and any lock/condition + state it held, are simply gone in the child -- reusing them could + hang forever rather than merely losing already-queued spans.""" + self._init_state_after_fork() + self._pid = os.getpid() + + # Backward-compat accessor mirroring BatchSpanProcessor.span_exporter. + @property + def span_exporter(self) -> SpanExporter: + return self._exporter + + def on_start(self, span: Span, parent_context: Optional[Context] = None) -> None: + """No-op: this processor only acts on span end.""" + def on_end(self, span: ReadableSpan) -> None: - """Apply the span enricher and pass to parent for batching.""" + """Apply enrichment/suppression, then atomically enqueue for export.""" enriched_span = span enricher = get_span_enricher() @@ -109,4 +337,161 @@ def on_end(self, span: ReadableSpan) -> None: excluded_attribute_keys={GEN_AI_INPUT_MESSAGES_KEY}, ) - super().on_end(enriched_span) + if not (enriched_span.context and enriched_span.context.trace_flags.sampled): + return + + self._enqueue(enriched_span) + + def _enqueue(self, span: ReadableSpan) -> bool: + """Reserve capacity and enqueue atomically. Returns whether accepted.""" + self._check_fork_reinit() + + drop_reason: Optional[str] = None + accepted = False + with self._condition: + if not self._accepting: + self._dropped_count += 1 + drop_reason = "shutdown" + elif len(self._queue) >= self._max_queue_size: + self._dropped_count += 1 + drop_reason = "queue_full" + else: + self._queue.append(span) + self._enqueued_total += 1 + accepted = True + if len(self._queue) >= self._max_export_batch_size: + # Wake the worker now instead of waiting for the + # schedule delay to elapse -- otherwise a queue that + # fills to capacity between schedule-delay ticks would + # stall (or, once truly full, start dropping) even + # though the worker could have drained it immediately. + self._wake_requested = True + self._condition.notify_all() + + # Logging never happens while self._condition is held: a slow or + # blocking handler (or a log storm from a sustained drop condition) + # must never be able to stall the worker or other producer threads. + if drop_reason is not None: + self._log_dropped_span(drop_reason) + return accepted + + def _log_dropped_span(self, reason: str) -> None: + """Log a dropped-span message, throttled per reason so a sustained + drop condition (queue full, or draining after shutdown) logs at + most once every _DROP_LOG_INTERVAL_SECONDS instead of once per + dropped span.""" + now = time.monotonic() + with self._drop_log_lock: + last = self._last_drop_log_time.get(reason) + if last is not None and (now - last) < _DROP_LOG_INTERVAL_SECONDS: + self._suppressed_drop_count[reason] = self._suppressed_drop_count.get(reason, 0) + 1 + return + suppressed = self._suppressed_drop_count.pop(reason, 0) + self._last_drop_log_time[reason] = now + + if reason == "shutdown": + message = "A365 span processor is shutting down; dropping span." + level = logging.INFO + else: + message = f"A365 span queue is full (max_queue_size={self._max_queue_size}); dropping span." + level = logging.WARNING + if suppressed: + message += ( + f" ({suppressed} further drops of this kind suppressed" + f" in the last {_DROP_LOG_INTERVAL_SECONDS:.0f}s)" + ) + logger.log(level, message) + + def _worker(self) -> None: + """Own the queue: batch, export outside the lock, then drain-to-exit on shutdown.""" + with self._condition: + while True: + if not self._wake_requested: + self._condition.wait(timeout=self._schedule_delay_seconds) + self._wake_requested = False + self._drain_locked() + if self._shutdown_requested and not self._queue and self._active_exports == 0: + break + self._finalize_locked() + + def _drain_locked(self) -> None: + """Export batches of up to max_export_batch_size until the queue is empty. + + Caller holds ``self._condition``; it is released only around the + actual (blocking) export call. + """ + while self._queue: + batch: List[ReadableSpan] = [ + self._queue.popleft() for _ in range(min(len(self._queue), self._max_export_batch_size)) + ] + self._active_exports += 1 + self._condition.release() + try: + self._export_batch(batch) + finally: + self._condition.acquire() + self._active_exports -= 1 + self._completed_total += len(batch) + # Wake any force_flush()/shutdown() callers waiting on progress. + self._condition.notify_all() + + def _export_batch(self, batch: List[ReadableSpan]) -> None: + token = attach(set_value(_SUPPRESS_INSTRUMENTATION_KEY, True)) + try: + self._exporter.export(batch) + except Exception: + logger.exception("Exception while exporting spans from the A365 batch processor.") + finally: + detach(token) + + def _finalize_locked(self) -> None: + """Perform the single exporter.shutdown() call. Caller holds the condition on entry.""" + self._condition.release() + try: + self._exporter.shutdown() + except Exception: + logger.exception("Exception while shutting down the A365 span exporter.") + finally: + self._condition.acquire() + self._shutdown_complete = True + self._condition.notify_all() + + def shutdown(self, timeout_millis: Optional[int] = None) -> None: + """Stop accepting new spans, drain the queue, then shut down the exporter once. + + Safe to call concurrently from multiple threads: every caller waits + on the same completion signal, and only the worker thread ever calls + ``exporter.shutdown()``. If ``timeout_millis`` elapses first, this + call returns without touching the exporter; the worker keeps running + in the background and remains the sole owner of that cleanup. + """ + if timeout_millis is None: + timeout_millis = _DEFAULT_SHUTDOWN_TIMEOUT_MILLIS + deadline = time.monotonic() + (timeout_millis / 1000.0) + with self._condition: + self._accepting = False + self._shutdown_requested = True + self._wake_requested = True + self._condition.notify_all() + while not self._shutdown_complete: + remaining = deadline - time.monotonic() + if remaining <= 0: + return + self._condition.wait(timeout=remaining) + + def force_flush(self, timeout_millis: int = 30000) -> bool: + """Block until every span enqueued so far has been exported (or attempted).""" + deadline = time.monotonic() + (timeout_millis / 1000.0) + with self._condition: + if not self._accepting: + # Shutdown already started/finished; it owns draining now. + return False + target = self._enqueued_total + self._wake_requested = True + self._condition.notify_all() + while self._completed_total < target: + remaining = deadline - time.monotonic() + if remaining <= 0: + return False + self._condition.wait(timeout=remaining) + return True diff --git a/src/microsoft/opentelemetry/a365/core/exporters/persistent_storage.py b/src/microsoft/opentelemetry/a365/core/exporters/persistent_storage.py new file mode 100644 index 00000000..d7e1cada --- /dev/null +++ b/src/microsoft/opentelemetry/a365/core/exporters/persistent_storage.py @@ -0,0 +1,408 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Secure SQLite-backed durable queue for A365 telemetry delivery.""" + +from __future__ import annotations + +import getpass +import hashlib +import logging +import os +import sqlite3 +import stat +import sys +import tempfile +import threading +import time +from dataclasses import dataclass, field +from pathlib import Path + +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import IdentityKey + +_logger = logging.getLogger(__name__) + +_DEFAULT_CAPACITY_BYTES = 50 * 1024 * 1024 # 50 MB +_DEFAULT_RETENTION_SECONDS = 2 * 24 * 3600 # 2 days + +_SCHEMA_VERSION = 2 + + +def _table_ddl(table_name: str) -> str: + return f""" +CREATE TABLE IF NOT EXISTS {table_name} ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + schema_version INTEGER NOT NULL, + tenant_id TEXT NOT NULL, + agent_id TEXT NOT NULL, + agentic_user_id TEXT, + use_s2s_endpoint INTEGER NOT NULL, + payload TEXT NOT NULL, + created_at REAL NOT NULL, + lease_until REAL, + retry_count INTEGER NOT NULL DEFAULT 0 +); +""" + + +@dataclass(frozen=True) +class DurableRecord: + """An envelope for one telemetry payload.""" + + schema_version: int + tenant_id: str + agent_id: str + agentic_user_id: str | None + use_s2s_endpoint: bool + payload: str + created_at: float + lease_until: float | None = None + retry_count: int = 0 + record_id: int | None = field(default=None) + + @staticmethod + def new(key: IdentityKey, payload: str) -> DurableRecord: + """Construct an unpersisted record from an IdentityKey.""" + return DurableRecord( + schema_version=_SCHEMA_VERSION, + tenant_id=key.tenant_id, + agent_id=key.agent_id, + agentic_user_id=key.agentic_user_id, + use_s2s_endpoint=key.use_s2s_endpoint, + payload=payload, + created_at=time.time(), + ) + + +def _resolve_default_directory() -> Path: + digest = hashlib.sha256((getpass.getuser() + sys.executable + str(Path.cwd())).encode()).hexdigest()[:16] + if sys.platform == "win32": + base = Path(os.environ.get("LOCALAPPDATA", tempfile.gettempdir())) + else: + xdg = os.environ.get("XDG_STATE_HOME") + if xdg: + base = Path(xdg) + else: + # Prefer ~/.local/state (created on demand) rather than falling back + # to a shared temp dir merely because the path does not exist yet. + # Only fall back when the home directory cannot be resolved at all. + try: + base = Path.home() / ".local" / "state" + except (RuntimeError, OSError): + base = Path(tempfile.gettempdir()) + return base / "a365-durable-queue" / digest + + +def _ensure_private_directory(directory: Path) -> None: + """Create the directory with mode 0700, or validate ownership if it exists.""" + if directory.exists(): + if os.name != "nt": + # Use a non-symlink-following lstat so a symlinked queue directory + # cannot redirect telemetry writes outside a private, caller-owned + # location or defeat the ownership check via its target. + st = os.lstat(directory) + if stat.S_ISLNK(st.st_mode): + raise PermissionError(f"Durable queue directory must not be a symlink: {directory}") + if st.st_uid != os.getuid(): # pylint: disable=no-member + raise PermissionError(f"Durable queue directory has unsafe ownership: {directory}") + os.chmod(directory, 0o700) + return + # Create parents first (no mode enforcement needed for intermediate dirs), + # then create the final directory with explicit mode so the kernel sets it + # before any child entry can appear. chmod follows to override a restrictive umask. + directory.mkdir(parents=True, exist_ok=True, mode=0o700) + if os.name != "nt": + os.chmod(directory, 0o700) + + +class PersistentStorage: + """Thread-safe SQLite-backed durable record queue.""" + + def __init__( + self, + directory: Path | None = None, + capacity_bytes: int = _DEFAULT_CAPACITY_BYTES, + retention_seconds: float = _DEFAULT_RETENTION_SECONDS, + ) -> None: + self._directory = Path(directory) if directory is not None else _resolve_default_directory() + self._capacity_bytes = capacity_bytes + self._retention_seconds = retention_seconds + self._lock = threading.RLock() + + _ensure_private_directory(self._directory) + + self.database_path = self._directory / "queue.db" + # isolation_level=None → autocommit; all transactions are explicit. + self._conn = sqlite3.connect(str(self.database_path), check_same_thread=False, isolation_level=None) + if os.name != "nt": + os.chmod(self.database_path, 0o600) + + self._conn.execute("PRAGMA journal_mode=WAL") + self._initialize_schema() + + if os.name != "nt": + # WAL journal initialization creates the -wal/-shm sidecars, which can + # hold the same OTLP payloads as the DB. Lock the DB and any existing + # sidecars to owner-only now; the 0700 directory keeps future sidecars + # private on creation. + self._restrict_file_permissions() + + def _initialize_schema(self) -> None: + """Create the current schema or migrate the legacy url-backed schema.""" + self._conn.execute("BEGIN IMMEDIATE") + try: + columns = self._table_columns("durable_records") + if not columns: + self._conn.execute(_table_ddl("durable_records")) + elif "url" in columns: + self._migrate_legacy_schema() + self._conn.execute("COMMIT") + except sqlite3.Error: + self._conn.execute("ROLLBACK") + raise + + def _table_columns(self, table_name: str) -> set[str]: + rows = self._conn.execute(f"PRAGMA table_info({table_name})").fetchall() + return {row[1] for row in rows} + + def _migrate_legacy_schema(self) -> None: + """Rewrite the v1 url-backed table into the v2 identity-only schema.""" + self._conn.execute("DROP TABLE IF EXISTS durable_records_v2") + self._conn.execute(_table_ddl("durable_records_v2")) + self._conn.execute( + """ + INSERT INTO durable_records_v2 ( + id, schema_version, tenant_id, agent_id, agentic_user_id, + use_s2s_endpoint, payload, created_at, lease_until, retry_count + ) + SELECT + id, + ?, + tenant_id, + agent_id, + agentic_user_id, + use_s2s_endpoint, + payload, + created_at, + lease_until, + retry_count + FROM durable_records + """, + (_SCHEMA_VERSION,), + ) + self._conn.execute("DROP TABLE durable_records") + self._conn.execute("ALTER TABLE durable_records_v2 RENAME TO durable_records") + + def _restrict_file_permissions(self) -> None: + """Restrict the DB and any existing WAL/SHM sidecars to owner-only (0600). + + Callers gate this on POSIX; on Windows the durable queue relies on the + private (0700) directory for confidentiality. + """ + for suffix in ("", "-wal", "-shm"): + sidecar = Path(f"{self.database_path}{suffix}") + if sidecar.exists(): + os.chmod(sidecar, 0o600) + + # ------------------------------------------------------------------ + # Public API + # ------------------------------------------------------------------ + + def store(self, record: DurableRecord) -> bool: + """Persist a record. Returns False (and logs) if storage fails.""" + with self._lock: + try: + now = time.time() + expire_before = now - self._retention_seconds + + self._conn.execute("BEGIN IMMEDIATE") + # Prune expired rows first + self._conn.execute( + "DELETE FROM durable_records WHERE created_at < ?", + (expire_before,), + ) + + # Capacity check based on live (in-use) pages. SQLite does not + # shrink the file on delete; freed pages move to the freelist and + # would otherwise be counted as "used", permanently wedging the + # queue after a fill -> delete -> refill cycle. Subtracting the + # freelist gives the reclaimable, live footprint. + row = self._conn.execute( + "SELECT (page_count - freelist_count) * page_size " + "FROM pragma_page_count(), pragma_freelist_count(), pragma_page_size()" + ).fetchone() + current_bytes = row[0] if row and row[0] is not None else 0 + current_bytes = max(current_bytes, 0) + if current_bytes + len(record.payload.encode()) > self._capacity_bytes: + self._conn.execute("ROLLBACK") + _logger.error( + "PersistentStorage: capacity exceeded (%d bytes used, limit %d)", + current_bytes, + self._capacity_bytes, + ) + return False + + self._conn.execute( + """INSERT INTO durable_records + (schema_version, tenant_id, agent_id, agentic_user_id, + use_s2s_endpoint, payload, created_at) + VALUES (?, ?, ?, ?, ?, ?, ?)""", + ( + record.schema_version, + record.tenant_id, + record.agent_id, + record.agentic_user_id, + int(record.use_s2s_endpoint), + record.payload, + record.created_at, + ), + ) + self._conn.execute("COMMIT") + return True + except sqlite3.Error as exc: + _logger.error("PersistentStorage.store failed: %s", exc) + try: + self._conn.execute("ROLLBACK") + except sqlite3.Error: + pass + return False + + def claim(self, limit: int, lease_seconds: float) -> list[DurableRecord]: + """Atomically lease up to *limit* unleased records.""" + with self._lock: + try: + now = time.time() + expire_before = now - self._retention_seconds + lease_until = now + lease_seconds + + self._conn.execute("BEGIN IMMEDIATE") + + # Prune expired rows inside the same transaction + self._conn.execute( + "DELETE FROM durable_records WHERE created_at < ?", + (expire_before,), + ) + + records: list[DurableRecord] = [] + claimed_ids: set[int] = set() + while len(records) < limit: + select_sql = """ + SELECT id, schema_version, tenant_id, agent_id, agentic_user_id, + use_s2s_endpoint, payload, created_at, lease_until, retry_count + FROM durable_records + WHERE (lease_until IS NULL OR lease_until <= ?) + AND created_at >= ? + """ + params: list[object] = [now, expire_before] + if claimed_ids: + placeholders = ", ".join("?" for _ in claimed_ids) + select_sql += f" AND id NOT IN ({placeholders})" + params.extend(claimed_ids) + select_sql += " ORDER BY created_at LIMIT 1" + + row = self._conn.execute(select_sql, tuple(params)).fetchone() + if row is None: + break + + invalid_reason = self._claim_validation_error(row) + if invalid_reason is not None: + self._conn.execute( + "DELETE FROM durable_records WHERE id = ?", + (row[0],), + ) + _logger.warning( + "PersistentStorage.claim dropped durable record %s: %s", + row[0], + invalid_reason, + ) + continue + + self._conn.execute( + "UPDATE durable_records SET lease_until = ? WHERE id = ?", + (lease_until, row[0]), + ) + claimed_ids.add(int(row[0])) + records.append( + DurableRecord( + record_id=row[0], + schema_version=row[1], + tenant_id=row[2], + agent_id=row[3], + agentic_user_id=row[4], + use_s2s_endpoint=bool(row[5]), + payload=row[6], + created_at=row[7], + lease_until=lease_until, + retry_count=row[9], + ) + ) + + self._conn.execute("COMMIT") + return records + except sqlite3.Error as exc: + _logger.error("PersistentStorage.claim failed: %s", exc) + try: + self._conn.execute("ROLLBACK") + except sqlite3.Error: + pass + return [] + + def delete(self, record_id: int) -> bool: + """Delete a record by id. Returns False if not found or on error.""" + with self._lock: + try: + self._conn.execute("BEGIN IMMEDIATE") + cur = self._conn.execute("DELETE FROM durable_records WHERE id = ?", (record_id,)) + found = cur.rowcount > 0 + self._conn.execute("COMMIT") + return found + except sqlite3.Error as exc: + _logger.error("PersistentStorage.delete failed: %s", exc) + try: + self._conn.execute("ROLLBACK") + except sqlite3.Error: + pass + return False + + @staticmethod + def _claim_validation_error(row: tuple[object, ...]) -> str | None: + if row[1] != _SCHEMA_VERSION: + return f"unsupported schema_version={row[1]!r}" + if not isinstance(row[2], str) or not row[2].strip(): + return "blank tenant_id" + if not isinstance(row[3], str) or not row[3].strip(): + return "blank agent_id" + if not isinstance(row[6], str) or not row[6].strip(): + return "blank payload" + return None + + def release(self, record_id: int) -> bool: + """Release a lease so the record becomes claimable again.""" + with self._lock: + try: + self._conn.execute("BEGIN IMMEDIATE") + cur = self._conn.execute( + "UPDATE durable_records SET lease_until = NULL WHERE id = ?", + (record_id,), + ) + found = cur.rowcount > 0 + self._conn.execute("COMMIT") + return found + except sqlite3.Error as exc: + _logger.error("PersistentStorage.release failed: %s", exc) + try: + self._conn.execute("ROLLBACK") + except sqlite3.Error: + pass + return False + + def close(self) -> None: + """Close the underlying SQLite connection.""" + with self._lock: + try: + self._conn.close() + except sqlite3.Error as exc: + _logger.error("PersistentStorage.close failed: %s", exc) + + +__all__ = ["DurableRecord", "PersistentStorage"] diff --git a/src/microsoft/opentelemetry/a365/core/exporters/replay_coordinator.py b/src/microsoft/opentelemetry/a365/core/exporters/replay_coordinator.py new file mode 100644 index 00000000..57f3198b --- /dev/null +++ b/src/microsoft/opentelemetry/a365/core/exporters/replay_coordinator.py @@ -0,0 +1,289 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Background replay coordinator for durable telemetry delivery.""" + +from __future__ import annotations + +import logging +import threading +from collections.abc import Callable + +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, + TransmissionGate, +) +from microsoft.opentelemetry.a365.core.exporters.persistent_storage import ( + DurableRecord, + PersistentStorage, +) +from microsoft.opentelemetry.a365.constants import A365_HTTP_TIMEOUT_SECONDS + +_logger = logging.getLogger(__name__) + +_MAX_RECORDS_PER_PASS = 10 +# A pass leases all records before sending them sequentially. Keep every lease +# valid for the worst-case full pass so another process sharing the SQLite +# queue cannot reclaim a record while this coordinator is still sending it. +_LEASE_SECONDS = (_MAX_RECORDS_PER_PASS * A365_HTTP_TIMEOUT_SECONDS) + 5.0 + +# Background cadence: even without an explicit wake(), the replay loop re-runs a +# pass on this interval so a startup backlog larger than one pass (or records +# left behind by a bounded pass) is eventually drained. Matches the durable +# design's "wakes on new persisted work and periodically" contract. +_REPLAY_POLL_INTERVAL_SECONDS = 30.0 + + +class ReplayIdentityError(Exception): + """Raised by the send callback when an identity or token cannot be resolved. + + When the coordinator catches this exception, it releases the current record + and releases the gate probe for that identity, then continues processing + remaining records in the batch. This is appropriate for transient, + per-identity failures (e.g. credential look-up errors) that should not + block delivery of records belonging to other identities. + + Contrast with unexpected / general exceptions, which cause the coordinator + to release *all* remaining leased records and abort the current pass. + """ + + +class ReplayEndpointError(Exception): + """Raised when replay cannot safely use the current exporter endpoint. + + Task 2 raises this from the replay send callback when the reconstructed + endpoint is invalid for bearer-token replay (for example, non-HTTPS). Task + 3 will add coordinator-specific handling. + """ + + +class ReplayCoordinator: + """Drive durable record replay on a single daemon thread.""" + + def __init__( + self, + storage: PersistentStorage, + gate: TransmissionGate, + send: Callable[[DurableRecord], DeliveryResult], + poll_interval_seconds: float = _REPLAY_POLL_INTERVAL_SECONDS, + ) -> None: + self._storage = storage + self._gate = gate + self._send = send + self._poll_interval_seconds = poll_interval_seconds + self._stop_event = threading.Event() + self._wake_event = threading.Event() + self._lock = threading.RLock() + self._thread: threading.Thread | None = None + + def start(self) -> None: + """Start the replay loop on one daemon thread. + + Calling ``start()`` after ``shutdown()`` is a deliberate safe no-op: + once the stop event has been set the coordinator is permanently + stopped and a new instance should be created instead. + """ + with self._lock: + if self._thread is not None and self._thread.is_alive(): + self._wake_event.set() + return + if self._stop_event.is_set(): + _logger.debug("ReplayCoordinator: start() called after shutdown — ignored") + return + + self._wake_event.set() + self._thread = threading.Thread( + target=self._run_loop, + name="ReplayCoordinator", + daemon=True, + ) + self._thread.start() + + def wake(self) -> None: + """Wake the replay thread to run another pass.""" + self._wake_event.set() + + def shutdown(self, timeout_seconds: float | None = None) -> bool: + """Signal the replay thread to stop and wait for it to exit. + + ``timeout_seconds=None`` (the default) waits indefinitely: the caller + decides how long "long enough" is, so this primitive never silently + gives up and reports success while the thread is still running a + pass. A finite value performs a bounded wait instead and returns + whether the thread had exited by the deadline; the stop request + itself is always recorded regardless of the timeout, so a later + bounded or unbounded call will still observe (and can wait out) the + same in-progress shutdown. + + Safe to call concurrently from multiple threads. A thread can never + join itself, so a call made from the replay thread itself (e.g. via + an unexpected reentrant callback) returns ``False`` immediately + without blocking or raising -- the stop request is still recorded, + but the caller cannot safely wait here for its own thread to exit. + """ + with self._lock: + thread = self._thread + self._stop_event.set() + self._wake_event.set() + if thread is None: + return True + if thread is threading.current_thread(): + return False + thread.join(timeout_seconds) + return not thread.is_alive() + + def run_once(self) -> bool: + """Claim and process a single bounded replay batch. + + Returns ``True`` only when a maximal batch (``_MAX_RECORDS_PER_PASS``) + was claimed *and* every record in it reached a terminal state + (delivered or permanently dropped). In that case more records may + remain and the loop should run again immediately. It returns ``False`` + for an empty/partial batch, when the pass was stopped early (retryable + failure, shutdown, or unexpected error), or when any record was left + behind (gate-blocked or released), so the loop falls back to the + periodic cadence and does not busy-spin. + """ + records = self._storage.claim(_MAX_RECORDS_PER_PASS, _LEASE_SECONDS) + if not records: + return False + + deleted_count = 0 + for index, record in enumerate(records): + if self._stop_event.is_set(): + self._release_remaining(records, index) + return False + + identity = self._identity_for(record) + if not self._gate.try_acquire(identity): + self._release_record(record) + continue + + try: + result = self._send(record) + except ReplayIdentityError as exc: + # Per-identity token/credential failure: release this record and + # its gate probe, but continue processing the rest of the batch. + _logger.debug("Replay identity error for record %s: %s", record.record_id, exc) + self._release_record(record) + self._gate.release_probe(identity) + continue + except ReplayEndpointError as exc: + _logger.warning( + "Replay endpoint error for record %s: %s", + record.record_id, + exc, + ) + self._release_record(record) + self._gate.release_probe(identity) + self._release_remaining(records, index + 1) + return False + except Exception as exc: # pylint: disable=broad-except + # Unexpected failure: release the current record and all + # remaining leased records, then abort the pass so we do not + # send stale data after an unknown error. + _logger.warning( + "Unexpected error during replay for record %s: %s", + record.record_id, + exc, + exc_info=True, + ) + self._release_record(record) + self._gate.release_probe(identity) + self._release_remaining(records, index + 1) + return False + + if result.disposition is DeliveryDisposition.DELIVERED: + deleted = self._delete_record(record, reason="delivered") + self._gate.record_success(identity) + if deleted: + deleted_count += 1 + continue + + if result.disposition is DeliveryDisposition.PERMANENT: + # Permanent failures (e.g. 400 Bad Request) indicate the + # payload is undeliverable regardless of retry count. We + # delete the record to avoid re-queuing it forever and call + # record_success so the gate resets: the identity itself is + # healthy; only this particular record was rejected. + deleted = self._delete_record(record, reason="permanent") + self._gate.record_success(identity) + if deleted: + deleted_count += 1 + continue + + self._gate.record_retryable_failure(identity, result.retry_after) + self._release_record(record) + self._release_remaining(records, index + 1) + return False + + # Only request an immediate re-run when we fully drained a maximal + # batch; otherwise re-claiming would return records that are still + # gated/leased and spin the loop. + return deleted_count == len(records) and len(records) >= _MAX_RECORDS_PER_PASS + + def _run_loop(self) -> None: + while not self._stop_event.is_set(): + # A set wake event returns immediately; otherwise wake on the fixed + # background cadence so leftover records are not stranded until an + # external wake() arrives. + self._wake_event.wait(self._poll_interval_seconds) + self._wake_event.clear() + if self._stop_event.is_set(): + break + # Drain consecutive full passes so a startup backlog larger than one + # pass is not left at >10 records until the next wake. + try: + while not self._stop_event.is_set() and self.run_once(): + pass + except Exception: # pylint: disable=broad-except + # An unexpected exception from run_once (e.g. a programming bug, + # unexpected storage error not caught inside run_once) must not + # permanently kill the thread. Log it and fall back to the + # periodic cadence so later passes have a chance to succeed. + _logger.exception( + "ReplayCoordinator: unexpected exception from run_once; " + "replay thread will retry on the next periodic wake" + ) + + @staticmethod + def _identity_for(record: DurableRecord) -> IdentityKey: + return IdentityKey( + tenant_id=record.tenant_id, + agent_id=record.agent_id, + agentic_user_id=record.agentic_user_id, + use_s2s_endpoint=record.use_s2s_endpoint, + ) + + def _delete_record(self, record: DurableRecord, reason: str) -> bool: + if record.record_id is None: + return False + + deleted = self._storage.delete(record.record_id) + if deleted: + return True + + if reason == "delivered": + _logger.warning( + "Replay delete failed for delivered record %s; duplicate delivery may occur.", + record.record_id, + ) + else: + _logger.warning( + "Replay delete failed for permanent record %s; poison record may recur.", + record.record_id, + ) + return False + + def _release_record(self, record: DurableRecord) -> None: + if record.record_id is not None: + self._storage.release(record.record_id) + + def _release_remaining(self, records: list[DurableRecord], start_index: int) -> None: + for record in records[start_index:]: + self._release_record(record) + + +__all__ = ["ReplayCoordinator", "ReplayEndpointError", "ReplayIdentityError"] diff --git a/src/microsoft/opentelemetry/a365/core/exporters/utils.py b/src/microsoft/opentelemetry/a365/core/exporters/utils.py index 93c1a65d..3cea00bf 100644 --- a/src/microsoft/opentelemetry/a365/core/exporters/utils.py +++ b/src/microsoft/opentelemetry/a365/core/exporters/utils.py @@ -19,6 +19,9 @@ import time from collections.abc import Callable, Mapping, Sequence from dataclasses import dataclass, field +from datetime import datetime, timezone +from email.utils import parsedate_to_datetime +from pathlib import Path from typing import TYPE_CHECKING, Any, List, Optional, TypeVar from urllib.parse import urlparse @@ -266,10 +269,13 @@ def build_export_url(endpoint: str, agent_id: str, tenant_id: str, use_s2s_endpo return f"https://{endpoint}{endpoint_path}?api-version=1" -def parse_retry_after(headers: Mapping[str, str]) -> float | None: +def parse_retry_after( + headers: Mapping[str, str], + now: Callable[[], datetime] | None = None, +) -> float | None: """Parse the ``Retry-After`` header value. - Only numeric (seconds) values are supported. HTTP-date values are ignored. + Supports delta-seconds and HTTP-date values. """ retry_after = headers.get("Retry-After") if retry_after is None: @@ -277,7 +283,18 @@ def parse_retry_after(headers: Mapping[str, str]) -> float | None: try: return float(retry_after) except (ValueError, TypeError): - return None + try: + retry_at = parsedate_to_datetime(retry_after) + except (TypeError, ValueError, IndexError, OverflowError): + return None + + if retry_at.tzinfo is None: + retry_at = retry_at.replace(tzinfo=timezone.utc) + + current_time = now() if now is not None else datetime.now(timezone.utc) + if current_time.tzinfo is None: + current_time = current_time.replace(tzinfo=timezone.utc) + return (retry_at - current_time).total_seconds() def is_agent365_exporter_enabled() -> bool: @@ -620,9 +637,29 @@ def _env_bool(name: str, default: bool = False) -> bool: return val in ("true", "1", "yes", "on") +def coerce_storage_directory(value: Optional[str | Path]) -> Optional[Path]: + """Normalize a ``storage_directory`` option to a ``Path`` or ``None``. + + ``None`` selects the platform default path. An explicitly empty or + whitespace-only string is rejected with :class:`ValueError` so it is never + silently treated as "use the default". + """ + if value is None: + return None + if isinstance(value, Path): + return value + if isinstance(value, str): + if not value.strip(): + raise ValueError("storage_directory must be a non-empty path or None") + return Path(value) + raise ValueError("storage_directory must be a string path, Path, or None") + + def create_a365_components( token_resolver: Callable[[str, str], Optional[str]] | None = None, contextual_token_resolver: Callable[[TokenResolverContext], Optional[str]] | None = None, + disable_offline_storage: bool = False, + storage_directory: Optional[str] = None, ) -> A365Handlers: """Create Agent365 span processors ready to be added to a TracerProvider. @@ -632,6 +669,10 @@ def create_a365_components( :param contextual_token_resolver: Optional callable ``(TokenResolverContext) -> str | None``. Provides rich context including the agentic user ID. Takes precedence over ``token_resolver`` when set. + :param disable_offline_storage: When True, disables durable delivery (no disk writes or + replay). Defaults to False. + :param storage_directory: Custom directory for durable offline storage. When None, a + platform default path is used. Defaults to None. All other configuration is read from environment variables: - ``ENABLE_A365_OBSERVABILITY_EXPORTER`` -- must be true for the HTTP exporter @@ -660,6 +701,8 @@ def create_a365_components( token_resolver=resolved_token_resolver, contextual_token_resolver=contextual_token_resolver, use_s2s_endpoint=use_s2s_endpoint, + disable_offline_storage=disable_offline_storage, + storage_directory=storage_directory, ) # Create the exporter (Agent365 HTTP or console fallback) @@ -671,6 +714,8 @@ def create_a365_components( cluster_category=options.cluster_category, use_s2s_endpoint=options.use_s2s_endpoint, max_payload_bytes=options.max_payload_bytes, + enable_durable_delivery=not options.disable_offline_storage, + storage_directory=coerce_storage_directory(options.storage_directory), ) else: logger.warning( diff --git a/tests/a365/test_circuit_breaker.py b/tests/a365/test_circuit_breaker.py index 2429c832..98f54dec 100644 --- a/tests/a365/test_circuit_breaker.py +++ b/tests/a365/test_circuit_breaker.py @@ -1,8 +1,17 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. +"""Transmission-gate coverage. + +The legacy global ``_CircuitBreaker`` was removed in favour of the +per-identity :class:`TransmissionGate`. Its half-open / probe behaviour now +lives on the gate, so the circuit-breaker tests were migrated here to cover the +gate directly and to verify that the exporter honours it (a blocked identity +persists instead of sending, and a single probe is admitted once the block +window elapses). +""" + import os -import time import unittest from unittest.mock import MagicMock, patch @@ -10,113 +19,95 @@ from opentelemetry.trace import SpanKind, StatusCode from microsoft.opentelemetry.a365.core.exporters.agent365_exporter import ( - DEFAULT_CB_FAILURE_THRESHOLD, _Agent365Exporter, - _CircuitBreaker, ) +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, + TransmissionGate, +) + + +class FakeClock: + """Callable monotonic clock used to drive the gate deterministically.""" + + def __init__(self, value: float = 0.0) -> None: + self.value = value + + def __call__(self) -> float: + return self.value + + def advance(self, seconds: float) -> None: + self.value += seconds + + +KEY = IdentityKey(tenant_id="t1", agent_id="a1", agentic_user_id=None, use_s2s_endpoint=False) +OTHER_KEY = IdentityKey(tenant_id="t2", agent_id="a2", agentic_user_id=None, use_s2s_endpoint=False) + # --------------------------------------------------------------------------- -# _CircuitBreaker unit tests +# TransmissionGate unit tests (half-open probe behaviour). # --------------------------------------------------------------------------- -class TestCircuitBreakerInit(unittest.TestCase): - def test_starts_closed(self): - cb = _CircuitBreaker() - self.assertEqual(cb.state, _CircuitBreaker.CLOSED) - - def test_custom_thresholds(self): - cb = _CircuitBreaker(failure_threshold=10, recovery_timeout=60.0) - self.assertEqual(cb.state, _CircuitBreaker.CLOSED) - self.assertEqual(cb.total_rejected, 0) - - -class TestCircuitBreakerTransitions(unittest.TestCase): - def test_stays_closed_below_threshold(self): - cb = _CircuitBreaker(failure_threshold=5) - for _ in range(4): - cb.record_failure() - self.assertEqual(cb.state, _CircuitBreaker.CLOSED) - self.assertTrue(cb.allow_request()) - - def test_opens_at_threshold(self): - cb = _CircuitBreaker(failure_threshold=5) - for _ in range(5): - cb.record_failure() - self.assertEqual(cb.state, _CircuitBreaker.OPEN) - self.assertFalse(cb.allow_request()) - - def test_rejects_when_open(self): - cb = _CircuitBreaker(failure_threshold=2) - cb.record_failure() - cb.record_failure() - self.assertFalse(cb.allow_request()) - self.assertFalse(cb.allow_request()) - self.assertEqual(cb.total_rejected, 2) - - def test_transitions_to_half_open_after_recovery_timeout(self): - cb = _CircuitBreaker(failure_threshold=1, recovery_timeout=30.0) - cb.record_failure() - self.assertEqual(cb.state, _CircuitBreaker.OPEN) - # Simulate recovery timeout elapsing - cb._last_failure_time = time.monotonic() - 31.0 - self.assertEqual(cb.state, _CircuitBreaker.HALF_OPEN) - self.assertTrue(cb.allow_request()) - - def test_half_open_success_closes(self): - cb = _CircuitBreaker(failure_threshold=1, recovery_timeout=30.0) - cb.record_failure() - cb._last_failure_time = time.monotonic() - 31.0 - self.assertTrue(cb.allow_request()) # half-open allows probe - cb.record_success() - self.assertEqual(cb.state, _CircuitBreaker.CLOSED) - self.assertTrue(cb.allow_request()) - - def test_half_open_failure_reopens(self): - cb = _CircuitBreaker(failure_threshold=1, recovery_timeout=30.0) - cb.record_failure() - cb._last_failure_time = time.monotonic() - 31.0 - self.assertTrue(cb.allow_request()) # half-open probe - cb.record_failure() - self.assertEqual(cb.state, _CircuitBreaker.OPEN) - self.assertFalse(cb.allow_request()) - - def test_half_open_allows_only_one_probe(self): - cb = _CircuitBreaker(failure_threshold=1, recovery_timeout=30.0) - cb.record_failure() - cb._last_failure_time = time.monotonic() - 31.0 - # First call gets the probe token - self.assertTrue(cb.allow_request()) - # Second call should be rejected while probe is in flight - self.assertFalse(cb.allow_request()) - self.assertEqual(cb.total_rejected, 1) - - def test_success_resets_failure_count(self): - cb = _CircuitBreaker(failure_threshold=3) - cb.record_failure() - cb.record_failure() - cb.record_success() - # After reset, need 3 more failures to trip - cb.record_failure() - cb.record_failure() - self.assertEqual(cb.state, _CircuitBreaker.CLOSED) - cb.record_failure() - self.assertEqual(cb.state, _CircuitBreaker.OPEN) - - def test_total_rejected_resets_on_close(self): - cb = _CircuitBreaker(failure_threshold=1, recovery_timeout=30.0) - cb.record_failure() - cb.allow_request() # rejected - cb.allow_request() # rejected - self.assertEqual(cb.total_rejected, 2) - cb._last_failure_time = time.monotonic() - 31.0 - cb.allow_request() # half-open probe allowed - cb.record_success() - self.assertEqual(cb.total_rejected, 0) +class TestTransmissionGate(unittest.TestCase): + def _gate(self, clock=None): + return TransmissionGate(clock=clock or FakeClock(), random_fn=lambda: 0.0) + + def test_closed_gate_allows_concurrent_sends(self): + gate = self._gate() + self.assertTrue(gate.try_acquire(KEY)) + self.assertTrue(gate.try_acquire(KEY)) + + def test_blocks_after_retryable_failure(self): + clock = FakeClock() + gate = self._gate(clock) + gate.record_retryable_failure(KEY, retry_after=30) + self.assertFalse(gate.try_acquire(KEY)) + + def test_allows_single_probe_after_block_window(self): + clock = FakeClock() + gate = self._gate(clock) + gate.record_retryable_failure(KEY, retry_after=30) + clock.advance(30) + # Exactly one probe is admitted; a concurrent second acquire is refused. + self.assertTrue(gate.try_acquire(KEY)) + self.assertFalse(gate.try_acquire(KEY)) + + def test_success_resets_block(self): + clock = FakeClock() + gate = self._gate(clock) + gate.record_retryable_failure(KEY, retry_after=30) + clock.advance(30) + self.assertTrue(gate.try_acquire(KEY)) # probe + gate.record_success(KEY) + self.assertTrue(gate.try_acquire(KEY)) # fully reset + + def test_failed_probe_reblocks(self): + clock = FakeClock() + gate = self._gate(clock) + gate.record_retryable_failure(KEY, retry_after=30) + clock.advance(30) + self.assertTrue(gate.try_acquire(KEY)) # probe admitted + gate.record_retryable_failure(KEY, retry_after=30) # probe failed + self.assertFalse(gate.try_acquire(KEY)) + + def test_release_probe_allows_reacquire(self): + gate = self._gate() + self.assertTrue(gate.try_acquire(KEY)) + gate.release_probe(KEY) + self.assertTrue(gate.try_acquire(KEY)) + + def test_isolates_identities(self): + gate = self._gate() + gate.record_retryable_failure(KEY, retry_after=30) + self.assertFalse(gate.try_acquire(KEY)) + self.assertTrue(gate.try_acquire(OTHER_KEY)) # --------------------------------------------------------------------------- -# Integration: _Agent365Exporter with circuit breaker +# Exporter integration: the gate governs sending vs. persisting. # --------------------------------------------------------------------------- @@ -169,218 +160,69 @@ def _make_span( return span -class TestExporterCircuitBreakerIntegration(unittest.TestCase): - """Verify that _Agent365Exporter honours the circuit breaker.""" +class TestExporterGateIntegration(unittest.TestCase): + def _make_exporter(self, clock): + exporter = _Agent365Exporter( + token_resolver=lambda a, t: "token", + enable_durable_delivery=False, + ) + exporter._gate = TransmissionGate(clock=clock, random_fn=lambda: 0.0) + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + return exporter @patch.dict(os.environ, {}, clear=True) - def _make_exporter(self): - return _Agent365Exporter(token_resolver=lambda a, t: "token") - - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep") - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.requests.Session") - @patch.dict(os.environ, {}, clear=True) - def test_circuit_opens_after_consecutive_500s(self, mock_session_cls, mock_sleep): - """After DEFAULT_CB_FAILURE_THRESHOLD export cycles all returning 500, - subsequent exports should be rejected without HTTP calls.""" - mock_resp = MagicMock() - mock_resp.status_code = 500 - mock_resp.text = "Internal Server Error" - mock_resp.headers = {} - - session_instance = MagicMock() - session_instance.post.return_value = mock_resp - mock_session_cls.return_value = session_instance - - exporter = self._make_exporter() - exporter._session = session_instance - + def test_retryable_blocks_gate_then_subsequent_export_persists_without_send(self): + clock = FakeClock() + exporter = self._make_exporter(clock) + exporter._post_once = MagicMock(return_value=DeliveryResult(DeliveryDisposition.RETRYABLE, 30)) span = _make_span() - # Each failed export cycle = 1 circuit breaker failure - for _ in range(DEFAULT_CB_FAILURE_THRESHOLD): - result = exporter.export([span]) - self.assertEqual(result, SpanExportResult.FAILURE) - - # Circuit should now be open - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.OPEN) - - # Next export should fail immediately without HTTP - session_instance.post.reset_mock() - result = exporter.export([span]) - self.assertEqual(result, SpanExportResult.FAILURE) - session_instance.post.assert_not_called() + # First export: one send, retryable => persisted, gate blocked. + self.assertIs(exporter.export([span]), SpanExportResult.SUCCESS) + self.assertEqual(exporter._post_once.call_count, 1) + # Second export while blocked: gate rejects => persisted, no send. + exporter._post_once.reset_mock() + exporter._storage.store.reset_mock() + self.assertIs(exporter.export([span]), SpanExportResult.SUCCESS) + exporter._post_once.assert_not_called() + exporter._storage.store.assert_called_once() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep") - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.requests.Session") @patch.dict(os.environ, {}, clear=True) - def test_circuit_recovers_after_success(self, mock_session_cls, mock_sleep): - """After the circuit opens and recovery timeout elapses, a successful - probe should close the circuit.""" - mock_fail_resp = MagicMock() - mock_fail_resp.status_code = 503 - mock_fail_resp.text = "Service Unavailable" - mock_fail_resp.headers = {} - - mock_ok_resp = MagicMock() - mock_ok_resp.status_code = 200 - mock_ok_resp.text = "OK" - mock_ok_resp.headers = {} - - session_instance = MagicMock() - mock_session_cls.return_value = session_instance - - exporter = self._make_exporter() - exporter._session = session_instance - exporter._circuit_breaker._recovery_timeout = 30.0 - + def test_probe_admitted_after_block_window_elapses(self): + clock = FakeClock() + exporter = self._make_exporter(clock) + exporter._post_once = MagicMock(return_value=DeliveryResult(DeliveryDisposition.RETRYABLE, 30)) span = _make_span() - # Trip the circuit - session_instance.post.return_value = mock_fail_resp - for _ in range(DEFAULT_CB_FAILURE_THRESHOLD): - exporter.export([span]) - - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.OPEN) - - # Simulate recovery timeout elapsing by backdating _last_failure_time - exporter._circuit_breaker._last_failure_time = time.monotonic() - 31.0 - - # Next call should be a probe (half-open) — make it succeed - session_instance.post.return_value = mock_ok_resp - result = exporter.export([span]) - self.assertEqual(result, SpanExportResult.SUCCESS) - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.CLOSED) + exporter.export([span]) # block gate + clock.advance(30) + exporter._post_once.reset_mock() + exporter._post_once.return_value = DeliveryResult(DeliveryDisposition.DELIVERED) + exporter._storage.store.reset_mock() + self.assertIs(exporter.export([span]), SpanExportResult.SUCCESS) + exporter._post_once.assert_called_once() # probe sent + exporter._storage.store.assert_not_called() # delivered => no persist exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep") - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.requests.Session") @patch.dict(os.environ, {}, clear=True) - def test_circuit_reopens_on_failed_probe(self, mock_session_cls, mock_sleep): - """If the half-open probe fails, the circuit re-opens.""" - mock_fail_resp = MagicMock() - mock_fail_resp.status_code = 500 - mock_fail_resp.text = "Error" - mock_fail_resp.headers = {} - - session_instance = MagicMock() - session_instance.post.return_value = mock_fail_resp - mock_session_cls.return_value = session_instance - - exporter = self._make_exporter() - exporter._session = session_instance - exporter._circuit_breaker._recovery_timeout = 30.0 - - span = _make_span() - - # Trip the circuit - for _ in range(DEFAULT_CB_FAILURE_THRESHOLD): - exporter.export([span]) - - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.OPEN) - - # Simulate recovery timeout elapsing - exporter._circuit_breaker._last_failure_time = time.monotonic() - 31.0 - - # Probe should fail, re-opening the circuit - result = exporter.export([span]) - self.assertEqual(result, SpanExportResult.FAILURE) - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.OPEN) - - exporter.shutdown() - - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep") - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.requests.Session") - @patch.dict(os.environ, {}, clear=True) - def test_non_retryable_errors_do_not_trip_circuit(self, mock_session_cls, mock_sleep): - """Non-retryable 4xx errors (e.g. 401, 403) should not count toward - the circuit breaker threshold — they indicate config problems, not - transient endpoint failures.""" - mock_resp = MagicMock() - mock_resp.status_code = 403 - mock_resp.text = "Forbidden" - mock_resp.headers = {} - - session_instance = MagicMock() - session_instance.post.return_value = mock_resp - mock_session_cls.return_value = session_instance - - exporter = self._make_exporter() - exporter._session = session_instance - - span = _make_span() - - # Non-retryable errors should NOT trip the circuit breaker - for _ in range(DEFAULT_CB_FAILURE_THRESHOLD + 2): - exporter.export([span]) - - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.CLOSED) - exporter.shutdown() - - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep") - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.requests.Session") - @patch.dict(os.environ, {}, clear=True) - def test_network_errors_trip_circuit(self, mock_session_cls, mock_sleep): - """Network-level failures (RequestException) count toward the circuit breaker.""" - import requests as req - - session_instance = MagicMock() - session_instance.post.side_effect = req.ConnectionError("connection refused") - mock_session_cls.return_value = session_instance - - exporter = self._make_exporter() - exporter._session = session_instance - - span = _make_span() - - for _ in range(DEFAULT_CB_FAILURE_THRESHOLD): - exporter.export([span]) - - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.OPEN) - exporter.shutdown() - - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep") - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.requests.Session") - @patch.dict(os.environ, {}, clear=True) - def test_success_between_failures_resets_circuit(self, mock_session_cls, mock_sleep): - """A successful POST mid-stream should reset the failure counter.""" - mock_fail_resp = MagicMock() - mock_fail_resp.status_code = 500 - mock_fail_resp.text = "Error" - mock_fail_resp.headers = {} - - mock_ok_resp = MagicMock() - mock_ok_resp.status_code = 200 - mock_ok_resp.text = "OK" - mock_ok_resp.headers = {} - - session_instance = MagicMock() - mock_session_cls.return_value = session_instance - - exporter = self._make_exporter() - exporter._session = session_instance - - span = _make_span() - - # Fail 4 times (threshold is 5) - session_instance.post.return_value = mock_fail_resp - for _ in range(DEFAULT_CB_FAILURE_THRESHOLD - 1): - exporter.export([span]) - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.CLOSED) - - # Succeed once — resets counter - session_instance.post.return_value = mock_ok_resp - exporter.export([span]) - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.CLOSED) - - # Fail 4 more times — circuit should still be closed - session_instance.post.return_value = mock_fail_resp - for _ in range(DEFAULT_CB_FAILURE_THRESHOLD - 1): - exporter.export([span]) - self.assertEqual(exporter._circuit_breaker.state, _CircuitBreaker.CLOSED) - + def test_block_is_isolated_to_failing_identity(self): + clock = FakeClock() + exporter = self._make_exporter(clock) + exporter._post_once = MagicMock(return_value=DeliveryResult(DeliveryDisposition.RETRYABLE, 30)) + + exporter.export([_make_span(tenant_id="t1", agent_id="a1")]) # block a1 + + exporter._post_once.reset_mock() + exporter._post_once.return_value = DeliveryResult(DeliveryDisposition.DELIVERED) + self.assertIs( + exporter.export([_make_span(tenant_id="t2", agent_id="a2")]), + SpanExportResult.SUCCESS, + ) + exporter._post_once.assert_called_once() # a2 unaffected by a1's block exporter.shutdown() diff --git a/tests/a365/test_contextual_token_resolver.py b/tests/a365/test_contextual_token_resolver.py index 320c37af..46cbd421 100644 --- a/tests/a365/test_contextual_token_resolver.py +++ b/tests/a365/test_contextual_token_resolver.py @@ -11,6 +11,10 @@ from microsoft.opentelemetry.a365.core.exporters.agent365_exporter import ( _Agent365Exporter, ) +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, +) from microsoft.opentelemetry.a365.core.exporters.token_resolver_context import ( AgentIdentity, TokenResolverContext, @@ -132,12 +136,12 @@ def test_creates_with_both_resolvers(self): class TestContextualTokenResolverExport(unittest.TestCase): - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") + @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_once") @patch.dict(os.environ, {}, clear=True) def test_contextual_resolver_called_with_context(self, mock_post): - mock_post.return_value = True + mock_post.return_value = DeliveryResult(DeliveryDisposition.DELIVERED) resolver = MagicMock(return_value="ctx-token") - exporter = _Agent365Exporter(contextual_token_resolver=resolver) + exporter = _Agent365Exporter(contextual_token_resolver=resolver, enable_durable_delivery=False) span = _make_span(tenant_id="t1", agent_id="a1", agentic_user_id="user-42") exporter.export([span]) @@ -149,12 +153,12 @@ def test_contextual_resolver_called_with_context(self, mock_post): self.assertEqual(ctx.tenant_id, "t1") exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") + @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_once") @patch.dict(os.environ, {}, clear=True) def test_contextual_resolver_null_agentic_user_id(self, mock_post): - mock_post.return_value = True + mock_post.return_value = DeliveryResult(DeliveryDisposition.DELIVERED) resolver = MagicMock(return_value="ctx-token") - exporter = _Agent365Exporter(contextual_token_resolver=resolver) + exporter = _Agent365Exporter(contextual_token_resolver=resolver, enable_durable_delivery=False) span = _make_span(tenant_id="t1", agent_id="a1") # no agentic_user_id exporter.export([span]) @@ -162,15 +166,16 @@ def test_contextual_resolver_null_agentic_user_id(self, mock_post): self.assertIsNone(ctx.identity.agentic_user_id) exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") + @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_once") @patch.dict(os.environ, {}, clear=True) def test_contextual_resolver_takes_precedence_over_token_resolver(self, mock_post): - mock_post.return_value = True + mock_post.return_value = DeliveryResult(DeliveryDisposition.DELIVERED) token_resolver = MagicMock(return_value="old-token") contextual_resolver = MagicMock(return_value="new-token") exporter = _Agent365Exporter( token_resolver=token_resolver, contextual_token_resolver=contextual_resolver, + enable_durable_delivery=False, ) span = _make_span(tenant_id="t1", agent_id="a1") exporter.export([span]) @@ -180,38 +185,42 @@ def test_contextual_resolver_takes_precedence_over_token_resolver(self, mock_pos token_resolver.assert_not_called() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") + @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_once") @patch.dict(os.environ, {}, clear=True) def test_token_resolver_used_when_no_contextual(self, mock_post): - mock_post.return_value = True + mock_post.return_value = DeliveryResult(DeliveryDisposition.DELIVERED) token_resolver = MagicMock(return_value="old-token") - exporter = _Agent365Exporter(token_resolver=token_resolver) + exporter = _Agent365Exporter(token_resolver=token_resolver, enable_durable_delivery=False) span = _make_span(tenant_id="t1", agent_id="a1") exporter.export([span]) token_resolver.assert_called_once_with("a1", "t1") exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") + @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_once") @patch.dict(os.environ, {}, clear=True) def test_contextual_resolver_exception_marks_failure(self, mock_post): - mock_post.return_value = True + # Durable storage disabled => a token failure cannot be persisted, so + # the export surfaces failure and no send is attempted. resolver = MagicMock(side_effect=Exception("auth error")) - exporter = _Agent365Exporter(contextual_token_resolver=resolver) + exporter = _Agent365Exporter(contextual_token_resolver=resolver, enable_durable_delivery=False) span = _make_span(tenant_id="t1", agent_id="a1") result = exporter.export([span]) self.assertEqual(result, SpanExportResult.FAILURE) + mock_post.assert_not_called() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") + @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_once") @patch.dict(os.environ, {}, clear=True) - def test_contextual_resolver_returns_none_no_auth_header(self, mock_post): - mock_post.return_value = True + def test_contextual_resolver_returns_none_is_permanent_failure(self, mock_post): + # An empty token is a permanent condition: nothing is sent or stored and + # the export fails. resolver = MagicMock(return_value=None) - exporter = _Agent365Exporter(contextual_token_resolver=resolver) + exporter = _Agent365Exporter(contextual_token_resolver=resolver, enable_durable_delivery=False) span = _make_span(tenant_id="t1", agent_id="a1") result = exporter.export([span]) - self.assertEqual(result, SpanExportResult.SUCCESS) + self.assertEqual(result, SpanExportResult.FAILURE) + mock_post.assert_not_called() exporter.shutdown() diff --git a/tests/a365/test_durable_delivery.py b/tests/a365/test_durable_delivery.py new file mode 100644 index 00000000..dfc5d799 --- /dev/null +++ b/tests/a365/test_durable_delivery.py @@ -0,0 +1,295 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Tests for durable delivery dispositions and the transmission gate.""" + +from __future__ import annotations + +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, + TransmissionGate, +) + + +class FakeClock: + """Callable monotonic clock used by gate tests.""" + + def __init__(self, value: float = 0.0) -> None: + self.value = value + + def __call__(self) -> float: + return self.value + + def advance(self, seconds: float) -> None: + self.value += seconds + + +def test_delivery_result_defaults_to_retryable_without_backoff() -> None: + """DeliveryResult should model a retryable disposition with no delay.""" + result = DeliveryResult(DeliveryDisposition.RETRYABLE) + + assert result.disposition is DeliveryDisposition.RETRYABLE + assert result.retry_after is None + + +def test_gate_isolates_identities() -> None: + """A retryable failure should not block a different identity.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + first = IdentityKey("t1", "a1", None, False) + second = IdentityKey("t2", "a2", None, False) + + gate.record_retryable_failure(first, retry_after=30) + + assert not gate.try_acquire(first) + assert gate.try_acquire(second) + + +def test_healthy_acquire_does_not_create_gate_state() -> None: + """Healthy sends should remain allocation-free until a failure occurs.""" + gate = TransmissionGate(clock=FakeClock(), random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + assert gate.try_acquire(key) + assert gate.try_acquire(key) + assert key not in gate._states # type: ignore[attr-defined] + + +def test_gate_allows_only_one_half_open_probe() -> None: + """Only one probe may be in flight when a gate opens.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_retryable_failure(key, retry_after=10) + clock.advance(10) + + assert gate.try_acquire(key) + assert not gate.try_acquire(key) + + +def test_positive_retry_after_is_honored_without_flooring() -> None: + """Positive Retry-After values should keep their exact delay.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_retryable_failure(key, retry_after=1.5) + + assert not gate.try_acquire(key) + clock.advance(1.49) + assert not gate.try_acquire(key) + clock.advance(0.01) + assert gate.try_acquire(key) + + +def test_non_positive_retry_after_falls_back_to_jittered_backoff() -> None: + """Retry-After values at or below zero should use exponential-jitter backoff.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_retryable_failure(key, retry_after=None) + clock.advance(10) + assert gate.try_acquire(key) + + gate.record_retryable_failure(key, retry_after=0) + + assert not gate.try_acquire(key) + clock.advance(14.99) + assert not gate.try_acquire(key) + clock.advance(0.01) + assert gate.try_acquire(key) + + +def test_explicit_retry_after_is_clamped_to_cap() -> None: + """Retry-After values above one hour should be capped.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_retryable_failure(key, retry_after=7200) + + assert not gate.try_acquire(key) + clock.advance(3599.9) + assert not gate.try_acquire(key) + clock.advance(0.1) + assert gate.try_acquire(key) + + +def test_release_probe_allows_another_probe_to_be_acquired() -> None: + """Releasing an in-flight probe should let a fresh probe be acquired.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_retryable_failure(key, retry_after=10) + clock.advance(10) + + assert gate.try_acquire(key) + # Only one probe may be in flight, so a second acquire is refused. + assert not gate.try_acquire(key) + + gate.release_probe(key) + + # After releasing the probe (without changing the retry window) another + # probe may be acquired. + assert gate.try_acquire(key) + + +def test_release_probe_is_noop_for_unknown_identity() -> None: + """Releasing a probe for an unseen identity must not create state or raise.""" + gate = TransmissionGate(clock=FakeClock(), random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.release_probe(key) + + # The identity has never failed, so a probe should still be acquirable. + assert gate.try_acquire(key) + + +def test_release_probe_preserves_retry_window() -> None: + """release_probe must not shorten the active backoff window.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_retryable_failure(key, retry_after=30) + gate.release_probe(key) + + # Still blocked because the window has not elapsed. + assert not gate.try_acquire(key) + clock.advance(30) + assert gate.try_acquire(key) + + +def test_record_success_resets_backoff_immediately() -> None: + """A success should clear the block so the identity can send at once.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_retryable_failure(key, retry_after=3600) + assert not gate.try_acquire(key) + + gate.record_success(key) + + # State is fully reset, so a send may proceed without waiting the window. + assert gate.try_acquire(key) + + +def test_record_success_resets_failure_count() -> None: + """After success, the next failure uses the base backoff, not escalated.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 1.0) + key = IdentityKey("t1", "a1", None, False) + + # Escalate the failure count several times. + for _ in range(4): + gate.record_retryable_failure(key, retry_after=None) + + gate.record_success(key) + + # A fresh failure after success blocks only for the base floor window, + # proving failure_count was reset to zero. + gate.record_retryable_failure(key, retry_after=None) + clock.advance(9.999) + assert not gate.try_acquire(key) + clock.advance(0.001) + assert gate.try_acquire(key) + + +def test_record_success_for_unknown_identity_is_noop() -> None: + """Recording success for an unseen identity must not raise or block.""" + gate = TransmissionGate(clock=FakeClock(), random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + gate.record_success(key) + + assert gate.try_acquire(key) + + +# --------------------------------------------------------------------------- +# Regression tests: backoff overflow at high failure counts (exponent ≥ 1024) +# --------------------------------------------------------------------------- + + +def _drive_failure_count(gate: TransmissionGate, key: IdentityKey, n: int) -> None: + """Record *n* consecutive retryable failures without a retry_after hint.""" + for _ in range(n): + gate.record_retryable_failure(key, retry_after=None) + + +def test_record_retryable_failure_never_raises_beyond_exponent_1024() -> None: + """Calling record_retryable_failure 1025+ times must never raise OverflowError. + + Previously ``2.0 ** failure_count`` would overflow once failure_count + reached ~1024, producing an OverflowError (Python floats map to C doubles). + The fix must clamp the exponent so the calculation stays finite. + """ + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 1.0) + key = IdentityKey("t1", "a1", None, False) + + # Drive failure_count well past the problematic threshold and verify no + # exception is raised and no busy-loop / infinite delay results. + _drive_failure_count(gate, key, 1025) + + +def test_backoff_stays_capped_at_3600_seconds_beyond_exponent_1024() -> None: + """Delay must never exceed 3600 s regardless of failure count.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 1.0) + key = IdentityKey("t1", "a1", None, False) + + _drive_failure_count(gate, key, 1025) + + # Check that the gate opens exactly at 3600 s (worst-case random fraction = 1.0). + clock.advance(3599.9) + assert not gate.try_acquire(key) + clock.advance(0.1) + assert gate.try_acquire(key) + + +def test_half_open_behavior_preserved_after_high_failure_count() -> None: + """Only one probe is allowed in the half-open window after >1024 failures.""" + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 1.0) + key = IdentityKey("t1", "a1", None, False) + + _drive_failure_count(gate, key, 2000) + + # Advance past the cap window. + clock.advance(3600.0) + + # Exactly one probe must be allowed (half-open), then the gate must hold. + assert gate.try_acquire(key), "first probe should be granted" + assert not gate.try_acquire(key), "second probe must be refused while first is in flight" + + +def test_failure_count_does_not_grow_unbounded() -> None: + """failure_count must be saturated at a finite value; it must not grow to + an arbitrary integer that would cause overflow on subsequent calls.""" + from microsoft.opentelemetry.a365.core.exporters.durable_delivery import _GateState # noqa: PLC0415 + + clock = FakeClock() + gate = TransmissionGate(clock=clock, random_fn=lambda: 0.5) + key = IdentityKey("t1", "a1", None, False) + + _drive_failure_count(gate, key, 5000) + + state: _GateState = gate._states[key] # type: ignore[attr-defined] + # The clamped value must be at most the threshold that makes backoff hit cap. + # Derived from: floor * 2^n >= cap => n = ceil(log2(cap / floor)) = 9 + import math # noqa: PLC0415 + from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( # noqa: PLC0415 + _RETRY_AFTER_CAP_SECONDS, + _RETRY_AFTER_FLOOR_SECONDS, + ) + + max_useful_exponent = math.ceil(math.log2(_RETRY_AFTER_CAP_SECONDS / _RETRY_AFTER_FLOOR_SECONDS)) + assert ( + state.failure_count <= max_useful_exponent + ), f"failure_count={state.failure_count} exceeds max useful exponent {max_useful_exponent}" diff --git a/tests/a365/test_durable_restart.py b/tests/a365/test_durable_restart.py new file mode 100644 index 00000000..47405606 --- /dev/null +++ b/tests/a365/test_durable_restart.py @@ -0,0 +1,263 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Restart / durability tests. + +Verify that a payload persisted by one exporter instance is replayed and +delivered by a *new* exporter instance pointed at the same storage directory, +rebuilding authentication with a freshly resolved token. This is the crash / +process-restart scenario the durable queue exists for. +""" + +from __future__ import annotations + +import threading +import time +from unittest.mock import MagicMock + +from opentelemetry.sdk.trace.export import SpanExportResult +from opentelemetry.trace import SpanKind, StatusCode + +from microsoft.opentelemetry.a365.core.exporters.agent365_exporter import ( + _Agent365Exporter, +) +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, +) +from microsoft.opentelemetry.a365.core.exporters.persistent_storage import DurableRecord + + +def _make_span( + tenant_id="t1", + agent_id="a1", + agentic_user_id=None, + name="test_span", + trace_id=0x1234, + span_id=0x5678, + operation_name="invoke_agent", +): + span = MagicMock() + span.name = name + attrs = { + "microsoft.tenant.id": tenant_id, + "gen_ai.agent.id": agent_id, + } + if operation_name is not None: + attrs["gen_ai.operation.name"] = operation_name + if agentic_user_id is not None: + attrs["microsoft.agent.user.id"] = agentic_user_id + span.attributes = attrs + + ctx = MagicMock() + ctx.trace_id = trace_id + ctx.span_id = span_id + span.context = ctx + span.get_span_context.return_value = ctx + + span.parent = None + span.kind = SpanKind.INTERNAL + span.start_time = 1000000000 + span.end_time = 2000000000 + + status = MagicMock() + status.status_code = StatusCode.OK + status.description = "" + span.status = status + + span.events = [] + span.links = [] + + scope = MagicMock() + scope.name = "test_scope" + scope.version = "1.0" + span.instrumentation_scope = scope + + resource = MagicMock() + resource.attributes = {"service.name": "test-service"} + span.resource = resource + + return span + + +def _queue_size(storage) -> int: + """Count claimable records without leaving them leased.""" + claimed = storage.claim(limit=1000, lease_seconds=0.0) + for record in claimed: + storage.release(record.record_id) + return len(claimed) + + +def test_restart_replays_persisted_record_with_fresh_token(tmp_path): + storage_dir = tmp_path / "queue" + + # --- Instance A: a retryable send persists the payload, then shuts down. --- + exporter_a = _Agent365Exporter( + token_resolver=lambda a, t: "stale-token", + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + exporter_a._post_once = MagicMock(return_value=DeliveryResult(DeliveryDisposition.RETRYABLE, 30)) + + assert exporter_a.export([_make_span(agentic_user_id="user-9")]) is SpanExportResult.SUCCESS + assert _queue_size(exporter_a._storage) == 1 + exporter_a.shutdown() + + # --- Instance B: fresh process, same directory, fresh token. --- + captured = {} + + def fresh_resolver(agent_id, tenant_id): + return "fresh-token" + + exporter_b = _Agent365Exporter( + token_resolver=fresh_resolver, + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + # Bring up storage + replay coordinator without starting the background + # thread, so replay can be driven deterministically from the test. + exporter_b._ensure_durable_initialized() + + def fake_post_once(url, body, headers): + captured["authorization"] = headers.get("authorization") + return DeliveryResult(DeliveryDisposition.DELIVERED) + + exporter_b._post_once = fake_post_once + + # The leftover record is claimed, re-authenticated, delivered, and removed. + exporter_b._replay.run_once() + + assert _queue_size(exporter_b._storage) == 0 + assert captured["authorization"] == "Bearer fresh-token" + exporter_b.shutdown() + + +def test_restart_replays_using_current_exporter_endpoint_settings(tmp_path): + storage_dir = tmp_path / "queue" + + exporter_a = _Agent365Exporter( + token_resolver=lambda a, t: "stale-token", + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + exporter_a._domain_override = "https://stale.example.test" + exporter_a._post_once = MagicMock(return_value=DeliveryResult(DeliveryDisposition.RETRYABLE, 30)) + + assert exporter_a.export([_make_span()]) is SpanExportResult.SUCCESS + assert _queue_size(exporter_a._storage) == 1 + exporter_a.shutdown() + + captured = {} + exporter_b = _Agent365Exporter( + token_resolver=lambda a, t: "fresh-token", + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + exporter_b._domain_override = "https://current.example.test" + exporter_b._ensure_durable_initialized() + + def fake_post_once(url, body, headers): + del body, headers + captured["url"] = url + return DeliveryResult(DeliveryDisposition.DELIVERED) + + exporter_b._post_once = fake_post_once + + exporter_b._replay.run_once() + + assert _queue_size(exporter_b._storage) == 0 + assert captured["url"] == ( + "https://current.example.test/observability/tenants/t1/otlp/agents/a1/traces" "?api-version=1" + ) + exporter_b.shutdown() + + +def test_restart_replays_record_persisted_after_token_failure(tmp_path): + storage_dir = tmp_path / "queue" + + # --- Instance A: token resolution fails, so the payload is persisted. --- + exporter_a = _Agent365Exporter( + token_resolver=MagicMock(side_effect=RuntimeError("credential outage")), + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + # No send should happen when the token cannot be resolved. + exporter_a._post_once = MagicMock() + + assert exporter_a.export([_make_span()]) is SpanExportResult.SUCCESS + exporter_a._post_once.assert_not_called() + assert _queue_size(exporter_a._storage) == 1 + exporter_a.shutdown() + + # --- Instance B: credentials recovered; replay drains the queue. --- + exporter_b = _Agent365Exporter( + token_resolver=lambda a, t: "recovered-token", + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + exporter_b._ensure_durable_initialized() + exporter_b._post_once = MagicMock(return_value=DeliveryResult(DeliveryDisposition.DELIVERED)) + + exporter_b._replay.run_once() + + assert _queue_size(exporter_b._storage) == 0 + exporter_b._post_once.assert_called_once() + exporter_b.shutdown() + + +def test_shutdown_blocks_until_active_replay_send_completes_then_removes_record(tmp_path): + """Regression for exporter/replay shutdown ownership: exporter.shutdown() + must not close storage/session while a replay send is in flight. If it + did, the delete() that follows the DELIVERED result below would silently + fail against a closed connection, leaving the record duplicated/orphaned + for the next restart instead of cleanly removed. + """ + storage_dir = tmp_path / "queue" + + exporter_a = _Agent365Exporter( + token_resolver=lambda a, t: "token", + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + exporter_a._ensure_durable_initialized() + identity = IdentityKey(tenant_id="t1", agent_id="a1", agentic_user_id=None, use_s2s_endpoint=False) + assert exporter_a._storage.store(DurableRecord.new(identity, '{"resourceSpans":[]}')) + assert _queue_size(exporter_a._storage) == 1 + + release_send = threading.Event() + entered_send = threading.Event() + + def blocking_send(record): + del record + entered_send.set() + release_send.wait() + return DeliveryResult(DeliveryDisposition.DELIVERED) + + # Patch the coordinator's own _send (read fresh per run_once() call, not + # yet captured by the not-yet-started thread) before starting it, so the + # very first pass -- with a fresh, never-throttled gate -- blocks here. + exporter_a._replay._send = blocking_send + exporter_a._replay.start() + assert entered_send.wait(5.0), "replay never reached the blocking send" + + shutdown_thread = threading.Thread(target=exporter_a.shutdown) + shutdown_thread.start() + try: + time.sleep(0.2) + assert shutdown_thread.is_alive(), "shutdown() must wait for the active replay send" + finally: + release_send.set() + shutdown_thread.join(5.0) + assert not shutdown_thread.is_alive() + + # Restart against the same directory: the record must be delivered and + # removed, not stuck leased or resurrected by a corrupted queue. + exporter_b = _Agent365Exporter( + token_resolver=lambda a, t: "fresh-token", + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + exporter_b._ensure_durable_initialized() + assert _queue_size(exporter_b._storage) == 0 + exporter_b.shutdown() diff --git a/tests/a365/test_enriching_span_processor.py b/tests/a365/test_enriching_span_processor.py index b6827e6b..14855afa 100644 --- a/tests/a365/test_enriching_span_processor.py +++ b/tests/a365/test_enriching_span_processor.py @@ -1,18 +1,107 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. +import logging +import multiprocessing +import os +import threading +import time import unittest -from unittest.mock import MagicMock, patch - +from typing import List, Set +from unittest import mock +from unittest.mock import MagicMock + +from opentelemetry.sdk.environment_variables import ( + OTEL_BSP_EXPORT_TIMEOUT, + OTEL_BSP_MAX_EXPORT_BATCH_SIZE, + OTEL_BSP_MAX_QUEUE_SIZE, + OTEL_BSP_SCHEDULE_DELAY, +) from opentelemetry.sdk.trace import ReadableSpan +from opentelemetry.sdk.trace.export import SpanExportResult from microsoft.opentelemetry.a365.core.exporters.enriching_span_processor import ( _EnrichingBatchSpanProcessor, get_span_enricher, + logger as _processor_logger, register_span_enricher, unregister_span_enricher, ) +# Real (not simulated) fork-safety coverage needs the multiprocessing "fork" +# start method, which only exists on POSIX. Resolve this once, defensively, +# so a start method already configured by another plugin/module never turns +# into an import-time crash -- it just disables the POSIX-only tests below. +_FORK_AVAILABLE = hasattr(os, "fork") +if _FORK_AVAILABLE: + try: + if multiprocessing.get_start_method(allow_none=True) is None: + multiprocessing.set_start_method("fork") + _FORK_AVAILABLE = multiprocessing.get_start_method(allow_none=True) == "fork" + except RuntimeError: + _FORK_AVAILABLE = False + + +def _make_span(name: str = "test-span", attributes=None) -> ReadableSpan: + """Build a MagicMock standing in for a sampled, already-ended ReadableSpan.""" + span = MagicMock(spec=ReadableSpan) + span.name = name + span.attributes = {} if attributes is None else attributes + span.context = MagicMock() + span.context.trace_flags.sampled = True + return span + + +class _RecordingExporter: + """Thread-safe fake SpanExporter. + + Records every exported span and every ``shutdown()`` call, and can be + told to block inside ``export()`` until released. Also keeps an ordered + event log so lifecycle tests can assert *happens-before* relationships + (e.g. "export finished before exporter.shutdown() ran") using + synchronization primitives instead of sleeps. + """ + + def __init__(self) -> None: + self._lock = threading.Lock() + self.exported: List[ReadableSpan] = [] + self.export_calls = 0 + self.shutdown_calls = 0 + self.events: List[str] = [] + self.shutdown_thread_name: str = "" + self._release_gate = threading.Event() + self._release_gate.set() # not blocking by default + self.export_started = threading.Event() + self.shutdown_called_event = threading.Event() + + def block(self) -> None: + """Cause export() calls to block until release() is called.""" + self._release_gate.clear() + + def release(self) -> None: + self._release_gate.set() + + def export(self, spans): + self.export_started.set() + with self._lock: + self.events.append("export_start") + self._release_gate.wait(timeout=5) + with self._lock: + self.exported.extend(spans) + self.export_calls += 1 + self.events.append("export_end") + return SpanExportResult.SUCCESS + + def shutdown(self): + with self._lock: + self.shutdown_calls += 1 + self.shutdown_thread_name = threading.current_thread().name + self.events.append("shutdown_called") + self.shutdown_called_event.set() + + def force_flush(self, timeout_millis: int = 30000) -> bool: + return True + class TestSpanEnricherRegistration(unittest.TestCase): def setUp(self): @@ -54,85 +143,835 @@ def test_unregister_when_none(self): unregister_span_enricher() # should not raise -class TestEnrichingBatchSpanProcessor(unittest.TestCase): +class TestEnrichingBatchSpanProcessorEnrichment(unittest.TestCase): + """Behavioral (non-white-box) coverage of enrichment/suppression. + + The processor no longer inherits BatchSpanProcessor, so these tests + exercise the real on_end -> force_flush -> exporter path instead of + patching a base-class on_end. + """ + def setUp(self): unregister_span_enricher() def tearDown(self): unregister_span_enricher() - @patch.object(_EnrichingBatchSpanProcessor, "__init__", lambda self, *a, **kw: None) + @staticmethod + def _make_processor(exporter, **kwargs): + return _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=10, + schedule_delay_millis=5, + max_export_batch_size=10, + **kwargs, + ) + def test_on_end_calls_enricher(self): - enriched = MagicMock(spec=ReadableSpan) - enriched.name = "test" - enriched.attributes = {} + enriched = _make_span(name="enriched") def my_enricher(span): return enriched register_span_enricher(my_enricher) - processor = _EnrichingBatchSpanProcessor.__new__(_EnrichingBatchSpanProcessor) - processor._suppress_invoke_agent_input = False + exporter = _RecordingExporter() + processor = self._make_processor(exporter) + try: + processor.on_end(_make_span(name="original")) + self.assertTrue(processor.force_flush(timeout_millis=5000)) + finally: + processor.shutdown() - original_span = MagicMock(spec=ReadableSpan) - original_span.name = "original" - original_span.attributes = {} - - with patch.object(_EnrichingBatchSpanProcessor.__bases__[0], "on_end") as mock_super_on_end: - processor.on_end(original_span) - mock_super_on_end.assert_called_once_with(enriched) + self.assertEqual(len(exporter.exported), 1) + self.assertIs(exporter.exported[0], enriched) - @patch.object(_EnrichingBatchSpanProcessor, "__init__", lambda self, *a, **kw: None) def test_on_end_falls_back_on_enricher_error(self): def bad_enricher(span): raise ValueError("enricher error") register_span_enricher(bad_enricher) - processor = _EnrichingBatchSpanProcessor.__new__(_EnrichingBatchSpanProcessor) - processor._suppress_invoke_agent_input = False - - original_span = MagicMock(spec=ReadableSpan) - original_span.name = "original" - original_span.attributes = {} - - with patch.object(_EnrichingBatchSpanProcessor.__bases__[0], "on_end") as mock_super_on_end: + exporter = _RecordingExporter() + processor = self._make_processor(exporter) + original_span = _make_span(name="original") + try: processor.on_end(original_span) - mock_super_on_end.assert_called_once_with(original_span) + self.assertTrue(processor.force_flush(timeout_millis=5000)) + finally: + processor.shutdown() + + self.assertEqual(len(exporter.exported), 1) + self.assertIs(exporter.exported[0], original_span) - @patch.object(_EnrichingBatchSpanProcessor, "__init__", lambda self, *a, **kw: None) def test_suppress_invoke_agent_input(self): - processor = _EnrichingBatchSpanProcessor.__new__(_EnrichingBatchSpanProcessor) - processor._suppress_invoke_agent_input = True + exporter = _RecordingExporter() + processor = self._make_processor(exporter, suppress_invoke_agent_input=True) + span = _make_span( + name="invoke_agent Travel_Assistant", + attributes={ + "gen_ai.operation.name": "invoke_agent", + "gen_ai.input.messages": "[{...}]", + }, + ) + try: + processor.on_end(span) + self.assertTrue(processor.force_flush(timeout_millis=5000)) + finally: + processor.shutdown() - span = MagicMock(spec=ReadableSpan) - span.name = "invoke_agent Travel_Assistant" - span.attributes = { - "gen_ai.operation.name": "invoke_agent", - "gen_ai.input.messages": "[{...}]", - } + self.assertEqual(len(exporter.exported), 1) + self.assertNotIn("gen_ai.input.messages", dict(exporter.exported[0].attributes)) - with patch.object(_EnrichingBatchSpanProcessor.__bases__[0], "on_end") as mock_super_on_end: + def test_no_suppress_for_non_invoke_agent(self): + exporter = _RecordingExporter() + processor = self._make_processor(exporter, suppress_invoke_agent_input=True) + span = _make_span( + name="chat gpt-4", + attributes={ + "gen_ai.operation.name": "chat", + "gen_ai.input.messages": "[{...}]", + }, + ) + try: processor.on_end(span) - passed_span = mock_super_on_end.call_args[0][0] - self.assertNotIn("gen_ai.input.messages", dict(passed_span.attributes)) + self.assertTrue(processor.force_flush(timeout_millis=5000)) + finally: + processor.shutdown() - @patch.object(_EnrichingBatchSpanProcessor, "__init__", lambda self, *a, **kw: None) - def test_no_suppress_for_non_invoke_agent(self): - processor = _EnrichingBatchSpanProcessor.__new__(_EnrichingBatchSpanProcessor) - processor._suppress_invoke_agent_input = True + self.assertEqual(len(exporter.exported), 1) + self.assertIs(exporter.exported[0], span) + + +class TestEnrichingBatchSpanProcessorCapacity(unittest.TestCase): + """Atomic enqueue/capacity under a producer race (Task 5, Step 1).""" - span = MagicMock(spec=ReadableSpan) - span.name = "chat gpt-4" - span.attributes = { - "gen_ai.operation.name": "chat", - "gen_ai.input.messages": "[{...}]", - } + def setUp(self): + unregister_span_enricher() + + def tearDown(self): + unregister_span_enricher() + + def test_on_end_capacity_race_never_silently_evicts(self): + """More producer threads than queue capacity race on_end via a barrier. + + Every accepted span must eventually be exported exactly once and + every rejected span must be explicitly counted -- none may vanish + silently (e.g. via deque-maxlen eviction of an already-accepted + span). + + Reaching max_export_batch_size (== max_queue_size here) may + legitimately wake the worker mid-race (Task 5 hardening finding #1): + it can pop exactly one batch and then block inside the still-blocked + exporter, reopening capacity for a bounded number of additional + acceptances. So the accepted count is asserted as a deterministic + range instead of a single fixed value -- the pre-fix version of this + test assumed the worker could never wake here, which the threshold + wake now correctly contradicts. + """ + exporter = _RecordingExporter() + exporter.block() # the exporter stays blocked: at most one pop-and-block cycle can occur + max_queue_size = 4 + num_threads = 12 + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=max_queue_size, + # Long enough that the worker only ever wakes via the + # max_export_batch_size threshold below, never via this timer. + schedule_delay_millis=60_000, + max_export_batch_size=max_queue_size, + ) + try: + barrier = threading.Barrier(num_threads) + spans = [_make_span(name=f"span-{i}") for i in range(num_threads)] + + def submit(span): + barrier.wait(timeout=5) + processor.on_end(span) + + threads = [threading.Thread(target=submit, args=(spans[i],)) for i in range(num_threads)] + for t in threads: + t.start() + for t in threads: + t.join(timeout=5) + self.assertFalse(t.is_alive()) + + # Conservation: every span was either accepted or explicitly + # counted as dropped -- none vanished silently. + self.assertEqual(processor._enqueued_total + processor._dropped_count, num_threads) + + # The exporter is still blocked, so at most one threshold-wake + # batch (<= max_export_batch_size) could have been popped and + # gone in-flight, reopening capacity exactly once. This bounds + # the accepted count without depending on exact scheduling. + self.assertGreaterEqual(processor._enqueued_total, max_queue_size) + self.assertLessEqual(processor._enqueued_total, max_queue_size + processor._max_export_batch_size) + + exporter.release() + finally: + processor.shutdown() + + # Every accepted span -- whether it was still queued or already + # popped into the in-flight batch at the moment of the assertions + # above -- was exported exactly once by the time shutdown() finishes + # draining. This is the core "no silent eviction" guarantee. + self.assertEqual(len(exporter.exported), processor._enqueued_total) + self.assertEqual(len(exporter.exported) + processor._dropped_count, num_threads) + exported_ids: Set[int] = {id(span) for span in exporter.exported} + self.assertEqual(len(exported_ids), len(exporter.exported), "a span was exported more than once") + submitted_ids = {id(span) for span in spans} + self.assertTrue(exported_ids.issubset(submitted_ids)) + + def test_on_end_rejects_explicitly_once_queue_is_at_capacity(self): + """Deterministic (single-threaded) companion to the race test above: + proves a full queue causes an explicit rejection of the new span + rather than silently evicting an already-accepted one. + + Bypasses on_end()/_enqueue() for the setup phase, appending directly + to processor._queue under processor._condition without ever calling + notify_all(): the worker is never signalled, so (with a schedule + delay far longer than this test's runtime) it is guaranteed to + remain parked in its own wait() throughout, and cannot interfere. + """ + exporter = _RecordingExporter() + max_queue_size = 4 + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=max_queue_size, + schedule_delay_millis=60_000, + max_export_batch_size=max_queue_size, + ) + try: + accepted_spans = [_make_span(name=f"pre-{i}") for i in range(max_queue_size)] + with processor._condition: + processor._queue.extend(accepted_spans) + processor._enqueued_total = len(accepted_spans) + + overflow_span = _make_span(name="overflow") + accepted = processor._enqueue(overflow_span) + + self.assertFalse(accepted) + self.assertEqual(processor._dropped_count, 1) + self.assertEqual(list(processor._queue), accepted_spans) + self.assertNotIn(overflow_span, processor._queue) + finally: + processor.shutdown() + + self.assertEqual(len(exporter.exported), max_queue_size) + self.assertEqual({id(s) for s in exporter.exported}, {id(s) for s in accepted_spans}) + + +class TestEnrichingBatchSpanProcessorLifecycle(unittest.TestCase): + """Deterministic lifecycle ordering tests (Task 5, Step 2).""" + + def setUp(self): + unregister_span_enricher() + + def tearDown(self): + unregister_span_enricher() - with patch.object(_EnrichingBatchSpanProcessor.__bases__[0], "on_end") as mock_super_on_end: + def test_shutdown_drains_every_accepted_span(self): + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=100, + schedule_delay_millis=60_000, + max_export_batch_size=5, + ) + spans = [_make_span(name=f"span-{i}") for i in range(37)] + for span in spans: processor.on_end(span) - mock_super_on_end.assert_called_once_with(span) + + processor.shutdown() + + self.assertEqual(len(exporter.exported), len(spans)) + self.assertEqual({id(s) for s in exporter.exported}, {id(s) for s in spans}) + self.assertEqual(exporter.shutdown_calls, 1) + self.assertEqual(processor._dropped_count, 0) + + def test_shutdown_waits_for_active_export_before_exporter_shutdown(self): + exporter = _RecordingExporter() + exporter.block() # hold the export open so we can observe it in flight + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=10, + schedule_delay_millis=60_000, + max_export_batch_size=10, + ) + processor.on_end(_make_span()) + + shutdown_thread = threading.Thread(target=processor.shutdown) + shutdown_thread.start() + + # Deterministically wait for export to actually begin -- no sleeps. + self.assertTrue(exporter.export_started.wait(timeout=5)) + # The export is still blocked: exporter.shutdown must not have run. + self.assertEqual(exporter.shutdown_calls, 0) + + exporter.release() + shutdown_thread.join(timeout=5) + self.assertFalse(shutdown_thread.is_alive()) + + self.assertEqual(exporter.shutdown_calls, 1) + self.assertEqual(exporter.events, ["export_start", "export_end", "shutdown_called"]) + self.assertEqual(exporter.shutdown_thread_name, processor._worker_thread.name) + + def test_shutdown_timeout_leaves_worker_owning_cleanup(self): + exporter = _RecordingExporter() + exporter.block() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=10, + schedule_delay_millis=60_000, + max_export_batch_size=10, + ) + processor.on_end(_make_span()) + + # shutdown() must give up after its own short timeout while export is + # still blocked, without ever touching the exporter itself. + start = time.monotonic() + processor.shutdown(timeout_millis=50) + elapsed = time.monotonic() - start + self.assertLess(elapsed, 5) + self.assertEqual(exporter.shutdown_calls, 0) + + # The worker still owns cleanup: once export unblocks, it alone + # finishes the drain and performs the single exporter.shutdown() call. + exporter.release() + self.assertTrue(exporter.shutdown_called_event.wait(timeout=5)) + self.assertEqual(exporter.shutdown_calls, 1) + self.assertEqual(exporter.shutdown_thread_name, processor._worker_thread.name) + + def test_concurrent_shutdown_calls_exporter_shutdown_once(self): + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=10, + schedule_delay_millis=60_000, + max_export_batch_size=10, + ) + num_threads = 8 + barrier = threading.Barrier(num_threads) + + def call_shutdown(): + barrier.wait(timeout=5) + processor.shutdown() + + threads = [threading.Thread(target=call_shutdown) for _ in range(num_threads)] + for t in threads: + t.start() + for t in threads: + t.join(timeout=5) + self.assertFalse(t.is_alive()) + + self.assertEqual(exporter.shutdown_calls, 1) + self.assertEqual(exporter.shutdown_thread_name, processor._worker_thread.name) + + def test_on_end_racing_shutdown_never_strands_or_throws(self): + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=200, + schedule_delay_millis=5, + max_export_batch_size=8, + ) + num_producers = 8 + spans_per_producer = 25 + total_submitted = num_producers * spans_per_producer + errors: List[BaseException] = [] + errors_lock = threading.Lock() + start_barrier = threading.Barrier(num_producers + 1) + + def produce(index): + start_barrier.wait(timeout=5) + try: + for i in range(spans_per_producer): + processor.on_end(_make_span(name=f"p{index}-{i}")) + except BaseException as exc: # pragma: no cover - failure path + with errors_lock: + errors.append(exc) + + producers = [threading.Thread(target=produce, args=(i,)) for i in range(num_producers)] + for t in producers: + t.start() + + start_barrier.wait(timeout=5) # release producers and shutdown together + processor.shutdown() # races with the in-flight on_end calls above + + for t in producers: + t.join(timeout=5) + self.assertFalse(t.is_alive()) + + self.assertEqual(errors, []) + # Nothing is stranded: every span is either exported or explicitly + # dropped -- the totals reconcile exactly. + self.assertEqual(len(exporter.exported) + processor._dropped_count, total_submitted) + self.assertEqual(len(processor._queue), 0) + self.assertEqual(processor._active_exports, 0) + + +class TestEnrichingBatchSpanProcessorThresholdWake(unittest.TestCase): + """Task 5 hardening finding #1: wake the worker at max_export_batch_size.""" + + def setUp(self): + unregister_span_enricher() + + def tearDown(self): + unregister_span_enricher() + + def test_batch_threshold_wakes_worker_before_schedule_delay(self): + """Reaching max_export_batch_size must drain well before the long + schedule_delay elapses (mirrors upstream's + ``test_telemetry_exported_once_batch_size_reached``).""" + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=15, + max_export_batch_size=15, + # Not reached during the test -- a spontaneous drain could only + # happen here via the threshold wake under test. + schedule_delay_millis=30_000, + ) + try: + before = time.monotonic() + for i in range(15): + processor.on_end(_make_span(name=f"span-{i}")) + + deadline = time.monotonic() + 2 + while exporter.export_calls == 0 and time.monotonic() < deadline: + time.sleep(0.01) + elapsed = time.monotonic() - before + + self.assertEqual(exporter.export_calls, 1) + self.assertEqual(len(exporter.exported), 15) + self.assertLess( + elapsed, + 2, + "worker did not drain until close to the schedule delay -- threshold wake not firing", + ) + finally: + processor.shutdown() + + def test_long_delay_burst_never_drops_when_worker_wakes_each_batch(self): + """A sustained burst far larger than max_queue_size must complete + with zero drops when schedule_delay is a full day: only possible if + on_end()/_enqueue() wakes the worker every time the queue reaches + max_export_batch_size. Without that wake, the queue fills once and + stays full (the worker only drains on the schedule-delay timer, + force_flush, or shutdown), so every span submitted afterward would + be silently rejected (avoidable drop) -- or the test would have to + block for the full schedule delay to ever observe a drain + (avoidable stall).""" + exporter = _RecordingExporter() + batch_size = 5 + processor = _EnrichingBatchSpanProcessor( + exporter, + # Equal to batch size: capacity only ever holds one batch, so if + # the worker doesn't proactively drain between bursts, the next + # burst is guaranteed to be rejected outright. + max_queue_size=batch_size, + max_export_batch_size=batch_size, + # A full day: passing proves it is entirely because of the + # threshold wake, never because of this timer. + schedule_delay_millis=24 * 60 * 60 * 1000, + ) + num_batches = 6 + total_spans = batch_size * num_batches + try: + for batch_index in range(num_batches): + for i in range(batch_size): + processor.on_end(_make_span(name=f"b{batch_index}-{i}")) + + # Deterministically wait for *this* batch to drain before + # submitting the next -- bounds the proof to two seconds + # per batch instead of the 24-hour schedule delay. + deadline = time.monotonic() + 2 + while exporter.export_calls <= batch_index and time.monotonic() < deadline: + time.sleep(0.005) + self.assertEqual( + exporter.export_calls, + batch_index + 1, + f"batch {batch_index} was not drained within 2s -- worker stalled instead of waking", + ) + finally: + processor.shutdown() + + self.assertEqual(processor._dropped_count, 0) + self.assertEqual(len(exporter.exported), total_spans) + + +class TestEnrichingBatchSpanProcessorEnvDefaults(unittest.TestCase): + """Task 5 hardening finding #3: OTEL_BSP_* env vars seed the defaults + when constructor args are None, exactly like upstream BatchSpanProcessor + (including invalid-value fallback behavior).""" + + def setUp(self): + unregister_span_enricher() + + def tearDown(self): + unregister_span_enricher() + + @staticmethod + def _without_bsp_env_vars(): + return {k: v for k, v in os.environ.items() if not k.startswith("OTEL_BSP_")} + + @mock.patch.dict( + os.environ, + { + OTEL_BSP_MAX_QUEUE_SIZE: "10", + OTEL_BSP_SCHEDULE_DELAY: "2000", + OTEL_BSP_MAX_EXPORT_BATCH_SIZE: "3", + OTEL_BSP_EXPORT_TIMEOUT: "4000", + }, + ) + def test_env_vars_used_when_args_omitted(self): + processor = _EnrichingBatchSpanProcessor(_RecordingExporter()) + try: + self.assertEqual(processor._max_queue_size, 10) + self.assertEqual(processor._schedule_delay_seconds, 2.0) + self.assertEqual(processor._max_export_batch_size, 3) + self.assertEqual(processor._export_timeout_millis, 4000) + finally: + processor.shutdown() + + def test_defaults_used_when_no_env_vars_and_no_args(self): + with mock.patch.dict(os.environ, self._without_bsp_env_vars(), clear=True): + processor = _EnrichingBatchSpanProcessor(_RecordingExporter()) + try: + self.assertEqual(processor._max_queue_size, 2048) + self.assertEqual(processor._schedule_delay_seconds, 5.0) + self.assertEqual(processor._max_export_batch_size, 512) + self.assertEqual(processor._export_timeout_millis, 30000) + finally: + processor.shutdown() + + @mock.patch.dict( + os.environ, + { + OTEL_BSP_MAX_QUEUE_SIZE: "a", + OTEL_BSP_SCHEDULE_DELAY: " ", + OTEL_BSP_MAX_EXPORT_BATCH_SIZE: "One", + OTEL_BSP_EXPORT_TIMEOUT: "@", + }, + ) + def test_invalid_env_vars_fall_back_to_defaults(self): + _processor_logger.disabled = True + try: + processor = _EnrichingBatchSpanProcessor(_RecordingExporter()) + finally: + _processor_logger.disabled = False + try: + self.assertEqual(processor._max_queue_size, 2048) + self.assertEqual(processor._schedule_delay_seconds, 5.0) + self.assertEqual(processor._max_export_batch_size, 512) + self.assertEqual(processor._export_timeout_millis, 30000) + finally: + processor.shutdown() + + @mock.patch.dict( + os.environ, + {OTEL_BSP_MAX_QUEUE_SIZE: "10", OTEL_BSP_MAX_EXPORT_BATCH_SIZE: "10"}, + ) + def test_explicit_args_take_precedence_over_env_vars(self): + processor = _EnrichingBatchSpanProcessor(_RecordingExporter(), max_queue_size=99, max_export_batch_size=9) + try: + self.assertEqual(processor._max_queue_size, 99) + self.assertEqual(processor._max_export_batch_size, 9) + finally: + processor.shutdown() + + +class _CountingLogHandler(logging.Handler): + """Non-blocking fake handler that just records every emitted record.""" + + def __init__(self): + super().__init__() + self.records: List[logging.LogRecord] = [] + + def emit(self, record): + self.records.append(record) + + +class _BlockingLogHandler(logging.Handler): + """A log handler whose emit() blocks until release() is called. + + Stands in for a slow or misbehaving log sink (e.g. a network handler). + """ + + def __init__(self): + super().__init__() + self.emit_started = threading.Event() + self._release = threading.Event() + + def release(self): + self._release.set() + + def emit(self, record): + self.emit_started.set() + self._release.wait(timeout=5) + + +class TestEnrichingBatchSpanProcessorDropLogging(unittest.TestCase): + """Task 5 hardening finding #4: per-drop/post-shutdown logging must run + outside the processor's lock and must not turn into a log storm.""" + + def setUp(self): + unregister_span_enricher() + self._logger = logging.getLogger("microsoft.opentelemetry.a365.core.exporters.enriching_span_processor") + self._prev_level = self._logger.level + self._logger.setLevel(logging.DEBUG) + + def tearDown(self): + self._logger.setLevel(self._prev_level) + unregister_span_enricher() + + def test_repeated_post_shutdown_drops_are_throttled(self): + handler = _CountingLogHandler() + self._logger.addHandler(handler) + try: + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=10, + schedule_delay_millis=60_000, + max_export_batch_size=10, + ) + processor.shutdown() # _accepting is now False: every on_end() below drops deterministically + + for i in range(100): + processor.on_end(_make_span(name=f"dropped-{i}")) + + info_records = [r for r in handler.records if r.levelno == logging.INFO] + self.assertEqual( + len(info_records), + 1, + "each post-shutdown drop logged independently -- no throttling of a repeated message", + ) + finally: + self._logger.removeHandler(handler) + + def test_blocking_log_handler_does_not_hold_processor_lock(self): + handler = _BlockingLogHandler() + self._logger.addHandler(handler) + try: + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=10, + schedule_delay_millis=60_000, + max_export_batch_size=10, + ) + processor.shutdown() # deterministic drop path: no capacity/timing races needed + + stuck_thread = threading.Thread(target=processor.on_end, args=(_make_span(),)) + stuck_thread.start() + try: + self.assertTrue(handler.emit_started.wait(timeout=5), "log call never reached the handler") + + # The lock must already be free here: proves _enqueue() logs + # *after* releasing self._condition, so a slow/blocking log + # handler can never starve the worker or other producers. + acquired = processor._condition.acquire(timeout=2) + self.assertTrue( + acquired, + "processor._condition was held while a log handler was blocked in emit()", + ) + processor._condition.release() + + # A second, independent producer must not be blocked either. + second_done = threading.Event() + + def second_call(): + processor.on_end(_make_span()) + second_done.set() + + second_thread = threading.Thread(target=second_call) + second_thread.start() + self.assertTrue(second_done.wait(timeout=2), "a second producer was blocked by the stuck log call") + second_thread.join(timeout=2) + finally: + handler.release() + stuck_thread.join(timeout=5) + self.assertFalse(stuck_thread.is_alive()) + finally: + self._logger.removeHandler(handler) + + +class TestEnrichingBatchSpanProcessorForkSafety(unittest.TestCase): + """Task 5 hardening finding #2: PID-guard fallback path. + + Exercises the enqueue-time PID guard directly, without an actual + ``os.fork()``, so it runs on every platform including Windows. The old + (pre-"fork") worker thread here is a harmless leftover daemon thread + sleeping on a schedule delay far longer than this test's runtime -- in a + real fork it simply would not exist in the child at all. End-to-end + ``os.fork()`` coverage lives in ``TestEnrichingBatchSpanProcessorForkPosix`` + below. + """ + + def setUp(self): + unregister_span_enricher() + + def tearDown(self): + unregister_span_enricher() + + def test_pid_change_reinitializes_queue_state_and_worker(self): + exporter = _RecordingExporter() + exporter.block() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=10, + schedule_delay_millis=5_000, + max_export_batch_size=10, + ) + try: + stale_span = _make_span(name="pre-fork") + processor.on_end(stale_span) + self.assertEqual(len(processor._queue), 1) + old_worker = processor._worker_thread + + # Simulate "we are now the forked child" -- nothing actually + # forked, but a stale pid is exactly what a real os.fork() + # child observes on its very next enqueue. + processor._pid = -1 + + fresh_span = _make_span(name="post-fork") + processor.on_end(fresh_span) + + # State was reinitialized: the stale pre-"fork" span is gone, + # only the fresh one is queued, and a brand-new worker thread is + # running under the current pid. + self.assertEqual(len(processor._queue), 1) + self.assertIs(processor._queue[0], fresh_span) + self.assertIsNot(processor._worker_thread, old_worker) + self.assertTrue(processor._worker_thread.is_alive()) + self.assertEqual(processor._pid, os.getpid()) + self.assertEqual(processor._dropped_count, 0) + finally: + exporter.release() + processor.shutdown() + + self.assertEqual(exporter.exported, [fresh_span]) + + def test_register_at_fork_hook_uses_a_weakref(self): + """The at-fork registration must not keep the processor alive + forever via a strong reference in the process-wide fork registry.""" + if not hasattr(os, "register_at_fork"): + self.skipTest("os.register_at_fork not available on this platform") + + import gc + import weakref + + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor(exporter, max_queue_size=10, max_export_batch_size=10) + processor.shutdown() + weak_processor = weakref.ref(processor) + + del processor + gc.collect() + + self.assertIsNone(weak_processor(), "processor was kept alive by the os.register_at_fork hook") + + +@unittest.skipUnless(_FORK_AVAILABLE, "requires POSIX fork with the 'fork' multiprocessing start method") +class TestEnrichingBatchSpanProcessorForkPosix(unittest.TestCase): + """Task 5 hardening finding #2: real os.fork() end-to-end coverage. + + POSIX-only: os.fork()/os.register_at_fork() do not exist on Windows, so + this whole class is skipped there. + """ + + def setUp(self): + unregister_span_enricher() + + def tearDown(self): + unregister_span_enricher() + + def test_fork_child_reinitializes_and_exports_independently(self): + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=200, + max_export_batch_size=10, + schedule_delay_millis=30_000, + ) + try: + # Queued in the parent only. A real child process has no + # visibility into it -- the worker thread that would have + # drained it does not survive the fork. + for i in range(9): + processor.on_end(_make_span(name=f"parent-{i}")) + + def child(conn): + try: + for i in range(100): + processor.on_end(_make_span(name=f"child-{i}")) + flushed = processor.force_flush(timeout_millis=5000) + # Assert full delivery, not an exact batch count: the + # worker (a genuinely concurrent OS thread in the child) + # may interleave partial drains with this tight + # enqueue loop, so the number of individual export() + # calls it takes to move all 100 spans is not + # deterministic -- only the total delivered count is. + conn.send(flushed and len(exporter.exported) == 100) + finally: + conn.close() + + parent_conn, child_conn = multiprocessing.Pipe() + process = multiprocessing.Process(target=child, args=(child_conn,)) + process.start() + try: + self.assertTrue(parent_conn.poll(10), "child process did not report back in time") + self.assertTrue(parent_conn.recv(), "child did not export all 100 of its own spans") + finally: + process.join(10) + self.assertEqual(process.exitcode, 0) + self.assertFalse(process.is_alive()) + finally: + processor.force_flush(timeout_millis=5000) + processor.shutdown() + + # Only the parent's own pre-fork spans were ever exported here: the + # child's copy-on-write memory keeps its 100 spans/exports entirely + # invisible to the parent's exporter instance. + self.assertEqual(exporter.export_calls, 1) + self.assertEqual(len(exporter.exported), 9) + + def test_fork_child_shutdown_and_force_flush_do_not_hang(self): + exporter = _RecordingExporter() + processor = _EnrichingBatchSpanProcessor( + exporter, + max_queue_size=50, + max_export_batch_size=10, + schedule_delay_millis=30_000, + ) + try: + processor.on_end(_make_span(name="pre-fork")) + + def child(conn): + try: + for i in range(5): + processor.on_end(_make_span(name=f"child-{i}")) + flushed = processor.force_flush(timeout_millis=5000) + processor.shutdown(timeout_millis=5000) + conn.send(bool(flushed)) + finally: + conn.close() + + parent_conn, child_conn = multiprocessing.Pipe() + process = multiprocessing.Process(target=child, args=(child_conn,)) + process.start() + try: + # Bounded wait: a hang here (an inherited, stuck lock) would + # be exactly the fork-safety regression under test. + self.assertTrue(parent_conn.poll(10), "child's force_flush/shutdown hung after fork") + self.assertTrue(parent_conn.recv()) + finally: + process.join(10) + self.assertEqual(process.exitcode, 0) + self.assertFalse(process.is_alive()) + finally: + processor.shutdown() if __name__ == "__main__": diff --git a/tests/a365/test_exporter.py b/tests/a365/test_exporter.py index cd950a4f..4184e9f8 100644 --- a/tests/a365/test_exporter.py +++ b/tests/a365/test_exporter.py @@ -2,15 +2,26 @@ # Licensed under the MIT License. import os +import tempfile +import threading +import time import unittest +from pathlib import Path from unittest.mock import MagicMock, patch +import microsoft.opentelemetry.a365.core.exporters.agent365_exporter as exporter_module from opentelemetry.sdk.trace.export import SpanExportResult from opentelemetry.trace import SpanKind, StatusCode from microsoft.opentelemetry.a365.core.exporters.agent365_exporter import ( _Agent365Exporter, ) +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, +) +from microsoft.opentelemetry.a365.core.exporters.persistent_storage import DurableRecord def _make_span( @@ -62,6 +73,54 @@ def _make_span( return span +def make_exporter(token_resolver=None, **kwargs): + """Build an exporter with durable delivery disabled by default. + + Durable delivery is disabled so tests do not create a real on-disk queue + or spawn a replay thread. Durability-specific tests opt back in by setting + ``exporter._storage`` (or passing ``enable_durable_delivery=True``). + """ + if token_resolver is None and "contextual_token_resolver" not in kwargs: + token_resolver = lambda a, t: "token" # noqa: E731 + kwargs.setdefault("enable_durable_delivery", False) + return _Agent365Exporter(token_resolver=token_resolver, **kwargs) + + +def _delivered(): + return DeliveryResult(DeliveryDisposition.DELIVERED) + + +def _permanent(): + return DeliveryResult(DeliveryDisposition.PERMANENT) + + +def _retryable(retry_after=None): + return DeliveryResult(DeliveryDisposition.RETRYABLE, retry_after) + + +def _make_durable_record( + payload='{"resourceSpans":[]}', + tenant_id="t1", + agent_id="a1", + agentic_user_id=None, + use_s2s_endpoint=False, + url="https://stale.example.test/observability/tenants/stale/otlp/agents/stale/traces?api-version=1", +): + kwargs = { + "schema_version": 1 if "url" in DurableRecord.__dataclass_fields__ else 2, + "tenant_id": tenant_id, + "agent_id": agent_id, + "agentic_user_id": agentic_user_id, + "use_s2s_endpoint": use_s2s_endpoint, + "payload": payload, + "created_at": 1.0, + "record_id": 1, + } + if "url" in DurableRecord.__dataclass_fields__: + kwargs["url"] = url + return DurableRecord(**kwargs) + + class TestAgent365ExporterInit(unittest.TestCase): def test_raises_on_none_resolver(self): with self.assertRaises(ValueError): @@ -76,36 +135,103 @@ def test_raises_on_negative_max_payload_bytes(self): _Agent365Exporter(token_resolver=lambda a, t: "token", max_payload_bytes=-1) def test_creates_with_valid_resolver(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() self.assertIsNotNone(exporter) exporter.shutdown() + @patch.dict(os.environ, {}, clear=True) + def test_pid_change_abandons_inherited_resources_and_reinitializes(self): + exporter = make_exporter(enable_durable_delivery=True) + old_session = MagicMock() + old_storage = MagicMock() + old_replay = MagicMock() + exporter._session = old_session + exporter._storage = old_storage + exporter._replay = old_replay + exporter._replay_started = True + exporter._pid = -1 + + exporter._check_fork_reinit() + + self.assertIsNot(exporter._session, old_session) + self.assertIsNone(exporter._storage) + self.assertIsNone(exporter._replay) + self.assertFalse(exporter._replay_started) + self.assertIn(old_session, exporter._fork_abandoned_resources) + self.assertIn(old_storage, exporter._fork_abandoned_resources) + self.assertIn(old_replay, exporter._fork_abandoned_resources) + old_session.close.assert_not_called() + old_storage.close.assert_not_called() + old_replay.shutdown.assert_not_called() + exporter.shutdown() + + @unittest.skipUnless(hasattr(os, "fork"), "requires POSIX fork") + @patch.dict(os.environ, {}, clear=True) + def test_forked_child_reopens_durable_resources_without_closing_parent(self): + with tempfile.TemporaryDirectory() as tmp: + exporter = _Agent365Exporter( + token_resolver=lambda a, t: "token", + storage_directory=Path(tmp), + enable_durable_delivery=True, + ) + exporter._ensure_durable_initialized() + parent_storage = exporter._storage + self.assertIsNotNone(parent_storage) + read_fd, write_fd = os.pipe() + child_pid = os.fork() + if child_pid == 0: + os.close(read_fd) + try: + exporter._check_fork_reinit() + exporter._ensure_durable_initialized() + child_storage = exporter._storage + if child_storage is None or child_storage is parent_storage: + raise AssertionError("child did not reopen durable storage") + identity = IdentityKey("child-tenant", "child-agent", None, False) + if not child_storage.store(DurableRecord.new(identity, '{"child":true}')): + raise AssertionError("child could not persist after fork") + exporter.shutdown() + os.write(write_fd, b"ok") + except BaseException as exc: # pragma: no cover - POSIX-only child diagnostics + os.write(write_fd, repr(exc).encode("utf-8", errors="replace")) + finally: + os.close(write_fd) + os._exit(0) + + os.close(write_fd) + try: + child_result = os.read(read_fd, 4096) + _, status = os.waitpid(child_pid, 0) + self.assertEqual(status, 0) + self.assertEqual(child_result, b"ok") + identity = IdentityKey("parent-tenant", "parent-agent", None, False) + self.assertTrue(parent_storage.store(DurableRecord.new(identity, '{"parent":true}'))) + finally: + os.close(read_fd) + exporter.shutdown() + class TestAgent365ExporterExport(unittest.TestCase): - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_success(self, mock_post): - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") - span = _make_span() - result = exporter.export([span]) + def test_export_success(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) + result = exporter.export([_make_span()]) self.assertEqual(result, SpanExportResult.SUCCESS) - mock_post.assert_called_once() + exporter._post_once.assert_called_once() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_failure(self, mock_post): - mock_post.return_value = False - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") - span = _make_span() - result = exporter.export([span]) + def test_export_failure(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_permanent()) + result = exporter.export([_make_span()]) self.assertEqual(result, SpanExportResult.FAILURE) exporter.shutdown() @patch.dict(os.environ, {}, clear=True) def test_export_no_identity_spans(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() span = MagicMock() span.attributes = {} result = exporter.export([span]) @@ -114,54 +240,72 @@ def test_export_no_identity_spans(self): @patch.dict(os.environ, {}, clear=True) def test_export_after_shutdown(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter.shutdown() - span = _make_span() - result = exporter.export([span]) + result = exporter.export([_make_span()]) self.assertEqual(result, SpanExportResult.FAILURE) - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_partitions_by_identity(self, mock_post): - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + def test_export_partitions_by_identity(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) s1 = _make_span(tenant_id="t1", agent_id="a1") s2 = _make_span(tenant_id="t2", agent_id="a2") result = exporter.export([s1, s2]) self.assertEqual(result, SpanExportResult.SUCCESS) - self.assertEqual(mock_post.call_count, 2) + self.assertEqual(exporter._post_once.call_count, 2) + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_permanent_first_chunk_stops_identity_but_later_identity_continues(self): + exporter = make_exporter() + exporter._post_once = MagicMock(side_effect=[_permanent(), _delivered(), _delivered()]) + first_identity_spans = [ + _make_span(tenant_id="t1", agent_id="a1", trace_id=1, span_id=1), + _make_span(tenant_id="t1", agent_id="a1", trace_id=2, span_id=2), + ] + later_identity_span = _make_span(tenant_id="t2", agent_id="a2", trace_id=3, span_id=3) + + def split_first_identity(mapped_spans, *_args): + if len(mapped_spans) == 2: + return [[mapped_spans[0]], [mapped_spans[1]]] + return [mapped_spans] + + with patch.object(exporter_module, "chunk_by_size", side_effect=split_first_identity): + result = exporter.export([*first_identity_spans, later_identity_span]) + + self.assertEqual(result, SpanExportResult.FAILURE) + self.assertEqual(exporter._post_once.call_count, 2) + second_url = exporter._post_once.call_args_list[1].args[0] + self.assertIn("/tenants/t2/", second_url) + self.assertIn("/agents/a2/", second_url) exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_token_resolver_called_with_agent_tenant(self, mock_post): - mock_post.return_value = True + def test_token_resolver_called_with_agent_tenant(self): resolver = MagicMock(return_value="token123") - exporter = _Agent365Exporter(token_resolver=resolver) - span = _make_span(tenant_id="my_tenant", agent_id="my_agent") - exporter.export([span]) + exporter = make_exporter(token_resolver=resolver) + exporter._post_once = MagicMock(return_value=_delivered()) + exporter.export([_make_span(tenant_id="my_tenant", agent_id="my_agent")]) resolver.assert_called_once_with("my_agent", "my_tenant") exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_token_resolution_failure_continues(self, mock_post): + def test_token_resolution_failure_without_storage_is_failure(self): resolver = MagicMock(side_effect=Exception("auth error")) - exporter = _Agent365Exporter(token_resolver=resolver) - span = _make_span() - result = exporter.export([span]) + exporter = make_exporter(token_resolver=resolver) + exporter._post_once = MagicMock() + result = exporter.export([_make_span()]) self.assertEqual(result, SpanExportResult.FAILURE) - mock_post.assert_not_called() + exporter._post_once.assert_not_called() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {"A365_OBSERVABILITY_DOMAIN_OVERRIDE": "https://custom.host.com"}) - def test_domain_override(self, mock_post): - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") - span = _make_span() - exporter.export([span]) - url_arg = mock_post.call_args[0][0] + def test_domain_override(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) + exporter.export([_make_span()]) + url_arg = exporter._post_once.call_args[0][0] self.assertIn("custom.host.com", url_arg) exporter.shutdown() @@ -169,7 +313,7 @@ def test_domain_override(self, mock_post): class TestAgent365ExporterBuildRequest(unittest.TestCase): @patch.dict(os.environ, {}, clear=True) def test_build_export_request_structure(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() span = _make_span() mapped_spans = exporter._map_and_truncate_spans([span]) resource_attrs = exporter._get_resource_attributes([span]) @@ -183,7 +327,7 @@ def test_build_export_request_structure(self): @patch.dict(os.environ, {}, clear=True) def test_map_span_basic_fields(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() span = _make_span(name="my_span") mapped = exporter._map_span(span) self.assertEqual(mapped["name"], "my_span") @@ -198,7 +342,7 @@ def test_map_span_basic_fields(self): class TestAgent365ExporterForceFlush(unittest.TestCase): @patch.dict(os.environ, {}, clear=True) def test_force_flush_returns_true(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() self.assertTrue(exporter.force_flush()) exporter.shutdown() @@ -206,23 +350,196 @@ def test_force_flush_returns_true(self): class TestAgent365ExporterShutdown(unittest.TestCase): @patch.dict(os.environ, {}, clear=True) def test_double_shutdown_safe(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter.shutdown() exporter.shutdown() # should not raise - -class TestAgent365ExporterS2S(unittest.TestCase): - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_s2s_endpoint_url(self, mock_post): - mock_post.return_value = True + def test_shutdown_closes_replay_storage_and_session_once(self): + exporter = make_exporter() + replay = MagicMock() + storage = MagicMock() + session = MagicMock() + exporter._replay = replay + exporter._storage = storage + exporter._session = session + + exporter.shutdown() + exporter.shutdown() + + replay.shutdown.assert_called_once() + storage.close.assert_called_once() + session.close.assert_called_once() + + +class TestAgent365ExporterActiveReplayShutdown(unittest.TestCase): + """Active replay work must never observe closed storage/session, and + concurrent exporter.shutdown() callers must close resources exactly once. + + These use a real ReplayCoordinator/PersistentStorage (not mocks) so the + thread ordering, not just call counts, is what is actually verified. + """ + + def _make_durable_exporter_with_pending_record(self, storage_dir): exporter = _Agent365Exporter( token_resolver=lambda a, t: "token", - use_s2s_endpoint=True, + storage_directory=storage_dir, + enable_durable_delivery=True, ) - span = _make_span() - exporter.export([span]) - url_arg = mock_post.call_args[0][0] + exporter._ensure_durable_initialized() + identity = IdentityKey(tenant_id="t1", agent_id="a1", agentic_user_id=None, use_s2s_endpoint=False) + stored = exporter._storage.store(DurableRecord.new(identity, '{"resourceSpans":[]}')) + self.assertTrue(stored) + return exporter + + @staticmethod + def _block_replay_send(exporter): + """Make the *coordinator's* send callable block on an event. + + Patching ``coordinator._send`` (read fresh on every ``run_once()`` + call) rather than ``exporter._replay_record`` (already captured by + value when the coordinator was constructed) so the blocking stub is + guaranteed to be what the replay thread actually invokes. + """ + entered = threading.Event() + release = threading.Event() + + def blocking_send(record): + del record + entered.set() + release.wait() + return _delivered() + + exporter._replay._send = blocking_send + return entered, release + + @patch.dict(os.environ, {}, clear=True) + def test_shutdown_waits_for_active_replay_send_before_closing_storage_and_session(self): + with tempfile.TemporaryDirectory() as tmp: + exporter = self._make_durable_exporter_with_pending_record(Path(tmp)) + entered, release = self._block_replay_send(exporter) + + storage_close = MagicMock(wraps=exporter._storage.close) + exporter._storage.close = storage_close + session_close = MagicMock(wraps=exporter._session.close) + exporter._session.close = session_close + + exporter._replay.start() + self.assertTrue(entered.wait(5.0), "replay never reached the blocking send") + + shutdown_thread = threading.Thread(target=exporter.shutdown) + shutdown_thread.start() + try: + # Outlast the old fixed five-second bounded join: a correct + # implementation must keep waiting for the active replay send + # indefinitely instead of giving up and closing anyway. + time.sleep(5.5) + self.assertTrue(shutdown_thread.is_alive()) + storage_close.assert_not_called() + session_close.assert_not_called() + finally: + release.set() + shutdown_thread.join(5.0) + + self.assertFalse(shutdown_thread.is_alive()) + storage_close.assert_called_once() + session_close.assert_called_once() + + @patch.dict(os.environ, {}, clear=True) + def test_concurrent_shutdown_callers_close_storage_and_session_exactly_once(self): + with tempfile.TemporaryDirectory() as tmp: + exporter = self._make_durable_exporter_with_pending_record(Path(tmp)) + entered, release = self._block_replay_send(exporter) + + storage_close = MagicMock(wraps=exporter._storage.close) + exporter._storage.close = storage_close + session_close = MagicMock(wraps=exporter._session.close) + exporter._session.close = session_close + + exporter._replay.start() + self.assertTrue(entered.wait(5.0), "replay never reached the blocking send") + + shutdown_threads = [threading.Thread(target=exporter.shutdown) for _ in range(2)] + for thread in shutdown_threads: + thread.start() + try: + time.sleep(0.3) + for thread in shutdown_threads: + self.assertTrue(thread.is_alive()) + storage_close.assert_not_called() + session_close.assert_not_called() + finally: + release.set() + for thread in shutdown_threads: + thread.join(5.0) + + for thread in shutdown_threads: + self.assertFalse(thread.is_alive()) + storage_close.assert_called_once() + session_close.assert_called_once() + + @patch.dict(os.environ, {}, clear=True) + def test_shutdown_sets_completion_event_when_owner_cleanup_raises_baseexception(self): + class CleanupInterrupted(BaseException): + pass + + exporter = make_exporter() + replay = MagicMock() + storage = MagicMock() + exporter._replay = replay + exporter._storage = storage + + owner_started = threading.Event() + owner_errors = [] + + def raising_shutdown(_timeout): + owner_started.set() + raise CleanupInterrupted("owner cleanup interrupted") + + replay.shutdown.side_effect = raising_shutdown + + def call_owner_shutdown(): + try: + exporter.shutdown() + except BaseException as exc: # pragma: no cover - asserted below + owner_errors.append(exc) + + owner_thread = threading.Thread(target=call_owner_shutdown) + owner_thread.start() + self.assertTrue(owner_started.wait(5.0), "shutdown owner never reached replay cleanup") + + follower_done = threading.Event() + follower_errors = [] + + def call_follower_shutdown(): + try: + exporter.shutdown() + except BaseException as exc: # pragma: no cover - asserted below + follower_errors.append(exc) + finally: + follower_done.set() + + follower_thread = threading.Thread(target=call_follower_shutdown) + follower_thread.start() + + owner_thread.join(5.0) + follower_thread.join(5.0) + + self.assertFalse(owner_thread.is_alive()) + self.assertFalse(follower_thread.is_alive(), "future shutdown caller blocked forever") + self.assertEqual(len(owner_errors), 1) + self.assertIsInstance(owner_errors[0], CleanupInterrupted) + self.assertEqual(follower_errors, []) + storage.close.assert_not_called() + + +class TestAgent365ExporterS2S(unittest.TestCase): + @patch.dict(os.environ, {}, clear=True) + def test_s2s_endpoint_url(self): + exporter = make_exporter(use_s2s_endpoint=True) + exporter._post_once = MagicMock(return_value=_delivered()) + exporter.export([_make_span()]) + url_arg = exporter._post_once.call_args[0][0] self.assertIn("/observabilityService/", url_arg) exporter.shutdown() @@ -230,7 +547,7 @@ def test_s2s_endpoint_url(self, mock_post): class TestAgent365ExporterFiltering(unittest.TestCase): @patch.dict(os.environ, {}, clear=True) def test_export_no_eligible_spans_logs_info(self): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() span = MagicMock() span.attributes = {} with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.logger") as mock_logger: @@ -239,12 +556,11 @@ def test_export_no_eligible_spans_logs_info(self): mock_logger.info.assert_called_with("No eligible genAI spans to export; nothing exported.") exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_filters_out_non_genai_spans(self, mock_post): + def test_export_filters_out_non_genai_spans(self): """Spans without a known gen_ai.operation.name are filtered out.""" - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) genai_span = _make_span(name="genai_span", trace_id=1, span_id=2) no_op_span = _make_span(name="http_span", trace_id=3, span_id=4, operation_name=None) unknown_op_span = _make_span(name="db_span", trace_id=5, span_id=6, operation_name="some_random_op") @@ -252,15 +568,14 @@ def test_export_filters_out_non_genai_spans(self, mock_post): result = exporter.export([genai_span, no_op_span, unknown_op_span]) self.assertEqual(result, SpanExportResult.SUCCESS) - mock_post.assert_called_once() + exporter._post_once.assert_called_once() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_filters_out_only_non_genai_spans_returns_success(self, mock_post): + def test_export_filters_out_only_non_genai_spans_returns_success(self): """When all spans are filtered out, export returns SUCCESS without HTTP call.""" - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) spans = [ _make_span(name="http_span", operation_name=None), _make_span(name="db_span", operation_name="other"), @@ -269,29 +584,27 @@ def test_export_filters_out_only_non_genai_spans_returns_success(self, mock_post result = exporter.export(spans) self.assertEqual(result, SpanExportResult.SUCCESS) - mock_post.assert_not_called() + exporter._post_once.assert_not_called() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_includes_inference_operation_type_chat_spans(self, mock_post): + def test_export_includes_inference_operation_type_chat_spans(self): """Spans with InferenceOperationType.CHAT value ('Chat') are kept without normalization.""" - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) chat_span = _make_span(name="chat_span", trace_id=1, span_id=2, operation_name="Chat") result = exporter.export([chat_span]) self.assertEqual(result, SpanExportResult.SUCCESS) - mock_post.assert_called_once() + exporter._post_once.assert_called_once() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_filters_out_unsupported_inference_operation_types(self, mock_post): + def test_export_filters_out_unsupported_inference_operation_types(self): """Spans with TextCompletion / GenerateContent are filtered out.""" - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) text_completion_span = _make_span( name="text_completion_span", trace_id=3, span_id=4, operation_name="TextCompletion" ) @@ -302,27 +615,243 @@ def test_export_filters_out_unsupported_inference_operation_types(self, mock_pos result = exporter.export([text_completion_span, generate_content_span]) self.assertEqual(result, SpanExportResult.SUCCESS) - mock_post.assert_not_called() + exporter._post_once.assert_not_called() exporter.shutdown() - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter._post_with_retries") @patch.dict(os.environ, {}, clear=True) - def test_export_does_not_normalize_canonical_operation_names(self, mock_post): + def test_export_does_not_normalize_canonical_operation_names(self): """invoke_agent / execute_tool / output_messages / chat are not rewritten.""" - mock_post.return_value = True - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_delivered()) for op in ("invoke_agent", "execute_tool", "output_messages", "chat"): with self.subTest(operation_name=op): - mock_post.reset_mock() + exporter._post_once.reset_mock() span = _make_span(name=f"{op}_span", trace_id=1, span_id=2, operation_name=op) result = exporter.export([span]) self.assertEqual(result, SpanExportResult.SUCCESS) - mock_post.assert_called_once() + exporter._post_once.assert_called_once() + exporter.shutdown() + + +# --------------------------------------------------------------------------- +# Durable delivery integration (classified single-send + storage + gate). +# --------------------------------------------------------------------------- + + +class TestAgent365ExporterDurableDelivery(unittest.TestCase): + @patch.dict(os.environ, {}, clear=True) + def test_retryable_failure_returns_success_when_payload_is_stored(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_retryable(30)) + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + self.assertIs(exporter.export([_make_span()]), SpanExportResult.SUCCESS) + exporter._storage.store.assert_called_once() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_retryable_failure_returns_failure_when_storage_unavailable(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_retryable(30)) + exporter._storage = MagicMock() + exporter._storage.store.return_value = False + self.assertIs(exporter.export([_make_span()]), SpanExportResult.FAILURE) exporter.shutdown() + @patch.dict(os.environ, {}, clear=True) + def test_retryable_failure_is_failure_when_storage_disabled(self): + # Durable delivery disabled => _storage is None => must surface failure. + exporter = make_exporter() + self.assertIsNone(exporter._storage) + exporter._post_once = MagicMock(return_value=_retryable(30)) + self.assertIs(exporter.export([_make_span()]), SpanExportResult.FAILURE) + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_permanent_failure_is_not_stored(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_permanent()) + exporter._storage = MagicMock() + self.assertIs(exporter.export([_make_span()]), SpanExportResult.FAILURE) + exporter._storage.store.assert_not_called() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_token_resolver_exception_is_stored_and_returns_success(self): + resolver = MagicMock(side_effect=Exception("auth error")) + exporter = make_exporter(token_resolver=resolver) + exporter._post_once = MagicMock() + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + self.assertIs(exporter.export([_make_span()]), SpanExportResult.SUCCESS) + exporter._storage.store.assert_called_once() + exporter._post_once.assert_not_called() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_empty_token_is_permanent_and_not_sent_or_stored(self): + exporter = make_exporter(token_resolver=lambda a, t: None) + exporter._post_once = MagicMock() + exporter._storage = MagicMock() + self.assertIs(exporter.export([_make_span()]), SpanExportResult.FAILURE) + exporter._post_once.assert_not_called() + exporter._storage.store.assert_not_called() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_gate_rejection_persists_without_sending(self): + exporter = make_exporter() + exporter._gate = MagicMock() + exporter._gate.try_acquire.return_value = False + exporter._post_once = MagicMock() + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + self.assertIs(exporter.export([_make_span()]), SpanExportResult.SUCCESS) + exporter._post_once.assert_not_called() + exporter._storage.store.assert_called_once() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_successful_persistence_wakes_replay(self): + exporter = make_exporter() + exporter._post_once = MagicMock(return_value=_retryable(30)) + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + exporter._replay = MagicMock() + exporter.export([_make_span()]) + exporter._replay.wake.assert_called() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_post_once_exception_releases_probe_and_persists(self): + """If _post_once raises unexpectedly, the acquired gate probe must be + released (so the identity is not permanently blocked) and the payload + must be persisted for later replay.""" + exporter = make_exporter() + exporter._gate = MagicMock() + exporter._gate.try_acquire.return_value = True + exporter._post_once = MagicMock(side_effect=RuntimeError("boom")) + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + + # A stored payload after an unexpected send error counts as success. + self.assertIs(exporter.export([_make_span()]), SpanExportResult.SUCCESS) + exporter._storage.store.assert_called_once() + exporter._gate.release_probe.assert_called_once() + # The probe we acquired must not be recorded as a success/failure. + exporter._gate.record_success.assert_not_called() + exporter._gate.record_retryable_failure.assert_not_called() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_post_once_exception_is_failure_when_storage_unavailable(self): + """An unexpected _post_once error with no durable storage still releases + the probe and surfaces failure (payload dropped).""" + exporter = make_exporter() + exporter._gate = MagicMock() + exporter._gate.try_acquire.return_value = True + exporter._post_once = MagicMock(side_effect=RuntimeError("boom")) + exporter._storage = MagicMock() + exporter._storage.store.return_value = False + + self.assertIs(exporter.export([_make_span()]), SpanExportResult.FAILURE) + exporter._gate.release_probe.assert_called_once() + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_probe_not_leaked_across_exports_when_post_once_raises(self): + """A real gate must remain acquirable after an unexpected send error, + proving the half-open probe is not leaked.""" + exporter = make_exporter() + exporter._storage = MagicMock() + exporter._storage.store.return_value = True + exporter._post_once = MagicMock(side_effect=RuntimeError("boom")) + + # First export: the send raises; the probe must be released. + exporter.export([_make_span()]) + + # Second export with a working send must be able to acquire the probe + # (the real gate would refuse if the probe were still held). + exporter._post_once = MagicMock(return_value=_delivered()) + self.assertIs(exporter.export([_make_span()]), SpanExportResult.SUCCESS) + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_replay_rebuilds_endpoint_from_current_exporter_settings(self): + exporter = make_exporter() + exporter._domain_override = "https://current.example.test" + exporter._post_once = MagicMock(return_value=_delivered()) + + result = exporter._replay_record(_make_durable_record()) + + self.assertIs(result.disposition, DeliveryDisposition.DELIVERED) + sent_url = exporter._post_once.call_args[0][0] + self.assertEqual( + sent_url, + "https://current.example.test/observability/tenants/t1/otlp/agents/a1/traces" "?api-version=1", + ) + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_plaintext_replay_endpoint_raises_before_resolving_token_or_sending(self): + resolver = MagicMock(return_value="token") + exporter = make_exporter(token_resolver=resolver) + exporter._domain_override = "http://plaintext.example.test" + exporter._post_once = MagicMock() + + self.assertTrue(hasattr(exporter_module, "ReplayEndpointError")) + with self.assertRaises(exporter_module.ReplayEndpointError): + exporter._replay_record(_make_durable_record()) + + resolver.assert_not_called() + exporter._post_once.assert_not_called() + exporter.shutdown() + + +class TestAgent365ExporterStorageDirectory(unittest.TestCase): + """End-to-end behavior of the storage_directory option and no-leak checks.""" + + @patch.dict(os.environ, {}, clear=True) + def test_storage_directory_is_honored_end_to_end(self): + import tempfile + from pathlib import Path + + with tempfile.TemporaryDirectory() as tmp: + storage_dir = Path(tmp) / "queue" + exporter = _Agent365Exporter( + token_resolver=lambda a, t: "token", + storage_directory=storage_dir, + enable_durable_delivery=True, + ) + exporter._ensure_durable_initialized() + # The durable queue database lives under the requested directory. + self.assertEqual(exporter._storage.database_path.parent, storage_dir) + self.assertTrue((storage_dir / "queue.db").exists()) + exporter.shutdown() + + @patch.dict(os.environ, {}, clear=True) + def test_no_disk_writes_when_durable_delivery_disabled(self): + import tempfile + from pathlib import Path + + with tempfile.TemporaryDirectory() as tmp: + storage_dir = Path(tmp) / "queue" + exporter = _Agent365Exporter( + token_resolver=lambda a, t: "token", + storage_directory=storage_dir, + enable_durable_delivery=False, + ) + exporter._post_once = MagicMock(return_value=_retryable(30)) + # A retryable failure with storage disabled must surface FAILURE and + # must not create any on-disk queue. + self.assertIs(exporter.export([_make_span()]), SpanExportResult.FAILURE) + self.assertIsNone(exporter._storage) + self.assertFalse(storage_dir.exists()) + exporter.shutdown() + # --------------------------------------------------------------------------- -# Network statsbeat — request_success_count recorded inside _post_with_retries. +# Network statsbeat — recorded inside the classified single-send _post_once. # --------------------------------------------------------------------------- @@ -353,30 +882,22 @@ def tearDown(self): def test_success_records_success(self, _enabled): from microsoft.opentelemetry._sdkstats._utils import REQUEST_SUCCESS_NAME, drain - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter._session = MagicMock() exporter._session.post.return_value = _make_response(200) - ok = exporter._post_with_retries(self.URL, "{}", {}) - self.assertTrue(ok) - self.assertEqual( - drain(REQUEST_SUCCESS_NAME), - { - ( - self.ENDPOINT, - self.HOST, - ): 1 - }, - ) + result = exporter._post_once(self.URL, "{}", {}) + self.assertIs(result.disposition, DeliveryDisposition.DELIVERED) + self.assertEqual(drain(REQUEST_SUCCESS_NAME), {(self.ENDPOINT, self.HOST): 1}) exporter.shutdown() @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) - def test_non_2xx_does_not_record(self, _enabled): + def test_non_2xx_does_not_record_success(self, _enabled): from microsoft.opentelemetry._sdkstats._utils import REQUEST_SUCCESS_NAME, drain - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter._session = MagicMock() exporter._session.post.return_value = _make_response(404) - exporter._post_with_retries(self.URL, "{}", {}) + exporter._post_once(self.URL, "{}", {}) self.assertEqual(drain(REQUEST_SUCCESS_NAME), {}) exporter.shutdown() @@ -384,23 +905,21 @@ def test_non_2xx_does_not_record(self, _enabled): def test_disabled_does_not_record(self, _enabled): from microsoft.opentelemetry._sdkstats._utils import REQUEST_SUCCESS_NAME, drain - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter._session = MagicMock() exporter._session.post.return_value = _make_response(200) - exporter._post_with_retries(self.URL, "{}", {}) + exporter._post_once(self.URL, "{}", {}) self.assertEqual(drain(REQUEST_SUCCESS_NAME), {}) exporter.shutdown() - # ------- duration / failure / retry / throttle / exception ------- - @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) def test_success_records_duration(self, _enabled): from microsoft.opentelemetry._sdkstats._utils import REQUEST_DURATION_NAME, drain - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter._session = MagicMock() exporter._session.post.return_value = _make_response(200) - exporter._post_with_retries(self.URL, "{}", {}) + exporter._post_once(self.URL, "{}", {}) snap = drain(REQUEST_DURATION_NAME) self.assertEqual(set(snap.keys()), {(self.ENDPOINT, self.HOST)}) @@ -410,92 +929,63 @@ def test_success_records_duration(self, _enabled): exporter.shutdown() @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) - def test_non_retryable_status_records_failure(self, _enabled): + def test_permanent_status_records_failure(self, _enabled): from microsoft.opentelemetry._sdkstats._utils import REQUEST_FAILURE_NAME, drain - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter._session = MagicMock() - exporter._session.post.return_value = _make_response(401) - exporter._post_with_retries(self.URL, "{}", {}) - self.assertEqual( - drain(REQUEST_FAILURE_NAME), - {(self.ENDPOINT, self.HOST, 401): 1}, - ) + exporter._session.post.return_value = _make_response(400) + result = exporter._post_once(self.URL, "{}", {}) + self.assertIs(result.disposition, DeliveryDisposition.PERMANENT) + self.assertEqual(drain(REQUEST_FAILURE_NAME), {(self.ENDPOINT, self.HOST, 400): 1}) exporter.shutdown() @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) - def test_non_retryable_throttle_status_records_throttle(self, _enabled): + def test_throttle_status_records_throttle(self, _enabled): from microsoft.opentelemetry._sdkstats._utils import REQUEST_THROTTLE_NAME, drain - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter._session = MagicMock() exporter._session.post.return_value = _make_response(402) - exporter._post_with_retries(self.URL, "{}", {}) - self.assertEqual( - drain(REQUEST_THROTTLE_NAME), - {(self.ENDPOINT, self.HOST, 402): 1}, - ) + result = exporter._post_once(self.URL, "{}", {}) + self.assertIs(result.disposition, DeliveryDisposition.PERMANENT) + self.assertEqual(drain(REQUEST_THROTTLE_NAME), {(self.ENDPOINT, self.HOST, 402): 1}) exporter.shutdown() @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) - def test_retryable_then_success_records_retry_and_success(self, _enabled): - from microsoft.opentelemetry._sdkstats._utils import ( - REQUEST_RETRY_NAME, - REQUEST_SUCCESS_NAME, - drain, - ) + def test_retryable_5xx_records_retry(self, _enabled): + from microsoft.opentelemetry._sdkstats._utils import REQUEST_RETRY_NAME, drain - with patch( - "microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep", - return_value=None, - ): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") - exporter._session = MagicMock() - exporter._session.post.side_effect = [ - _make_response(503), - _make_response(200), - ] - ok = exporter._post_with_retries(self.URL, "{}", {}) - - self.assertTrue(ok) - self.assertEqual( - drain(REQUEST_RETRY_NAME), - {(self.ENDPOINT, self.HOST, 503): 1}, - ) - self.assertEqual( - drain(REQUEST_SUCCESS_NAME), - {(self.ENDPOINT, self.HOST): 1}, - ) + exporter = make_exporter() + exporter._session = MagicMock() + exporter._session.post.return_value = _make_response(503) + result = exporter._post_once(self.URL, "{}", {}) + self.assertIs(result.disposition, DeliveryDisposition.RETRYABLE) + self.assertEqual(drain(REQUEST_RETRY_NAME), {(self.ENDPOINT, self.HOST, 503): 1}) exporter.shutdown() @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) - def test_retryable_final_failure_records_failure(self, _enabled): - """All retries exhausted with a 5xx → record_failure (not throttle).""" - from microsoft.opentelemetry._sdkstats._utils import ( - REQUEST_FAILURE_NAME, - REQUEST_RETRY_NAME, - drain, - ) + def test_retryable_401_records_retry(self, _enabled): + from microsoft.opentelemetry._sdkstats._utils import REQUEST_RETRY_NAME, drain - with patch( - "microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep", - return_value=None, - ): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") - exporter._session = MagicMock() - exporter._session.post.return_value = _make_response(503) - ok = exporter._post_with_retries(self.URL, "{}", {}) - - self.assertFalse(ok) - # 3 retries (each leading to another attempt) + 1 final failed attempt - self.assertEqual( - drain(REQUEST_RETRY_NAME), - {(self.ENDPOINT, self.HOST, 503): 3}, - ) - self.assertEqual( - drain(REQUEST_FAILURE_NAME), - {(self.ENDPOINT, self.HOST, 503): 1}, - ) + exporter = make_exporter() + exporter._session = MagicMock() + exporter._session.post.return_value = _make_response(401) + result = exporter._post_once(self.URL, "{}", {}) + self.assertIs(result.disposition, DeliveryDisposition.RETRYABLE) + self.assertEqual(drain(REQUEST_RETRY_NAME), {(self.ENDPOINT, self.HOST, 401): 1}) + exporter.shutdown() + + @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) + def test_retry_after_header_is_parsed_without_sleeping(self, _enabled): + exporter = make_exporter() + exporter._session = MagicMock() + exporter._session.post.return_value = _make_response(429, headers={"Retry-After": "42"}) + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep") as mock_sleep: + result = exporter._post_once(self.URL, "{}", {}) + self.assertIs(result.disposition, DeliveryDisposition.RETRYABLE) + self.assertEqual(result.retry_after, 42.0) + mock_sleep.assert_not_called() exporter.shutdown() @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=True) @@ -508,32 +998,27 @@ def test_request_exception_records_exception_and_duration(self, _enabled): drain, ) - with patch( - "microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep", - return_value=None, - ): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") - exporter._session = MagicMock() - exporter._session.post.side_effect = requests.ConnectionError("boom") - ok = exporter._post_with_retries(self.URL, "{}", {}) - - self.assertFalse(ok) - # record_exception fires on every attempt (4 = 1 initial + 3 retries) + exporter = make_exporter() + exporter._session = MagicMock() + exporter._session.post.side_effect = requests.ConnectionError("boom") + result = exporter._post_once(self.URL, "{}", {}) + + self.assertIs(result.disposition, DeliveryDisposition.RETRYABLE) + # Single send => exception recorded exactly once. self.assertEqual( drain(REQUEST_EXCEPTION_NAME), - {(self.ENDPOINT, self.HOST, "ConnectionError"): 4}, + {(self.ENDPOINT, self.HOST, "ConnectionError"): 1}, ) - # record_duration likewise fires on every attempt snap = drain(REQUEST_DURATION_NAME) self.assertEqual(set(snap.keys()), {(self.ENDPOINT, self.HOST)}) _total, count = snap[(self.ENDPOINT, self.HOST)] - self.assertEqual(count, 4) + self.assertEqual(count, 1) exporter.shutdown() @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=False) def test_403_insufficient_scope_logs_actionable_message(self, _enabled): """HTTP 403 with insufficient_scope logs an actionable message with doc links.""" - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") + exporter = make_exporter() exporter._session = MagicMock() exporter._session.post.return_value = _make_response( 403, @@ -547,9 +1032,9 @@ def test_403_insufficient_scope_logs_actionable_message(self, _enabled): }, ) with self.assertLogs("microsoft.opentelemetry.a365.core.exporters.agent365_exporter", level="ERROR") as log: - result = exporter._post_with_retries(self.URL, "{}", {}) + result = exporter._post_once(self.URL, "{}", {}) - self.assertFalse(result) + self.assertIs(result.disposition, DeliveryDisposition.PERMANENT) self.assertEqual(len(log.output), 1) msg = log.output[0] self.assertIn("Agent365.Observability.OtelWrite", msg) @@ -560,7 +1045,7 @@ def test_403_insufficient_scope_logs_actionable_message(self, _enabled): @patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter.is_sdkstats_enabled", return_value=False) def test_disabled_records_no_metrics(self, _enabled): - """When sdkstats is disabled, none of the new helpers fire.""" + """When sdkstats is disabled, none of the helpers fire.""" from microsoft.opentelemetry._sdkstats._utils import ( REQUEST_DURATION_NAME, REQUEST_FAILURE_NAME, @@ -569,14 +1054,10 @@ def test_disabled_records_no_metrics(self, _enabled): drain, ) - with patch( - "microsoft.opentelemetry.a365.core.exporters.agent365_exporter.time.sleep", - return_value=None, - ): - exporter = _Agent365Exporter(token_resolver=lambda a, t: "token") - exporter._session = MagicMock() - exporter._session.post.return_value = _make_response(503) - exporter._post_with_retries(self.URL, "{}", {}) + exporter = make_exporter() + exporter._session = MagicMock() + exporter._session.post.return_value = _make_response(503) + exporter._post_once(self.URL, "{}", {}) self.assertEqual(drain(REQUEST_DURATION_NAME), {}) self.assertEqual(drain(REQUEST_FAILURE_NAME), {}) diff --git a/tests/a365/test_handler.py b/tests/a365/test_handler.py index cadff5c9..f035431b 100644 --- a/tests/a365/test_handler.py +++ b/tests/a365/test_handler.py @@ -3,7 +3,7 @@ import os import unittest -from unittest.mock import patch +from unittest.mock import MagicMock, patch from microsoft.opentelemetry.a365 import ( A365Handlers, @@ -95,5 +95,92 @@ def test_default_empty(self): self.assertEqual(handlers.span_processors, []) +class TestA365ExporterOptionsOfflineStorage(unittest.TestCase): + """Tests that Agent365ExporterOptions exposes offline-storage config.""" + + def test_disable_offline_storage_defaults_false(self): + from microsoft.opentelemetry.a365.core.exporters.agent365_exporter_options import Agent365ExporterOptions + + opts = Agent365ExporterOptions() + self.assertFalse(opts.disable_offline_storage) + + def test_storage_directory_defaults_none(self): + from microsoft.opentelemetry.a365.core.exporters.agent365_exporter_options import Agent365ExporterOptions + + opts = Agent365ExporterOptions() + self.assertIsNone(opts.storage_directory) + + def test_disable_offline_storage_can_be_set_true(self): + from microsoft.opentelemetry.a365.core.exporters.agent365_exporter_options import Agent365ExporterOptions + + opts = Agent365ExporterOptions(disable_offline_storage=True) + self.assertTrue(opts.disable_offline_storage) + + def test_storage_directory_can_be_set(self): + from microsoft.opentelemetry.a365.core.exporters.agent365_exporter_options import Agent365ExporterOptions + + opts = Agent365ExporterOptions(storage_directory="C:\\telemetry") + self.assertEqual(opts.storage_directory, "C:\\telemetry") + + def test_empty_storage_directory_raises_value_error(self): + from microsoft.opentelemetry.a365.core.exporters.agent365_exporter_options import Agent365ExporterOptions + + with self.assertRaises(ValueError): + Agent365ExporterOptions(storage_directory="") + + def test_whitespace_storage_directory_raises_value_error(self): + from microsoft.opentelemetry.a365.core.exporters.agent365_exporter_options import Agent365ExporterOptions + + with self.assertRaises(ValueError): + Agent365ExporterOptions(storage_directory=" ") + + +class TestCreateA365ComponentsOfflineStorage(unittest.TestCase): + """Tests that create_a365_components forwards offline-storage options.""" + + @patch.dict(os.environ, {"ENABLE_A365_OBSERVABILITY_EXPORTER": "true"}) + def test_disable_offline_storage_forwarded_to_exporter(self): + from pathlib import Path + + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + exporter_mock.return_value = MagicMock() + create_a365_components(disable_offline_storage=True) + _, kwargs = exporter_mock.call_args + self.assertFalse(kwargs["enable_durable_delivery"]) + + @patch.dict(os.environ, {"ENABLE_A365_OBSERVABILITY_EXPORTER": "true"}) + def test_storage_directory_forwarded_to_exporter_as_path(self): + from pathlib import Path + + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + exporter_mock.return_value = MagicMock() + create_a365_components(storage_directory="C:\\telemetry") + _, kwargs = exporter_mock.call_args + self.assertEqual(kwargs["storage_directory"], Path("C:\\telemetry")) + + @patch.dict(os.environ, {"ENABLE_A365_OBSERVABILITY_EXPORTER": "true"}) + def test_durable_delivery_enabled_by_default(self): + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + exporter_mock.return_value = MagicMock() + create_a365_components() + _, kwargs = exporter_mock.call_args + self.assertTrue(kwargs["enable_durable_delivery"]) + + @patch.dict(os.environ, {"ENABLE_A365_OBSERVABILITY_EXPORTER": "true"}) + def test_storage_directory_none_by_default(self): + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + exporter_mock.return_value = MagicMock() + create_a365_components() + _, kwargs = exporter_mock.call_args + self.assertIsNone(kwargs["storage_directory"]) + + @patch.dict(os.environ, {"ENABLE_A365_OBSERVABILITY_EXPORTER": "true"}) + def test_empty_storage_directory_rejected_end_to_end(self): + """An explicitly empty storage directory must raise ValueError rather + than silently defaulting to the platform path.""" + with self.assertRaises(ValueError): + create_a365_components(storage_directory="") + + if __name__ == "__main__": unittest.main() diff --git a/tests/a365/test_payload_chunking.py b/tests/a365/test_payload_chunking.py index a715bace..201865c4 100644 --- a/tests/a365/test_payload_chunking.py +++ b/tests/a365/test_payload_chunking.py @@ -16,6 +16,10 @@ from microsoft.opentelemetry.a365.core.exporters.agent365_exporter import ( _Agent365Exporter, ) +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, +) from microsoft.opentelemetry.a365.core.exporters.utils import ( chunk_by_size, estimate_span_bytes, @@ -188,13 +192,16 @@ def test_oversized_batch_is_split_into_multiple_requests(self) -> None: token_resolver=self.token_resolver, cluster_category="test", max_payload_bytes=300_000, + enable_durable_delivery=False, ) # Each span carries ~200 KB of payload; with a 300 KB chunk limit, # 5 spans should yield at least 2 chunks. spans = [self._make_span(span_id=i + 1, attribute_size=200_000) for i in range(5)] - with patch.object(exporter, "_post_with_retries", return_value=True) as mock_post: + with patch.object( + exporter, "_post_once", return_value=DeliveryResult(DeliveryDisposition.DELIVERED) + ) as mock_post: result = exporter.export(spans) self.assertEqual(result, SpanExportResult.SUCCESS) @@ -217,14 +224,20 @@ def test_chunk_failure_short_circuits_remaining_chunks(self) -> None: token_resolver=self.token_resolver, cluster_category="test", max_payload_bytes=300_000, + enable_durable_delivery=False, ) spans = [self._make_span(span_id=i + 1, attribute_size=200_000) for i in range(5)] - with patch.object(exporter, "_post_with_retries", return_value=False) as mock_post: + # A retryable failure blocks the identity gate; with durable storage + # disabled the payload cannot be stored, so the export fails and the + # remaining chunks are gated off (persisted-or-dropped, never sent). + with patch.object( + exporter, "_post_once", return_value=DeliveryResult(DeliveryDisposition.RETRYABLE) + ) as mock_post: result = exporter.export(spans) self.assertEqual(result, SpanExportResult.FAILURE) - # First chunk fails; remaining chunks must not be sent. + # First chunk is sent; the gate blocks the rest, so no further sends. self.assertEqual(mock_post.call_count, 1) @patch.dict("os.environ", {}, clear=True) @@ -232,10 +245,13 @@ def test_small_batch_uses_single_request(self) -> None: exporter = _Agent365Exporter( token_resolver=self.token_resolver, cluster_category="test", + enable_durable_delivery=False, ) spans = [self._make_span(span_id=1, attribute_size=100)] - with patch.object(exporter, "_post_with_retries", return_value=True) as mock_post: + with patch.object( + exporter, "_post_once", return_value=DeliveryResult(DeliveryDisposition.DELIVERED) + ) as mock_post: result = exporter.export(spans) self.assertEqual(result, SpanExportResult.SUCCESS) diff --git a/tests/a365/test_persistent_storage.py b/tests/a365/test_persistent_storage.py new file mode 100644 index 00000000..d8d700c5 --- /dev/null +++ b/tests/a365/test_persistent_storage.py @@ -0,0 +1,526 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Tests for PersistentStorage (Task 2).""" + +from __future__ import annotations + +import inspect +import os +import sqlite3 +import stat +import time +from unittest.mock import patch + +import pytest + +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import IdentityKey +from microsoft.opentelemetry.a365.core.exporters.persistent_storage import ( + DurableRecord, + PersistentStorage, +) + +KEY = IdentityKey( + tenant_id="t1", + agent_id="a1", + agentic_user_id=None, + use_s2s_endpoint=False, +) +LEGACY_URL = "https://example.test" + + +def _new_record(payload: str, key: IdentityKey = KEY) -> DurableRecord: + params = list(inspect.signature(DurableRecord.new).parameters) + if params == ["key", "payload"]: + return DurableRecord.new(key, payload) + return DurableRecord.new(key, LEGACY_URL, payload) + + +def _schema_version_for(columns: set[str]) -> int: + return 1 if "url" in columns else 2 + + +def _table_columns(storage: PersistentStorage) -> set[str]: + rows = storage._conn.execute("PRAGMA table_info(durable_records)").fetchall() + return {row[1] for row in rows} + + +def insert_raw_record( + storage: PersistentStorage, + *, + created_at: float | None = None, + **overrides, +) -> int: + columns = _table_columns(storage) + row = { + "schema_version": _schema_version_for(columns), + "tenant_id": KEY.tenant_id, + "agent_id": KEY.agent_id, + "agentic_user_id": KEY.agentic_user_id, + "use_s2s_endpoint": int(KEY.use_s2s_endpoint), + "payload": '{"raw":true}', + "created_at": time.time() - 1.0 if created_at is None else created_at, + "lease_until": None, + "retry_count": 0, + } + if "url" in columns: + row["url"] = LEGACY_URL + row.update(overrides) + names = list(row) + placeholders = ", ".join("?" for _ in names) + sql = f"INSERT INTO durable_records ({', '.join(names)}) VALUES ({placeholders})" + with storage._lock: + storage._conn.execute("BEGIN IMMEDIATE") + cur = storage._conn.execute(sql, tuple(row[name] for name in names)) + storage._conn.execute("COMMIT") + return int(cur.lastrowid) + + +def raw_record_exists(storage: PersistentStorage, record_id: int) -> bool: + with storage._lock: + row = storage._conn.execute( + "SELECT COUNT(*) FROM durable_records WHERE id = ?", + (record_id,), + ).fetchone() + return bool(row[0]) + + +def _create_legacy_v1_database(database_path): + database_path.parent.mkdir(parents=True, exist_ok=True) + conn = sqlite3.connect(str(database_path)) + try: + conn.execute(""" + CREATE TABLE durable_records ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + schema_version INTEGER NOT NULL, + tenant_id TEXT NOT NULL, + agent_id TEXT NOT NULL, + agentic_user_id TEXT, + use_s2s_endpoint INTEGER NOT NULL, + url TEXT NOT NULL, + payload TEXT NOT NULL, + created_at REAL NOT NULL, + lease_until REAL, + retry_count INTEGER NOT NULL DEFAULT 0 + ) + """) + conn.execute( + """ + INSERT INTO durable_records ( + schema_version, tenant_id, agent_id, agentic_user_id, + use_s2s_endpoint, url, payload, created_at, lease_until, retry_count + ) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) + """, + ( + 1, + "legacy-tenant", + "legacy-agent", + "legacy-user", + 1, + "https://legacy.example.test", + '{"legacy":true}', + time.time() - 5.0, + None, + 3, + ), + ) + conn.commit() + finally: + conn.close() + + +# --------------------------------------------------------------------------- +# Transaction safety: isolation_level=None (autocommit mode) +# --------------------------------------------------------------------------- + + +def test_connection_is_in_autocommit_mode(tmp_path): + """The connection must use isolation_level=None so transactions are explicit.""" + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + assert storage._conn.isolation_level is None + storage.close() + + +# --------------------------------------------------------------------------- +# claim() prunes expired rows during the transaction +# --------------------------------------------------------------------------- + + +def test_claim_prunes_expired_rows(tmp_path): + """Expired records stored before a claim call must be deleted by claim itself.""" + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=0) + insert_raw_record(storage, created_at=0.0, payload='{"stale":true}') + + # claim must prune the expired row and return nothing + claimed = storage.claim(limit=10, lease_seconds=30) + assert claimed == [] + + # Row must actually be gone + with storage._lock: + row = storage._conn.execute("SELECT COUNT(*) FROM durable_records").fetchone() + assert row[0] == 0 + storage.close() + + +def test_initialization_migrates_v1_schema_and_preserves_records(tmp_path): + queue_dir = tmp_path / "queue" + _create_legacy_v1_database(queue_dir / "queue.db") + + storage = PersistentStorage(queue_dir, capacity_bytes=1024 * 1024, retention_seconds=3600) + columns = _table_columns(storage) + + assert "url" not in columns + claimed = storage.claim(limit=10, lease_seconds=30) + assert len(claimed) == 1 + assert claimed[0].schema_version == 2 + assert claimed[0].tenant_id == "legacy-tenant" + assert claimed[0].agent_id == "legacy-agent" + assert claimed[0].agentic_user_id == "legacy-user" + assert claimed[0].use_s2s_endpoint is True + assert claimed[0].payload == '{"legacy":true}' + assert claimed[0].retry_count == 3 + storage.close() + + +@pytest.mark.parametrize( + ("column", "value"), + [ + ("schema_version", 999), + ("tenant_id", ""), + ("agent_id", ""), + ("payload", ""), + ], +) +def test_claim_deletes_invalid_records_and_continues_to_valid_later_record(tmp_path, column, value): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + invalid_id = insert_raw_record(storage, **{column: value}) + valid = _new_record('{"resourceSpans":[]}') + + assert storage.store(valid) + + claimed = storage.claim(limit=1, lease_seconds=30) + + assert [record.payload for record in claimed] == [valid.payload] + assert raw_record_exists(storage, invalid_id) is False + storage.close() + + +# --------------------------------------------------------------------------- +# Round-trip +# --------------------------------------------------------------------------- + + +def test_store_claim_delete_round_trip(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + record = _new_record('{"resourceSpans":[]}') + assert storage.store(record) + claimed = storage.claim(limit=10, lease_seconds=30) + assert [item.payload for item in claimed] == [record.payload] + assert storage.delete(claimed[0].record_id) + assert storage.claim(limit=10, lease_seconds=30) == [] + storage.close() + + +# --------------------------------------------------------------------------- +# Lease release +# --------------------------------------------------------------------------- + + +def test_release_makes_record_claimable_again(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + record = _new_record('{"payload":1}') + assert storage.store(record) + + claimed = storage.claim(limit=10, lease_seconds=30) + assert len(claimed) == 1 + + # While leased, claim returns nothing + assert storage.claim(limit=10, lease_seconds=30) == [] + + # After release the record is available again + assert storage.release(claimed[0].record_id) + reclaimed = storage.claim(limit=10, lease_seconds=30) + assert len(reclaimed) == 1 + assert reclaimed[0].payload == record.payload + storage.close() + + +# --------------------------------------------------------------------------- +# Expired-record cleanup +# --------------------------------------------------------------------------- + + +def test_expired_records_are_cleaned_up(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=0) + # Insert the to-be-expired row directly with an unambiguously-past + # created_at (matching the insert_raw_record convention used by + # test_claim_prunes_expired_rows above) instead of two back-to-back + # DurableRecord.new()/store() calls. time.time() has ~15ms resolution on + # Windows, so two calls made microseconds apart can return the identical + # value; with retention_seconds=0 that made "created_at < expire_before" + # a tie (record.created_at == the claim's own now-clock read), leaving + # the "expired" record un-pruned and intermittently failing this test. + insert_raw_record(storage, created_at=0.0, payload='{"payload":2}') + + # Store a second, live record to trigger the cleanup path alongside it. + record2 = _new_record('{"payload":3}') + assert storage.store(record2) + + # Expired records must not be returned by claim + claimed = storage.claim(limit=10, lease_seconds=30) + for item in claimed: + assert item.payload != '{"payload":2}' + storage.close() + + +# --------------------------------------------------------------------------- +# Capacity rejection +# --------------------------------------------------------------------------- + + +def test_store_rejects_when_capacity_exceeded(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1, retention_seconds=3600) + record = _new_record("x" * 100) + # Must return False and not raise + result = storage.store(record) + assert result is False + storage.close() + + +def test_store_reclaims_capacity_after_fill_delete_refill(tmp_path): + """Capacity accounting must use live pages, not the file high-water mark. + + Regression: with ``page_count * page_size`` accounting, filling the queue to + its cap and then claiming/deleting every record left the freed (freelist) + pages counted as "used", because SQLite does not shrink the file on delete. + The queue was therefore permanently wedged and rejected all new records. + Live-page accounting — ``(page_count - freelist_count) * page_size`` — must + reclaim the freed space so new records can be stored again. + """ + storage = PersistentStorage(tmp_path, capacity_bytes=64 * 1024, retention_seconds=3600) + payload = "x" * 4000 + + # Fill until the capacity cap rejects a store. + stored = 0 + while stored < 500 and storage.store(_new_record(payload)): + stored += 1 + # A store was actually rejected (we reached the cap, not the loop guard). + assert 0 < stored < 500 + + # Claim and delete every stored record. + while True: + claimed = storage.claim(limit=100, lease_seconds=300) + if not claimed: + break + for rec in claimed: + assert storage.delete(rec.record_id) + + # The freed space must be reclaimed so new records can be stored again. + assert storage.store(_new_record(payload)) is True + storage.close() + + +# --------------------------------------------------------------------------- +# POSIX permissions +# --------------------------------------------------------------------------- + + +@pytest.mark.skipif(os.name == "nt", reason="POSIX permissions") +def test_storage_permissions_are_private(tmp_path): + storage = PersistentStorage(tmp_path / "queue") + assert stat.S_IMODE((tmp_path / "queue").stat().st_mode) == 0o700 + assert stat.S_IMODE(storage.database_path.stat().st_mode) == 0o600 + storage.close() + + +@pytest.mark.skipif(os.name == "nt", reason="POSIX permissions") +def test_wal_and_shm_sidecars_are_private(tmp_path): + """The DB and its WAL/SHM sidecars must be mode 0600 after journal init. + + WAL mode creates ``queue.db-wal`` and ``queue.db-shm`` sidecars that would + otherwise inherit the process umask; they can contain the same OTLP payloads + as the DB and must be locked to the owner. + """ + storage = PersistentStorage(tmp_path / "queue") + try: + for name in ("queue.db", "queue.db-wal", "queue.db-shm"): + sidecar = tmp_path / "queue" / name + assert sidecar.exists(), name + assert stat.S_IMODE(sidecar.stat().st_mode) == 0o600, name + finally: + storage.close() + + +def test_restrict_file_permissions_locks_db_and_sidecars(tmp_path, monkeypatch): + """The helper chmods the DB and any existing WAL/SHM sidecars to 0600. + + Runs on Windows (mocks only ``os.chmod``, not ``os.name``, so ``pathlib`` is + unaffected) to make the sidecar hardening verifiable off-POSIX; the real + end-to-end modes are checked by the POSIX-only test above. + """ + import microsoft.opentelemetry.a365.core.exporters.persistent_storage as _mod + + storage = PersistentStorage(tmp_path / "queue") + try: + # Journal init created queue.db plus its -wal/-shm sidecars. + for name in ("queue.db", "queue.db-wal", "queue.db-shm"): + assert (tmp_path / "queue" / name).exists(), name + + recorded: dict[str, int] = {} + monkeypatch.setattr(_mod.os, "chmod", lambda p, m: recorded.__setitem__(os.path.basename(str(p)), m)) + storage._restrict_file_permissions() + + assert recorded.get("queue.db") == 0o600 + assert recorded.get("queue.db-wal") == 0o600 + assert recorded.get("queue.db-shm") == 0o600 + finally: + storage.close() + + +# --------------------------------------------------------------------------- +# Unsafe ownership rejected +# --------------------------------------------------------------------------- + + +@pytest.mark.skipif(os.name == "nt", reason="POSIX ownership check") +def test_rejects_directory_owned_by_another_uid(tmp_path): + import types + import microsoft.opentelemetry.a365.core.exporters.persistent_storage as _mod + + foreign_uid = os.getuid() + 1 + + real_stat = os.lstat(tmp_path) + mock_result = types.SimpleNamespace( + st_uid=foreign_uid, + st_mode=real_stat.st_mode, + st_size=real_stat.st_size, + st_mtime=real_stat.st_mtime, + ) + + target_dir = tmp_path / "queue_foreign" + target_dir.mkdir(parents=True, exist_ok=True) + + # Ownership is validated with a non-symlink-following lstat. + with patch.object(_mod.os, "lstat", return_value=mock_result): + with pytest.raises(PermissionError, match="unsafe ownership"): + PersistentStorage(target_dir) + + +@pytest.mark.skipif(os.name == "nt", reason="POSIX symlink rejection") +def test_rejects_symlinked_directory(tmp_path): + """A symlinked queue directory must be rejected, not silently followed.""" + real_dir = tmp_path / "real" + real_dir.mkdir() + link_dir = tmp_path / "link" + os.symlink(real_dir, link_dir, target_is_directory=True) + + with pytest.raises(PermissionError, match="symlink"): + PersistentStorage(link_dir) + + +def test_default_directory_prefers_local_state_even_if_missing(tmp_path): + """On POSIX without XDG_STATE_HOME, prefer ~/.local/state (to be created) + rather than falling back to the temp dir merely because it does not exist.""" + import microsoft.opentelemetry.a365.core.exporters.persistent_storage as _mod + + fake_home = tmp_path / "home" + fake_home.mkdir() + local_state = fake_home / ".local" / "state" + assert not local_state.exists() + + env = {k: v for k, v in os.environ.items() if k != "XDG_STATE_HOME"} + with ( + patch.object(_mod.sys, "platform", "linux"), + patch.dict(os.environ, env, clear=True), + patch.object(_mod.Path, "home", return_value=fake_home), + ): + resolved = _mod._resolve_default_directory() + + # The resolved base must be under ~/.local/state, not the temp directory. + assert str(resolved).startswith(str(local_state)) + + +def test_default_directory_falls_back_to_tmp_when_home_unusable(tmp_path): + """When the home directory cannot be resolved, fall back to the temp dir.""" + import microsoft.opentelemetry.a365.core.exporters.persistent_storage as _mod + + env = {k: v for k, v in os.environ.items() if k != "XDG_STATE_HOME"} + with ( + patch.object(_mod.sys, "platform", "linux"), + patch.dict(os.environ, env, clear=True), + patch.object(_mod.Path, "home", side_effect=RuntimeError("no home")), + ): + resolved = _mod._resolve_default_directory() + + assert str(resolved).startswith(str(_mod.tempfile.gettempdir())) + + +def test_default_directory_honors_xdg_state_home(tmp_path): + """XDG_STATE_HOME, when set, takes precedence over ~/.local/state.""" + import microsoft.opentelemetry.a365.core.exporters.persistent_storage as _mod + + xdg = tmp_path / "xdg" + with patch.object(_mod.sys, "platform", "linux"), patch.dict(os.environ, {"XDG_STATE_HOME": str(xdg)}, clear=False): + resolved = _mod._resolve_default_directory() + + assert str(resolved).startswith(str(xdg)) + + +# --------------------------------------------------------------------------- +# Multiple claims respect limit +# --------------------------------------------------------------------------- + + +def test_claim_respects_limit(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + for i in range(5): + storage.store(_new_record(f'{{"i":{i}}}')) + + claimed = storage.claim(limit=3, lease_seconds=30) + assert len(claimed) == 3 + storage.close() + + +# --------------------------------------------------------------------------- +# DurableRecord.new round-trips IdentityKey fields +# --------------------------------------------------------------------------- + + +def test_durable_record_new_fields(): + key = IdentityKey( + tenant_id="myTenant", + agent_id="myAgent", + agentic_user_id="user42", + use_s2s_endpoint=True, + ) + assert list(inspect.signature(DurableRecord.new).parameters) == ["key", "payload"] + rec = DurableRecord.new(key, '{"data":1}') + assert rec.tenant_id == "myTenant" + assert rec.agent_id == "myAgent" + assert rec.agentic_user_id == "user42" + assert rec.use_s2s_endpoint is True + assert not hasattr(rec, "url") + assert rec.payload == '{"data":1}' + assert rec.record_id is None # not yet persisted + + +# --------------------------------------------------------------------------- +# delete returns False for unknown id +# --------------------------------------------------------------------------- + + +def test_delete_unknown_record_id(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + assert storage.delete(99999) is False + storage.close() + + +# --------------------------------------------------------------------------- +# release returns False for unknown id +# --------------------------------------------------------------------------- + + +def test_release_unknown_record_id(tmp_path): + storage = PersistentStorage(tmp_path, capacity_bytes=1024 * 1024, retention_seconds=3600) + assert storage.release(99999) is False + storage.close() diff --git a/tests/a365/test_replay_coordinator.py b/tests/a365/test_replay_coordinator.py new file mode 100644 index 00000000..bb6c4278 --- /dev/null +++ b/tests/a365/test_replay_coordinator.py @@ -0,0 +1,599 @@ +# Copyright (c) Microsoft Corporation. +# Licensed under the MIT License. + +"""Tests for the durable replay coordinator.""" + +from __future__ import annotations + +import threading +import time +from unittest.mock import MagicMock + +from microsoft.opentelemetry.a365.constants import A365_HTTP_TIMEOUT_SECONDS +from microsoft.opentelemetry.a365.core.exporters.durable_delivery import ( + DeliveryDisposition, + DeliveryResult, + IdentityKey, + TransmissionGate, +) +from microsoft.opentelemetry.a365.core.exporters.persistent_storage import DurableRecord +from microsoft.opentelemetry.a365.core.exporters.replay_coordinator import ( + _LEASE_SECONDS, + _MAX_RECORDS_PER_PASS, + ReplayCoordinator, + ReplayEndpointError, + ReplayIdentityError, +) + +IDENTITY = IdentityKey( + tenant_id="tenant-1", + agent_id="agent-1", + agentic_user_id=None, + use_s2s_endpoint=False, +) + + +def _record_kwargs(record_id: int, payload: str, created_at: float) -> dict[str, object]: + kwargs: dict[str, object] = { + "schema_version": 1 if "url" in DurableRecord.__dataclass_fields__ else 2, + "tenant_id": IDENTITY.tenant_id, + "agent_id": IDENTITY.agent_id, + "agentic_user_id": IDENTITY.agentic_user_id, + "use_s2s_endpoint": IDENTITY.use_s2s_endpoint, + "payload": payload, + "created_at": created_at, + "record_id": record_id, + } + if "url" in DurableRecord.__dataclass_fields__: + kwargs["url"] = "https://example.test" + return kwargs + + +RECORD = DurableRecord(**_record_kwargs(1, '{"value":1}', 1.0)) + +SECOND_RECORD = DurableRecord(**_record_kwargs(2, '{"value":2}', 2.0)) + + +def _make_record(record_id: int) -> DurableRecord: + """Build a distinct durable record for backlog tests.""" + return DurableRecord(**_record_kwargs(record_id, f'{{"value":{record_id}}}', float(record_id))) + + +class FakeStorage: + """Minimal storage double used to observe replay behavior.""" + + def __init__( + self, + batches: list[list[DurableRecord]], + *, + delete_result: bool = True, + delete_results: dict[int, bool] | None = None, + ) -> None: + self._batches = [list(batch) for batch in batches] + self._delete_result = delete_result + self._delete_results = delete_results or {} + self._lock = threading.Lock() + self.block_event: threading.Event | None = None + self.claim_calls = 0 + self.claim_limits: list[int] = [] + self.claim_lease_seconds: list[float] = [] + self.deleted: list[int] = [] + self.released: list[int] = [] + + def claim(self, limit: int, lease_seconds: float) -> list[DurableRecord]: + with self._lock: + self.claim_calls += 1 + self.claim_limits.append(limit) + self.claim_lease_seconds.append(lease_seconds) + if self.block_event is not None: + self.block_event.wait() + with self._lock: + if self._batches: + return self._batches.pop(0) + return [] + + def delete(self, record_id: int) -> bool: + with self._lock: + self.deleted.append(record_id) + return self._delete_results.get(record_id, self._delete_result) + + def release(self, record_id: int) -> bool: + with self._lock: + self.released.append(record_id) + return True + + +def wait_until(predicate, timeout: float = 2.0) -> bool: + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + if predicate(): + return True + time.sleep(0.01) + return predicate() + + +def test_replay_deletes_delivered_record() -> None: + storage = FakeStorage([[RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.run_once() + + assert storage.deleted == [RECORD.record_id] + assert storage.released == [] + gate.record_success.assert_called_once_with(IDENTITY) + + +def test_replay_lease_covers_worst_case_full_pass() -> None: + storage = FakeStorage([[RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.run_once() + + assert storage.claim_limits == [_MAX_RECORDS_PER_PASS] + assert storage.claim_lease_seconds == [_LEASE_SECONDS] + assert _LEASE_SECONDS > _MAX_RECORDS_PER_PASS * A365_HTTP_TIMEOUT_SECONDS + + +def test_replay_retains_retryable_record_and_updates_gate() -> None: + storage = FakeStorage([[RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.RETRYABLE, retry_after=45), + ) + + coordinator.run_once() + + assert storage.released == [RECORD.record_id] + assert storage.deleted == [] + gate.record_retryable_failure.assert_called_once_with(IDENTITY, 45) + + +def test_replay_deletes_permanent_record() -> None: + storage = FakeStorage([[RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.PERMANENT), + ) + + coordinator.run_once() + + assert storage.deleted == [RECORD.record_id] + assert storage.released == [] + gate.record_success.assert_called_once_with(IDENTITY) + + +def test_delete_failure_after_success_logs_duplicate_risk(caplog) -> None: + storage = FakeStorage([[RECORD]], delete_result=False) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.run_once() + + assert "duplicate delivery" in caplog.text.lower() + gate.record_success.assert_called_once_with(IDENTITY) + + +def test_full_batch_delete_failure_after_delivered_records_returns_false() -> None: + full_batch = [_make_record(i) for i in range(1, 11)] + failed_record_id = full_batch[-1].record_id + assert failed_record_id is not None + storage = FakeStorage([full_batch], delete_results={failed_record_id: False}) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + assert coordinator.run_once() is False + assert len(storage.deleted) == 10 + + +def test_delete_failure_after_permanent_logs_poison_record_risk(caplog) -> None: + storage = FakeStorage([[RECORD]], delete_result=False) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.PERMANENT), + ) + + coordinator.run_once() + + assert "poison record may recur" in caplog.text.lower() + gate.record_success.assert_called_once_with(IDENTITY) + + +def test_full_batch_delete_failure_after_permanent_records_returns_false() -> None: + full_batch = [_make_record(i) for i in range(1, 11)] + failed_record_id = full_batch[0].record_id + assert failed_record_id is not None + storage = FakeStorage([full_batch], delete_results={failed_record_id: False}) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.PERMANENT), + ) + + assert coordinator.run_once() is False + assert len(storage.deleted) == 10 + + +def test_endpoint_error_retains_record_and_stops_pass(caplog) -> None: + storage = FakeStorage([[RECORD, SECOND_RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + + def send(record: DurableRecord) -> DeliveryResult: + if record.record_id == RECORD.record_id: + raise ReplayEndpointError("invalid replay endpoint") + return DeliveryResult(DeliveryDisposition.DELIVERED) + + coordinator = ReplayCoordinator(storage, gate, send=send) + + assert coordinator.run_once() is False + assert storage.deleted == [] + assert storage.released == [RECORD.record_id, SECOND_RECORD.record_id] + assert "unexpected error during replay" not in caplog.text.lower() + gate.release_probe.assert_called_once_with(IDENTITY) + + +def test_replay_releases_record_when_identity_error_and_continues() -> None: + """ReplayIdentityError: release current record and continue the batch.""" + storage = FakeStorage([[RECORD, SECOND_RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + + def send(record: DurableRecord) -> DeliveryResult: + if record.record_id == RECORD.record_id: + raise ReplayIdentityError("token resolution failed") + return DeliveryResult(DeliveryDisposition.DELIVERED) + + coordinator = ReplayCoordinator(storage, gate, send=send) + + coordinator.run_once() + + assert storage.released == [RECORD.record_id] + assert storage.deleted == [SECOND_RECORD.record_id] + gate.release_probe.assert_called_once_with(IDENTITY) + + +def test_general_exception_releases_current_and_remaining_and_stops() -> None: + """Unexpected exceptions: release current + remaining records and stop the pass.""" + storage = FakeStorage([[RECORD, SECOND_RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + + def send(record: DurableRecord) -> DeliveryResult: + if record.record_id == RECORD.record_id: + raise RuntimeError("unexpected crash") + return DeliveryResult(DeliveryDisposition.DELIVERED) + + coordinator = ReplayCoordinator(storage, gate, send=send) + + coordinator.run_once() + + assert RECORD.record_id in storage.released + assert SECOND_RECORD.record_id in storage.released + assert storage.deleted == [] + gate.release_probe.assert_called_once_with(IDENTITY) + + +def test_run_once_claims_at_most_ten_records() -> None: + storage = FakeStorage([[RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator(storage, gate, send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED)) + + coordinator.run_once() + + assert storage.claim_limits == [10] + + +def test_start_and_wake_process_a_later_batch() -> None: + storage = FakeStorage([[], [RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.start() + try: + assert wait_until(lambda: storage.claim_calls >= 1) + assert storage.deleted == [] + + coordinator.wake() + + assert wait_until(lambda: storage.deleted == [RECORD.record_id]) + finally: + coordinator.shutdown(1.0) + + +def test_shutdown_is_bounded_and_idempotent() -> None: + storage = FakeStorage([[RECORD]]) + storage.block_event = threading.Event() + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.start() + try: + assert wait_until(lambda: storage.claim_calls >= 1) + + started = time.monotonic() + assert coordinator.shutdown(0.05) is False + assert time.monotonic() - started < 0.5 + + storage.block_event.set() + assert wait_until(lambda: coordinator.shutdown(1.0)) + assert coordinator.shutdown(0.05) is True + finally: + storage.block_event.set() + coordinator.shutdown(1.0) + + +def test_shutdown_default_timeout_waits_unbounded_for_active_work() -> None: + """shutdown() with no argument (the new default) must block until the + thread actually exits, not return early while replay work is active.""" + storage = FakeStorage([[RECORD]]) + storage.block_event = threading.Event() + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.start() + try: + assert wait_until(lambda: storage.claim_calls >= 1) + + result: dict[str, bool] = {} + + def call_default_shutdown() -> None: + result["stopped"] = coordinator.shutdown() + + shutdown_thread = threading.Thread(target=call_default_shutdown) + shutdown_thread.start() + + # The replay thread is still blocked inside claim(); the unbounded + # shutdown() call must still be waiting, not have returned already. + time.sleep(0.2) + assert shutdown_thread.is_alive() + + storage.block_event.set() + shutdown_thread.join(2.0) + assert not shutdown_thread.is_alive() + assert result["stopped"] is True + finally: + storage.block_event.set() + coordinator.shutdown(1.0) + + +def test_gate_blocked_releases_record_without_send() -> None: + """When the gate blocks an identity, the record is released without calling send.""" + storage = FakeStorage([[RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = False + send = MagicMock() + coordinator = ReplayCoordinator(storage, gate, send=send) + + coordinator.run_once() + + assert storage.released == [RECORD.record_id] + assert storage.deleted == [] + send.assert_not_called() + + +def test_start_after_shutdown_is_safe_noop() -> None: + """Calling start() after shutdown() is a safe no-op: no new thread is spawned.""" + storage = FakeStorage([[]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.start() + coordinator.shutdown(1.0) + thread_before = coordinator._thread + + # start() after shutdown must not raise and must not spawn a new thread + coordinator.start() + + assert coordinator._thread is thread_before + + +def test_mid_batch_stop_releases_remaining_records() -> None: + """When stop_event fires mid-batch, all un-processed records are released.""" + storage = FakeStorage([[RECORD, SECOND_RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + # Simulate stop being set before the first record is processed + coordinator._stop_event.set() + + coordinator.run_once() + + assert RECORD.record_id in storage.released + assert SECOND_RECORD.record_id in storage.released + assert storage.deleted == [] + + +def test_run_once_requests_continuation_after_full_pass() -> None: + """A fully-drained maximal batch signals that more records may remain.""" + full_batch = [_make_record(i) for i in range(1, 11)] # exactly 10 + storage = FakeStorage([full_batch]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + assert coordinator.run_once() is True + assert len(storage.deleted) == 10 + + +def test_run_once_does_not_request_continuation_for_partial_pass() -> None: + """A batch smaller than the pass cap does not request an immediate re-run.""" + storage = FakeStorage([[RECORD, SECOND_RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + assert coordinator.run_once() is False + + +def test_run_once_no_continuation_when_full_pass_gate_blocked() -> None: + """A full batch that is entirely gate-blocked must NOT request continuation, + otherwise the loop would busy-spin re-claiming the same records.""" + full_batch = [_make_record(i) for i in range(1, 11)] + storage = FakeStorage([full_batch]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = False # every record is gate-blocked + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + assert coordinator.run_once() is False + assert len(storage.released) == 10 + assert storage.deleted == [] + + +def test_start_drains_backlog_larger_than_one_pass() -> None: + """A startup backlog larger than one pass is fully drained after a wake, + not left at >10 records until the next external wake.""" + first = [_make_record(i) for i in range(1, 11)] # 10 records + second = [_make_record(i) for i in range(11, 16)] # 5 records + storage = FakeStorage([first, second]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + ) + + coordinator.start() + try: + assert wait_until(lambda: len(storage.deleted) == 15) + finally: + coordinator.shutdown(1.0) + + +def test_periodic_wake_processes_backlog_without_external_wake() -> None: + """A fixed periodic wake re-runs a pass even without an explicit wake(), + so records left behind are eventually drained on the background cadence.""" + # First pass claims nothing; a record only becomes available on the second + # pass, which must be triggered by the periodic timeout (no wake() call). + storage = FakeStorage([[], [RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + poll_interval_seconds=0.05, + ) + + coordinator.start() + try: + # No coordinator.wake() here: only the periodic timeout can drive the + # second pass that deletes the record. + assert wait_until(lambda: storage.deleted == [RECORD.record_id]) + finally: + coordinator.shutdown(1.0) + + +# --------------------------------------------------------------------------- +# Regression test: unexpected exception from run_once must not kill the thread +# --------------------------------------------------------------------------- + + +def test_run_loop_survives_unexpected_exception_from_run_once() -> None: + """An unexpected exception raised inside _run_loop (outside run_once's own + broad-except) must be caught and logged so the replay thread stays alive. + + The test monkey-patches the coordinator instance's run_once to throw a + RuntimeError on the first call, then verifies the thread still delivers a + record on the next periodic wake. + """ + calls: list[int] = [] + storage = FakeStorage([[], [RECORD]]) + gate = MagicMock(spec=TransmissionGate) + gate.try_acquire.return_value = True + + original_run_once = ReplayCoordinator.run_once + + def patched_run_once(self: ReplayCoordinator) -> bool: + calls.append(1) + if len(calls) == 1: + raise RuntimeError("injected fault in run_once") + return original_run_once(self) + + coordinator = ReplayCoordinator( + storage, + gate, + send=lambda record: DeliveryResult(DeliveryDisposition.DELIVERED), + poll_interval_seconds=0.05, + ) + coordinator.run_once = patched_run_once.__get__(coordinator, ReplayCoordinator) # type: ignore[method-assign] + + coordinator.start() + try: + # The thread must survive the injected fault and process the second pass. + assert wait_until( + lambda: storage.deleted == [RECORD.record_id], timeout=3.0 + ), "replay thread did not recover after unexpected exception from run_once" + finally: + coordinator.shutdown(1.0) diff --git a/tests/a365/test_utils.py b/tests/a365/test_utils.py index a967c53c..ab7d3879 100644 --- a/tests/a365/test_utils.py +++ b/tests/a365/test_utils.py @@ -3,6 +3,7 @@ import os import unittest +from datetime import datetime, timezone from unittest.mock import MagicMock from opentelemetry.trace import SpanKind, StatusCode @@ -215,8 +216,15 @@ def test_float(self): def test_absent(self): self.assertIsNone(parse_retry_after({})) - def test_http_date_ignored(self): - self.assertIsNone(parse_retry_after({"Retry-After": "Wed, 21 Oct 2025 07:28:00 GMT"})) + def test_http_date_is_converted_to_relative_seconds(self): + now = datetime(2026, 8, 14, 18, 0, tzinfo=timezone.utc) + headers = {"Retry-After": "Fri, 14 Aug 2026 18:00:42 GMT"} + self.assertEqual(parse_retry_after(headers, now=lambda: now), 42.0) + + def test_past_http_date_returns_non_positive_delta(self): + now = datetime(2026, 8, 14, 18, 1, tzinfo=timezone.utc) + headers = {"Retry-After": "Fri, 14 Aug 2026 18:00:42 GMT"} + self.assertEqual(parse_retry_after(headers, now=lambda: now), -18.0) class TestIsAgent365ExporterEnabled(unittest.TestCase): diff --git a/tests/test_distro.py b/tests/test_distro.py index ba037d58..b0518ddf 100644 --- a/tests/test_distro.py +++ b/tests/test_distro.py @@ -798,11 +798,198 @@ def test_all_batch_kwargs_forwarded_together(self): # Always-forwarded enriching kwarg is preserved. self.assertIn("suppress_invoke_agent_input", proc_kwargs) - def test_zero_value_is_forwarded(self): - """Falsy-but-not-None integer values must still be forwarded (not dropped).""" - proc_kwargs = self._build(max_queue_size=0, max_export_batch_size=0) - self.assertEqual(proc_kwargs["max_queue_size"], 0) - self.assertEqual(proc_kwargs["max_export_batch_size"], 0) + def test_none_values_are_not_forwarded(self): + """Explicit None values preserve BatchSpanProcessor defaults.""" + proc_kwargs = self._build( + max_queue_size=None, + scheduled_delay_ms=None, + exporter_timeout_ms=None, + max_export_batch_size=None, + ) + self.assertNotIn("max_queue_size", proc_kwargs) + self.assertNotIn("schedule_delay_millis", proc_kwargs) + self.assertNotIn("export_timeout_millis", proc_kwargs) + self.assertNotIn("max_export_batch_size", proc_kwargs) + + def test_invalid_batch_kwargs_raise_value_error(self): + for kwargs in ( + {"max_queue_size": 0}, + {"scheduled_delay_ms": 0}, + {"max_export_batch_size": 0}, + {"max_queue_size": 10, "max_export_batch_size": 11}, + ): + with self.subTest(kwargs=kwargs): + with self.assertRaises(ValueError): + self._build(**kwargs) + + @patch.dict(os.environ, {}, clear=True) + def test_queue_smaller_than_default_batch_raises_value_error(self): + with self.assertRaises(ValueError): + self._build(max_queue_size=256) + + @patch.dict( + os.environ, + { + "OTEL_BSP_MAX_QUEUE_SIZE": "256", + "OTEL_BSP_MAX_EXPORT_BATCH_SIZE": "512", + }, + clear=True, + ) + def test_conflicting_environment_batch_defaults_raise_value_error(self): + with self.assertRaises(ValueError): + self._build() + + @patch.dict( + os.environ, + { + "OTEL_BSP_MAX_QUEUE_SIZE": "invalid", + "OTEL_BSP_MAX_EXPORT_BATCH_SIZE": "256", + }, + clear=True, + ) + def test_invalid_environment_queue_uses_valid_default(self): + self._build() + + +class TestA365OfflineStorageKwargs(unittest.TestCase): + """Tests for a365_exporter_disable_offline_storage and a365_exporter_storage_directory.""" + + @patch("microsoft.opentelemetry._sdkstats._network_metrics.register_network_gauges") + @patch("microsoft.opentelemetry._distro._setup_logging") + @patch("microsoft.opentelemetry._distro._setup_metrics") + @patch("microsoft.opentelemetry._distro._setup_tracing") + @patch("microsoft.opentelemetry._distro._append_a365_components") + def test_disable_offline_storage_forwarded_to_append_a365(self, a365_mock, *_): + """a365_exporter_disable_offline_storage is parsed and forwarded to _append_a365_components.""" + use_microsoft_opentelemetry( + enable_a365=True, + a365_exporter_disable_offline_storage=True, + ) + a365_mock.assert_called_once() + _, kwargs = a365_mock.call_args + self.assertTrue(kwargs["disable_offline_storage"]) + + @patch("microsoft.opentelemetry._sdkstats._network_metrics.register_network_gauges") + @patch("microsoft.opentelemetry._distro._setup_logging") + @patch("microsoft.opentelemetry._distro._setup_metrics") + @patch("microsoft.opentelemetry._distro._setup_tracing") + @patch("microsoft.opentelemetry._distro._append_a365_components") + def test_storage_directory_forwarded_to_append_a365(self, a365_mock, *_): + """a365_exporter_storage_directory is parsed and forwarded to _append_a365_components.""" + use_microsoft_opentelemetry( + enable_a365=True, + a365_exporter_storage_directory="C:\\telemetry", + ) + a365_mock.assert_called_once() + _, kwargs = a365_mock.call_args + self.assertEqual(kwargs["storage_directory"], "C:\\telemetry") + + @patch("microsoft.opentelemetry._sdkstats._network_metrics.register_network_gauges") + @patch("microsoft.opentelemetry._distro._setup_logging") + @patch("microsoft.opentelemetry._distro._setup_metrics") + @patch("microsoft.opentelemetry._distro._setup_tracing") + @patch("microsoft.opentelemetry._distro._append_a365_components") + def test_offline_storage_kwargs_default_to_none(self, a365_mock, *_): + """Defaults: disable_offline_storage=False, storage_directory=None.""" + use_microsoft_opentelemetry(enable_a365=True) + a365_mock.assert_called_once() + _, kwargs = a365_mock.call_args + self.assertFalse(kwargs["disable_offline_storage"]) + self.assertIsNone(kwargs["storage_directory"]) + + @patch("microsoft.opentelemetry._sdkstats._network_metrics.register_network_gauges") + @patch("microsoft.opentelemetry._distro._setup_logging") + @patch("microsoft.opentelemetry._distro._setup_metrics") + @patch("microsoft.opentelemetry._distro._setup_tracing") + @patch("microsoft.opentelemetry._distro._append_a365_components") + def test_offline_storage_kwargs_not_leaked_to_otel(self, a365_mock, *_): + """a365_exporter_disable_offline_storage/storage_directory do not appear in otel_kwargs.""" + use_microsoft_opentelemetry( + enable_a365=True, + a365_exporter_disable_offline_storage=True, + a365_exporter_storage_directory="C:\\telemetry", + ) + otel_kwargs = a365_mock.call_args[0][1] + self.assertNotIn("a365_exporter_disable_offline_storage", otel_kwargs) + self.assertNotIn("a365_exporter_storage_directory", otel_kwargs) + self.assertNotIn("disable_offline_storage", otel_kwargs) + self.assertNotIn("storage_directory", otel_kwargs) + + @patch("microsoft.opentelemetry.a365.core.exporters.utils._create_default_token_resolver") + def test_disable_offline_storage_true_disables_durable_delivery(self, default_resolver_mock): + """disable_offline_storage=True maps to enable_durable_delivery=False on _Agent365Exporter.""" + default_resolver_mock.return_value = lambda aid, tid: "token" + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + otel_kwargs = {"span_processors": []} + _append_a365_components( + True, + otel_kwargs, + enable_observability_exporter=True, + disable_offline_storage=True, + ) + _, exporter_kwargs = exporter_mock.call_args + self.assertFalse(exporter_kwargs["enable_durable_delivery"]) + + @patch("microsoft.opentelemetry.a365.core.exporters.utils._create_default_token_resolver") + def test_disable_offline_storage_false_enables_durable_delivery(self, default_resolver_mock): + """disable_offline_storage=False (default) maps to enable_durable_delivery=True.""" + default_resolver_mock.return_value = lambda aid, tid: "token" + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + otel_kwargs = {"span_processors": []} + _append_a365_components( + True, + otel_kwargs, + enable_observability_exporter=True, + disable_offline_storage=False, + ) + _, exporter_kwargs = exporter_mock.call_args + self.assertTrue(exporter_kwargs["enable_durable_delivery"]) + + @patch("microsoft.opentelemetry.a365.core.exporters.utils._create_default_token_resolver") + def test_storage_directory_passed_to_exporter(self, default_resolver_mock): + """storage_directory kwarg is forwarded to _Agent365Exporter as a Path.""" + from pathlib import Path + + default_resolver_mock.return_value = lambda aid, tid: "token" + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + otel_kwargs = {"span_processors": []} + _append_a365_components( + True, + otel_kwargs, + enable_observability_exporter=True, + storage_directory="C:\\telemetry", + ) + _, exporter_kwargs = exporter_mock.call_args + self.assertEqual(exporter_kwargs["storage_directory"], Path("C:\\telemetry")) + + @patch("microsoft.opentelemetry.a365.core.exporters.utils._create_default_token_resolver") + def test_storage_directory_none_by_default(self, default_resolver_mock): + """storage_directory defaults to None when not provided.""" + default_resolver_mock.return_value = lambda aid, tid: "token" + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter") as exporter_mock: + otel_kwargs = {"span_processors": []} + _append_a365_components( + True, + otel_kwargs, + enable_observability_exporter=True, + ) + _, exporter_kwargs = exporter_mock.call_args + self.assertIsNone(exporter_kwargs["storage_directory"]) + + @patch("microsoft.opentelemetry.a365.core.exporters.utils._create_default_token_resolver") + def test_empty_storage_directory_raises_value_error(self, default_resolver_mock): + """An explicitly empty storage_directory must raise ValueError rather + than silently defaulting to the platform path.""" + default_resolver_mock.return_value = lambda aid, tid: "token" + with patch("microsoft.opentelemetry.a365.core.exporters.agent365_exporter._Agent365Exporter"): + otel_kwargs = {"span_processors": []} + with self.assertRaises(ValueError): + _append_a365_components( + True, + otel_kwargs, + enable_observability_exporter=True, + storage_directory="", + ) class TestA365Components(unittest.TestCase):