fix(tracing): enforce the OTEL flush timeout, and document ORQ_OTEL_* batching - #169
fix(tracing): enforce the OTEL flush timeout, and document ORQ_OTEL_* batching#169Baukebrenninkmeijer wants to merge 11 commits into
Conversation
Add a 'Batching and flush' section to the Tracing page covering the four BatchSpanProcessor tuning env vars (ORQ_OTEL_MAX_QUEUE_SIZE, ORQ_OTEL_MAX_BATCH_SIZE, ORQ_OTEL_SCHEDULE_DELAY_MS, ORQ_OTEL_FLUSH_TIMEOUT_MS), previously documented only in the tracing/setup.py docstring. Explains queue-overflow and exit-before-flush span loss and gives a runnable CI configuration.
Apply review feedback: correct the per-run vs init read timing of ORQ_OTEL_FLUSH_TIMEOUT_MS, quote the flush warning verbatim, drop duplicated prose (BatchSpanProcessor restatement, ORQ_DEBUG tip, second example), add silent-overflow detection guidance, and list the four vars in configuration.md's canonical env-var table with cross-references. Records the docs-autofill ledger row for this attempt.
|
The The failing job died in ~16s at the "Run Claude Code Action" step with All checks relevant to this docs-only change are passing: Build (strict), Lint, Examples (static), and SDK compatibility. Leaving Generated by Claude Code |
Coverage reportClick to see where and how coverage changed
This report was generated by python-coverage-comment-action |
||||||||||||||||||||||||
currentlycodinng
left a comment
There was a problem hiding this comment.
Verified this against src/evaluatorq/tracing/setup.py on the PR branch (feb073f), not just the diff.
Var names and defaults, all exact matches:
- ORQ_OTEL_MAX_QUEUE_SIZE, default 4096 (setup.py:214)
- ORQ_OTEL_MAX_BATCH_SIZE, default 512 (setup.py:215)
- ORQ_OTEL_SCHEDULE_DELAY_MS, default 5000 (setup.py:219)
- ORQ_OTEL_FLUSH_TIMEOUT_MS, default 5000 (setup.py:259)
Read timing: docs say the first three are read "at init," the fourth "per run." Confirmed, the first three are only read inside init_tracing_if_needed(), gated by _initialization_attempted and runs once per process; ORQ_OTEL_FLUSH_TIMEOUT_MS is read fresh in flush_tracing() every call (setup.py:259). Correct.
Batch-size clamping: docs say ORQ_OTEL_MAX_BATCH_SIZE is "clamped down to the queue size." setup.py:220 does exactly that: max_export_batch_size=min(requested_batch_size, max_queue_size). This isn't cosmetic, the underlying otel-sdk BatchSpanProcessor raises ValueError if batch size exceeds queue size, so the clamp is load-bearing, not just tidiness. tests/common/test_tracing_lifecycle.py:197-206 exercises this directly: MAX_BATCH_SIZE=200 with MAX_QUEUE_SIZE=100 asserts max_export_batch_size == 100. Docs match.
Invalid-value fallback: docs say a non-numeric or non-positive value logs a WARNING and falls back to default. Matches _env_int() at setup.py:51-68 exactly (the ValueError branch and the value <= 0 branch both warn and return default).
Silent queue overflow: docs say overflow drops spans with no log and no exception. Confirmed at the otel-sdk level, its queue is a collections.deque(maxlen=...) that evicts silently on append. The doc's "no first-party signal" framing is accurate.
Flush timeout warning text: docs quote it verbatim as "OTEL span flush timed out after ms; some spans may not have been exported." Matches the logger.warning() format string at setup.py:263-266 character for character.
No stray vars either direction: grepped ORQ_OTEL_ across src/ and tests/, the only hits outside tracing/setup.py and tracing/context.py are the four in tests/common/test_tracing_lifecycle.py exercising these same four vars. Nothing documented that doesn't exist in code, nothing in code left undocumented.
configuration.md changes are consistent with tracing.md and don't duplicate content, just cross-reference it. All internal anchors resolve to real headings.
CI green except claude-review, the known-flaky bot check, not the diff's fault.
Approving.
`_env_int` used a falsy check on the raw env value, so a set-but-empty
variable took the same silent path as an unset one. That is the exact
shape a CI `env:` block produces when `${{ vars.X }}` does not resolve,
so the tuning knob the tracing docs recommend for CI could be disabled
with no signal at all. Treat empty (and whitespace-only) as
set-but-invalid: warn and fall back, like every other rejected value.
`max_export_batch_size` was clamped to the queue size with a bare
`min()` next to a helper that warns on every rejected value — two
adjacent branches differing in whether they log, which is what the
"a degraded path announces itself" rule exists to prevent. It now warns.
Tests: pin the three documented batching defaults (4096/512/5000) where
they are actually consumed, so a change to the literals fails instead of
silently contradicting docs/tracing.md; add the empty and whitespace
cases to the `_env_int` parametrizations; assert the clamp warning.
The processor-faking scaffolding moves into `_fake_tracing_sdk` rather
than being copied for the second case.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The section asserted that queue overflow is completely silent and has "no first-party signal", so the only remedy it offered was hand-counting spans in the Orq trace UI. The SDK logs `Queue full, dropping Span.` on the stdlib `opentelemetry` logger (verified against the pinned 1.42.1 with a blocking exporter), deduplicated per process. It also evicts the *oldest* buffered span, not the newest, so a truncated trace is missing its early spans — the opposite of what the page implied. Other corrections and additions: - Both failure modes log; neither is silent. Reframed accordingly, and the second flush warning (`OTEL span flush failed (...)`) is documented alongside the timeout one it shares a code path with. - State the flush guarantee rather than the mechanism: `simulate()` flushes in its own teardown, not via `tracing_session`, so naming the session was drift bait even though the outcome is the same. - Sizing: the queue drains continuously, so raising it buys stall tolerance, not capacity. Gives the practitioner an actual formula instead of "raise it if the counts disagree". - The per-request export timeout is a fixed 5s and is not the flush timeout; three different "5 seconds" sat within 45 lines undisambiguated. - The SDK's own `OTEL_BSP_*` variables are inert here. - Adds the YAML `env:` block the prose promised, and a note that the flush timeout bounds wall-clock added to the job. - Drops the four-row table: `configuration.md` is the canonical env-var reference, and the page's existing `OTEL_EXPORTER_OTLP_*` bullets already follow that one-directional precedent. Also drops the opening and closing paragraphs, which restated bullets six lines away. - A scale boundary for readers on `deployment:` targets, and a discovery path from the symptom: an FAQ entry and a link from `dashboard.md`, the long-lived host the section is about. `axes.md` gains the ledger convention for Tier-1 gaps — they are not matrix cells, and the row recorded a `surface` value that does not exist, which next week's free-text dedupe would never match. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…e batching docs A Codex fact-check pass over every claim in the batching section against the installed SDK found the variable did nothing and three of the surrounding statements were wrong. `BatchProcessor.force_flush` ignores its `timeout_millis` argument and unconditionally returns `True` (upstream issue #4568), so passing `ORQ_OTEL_FLUSH_TIMEOUT_MS` down bounded nothing and the `ok is False` warning branch was unreachable. A run whose collector had stopped responding waited for the export to finish however long that took — the opposite of what the docs promised. `flush_tracing` now wraps the call in `asyncio.wait_for`, so the timeout is real and the warning fires. The exporter thread is a daemon and keeps draining behind it, which the docstring says. Doc corrections, each verified against source: - The processor does not export on a fixed cadence. `emit` wakes the worker the moment the queue reaches `max_export_batch_size`, which then drains while the queue stays above the threshold; the schedule delay is the idle timer for a *partial* batch. So the old "512 spans per 5 seconds" arithmetic, and the advice to lower the schedule delay under a burst, were both wrong. Rewritten around what the worker actually does. - The overflow warning is on `opentelemetry.sdk._shared_internal`, not a bare `opentelemetry` logger, and its `DuplicateFilter` dedupes in 20-second buckets rather than once per process. - The flush guarantee is narrower than "every call, including on failure": validation that fails before the tracing scope opens does not flush, and the standalone pairwise entry points never do. A hard `SIGKILL` drops the buffer with no warning, which the FAQ entry claimed otherwise. - The dashboard paragraph is removed outright: `eq dashboard` reads saved reports and manifests and never initializes tracing, so it has no span queue to share. The same wrong example is dropped from `setup.py`'s comment. - `docs/faq.md` said `datapoint_parallelism` defaults to 10 "everywhere"; the adaptive red-team pipeline defaults to 5. Style, from a corpus check rather than taste: `›` for section breadcrumbs in link labels (8 existing uses, no `→`), `**Label** —` list labels (31 existing uses, no `**Label.**`), and "warning" as prose rather than `WARNING` as an identifier. Long sentences split; the announce-the-next-sentence lines cut. Tests: assert an all-default initialization does not trip the clamp warning (it was conditional and unpinned), and assert a hanging force-flush is bounded and warns. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Both defects are contradicted by `redteam/tracing.py`'s own module docstring,
which the page was written against but drifted from.
- The tree drew `orq.redteam.security_evaluation` between `orq.evaluation` and
the judge's LLM span. That span does not exist: the OWASP scorer calls
`annotate_current_span`, tagging the framework's `orq.evaluation` span in
place, precisely to avoid that layer.
- `attack_turn`, `adversarial_generation`, `context_retrieval` and
`datapoint_generation` were shown as the general red-team shape. Static mode
is single-shot and emits none of them. The page now shows both trees and says
which mode each belongs to.
- Judge LLM spans were documented as `chat {model}` in the red-team tree, the
jury tree and the trace-context seam paragraph. `EvaluatorConfig.api` defaults
to `'responses'` (the endpoint the Orq router prices), so the span is normally
`responses {provider}/{model}`; `chat` is the fallback. `gen_ai.operation.name`
documented both values.
`annotate_current_span`'s docstring said "the judge `chat` span" for the same
reason and is updated with it.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…tching # Conflicts: # .claude/skills/docs-coverage/axes.md # CHANGELOG.md
Puts the four-variable reference back on the tracing page, where a reader tuning span export actually is. It earns its place against the canonical table in configuration.md by carrying two columns that one cannot: when each value is read (at init versus per run), and which direction to move it and on what signal. The prose that previously carried those facts in narrative form is shorter for it. Paragraphs are one line each, matching the reflow main applied to docs-coverage/axes.md, and leaving diffs on a sentence edit instead of a reflowed block. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
comment-scrub over the added comments: the batch-processor comment drops from four lines to two, and the test's export-guard note to one. Two one-line test comments stay; each says why an assertion exists, which the assertion cannot. humanizer over the added prose: "a typo neither disables tracing nor takes effect unnoticed" was a negative parallelism and now says what does happen; "What survives none of that is..." was written as a closing line rather than a statement; and two sentences that announced their own inference say it plainly. Em dashes are kept deliberately. The skill treats them as a hard cut, but its voice-calibration rule puts a writing sample above that, and the corpus is the sample: 777 across docs/, and this section sits below the density of tuning.md or guides/red-teaming.md. Stripping them here alone would make the section read as though a different person wrote it. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
One line per paragraph, list item and admonition body. Whitespace only: the word-level diff is empty. Code fences and tables are untouched.
…tching Resolves the only conflict, an append collision in the docs-autofill ledger: #165 and this branch each added a row after the same header. Both rows are kept, in date order, per the ledger's own 'never delete a row' rule.
89f0e68 to
5cd288b
Compare
What this covers
Documents the four OpenTelemetry
BatchSpanProcessortuning environment variables —ORQ_OTEL_MAX_QUEUE_SIZE,ORQ_OTEL_MAX_BATCH_SIZE,ORQ_OTEL_SCHEDULE_DELAY_MS,ORQ_OTEL_FLUSH_TIMEOUT_MS— which previously existed only in thesrc/evaluatorq/tracing/setup.pydocstring, i.e. the generated API reference, whichdocs-coveragedoes not count as discovery (Tier 1: every env var needs prose).Writing that prose surfaced defects in the code it described, so the PR grew a
fix(tracing):half. The scope is wider than the docs-autofill routine's default and is described below.
Docs
A "Batching and flush" section in
docs/tracing.md, covering how the processor queues anddrains spans, the two ways spans are silently lost, what each variable actually controls and when
it is read, and a CI recipe in both shell and GitHub Actions form. The four variables are added to
the canonical env-var table in
docs/configuration.md, and an FAQ entry gives the symptom("some spans are missing from my traces") a discovery path.
Two pre-existing inaccuracies in the same page are corrected: the red-team span tree drew an
orq.redteam.security_evaluationspan that does not exist, and showed the multi-turn spans(
attack_turn,adversarial_generation,context_retrieval,datapoint_generation) as thegeneral shape when static mode emits none of them. Judge LLM spans were documented as
chat {model};EvaluatorConfig.apidefaults to'responses'.Code
Three behaviour fixes, each one a claim the docs could not have made truthfully otherwise:
ORQ_OTEL_FLUSH_TIMEOUT_MSdid nothing.BatchProcessor.force_flushignores itstimeout_millisargument and unconditionally returnsTrue(open-telemetry/opentelemetry-python#4568),
so the value was passed down and discarded and the timeout-warning branch was unreachable. A run
whose collector stopped responding waited for the export to finish, however long that took.
flush_tracingnow enforces the bound withasyncio.wait_for._env_intused a falsy check, soORQ_OTEL_MAX_QUEUE_SIZE=""— what an unresolved workflow variable expands to in a CIenv:block — took the same path as an unset variable. Empty and whitespace-only now warn like every
other rejected value.
max_export_batch_sizewas clamped to the queue size with abare
min()next to a helper that warns on every rejected value: two adjacent branches differingin whether they log, which is what the "a degraded path announces itself" house rule exists to
prevent. It warns now.
Verification
uv run ruff check srcuv run ruff format --check srcuv run basedpyrightuv run pytest -m 'not integration'uv run --group docs mkdocs build --strictuv run python scripts/validate_mermaid.pymermaid OK — 39 file(s)CI's lint/typecheck/test jobs run on every PR (neither
ci.ymlnordocs.ymlhas apaths:filter) and are listed here because this PR now changes
src/. The job that gates the docs half isDocs / Build (strict).Behaviour claimed in prose is pinned by tests rather than asserted:
4096/512/5000) are asserted where the processor consumesthem, so changing the literals fails instead of silently contradicting the page;
_env_int's empty and whitespace cases are in both parametrizations.The two live claims that prompted the corrections were reproduced directly against the pinned SDK
(1.42.1):
WARNING:opentelemetry.sdk._shared_internal:Queue full, dropping Span.from amax_queue_size=2processor with a blocking exporter, andORQ_OTEL_MAX_QUEUE_SIZE= → default 4096, no warningbefore the fix.Review
Reviewed by two rounds of parallel agents, both read-only:
repo standards, structure). Four of five independently flagged the same Critical defect — the
section claimed queue overflow had "no first-party signal" and sent readers to hand-count spans
in the Orq trace UI, when the SDK logs on every drop.
gpt-5.6-luna, read-only): four writing lenses plus two fact-checkers thatvalidated every assertion in the changed pages against source. They found the
force_flushno-op, the wrong drain model (the worker wakes immediately at the batch threshold, so the
"512 spans per 5 seconds" arithmetic and the advice to lower the schedule delay under a burst
were both wrong), the wrong logger name and dedup window, and a
dashboard.mdparagraphasserting a shared tracer provider for a process that never initializes tracing.
Every finding was verified against source before being acted on. Two house-voice claims were
checked and rejected: the corpus is majority American spelling (
behavior19 /behaviour4),and statement-form FAQ headings already exist. Two were checked and applied:
›for sectionbreadcrumbs in link labels (8 existing uses, no
→) and**Label** —for list labels (31 existinguses, no
**Label.**).Scope
Beyond the routine's default "one section on an existing page":
docs/configuration.md— the gap is not closed unless the canonical env-var reference lists thevariables, or next week's
docs-coveragere-derives the same gap.docs/faq.md,docs/dashboard.md— discovery path from the symptom..claude/skills/docs-coverage/axes.md— the ledger row named asurfacevalue that does notexist. Env vars are a Tier-1 obligation, not a matrix cell; the file now says how to record one so
the free-text dedupe matches.
CLAUDE.mdrequires anaxes.mdchange to land in the same PR.src/,tests/,CHANGELOG.md— the three fixes above.Follow-ups, deliberately not in this PR
docs/tracing.mdhas further pre-existing drift found by the fact-check sweep and not yetverified by hand: persona/scenario LLM calls shown without their
orq.simulation.persona_generation/scenario_generationwrappers;orq.scoredescribed asJSON when scalars go through
str(); thesingle_trace=Falseparagraph ignoring an ambientparent; the
.orq.aiauth check usingnetloc, somy.orq.ai:443is not recognised as an Orqdomain.
docs-driftruns scoped-to-diff, so it never checksconfiguration.mdwhen an env-var gap isfilled on a surface page. Handled manually here; the durable fix is a tooling change.
Opened by the weekly docs-autofill routine; scope extended during review.