Filter OpenTelemetry child spans before export [TE-6816] - #25
Conversation
|
Not sure I like adding this to the per-language layer. |
a2342b8 to
433a6e0
Compare
![buildsworth-bk-app[bot]](https://avatars.githubusercontent.com/in/3010600?s=60&v=4){kind=small}
There was a problem hiding this comment.
The new synchronous callback changes runtime behavior in the child-span export path, so this needs a human sanity-check. I found no code-level issues in this pass.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25481, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
About buildsworth
Model: gpt-5.6-sol with xhigh thinking.
How to request a review: Comment @buildsworth-bk review on the PR, or request buildsworth-bk as a reviewer.
Risk labels (how buildsworth classifies risk) — buildsworth classifies risk itself from the diff. Unless repository policy already allows L2 approval, grant it by mentioning @buildsworth-bk (see approval ceiling and L2 approval grant):
- L1 — Low risk (dep bumps, docs/copy, lockfiles, small presentational fixes). buildsworth may approve by default.
- L2 — Standard risk (new UI, additive API fields, refactors). Approved only when repository policy or a verified grant allows it; otherwise comment-only.
- L3 — High risk (auth, migrations, payments, secrets, perf-critical pipeline paths). Human review always required.
There was a problem hiding this comment.
The latest change preserves test.execution export when the callback is invalid; I found no new code-level issues. The synchronous callback in the child-span completion path still puts this above the repository's L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25504, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
There was a problem hiding this comment.
One blocking re-entrancy issue in the child-span filter path.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25511, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
Add an opt-in otel_span_filter callback that decides which finished child spans reach the batch processor, so suites can drop fast, successful SQL and Redis spans with little diagnostic value before the bktec relay and cloud ingestion. test.execution spans use a separate provider and are never filtered. The filter is only a volume optimisation, so it can never reduce what is exported except by returning falsy: * A value that cannot be called with one span argument (non-callable, or a lambda/method with the wrong arity) is ignored with one warning at setup, and child spans are exported unfiltered. * A filter that raises retains the span; the first failure is reported and further failures are silent rather than warning per span. * The filter runs outside the forwarder lock so a slow filter cannot stall other spans, and a thread-local mark stops a filter that performs an instrumented call from recursing through its own span's on_finish until SystemStackError. Document a 200 µs PostgreSQL/Redis example, plus the concurrency and orphaned-child caveats. Co-authored-by: Paul Annesley <paul@annesley.cc>
718ff4d to
5341a6f
Compare
Previous concerns have been addressed.
There was a problem hiding this comment.
The re-entrancy issue is fixed. I left one non-blocking setup-validation edge case; the synchronous callback in the child-span completion path remains above the repository's L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25521, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
SpanFilter owns everything that keeps a suite's otel_span_filter from costing it spans: a failing or uncallable filter retains the span and warns once, and a span finished while the filter is running is retained rather than re-entering the filter. ChildSpanForwarder now only tracks and forwards. The setup-time arity check is gone: the runtime path already guarantees a bad filter never drops a span, and the check only bought an earlier message for ten lines of heuristics.
There was a problem hiding this comment.
The latest refactor keeps invalid filters fail-open and preserves the re-entrancy guard; I found no new code-level issues. The synchronous callback in the child-span completion path remains above this repository's L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25526, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
mttns
changed the title
There was a problem hiding this comment.
One blocking re-entrancy issue remains in the span-filter guard.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25532, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
Thread.current[] is fiber-local, so a filter that finished an instrumented span inside a fiber bypassed the guard and re-entered the filter. Thread variables are shared by all fibers on the thread.
Previous concerns have been addressed.
There was a problem hiding this comment.
The fiber re-entrancy concern is fixed by making the guard thread-wide, and the added regression covers that path. I found no new code-level issues; the synchronous callback in the child-span completion path remains above this repository's L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25562, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
A filter that raises per span still fails open and retains the span, but an object that cannot be called at all is a configuration mistake, so surface it as an ArgumentError like other configure options. Also fold the two span-filter re-entrancy specs into one parameterised pair, and note the fiber-scheduler consequence of the thread-wide guard.
There was a problem hiding this comment.
I found no code-level issues in the latest revision. The synchronous callback in the child-span completion path remains above this repository's L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25573, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
There was a problem hiding this comment.
I found one non-blocking shutdown interleaving in the no-filter path. Separately, the new synchronous callback in child-span completion remains above this repository’s L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review’s Buildkite build:
Download the buildsworth logs from build 25914, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
| end | ||
|
|
||
| def on_finish(span) | ||
| return unless @mutex.synchronize { @active && @spans.delete(span) } |
There was a problem hiding this comment.
Non-blocking: Splitting the old delete-and-enqueue critical section creates a no-filter regression: shutdown can acquire the mutex after this line but before the second synchronized block, set @active = false, and drop a child span that already finished. Previously on_finish held the lock through @processor.on_finish, so deactivation waited for that span to be queued. Keeping the original atomic path when SpanFilter.from returns RetainAll would preserve the promised no-option behavior while caller filters still run outside the lock.
60f602d to
acdeb87
Compare
There was a problem hiding this comment.
I found no new code-level issues in the current revision. The synchronous callback in the child-span completion path remains above this repository’s L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25919, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
Running the span filter outside the forwarder's lock split accepting a span from queueing it, so shutdown could deactivate the forwarder in between and drop a span that had already finished. That window applied even when no filter was configured, which the PR promised leaves behaviour unchanged. Without a filter, accept and queue under a single lock acquisition as before. With a filter, keep running it unlocked; a span still in its filter when shutdown runs is dropped, as documented in the forwarder. SpanFilter no longer needs a retain-everything stand-in, since the forwarder now distinguishes the two paths itself.
There was a problem hiding this comment.
The no-filter path now preserves the original atomic shutdown behavior, and I found no new code-level issues in the current revision. The synchronous callback in the child-span completion path remains above this repository’s L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25922, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
There was a problem hiding this comment.
The added regression test covers the intentional shutdown interleaving for spans still in the filter, and I found no new code-level issues. The synchronous callback in the child-span completion path keeps the change above this repository's L1 approval ceiling.
Want to dig deeper?
Paste this into your agent to explore the findings from this review's Buildkite build:
Download the buildsworth logs from build 25923, then answer my questions about the findings.
Install the reading-buildsworth-logs skill to run this.
2 participants
Why
Test Engine is ingesting very high span volume, and dogfooding shows many fast, successful SQL and Redis child spans with little diagnostic value. Ruby suites can currently disable an entire instrumentation, but cannot prune selected completed spans before the blind bktec relay and cloud ingestion path.
Related: TE-6816 tracks
db.statementbeing over-sanitized to;on the same PostgreSQL spans; this PR reduces their volume but does not change their attributes.What
otel_span_filtercallback for finished child spans before they enter the batch processor.test.executionspan path independent, and fail open by retaining a span when its filter raises.SpanFilterobject: a filter that raises or cannot be called retains the span and warns once, and a span finished while the filter is running (an instrumented call inside the filter) is retained rather than re-entering the filter. A bad filter never reduces what is exported.The callback runs after span creation, so it reduces queueing, export, and ingestion volume rather than instrumentation overhead. It runs synchronously and should return quickly.
Verification
bundle exec rspecon Ruby 3.4.10 — 187 examples, 0 failuresbundle exec rspecon Ruby 3.2.11 (no OpenTelemetry gems) — 99 examples, 0 failuresbundle exec cucumber— 1 scenario, 3 steps, all passingDeployment
No existing behavior changes unless a suite passes
otel_span_filter. Buildkite dogfood adoption is tracked in buildkite/buildkite#33479, which temporarily pins this PR's commit (needs bumping to the current head) and will return tomainafter merge.Context
https://linear.app/buildkite/issue/TE-6816/fix-dbstatement-over-sanitization-leaving-sql-spans-as-just
Rollback
Revert this PR; callers can also remove the optional filter without changing their instrumentation setup.