Skip to content

Add pluggable tuple tracing with an OpenTelemetry tracer - #9154

Open
dpol1 wants to merge 16 commits into
apache:masterfrom
dpol1:9016-otel-context
Open

dpol1 wants to merge 16 commits into
apache:masterfrom
dpol1:9016-otel-context

Conversation

@dpol1

@dpol1 dpol1 commented Oct 1, 2026 •

Copy link
Copy Markdown
Contributor

What is the purpose of the change

Part of #9016.

Storm can carry a trace context with each tuple, so a trace follows a tuple tree across bolts, threads and workers. Tracing is pluggable and off by default.

  • storm-client gets a TupleTracer SPI (org.apache.storm.tracing), selected with topology.tracing.tracer. Each worker creates one tracer and calls it on spout and bolt emits, around execute(), when a tuple tree is acked, fails or times out, when a bolt fails a tuple, and to encode and decode contexts for other workers. Storm catches runtime exceptions and linkage errors from the tracer and carries on without that call's result. It logs them at most once a minute per method. An exception from prepare() stops the worker from starting. The execute latency leaves out the tracer's calls around execute(). storm-client has no OpenTelemetry dependency.
  • external/storm-opentelemetry implements the SPI with the OpenTelemetry API. The SDK registered as the global instance, usually the Java agent on the workers, samples and exports the spans. StormTracing.context(tuple) gives bolt code the context of a tuple.

Each spout emit starts a trace, each execute() on a traced tuple runs in a child span, and an emit takes its parent from its anchors, on any thread. A join within one trace becomes a child of the first anchor, linked to the others. A join of different traces starts a new root, linked to each. For reliable spouts, a span under the root lasts from the emit to the ack, fail or timeout and carries storm.tuple.latency_ms. docs/Tracing.md has the details and the limits.

When a tracer is set, the context travels after the tuple values as a tagged entry (tag byte, varint length, bytes), inside the compressed frame. A reader that stops after the values ignores it, and a reader skips tags it does not know. Without a tracer, tuples serialize to the same bytes as today. Tuples saved in the state of stateful bolts keep no context.

New public API in storm-client: TupleTracer, Config.TOPOLOGY_TRACING_TRACER, and TupleImpl#getTraceContext/setTraceContext, typed Object. Internal classes gain public members too: Executor and WorkerState expose the worker's tracer, TupleInfo keeps the emit time of traced tuples, and KryoTupleSerializer, KryoTupleDeserializer and DeserializingConnectionCallback get constructors that take a tracer.

The binary distribution gains only the module README. It ships no module jar and no OpenTelemetry jar, so the license files do not change.

Keeping every failure at 100% sampling is out of scope; see #9155. The storm-client fast path that @GGraziadei suggested, sampling at the spout and skipping untraced emits, goes to a follow-up PR and gets measured on its own (comment).

Cost

These numbers come from my laptop (LocalCluster, one JVM), so please read them as a rough guide rather than a benchmark. I'm happy to run other setups if that helps.

Since ecdfe2f, when the sampler drops the root span of a spout emit, the tuple carries no context. The numbers below predate that commit. This comment measures it, as "this change", against 42e1430.

Latency, on 42e1430, with an async bolt and the spout at a fixed 50 k tuples/s. Against the agent with tracing off, the median barely moves (at most 0.1 ms on one worker, 0.3 ms on two). On one worker p99 goes from about 2.6 ms to 3.3–3.4 ms at ratio 0 and 1%, and to 6.6 ms at 100%; on two workers it goes from about 7 ms to 7.3–8.6 ms, and to 12.7 ms. Attaching the agent without tracing made no visible difference.

Throughput I measured before the SPI split and the rebase, on ae9c19253. The comment linked above re-measures it on 42e1430. Against the agent with tracing off, an async bolt on one worker lost about 29% of its throughput at ratio 0, 34% at 1% and 57% at 100%. JFR profiles put half to two thirds of the ratio-0 cost in the agent's API bridge (open-telemetry/opentelemetry-java-instrumentation#20340). With the agent's executors instrumentation on, its default, ratio 0 lost 67%; docs/Tracing.md says when it can be turned off. With tracing off I saw no difference from master.

At 100% the batch span processor drops most spans: 61–78% at 50 k tuples/s and 94% with the spout at full speed. A larger queue and batch helped: the Collector received 2 to 2.5 times as many spans once I raised its gRPC limit. Most spans were still dropped, though, and the topology slowed down. I doubt tuning alone keeps every span at these rates; I'd like to compare the collector bolt against these numbers in #9155.

Numbers

Setup: storm-perf ConstSpout → IdBolt → DevNullBolt on LocalCluster (one JVM, so with 2 workers both share one SDK), Java agent 2.31.1 with its executors instrumentation off unless noted, OTLP gRPC to a local Collector that discards the spans. In the async variant the id bolt emits and acks from a thread pool; in the sync variant it does so in execute(). With 2 workers both hops cross workers. Two runs per configuration.

Latency (42e1430, async). The spout emits 50,000 tuples/s and records the time from each emit to its ack(). Percentiles cover every ack in intervals of about 15 s; each cell is the range over four intervals. Every run kept up with the rate and no tuple failed. Max spout pending (1000) was reached once, by at most 143 tuples.

ms, p50 / p99 / p99.9 1 worker 2 workers
no agent, tracing off 1.11–1.16 / 2.24–3.08 / 3.22–4.36 3.39–3.41 / 6.82–6.94 / 8.38–9.78
agent, tracing off 1.14–1.15 / 2.46–2.73 / 4.32–4.91 3.40–3.44 / 6.90–7.01 / 8.70–9.41
ratio 0 1.19–1.21 / 3.18–3.45 / 4.21–5.12 3.60–3.63 / 7.32–8.00 / 9.06–10.58
1% 1.16–1.19 / 3.33–3.46 / 5.19–6.21 3.61–3.62 / 7.96–8.55 / 10.31–11.60
100% 1.21–1.23 / 6.42–6.88 / 9.18–11.41 3.45–3.71 / 12.45–12.93 / 15.36–16.80

At 100% the SDK's queue dropped 61–65% of the spans with one worker and 73–78% with two; at 1% it dropped none.

Batch span processor (42e1430, 100%, async, one worker, spout at full speed). Received/s is what the Collector got over the whole run divided by the run time, start-up included, so it is a run average, not a maximum rate.

queue, batch, delay acks/s received/s dropped by the queue rejected by the Collector
2048, 512, 5 s (default) 204–236 k 37–41 k 94% –
32768, 4096, 500 ms 165–184 k 65–66 k 86–87% –
32768, 4096, 5 s 160–170 k 66–70 k 86–87% –
131072, 16384, 5 s 244–260 k 0 99.4–99.5% all (6 logged per run)
131072, 16384, 5 s, Collector limit 16 MiB 138–145 k 80–92 k 79–80% –

The schedule delay made no difference here. With batch 16384 each export (4.7–4.9 MB) went over the Collector's default 4 MiB gRPC limit and was rejected. The remaining 0.5% of the spans were neither dropped nor received; I couldn't tell whether they were in rejected exports or still queued at shutdown.

Throughput (ae9c19253, before the split). Acks/s at the spout, whole-JVM CPU per ack.

async, 1 worker async, 2 workers sync, 1 worker
agent, tracing off 530–598 k/s, 7.3–7.5 µs 213–215 k/s, 19.1–19.4 µs 250–258 k/s, 10.5–10.8 µs
ratio 0 393–406 k/s, 10.8–11.2 µs 171–174 k/s, 26.0–27.3 µs 215–221 k/s, 13.4–13.7 µs
1% 365–379 k/s, 11.7–12.2 µs 167–168 k/s, 27.0–28.0 µs –
100% 205–275 k/s, 17.0–19.6 µs 137–175 k/s, 33.2–37.4 µs 140–160 k/s, 20.3–22.8 µs
ratio 0, executors instrumentation on 179–191 k/s, 17.7–17.9 µs 122–126 k/s, 32.5–33.2 µs –

Not measured: several hosts, one SDK per worker process, a real backend, OTLP compression, a steady-state export rate, failed or timed-out tuples, latency of the sync variant or at other rates.

How was the change tested

  • storm-client: KryoTupleSerializerDeserializerTest (10 new tests) covers round trips with and without compression, unchanged bytes without a context, serializers and deserializers without a tracer, the previous reader on new bytes, unknown tags, truncated entries and failing decodes. DefaultStateSerializerTest (1 new test) checks that tuples restored from state carry no context. SafeTupleTracerTest (3 tests) checks that Storm catches runtime exceptions and linkage errors from every method except prepare(), lets other errors through, and logs at most once a minute per method. BoltExecutorTest (4 tests) checks the execute and process latency with and without a tracer, and that a bolt exception still propagates and the scope is still closed.
  • storm-server: TupleTracerTest (8 tests) runs a fake tracer on a LocalCluster and checks the calls along a tuple tree, fail outcomes, the timeout outcome with its latency, bolt fail without ackers, anchor order, unanchored emits, a tracer that throws from startExecute(), from its execute scope and from spoutOutcome(), with every tuple still executed and acked, and tracing off.
  • storm-opentelemetry: TopologyTracingTest (17 tests) runs topologies on a two-worker LocalCluster and reads the spans through OpenTelemetryExtension, including same-trace and cross-trace joins, a join of a traced and an untraced tuple, tuples of a dropped root, and outcome span durations. TraceContextCodecTest (7 tests) covers the binary form. OpenTelemetryTupleTracerTest (3 tests) covers the SDK lookup and which spout roots pass their context on.
  • With the CI test command and RAT, without -Pnative, on a clean clone of 59f06da: storm-client ran 725 tests (4 skipped), storm-server 542 (1 skipped) and storm-opentelemetry 27, with no failures.

dpol1 added 8 commits October 1, 2026 14:28
Add the OpenTelemetry BOM and opentelemetry-api to storm-client. TupleImpl
holds an optional OpenTelemetry context. KryoTupleSerializer writes it after
the tuple values, inside the compressed frame: a header byte (version and a
tracestate bit), trace id, span id, trace flags and an optional W3C
tracestate. KryoTupleDeserializer reads it only when bytes remain after the
values, so tuples without a context keep their current bytes and readers
that stop after the values ignore the extension. An unknown version or a
malformed extension is read as no context.
With topology.tracing.enabled (default false), SpoutOutputCollectorImpl
records a root span for every emit, started and ended at once, and puts its
context on the emitted tuples. The tracer comes from the global
OpenTelemetry instance. Until an instance is registered, for example by the
OpenTelemetry Java agent, Storm leaves the global unset and creates no
spans, so an SDK registered later is still picked up. A span that is not
valid puts nothing on the tuple.

TopologyTracingTest runs topologies on a local cluster with two workers and
reads the spans through OpenTelemetryExtension, which registers the global
instance in the test JVM.
… context

BoltExecutor runs execute() inside a span named "<component> execute", a
child of the context the tuple carries. The span is current on the executor
thread while execute() runs, its context replaces the tuple's so anchored
emits can use it as their parent, and its scope is closed when the call
returns or throws. Tuples without a context, such as tick tuples, get no
span.

The tracer lookup moves to Executor so spouts and bolts share it; it stays
unset until an OpenTelemetry SDK is registered as the global instance.

The local-cluster test checks the parent of each execute span, that at
least one parent is remote (the tuple crossed workers), that the execute
span is current inside the bolt, that tick tuples get no span and see no
leftover span, and waits for the spans instead of reading them right after
the acks.
BoltOutputCollectorImpl gives an emitted tuple the context of its anchors,
on whatever thread emits. When the traced anchors carry one span, the tuple
carries that context; when they carry several, a new root span named
"<component> emit", started and ended at once, links to each of them.
Untraced anchors are ignored and unanchored emits carry no context; if a
span is current on the emitting thread, a DEBUG line says so at most once a
minute.

The tracing flag and the root-span helper move to Executor, shared by the
spout and bolt collectors. Checkpoint tuples of stateful bolts are emitted
without a trace, like other system tuples.

The local-cluster test covers anchored, twice-anchored, joined and
unanchored emits, and waits for the expected spans and sink tuples.
A middle bolt holds the first tuple and, on the second, emits both from
another thread in reverse order while the first tuple's span is current.
Each sink span must be the child of the middle span that handled the same
value, so the emit takes its parent from its anchor, not from the thread.

With a parent-based always-off sampler, unsampled contexts reach the sink
through the serializer (middle and sink run on different workers), the trace
continues from middle to sink, and no span is exported. With tracing off the
sink receives no context.
The spout keeps the root context in TupleInfo (transient, reset by clear())
and, when the tuple tree is acked, failed or times out, records a span named
"<spout> ack", "<spout> fail" or "<spout> timeout" under the root, started
and ended at once. Fail and timeout have status ERROR. A spout without
ackers records no outcome, since its ack is immediate. A bolt's fail()
records "<bolt> fail" with status ERROR under the tuple's context, with or
without ackers.

Contexts stored on tuples and in TupleInfo now keep only the span ids, so a
pending tuple does not retain the SDK span.
A recording execute span carries storm.topology.name, storm.topology.id,
storm.component.id, storm.task.id, storm.source.component.id,
storm.source.stream.id, storm.worker.host and storm.worker.port. No
OpenTelemetry semantic convention covers these; host.name is a resource
attribute and can differ from the host name Storm reports. The host comes
from Utils.hostname(), as for the supervisor, and is omitted when it cannot
be resolved.

The executor-level attributes are built once. All attributes are set only
when the span records, so an unsampled execute pays nothing; a custom
sampler therefore cannot see them when it decides.
TupleUtils.traceContext(Tuple) returns the OpenTelemetry context to run work
for a tuple under, or Context.root() when the tuple carries none, so a bolt
can continue a trace on its own threads. It is the supported public API with
OpenTelemetry types; Executor.tracer() becomes protected.

docs/Tracing.md describes how to enable tracing with the OpenTelemetry Java
agent, the spans and attributes Storm records, how the context moves through
anchors and between workers, sampling, and the costs and limits.
@reiabreu
reiabreu requested review from GGraziadei and rzo1 and removed request for GGraziadei October 2, 2026 16:39

@rzo1 rzo1 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks, looks good overall. Wire compat holds in both directions as far as I can tell, and the tests pass locally. A few remarks inline.

One bigger point on the shape. I would prefer not to have OpenTelemetry in storm-client at all. Right now every topology gets opentelemetry-api 1.66 on the worker classpath (before its own jar), Context ends up in our public API, and the root BOM pins OTel for all modules, even though tracing is off by default.

Could we split it?

  • storm-client gets a small vendor neutral SPI, e.g. TupleTracer with hooks for spout emit, bolt emit (anchor contexts in, context out), around execute(), outcome (with latency), and serialize/deserialize of the context. TupleImpl/TupleInfo hold an opaque Object. Selected via something like topology.tracing.tracer; unset means a null check on the hot path and the same bytes as today.
  • The serializer writes tag + length + opaque bytes after the values. That also solves the missing envelope (see inline).
  • Everything OTel specific (tracer lookup, span names, attributes, W3C encoding) moves to external/storm-opentelemetry, which is the only module depending on opentelemetry-api. Users drop it into lib-worker or their topology jar together with the agent.

ITaskHook is not enough for this, since it cannot attach anything to a tuple and boltExecute is called after execute() returned, so nothing can be made current while user code runs.

Most of the code here would move as is, so this should be a reshuffle rather than a rewrite. Happy to discuss on #9016 if you see it differently.

Also: LICENSE-binary and DEPENDENCY-LICENSES still list opentelemetry-api/-context 1.49.0 and miss opentelemetry-common, which now ends up in lib-worker/. The workflow would regenerate it after merge, but we could just do it here (moot if the split happens).

Comment thread storm-client/src/jvm/org/apache/storm/executor/Executor.java Outdated
Comment thread storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java Outdated
Comment thread storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java Outdated
Comment thread storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java Outdated
Comment thread storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java Outdated
Comment thread storm-client/src/jvm/org/apache/storm/executor/Executor.java Outdated
Comment thread storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java Outdated
Comment thread pom.xml Outdated
@dpol1

dpol1 commented Oct 5, 2026

Copy link
Copy Markdown
Contributor Author

Makes sense, I'll do the split. A TupleTracer interface in storm-client, one instance per worker, picked by topology.tracing.tracer (unset = off, same bytes as today). Hooks for spout emit, bolt emit, execute, outcome with latency, and encoding of an opaque context; the serializer writes a tag, a length and the bytes. The OTel code moves to external/storm-opentelemetry. I'll push it as new commits on top. Shout if you'd shape the hooks differently.

dpol1 added 4 commits October 5, 2026 15:41
storm-client no longer depends on OpenTelemetry. Tracing goes through
org.apache.storm.tracing.TupleTracer. Each worker creates one instance
from the class named in topology.tracing.tracer, which replaces
topology.tracing.enabled; when the key is unset, nothing is traced.
Tuples and pending spout trees hold an opaque context. The spout keeps
the emit time of traced trees and passes the latency to the outcome
hook.

After the values, the serializer writes a tag byte, a varint length
and the bytes the tracer encodes. Readers skip unknown tags. A
truncated entry, or one longer than the tuple, reads as no context.
Serializers built without a tracer, such as the ones
DefaultStateSerializer uses, write no context and skip it on read, so
state no longer stores contexts.

TupleUtils.traceContext, the OpenTelemetry BOM and version property,
and the OpenTelemetry LocalCluster test are removed. The OpenTelemetry
implementation and that test move to a separate module in the next
commit. TupleTracerTest checks the calls Storm makes to a tracer on a
two-worker local cluster.
external/storm-opentelemetry implements TupleTracer with OpenTelemetry,
using the code that left storm-client in the previous commit. To trace
a topology, set topology.tracing.tracer to
org.apache.storm.opentelemetry.OpenTelemetryTupleTracer and put the
module and opentelemetry-api in lib-worker or in the topology jar.
StormTracing.context(tuple) replaces TupleUtils.traceContext.
opentelemetry-api is managed in the module pom only.

Changes from the code it replaces:
- Until an SDK is registered as the global instance, the tracer calls
  GlobalOpenTelemetry.isSet() at most once a second and logs one
  warning. With the OpenTelemetry Java agent, isSet() sees the SDK from
  version 2.23.0.
- The context crosses workers as a version byte, the trace and span
  ids, the flags and the tracestate. A tracestate over 512 characters
  is not sent, and one over 512 reads as no context.
- The debug line for an emit with no traced anchor while a span is
  current is still limited to one a minute per task.

TopologyTracingTest moves from storm-server. Its expected span counts
now include the spout ack spans, so the wait ends only after every
execute span has ended.
A bolt emit anchored to several spans of one trace is now a child of
the first anchor's span, linked to the others, instead of a new root;
anchors from different traces still start a new root linked to each.

Spout ack, fail and timeout spans now last from the emit to the
outcome and carry the same value as storm.tuple.latency_ms. The spout
calls the outcome hook before its ack() or fail(), so a slow callback
does not move the span.
Tracing.md now covers topology.tracing.tracer, installing
storm-opentelemetry in lib-worker or the topology jar, the minimum
agent version, StormTracing.context, joins within one trace, outcome
span durations and storm.tuple.latency_ms, the limits for spouts that
receive a trace in message headers and for Trident coordinator
streams, and how to write another tracer.

Add a README to storm-opentelemetry and ship it in the binary
distribution like the other external modules.
@dpol1 dpol1 changed the title Add optional OpenTelemetry tracing of tuple trees Add pluggable tuple tracing with an OpenTelemetry tracer Oct 5, 2026
@dpol1

dpol1 commented Oct 5, 2026

Copy link
Copy Markdown
Contributor Author

Pushed the split as 4 commits on top (SPI, external/storm-opentelemetry, threads 2 and 7, docs) and updated the description. storm-client no longer depends on OTel, so the license files stay as they are.

@dpol1
dpol1 requested a review from rzo1 October 5, 2026 18:20
@GGraziadei

GGraziadei commented Oct 6, 2026 •

Copy link
Copy Markdown
Member

Hi @dpol1, thanks for this contribution. The idea is solid and there is a real need for it;

Latency has a stragic value for Storm, so I think we should aim to do better on that side. The PR measures throughput and CPU per ack, but not latency: could you add complete latency (p50/p99) to the benchmark, with tracing off, at ratio 0, 1% and 100%?

On the export side, could you publish the otel.bsp.max.export.batch.size, otel.bsp.max.queue.size and otel.bsp.schedule.delay values you used, and the ones you tried when tuning? Freshness is not a strict requirement for telemetry, so larger batches, a larger queue and a longer schedule delay should be acceptable; it would be useful to see how far they go and where they stop helping.

A further idea: collect the telemetry on a dedicated stream into a collector bolt (unanchored tuples), flushed at a fixed interval with a tick tuple, instead of exporting from every worker. It changes where the cost lands, so it is worth keeping in mind here (but better producing benchmarks also for this approach).

@dpol1

dpol1 commented Oct 7, 2026

Copy link
Copy Markdown
Contributor Author

Will do: p50/p99 complete latency at a fixed input rate (off, 0, 1%, 100%) and a BSP sweep; so far I tried the defaults (queue 2048, batch 512, 5 s) and 32768/4096/500 ms. The collector bolt is #9155: I'll benchmark it there against these numbers.

@dpol1

dpol1 commented Oct 7, 2026

Copy link
Copy Markdown
Contributor Author

Thanks @GGraziadei, I've added p50/p99 latency and a BSP sweep to the description (under Cost).
In short: 1% adds about 1 ms at p99, and at 100% a larger queue and batch help but most spans are still dropped. Happy to try other settings if useful.

@GGraziadei GGraziadei added this to the 3.2.0 milestone Oct 7, 2026
@GGraziadei

Copy link
Copy Markdown
Member

Alert: comment refactored with an LLM (GPT 5.6)

Thanks for the latency numbers and the BSP sweep, @dpol1. They help a lot.

Reading through the hot path, my main concern is the cost at ratio 0: about -29% throughput and +0.7 ms at p99. This cost is paid by every topology that enables the tracer, even when nothing is sampled.

I think most of this can go away with a few small changes while keeping the SPI as it is.

For unsampled trees, we should avoid calling the tracer altogether. With a parent-based sampler, no child of an unsampled root can ever be sampled. We could keep the root's sampled flag on the tuple (TupleImpl/TupleInfo) and have BoltExecutor, BoltOutputCollectorImpl and SpoutExecutor skip tracing when it is false. Right now an unsampled tuple still goes through startExecute, boltEmit and spoutOutcome, and with the agent each of those calls crosses the API bridge and allocates wrappers. The cost should ideally become just a branch.

We could also let Storm make the sampling decision at the spout. A topology.tracing.sample.ratio check in SpoutOutputCollectorImpl.sendSpoutMsg would mean the tracer is only called for trees that are actually selected. At ratio 0, the SDK would never be touched. The existing rootId from MessageId.generateId(random) gives us randomness for acked trees, with random as a fallback for unanchored emits. Using it to derive the trace ID would also make it possible to correlate Storm debug logs with traces. The SDK sampler could then stay parent-based (or always-on), and we could document this in Tracing.md.

We should also avoid encoding and decoding unsampled contexts. TraceContextCodec.encode currently writes 26+ bytes for every cross-worker tuple, and decode allocates several objects even when the tuple is unsampled. Once the fast path is in place, this will mostly happen only for sampled tuples. As a cheap safety net, decode could read the flags byte first and return null when the sampled bit is clear, before doing any allocations.

So the changes should be limited to BoltExecutor, BoltOutputCollectorImpl, SpoutOutputCollectorImpl, KryoTupleSerializer/Deserializer and the tracer.

Could you implement these changes and re-measure ratio 0 and 1% on the current head? The existing throughput numbers are from before the SPI split. For ratio 0, I would expect performance to be within the noise of "agent, tracing off". That is the key property we need before recommending that tracing can be enabled by default.

A couple of measurement requests are not blocking:

  • 50k tuples/s is only about 10% of the measured capacity, so the latency numbers show the added service time but not the queueing effect from the lost throughput. It would be useful to add one or two higher-load points, such as 50% and 75% of the tracing-off maximum, with runs of a few minutes. Discard the first minute and build the histogram from the rest. This should make the p99 differences easier to see.

OpenTelemetryTupleTracer.spoutEmit returns the root span's context only
when the span is recording, that is sampled or RECORD_ONLY. A tuple tree
whose root the sampler drops carries no context, so Storm skips the
execute, fail and outcome hooks for the rest of the tree, and the tracer
returns at once on its bolt emits.

Instrumented clients called for tuples of such a tree start their own
traces, and an emit anchored to a traced and an untraced tuple continues
the traced tree with no link to the other. docs/Tracing.md describes
both.
@dpol1

dpol1 commented Oct 9, 2026

Copy link
Copy Markdown
Contributor Author

Thanks @GGraziadei. Before touching storm-client I tried something smaller in the tracer: when the sampler drops the root span of a spout emit, the tuple now carries no trace context, so Storm skips startExecute, boltFail and spoutOutcome for that tree.

On my laptop this removes most of the throughput loss. On one worker, ratio 0 goes from about 40% below tracing off on the current head to 12% or less, so it's not yet within the noise you were hoping for. On two workers it's level with tracing off (head is 21 to 26% below). The numbers are below, please take them as a rough guide.

It does change the traces in two ways, and I'd like your opinion on them. A client instrumented by the agent and called in execute() for such a tuple now starts its own trace, decided by the root sampler, so at 1% some of these calls show up as sampled traces with no link to the tuple. An emit anchored to a traced and an untraced tuple now continues the traced tree, with no link to the untraced one.

Would that be ok as the basis for this optimization, with RECORD_ONLY roots still passing their context on? I think your storm-client fast path would have the same two effects, so I'd rather agree on this first and measure any storm-client change on its own afterwards. I haven't pushed it yet, and I'm happy to run other setups if useful.

Numbers (laptop)

Laptop, LocalCluster with all workers in one JVM, agent 2.31.1 with its executors instrumentation off, the async variant from the Cost section of the PR description. IPv6 is disabled on this machine, so ZooKeeper clients retried [::1] in every run, sometimes during a measurement window. It affects all configurations. It also limits how precisely I can attribute the remaining cost. Head is 42e1430. "This change" swaps only the storm-opentelemetry jar. Throughput with the spout at full speed, against "agent, tracing off". One worker: four rounds, each against its own control run, because the control drifted between rounds. Two workers: two runs.

1 worker 2 workers
ratio 0, head -46 to -37% -26 to -21%
ratio 0, this change -12 to -4% in three rounds, -1 to +6% in one -0.3 to +3.6%
1%, head -60 to -44% -25 to -23%
1%, this change -23 to -4% -5 to -1%

The head range at ratio 0 on one worker includes a run that the harness rejected for its exit code at shutdown, after both windows. Without it the range is -46 to -40%.

In round 2, head at 1% ran at 223-232k tuples/s against 313-336k in the other rounds, and I haven't looked into why. Without that round the range is -49 to -44%.

At 1% on one worker, three of the four runs with this change dropped spans from a full export queue, up to 2,400 per run. Head dropped none. This change acked 1.5 to 2.3 times as many tuples per second as head in the same round, so the SDK received more spans per second.

Complete latency at 50k tuples/s on one worker, p99 against tracing off, which itself varies by ±0.14 ms. Ratio 0, head +0.83 to +1.05 ms and this change -0.15 to +0.28 ms. 1%, head +0.18 to +1.03 ms and this change -0.05 to +0.19 ms. At the same rate, CPU per ack at ratio 0 is 44.5 to 55.2 µs with this change, against 44.5 to 47.5 µs on head and 40.1 to 43.6 µs with tracing off. The upper end with this change is above head's range, and I haven't looked into why.

The SDK still starts one dropped root span per spout emit, and each bolt emit still calls the tracer, which returns at once. Your storm-client changes, sampling at the spout and skipping untraced emits, would remove those calls. I haven't profiled where the remaining cost goes.

Tuples of dropped trees now cross workers without trace bytes, so encode and decode do not run for them. With a parent-based sampler, unsampled contexts still cross workers for trees under a RECORD_ONLY root, and for tuples of an emit whose anchors come from different traces, when the sampler drops the new root that emit starts. Both cases are intended, so decode keeps unsampled contexts instead of returning null when the sampled bit is clear.

Next to measure: the 50% and 75% load points with longer runs, a network between workers, real client libraries and a RECORD_ONLY sampler.

@GGraziadei

Copy link
Copy Markdown
Member

Hi @dpol1
Thanks for working on this improvement! The performance gains are very significant compared to the first version, and I think it's worth moving forward with the PR.
What about a follow-up PR for the fast-path optimization as well, so we can evaluate its impact separately?
Thanks again for investigating this!

@rzo1 rzo1 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Most remarks are given inline. One question concerns the scope of the PR and is therefore stated here.

The pushed head still propagates unsampled contexts, so a sampling ratio of 0 is not without cost. The measurements on 42e1430 report a throughput between 21 and 46% below the configuration with the agent and without tracing. In the comment of 10-09, @dpol1 described a change confined to the tracer that drops the context of unsampled roots, and asked whether its two effects on the recorded traces are acceptable. @GGraziadei proposed a follow-up for the fast path, which in my reading does not answer that question. It would be good to agree on whether the tracer change belongs to this PR or to the follow-up. Independently of that decision, the section "Costs and limits" in Tracing.md should state that configuring a tracer reduces throughput even at a ratio of 0, since users will otherwise assume that a ratio of 0 is equivalent to disabled tracing.

The wire compatibility in both directions, the decoding of the trace entry after decompression, the handling of late tuples (a DetachedTuple is anchored on the original input, so its context is preserved), the absence of a context on tick, acker, checkpoint and feedback tuples, and the restriction of contexts to span ids were checked and found correct.

Comment thread storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java Outdated
/**
* Called once, before any other method.
*/
void prepare(Map<String, Object> topoConf, WorkerTopologyContext context);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The interface defines prepare but no counterpart that is called on worker shutdown, so an implementation has no opportunity to flush or release resources. This is irrelevant with the agent, but not for an SDK registered by the application, nor in local mode with several topologies in one JVM. I suggest adding default void cleanup() {} before the interface becomes public API.

@dpol1 dpol1 Oct 14, 2026 •

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The bundled tracer borrows a Tracer from the global SDK, the agent's or the application's, and has nothing to close. Adding a default method later stays binary compatible, so could we add it when a tracer that owns its SDK needs it?

Comment thread storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java Outdated
/**
* Returns the trace contexts of the anchors, in anchor order, skipping anchors without one.
*/
private static List<Object> traceContexts(Collection<Tuple> anchors) {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For windowed bolts, every emit is anchored to the whole window, so this method allocates a list of the window's size on each emit, and boltEmit subsequently builds a set of all span contexts (see the corresponding comment in OpenTelemetryTupleTracer). Since the SDK retains at most 128 links by default, the work is largely discarded.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Documented in 59f06da: "Costs and limits" in Tracing.md says the tracing cost of an emit grows with the number of anchors, for example in windowed bolts. boltEmit still gets every anchor's context, since the 128-link cap is an OpenTelemetry SDK setting that another tracer may not have.

return first;
}
SpanContext firstSpan = Span.fromContext(first).getSpanContext();
Set<SpanContext> otherSpans = new LinkedHashSet<>();

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This set grows with the number of anchors, whereas at most 128 links are retained (line 135). Stopping once 129 distinct span contexts have been collected would bound the cost for emits with many anchors without changing the result.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

With 129 distinct anchor spans in trace A and a later one in B, a stopped scan makes the emit a child of the first anchor instead of a new root. The link limit is also configurable (otel.span.link.count.limit) and a fixed cap would drop links the SDK keeps, so I'd keep the full scan and document its cost in Tracing.md.

* an unknown tag, and readers that stop after the values ignore all of them.
*/
private void writeTraceContext(Object traceContext) {
byte[] payload = tracer.encode(traceContext);

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Minor: with an all grouping to tasks on remote workers, the same context is encoded once per destination, including the construction of the tracestate string if one is present. Caching the encoded form per context object would avoid this, although the gain is presumably small.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Right, the values are also serialized once per remote task, and the context adds 28 bytes plus any tracestate. I'd leave it until a measurement shows a gain.

Comment thread storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java Outdated
Comment thread storm-client/src/jvm/org/apache/storm/daemon/worker/WorkerState.java Outdated
@dpol1

dpol1 commented Oct 14, 2026 •

Copy link
Copy Markdown
Contributor Author

Thanks @GGraziadei and @rzo1. ecdfe2f adds the tracer change, with its two effects on traces described in docs/Tracing.md, and the storm-client fast path would go in the follow-up @GGraziadei suggested.

dpol1 added 3 commits October 14, 2026 17:21
A runtime exception from a TupleTracer method other than decode()
propagated into the executor or the serializer and could stop the
worker. WorkerState now wraps the configured tracer in SafeTupleTracer:
a call that throws a runtime exception or a linkage error is treated as
returning null, ExecuteScope.context() falls back to the context the
tuple arrived with, and ExecuteScope.close() does not let either escape.
Each hook logs its first failure with the stack trace and then at most
once a minute, so decode() failures are now logged as warnings rather
than at debug level. Exceptions from prepare() still stop the worker
from starting. The TupleTracer Javadoc describes the new contract.

The OpenTelemetry tracer now ends the execute span even when closing
its scope fails.
With a tracer, the execute latency started before startExecute() and
ended after the scope closed, so it included opening the scope, reading
its context and ending the execute span. BoltExecutor now starts the
execute measurement after startExecute() returns and, when it opened a
scope, after the tuple has its context, and takes it before the scope
closes. The process latency still starts where it did, and without a
tracer the timing is unchanged. The execute latency feeds the UI, the
task metrics and BoltExecuteInfo.
The "Costs and limits" section of docs/Tracing.md now says that a
configured tracer can reduce throughput at a sampling ratio of 0 and
how to turn tracing off, that an emit anchored to many tuples costs more
to trace, that Storm logs a tracer's runtime exceptions and linkage
errors and carries on without that call's result, and that a tracer
class Storm cannot create, or a prepare() that throws, keeps the worker
from starting. SpoutExecutor uses one constant for the timeout reason
that it passes to failSpoutMsg and checks to report the outcome.
@dpol1

dpol1 commented Oct 14, 2026

Copy link
Copy Markdown
Contributor Author

I pushed dcc6eae, 23de581 and 59f06da for six of your eight inline comments; cleanup() and the encode cache have a reply without a change. "Costs and limits" in Tracing.md now also says a tracer can reduce throughput at a sampling ratio of 0, as the one-worker "this change" rows here show.

@dpol1
dpol1 requested a review from rzo1 October 14, 2026 20:39
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants