From 72c22ee84d0ce92e0ef36568a61959414a490f31 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Sat, 26 Sep 2026 20:25:55 +0200 Subject: [PATCH 01/12] feat: carry an OpenTelemetry context on tuples across workers 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. --- pom.xml | 8 ++ storm-client/pom.xml | 6 + .../serialization/KryoTupleDeserializer.java | 55 +++++++- .../serialization/KryoTupleSerializer.java | 39 ++++++ .../jvm/org/apache/storm/tuple/TupleImpl.java | 17 +++ .../KryoTupleSerializerDeserializerTest.java | 125 ++++++++++++++++++ 6 files changed, 249 insertions(+), 1 deletion(-) diff --git a/pom.xml b/pom.xml index 4bb39882c86..d1aa1382d70 100644 --- a/pom.xml +++ b/pom.xml @@ -124,6 +124,7 @@ above, so this is bumped explicitly rather than tracking the newest release. --> 1.12.0 5.6.2 + 1.66.0 3.6 6.1.0 0.24.0 @@ -759,6 +760,13 @@ pom import + + io.opentelemetry + opentelemetry-bom + ${opentelemetry.version} + pom + import + io.dropwizard.metrics metrics-core diff --git a/storm-client/pom.xml b/storm-client/pom.xml index cfa56683086..e1683e0a917 100644 --- a/storm-client/pom.xml +++ b/storm-client/pom.xml @@ -96,6 +96,12 @@ kryo + + + io.opentelemetry + opentelemetry-api + + io.dropwizard.metrics diff --git a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java index 301a8ca96de..d90fbc094c2 100644 --- a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java +++ b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java @@ -13,6 +13,14 @@ package org.apache.storm.serialization; import com.esotericsoftware.kryo.io.Input; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.SpanId; +import io.opentelemetry.api.trace.TraceFlags; +import io.opentelemetry.api.trace.TraceId; +import io.opentelemetry.api.trace.TraceState; +import io.opentelemetry.api.trace.TraceStateBuilder; +import io.opentelemetry.context.Context; import java.io.IOException; import java.util.List; import java.util.Map; @@ -30,6 +38,8 @@ public class KryoTupleDeserializer implements ITupleDeserializer { private static final Integer DEFAULT_MAX_DECOMPRESSED_BYTES = 10 * 1024 * 1024; // 10MBytes public static final Logger LOG = LoggerFactory.getLogger(KryoTupleDeserializer.class); public static final String FAILED_TO_DESERIALIZE_TUPLE = "Failed to deserialize tuple"; + private static final int TRACE_ID_BYTES = 16; + private static final int SPAN_ID_BYTES = 8; private final GeneralTopologyContext context; private final KryoValuesDeserializer kryo; private final SerializationFactory.IdDictionary ids; @@ -84,12 +94,55 @@ private TupleImpl deserializeTuple(byte[] data) { String streamName = ids.getStreamName(componentName, streamId); MessageId id = MessageId.deserialize(kryoInput); List values = kryo.deserializeFrom(kryoInput); - return new TupleImpl(context, values, componentName, taskId, streamName, id); + TupleImpl tuple = new TupleImpl(context, values, componentName, taskId, streamName, id); + tuple.setTraceContext(readTraceContext(kryoInput)); + return tuple; } catch (IOException e) { throw new RuntimeException(FAILED_TO_DESERIALIZE_TUPLE, e); } } + /** + * Reads the trace context written after the values. Null when absent, of an unknown version + * or unreadable, so a bad extension never fails the tuple. Invalid tracestate entries are + * dropped. + */ + private static Context readTraceContext(Input in) { + if (in.position() == in.limit()) { + return null; + } + try { + int header = in.readByte() & 0xFF; + int version = header & ~KryoTupleSerializer.HAS_TRACE_STATE; + if (version != KryoTupleSerializer.TRACE_CONTEXT_VERSION) { + return null; + } + String traceId = TraceId.fromBytes(in.readBytes(TRACE_ID_BYTES)); + String spanId = SpanId.fromBytes(in.readBytes(SPAN_ID_BYTES)); + TraceFlags flags = TraceFlags.fromByte(in.readByte()); + TraceState traceState = TraceState.getDefault(); + if ((header & KryoTupleSerializer.HAS_TRACE_STATE) != 0) { + String[] entries = in.readString().split(","); + TraceStateBuilder builder = TraceState.builder(); + // put() inserts in front of existing entries: add in reverse to keep the order + for (int i = entries.length - 1; i >= 0; i--) { + String entry = entries[i]; + int separator = entry.indexOf('='); + if (separator > 0) { + builder.put(entry.substring(0, separator), entry.substring(separator + 1)); + } + } + traceState = builder.build(); + } + SpanContext span = + SpanContext.createFromRemoteParent(traceId, spanId, flags, traceState); + return span.isValid() ? Context.root().with(Span.wrap(span)) : null; + } catch (RuntimeException malformed) { + LOG.debug("Ignoring a malformed trace context on a received tuple", malformed); + return null; + } + } + private static boolean isTupleCompressionEnabled(final Map conf, final GeneralTopologyContext context) { if (ObjectReader.getBoolean(conf.get(Config.TOPOLOGY_TUPLE_COMPRESSION_ENABLE), false)) { return true; diff --git a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java index 7691faf062c..e71e2b340d1 100644 --- a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java +++ b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java @@ -13,18 +13,28 @@ package org.apache.storm.serialization; import com.esotericsoftware.kryo.io.Output; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.TraceState; +import io.opentelemetry.context.Context; import java.io.IOException; import java.util.Arrays; import java.util.Map; +import java.util.StringJoiner; import org.apache.storm.Config; import org.apache.storm.task.GeneralTopologyContext; import org.apache.storm.tuple.Tuple; +import org.apache.storm.tuple.TupleImpl; import org.apache.storm.utils.ObjectReader; import org.apache.storm.utils.Utils; public class KryoTupleSerializer implements ITupleSerializer { private static final int DEFAULT_COMPRESSION_THRESHOLD = 1460; private static final Integer DEFAULT_ZSTD_COMPRESSION_LEVEL = 3; + /** Below 0x80, the bit HAS_TRACE_STATE takes; bump it when the layout changes. */ + static final int TRACE_CONTEXT_VERSION = 1; + /** Header bit: a W3C tracestate follows the trace flags. */ + static final int HAS_TRACE_STATE = 0x80; private final KryoValuesSerializer kryo; private final SerializationFactory.IdDictionary ids; @@ -51,6 +61,9 @@ public byte[] serialize(Tuple tuple) { kryoOut.writeInt(ids.getStreamId(tuple.getSourceComponent(), tuple.getSourceStreamId()), true); tuple.getMessageId().serialize(kryoOut); kryo.serializeInto(tuple.getValues(), kryoOut); + if (tuple instanceof TupleImpl impl) { + writeTraceContext(kryoOut, impl.getTraceContext()); + } byte[] rawBytes = kryoOut.getBuffer(); int dataLength = kryoOut.position(); @@ -64,4 +77,30 @@ public byte[] serialize(Tuple tuple) { throw new RuntimeException(e); } } + + /** + * Appends the trace context after the values: header byte (version, tracestate bit), 16-byte + * trace id, 8-byte span id, trace flags byte, then the tracestate if not empty. Readers that + * stop after the values ignore these bytes. + */ + private static void writeTraceContext(Output out, Context traceContext) { + if (traceContext == null) { + return; + } + SpanContext span = Span.fromContext(traceContext).getSpanContext(); + // isValid() ignores the sampled flag: unsampled contexts propagate too + if (!span.isValid()) { + return; + } + TraceState traceState = span.getTraceState(); + out.writeByte(TRACE_CONTEXT_VERSION | (traceState.isEmpty() ? 0 : HAS_TRACE_STATE)); + out.writeBytes(span.getTraceIdBytes()); + out.writeBytes(span.getSpanIdBytes()); + out.writeByte(span.getTraceFlags().asByte()); + if (!traceState.isEmpty()) { + StringJoiner entries = new StringJoiner(","); + traceState.forEach((key, value) -> entries.add(key + '=' + value)); + out.writeString(entries.toString()); + } + } } diff --git a/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java b/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java index e0a2827eba5..4c8ab3aee5f 100644 --- a/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java +++ b/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java @@ -12,6 +12,7 @@ package org.apache.storm.tuple; +import io.opentelemetry.context.Context; import java.util.Collections; import java.util.List; import org.apache.storm.generated.GlobalStreamId; @@ -27,6 +28,7 @@ public class TupleImpl implements Tuple { private Long processSampleStartTime; private Long executeSampleStartTime; private long outAckVal = 0; + private Context traceContext; public TupleImpl(Tuple t) { this.values = t.getValues(); @@ -40,6 +42,7 @@ public TupleImpl(Tuple t) { this.processSampleStartTime = ti.processSampleStartTime; this.executeSampleStartTime = ti.executeSampleStartTime; this.outAckVal = ti.outAckVal; + this.traceContext = ti.traceContext; } catch (ClassCastException e) { // ignore ... if t is not a TupleImpl type .. faster than checking and then casting } @@ -83,6 +86,20 @@ public void setExecuteSampleStartTime(long ms) { executeSampleStartTime = ms; } + /** + * Returns the OpenTelemetry context this tuple carries, or null. Internal to Storm. + */ + public Context getTraceContext() { + return traceContext; + } + + /** + * Sets the OpenTelemetry context this tuple carries; null removes it. Internal to Storm. + */ + public void setTraceContext(Context traceContext) { + this.traceContext = traceContext; + } + public void updateAckVal(long val) { outAckVal = outAckVal ^ val; } diff --git a/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java b/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java index bbd03697075..8e23cc7cc29 100644 --- a/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java +++ b/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java @@ -12,6 +12,15 @@ package org.apache.storm.serialization; +import com.esotericsoftware.kryo.io.Input; +import com.esotericsoftware.kryo.io.Output; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.TraceFlags; +import io.opentelemetry.api.trace.TraceState; +import io.opentelemetry.context.Context; +import java.io.IOException; +import java.util.Arrays; import java.util.Collections; import java.util.HashMap; import java.util.List; @@ -33,8 +42,10 @@ import org.junit.jupiter.api.Test; import org.mockito.MockedStatic; +import static org.junit.jupiter.api.Assertions.assertArrayEquals; import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNull; import static org.junit.jupiter.api.Assertions.assertThrows; import static org.junit.jupiter.api.Assertions.assertTrue; import static org.mockito.ArgumentMatchers.anyInt; @@ -351,6 +362,120 @@ private static class UnregisteredType { private final int field = 1; } + @Test + public void testTraceContextRoundTripUncompressed() { + assertTraceContextRoundTrip(baseConf()); + } + + @Test + public void testTraceContextRoundTripCompressed() { + assertTraceContextRoundTrip(compressionEnabledConf(0)); + } + + @Test + public void testTupleWithoutTraceContextSerializesAsBefore() throws IOException { + Map conf = baseConf(); + KryoTupleSerializer serializer = new KryoTupleSerializer(conf, context); + TupleImpl plain = tuple(new Values("hello", 42), MessageId.makeRootId(7L, 99L)); + TupleImpl rootOnly = tuple(new Values("hello", 42), MessageId.makeRootId(7L, 99L)); + rootOnly.setTraceContext(Context.root()); + + byte[] expected = serializeWithoutTraceContext(conf, plain); + assertArrayEquals(expected, serializer.serialize(plain)); + assertArrayEquals(expected, serializer.serialize(rootOnly), "a context without a valid span adds no bytes"); + assertNull(new KryoTupleDeserializer(conf, context).deserialize(expected).getTraceContext()); + } + + @Test + public void testPreviousReaderIgnoresTraceContext() throws IOException { + Map conf = baseConf(); + TupleImpl original = tracedTuple((byte) 0x03, TraceState.builder().put("vendor", "v1").build()); + byte[] bytes = new KryoTupleSerializer(conf, context).serialize(original); + + assertSameTuple(original, deserializeWithoutTraceContext(conf, bytes)); + } + + @Test + public void testTruncatedTraceContextReadsAsAbsent() throws IOException { + Map conf = baseConf(); + TupleImpl original = tracedTuple((byte) 0x03, TraceState.builder().put("vendor", "v1").build()); + byte[] full = new KryoTupleSerializer(conf, context).serialize(original); + int valuesEnd = serializeWithoutTraceContext(conf, original).length; + KryoTupleDeserializer deserializer = new KryoTupleDeserializer(conf, context); + + for (int end = valuesEnd + 1; end < full.length; end++) { + TupleImpl read = deserializer.deserialize(Arrays.copyOf(full, end)); + assertSameTuple(original, read); + assertNull(read.getTraceContext(), "truncated at byte " + end); + } + } + + @Test + public void testUnknownTraceContextVersionIsIgnored() throws IOException { + Map conf = baseConf(); + TupleImpl original = tracedTuple((byte) 0x03, TraceState.getDefault()); + byte[] bytes = new KryoTupleSerializer(conf, context).serialize(original); + bytes[serializeWithoutTraceContext(conf, original).length] = 2; + + TupleImpl read = new KryoTupleDeserializer(conf, context).deserialize(bytes); + assertSameTuple(original, read); + assertNull(read.getTraceContext()); + } + + private void assertTraceContextRoundTrip(Map conf) { + KryoTupleSerializer serializer = new KryoTupleSerializer(conf, context); + KryoTupleDeserializer deserializer = new KryoTupleDeserializer(conf, context); + TraceState twoEntries = TraceState.builder().put("vendor", "v1").put("ot", "th:8;rv:0123456789abcd").build(); + // 0x03 = sampled plus the W3C random-trace-id bit; 0x00 = not sampled, which must propagate too + List originals = List.of( + tracedTuple((byte) 0x03, TraceState.getDefault()), + tracedTuple((byte) 0x03, twoEntries), + tracedTuple((byte) 0x00, TraceState.getDefault())); + + for (TupleImpl original : originals) { + TupleImpl read = deserializer.deserialize(serializer.serialize(original)); + assertSameTuple(original, read); + SpanContext sent = Span.fromContext(original.getTraceContext()).getSpanContext(); + SpanContext received = Span.fromContext(read.getTraceContext()).getSpanContext(); + assertEquals(sent.getTraceId(), received.getTraceId()); + assertEquals(sent.getSpanId(), received.getSpanId()); + assertEquals(sent.getTraceFlags(), received.getTraceFlags()); + assertEquals(sent.getTraceState(), received.getTraceState()); + assertTrue(received.isRemote()); + } + } + + private TupleImpl tracedTuple(byte traceFlags, TraceState traceState) { + TupleImpl tuple = tuple(new Values("hello", 42), MessageId.makeRootId(7L, 99L)); + SpanContext span = SpanContext.create("0af7651916cd43dd8448eb211c80319c", "b7ad6b7169203331", + TraceFlags.fromByte(traceFlags), traceState); + tuple.setTraceContext(Context.root().with(Span.wrap(span))); + return tuple; + } + + /** The tuple format without the trace context extension: task, stream, message id, values. */ + private byte[] serializeWithoutTraceContext(Map conf, TupleImpl tuple) throws IOException { + SerializationFactory.IdDictionary ids = new SerializationFactory.IdDictionary(context.getRawTopology()); + Output out = new Output(2000, -1); + out.writeInt(tuple.getSourceTask(), true); + out.writeInt(ids.getStreamId(tuple.getSourceComponent(), tuple.getSourceStreamId()), true); + tuple.getMessageId().serialize(out); + new KryoValuesSerializer(conf).serializeInto(tuple.getValues(), out); + return out.toBytes(); + } + + /** The read sequence of a deserializer that predates the trace context extension. */ + private TupleImpl deserializeWithoutTraceContext(Map conf, byte[] bytes) throws IOException { + SerializationFactory.IdDictionary ids = new SerializationFactory.IdDictionary(context.getRawTopology()); + Input in = new Input(bytes); + int taskId = in.readInt(true); + int streamId = in.readInt(true); + String component = context.getComponentId(taskId); + MessageId id = MessageId.deserialize(in); + List values = new KryoValuesDeserializer(conf).deserializeFrom(in); + return new TupleImpl(context, values, component, taskId, ids.getStreamName(component, streamId), id); + } + private TupleImpl tuple(List values, MessageId id) { return new TupleImpl(context, values, SOURCE_COMPONENT, SOURCE_TASK_ID, Utils.DEFAULT_STREAM_ID, id); } From 99509293c76294df9da1d774f1c58d2d6d3aca06 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Mon, 28 Sep 2026 18:10:49 +0200 Subject: [PATCH 02/12] feat: add topology.tracing.enabled and a root span per spout emit 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. --- conf/defaults.yaml | 1 + .../src/jvm/org/apache/storm/Config.java | 10 ++ .../spout/SpoutOutputCollectorImpl.java | 35 +++++ storm-server/pom.xml | 5 + .../org/apache/storm/TopologyTracingTest.java | 146 ++++++++++++++++++ 5 files changed, 197 insertions(+) create mode 100644 storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java diff --git a/conf/defaults.yaml b/conf/defaults.yaml index 6fd7a04b9d4..59dce959026 100644 --- a/conf/defaults.yaml +++ b/conf/defaults.yaml @@ -289,6 +289,7 @@ storm.group.mapping.service.cache.duration.secs: 120 ### topology.* configs are for specific executing storms topology.enable.message.timeouts: true topology.debug: false +topology.tracing.enabled: false topology.workers: 1 topology.acker.executors: null topology.ras.acker.executors.per.worker: 1 diff --git a/storm-client/src/jvm/org/apache/storm/Config.java b/storm-client/src/jvm/org/apache/storm/Config.java index 519b8d943bb..35bdfe274c1 100644 --- a/storm-client/src/jvm/org/apache/storm/Config.java +++ b/storm-client/src/jvm/org/apache/storm/Config.java @@ -1648,6 +1648,16 @@ public class Config extends HashMap { */ @IsPositiveNumber(includeZero = false) public static final String TOPOLOGY_TUPLE_COMPRESSION_MAX_DECOMPRESSED_BYTES = "topology.tuple.compression.max.decompressed.bytes"; + + /** + * Enables OpenTelemetry tracing for the topology. When {@code true}, every spout emit starts + * a root span, and tuples carry the trace context between components and workers. Spans are + * recorded and exported by the OpenTelemetry SDK registered as the global instance, usually by + * the OpenTelemetry Java agent; without one, Storm creates no spans. Default: {@code false}. + */ + @IsBoolean + public static final String TOPOLOGY_TRACING_ENABLED = "topology.tracing.enabled"; + /** * Configure the topology metrics reporters to be used on workers. */ diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java index d47b5347c04..2926d2ac0d5 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java @@ -12,9 +12,14 @@ package org.apache.storm.executor.spout; +import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.Tracer; +import io.opentelemetry.context.Context; import java.util.ArrayList; import java.util.List; import java.util.Random; +import org.apache.storm.Config; import org.apache.storm.daemon.Acker; import org.apache.storm.daemon.Task; import org.apache.storm.executor.TupleInfo; @@ -25,6 +30,7 @@ import org.apache.storm.tuple.TupleImpl; import org.apache.storm.tuple.Values; import org.apache.storm.utils.MutableLong; +import org.apache.storm.utils.ObjectReader; import org.apache.storm.utils.RotatingMap; import org.apache.storm.utils.Utils; import org.slf4j.Logger; @@ -45,6 +51,9 @@ public class SpoutOutputCollectorImpl implements ISpoutOutputCollector { private final Boolean isDebug; private final RotatingMap pending; private final long spoutExecutorThdId; + private final boolean tracingEnabled; + private final String emitSpanName; + private Tracer tracer; private TupleInfo globalTupleInfo = new TupleInfo(); // thread safety: assumes Collector.emit*() calls are externally synchronized (if needed). @@ -62,6 +71,9 @@ public SpoutOutputCollectorImpl(ISpout spout, SpoutExecutor executor, Task taskD this.isDebug = isDebug; this.pending = pending; this.spoutExecutorThdId = executor.getThreadId(); + Object tracing = executor.getTopoConf().get(Config.TOPOLOGY_TRACING_ENABLED); + this.tracingEnabled = ObjectReader.getBoolean(tracing, false); + this.emitSpanName = executor.getComponentId() + " emit"; } @Override @@ -123,6 +135,8 @@ private List sendSpoutMsg(String stream, List values, Object me final long rootId = needAck ? MessageId.generateId(random) : 0; + final Context traceContext = tracingEnabled ? newRootContext() : null; + for (int i = 0; i < outTasks.size(); i++) { // perf critical path. don't use iterators. Integer t = outTasks.get(i); MessageId msgId; @@ -136,6 +150,9 @@ private List sendSpoutMsg(String stream, List values, Object me final TupleImpl tuple = new TupleImpl(executor.getWorkerTopologyContext(), values, executor.getComponentId(), this.taskId, stream, msgId); + if (traceContext != null) { + tuple.setTraceContext(traceContext); + } AddressedTuple adrTuple = new AddressedTuple(t, tuple); executor.getExecutorTransfer().tryTransfer(adrTuple, executor.getPendingEmits()); } @@ -179,4 +196,22 @@ private List sendSpoutMsg(String stream, List values, Object me } return outTasks; } + + /** + * Records the root span of one emit (started and ended at once) and returns a context holding + * it, or null when no OpenTelemetry SDK is registered as the global instance or the span is not + * valid. Until an SDK is registered the global instance is left unset, so an SDK registered + * later is still picked up. + */ + private Context newRootContext() { + if (tracer == null) { + if (!GlobalOpenTelemetry.isSet()) { + return null; + } + tracer = GlobalOpenTelemetry.get().getTracer("org.apache.storm"); + } + Span root = tracer.spanBuilder(emitSpanName).setNoParent().startSpan(); + root.end(); + return root.getSpanContext().isValid() ? Context.root().with(root) : null; + } } diff --git a/storm-server/pom.xml b/storm-server/pom.xml index ae859c3f5f5..c3995ba519a 100644 --- a/storm-server/pom.xml +++ b/storm-server/pom.xml @@ -112,6 +112,11 @@ awaitility test + + io.opentelemetry + opentelemetry-sdk-testing + test + commons-io commons-io diff --git a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java new file mode 100644 index 00000000000..075fff854a5 --- /dev/null +++ b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java @@ -0,0 +1,146 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm; + +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension; +import io.opentelemetry.sdk.trace.data.SpanData; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.concurrent.ConcurrentHashMap; +import java.util.stream.Collectors; +import org.apache.storm.ILocalCluster.ILocalTopology; +import org.apache.storm.generated.StormTopology; +import org.apache.storm.task.OutputCollector; +import org.apache.storm.task.TopologyContext; +import org.apache.storm.testing.AckFailMapTracker; +import org.apache.storm.testing.FeederSpout; +import org.apache.storm.topology.OutputFieldsDeclarer; +import org.apache.storm.topology.TopologyBuilder; +import org.apache.storm.topology.base.BaseRichBolt; +import org.apache.storm.tuple.Fields; +import org.apache.storm.tuple.Tuple; +import org.apache.storm.tuple.TupleImpl; +import org.apache.storm.tuple.Values; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * Runs topologies on a two-worker local cluster with tracing on or off and checks the spans + * Storm exports. + */ +public class TopologyTracingTest { + + @RegisterExtension + static final OpenTelemetryExtension OTEL = OpenTelemetryExtension.create(); + + /** Trace ids of the contexts carried by the tuples the sink received. */ + private static final Set RECEIVED_TRACE_IDS = ConcurrentHashMap.newKeySet(); + + private static ILocalCluster cluster; + private static int topologyCount; + + @BeforeAll + public static void startCluster() throws Exception { + cluster = new LocalCluster(); + } + + @AfterAll + public static void stopCluster() throws Exception { + cluster.close(); + } + + @Test + public void testEachSpoutEmitStartsARootSpan() throws Exception { + List spans = runSpoutToSink(true, 3); + + List emits = named(spans, "spout emit"); + assertEquals(3, emits.size()); + for (SpanData emit : emits) { + assertFalse(emit.getParentSpanContext().isValid(), "a spout emit starts a new trace"); + } + Set emitTraceIds = + emits.stream().map(SpanData::getTraceId).collect(Collectors.toSet()); + assertEquals(3, emitTraceIds.size()); + assertEquals(emitTraceIds, RECEIVED_TRACE_IDS, "each tuple carries its emit context"); + } + + @Test + public void testNoSpansWhenTracingIsOff() throws Exception { + assertTrue(runSpoutToSink(false, 1).isEmpty()); + } + + /** + * Feeds {@code count} tuples from spout "spout" to bolt "sink" on two workers, waits until all + * are acked and returns the spans exported meanwhile. + */ + private List runSpoutToSink(boolean tracing, int count) throws Exception { + FeederSpout spout = new FeederSpout(new Fields("value")); + AckFailMapTracker tracker = new AckFailMapTracker(); + spout.setAckFailDelegate(tracker); + TopologyBuilder builder = new TopologyBuilder(); + builder.setSpout("spout", spout); + builder.setBolt("sink", new SinkBolt()).shuffleGrouping("spout"); + + Config conf = new Config(); + conf.setNumWorkers(2); + conf.put(Config.TOPOLOGY_TRACING_ENABLED, tracing); + OTEL.clearSpans(); + RECEIVED_TRACE_IDS.clear(); + String name = "tracing-" + topologyCount++; + StormTopology topology = builder.createTopology(); + try (ILocalTopology ignored = cluster.submitTopology(name, conf, topology)) { + Object[] ids = new Object[count]; + for (int i = 0; i < count; i++) { + ids[i] = i; + spout.feed(new Values("v" + i), i); + } + AssertLoop.assertAcked(tracker, ids); + return OTEL.getSpans(); + } + } + + private static List named(List spans, String name) { + return spans.stream().filter(s -> s.getName().equals(name)).collect(Collectors.toList()); + } + + private static class SinkBolt extends BaseRichBolt { + private OutputCollector collector; + + @Override + public void prepare(Map conf, TopologyContext context, + OutputCollector collector) { + this.collector = collector; + } + + @Override + public void execute(Tuple input) { + if (((TupleImpl) input).getTraceContext() != null) { + Span span = Span.fromContext(((TupleImpl) input).getTraceContext()); + RECEIVED_TRACE_IDS.add(span.getSpanContext().getTraceId()); + } + collector.ack(input); + } + + @Override + public void declareOutputFields(OutputFieldsDeclarer declarer) { + } + } +} From 9caa98271f66db96282e43363239cc63d80e2b70 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Tue, 29 Sep 2026 09:11:16 +0200 Subject: [PATCH 03/12] feat: run bolt execute() inside a span when the tuple carries a trace context BoltExecutor runs execute() inside a span named " 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. --- .../src/jvm/org/apache/storm/Config.java | 7 +- .../org/apache/storm/executor/Executor.java | 17 ++++ .../storm/executor/bolt/BoltExecutor.java | 27 +++++- .../spout/SpoutOutputCollectorImpl.java | 12 +-- .../org/apache/storm/TopologyTracingTest.java | 84 +++++++++++++++++-- 5 files changed, 127 insertions(+), 20 deletions(-) diff --git a/storm-client/src/jvm/org/apache/storm/Config.java b/storm-client/src/jvm/org/apache/storm/Config.java index 35bdfe274c1..13fe762a014 100644 --- a/storm-client/src/jvm/org/apache/storm/Config.java +++ b/storm-client/src/jvm/org/apache/storm/Config.java @@ -1651,9 +1651,10 @@ public class Config extends HashMap { /** * Enables OpenTelemetry tracing for the topology. When {@code true}, every spout emit starts - * a root span, and tuples carry the trace context between components and workers. Spans are - * recorded and exported by the OpenTelemetry SDK registered as the global instance, usually by - * the OpenTelemetry Java agent; without one, Storm creates no spans. Default: {@code false}. + * a root span, every bolt execute() of a tuple that carries a trace context runs in a child + * span, and tuples carry the trace context between components and workers. Spans are recorded + * and exported by the OpenTelemetry SDK registered as the global instance, usually by the + * OpenTelemetry Java agent; without one, Storm creates no spans. Default: {@code false}. */ @IsBoolean public static final String TOPOLOGY_TRACING_ENABLED = "topology.tracing.enabled"; diff --git a/storm-client/src/jvm/org/apache/storm/executor/Executor.java b/storm-client/src/jvm/org/apache/storm/executor/Executor.java index 9a319bf07cc..8e13578bc08 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/Executor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/Executor.java @@ -19,6 +19,8 @@ import com.codahale.metrics.Metered; import com.codahale.metrics.Snapshot; import com.codahale.metrics.Timer; +import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.api.trace.Tracer; import java.io.IOException; import java.lang.reflect.Field; import java.net.UnknownHostException; @@ -108,6 +110,7 @@ public abstract class Executor implements Callable, JCQueue.Consumer { protected final CountDownLatch workerReady; protected final AtomicBoolean stormActive; protected final AtomicReference> stormComponentDebug; + private volatile Tracer tracer; protected final Runnable suicideFn; protected final IStormClusterState stormClusterState; protected final Map taskToComponent; @@ -781,6 +784,20 @@ public String getComponentId() { return componentId; } + /** + * Returns the tracer, or null until an OpenTelemetry SDK is registered as the global instance. + * Checking isSet() instead of calling get() leaves the global unset, so an SDK registered later + * is still used. Safe to call from any thread. + */ + public Tracer tracer() { + Tracer current = tracer; + if (current == null && GlobalOpenTelemetry.isSet()) { + current = GlobalOpenTelemetry.get().getTracer("org.apache.storm"); + tracer = current; + } + return current; + } + public AtomicBoolean getOpenOrPrepareWasCalled() { return openOrPrepareWasCalled; } diff --git a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java index 47a4940e72f..80657d6c022 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java @@ -12,6 +12,10 @@ package org.apache.storm.executor.bolt; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.Tracer; +import io.opentelemetry.context.Context; +import io.opentelemetry.context.Scope; import java.util.ArrayList; import java.util.HashMap; import java.util.List; @@ -60,12 +64,14 @@ public class BoltExecutor extends Executor { private final IWaitStrategy consumeWaitStrategy; // employed when no incoming data private final IWaitStrategy backPressureWaitStrategy; // employed when outbound path is congested private final BoltExecutorStats stats; + private final String executeSpanName; private BoltOutputCollectorImpl outputCollector; public BoltExecutor(WorkerState workerData, List executorId, Map credentials) { super(workerData, executorId, credentials, ClientStatsUtil.BOLT); this.executeSampler = ConfigUtils.mkStatsSampler(topoConf); this.isSystemBoltExecutor = (executorId == Constants.SYSTEM_EXECUTOR_ID); + this.executeSpanName = componentId + " execute"; if (isSystemBoltExecutor) { this.consumeWaitStrategy = makeSystemBoltWaitStrategy(); } else { @@ -214,7 +220,6 @@ public void tupleActionFn(int taskId, TupleImpl tuple) throws Exception { this.updateChildEwmaStats(idToTask.get(taskId - idToTaskBase), tuple); } } else { - IBolt boltObject = (IBolt) idToTask.get(taskId - idToTaskBase).getTaskObject(); boolean isSampled = sampler.getAsBoolean(); boolean isExecuteSampler = executeSampler.getAsBoolean(); Long now = (isSampled || isExecuteSampler) ? Time.currentTimeMillis() : null; @@ -224,7 +229,14 @@ public void tupleActionFn(int taskId, TupleImpl tuple) throws Exception { if (isExecuteSampler) { tuple.setExecuteSampleStartTime(now); } - boltObject.execute(tuple); + IBolt boltObject = (IBolt) idToTask.get(taskId - idToTaskBase).getTaskObject(); + Context received = tuple.getTraceContext(); + Tracer tracer = received == null ? null : tracer(); + if (tracer == null) { + boltObject.execute(tuple); + } else { + executeInSpan(tracer, boltObject, tuple, received); + } Long ms = tuple.getExecuteSampleStartTime(); long delta = (ms != null) ? Time.deltaMs(ms) : -1; @@ -245,4 +257,15 @@ public void tupleActionFn(int taskId, TupleImpl tuple) throws Exception { } } } + + private void executeInSpan(Tracer tracer, IBolt bolt, TupleImpl tuple, Context received) { + Span span = tracer.spanBuilder(executeSpanName).setParent(received).startSpan(); + // anchored emits take their parent from the tuple, also after execute() returns + tuple.setTraceContext(received.with(span)); + try (Scope ignored = span.makeCurrent()) { + bolt.execute(tuple); + } finally { + span.end(); + } + } } diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java index 2926d2ac0d5..f81a9eeb39e 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java @@ -12,7 +12,6 @@ package org.apache.storm.executor.spout; -import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Context; @@ -53,7 +52,6 @@ public class SpoutOutputCollectorImpl implements ISpoutOutputCollector { private final long spoutExecutorThdId; private final boolean tracingEnabled; private final String emitSpanName; - private Tracer tracer; private TupleInfo globalTupleInfo = new TupleInfo(); // thread safety: assumes Collector.emit*() calls are externally synchronized (if needed). @@ -199,16 +197,12 @@ private List sendSpoutMsg(String stream, List values, Object me /** * Records the root span of one emit (started and ended at once) and returns a context holding - * it, or null when no OpenTelemetry SDK is registered as the global instance or the span is not - * valid. Until an SDK is registered the global instance is left unset, so an SDK registered - * later is still picked up. + * it, or null when no OpenTelemetry SDK is registered yet or the span is not valid. */ private Context newRootContext() { + Tracer tracer = executor.tracer(); if (tracer == null) { - if (!GlobalOpenTelemetry.isSet()) { - return null; - } - tracer = GlobalOpenTelemetry.get().getTracer("org.apache.storm"); + return null; } Span root = tracer.spanBuilder(emitSpanName).setNoParent().startSpan(); root.end(); diff --git a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java index 075fff854a5..4af20979711 100644 --- a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java +++ b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java @@ -13,12 +13,17 @@ package org.apache.storm; import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension; import io.opentelemetry.sdk.trace.data.SpanData; import java.util.List; import java.util.Map; import java.util.Set; import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.function.Function; import java.util.stream.Collectors; import org.apache.storm.ILocalCluster.ILocalTopology; import org.apache.storm.generated.StormTopology; @@ -33,6 +38,8 @@ import org.apache.storm.tuple.Tuple; import org.apache.storm.tuple.TupleImpl; import org.apache.storm.tuple.Values; +import org.apache.storm.utils.TupleUtils; +import org.awaitility.Awaitility; import org.junit.jupiter.api.AfterAll; import org.junit.jupiter.api.BeforeAll; import org.junit.jupiter.api.Test; @@ -40,6 +47,7 @@ import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNotNull; import static org.junit.jupiter.api.Assertions.assertTrue; /** @@ -53,6 +61,12 @@ public class TopologyTracingTest { /** Trace ids of the contexts carried by the tuples the sink received. */ private static final Set RECEIVED_TRACE_IDS = ConcurrentHashMap.newKeySet(); + /** Span ids that were current on the bolt thread while execute() ran. */ + private static final Set CURRENT_IN_EXECUTE = ConcurrentHashMap.newKeySet(); + /** Tick tuples the sink received. */ + private static final AtomicInteger TICK_TUPLES_RECEIVED = new AtomicInteger(); + /** Set when a span was still current on the bolt thread while a tick tuple was handled. */ + private static final AtomicBoolean SPAN_CURRENT_DURING_TICK = new AtomicBoolean(); private static ILocalCluster cluster; private static int topologyCount; @@ -69,7 +83,7 @@ public static void stopCluster() throws Exception { @Test public void testEachSpoutEmitStartsARootSpan() throws Exception { - List spans = runSpoutToSink(true, 3); + List spans = runSpoutToSink(true, 3, 1, 0); // 3 tuples, 1 sink task, no ticks List emits = named(spans, "spout emit"); assertEquals(3, emits.size()); @@ -84,26 +98,66 @@ public void testEachSpoutEmitStartsARootSpan() throws Exception { @Test public void testNoSpansWhenTracingIsOff() throws Exception { - assertTrue(runSpoutToSink(false, 1).isEmpty()); + assertTrue(runSpoutToSink(false, 1, 1, 0).isEmpty()); // 1 tuple, 1 sink task, no ticks + } + + @Test + public void testExecuteSpanIsChildOfTheEmitAndCurrentDuringExecute() throws Exception { + // two sink tasks with all grouping: on two workers, a copy of each tuple crosses workers + List spans = runSpoutToSink(true, 2, 2, 0); // 2 tuples, 2 sink tasks, no ticks + + Map emits = named(spans, "spout emit").stream() + .collect(Collectors.toMap(SpanData::getSpanId, Function.identity())); + List executes = named(spans, "sink execute"); + assertEquals(2, emits.size()); + assertEquals(4, executes.size()); + for (SpanData execute : executes) { + SpanData emit = emits.get(execute.getParentSpanId()); + assertNotNull(emit, "an execute span is a child of the emit that produced its tuple"); + assertEquals(emit.getTraceId(), execute.getTraceId()); + } + assertTrue(executes.stream().anyMatch(s -> s.getParentSpanContext().isRemote()), + "at least one tuple crossed workers, so its context went through the serializer"); + Set executeIds = + executes.stream().map(SpanData::getSpanId).collect(Collectors.toSet()); + assertEquals(executeIds, CURRENT_IN_EXECUTE, "the execute span is current in the bolt"); + } + + @Test + public void testTickTuplesGetNoSpanAndSeeNoLeftoverContext() throws Exception { + List spans = runSpoutToSink(true, 1, 1, 1); // 1 tuple, 1 sink task, 1 s ticks + + assertEquals(1, named(spans, "sink execute").size()); + assertFalse(SPAN_CURRENT_DURING_TICK.get(), "the execute span's scope was closed"); } /** - * Feeds {@code count} tuples from spout "spout" to bolt "sink" on two workers, waits until all - * are acked and returns the spans exported meanwhile. + * Feeds {@code count} tuples from spout "spout" to bolt "sink" (all grouping) on two workers, + * waits until all are acked, all expected spans are exported and, when {@code tickSecs} is + * positive, until the sink got two tick tuples. Returns the exported spans. */ - private List runSpoutToSink(boolean tracing, int count) throws Exception { + private List runSpoutToSink(boolean tracing, int count, int sinkTasks, int tickSecs) + throws Exception { FeederSpout spout = new FeederSpout(new Fields("value")); AckFailMapTracker tracker = new AckFailMapTracker(); spout.setAckFailDelegate(tracker); TopologyBuilder builder = new TopologyBuilder(); builder.setSpout("spout", spout); - builder.setBolt("sink", new SinkBolt()).shuffleGrouping("spout"); + builder.setBolt("sink", new SinkBolt(), sinkTasks).allGrouping("spout"); Config conf = new Config(); conf.setNumWorkers(2); conf.put(Config.TOPOLOGY_TRACING_ENABLED, tracing); + if (tickSecs > 0) { + conf.put(Config.TOPOLOGY_TICK_TUPLE_FREQ_SECS, tickSecs); + } OTEL.clearSpans(); RECEIVED_TRACE_IDS.clear(); + CURRENT_IN_EXECUTE.clear(); + TICK_TUPLES_RECEIVED.set(0); + SPAN_CURRENT_DURING_TICK.set(false); + // one emit span per tuple and one execute span per tuple and sink task + int expectedSpans = tracing ? count * (1 + sinkTasks) : 0; String name = "tracing-" + topologyCount++; StormTopology topology = builder.createTopology(); try (ILocalTopology ignored = cluster.submitTopology(name, conf, topology)) { @@ -113,6 +167,13 @@ private List runSpoutToSink(boolean tracing, int count) throws Excepti spout.feed(new Values("v" + i), i); } AssertLoop.assertAcked(tracker, ids); + // an execute span ends after the bolt acked, so the ack can arrive before the span + Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) + .until(() -> OTEL.getSpans().size() >= expectedSpans); + if (tickSecs > 0) { + Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) + .until(() -> TICK_TUPLES_RECEIVED.get() >= 2); + } return OTEL.getSpans(); } } @@ -132,10 +193,21 @@ public void prepare(Map conf, TopologyContext context, @Override public void execute(Tuple input) { + if (TupleUtils.isTick(input)) { + if (Span.current().getSpanContext().isValid()) { + SPAN_CURRENT_DURING_TICK.set(true); + } + TICK_TUPLES_RECEIVED.incrementAndGet(); + return; + } if (((TupleImpl) input).getTraceContext() != null) { Span span = Span.fromContext(((TupleImpl) input).getTraceContext()); RECEIVED_TRACE_IDS.add(span.getSpanContext().getTraceId()); } + SpanContext current = Span.current().getSpanContext(); + if (current.isValid()) { + CURRENT_IN_EXECUTE.add(current.getSpanId()); + } collector.ack(input); } From 248de7592b6b7d3e07922fa5f2a9202fe0cb94c8 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Tue, 29 Sep 2026 09:34:41 +0200 Subject: [PATCH 04/12] feat: derive the trace context of bolt emits from their anchors 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 " 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. --- .../src/jvm/org/apache/storm/Config.java | 10 +- .../org/apache/storm/executor/Executor.java | 28 +++ .../bolt/BoltOutputCollectorImpl.java | 61 ++++++ .../spout/SpoutOutputCollectorImpl.java | 29 +-- .../org/apache/storm/TopologyTracingTest.java | 191 +++++++++++++++--- 5 files changed, 268 insertions(+), 51 deletions(-) diff --git a/storm-client/src/jvm/org/apache/storm/Config.java b/storm-client/src/jvm/org/apache/storm/Config.java index 13fe762a014..541899abd39 100644 --- a/storm-client/src/jvm/org/apache/storm/Config.java +++ b/storm-client/src/jvm/org/apache/storm/Config.java @@ -1650,11 +1650,11 @@ public class Config extends HashMap { public static final String TOPOLOGY_TUPLE_COMPRESSION_MAX_DECOMPRESSED_BYTES = "topology.tuple.compression.max.decompressed.bytes"; /** - * Enables OpenTelemetry tracing for the topology. When {@code true}, every spout emit starts - * a root span, every bolt execute() of a tuple that carries a trace context runs in a child - * span, and tuples carry the trace context between components and workers. Spans are recorded - * and exported by the OpenTelemetry SDK registered as the global instance, usually by the - * OpenTelemetry Java agent; without one, Storm creates no spans. Default: {@code false}. + * Enables OpenTelemetry tracing. Each spout emit, except checkpoint tuples, starts a trace, + * each bolt execute() of a traced tuple runs in a child span, and bolt emits carry a context + * derived from their anchors. Spans are recorded by the OpenTelemetry SDK registered as the + * global instance, usually by the OpenTelemetry Java agent; without one, Storm records nothing. + * Default: {@code false}. */ @IsBoolean public static final String TOPOLOGY_TRACING_ENABLED = "topology.tracing.enabled"; diff --git a/storm-client/src/jvm/org/apache/storm/executor/Executor.java b/storm-client/src/jvm/org/apache/storm/executor/Executor.java index 8e13578bc08..b9db71108e9 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/Executor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/Executor.java @@ -20,11 +20,16 @@ import com.codahale.metrics.Snapshot; import com.codahale.metrics.Timer; import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanBuilder; +import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.api.trace.Tracer; +import io.opentelemetry.context.Context; import java.io.IOException; import java.lang.reflect.Field; import java.net.UnknownHostException; import java.util.ArrayList; +import java.util.Collection; import java.util.Collections; import java.util.HashMap; import java.util.HashSet; @@ -110,6 +115,7 @@ public abstract class Executor implements Callable, JCQueue.Consumer { protected final CountDownLatch workerReady; protected final AtomicBoolean stormActive; protected final AtomicReference> stormComponentDebug; + private final boolean tracingEnabled; private volatile Tracer tracer; protected final Runnable suicideFn; protected final IStormClusterState stormClusterState; @@ -152,6 +158,8 @@ protected Executor(WorkerState workerData, List executorId, Map links) { + Tracer current = tracer(); + if (current == null) { + return null; + } + SpanBuilder builder = current.spanBuilder(spanName).setNoParent(); + links.forEach(builder::addLink); + Span span = builder.startSpan(); + span.end(); + return span.getSpanContext().isValid() ? Context.root().with(span) : null; + } + public AtomicBoolean getOpenOrPrepareWasCalled() { return openOrPrepareWasCalled; } diff --git a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java index 886a00c7f89..428e60c69f3 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java @@ -12,8 +12,12 @@ package org.apache.storm.executor.bolt; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.context.Context; import java.util.Collection; import java.util.HashMap; +import java.util.LinkedHashSet; import java.util.List; import java.util.Map; import java.util.Random; @@ -37,6 +41,7 @@ public class BoltOutputCollectorImpl implements IOutputCollector { private static final Logger LOG = LoggerFactory.getLogger(BoltOutputCollectorImpl.class); + private static final long UNANCHORED_LOG_INTERVAL_MS = 60_000; private final BoltExecutor executor; private final Task task; @@ -46,6 +51,8 @@ public class BoltOutputCollectorImpl implements IOutputCollector { private final ExecutorTransfer xsfer; private final boolean isDebug; private boolean ackingEnabled; + private final String emitSpanName; + private volatile long lastUnanchoredLogMs; public BoltOutputCollectorImpl(BoltExecutor executor, Task taskData, Random random, boolean isEventLoggers, boolean ackingEnabled, boolean isDebug) { @@ -57,6 +64,7 @@ public BoltOutputCollectorImpl(BoltExecutor executor, Task taskData, Random rand this.ackingEnabled = ackingEnabled; this.isDebug = isDebug; this.xsfer = executor.getExecutorTransfer(); + this.emitSpanName = executor.getComponentId() + " emit"; } @Override @@ -87,6 +95,14 @@ private List boltEmit(String streamId, Collection anchors, List< } else { outTasks = task.getOutgoingTasks(streamId, values); } + Context traceContext = null; + if (executor.isTracingEnabled()) { + if (anchors == null || anchors.isEmpty()) { + logUnanchoredEmitUnderSpan(streamId); + } else { + traceContext = traceContextFor(anchors); + } + } for (int i = 0; i < outTasks.size(); ++i) { Integer t = outTasks.get(i); @@ -109,6 +125,9 @@ private List boltEmit(String streamId, Collection anchors, List< } TupleImpl tupleExt = new TupleImpl( executor.getWorkerTopologyContext(), values, executor.getComponentId(), taskId, streamId, msgId); + if (traceContext != null) { + tupleExt.setTraceContext(traceContext); + } xsfer.tryTransfer(new AddressedTuple(t, tupleExt), executor.getPendingEmits()); } if (isEventLoggers) { @@ -117,6 +136,48 @@ private List boltEmit(String streamId, Collection anchors, List< return outTasks; } + /** + * Runs on the emitting thread. If the traced anchors share one span, returns their context. If + * they carry several, returns a new root linked to each (the SDK keeps up to 128 links by + * default), or null when no SDK is registered on this worker. + */ + private Context traceContextFor(Collection anchors) { + Context first = null; + Set linkedSpans = null; + for (Tuple anchor : anchors) { + Context context = anchor instanceof TupleImpl impl ? impl.getTraceContext() : null; + if (context == null) { + continue; + } + if (first == null) { + first = context; + } else { + if (linkedSpans == null) { + linkedSpans = new LinkedHashSet<>(); + linkedSpans.add(Span.fromContext(first).getSpanContext()); + } + linkedSpans.add(Span.fromContext(context).getSpanContext()); + } + } + if (linkedSpans == null || linkedSpans.size() == 1) { + return first; + } + return executor.newRootContext(emitSpanName, linkedSpans); + } + + private void logUnanchoredEmitUnderSpan(String streamId) { + if (!LOG.isDebugEnabled() || !Span.current().getSpanContext().isValid()) { + return; + } + long now = Time.currentTimeMillis(); + if (now - lastUnanchoredLogMs < UNANCHORED_LOG_INTERVAL_MS) { + return; + } + lastUnanchoredLogMs = now; + LOG.debug("{} emitted on stream {} without anchors while a span was current; " + + "the emitted tuple carries no trace context", executor.getComponentId(), streamId); + } + @Override public void ack(Tuple input) { if (!ackingEnabled) { diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java index f81a9eeb39e..b9a005a650e 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java @@ -12,16 +12,15 @@ package org.apache.storm.executor.spout; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Context; import java.util.ArrayList; +import java.util.Collections; import java.util.List; import java.util.Random; -import org.apache.storm.Config; import org.apache.storm.daemon.Acker; import org.apache.storm.daemon.Task; import org.apache.storm.executor.TupleInfo; +import org.apache.storm.spout.CheckpointSpout; import org.apache.storm.spout.ISpout; import org.apache.storm.spout.ISpoutOutputCollector; import org.apache.storm.tuple.AddressedTuple; @@ -29,7 +28,6 @@ import org.apache.storm.tuple.TupleImpl; import org.apache.storm.tuple.Values; import org.apache.storm.utils.MutableLong; -import org.apache.storm.utils.ObjectReader; import org.apache.storm.utils.RotatingMap; import org.apache.storm.utils.Utils; import org.slf4j.Logger; @@ -50,7 +48,6 @@ public class SpoutOutputCollectorImpl implements ISpoutOutputCollector { private final Boolean isDebug; private final RotatingMap pending; private final long spoutExecutorThdId; - private final boolean tracingEnabled; private final String emitSpanName; private TupleInfo globalTupleInfo = new TupleInfo(); // thread safety: assumes Collector.emit*() calls are externally synchronized (if needed). @@ -69,8 +66,6 @@ public SpoutOutputCollectorImpl(ISpout spout, SpoutExecutor executor, Task taskD this.isDebug = isDebug; this.pending = pending; this.spoutExecutorThdId = executor.getThreadId(); - Object tracing = executor.getTopoConf().get(Config.TOPOLOGY_TRACING_ENABLED); - this.tracingEnabled = ObjectReader.getBoolean(tracing, false); this.emitSpanName = executor.getComponentId() + " emit"; } @@ -133,7 +128,11 @@ private List sendSpoutMsg(String stream, List values, Object me final long rootId = needAck ? MessageId.generateId(random) : 0; - final Context traceContext = tracingEnabled ? newRootContext() : null; + // checkpoint tuples of stateful bolts are system tuples: no trace + boolean traced = executor.isTracingEnabled() + && !CheckpointSpout.CHECKPOINT_STREAM_ID.equals(stream); + final Context traceContext = + traced ? executor.newRootContext(emitSpanName, Collections.emptyList()) : null; for (int i = 0; i < outTasks.size(); i++) { // perf critical path. don't use iterators. Integer t = outTasks.get(i); @@ -194,18 +193,4 @@ private List sendSpoutMsg(String stream, List values, Object me } return outTasks; } - - /** - * Records the root span of one emit (started and ended at once) and returns a context holding - * it, or null when no OpenTelemetry SDK is registered yet or the span is not valid. - */ - private Context newRootContext() { - Tracer tracer = executor.tracer(); - if (tracer == null) { - return null; - } - Span root = tracer.spanBuilder(emitSpanName).setNoParent().startSpan(); - root.end(); - return root.getSpanContext().isValid() ? Context.root().with(root) : null; - } } diff --git a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java index 4af20979711..3773a5e9cf7 100644 --- a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java +++ b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java @@ -16,6 +16,7 @@ import io.opentelemetry.api.trace.SpanContext; import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension; import io.opentelemetry.sdk.trace.data.SpanData; +import java.util.Arrays; import java.util.List; import java.util.Map; import java.util.Set; @@ -23,6 +24,8 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicInteger; +import java.util.function.BooleanSupplier; +import java.util.function.Consumer; import java.util.function.Function; import java.util.stream.Collectors; import org.apache.storm.ILocalCluster.ILocalTopology; @@ -59,13 +62,11 @@ public class TopologyTracingTest { @RegisterExtension static final OpenTelemetryExtension OTEL = OpenTelemetryExtension.create(); - /** Trace ids of the contexts carried by the tuples the sink received. */ private static final Set RECEIVED_TRACE_IDS = ConcurrentHashMap.newKeySet(); - /** Span ids that were current on the bolt thread while execute() ran. */ + /** Span ids that were current on the sink's thread while its execute() ran. */ private static final Set CURRENT_IN_EXECUTE = ConcurrentHashMap.newKeySet(); - /** Tick tuples the sink received. */ + private static final AtomicInteger SINK_TUPLES_RECEIVED = new AtomicInteger(); private static final AtomicInteger TICK_TUPLES_RECEIVED = new AtomicInteger(); - /** Set when a span was still current on the bolt thread while a tick tuple was handled. */ private static final AtomicBoolean SPAN_CURRENT_DURING_TICK = new AtomicBoolean(); private static ILocalCluster cluster; @@ -106,8 +107,7 @@ public void testExecuteSpanIsChildOfTheEmitAndCurrentDuringExecute() throws Exce // two sink tasks with all grouping: on two workers, a copy of each tuple crosses workers List spans = runSpoutToSink(true, 2, 2, 0); // 2 tuples, 2 sink tasks, no ticks - Map emits = named(spans, "spout emit").stream() - .collect(Collectors.toMap(SpanData::getSpanId, Function.identity())); + Map emits = byId(named(spans, "spout emit")); List executes = named(spans, "sink execute"); assertEquals(2, emits.size()); assertEquals(4, executes.size()); @@ -131,33 +131,120 @@ public void testTickTuplesGetNoSpanAndSeeNoLeftoverContext() throws Exception { assertFalse(SPAN_CURRENT_DURING_TICK.get(), "the execute span's scope was closed"); } + @Test + public void testAnchoredEmitContinuesTheTrace() throws Exception { + // per tuple: spout emit, middle execute, sink execute + List spans = runThroughMiddle(EmitMode.ANCHORED, 2, 6, 2); + + assertSinkExecutesAreChildrenOfMiddleExecutes(spans, 2); + } + + @Test + public void testAnchorsCarryingTheSameSpanAddNoMergeSpan() throws Exception { + // per tuple: spout emit, middle execute, sink execute; the emit anchors the input twice + List spans = runThroughMiddle(EmitMode.ANCHORED_TWICE, 2, 6, 2); + + assertTrue(named(spans, "middle emit").isEmpty()); + assertSinkExecutesAreChildrenOfMiddleExecutes(spans, 2); + } + + @Test + public void testEmitAnchoredToTwoTracedTuplesStartsARootWithTwoLinks() throws Exception { + // 2 spout emits, 2 middle executes, 1 merge span, 1 sink execute + List spans = runThroughMiddle(EmitMode.JOIN, 2, 6, 1); + + List merges = named(spans, "middle emit"); + assertEquals(1, merges.size()); + SpanData merge = merges.get(0); + assertFalse(merge.getParentSpanContext().isValid(), "a merge starts a new trace"); + Set linked = merge.getLinks().stream() + .map(link -> link.getSpanContext().getSpanId()).collect(Collectors.toSet()); + assertEquals(byId(named(spans, "middle execute")).keySet(), linked); + List sinks = named(spans, "sink execute"); + assertEquals(1, sinks.size()); + assertEquals(merge.getSpanId(), sinks.get(0).getParentSpanId()); + } + + @Test + public void testUnanchoredEmitCarriesNoContext() throws Exception { + // per tuple: spout emit, middle execute; the sink gets untraced tuples + List spans = runThroughMiddle(EmitMode.UNANCHORED, 2, 4, 2); + + assertEquals(2, named(spans, "middle execute").size()); + assertTrue(named(spans, "sink execute").isEmpty()); + assertTrue(RECEIVED_TRACE_IDS.isEmpty(), "the sink's tuples carry no context"); + } + + private static void assertSinkExecutesAreChildrenOfMiddleExecutes(List spans, + int count) { + Map middles = byId(named(spans, "middle execute")); + List sinks = named(spans, "sink execute"); + assertEquals(count, middles.size()); + assertEquals(count, sinks.size()); + for (SpanData sink : sinks) { + SpanData middle = middles.get(sink.getParentSpanId()); + assertNotNull(middle, "the emit carries the middle execute span as parent"); + assertEquals(middle.getTraceId(), sink.getTraceId()); + } + } + /** - * Feeds {@code count} tuples from spout "spout" to bolt "sink" (all grouping) on two workers, - * waits until all are acked, all expected spans are exported and, when {@code tickSecs} is - * positive, until the sink got two tick tuples. Returns the exported spans. + * Spout to sink (all grouping). With {@code tickSecs} positive, also waits for two ticks. */ private List runSpoutToSink(boolean tracing, int count, int sinkTasks, int tickSecs) throws Exception { + Config conf = conf(tracing); + if (tickSecs > 0) { + conf.put(Config.TOPOLOGY_TICK_TUPLE_FREQ_SECS, tickSecs); + } + // one emit span per tuple and one execute span per tuple and sink task + int expectedSpans = tracing ? count * (1 + sinkTasks) : 0; + return runTopology(conf, count, + builder -> builder.setBolt("sink", new SinkBolt(), sinkTasks).allGrouping("spout"), + () -> OTEL.getSpans().size() >= expectedSpans + && (tickSecs == 0 || TICK_TUPLES_RECEIVED.get() >= 2)); + } + + /** + * Spout to middle (one task, which JOIN needs; emitting as {@code mode} says) to sink. + */ + private List runThroughMiddle(EmitMode mode, int count, int expectedSpans, + int sinkTuples) throws Exception { + return runTopology(conf(true), count, + builder -> { + builder.setBolt("middle", new MiddleBolt(mode)).shuffleGrouping("spout"); + builder.setBolt("sink", new SinkBolt()).shuffleGrouping("middle"); + }, + () -> OTEL.getSpans().size() >= expectedSpans + && SINK_TUPLES_RECEIVED.get() >= sinkTuples); + } + + private static Config conf(boolean tracing) { + Config conf = new Config(); + conf.setNumWorkers(2); + conf.put(Config.TOPOLOGY_TRACING_ENABLED, tracing); + return conf; + } + + /** + * Feeds {@code count} tuples to spout "spout", waits for the acks and {@code done}, and + * returns the exported spans. + */ + private List runTopology(Config conf, int count, Consumer bolts, + BooleanSupplier done) throws Exception { FeederSpout spout = new FeederSpout(new Fields("value")); AckFailMapTracker tracker = new AckFailMapTracker(); spout.setAckFailDelegate(tracker); TopologyBuilder builder = new TopologyBuilder(); builder.setSpout("spout", spout); - builder.setBolt("sink", new SinkBolt(), sinkTasks).allGrouping("spout"); + bolts.accept(builder); - Config conf = new Config(); - conf.setNumWorkers(2); - conf.put(Config.TOPOLOGY_TRACING_ENABLED, tracing); - if (tickSecs > 0) { - conf.put(Config.TOPOLOGY_TICK_TUPLE_FREQ_SECS, tickSecs); - } OTEL.clearSpans(); RECEIVED_TRACE_IDS.clear(); CURRENT_IN_EXECUTE.clear(); + SINK_TUPLES_RECEIVED.set(0); TICK_TUPLES_RECEIVED.set(0); SPAN_CURRENT_DURING_TICK.set(false); - // one emit span per tuple and one execute span per tuple and sink task - int expectedSpans = tracing ? count * (1 + sinkTasks) : 0; String name = "tracing-" + topologyCount++; StormTopology topology = builder.createTopology(); try (ILocalTopology ignored = cluster.submitTopology(name, conf, topology)) { @@ -167,13 +254,9 @@ private List runSpoutToSink(boolean tracing, int count, int sinkTasks, spout.feed(new Values("v" + i), i); } AssertLoop.assertAcked(tracker, ids); - // an execute span ends after the bolt acked, so the ack can arrive before the span + // spans end after the bolt acked, and unanchored tuples are not tracked by the acks Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) - .until(() -> OTEL.getSpans().size() >= expectedSpans); - if (tickSecs > 0) { - Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) - .until(() -> TICK_TUPLES_RECEIVED.get() >= 2); - } + .until(done::getAsBoolean); return OTEL.getSpans(); } } @@ -182,6 +265,65 @@ private static List named(List spans, String name) { return spans.stream().filter(s -> s.getName().equals(name)).collect(Collectors.toList()); } + private static Map byId(List spans) { + return spans.stream().collect(Collectors.toMap(SpanData::getSpanId, Function.identity())); + } + + private enum EmitMode { + ANCHORED, + /** Anchored to the input twice: both anchors carry the same span. */ + ANCHORED_TWICE, + UNANCHORED, + /** Holds the first input, then emits anchored to both. */ + JOIN + } + + private static class MiddleBolt extends BaseRichBolt { + private final EmitMode mode; + private transient OutputCollector collector; + private transient Tuple held; + + MiddleBolt(EmitMode mode) { + this.mode = mode; + } + + @Override + public void prepare(Map conf, TopologyContext context, + OutputCollector collector) { + this.collector = collector; + } + + @Override + public void execute(Tuple input) { + Values values = new Values(input.getValue(0)); + switch (mode) { + case ANCHORED: + collector.emit(input, values); + break; + case ANCHORED_TWICE: + collector.emit(Arrays.asList(input, input), values); + break; + case UNANCHORED: + collector.emit(values); + break; + default: + if (held == null) { + held = input; + return; + } + collector.emit(Arrays.asList(held, input), values); + collector.ack(held); + held = null; + } + collector.ack(input); + } + + @Override + public void declareOutputFields(OutputFieldsDeclarer declarer) { + declarer.declare(new Fields("value")); + } + } + private static class SinkBolt extends BaseRichBolt { private OutputCollector collector; @@ -208,6 +350,7 @@ public void execute(Tuple input) { if (current.isValid()) { CURRENT_IN_EXECUTE.add(current.getSpanId()); } + SINK_TUPLES_RECEIVED.incrementAndGet(); collector.ack(input); } From 148da9008bdc7323ccc31f832542d2ab048497a6 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Tue, 29 Sep 2026 15:48:11 +0200 Subject: [PATCH 05/12] test: cover delayed emits from another thread and unsampled propagation 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. --- .../org/apache/storm/TopologyTracingTest.java | 123 ++++++++++++++++-- 1 file changed, 114 insertions(+), 9 deletions(-) diff --git a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java index 3773a5e9cf7..e33c737d0cf 100644 --- a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java +++ b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java @@ -12,10 +12,18 @@ package org.apache.storm; +import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.context.Context; +import io.opentelemetry.context.Scope; +import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension; +import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.sdk.trace.data.SpanData; +import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; +import io.opentelemetry.sdk.trace.samplers.Sampler; import java.util.Arrays; import java.util.List; import java.util.Map; @@ -24,6 +32,7 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicReference; import java.util.function.BooleanSupplier; import java.util.function.Consumer; import java.util.function.Function; @@ -50,7 +59,9 @@ import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNotEquals; import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertNull; import static org.junit.jupiter.api.Assertions.assertTrue; /** @@ -66,6 +77,14 @@ public class TopologyTracingTest { /** Span ids that were current on the sink's thread while its execute() ran. */ private static final Set CURRENT_IN_EXECUTE = ConcurrentHashMap.newKeySet(); private static final AtomicInteger SINK_TUPLES_RECEIVED = new AtomicInteger(); + private static final AtomicInteger UNSAMPLED_CONTEXTS_RECEIVED = new AtomicInteger(); + private static final Set MIDDLE_TRACE_IDS = ConcurrentHashMap.newKeySet(); + /** Tuple value to the id of the span current while middle, then sink, handled it. */ + private static final Map MIDDLE_SPAN_BY_VALUE = new ConcurrentHashMap<>(); + private static final Map SINK_SPAN_BY_VALUE = new ConcurrentHashMap<>(); + private static final Map WORKER_PORT_BY_COMPONENT = new ConcurrentHashMap<>(); + private static final AtomicReference EMITTER_THREAD_FAILURE = + new AtomicReference<>(); private static final AtomicInteger TICK_TUPLES_RECEIVED = new AtomicInteger(); private static final AtomicBoolean SPAN_CURRENT_DURING_TICK = new AtomicBoolean(); @@ -100,6 +119,7 @@ public void testEachSpoutEmitStartsARootSpan() throws Exception { @Test public void testNoSpansWhenTracingIsOff() throws Exception { assertTrue(runSpoutToSink(false, 1, 1, 0).isEmpty()); // 1 tuple, 1 sink task, no ticks + assertTrue(RECEIVED_TRACE_IDS.isEmpty(), "tuples carry no context"); } @Test @@ -175,6 +195,47 @@ public void testUnanchoredEmitCarriesNoContext() throws Exception { assertTrue(RECEIVED_TRACE_IDS.isEmpty(), "the sink's tuples carry no context"); } + @Test + public void testDelayedEmitsFromAnotherThreadKeepTheirOwnParents() throws Exception { + // per tuple: spout emit, middle execute, sink execute + List spans = runThroughMiddle(EmitMode.ASYNC_REVERSED, 2, 6, 2); + + assertNull(EMITTER_THREAD_FAILURE.get()); + Map byId = byId(spans); + for (Object value : MIDDLE_SPAN_BY_VALUE.keySet()) { + SpanData sink = byId.get(SINK_SPAN_BY_VALUE.get(value)); + assertEquals(MIDDLE_SPAN_BY_VALUE.get(value), sink.getParentSpanId(), + "the sink span of " + value + " is a child of the middle span of " + value); + } + } + + @Test + public void testUnsampledContextsPropagateAndNothingIsExported() throws Exception { + // parent-based: a sampled flag flipped on the way would export the middle or sink span + InMemorySpanExporter exporter = InMemorySpanExporter.create(); + SdkTracerProvider tracerProvider = SdkTracerProvider.builder() + .setSampler(Sampler.parentBased(Sampler.alwaysOff())) + .addSpanProcessor(SimpleSpanProcessor.create(exporter)) + .build(); + try (OpenTelemetrySdk sdk = + OpenTelemetrySdk.builder().setTracerProvider(tracerProvider).build()) { + GlobalOpenTelemetry.resetForTest(); + GlobalOpenTelemetry.set(sdk); + // spans go to this SDK, not OTEL: wait for the sink only + runThroughMiddle(EmitMode.ANCHORED, 2, 0, 2); + } finally { + GlobalOpenTelemetry.resetForTest(); + GlobalOpenTelemetry.set(OTEL.getOpenTelemetry()); + } + + assertTrue(exporter.getFinishedSpanItems().isEmpty()); + assertEquals(2, UNSAMPLED_CONTEXTS_RECEIVED.get(), "the sink got unsampled contexts"); + assertEquals(MIDDLE_TRACE_IDS, RECEIVED_TRACE_IDS, "the traces continue to the sink"); + // different workers: the contexts went through the serializer + assertNotEquals(WORKER_PORT_BY_COMPONENT.get("middle"), + WORKER_PORT_BY_COMPONENT.get("sink")); + } + private static void assertSinkExecutesAreChildrenOfMiddleExecutes(List spans, int count) { Map middles = byId(named(spans, "middle execute")); @@ -206,7 +267,7 @@ private List runSpoutToSink(boolean tracing, int count, int sinkTasks, } /** - * Spout to middle (one task, which JOIN needs; emitting as {@code mode} says) to sink. + * Spout to middle (one task, which JOIN and ASYNC_REVERSED need) to sink. */ private List runThroughMiddle(EmitMode mode, int count, int expectedSpans, int sinkTuples) throws Exception { @@ -243,6 +304,12 @@ private List runTopology(Config conf, int count, Consumer conf, TopologyContext context, OutputCollector collector) { this.collector = collector; + WORKER_PORT_BY_COMPONENT.put("middle", context.getThisWorkerPort()); } @Override public void execute(Tuple input) { + SpanContext current = Span.current().getSpanContext(); + MIDDLE_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); + MIDDLE_TRACE_IDS.add(current.getTraceId()); + if ((mode == EmitMode.JOIN || mode == EmitMode.ASYNC_REVERSED) && held == null) { + held = input; + return; + } Values values = new Values(input.getValue(0)); switch (mode) { case ANCHORED: @@ -306,18 +387,36 @@ public void execute(Tuple input) { case UNANCHORED: collector.emit(values); break; - default: - if (held == null) { - held = input; - return; - } + case JOIN: collector.emit(Arrays.asList(held, input), values); collector.ack(held); held = null; + break; + case ASYNC_REVERSED: + Tuple first = held; + held = null; + new Thread(() -> emitReversed(first, input)).start(); + return; + default: + throw new IllegalStateException("unknown mode " + mode); } collector.ack(input); } + private void emitReversed(Tuple first, Tuple second) { + try { + Context firstContext = ((TupleImpl) first).getTraceContext(); + try (Scope ignored = firstContext.makeCurrent()) { + collector.emit(second, new Values(second.getValue(0))); + collector.emit(first, new Values(first.getValue(0))); + } + collector.ack(second); + collector.ack(first); + } catch (Throwable t) { + EMITTER_THREAD_FAILURE.set(t); + } + } + @Override public void declareOutputFields(OutputFieldsDeclarer declarer) { declarer.declare(new Fields("value")); @@ -331,6 +430,7 @@ private static class SinkBolt extends BaseRichBolt { public void prepare(Map conf, TopologyContext context, OutputCollector collector) { this.collector = collector; + WORKER_PORT_BY_COMPONENT.put("sink", context.getThisWorkerPort()); } @Override @@ -343,12 +443,17 @@ public void execute(Tuple input) { return; } if (((TupleImpl) input).getTraceContext() != null) { - Span span = Span.fromContext(((TupleImpl) input).getTraceContext()); - RECEIVED_TRACE_IDS.add(span.getSpanContext().getTraceId()); + SpanContext received = Span.fromContext(((TupleImpl) input).getTraceContext()) + .getSpanContext(); + RECEIVED_TRACE_IDS.add(received.getTraceId()); + if (received.isValid() && !received.isSampled()) { + UNSAMPLED_CONTEXTS_RECEIVED.incrementAndGet(); + } } SpanContext current = Span.current().getSpanContext(); if (current.isValid()) { CURRENT_IN_EXECUTE.add(current.getSpanId()); + SINK_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); } SINK_TUPLES_RECEIVED.incrementAndGet(); collector.ack(input); From cdbc1de224276eac605799469ae606e9e4955f8e Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Wed, 30 Sep 2026 16:22:41 +0200 Subject: [PATCH 06/12] feat: record ack, fail and timeout outcomes as spans 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 " ack", " fail" or " 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 " 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. --- .../src/jvm/org/apache/storm/Config.java | 7 +- .../org/apache/storm/executor/Executor.java | 21 ++++- .../org/apache/storm/executor/TupleInfo.java | 11 +++ .../storm/executor/bolt/BoltExecutor.java | 2 +- .../bolt/BoltOutputCollectorImpl.java | 6 ++ .../storm/executor/spout/SpoutExecutor.java | 16 ++++ .../spout/SpoutOutputCollectorImpl.java | 1 + .../org/apache/storm/TopologyTracingTest.java | 90 ++++++++++++++++++- 8 files changed, 145 insertions(+), 9 deletions(-) diff --git a/storm-client/src/jvm/org/apache/storm/Config.java b/storm-client/src/jvm/org/apache/storm/Config.java index 541899abd39..df06f0656f8 100644 --- a/storm-client/src/jvm/org/apache/storm/Config.java +++ b/storm-client/src/jvm/org/apache/storm/Config.java @@ -1652,9 +1652,10 @@ public class Config extends HashMap { /** * Enables OpenTelemetry tracing. Each spout emit, except checkpoint tuples, starts a trace, * each bolt execute() of a traced tuple runs in a child span, and bolt emits carry a context - * derived from their anchors. Spans are recorded by the OpenTelemetry SDK registered as the - * global instance, usually by the OpenTelemetry Java agent; without one, Storm records nothing. - * Default: {@code false}. + * derived from their anchors. The spout records the ack, fail or timeout of each traced tuple + * tree, and a bolt its fail() calls, as short spans. Spans are recorded by the OpenTelemetry + * SDK registered as the global instance, usually by the OpenTelemetry Java agent; without one, + * Storm records nothing. Default: {@code false}. */ @IsBoolean public static final String TOPOLOGY_TRACING_ENABLED = "topology.tracing.enabled"; diff --git a/storm-client/src/jvm/org/apache/storm/executor/Executor.java b/storm-client/src/jvm/org/apache/storm/executor/Executor.java index b9db71108e9..a453e9da709 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/Executor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/Executor.java @@ -23,6 +23,7 @@ import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.SpanBuilder; import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.StatusCode; import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Context; import java.io.IOException; @@ -823,7 +824,25 @@ public Context newRootContext(String spanName, Collection links) { links.forEach(builder::addLink); Span span = builder.startSpan(); span.end(); - return span.getSpanContext().isValid() ? Context.root().with(span) : null; + // keep only the ids: pending tuples hold this context until their tree completes + SpanContext ids = span.getSpanContext(); + return ids.isValid() ? Context.root().with(Span.wrap(ids)) : null; + } + + /** + * Records a span under {@code parent}, started and ended at once, with status ERROR when + * {@code error}. Nothing is recorded until an SDK is registered. + */ + public void recordOutcome(Context parent, String spanName, boolean error) { + Tracer current = tracer(); + if (current == null) { + return; + } + Span span = current.spanBuilder(spanName).setParent(parent).startSpan(); + if (error) { + span.setStatus(StatusCode.ERROR); + } + span.end(); } public AtomicBoolean getOpenOrPrepareWasCalled() { diff --git a/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java b/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java index ca53b33a9c3..784be021898 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java +++ b/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java @@ -12,6 +12,7 @@ package org.apache.storm.executor; +import io.opentelemetry.context.Context; import java.io.Serializable; import java.util.List; import org.apache.storm.shade.org.apache.commons.lang3.builder.ToStringBuilder; @@ -27,6 +28,7 @@ public class TupleInfo implements Serializable { private List values; private long timestamp; private long rootId; + private transient Context traceContext; public Object getMessageId() { return messageId; @@ -74,6 +76,14 @@ public void setRootId(long rootId) { this.rootId = rootId; } + public Context getTraceContext() { + return traceContext; + } + + public void setTraceContext(Context traceContext) { + this.traceContext = traceContext; + } + public int getTaskId() { return taskId; } @@ -88,5 +98,6 @@ public void clear() { values = null; timestamp = 0; rootId = 0; + traceContext = null; } } diff --git a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java index 80657d6c022..a4698b2e2aa 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java @@ -261,7 +261,7 @@ public void tupleActionFn(int taskId, TupleImpl tuple) throws Exception { private void executeInSpan(Tracer tracer, IBolt bolt, TupleImpl tuple, Context received) { Span span = tracer.spanBuilder(executeSpanName).setParent(received).startSpan(); // anchored emits take their parent from the tuple, also after execute() returns - tuple.setTraceContext(received.with(span)); + tuple.setTraceContext(received.with(Span.wrap(span.getSpanContext()))); try (Scope ignored = span.makeCurrent()) { bolt.execute(tuple); } finally { diff --git a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java index 428e60c69f3..faed0edefc7 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java @@ -52,6 +52,7 @@ public class BoltOutputCollectorImpl implements IOutputCollector { private final boolean isDebug; private boolean ackingEnabled; private final String emitSpanName; + private final String failSpanName; private volatile long lastUnanchoredLogMs; public BoltOutputCollectorImpl(BoltExecutor executor, Task taskData, Random random, @@ -65,6 +66,7 @@ public BoltOutputCollectorImpl(BoltExecutor executor, Task taskData, Random rand this.isDebug = isDebug; this.xsfer = executor.getExecutorTransfer(); this.emitSpanName = executor.getComponentId() + " emit"; + this.failSpanName = executor.getComponentId() + " fail"; } @Override @@ -207,6 +209,10 @@ public void ack(Tuple input) { @Override public void fail(Tuple input) { + Context traceContext = input instanceof TupleImpl impl ? impl.getTraceContext() : null; + if (traceContext != null) { + executor.recordOutcome(traceContext, failSpanName, true); + } if (!ackingEnabled) { return; } diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java index 2eab9b08816..abd9a1b52a6 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java @@ -12,6 +12,7 @@ package org.apache.storm.executor.spout; +import io.opentelemetry.context.Context; import java.util.ArrayList; import java.util.List; import java.util.Map; @@ -58,6 +59,9 @@ public class SpoutExecutor extends Executor { private final MutableLong emptyEmitStreak; private final boolean hasAckers; private final SpoutExecutorStats stats; + private final String ackSpanName; + private final String failSpanName; + private final String timeoutSpanName; SpoutOutputCollectorImpl spoutOutputCollector; private Integer maxSpoutPending; private List spouts; @@ -70,6 +74,9 @@ public class SpoutExecutor extends Executor { public SpoutExecutor(final WorkerState workerData, final List executorId, Map credentials) { super(workerData, executorId, credentials, ClientStatsUtil.SPOUT); + this.ackSpanName = componentId + " ack"; + this.failSpanName = componentId + " fail"; + this.timeoutSpanName = componentId + " timeout"; this.spoutWaitStrategy = ReflectionUtils.newInstance((String) topoConf.get(Config.TOPOLOGY_SPOUT_WAIT_STRATEGY)); this.spoutWaitStrategy.prepare(topoConf, WaitSituation.SPOUT_WAIT); this.backPressureWaitStrategy = ReflectionUtils.newInstance((String) topoConf.get(Config.TOPOLOGY_BACKPRESSURE_WAIT_STRATEGY)); @@ -359,7 +366,11 @@ public void ackSpoutMsg(SpoutExecutor executor, Task taskData, Long timeDelta, T if (executor.getIsDebug()) { LOG.info("SPOUT Acking message {} {}", tupleInfo.getRootId(), tupleInfo.getMessageId()); } + Context traceContext = tupleInfo.getTraceContext(); spout.ack(tupleInfo.getMessageId()); + if (traceContext != null) { + executor.recordOutcome(traceContext, ackSpanName, false); + } if (!taskData.getUserContext().getHooks().isEmpty()) { // avoid allocating SpoutAckInfo obj if not necessary new SpoutAckInfo(tupleInfo.getMessageId(), taskId, timeDelta).applyOn(taskData.getUserContext()); } @@ -379,7 +390,12 @@ public void failSpoutMsg(SpoutExecutor executor, Task taskData, Long timeDelta, if (executor.getIsDebug()) { LOG.info("SPOUT Failing {} : {} REASON: {}", tupleInfo.getRootId(), tupleInfo, reason); } + Context traceContext = tupleInfo.getTraceContext(); spout.fail(tupleInfo.getMessageId()); + if (traceContext != null) { + String spanName = "TIMEOUT".equals(reason) ? timeoutSpanName : failSpanName; + executor.recordOutcome(traceContext, spanName, true); + } new SpoutFailInfo(tupleInfo.getMessageId(), taskId, timeDelta).applyOn(taskData.getUserContext()); if (timeDelta != null) { executor.getStats().spoutFailedTuple(tupleInfo.getStream()); diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java index b9a005a650e..9fe5a833a29 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java @@ -163,6 +163,7 @@ private List sendSpoutMsg(String stream, List values, Object me info.setStream(stream); info.setMessageId(messageId); info.setRootId(rootId); + info.setTraceContext(traceContext); if (isDebug) { info.setValues(values); } diff --git a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java index e33c737d0cf..5d575e7a94f 100644 --- a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java +++ b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java @@ -15,6 +15,7 @@ import io.opentelemetry.api.GlobalOpenTelemetry; import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.StatusCode; import io.opentelemetry.context.Context; import io.opentelemetry.context.Scope; import io.opentelemetry.sdk.OpenTelemetrySdk; @@ -151,6 +152,59 @@ public void testTickTuplesGetNoSpanAndSeeNoLeftoverContext() throws Exception { assertFalse(SPAN_CURRENT_DURING_TICK.get(), "the execute span's scope was closed"); } + @Test + public void testAckRecordsAnOutcomeSpanUnderTheRoot() throws Exception { + // spout emit, sink execute, spout ack + List spans = runWithSink(SinkOutcome.ACK, conf(true), 3); + + SpanData emit = named(spans, "spout emit").get(0); + SpanData ack = named(spans, "spout ack").get(0); + assertEquals(emit.getSpanId(), ack.getParentSpanId()); + assertEquals(StatusCode.UNSET, ack.getStatus().getStatusCode()); + } + + @Test + public void testFailRecordsErrorSpansInTheBoltAndAtTheSpout() throws Exception { + // spout emit, sink execute, sink fail, spout fail + List spans = runWithSink(SinkOutcome.FAIL, conf(true), 4); + + SpanData emit = named(spans, "spout emit").get(0); + SpanData execute = named(spans, "sink execute").get(0); + assertEquals(1, named(spans, "sink fail").size()); + SpanData sinkFail = named(spans, "sink fail").get(0); + SpanData spoutFail = named(spans, "spout fail").get(0); + assertEquals(execute.getSpanId(), sinkFail.getParentSpanId()); + assertEquals(emit.getSpanId(), spoutFail.getParentSpanId()); + assertEquals(StatusCode.ERROR, sinkFail.getStatus().getStatusCode()); + assertEquals(StatusCode.ERROR, spoutFail.getStatus().getStatusCode()); + } + + @Test + public void testBoltFailIsRecordedWithoutAckers() throws Exception { + Config conf = conf(true); + conf.put(Config.TOPOLOGY_ACKER_EXECUTORS, 0); + // spout emit, sink execute, sink fail; without ackers the spout records no outcome + List spans = runWithSink(SinkOutcome.FAIL, conf, 3); + + SpanData sinkFail = named(spans, "sink fail").get(0); + assertEquals(StatusCode.ERROR, sinkFail.getStatus().getStatusCode()); + assertTrue(named(spans, "spout ack").isEmpty()); + } + + @Test + public void testTimeoutRecordsAnErrorSpanAtTheSpout() throws Exception { + Config conf = conf(true); + conf.put(Config.TOPOLOGY_MESSAGE_TIMEOUT_SECS, 2); + // spout emit, sink execute, spout timeout + List spans = runWithSink(SinkOutcome.HOLD, conf, 3); + + SpanData emit = named(spans, "spout emit").get(0); + SpanData timeout = named(spans, "spout timeout").get(0); + assertEquals(emit.getSpanId(), timeout.getParentSpanId()); + assertEquals(StatusCode.ERROR, timeout.getStatus().getStatusCode()); + assertTrue(named(spans, "spout fail").isEmpty()); + } + @Test public void testAnchoredEmitContinuesTheTrace() throws Exception { // per tuple: spout emit, middle execute, sink execute @@ -280,6 +334,14 @@ private List runThroughMiddle(EmitMode mode, int count, int expectedSp && SINK_TUPLES_RECEIVED.get() >= sinkTuples); } + /** One tuple from spout "spout" to a sink that acks, fails or holds it. */ + private List runWithSink(SinkOutcome outcome, Config conf, int expectedSpans) + throws Exception { + return runTopology(conf, 1, + builder -> builder.setBolt("sink", new SinkBolt(outcome)).shuffleGrouping("spout"), + () -> OTEL.getSpans().size() >= expectedSpans); + } + private static Config conf(boolean tracing) { Config conf = new Config(); conf.setNumWorkers(2); @@ -288,8 +350,8 @@ private static Config conf(boolean tracing) { } /** - * Feeds {@code count} tuples to spout "spout", waits for the acks and {@code done}, and - * returns the exported spans. + * Feeds {@code count} tuples to spout "spout", waits until each is acked or failed and + * {@code done} holds, and returns the exported spans. */ private List runTopology(Config conf, int count, Consumer bolts, BooleanSupplier done) throws Exception { @@ -320,7 +382,7 @@ private List runTopology(Config conf, int count, Consumer tracker.isAcked(id) || tracker.isFailed(id), ids); // spans end after the bolt acked, and unanchored tuples are not tracked by the acks Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) .until(done::getAsBoolean); @@ -423,9 +485,25 @@ public void declareOutputFields(OutputFieldsDeclarer declarer) { } } + private enum SinkOutcome { + ACK, + FAIL, + /** Neither acks nor fails, so the tree times out. */ + HOLD + } + private static class SinkBolt extends BaseRichBolt { + private final SinkOutcome outcome; private OutputCollector collector; + SinkBolt() { + this(SinkOutcome.ACK); + } + + SinkBolt(SinkOutcome outcome) { + this.outcome = outcome; + } + @Override public void prepare(Map conf, TopologyContext context, OutputCollector collector) { @@ -456,7 +534,11 @@ public void execute(Tuple input) { SINK_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); } SINK_TUPLES_RECEIVED.incrementAndGet(); - collector.ack(input); + if (outcome == SinkOutcome.ACK) { + collector.ack(input); + } else if (outcome == SinkOutcome.FAIL) { + collector.fail(input); + } } @Override From 34db9a0246197f93fd9f1d566a6716e9b797a63c Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Wed, 30 Sep 2026 16:46:34 +0200 Subject: [PATCH 07/12] feat: add Storm attributes to execute spans 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. --- .../storm/executor/bolt/BoltExecutor.java | 39 ++++++++++++++++++- .../org/apache/storm/TopologyTracingTest.java | 27 ++++++++++++- 2 files changed, 62 insertions(+), 4 deletions(-) diff --git a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java index a4698b2e2aa..f6f04ddd5d3 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java @@ -12,6 +12,9 @@ package org.apache.storm.executor.bolt; +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.api.common.AttributesBuilder; import io.opentelemetry.api.trace.Span; import io.opentelemetry.api.trace.Tracer; import io.opentelemetry.context.Context; @@ -58,6 +61,21 @@ public class BoltExecutor extends Executor { private static final Logger LOG = LoggerFactory.getLogger(BoltExecutor.class); + private static final AttributeKey TOPOLOGY_NAME_KEY = + AttributeKey.stringKey("storm.topology.name"); + private static final AttributeKey TOPOLOGY_ID_KEY = + AttributeKey.stringKey("storm.topology.id"); + private static final AttributeKey COMPONENT_ID_KEY = + AttributeKey.stringKey("storm.component.id"); + private static final AttributeKey TASK_ID_KEY = AttributeKey.longKey("storm.task.id"); + private static final AttributeKey SOURCE_COMPONENT_ID_KEY = + AttributeKey.stringKey("storm.source.component.id"); + private static final AttributeKey SOURCE_STREAM_ID_KEY = + AttributeKey.stringKey("storm.source.stream.id"); + private static final AttributeKey WORKER_HOST_KEY = + AttributeKey.stringKey("storm.worker.host"); + private static final AttributeKey WORKER_PORT_KEY = + AttributeKey.longKey("storm.worker.port"); private final BooleanSupplier executeSampler; private final boolean isSystemBoltExecutor; @@ -65,6 +83,7 @@ public class BoltExecutor extends Executor { private final IWaitStrategy backPressureWaitStrategy; // employed when outbound path is congested private final BoltExecutorStats stats; private final String executeSpanName; + private final Attributes executeSpanAttributes; private BoltOutputCollectorImpl outputCollector; public BoltExecutor(WorkerState workerData, List executorId, Map credentials) { @@ -72,6 +91,15 @@ public BoltExecutor(WorkerState workerData, List executorId, Map spans = runSpoutToSink(true, 1, 1, 0); // 1 tuple, 1 sink task, no ticks + + Attributes attributes = named(spans, "sink execute").get(0).getAttributes(); + assertEquals(topologyName, attributes.get(AttributeKey.stringKey("storm.topology.name"))); + String topologyId = attributes.get(AttributeKey.stringKey("storm.topology.id")); + assertTrue(topologyId.startsWith(topologyName), topologyId); + assertEquals("sink", attributes.get(AttributeKey.stringKey("storm.component.id"))); + assertEquals(sinkTaskId, attributes.get(AttributeKey.longKey("storm.task.id"))); + assertEquals("spout", attributes.get(AttributeKey.stringKey("storm.source.component.id"))); + assertEquals("default", attributes.get(AttributeKey.stringKey("storm.source.stream.id"))); + assertEquals(Utils.hostname(), attributes.get(AttributeKey.stringKey("storm.worker.host"))); + assertEquals(WORKER_PORT_BY_COMPONENT.get("sink").longValue(), + attributes.get(AttributeKey.longKey("storm.worker.port"))); + } + @Test public void testAckRecordsAnOutcomeSpanUnderTheRoot() throws Exception { // spout emit, sink execute, spout ack @@ -374,9 +396,9 @@ private List runTopology(Config conf, int count, Consumer conf, TopologyContext context, OutputCollector collector) { this.collector = collector; WORKER_PORT_BY_COMPONENT.put("sink", context.getThisWorkerPort()); + sinkTaskId = context.getThisTaskId(); } @Override From 2546829c40c19c2498ca09a5fb126ab1053aa998 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Thu, 1 Oct 2026 09:51:12 +0200 Subject: [PATCH 08/12] feat: add TupleUtils.traceContext and the tracing docs page 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. --- docs/Tracing.md | 100 ++++++++++++++++++ docs/index.md | 1 + .../org/apache/storm/executor/Executor.java | 2 +- .../org/apache/storm/utils/TupleUtils.java | 14 +++ .../org/apache/storm/TopologyTracingTest.java | 10 +- 5 files changed, 120 insertions(+), 7 deletions(-) create mode 100644 docs/Tracing.md diff --git a/docs/Tracing.md b/docs/Tracing.md new file mode 100644 index 00000000000..6cc997ff633 --- /dev/null +++ b/docs/Tracing.md @@ -0,0 +1,100 @@ +--- +title: Tracing +layout: documentation +documentation: true +--- +Storm can carry an [OpenTelemetry](https://opentelemetry.io/) trace context with every tuple. A trace then follows a +[tuple tree](Guaranteeing-message-processing.html) across bolts and workers: the spout emit and each bolt `execute()` +it caused. For reliable spouts, the trace also shows how the tree ended. Spans that the application creates during +`execute()`, and spans of instrumented clients called there, join the same trace. + +## Enabling tracing + +Tracing is off by default; set `topology.tracing.enabled` to `true` to turn it on. Storm calls only the OpenTelemetry +API; the OpenTelemetry SDK registered as the global instance records the spans. The +[OpenTelemetry Java agent](https://opentelemetry.io/docs/zero-code/java/agent/) attached to the workers is one way to +register it: + +```yaml +topology.tracing.enabled: true +topology.worker.childopts: >- + -javaagent:/opt/otel/opentelemetry-javaagent.jar + -Dotel.service.name=my-topology + -Dotel.exporter.otlp.endpoint=http://collector:4318 + -Dotel.traces.sampler=parentbased_traceidratio + -Dotel.traces.sampler.arg=0.01 +``` + +The SDK exports the spans to the backend it is configured for, such as an OpenTelemetry Collector or any service that +accepts OTLP. An SDK that the application registers as the global instance works as well; Storm starts recording once +it is registered. A worker without an SDK records nothing. + +## What is recorded + +| Span | Parent | Recorded when | +|------|--------|---------------| +| ` emit` | none, it starts a trace | a spout emits a tuple, except checkpoint tuples of stateful bolts | +| ` execute` | the context of the input tuple | `execute()` runs for a tuple that carries a context; the span is current on the executor thread during the call | +| ` emit` | none, linked to each anchor's span | a bolt emits a tuple whose anchors carry different spans | +| ` ack`, ` fail`, ` timeout` | the ` emit` span | the tuple tree is acked, fails or times out; only for emits with a message id when the topology has ackers; fail and timeout have status ERROR | +| ` fail` | the execute span of the tuple | a bolt calls `fail()`; status ERROR | + +A recording execute span has these attributes: `storm.topology.name`, `storm.topology.id`, `storm.component.id`, +`storm.task.id`, `storm.source.component.id`, `storm.source.stream.id`, `storm.worker.port` and, when the host name +resolves, `storm.worker.host`. + +## How the context moves + +An emitted tuple takes its context from its [anchors](Guaranteeing-message-processing.html), on whatever thread the +emit runs. When the traced anchors carry one span, the tuple carries that span as parent. When they carry different +spans, the tuple carries a new root span linked to each of them, so a tree with joins spans several linked traces. An +unanchored emit carries no context, and the work downstream of it is not traced. Tick and other system tuples carry no +context. + +Between workers, the context travels in the serialized tuple, after the values. Workers of one topology run the same +Storm version; a worker of an earlier version would read such a tuple and ignore the extra bytes. + +## Sampling + +The SDK's sampler decides whether the trace that a spout emit starts is sampled. Storm passes every context on, sampled +or not. With a parent-based sampler (the default), every span of a tuple tree therefore follows that decision. The root +sampler alone decides whether the new root of an emit with several anchors is sampled, because the built-in samplers +ignore links. + +## Continuing a trace on other threads + +`TupleUtils.traceContext(tuple)` returns the context to run work for a tuple under, or an empty context +(`Context.root()`) when the tuple carries none. Make it current where work for the tuple runs outside `execute()`: + +```java +import io.opentelemetry.context.Context; + +Context context = TupleUtils.traceContext(input); +pool.submit(context.wrap(() -> { + Object page = fetch(input); // an instrumented HTTP client called here joins the input's trace + collector.emit(input, new Values(page)); + collector.ack(input); +})); +``` + +Emits themselves do not need this: an anchored emit takes its parent from the anchor on any thread. + +## Costs and limits + +- The Java agent carries the current context into tasks submitted to `java.util.concurrent` executors, so while an + execute span is current it wraps each task the bolt submits. When no code on those threads needs the context (spans, + instrumented clients, correlated logs, baggage), or that code makes the context current itself, + `-Dotel.instrumentation.executors.enabled=false` turns this off for the whole JVM. +- An execute span covers the `execute()` call only. In a bolt that processes the tuple on another thread, the span can + end before that processing does. +- At high tuple rates with a high sampling ratio, the SDK's batch span processor drops spans once its queue is full and + logs how many it dropped. Lower the sampling ratio, or tune the processor with the `otel.bsp.*` settings. +- Execute span attributes are set after the span starts, so a sampler cannot use them in its decision. +- A span keeps up to 128 links by default, so an emit whose anchors carry more different spans keeps only part of them. +- On a worker without an SDK, a tuple with one traced anchor passes its context on, but an emit with several traced + anchors carries none. +- The trace shows how a tuple tree ended, not which bolt held a tuple that timed out. +- An exception thrown by `execute()` is not recorded on the span. +- Workers put Storm's libraries before the topology jar on the classpath, so a topology runs against the + `opentelemetry-api` version Storm ships, not one bundled in its jar. Build the topology against that version and + declare the dependency as `provided`. diff --git a/docs/index.md b/docs/index.md index 13259618955..8250e1da65e 100644 --- a/docs/index.md +++ b/docs/index.md @@ -71,6 +71,7 @@ We're also notifying it via annotating classes with marker interface `@Interface * [Hooks](Hooks.html) * [Metrics (Deprecated)](Metrics.html) * [Metrics V2](metrics_v2.html) +* [Tracing](Tracing.html) * [State Checkpointing](State-checkpointing.html) * [Windowing](Windowing.html) * [Joining Streams](Joins.html) diff --git a/storm-client/src/jvm/org/apache/storm/executor/Executor.java b/storm-client/src/jvm/org/apache/storm/executor/Executor.java index a453e9da709..dd4f876c1d8 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/Executor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/Executor.java @@ -798,7 +798,7 @@ public String getComponentId() { * Checking isSet() instead of calling get() leaves the global unset, so an SDK registered later * is still used. Safe to call from any thread. */ - public Tracer tracer() { + protected Tracer tracer() { Tracer current = tracer; if (current == null && GlobalOpenTelemetry.isSet()) { current = GlobalOpenTelemetry.get().getTracer("org.apache.storm"); diff --git a/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java b/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java index fd4397cf489..1f74ec87d5f 100644 --- a/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java +++ b/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java @@ -12,12 +12,14 @@ package org.apache.storm.utils; +import io.opentelemetry.context.Context; import java.util.Arrays; import java.util.List; import java.util.Map; import org.apache.storm.Config; import org.apache.storm.Constants; import org.apache.storm.tuple.Tuple; +import org.apache.storm.tuple.TupleImpl; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -34,6 +36,18 @@ public static boolean isTick(Tuple tuple) { && Constants.SYSTEM_TICK_STREAM_ID.equals(tuple.getSourceStreamId()); } + /** + * Returns the OpenTelemetry context to run work for this tuple under, so that spans created + * there join the tuple's trace, or {@link Context#root()} when the tuple carries none (see + * {@link Config#TOPOLOGY_TRACING_ENABLED}). Never null. The context holds span ids only: it + * parents new spans but gives no access to the execute span itself. Example: + * {@code pool.submit(TupleUtils.traceContext(input).wrap(task))}. + */ + public static Context traceContext(Tuple tuple) { + Context context = tuple instanceof TupleImpl impl ? impl.getTraceContext() : null; + return context != null ? context : Context.root(); + } + public static int chooseTaskIndex(List keys, int numTasks) { return Math.floorMod(listHashCode(keys), numTasks); } diff --git a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java index fec92401401..00f0b7ce40f 100644 --- a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java +++ b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java @@ -51,7 +51,6 @@ import org.apache.storm.topology.base.BaseRichBolt; import org.apache.storm.tuple.Fields; import org.apache.storm.tuple.Tuple; -import org.apache.storm.tuple.TupleImpl; import org.apache.storm.tuple.Values; import org.apache.storm.utils.TupleUtils; import org.apache.storm.utils.Utils; @@ -489,7 +488,7 @@ public void execute(Tuple input) { private void emitReversed(Tuple first, Tuple second) { try { - Context firstContext = ((TupleImpl) first).getTraceContext(); + Context firstContext = TupleUtils.traceContext(first); try (Scope ignored = firstContext.makeCurrent()) { collector.emit(second, new Values(second.getValue(0))); collector.emit(first, new Values(first.getValue(0))); @@ -543,11 +542,10 @@ public void execute(Tuple input) { TICK_TUPLES_RECEIVED.incrementAndGet(); return; } - if (((TupleImpl) input).getTraceContext() != null) { - SpanContext received = Span.fromContext(((TupleImpl) input).getTraceContext()) - .getSpanContext(); + SpanContext received = Span.fromContext(TupleUtils.traceContext(input)).getSpanContext(); + if (received.isValid()) { RECEIVED_TRACE_IDS.add(received.getTraceId()); - if (received.isValid() && !received.isSampled()) { + if (!received.isSampled()) { UNSAMPLED_CONTEXTS_RECEIVED.incrementAndGet(); } } From 269c38315d33cdd9731bb3e3fea2b71656ac1038 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Mon, 5 Oct 2026 15:41:11 +0200 Subject: [PATCH 09/12] refactor: introduce a pluggable tuple tracing SPI 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. --- conf/defaults.yaml | 1 - pom.xml | 8 - storm-client/pom.xml | 6 - .../src/jvm/org/apache/storm/Config.java | 12 +- .../storm/daemon/worker/WorkerState.java | 23 + .../org/apache/storm/executor/Executor.java | 66 +- .../storm/executor/ExecutorTransfer.java | 4 +- .../org/apache/storm/executor/TupleInfo.java | 20 +- .../storm/executor/bolt/BoltExecutor.java | 68 +-- .../bolt/BoltOutputCollectorImpl.java | 74 +-- .../storm/executor/spout/SpoutExecutor.java | 20 +- .../spout/SpoutOutputCollectorImpl.java | 20 +- .../DeserializingConnectionCallback.java | 10 +- .../serialization/KryoTupleDeserializer.java | 70 +-- .../serialization/KryoTupleSerializer.java | 54 +- .../org/apache/storm/tracing/TupleTracer.java | 104 ++++ .../jvm/org/apache/storm/tuple/TupleImpl.java | 12 +- .../org/apache/storm/utils/TupleUtils.java | 14 - .../KryoTupleSerializerDeserializerTest.java | 185 ++++-- .../state/DefaultStateSerializerTest.java | 26 + storm-server/pom.xml | 5 - .../org/apache/storm/TopologyTracingTest.java | 569 ------------------ .../org/apache/storm/TupleTracerTest.java | 372 ++++++++++++ 23 files changed, 803 insertions(+), 940 deletions(-) create mode 100644 storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java delete mode 100644 storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java create mode 100644 storm-server/src/test/java/org/apache/storm/TupleTracerTest.java diff --git a/conf/defaults.yaml b/conf/defaults.yaml index 59dce959026..6fd7a04b9d4 100644 --- a/conf/defaults.yaml +++ b/conf/defaults.yaml @@ -289,7 +289,6 @@ storm.group.mapping.service.cache.duration.secs: 120 ### topology.* configs are for specific executing storms topology.enable.message.timeouts: true topology.debug: false -topology.tracing.enabled: false topology.workers: 1 topology.acker.executors: null topology.ras.acker.executors.per.worker: 1 diff --git a/pom.xml b/pom.xml index d1aa1382d70..4bb39882c86 100644 --- a/pom.xml +++ b/pom.xml @@ -124,7 +124,6 @@ above, so this is bumped explicitly rather than tracking the newest release. --> 1.12.0 5.6.2 - 1.66.0 3.6 6.1.0 0.24.0 @@ -760,13 +759,6 @@ pom import - - io.opentelemetry - opentelemetry-bom - ${opentelemetry.version} - pom - import - io.dropwizard.metrics metrics-core diff --git a/storm-client/pom.xml b/storm-client/pom.xml index e1683e0a917..cfa56683086 100644 --- a/storm-client/pom.xml +++ b/storm-client/pom.xml @@ -96,12 +96,6 @@ kryo - - - io.opentelemetry - opentelemetry-api - - io.dropwizard.metrics diff --git a/storm-client/src/jvm/org/apache/storm/Config.java b/storm-client/src/jvm/org/apache/storm/Config.java index df06f0656f8..f40df23881d 100644 --- a/storm-client/src/jvm/org/apache/storm/Config.java +++ b/storm-client/src/jvm/org/apache/storm/Config.java @@ -1650,15 +1650,11 @@ public class Config extends HashMap { public static final String TOPOLOGY_TUPLE_COMPRESSION_MAX_DECOMPRESSED_BYTES = "topology.tuple.compression.max.decompressed.bytes"; /** - * Enables OpenTelemetry tracing. Each spout emit, except checkpoint tuples, starts a trace, - * each bolt execute() of a traced tuple runs in a child span, and bolt emits carry a context - * derived from their anchors. The spout records the ack, fail or timeout of each traced tuple - * tree, and a bolt its fail() calls, as short spans. Spans are recorded by the OpenTelemetry - * SDK registered as the global instance, usually by the OpenTelemetry Java agent; without one, - * Storm records nothing. Default: {@code false}. + * The class that traces tuples, an implementation of {@link org.apache.storm.tracing.TupleTracer} with a zero-arg constructor. + * Each worker creates one instance. When unset, tuples are not traced. */ - @IsBoolean - public static final String TOPOLOGY_TRACING_ENABLED = "topology.tracing.enabled"; + @IsString + public static final String TOPOLOGY_TRACING_TRACER = "topology.tracing.tracer"; /** * Configure the topology metrics reporters to be used on workers. diff --git a/storm-client/src/jvm/org/apache/storm/daemon/worker/WorkerState.java b/storm-client/src/jvm/org/apache/storm/daemon/worker/WorkerState.java index 59aceb8d65e..2658c66c570 100644 --- a/storm-client/src/jvm/org/apache/storm/daemon/worker/WorkerState.java +++ b/storm-client/src/jvm/org/apache/storm/daemon/worker/WorkerState.java @@ -72,11 +72,13 @@ import org.apache.storm.shade.com.google.common.collect.Sets; import org.apache.storm.task.WorkerTopologyContext; import org.apache.storm.task.WorkerUserContext; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.tuple.Fields; import org.apache.storm.utils.ConfigUtils; import org.apache.storm.utils.JCQueue; import org.apache.storm.utils.ObjectReader; +import org.apache.storm.utils.ReflectionUtils; import org.apache.storm.utils.SupervisorIfaceFactory; import org.apache.storm.utils.ThriftTopologyUtils; import org.apache.storm.utils.Utils; @@ -148,6 +150,7 @@ public class WorkerState { private final WorkerTransfer workerTransfer; private final BackPressureTracker bpTracker; private final List deserializedWorkerHooks; + private final TupleTracer tupleTracer; // global variables only used internally in class private final Set outboundTasks; private final AtomicLong nextLoadUpdate = new AtomicLong(0); @@ -236,9 +239,11 @@ public WorkerState(Map conf, this.bpTracker = new BackPressureTracker(workerId, taskToExecutorQueue, metricRegistry, taskToComponent); this.deserializedWorkerHooks = deserializeWorkerHooks(); + this.tupleTracer = mkTupleTracer(); LOG.info("Registering IConnectionCallbacks for {}:{}", assignmentId, port); IConnectionCallback cb = new DeserializingConnectionCallback(topologyConf, getWorkerTopologyContext(), + tupleTracer, this::transferLocalBatch); Supplier newConnectionResponse = () -> { BackPressureStatus bpStatus = bpTracker.getCurrStatus(); @@ -266,6 +271,13 @@ private static int getMaxTaskId(Map> componentToSortedTask return maxTaskId; } + /** + * Returns the tracer of this worker, or null when {@link Config#TOPOLOGY_TRACING_TRACER} is unset. + */ + public TupleTracer getTupleTracer() { + return tupleTracer; + } + public List getDeserializedWorkerHooks() { return deserializedWorkerHooks; } @@ -662,6 +674,17 @@ public final WorkerUserContext getWorkerUserContext() { } } + private TupleTracer mkTupleTracer() { + String className = (String) topologyConf.get(Config.TOPOLOGY_TRACING_TRACER); + if (className == null) { + return null; + } + TupleTracer tracer = ReflectionUtils.newInstance(className); + tracer.prepare(topologyConf, getWorkerTopologyContext()); + LOG.info("Tracing tuples with {}", className); + return tracer; + } + private List deserializeWorkerHooks() { List myHookList = new ArrayList<>(); if (topology.is_set_worker_hooks()) { diff --git a/storm-client/src/jvm/org/apache/storm/executor/Executor.java b/storm-client/src/jvm/org/apache/storm/executor/Executor.java index dd4f876c1d8..ffc9e35a26f 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/Executor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/Executor.java @@ -19,18 +19,10 @@ import com.codahale.metrics.Metered; import com.codahale.metrics.Snapshot; import com.codahale.metrics.Timer; -import io.opentelemetry.api.GlobalOpenTelemetry; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.SpanBuilder; -import io.opentelemetry.api.trace.SpanContext; -import io.opentelemetry.api.trace.StatusCode; -import io.opentelemetry.api.trace.Tracer; -import io.opentelemetry.context.Context; import java.io.IOException; import java.lang.reflect.Field; import java.net.UnknownHostException; import java.util.ArrayList; -import java.util.Collection; import java.util.Collections; import java.util.HashMap; import java.util.HashSet; @@ -86,6 +78,7 @@ import org.apache.storm.stats.ClientStatsUtil; import org.apache.storm.stats.CommonStats; import org.apache.storm.task.WorkerTopologyContext; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.tuple.Fields; import org.apache.storm.tuple.TupleImpl; @@ -116,8 +109,7 @@ public abstract class Executor implements Callable, JCQueue.Consumer { protected final CountDownLatch workerReady; protected final AtomicBoolean stormActive; protected final AtomicReference> stormComponentDebug; - private final boolean tracingEnabled; - private volatile Tracer tracer; + protected final TupleTracer tupleTracer; protected final Runnable suicideFn; protected final IStormClusterState stormClusterState; protected final Map taskToComponent; @@ -159,8 +151,7 @@ protected Executor(WorkerState workerData, List executorId, Map links) { - Tracer current = tracer(); - if (current == null) { - return null; - } - SpanBuilder builder = current.spanBuilder(spanName).setNoParent(); - links.forEach(builder::addLink); - Span span = builder.startSpan(); - span.end(); - // keep only the ids: pending tuples hold this context until their tree completes - SpanContext ids = span.getSpanContext(); - return ids.isValid() ? Context.root().with(Span.wrap(ids)) : null; - } - - /** - * Records a span under {@code parent}, started and ended at once, with status ERROR when - * {@code error}. Nothing is recorded until an SDK is registered. - */ - public void recordOutcome(Context parent, String spanName, boolean error) { - Tracer current = tracer(); - if (current == null) { - return; - } - Span span = current.spanBuilder(spanName).setParent(parent).startSpan(); - if (error) { - span.setStatus(StatusCode.ERROR); - } - span.end(); + public TupleTracer getTupleTracer() { + return tupleTracer; } public AtomicBoolean getOpenOrPrepareWasCalled() { diff --git a/storm-client/src/jvm/org/apache/storm/executor/ExecutorTransfer.java b/storm-client/src/jvm/org/apache/storm/executor/ExecutorTransfer.java index 7052dce4ac4..5391be9f707 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/ExecutorTransfer.java +++ b/storm-client/src/jvm/org/apache/storm/executor/ExecutorTransfer.java @@ -21,6 +21,7 @@ import org.apache.storm.daemon.worker.WorkerState; import org.apache.storm.serialization.KryoTupleSerializer; import org.apache.storm.task.WorkerTopologyContext; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.utils.JCQueue; import org.apache.storm.utils.ObjectReader; @@ -44,7 +45,8 @@ public class ExecutorTransfer { public ExecutorTransfer(WorkerState workerData, Map topoConf) { this.workerData = workerData; WorkerTopologyContext workerTopologyContext = workerData.getWorkerTopologyContext(); - this.threadLocalSerializer = ThreadLocal.withInitial(() -> new KryoTupleSerializer(topoConf, workerTopologyContext)); + TupleTracer tracer = workerData.getTupleTracer(); + this.threadLocalSerializer = ThreadLocal.withInitial(() -> new KryoTupleSerializer(topoConf, workerTopologyContext, tracer)); this.isDebug = ObjectReader.getBoolean(topoConf.get(Config.TOPOLOGY_DEBUG), false); } diff --git a/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java b/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java index 784be021898..f76c08c7926 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java +++ b/storm-client/src/jvm/org/apache/storm/executor/TupleInfo.java @@ -12,7 +12,6 @@ package org.apache.storm.executor; -import io.opentelemetry.context.Context; import java.io.Serializable; import java.util.List; import org.apache.storm.shade.org.apache.commons.lang3.builder.ToStringBuilder; @@ -28,7 +27,8 @@ public class TupleInfo implements Serializable { private List values; private long timestamp; private long rootId; - private transient Context traceContext; + private transient Object traceContext; + private long traceEmitTimeMs; public Object getMessageId() { return messageId; @@ -76,14 +76,25 @@ public void setRootId(long rootId) { this.rootId = rootId; } - public Context getTraceContext() { + public Object getTraceContext() { return traceContext; } - public void setTraceContext(Context traceContext) { + public void setTraceContext(Object traceContext) { this.traceContext = traceContext; } + /** + * Returns when the spout emitted the tuple tree, set for traced trees only. + */ + public long getTraceEmitTimeMs() { + return traceEmitTimeMs; + } + + public void setTraceEmitTimeMs(long traceEmitTimeMs) { + this.traceEmitTimeMs = traceEmitTimeMs; + } + public int getTaskId() { return taskId; } @@ -99,5 +110,6 @@ public void clear() { timestamp = 0; rootId = 0; traceContext = null; + traceEmitTimeMs = 0; } } diff --git a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java index f6f04ddd5d3..cf9f725550f 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltExecutor.java @@ -12,13 +12,6 @@ package org.apache.storm.executor.bolt; -import io.opentelemetry.api.common.AttributeKey; -import io.opentelemetry.api.common.Attributes; -import io.opentelemetry.api.common.AttributesBuilder; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.Tracer; -import io.opentelemetry.context.Context; -import io.opentelemetry.context.Scope; import java.util.ArrayList; import java.util.HashMap; import java.util.List; @@ -46,6 +39,7 @@ import org.apache.storm.task.IBolt; import org.apache.storm.task.OutputCollector; import org.apache.storm.task.TopologyContext; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.tuple.TupleImpl; import org.apache.storm.utils.ConfigUtils; @@ -61,45 +55,18 @@ public class BoltExecutor extends Executor { private static final Logger LOG = LoggerFactory.getLogger(BoltExecutor.class); - private static final AttributeKey TOPOLOGY_NAME_KEY = - AttributeKey.stringKey("storm.topology.name"); - private static final AttributeKey TOPOLOGY_ID_KEY = - AttributeKey.stringKey("storm.topology.id"); - private static final AttributeKey COMPONENT_ID_KEY = - AttributeKey.stringKey("storm.component.id"); - private static final AttributeKey TASK_ID_KEY = AttributeKey.longKey("storm.task.id"); - private static final AttributeKey SOURCE_COMPONENT_ID_KEY = - AttributeKey.stringKey("storm.source.component.id"); - private static final AttributeKey SOURCE_STREAM_ID_KEY = - AttributeKey.stringKey("storm.source.stream.id"); - private static final AttributeKey WORKER_HOST_KEY = - AttributeKey.stringKey("storm.worker.host"); - private static final AttributeKey WORKER_PORT_KEY = - AttributeKey.longKey("storm.worker.port"); private final BooleanSupplier executeSampler; private final boolean isSystemBoltExecutor; private final IWaitStrategy consumeWaitStrategy; // employed when no incoming data private final IWaitStrategy backPressureWaitStrategy; // employed when outbound path is congested private final BoltExecutorStats stats; - private final String executeSpanName; - private final Attributes executeSpanAttributes; private BoltOutputCollectorImpl outputCollector; public BoltExecutor(WorkerState workerData, List executorId, Map credentials) { super(workerData, executorId, credentials, ClientStatsUtil.BOLT); this.executeSampler = ConfigUtils.mkStatsSampler(topoConf); this.isSystemBoltExecutor = (executorId == Constants.SYSTEM_EXECUTOR_ID); - this.executeSpanName = componentId + " execute"; - AttributesBuilder attributes = Attributes.builder() - .put(TOPOLOGY_NAME_KEY, (String) topoConf.get(Config.TOPOLOGY_NAME)) - .put(TOPOLOGY_ID_KEY, stormId) - .put(COMPONENT_ID_KEY, componentId) - .put(WORKER_PORT_KEY, workerTopologyContext.getThisWorkerPort().longValue()); - if (!hostname.isEmpty()) { - attributes.put(WORKER_HOST_KEY, hostname); - } - this.executeSpanAttributes = attributes.build(); if (isSystemBoltExecutor) { this.consumeWaitStrategy = makeSystemBoltWaitStrategy(); } else { @@ -248,6 +215,7 @@ public void tupleActionFn(int taskId, TupleImpl tuple) throws Exception { this.updateChildEwmaStats(idToTask.get(taskId - idToTaskBase), tuple); } } else { + IBolt boltObject = (IBolt) idToTask.get(taskId - idToTaskBase).getTaskObject(); boolean isSampled = sampler.getAsBoolean(); boolean isExecuteSampler = executeSampler.getAsBoolean(); Long now = (isSampled || isExecuteSampler) ? Time.currentTimeMillis() : null; @@ -257,13 +225,17 @@ public void tupleActionFn(int taskId, TupleImpl tuple) throws Exception { if (isExecuteSampler) { tuple.setExecuteSampleStartTime(now); } - IBolt boltObject = (IBolt) idToTask.get(taskId - idToTaskBase).getTaskObject(); - Context received = tuple.getTraceContext(); - Tracer tracer = received == null ? null : tracer(); - if (tracer == null) { + Object received = tupleTracer == null ? null : tuple.getTraceContext(); + TupleTracer.ExecuteScope scope = + received == null ? null : tupleTracer.startExecute(taskId, tuple, received); + if (scope == null) { boltObject.execute(tuple); } else { - executeInSpan(tracer, boltObject, taskId, tuple, received); + try (scope) { + // anchored emits and fail() read the context from the tuple, also after execute() returns + tuple.setTraceContext(scope.context()); + boltObject.execute(tuple); + } } Long ms = tuple.getExecuteSampleStartTime(); @@ -285,22 +257,4 @@ public void tupleActionFn(int taskId, TupleImpl tuple) throws Exception { } } } - - private void executeInSpan(Tracer tracer, IBolt bolt, int taskId, TupleImpl tuple, - Context received) { - Span span = tracer.spanBuilder(executeSpanName).setParent(received).startSpan(); - if (span.isRecording()) { - span.setAllAttributes(executeSpanAttributes); - span.setAttribute(TASK_ID_KEY, taskId); - span.setAttribute(SOURCE_COMPONENT_ID_KEY, tuple.getSourceComponent()); - span.setAttribute(SOURCE_STREAM_ID_KEY, tuple.getSourceStreamId()); - } - // anchored emits take their parent from the tuple, also after execute() returns - tuple.setTraceContext(received.with(Span.wrap(span.getSpanContext()))); - try (Scope ignored = span.makeCurrent()) { - bolt.execute(tuple); - } finally { - span.end(); - } - } } diff --git a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java index faed0edefc7..86cb53edc98 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/bolt/BoltOutputCollectorImpl.java @@ -12,12 +12,10 @@ package org.apache.storm.executor.bolt; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.SpanContext; -import io.opentelemetry.context.Context; +import java.util.ArrayList; import java.util.Collection; +import java.util.Collections; import java.util.HashMap; -import java.util.LinkedHashSet; import java.util.List; import java.util.Map; import java.util.Random; @@ -28,6 +26,7 @@ import org.apache.storm.hooks.info.BoltAckInfo; import org.apache.storm.hooks.info.BoltFailInfo; import org.apache.storm.task.IOutputCollector; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.tuple.MessageId; import org.apache.storm.tuple.Tuple; @@ -41,7 +40,6 @@ public class BoltOutputCollectorImpl implements IOutputCollector { private static final Logger LOG = LoggerFactory.getLogger(BoltOutputCollectorImpl.class); - private static final long UNANCHORED_LOG_INTERVAL_MS = 60_000; private final BoltExecutor executor; private final Task task; @@ -51,9 +49,7 @@ public class BoltOutputCollectorImpl implements IOutputCollector { private final ExecutorTransfer xsfer; private final boolean isDebug; private boolean ackingEnabled; - private final String emitSpanName; - private final String failSpanName; - private volatile long lastUnanchoredLogMs; + private final TupleTracer tracer; public BoltOutputCollectorImpl(BoltExecutor executor, Task taskData, Random random, boolean isEventLoggers, boolean ackingEnabled, boolean isDebug) { @@ -65,8 +61,7 @@ public BoltOutputCollectorImpl(BoltExecutor executor, Task taskData, Random rand this.ackingEnabled = ackingEnabled; this.isDebug = isDebug; this.xsfer = executor.getExecutorTransfer(); - this.emitSpanName = executor.getComponentId() + " emit"; - this.failSpanName = executor.getComponentId() + " fail"; + this.tracer = executor.getTupleTracer(); } @Override @@ -97,14 +92,7 @@ private List boltEmit(String streamId, Collection anchors, List< } else { outTasks = task.getOutgoingTasks(streamId, values); } - Context traceContext = null; - if (executor.isTracingEnabled()) { - if (anchors == null || anchors.isEmpty()) { - logUnanchoredEmitUnderSpan(streamId); - } else { - traceContext = traceContextFor(anchors); - } - } + Object traceContext = tracer == null ? null : tracer.boltEmit(taskId, streamId, traceContexts(anchors)); for (int i = 0; i < outTasks.size(); ++i) { Integer t = outTasks.get(i); @@ -139,45 +127,23 @@ private List boltEmit(String streamId, Collection anchors, List< } /** - * Runs on the emitting thread. If the traced anchors share one span, returns their context. If - * they carry several, returns a new root linked to each (the SDK keeps up to 128 links by - * default), or null when no SDK is registered on this worker. + * Returns the trace contexts of the anchors, in anchor order, skipping anchors without one. */ - private Context traceContextFor(Collection anchors) { - Context first = null; - Set linkedSpans = null; + private static List traceContexts(Collection anchors) { + if (anchors == null) { + return Collections.emptyList(); + } + List contexts = null; for (Tuple anchor : anchors) { - Context context = anchor instanceof TupleImpl impl ? impl.getTraceContext() : null; - if (context == null) { - continue; - } - if (first == null) { - first = context; - } else { - if (linkedSpans == null) { - linkedSpans = new LinkedHashSet<>(); - linkedSpans.add(Span.fromContext(first).getSpanContext()); + Object context = anchor instanceof TupleImpl impl ? impl.getTraceContext() : null; + if (context != null) { + if (contexts == null) { + contexts = new ArrayList<>(anchors.size()); } - linkedSpans.add(Span.fromContext(context).getSpanContext()); + contexts.add(context); } } - if (linkedSpans == null || linkedSpans.size() == 1) { - return first; - } - return executor.newRootContext(emitSpanName, linkedSpans); - } - - private void logUnanchoredEmitUnderSpan(String streamId) { - if (!LOG.isDebugEnabled() || !Span.current().getSpanContext().isValid()) { - return; - } - long now = Time.currentTimeMillis(); - if (now - lastUnanchoredLogMs < UNANCHORED_LOG_INTERVAL_MS) { - return; - } - lastUnanchoredLogMs = now; - LOG.debug("{} emitted on stream {} without anchors while a span was current; " - + "the emitted tuple carries no trace context", executor.getComponentId(), streamId); + return contexts == null ? Collections.emptyList() : contexts; } @Override @@ -209,9 +175,9 @@ public void ack(Tuple input) { @Override public void fail(Tuple input) { - Context traceContext = input instanceof TupleImpl impl ? impl.getTraceContext() : null; + Object traceContext = tracer != null && input instanceof TupleImpl impl ? impl.getTraceContext() : null; if (traceContext != null) { - executor.recordOutcome(traceContext, failSpanName, true); + tracer.boltFail(taskId, traceContext); } if (!ackingEnabled) { return; diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java index abd9a1b52a6..83ff32516d3 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java @@ -12,7 +12,6 @@ package org.apache.storm.executor.spout; -import io.opentelemetry.context.Context; import java.util.ArrayList; import java.util.List; import java.util.Map; @@ -36,6 +35,7 @@ import org.apache.storm.spout.SpoutOutputCollector; import org.apache.storm.stats.ClientStatsUtil; import org.apache.storm.stats.SpoutExecutorStats; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.tuple.TupleImpl; import org.apache.storm.utils.ConfigUtils; @@ -59,9 +59,6 @@ public class SpoutExecutor extends Executor { private final MutableLong emptyEmitStreak; private final boolean hasAckers; private final SpoutExecutorStats stats; - private final String ackSpanName; - private final String failSpanName; - private final String timeoutSpanName; SpoutOutputCollectorImpl spoutOutputCollector; private Integer maxSpoutPending; private List spouts; @@ -74,9 +71,6 @@ public class SpoutExecutor extends Executor { public SpoutExecutor(final WorkerState workerData, final List executorId, Map credentials) { super(workerData, executorId, credentials, ClientStatsUtil.SPOUT); - this.ackSpanName = componentId + " ack"; - this.failSpanName = componentId + " fail"; - this.timeoutSpanName = componentId + " timeout"; this.spoutWaitStrategy = ReflectionUtils.newInstance((String) topoConf.get(Config.TOPOLOGY_SPOUT_WAIT_STRATEGY)); this.spoutWaitStrategy.prepare(topoConf, WaitSituation.SPOUT_WAIT); this.backPressureWaitStrategy = ReflectionUtils.newInstance((String) topoConf.get(Config.TOPOLOGY_BACKPRESSURE_WAIT_STRATEGY)); @@ -366,10 +360,11 @@ public void ackSpoutMsg(SpoutExecutor executor, Task taskData, Long timeDelta, T if (executor.getIsDebug()) { LOG.info("SPOUT Acking message {} {}", tupleInfo.getRootId(), tupleInfo.getMessageId()); } - Context traceContext = tupleInfo.getTraceContext(); + Object traceContext = tupleInfo.getTraceContext(); + long traceLatencyMs = traceContext != null ? Time.deltaMs(tupleInfo.getTraceEmitTimeMs()) : 0; spout.ack(tupleInfo.getMessageId()); if (traceContext != null) { - executor.recordOutcome(traceContext, ackSpanName, false); + executor.getTupleTracer().spoutOutcome(taskId, traceContext, TupleTracer.Outcome.ACK, traceLatencyMs); } if (!taskData.getUserContext().getHooks().isEmpty()) { // avoid allocating SpoutAckInfo obj if not necessary new SpoutAckInfo(tupleInfo.getMessageId(), taskId, timeDelta).applyOn(taskData.getUserContext()); @@ -390,11 +385,12 @@ public void failSpoutMsg(SpoutExecutor executor, Task taskData, Long timeDelta, if (executor.getIsDebug()) { LOG.info("SPOUT Failing {} : {} REASON: {}", tupleInfo.getRootId(), tupleInfo, reason); } - Context traceContext = tupleInfo.getTraceContext(); + Object traceContext = tupleInfo.getTraceContext(); + long traceLatencyMs = traceContext != null ? Time.deltaMs(tupleInfo.getTraceEmitTimeMs()) : 0; spout.fail(tupleInfo.getMessageId()); if (traceContext != null) { - String spanName = "TIMEOUT".equals(reason) ? timeoutSpanName : failSpanName; - executor.recordOutcome(traceContext, spanName, true); + TupleTracer.Outcome outcome = "TIMEOUT".equals(reason) ? TupleTracer.Outcome.TIMEOUT : TupleTracer.Outcome.FAIL; + executor.getTupleTracer().spoutOutcome(taskId, traceContext, outcome, traceLatencyMs); } new SpoutFailInfo(tupleInfo.getMessageId(), taskId, timeDelta).applyOn(taskData.getUserContext()); if (timeDelta != null) { diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java index 9fe5a833a29..63d17579a88 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutOutputCollectorImpl.java @@ -12,9 +12,7 @@ package org.apache.storm.executor.spout; -import io.opentelemetry.context.Context; import java.util.ArrayList; -import java.util.Collections; import java.util.List; import java.util.Random; import org.apache.storm.daemon.Acker; @@ -23,12 +21,14 @@ import org.apache.storm.spout.CheckpointSpout; import org.apache.storm.spout.ISpout; import org.apache.storm.spout.ISpoutOutputCollector; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.tuple.MessageId; import org.apache.storm.tuple.TupleImpl; import org.apache.storm.tuple.Values; import org.apache.storm.utils.MutableLong; import org.apache.storm.utils.RotatingMap; +import org.apache.storm.utils.Time; import org.apache.storm.utils.Utils; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -48,7 +48,7 @@ public class SpoutOutputCollectorImpl implements ISpoutOutputCollector { private final Boolean isDebug; private final RotatingMap pending; private final long spoutExecutorThdId; - private final String emitSpanName; + private final TupleTracer tracer; private TupleInfo globalTupleInfo = new TupleInfo(); // thread safety: assumes Collector.emit*() calls are externally synchronized (if needed). @@ -66,7 +66,7 @@ public SpoutOutputCollectorImpl(ISpout spout, SpoutExecutor executor, Task taskD this.isDebug = isDebug; this.pending = pending; this.spoutExecutorThdId = executor.getThreadId(); - this.emitSpanName = executor.getComponentId() + " emit"; + this.tracer = executor.getTupleTracer(); } @Override @@ -129,10 +129,9 @@ private List sendSpoutMsg(String stream, List values, Object me final long rootId = needAck ? MessageId.generateId(random) : 0; // checkpoint tuples of stateful bolts are system tuples: no trace - boolean traced = executor.isTracingEnabled() - && !CheckpointSpout.CHECKPOINT_STREAM_ID.equals(stream); - final Context traceContext = - traced ? executor.newRootContext(emitSpanName, Collections.emptyList()) : null; + final Object traceContext = tracer != null && !CheckpointSpout.CHECKPOINT_STREAM_ID.equals(stream) + ? tracer.spoutEmit(taskId, stream) : null; + final long traceEmitTimeMs = traceContext != null ? Time.currentTimeMillis() : 0; for (int i = 0; i < outTasks.size(); i++) { // perf critical path. don't use iterators. Integer t = outTasks.get(i); @@ -163,7 +162,10 @@ private List sendSpoutMsg(String stream, List values, Object me info.setStream(stream); info.setMessageId(messageId); info.setRootId(rootId); - info.setTraceContext(traceContext); + if (traceContext != null) { + info.setTraceContext(traceContext); + info.setTraceEmitTimeMs(traceEmitTimeMs); + } if (isDebug) { info.setValues(values); } diff --git a/storm-client/src/jvm/org/apache/storm/messaging/DeserializingConnectionCallback.java b/storm-client/src/jvm/org/apache/storm/messaging/DeserializingConnectionCallback.java index 6a8464f432c..eb022a93e01 100644 --- a/storm-client/src/jvm/org/apache/storm/messaging/DeserializingConnectionCallback.java +++ b/storm-client/src/jvm/org/apache/storm/messaging/DeserializingConnectionCallback.java @@ -29,6 +29,7 @@ import org.apache.storm.metric.api.IMetric; import org.apache.storm.serialization.KryoTupleDeserializer; import org.apache.storm.task.GeneralTopologyContext; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.AddressedTuple; import org.apache.storm.tuple.Tuple; import org.apache.storm.utils.ObjectReader; @@ -62,12 +63,13 @@ public class DeserializingConnectionCallback implements IConnectionCallback, IMe private final WorkerState.ILocalTransferCallback cb; private final Map conf; private final GeneralTopologyContext context; + private final TupleTracer tracer; private ThreadLocal des = new ThreadLocal() { @Override protected KryoTupleDeserializer initialValue() { - return new KryoTupleDeserializer(conf, context); + return new KryoTupleDeserializer(conf, context, tracer); } }; @@ -83,8 +85,14 @@ protected KryoTupleDeserializer initialValue() { public DeserializingConnectionCallback(final Map conf, final GeneralTopologyContext context, WorkerState.ILocalTransferCallback callback) { + this(conf, context, null, callback); + } + + public DeserializingConnectionCallback(final Map conf, final GeneralTopologyContext context, + final TupleTracer tracer, WorkerState.ILocalTransferCallback callback) { this.conf = conf; this.context = context; + this.tracer = tracer; cb = callback; sizeMetricsEnabled = ObjectReader.getBoolean(conf.get(Config.TOPOLOGY_SERIALIZED_MESSAGE_SIZE_METRICS), false); diff --git a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java index d90fbc094c2..4252067b743 100644 --- a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java +++ b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleDeserializer.java @@ -13,20 +13,13 @@ package org.apache.storm.serialization; import com.esotericsoftware.kryo.io.Input; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.SpanContext; -import io.opentelemetry.api.trace.SpanId; -import io.opentelemetry.api.trace.TraceFlags; -import io.opentelemetry.api.trace.TraceId; -import io.opentelemetry.api.trace.TraceState; -import io.opentelemetry.api.trace.TraceStateBuilder; -import io.opentelemetry.context.Context; import java.io.IOException; import java.util.List; import java.util.Map; import org.apache.storm.Config; import org.apache.storm.generated.ComponentCommon; import org.apache.storm.task.GeneralTopologyContext; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.MessageId; import org.apache.storm.tuple.TupleImpl; import org.apache.storm.utils.ObjectReader; @@ -38,16 +31,22 @@ public class KryoTupleDeserializer implements ITupleDeserializer { private static final Integer DEFAULT_MAX_DECOMPRESSED_BYTES = 10 * 1024 * 1024; // 10MBytes public static final Logger LOG = LoggerFactory.getLogger(KryoTupleDeserializer.class); public static final String FAILED_TO_DESERIALIZE_TUPLE = "Failed to deserialize tuple"; - private static final int TRACE_ID_BYTES = 16; - private static final int SPAN_ID_BYTES = 8; private final GeneralTopologyContext context; private final KryoValuesDeserializer kryo; private final SerializationFactory.IdDictionary ids; private final Input kryoInput; private final int maxZstdDecompressedBytes; private final boolean anyTupleCompressionEnabled; + private final TupleTracer tracer; public KryoTupleDeserializer(final Map conf, final GeneralTopologyContext context) { + this(conf, context, null); + } + + /** + * Creates a deserializer that reads the trace context of each tuple with {@code tracer}; a null tracer skips it. + */ + public KryoTupleDeserializer(final Map conf, final GeneralTopologyContext context, final TupleTracer tracer) { kryo = new KryoValuesDeserializer(conf); this.context = context; ids = new SerializationFactory.IdDictionary(context.getRawTopology()); @@ -55,6 +54,7 @@ public KryoTupleDeserializer(final Map conf, final GeneralTopolo maxZstdDecompressedBytes = ObjectReader.getInt(conf.get(Config.TOPOLOGY_TUPLE_COMPRESSION_MAX_DECOMPRESSED_BYTES), DEFAULT_MAX_DECOMPRESSED_BYTES); anyTupleCompressionEnabled = isTupleCompressionEnabled(conf, context); + this.tracer = tracer; } @Override @@ -95,7 +95,9 @@ private TupleImpl deserializeTuple(byte[] data) { MessageId id = MessageId.deserialize(kryoInput); List values = kryo.deserializeFrom(kryoInput); TupleImpl tuple = new TupleImpl(context, values, componentName, taskId, streamName, id); - tuple.setTraceContext(readTraceContext(kryoInput)); + if (tracer != null) { + tuple.setTraceContext(readTraceContext()); + } return tuple; } catch (IOException e) { throw new RuntimeException(FAILED_TO_DESERIALIZE_TUPLE, e); @@ -103,44 +105,26 @@ private TupleImpl deserializeTuple(byte[] data) { } /** - * Reads the trace context written after the values. Null when absent, of an unknown version - * or unreadable, so a bad extension never fails the tuple. Invalid tracestate entries are - * dropped. + * Reads the entries after the values, see {@link KryoTupleSerializer}. Returns null when no trace context entry is present or + * it cannot be read, so that a bad entry never drops the tuple. */ - private static Context readTraceContext(Input in) { - if (in.position() == in.limit()) { - return null; - } + private Object readTraceContext() { try { - int header = in.readByte() & 0xFF; - int version = header & ~KryoTupleSerializer.HAS_TRACE_STATE; - if (version != KryoTupleSerializer.TRACE_CONTEXT_VERSION) { - return null; - } - String traceId = TraceId.fromBytes(in.readBytes(TRACE_ID_BYTES)); - String spanId = SpanId.fromBytes(in.readBytes(SPAN_ID_BYTES)); - TraceFlags flags = TraceFlags.fromByte(in.readByte()); - TraceState traceState = TraceState.getDefault(); - if ((header & KryoTupleSerializer.HAS_TRACE_STATE) != 0) { - String[] entries = in.readString().split(","); - TraceStateBuilder builder = TraceState.builder(); - // put() inserts in front of existing entries: add in reverse to keep the order - for (int i = entries.length - 1; i >= 0; i--) { - String entry = entries[i]; - int separator = entry.indexOf('='); - if (separator > 0) { - builder.put(entry.substring(0, separator), entry.substring(separator + 1)); - } + while (kryoInput.position() < kryoInput.limit()) { + int tag = kryoInput.readByte(); + int length = kryoInput.readVarInt(true); + if (length < 0 || length > kryoInput.limit() - kryoInput.position()) { + return null; + } + if (tag == KryoTupleSerializer.TRACE_CONTEXT_TAG) { + return tracer.decode(kryoInput.readBytes(length)); } - traceState = builder.build(); + kryoInput.skip(length); } - SpanContext span = - SpanContext.createFromRemoteParent(traceId, spanId, flags, traceState); - return span.isValid() ? Context.root().with(Span.wrap(span)) : null; } catch (RuntimeException malformed) { - LOG.debug("Ignoring a malformed trace context on a received tuple", malformed); - return null; + LOG.debug("Ignoring an unreadable trace context on a received tuple", malformed); } + return null; } private static boolean isTupleCompressionEnabled(final Map conf, final GeneralTopologyContext context) { diff --git a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java index e71e2b340d1..9ad52e8cae2 100644 --- a/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java +++ b/storm-client/src/jvm/org/apache/storm/serialization/KryoTupleSerializer.java @@ -13,16 +13,12 @@ package org.apache.storm.serialization; import com.esotericsoftware.kryo.io.Output; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.SpanContext; -import io.opentelemetry.api.trace.TraceState; -import io.opentelemetry.context.Context; import java.io.IOException; import java.util.Arrays; import java.util.Map; -import java.util.StringJoiner; import org.apache.storm.Config; import org.apache.storm.task.GeneralTopologyContext; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.Tuple; import org.apache.storm.tuple.TupleImpl; import org.apache.storm.utils.ObjectReader; @@ -31,10 +27,8 @@ public class KryoTupleSerializer implements ITupleSerializer { private static final int DEFAULT_COMPRESSION_THRESHOLD = 1460; private static final Integer DEFAULT_ZSTD_COMPRESSION_LEVEL = 3; - /** Below 0x80, the bit HAS_TRACE_STATE takes; bump it when the layout changes. */ - static final int TRACE_CONTEXT_VERSION = 1; - /** Header bit: a W3C tracestate follows the trace flags. */ - static final int HAS_TRACE_STATE = 0x80; + /** Tag of the entry that carries the trace context, see {@link #writeTraceContext}. */ + static final int TRACE_CONTEXT_TAG = 1; private final KryoValuesSerializer kryo; private final SerializationFactory.IdDictionary ids; @@ -42,14 +36,23 @@ public class KryoTupleSerializer implements ITupleSerializer { private final boolean isCompressionEnabled; private final int compressionThreshold; private final int zstdCompressionLevel; + private final TupleTracer tracer; public KryoTupleSerializer(final Map conf, final GeneralTopologyContext context) { + this(conf, context, null); + } + + /** + * Creates a serializer that writes the trace context of each tuple, as encoded by {@code tracer}; a null tracer writes none. + */ + public KryoTupleSerializer(final Map conf, final GeneralTopologyContext context, final TupleTracer tracer) { kryo = new KryoValuesSerializer(conf); kryoOut = new Output(2000, 2000000000); ids = new SerializationFactory.IdDictionary(context.getRawTopology()); isCompressionEnabled = ObjectReader.getBoolean(conf.get(Config.TOPOLOGY_TUPLE_COMPRESSION_ENABLE), false); compressionThreshold = ObjectReader.getInt(conf.get(Config.TOPOLOGY_TUPLE_COMPRESSION_THRESHOLD), DEFAULT_COMPRESSION_THRESHOLD); zstdCompressionLevel = ObjectReader.getInt(conf.get(Config.STORM_COMPRESSION_ZSTD_LEVEL), DEFAULT_ZSTD_COMPRESSION_LEVEL); + this.tracer = tracer; } @Override @@ -61,8 +64,9 @@ public byte[] serialize(Tuple tuple) { kryoOut.writeInt(ids.getStreamId(tuple.getSourceComponent(), tuple.getSourceStreamId()), true); tuple.getMessageId().serialize(kryoOut); kryo.serializeInto(tuple.getValues(), kryoOut); - if (tuple instanceof TupleImpl impl) { - writeTraceContext(kryoOut, impl.getTraceContext()); + Object traceContext = tracer != null && tuple instanceof TupleImpl impl ? impl.getTraceContext() : null; + if (traceContext != null) { + writeTraceContext(traceContext); } byte[] rawBytes = kryoOut.getBuffer(); @@ -79,28 +83,16 @@ public byte[] serialize(Tuple tuple) { } /** - * Appends the trace context after the values: header byte (version, tracestate bit), 16-byte - * trace id, 8-byte span id, trace flags byte, then the tracestate if not empty. Readers that - * stop after the values ignore these bytes. + * Appends an entry after the values: a tag byte, the payload length as a varint, then the payload. Readers skip entries with + * an unknown tag, and readers that stop after the values ignore all of them. */ - private static void writeTraceContext(Output out, Context traceContext) { - if (traceContext == null) { + private void writeTraceContext(Object traceContext) { + byte[] payload = tracer.encode(traceContext); + if (payload == null) { return; } - SpanContext span = Span.fromContext(traceContext).getSpanContext(); - // isValid() ignores the sampled flag: unsampled contexts propagate too - if (!span.isValid()) { - return; - } - TraceState traceState = span.getTraceState(); - out.writeByte(TRACE_CONTEXT_VERSION | (traceState.isEmpty() ? 0 : HAS_TRACE_STATE)); - out.writeBytes(span.getTraceIdBytes()); - out.writeBytes(span.getSpanIdBytes()); - out.writeByte(span.getTraceFlags().asByte()); - if (!traceState.isEmpty()) { - StringJoiner entries = new StringJoiner(","); - traceState.forEach((key, value) -> entries.add(key + '=' + value)); - out.writeString(entries.toString()); - } + kryoOut.writeByte(TRACE_CONTEXT_TAG); + kryoOut.writeVarInt(payload.length, true); + kryoOut.writeBytes(payload); } } diff --git a/storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java b/storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java new file mode 100644 index 00000000000..3b361c72e48 --- /dev/null +++ b/storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java @@ -0,0 +1,104 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm.tracing; + +import java.util.List; +import java.util.Map; +import org.apache.storm.Config; +import org.apache.storm.task.WorkerTopologyContext; +import org.apache.storm.tuple.Tuple; + +/** + * Attaches a trace context to tuples and records how their tuple trees are processed. Each worker creates one instance from the + * class named in {@link Config#TOPOLOGY_TRACING_TRACER}, through its zero-arg constructor, and shares it between its executors + * and the threads that serialize and deserialize tuples, so implementations must be thread safe. + * + *

A context is any object the implementation chooses; null means not traced. Storm keeps it on the tuple and, for the tuple + * trees a spout starts, until the tree completes. Tuples sent to another worker carry the bytes {@link #encode} returns, and the + * receiving worker turns them back into a context with {@link #decode}. + * + *

An exception from {@link #decode} leaves the tuple without a context. Exceptions from the other methods propagate to the + * caller. + */ +public interface TupleTracer { + + /** + * Called once, before any other method. + */ + void prepare(Map topoConf, WorkerTopologyContext context); + + /** + * Returns the context of a tuple tree that spout task {@code taskId} starts on {@code streamId}, or null to leave it untraced. + * Not called for checkpoint tuples. + */ + Object spoutEmit(int taskId, String streamId); + + /** + * Returns the context of a tuple that bolt task {@code taskId} emits on {@code streamId}, or null. {@code anchorContexts} holds + * the contexts of the anchors that carry one, in anchor order; it is empty when none does or the emit is unanchored. Called on + * the emitting thread. + */ + Object boltEmit(int taskId, String streamId, List anchorContexts); + + /** + * Called on the executor thread before bolt task {@code taskId} runs {@code execute()} for {@code tuple}, which carries + * {@code context}. Storm puts {@link ExecuteScope#context()} on the tuple, then closes the scope on the same thread once + * {@code execute()} returns or throws. Returns null to run {@code execute()} without a scope; the tuple keeps {@code context}. + */ + ExecuteScope startExecute(int taskId, Tuple tuple, Object context); + + /** + * Called on the executor thread of spout task {@code taskId} after the tuple tree of {@code context} was acked, failed or timed + * out, and the spout's {@code ack()} or {@code fail()} returned. {@code latencyMs} is the time from the emit of the tree to + * its outcome, measured before the spout's {@code ack()} or {@code fail()} runs. Not called for trees that no acker tracks, + * such as all trees of a topology without ackers. + */ + void spoutOutcome(int taskId, Object context, Outcome outcome, long latencyMs); + + /** + * Called when bolt task {@code taskId} fails a tuple that carries {@code context}, on the thread that calls {@code fail()}. + */ + void boltFail(int taskId, Object context); + + /** + * Returns the bytes that carry {@code context} to another worker, or null to send the tuple without it. + */ + byte[] encode(Object context); + + /** + * Returns the context in bytes that {@link #encode} returned on a worker of the same topology, or null. + */ + Object decode(byte[] bytes); + + /** + * How a spout tuple tree ended. + */ + enum Outcome { + ACK, + FAIL, + TIMEOUT + } + + /** + * The tracing state of one {@code execute()} call. + */ + interface ExecuteScope extends AutoCloseable { + /** + * Returns the context the tuple carries while and after {@code execute()} runs. + */ + Object context(); + + @Override + void close(); + } +} diff --git a/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java b/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java index 4c8ab3aee5f..7966bf982c6 100644 --- a/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java +++ b/storm-client/src/jvm/org/apache/storm/tuple/TupleImpl.java @@ -12,7 +12,6 @@ package org.apache.storm.tuple; -import io.opentelemetry.context.Context; import java.util.Collections; import java.util.List; import org.apache.storm.generated.GlobalStreamId; @@ -28,7 +27,7 @@ public class TupleImpl implements Tuple { private Long processSampleStartTime; private Long executeSampleStartTime; private long outAckVal = 0; - private Context traceContext; + private Object traceContext; public TupleImpl(Tuple t) { this.values = t.getValues(); @@ -87,16 +86,17 @@ public void setExecuteSampleStartTime(long ms) { } /** - * Returns the OpenTelemetry context this tuple carries, or null. Internal to Storm. + * Returns the trace context this tuple carries, or null. The context is created by the configured + * {@link org.apache.storm.tracing.TupleTracer}. */ - public Context getTraceContext() { + public Object getTraceContext() { return traceContext; } /** - * Sets the OpenTelemetry context this tuple carries; null removes it. Internal to Storm. + * Sets the trace context this tuple carries; null removes it. */ - public void setTraceContext(Context traceContext) { + public void setTraceContext(Object traceContext) { this.traceContext = traceContext; } diff --git a/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java b/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java index 1f74ec87d5f..fd4397cf489 100644 --- a/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java +++ b/storm-client/src/jvm/org/apache/storm/utils/TupleUtils.java @@ -12,14 +12,12 @@ package org.apache.storm.utils; -import io.opentelemetry.context.Context; import java.util.Arrays; import java.util.List; import java.util.Map; import org.apache.storm.Config; import org.apache.storm.Constants; import org.apache.storm.tuple.Tuple; -import org.apache.storm.tuple.TupleImpl; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -36,18 +34,6 @@ public static boolean isTick(Tuple tuple) { && Constants.SYSTEM_TICK_STREAM_ID.equals(tuple.getSourceStreamId()); } - /** - * Returns the OpenTelemetry context to run work for this tuple under, so that spans created - * there join the tuple's trace, or {@link Context#root()} when the tuple carries none (see - * {@link Config#TOPOLOGY_TRACING_ENABLED}). Never null. The context holds span ids only: it - * parents new spans but gives no access to the execute span itself. Example: - * {@code pool.submit(TupleUtils.traceContext(input).wrap(task))}. - */ - public static Context traceContext(Tuple tuple) { - Context context = tuple instanceof TupleImpl impl ? impl.getTraceContext() : null; - return context != null ? context : Context.root(); - } - public static int chooseTaskIndex(List keys, int numTasks) { return Math.floorMod(listHashCode(keys), numTasks); } diff --git a/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java b/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java index 8e23cc7cc29..79c707a97a0 100644 --- a/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java +++ b/storm-client/test/jvm/org/apache/storm/serialization/KryoTupleSerializerDeserializerTest.java @@ -14,12 +14,8 @@ import com.esotericsoftware.kryo.io.Input; import com.esotericsoftware.kryo.io.Output; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.SpanContext; -import io.opentelemetry.api.trace.TraceFlags; -import io.opentelemetry.api.trace.TraceState; -import io.opentelemetry.context.Context; import java.io.IOException; +import java.nio.charset.StandardCharsets; import java.util.Arrays; import java.util.Collections; import java.util.HashMap; @@ -30,11 +26,14 @@ import org.apache.storm.generated.StormTopology; import org.apache.storm.shade.net.minidev.json.JSONValue; import org.apache.storm.task.GeneralTopologyContext; +import org.apache.storm.task.WorkerTopologyContext; import org.apache.storm.testing.TestWordCounter; import org.apache.storm.testing.TestWordSpout; import org.apache.storm.topology.TopologyBuilder; +import org.apache.storm.tracing.TupleTracer; import org.apache.storm.tuple.Fields; import org.apache.storm.tuple.MessageId; +import org.apache.storm.tuple.Tuple; import org.apache.storm.tuple.TupleImpl; import org.apache.storm.tuple.Values; import org.apache.storm.utils.Utils; @@ -373,86 +372,170 @@ public void testTraceContextRoundTripCompressed() { } @Test - public void testTupleWithoutTraceContextSerializesAsBefore() throws IOException { + public void testTupleWithoutEncodedContextSerializesAsBefore() throws IOException { Map conf = baseConf(); - KryoTupleSerializer serializer = new KryoTupleSerializer(conf, context); + KryoTupleSerializer serializer = new KryoTupleSerializer(conf, context, new StringTracer()); TupleImpl plain = tuple(new Values("hello", 42), MessageId.makeRootId(7L, 99L)); - TupleImpl rootOnly = tuple(new Values("hello", 42), MessageId.makeRootId(7L, 99L)); - rootOnly.setTraceContext(Context.root()); + TupleImpl notEncoded = tracedTuple(StringTracer.NOT_ENCODED); byte[] expected = serializeWithoutTraceContext(conf, plain); assertArrayEquals(expected, serializer.serialize(plain)); - assertArrayEquals(expected, serializer.serialize(rootOnly), "a context without a valid span adds no bytes"); - assertNull(new KryoTupleDeserializer(conf, context).deserialize(expected).getTraceContext()); + assertArrayEquals(expected, serializer.serialize(notEncoded), "encode() returned null"); } @Test - public void testPreviousReaderIgnoresTraceContext() throws IOException { + public void testSerializerWithoutTracerWritesNoContext() throws IOException { Map conf = baseConf(); - TupleImpl original = tracedTuple((byte) 0x03, TraceState.builder().put("vendor", "v1").build()); - byte[] bytes = new KryoTupleSerializer(conf, context).serialize(original); + TupleImpl traced = tracedTuple("trace-1"); - assertSameTuple(original, deserializeWithoutTraceContext(conf, bytes)); + assertArrayEquals(serializeWithoutTraceContext(conf, traced), new KryoTupleSerializer(conf, context).serialize(traced)); } @Test - public void testTruncatedTraceContextReadsAsAbsent() throws IOException { + public void testDeserializerWithoutTracerSkipsTheContext() { Map conf = baseConf(); - TupleImpl original = tracedTuple((byte) 0x03, TraceState.builder().put("vendor", "v1").build()); - byte[] full = new KryoTupleSerializer(conf, context).serialize(original); - int valuesEnd = serializeWithoutTraceContext(conf, original).length; - KryoTupleDeserializer deserializer = new KryoTupleDeserializer(conf, context); + TupleImpl traced = tracedTuple("trace-1"); + byte[] bytes = new KryoTupleSerializer(conf, context, new StringTracer()).serialize(traced); + + TupleImpl read = new KryoTupleDeserializer(conf, context).deserialize(bytes); + assertSameTuple(traced, read); + assertNull(read.getTraceContext()); + } + + @Test + public void testPreviousReaderIgnoresTheContext() throws IOException { + Map conf = baseConf(); + TupleImpl traced = tracedTuple("trace-1"); + byte[] bytes = new KryoTupleSerializer(conf, context, new StringTracer()).serialize(traced); + + assertSameTuple(traced, deserializeWithoutTraceContext(conf, bytes)); + } + + @Test + public void testUnknownTagIsSkipped() throws IOException { + Map conf = baseConf(); + TupleImpl traced = tracedTuple("trace-1"); + Output out = new Output(2000, -1); + out.writeBytes(serializeWithoutTraceContext(conf, traced)); + writeEntry(out, 9, "from a later version"); + writeEntry(out, KryoTupleSerializer.TRACE_CONTEXT_TAG, "trace-1"); + + TupleImpl read = new KryoTupleDeserializer(conf, context, new StringTracer()).deserialize(out.toBytes()); + assertSameTuple(traced, read); + assertEquals("trace-1", read.getTraceContext()); + } + + @Test + public void testTruncatedContextReadsAsAbsent() throws IOException { + Map conf = baseConf(); + TupleImpl traced = tracedTuple("trace-1"); + byte[] full = new KryoTupleSerializer(conf, context, new StringTracer()).serialize(traced); + int valuesEnd = serializeWithoutTraceContext(conf, traced).length; + KryoTupleDeserializer deserializer = new KryoTupleDeserializer(conf, context, new StringTracer()); for (int end = valuesEnd + 1; end < full.length; end++) { TupleImpl read = deserializer.deserialize(Arrays.copyOf(full, end)); - assertSameTuple(original, read); + assertSameTuple(traced, read); assertNull(read.getTraceContext(), "truncated at byte " + end); } } @Test - public void testUnknownTraceContextVersionIsIgnored() throws IOException { + public void testLengthBeyondTheTupleReadsAsAbsent() throws IOException { Map conf = baseConf(); - TupleImpl original = tracedTuple((byte) 0x03, TraceState.getDefault()); - byte[] bytes = new KryoTupleSerializer(conf, context).serialize(original); - bytes[serializeWithoutTraceContext(conf, original).length] = 2; + TupleImpl traced = tracedTuple("trace-1"); + Output out = new Output(2000, -1); + out.writeBytes(serializeWithoutTraceContext(conf, traced)); + out.writeByte(KryoTupleSerializer.TRACE_CONTEXT_TAG); + out.writeVarInt(Integer.MAX_VALUE, true); + out.writeBytes(new byte[]{1, 2, 3}); - TupleImpl read = new KryoTupleDeserializer(conf, context).deserialize(bytes); - assertSameTuple(original, read); + TupleImpl read = new KryoTupleDeserializer(conf, context, new StringTracer()).deserialize(out.toBytes()); + assertSameTuple(traced, read); + assertNull(read.getTraceContext()); + } + + @Test + public void testFailingDecodeReadsAsAbsent() { + Map conf = baseConf(); + TupleImpl traced = tracedTuple("trace-1"); + byte[] bytes = new KryoTupleSerializer(conf, context, new StringTracer()).serialize(traced); + StringTracer failing = new StringTracer() { + @Override + public Object decode(byte[] bytes) { + throw new IllegalArgumentException("unreadable"); + } + }; + + TupleImpl read = new KryoTupleDeserializer(conf, context, failing).deserialize(bytes); + assertSameTuple(traced, read); assertNull(read.getTraceContext()); } private void assertTraceContextRoundTrip(Map conf) { - KryoTupleSerializer serializer = new KryoTupleSerializer(conf, context); - KryoTupleDeserializer deserializer = new KryoTupleDeserializer(conf, context); - TraceState twoEntries = TraceState.builder().put("vendor", "v1").put("ot", "th:8;rv:0123456789abcd").build(); - // 0x03 = sampled plus the W3C random-trace-id bit; 0x00 = not sampled, which must propagate too - List originals = List.of( - tracedTuple((byte) 0x03, TraceState.getDefault()), - tracedTuple((byte) 0x03, twoEntries), - tracedTuple((byte) 0x00, TraceState.getDefault())); - - for (TupleImpl original : originals) { - TupleImpl read = deserializer.deserialize(serializer.serialize(original)); - assertSameTuple(original, read); - SpanContext sent = Span.fromContext(original.getTraceContext()).getSpanContext(); - SpanContext received = Span.fromContext(read.getTraceContext()).getSpanContext(); - assertEquals(sent.getTraceId(), received.getTraceId()); - assertEquals(sent.getSpanId(), received.getSpanId()); - assertEquals(sent.getTraceFlags(), received.getTraceFlags()); - assertEquals(sent.getTraceState(), received.getTraceState()); - assertTrue(received.isRemote()); - } + TupleImpl traced = tracedTuple("trace-1"); + byte[] bytes = new KryoTupleSerializer(conf, context, new StringTracer()).serialize(traced); + + TupleImpl read = new KryoTupleDeserializer(conf, context, new StringTracer()).deserialize(bytes); + assertSameTuple(traced, read); + assertEquals("trace-1", read.getTraceContext()); } - private TupleImpl tracedTuple(byte traceFlags, TraceState traceState) { + private TupleImpl tracedTuple(String traceContext) { TupleImpl tuple = tuple(new Values("hello", 42), MessageId.makeRootId(7L, 99L)); - SpanContext span = SpanContext.create("0af7651916cd43dd8448eb211c80319c", "b7ad6b7169203331", - TraceFlags.fromByte(traceFlags), traceState); - tuple.setTraceContext(Context.root().with(Span.wrap(span))); + tuple.setTraceContext(traceContext); return tuple; } + private static void writeEntry(Output out, int tag, String payload) { + byte[] bytes = payload.getBytes(StandardCharsets.UTF_8); + out.writeByte(tag); + out.writeVarInt(bytes.length, true); + out.writeBytes(bytes); + } + + /** Carries String contexts as their UTF-8 bytes; only encode and decode are used. */ + private static class StringTracer implements TupleTracer { + static final String NOT_ENCODED = "not encoded"; + + @Override + public void prepare(Map topoConf, WorkerTopologyContext context) { + } + + @Override + public Object spoutEmit(int taskId, String streamId) { + return null; + } + + @Override + public Object boltEmit(int taskId, String streamId, List anchorContexts) { + return null; + } + + @Override + public ExecuteScope startExecute(int taskId, Tuple tuple, Object context) { + return null; + } + + @Override + public void spoutOutcome(int taskId, Object context, Outcome outcome, long latencyMs) { + } + + @Override + public void boltFail(int taskId, Object context) { + } + + @Override + public byte[] encode(Object context) { + return NOT_ENCODED.equals(context) ? null : ((String) context).getBytes(StandardCharsets.UTF_8); + } + + @Override + public Object decode(byte[] bytes) { + return new String(bytes, StandardCharsets.UTF_8); + } + } + /** The tuple format without the trace context extension: task, stream, message id, values. */ private byte[] serializeWithoutTraceContext(Map conf, TupleImpl tuple) throws IOException { SerializationFactory.IdDictionary ids = new SerializationFactory.IdDictionary(context.getRawTopology()); diff --git a/storm-client/test/jvm/org/apache/storm/state/DefaultStateSerializerTest.java b/storm-client/test/jvm/org/apache/storm/state/DefaultStateSerializerTest.java index 15718b2d4d6..2b3139d160f 100644 --- a/storm-client/test/jvm/org/apache/storm/state/DefaultStateSerializerTest.java +++ b/storm-client/test/jvm/org/apache/storm/state/DefaultStateSerializerTest.java @@ -28,6 +28,13 @@ import java.util.Map; import org.apache.storm.Config; import org.apache.storm.spout.CheckPointState; +import org.apache.storm.task.TopologyContext; +import org.apache.storm.testing.TestWordSpout; +import org.apache.storm.topology.TopologyBuilder; +import org.apache.storm.tuple.MessageId; +import org.apache.storm.tuple.TupleImpl; +import org.apache.storm.tuple.Values; +import org.apache.storm.utils.Utils; import org.junit.jupiter.api.Test; import org.objenesis.strategy.StdInstantiatorStrategy; @@ -35,6 +42,8 @@ import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertNull; import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; /** * Unit tests for {@link DefaultStateSerializer} @@ -80,6 +89,23 @@ public void testDefaultStateEncoderRoundTrip() { assertNull(encoder.decodeValue(encoder.getTombstoneValue())); } + @Test + public void testTupleRestoredFromStateCarriesNoTraceContext() { + TopologyBuilder builder = new TopologyBuilder(); + builder.setSpout("spout", new TestWordSpout(), 1); + TopologyContext context = mock(TopologyContext.class); + when(context.getRawTopology()).thenReturn(builder.createTopology()); + when(context.getComponentId(1)).thenReturn("spout"); + Serializer serializer = new DefaultStateSerializer<>(Utils.readStormConfig(), context); + TupleImpl tuple = new TupleImpl(context, new Values("hello"), "spout", 1, Utils.DEFAULT_STREAM_ID, + MessageId.makeUnanchored()); + tuple.setTraceContext("trace-1"); + + TupleImpl restored = serializer.deserialize(serializer.serialize(tuple)); + assertEquals(tuple.getValues(), restored.getValues()); + assertNull(restored.getTraceContext()); + } + @Test public void testDeserializeRejectsUnregisteredClasses() { // a Kryo stream naming a class the topology never registered, as an earlier release diff --git a/storm-server/pom.xml b/storm-server/pom.xml index c3995ba519a..ae859c3f5f5 100644 --- a/storm-server/pom.xml +++ b/storm-server/pom.xml @@ -112,11 +112,6 @@ awaitility test - - io.opentelemetry - opentelemetry-sdk-testing - test - commons-io commons-io diff --git a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java b/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java deleted file mode 100644 index 00f0b7ce40f..00000000000 --- a/storm-server/src/test/java/org/apache/storm/TopologyTracingTest.java +++ /dev/null @@ -1,569 +0,0 @@ -/** - * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with - * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version - * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions - * and limitations under the License. - */ - -package org.apache.storm; - -import io.opentelemetry.api.GlobalOpenTelemetry; -import io.opentelemetry.api.common.AttributeKey; -import io.opentelemetry.api.common.Attributes; -import io.opentelemetry.api.trace.Span; -import io.opentelemetry.api.trace.SpanContext; -import io.opentelemetry.api.trace.StatusCode; -import io.opentelemetry.context.Context; -import io.opentelemetry.context.Scope; -import io.opentelemetry.sdk.OpenTelemetrySdk; -import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; -import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension; -import io.opentelemetry.sdk.trace.SdkTracerProvider; -import io.opentelemetry.sdk.trace.data.SpanData; -import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; -import io.opentelemetry.sdk.trace.samplers.Sampler; -import java.util.Arrays; -import java.util.List; -import java.util.Map; -import java.util.Set; -import java.util.concurrent.ConcurrentHashMap; -import java.util.concurrent.TimeUnit; -import java.util.concurrent.atomic.AtomicBoolean; -import java.util.concurrent.atomic.AtomicInteger; -import java.util.concurrent.atomic.AtomicReference; -import java.util.function.BooleanSupplier; -import java.util.function.Consumer; -import java.util.function.Function; -import java.util.stream.Collectors; -import org.apache.storm.ILocalCluster.ILocalTopology; -import org.apache.storm.generated.StormTopology; -import org.apache.storm.task.OutputCollector; -import org.apache.storm.task.TopologyContext; -import org.apache.storm.testing.AckFailMapTracker; -import org.apache.storm.testing.FeederSpout; -import org.apache.storm.topology.OutputFieldsDeclarer; -import org.apache.storm.topology.TopologyBuilder; -import org.apache.storm.topology.base.BaseRichBolt; -import org.apache.storm.tuple.Fields; -import org.apache.storm.tuple.Tuple; -import org.apache.storm.tuple.Values; -import org.apache.storm.utils.TupleUtils; -import org.apache.storm.utils.Utils; -import org.awaitility.Awaitility; -import org.junit.jupiter.api.AfterAll; -import org.junit.jupiter.api.BeforeAll; -import org.junit.jupiter.api.Test; -import org.junit.jupiter.api.extension.RegisterExtension; - -import static org.junit.jupiter.api.Assertions.assertEquals; -import static org.junit.jupiter.api.Assertions.assertFalse; -import static org.junit.jupiter.api.Assertions.assertNotEquals; -import static org.junit.jupiter.api.Assertions.assertNotNull; -import static org.junit.jupiter.api.Assertions.assertNull; -import static org.junit.jupiter.api.Assertions.assertTrue; - -/** - * Runs topologies on a two-worker local cluster with tracing on or off and checks the spans - * Storm exports. - */ -public class TopologyTracingTest { - - @RegisterExtension - static final OpenTelemetryExtension OTEL = OpenTelemetryExtension.create(); - - private static final Set RECEIVED_TRACE_IDS = ConcurrentHashMap.newKeySet(); - /** Span ids that were current on the sink's thread while its execute() ran. */ - private static final Set CURRENT_IN_EXECUTE = ConcurrentHashMap.newKeySet(); - private static final AtomicInteger SINK_TUPLES_RECEIVED = new AtomicInteger(); - private static final AtomicInteger UNSAMPLED_CONTEXTS_RECEIVED = new AtomicInteger(); - private static final Set MIDDLE_TRACE_IDS = ConcurrentHashMap.newKeySet(); - /** Tuple value to the id of the span current while middle, then sink, handled it. */ - private static final Map MIDDLE_SPAN_BY_VALUE = new ConcurrentHashMap<>(); - private static final Map SINK_SPAN_BY_VALUE = new ConcurrentHashMap<>(); - private static final Map WORKER_PORT_BY_COMPONENT = new ConcurrentHashMap<>(); - private static final AtomicReference EMITTER_THREAD_FAILURE = - new AtomicReference<>(); - private static final AtomicInteger TICK_TUPLES_RECEIVED = new AtomicInteger(); - private static final AtomicBoolean SPAN_CURRENT_DURING_TICK = new AtomicBoolean(); - - private static ILocalCluster cluster; - private static int topologyCount; - private static String topologyName; - private static volatile int sinkTaskId; - - @BeforeAll - public static void startCluster() throws Exception { - cluster = new LocalCluster(); - } - - @AfterAll - public static void stopCluster() throws Exception { - cluster.close(); - } - - @Test - public void testEachSpoutEmitStartsARootSpan() throws Exception { - List spans = runSpoutToSink(true, 3, 1, 0); // 3 tuples, 1 sink task, no ticks - - List emits = named(spans, "spout emit"); - assertEquals(3, emits.size()); - for (SpanData emit : emits) { - assertFalse(emit.getParentSpanContext().isValid(), "a spout emit starts a new trace"); - } - Set emitTraceIds = - emits.stream().map(SpanData::getTraceId).collect(Collectors.toSet()); - assertEquals(3, emitTraceIds.size()); - assertEquals(emitTraceIds, RECEIVED_TRACE_IDS, "each tuple carries its emit context"); - } - - @Test - public void testNoSpansWhenTracingIsOff() throws Exception { - assertTrue(runSpoutToSink(false, 1, 1, 0).isEmpty()); // 1 tuple, 1 sink task, no ticks - assertTrue(RECEIVED_TRACE_IDS.isEmpty(), "tuples carry no context"); - } - - @Test - public void testExecuteSpanIsChildOfTheEmitAndCurrentDuringExecute() throws Exception { - // two sink tasks with all grouping: on two workers, a copy of each tuple crosses workers - List spans = runSpoutToSink(true, 2, 2, 0); // 2 tuples, 2 sink tasks, no ticks - - Map emits = byId(named(spans, "spout emit")); - List executes = named(spans, "sink execute"); - assertEquals(2, emits.size()); - assertEquals(4, executes.size()); - for (SpanData execute : executes) { - SpanData emit = emits.get(execute.getParentSpanId()); - assertNotNull(emit, "an execute span is a child of the emit that produced its tuple"); - assertEquals(emit.getTraceId(), execute.getTraceId()); - } - assertTrue(executes.stream().anyMatch(s -> s.getParentSpanContext().isRemote()), - "at least one tuple crossed workers, so its context went through the serializer"); - Set executeIds = - executes.stream().map(SpanData::getSpanId).collect(Collectors.toSet()); - assertEquals(executeIds, CURRENT_IN_EXECUTE, "the execute span is current in the bolt"); - } - - @Test - public void testTickTuplesGetNoSpanAndSeeNoLeftoverContext() throws Exception { - List spans = runSpoutToSink(true, 1, 1, 1); // 1 tuple, 1 sink task, 1 s ticks - - assertEquals(1, named(spans, "sink execute").size()); - assertFalse(SPAN_CURRENT_DURING_TICK.get(), "the execute span's scope was closed"); - } - - @Test - public void testExecuteSpanCarriesStormAttributes() throws Exception { - List spans = runSpoutToSink(true, 1, 1, 0); // 1 tuple, 1 sink task, no ticks - - Attributes attributes = named(spans, "sink execute").get(0).getAttributes(); - assertEquals(topologyName, attributes.get(AttributeKey.stringKey("storm.topology.name"))); - String topologyId = attributes.get(AttributeKey.stringKey("storm.topology.id")); - assertTrue(topologyId.startsWith(topologyName), topologyId); - assertEquals("sink", attributes.get(AttributeKey.stringKey("storm.component.id"))); - assertEquals(sinkTaskId, attributes.get(AttributeKey.longKey("storm.task.id"))); - assertEquals("spout", attributes.get(AttributeKey.stringKey("storm.source.component.id"))); - assertEquals("default", attributes.get(AttributeKey.stringKey("storm.source.stream.id"))); - assertEquals(Utils.hostname(), attributes.get(AttributeKey.stringKey("storm.worker.host"))); - assertEquals(WORKER_PORT_BY_COMPONENT.get("sink").longValue(), - attributes.get(AttributeKey.longKey("storm.worker.port"))); - } - - @Test - public void testAckRecordsAnOutcomeSpanUnderTheRoot() throws Exception { - // spout emit, sink execute, spout ack - List spans = runWithSink(SinkOutcome.ACK, conf(true), 3); - - SpanData emit = named(spans, "spout emit").get(0); - SpanData ack = named(spans, "spout ack").get(0); - assertEquals(emit.getSpanId(), ack.getParentSpanId()); - assertEquals(StatusCode.UNSET, ack.getStatus().getStatusCode()); - } - - @Test - public void testFailRecordsErrorSpansInTheBoltAndAtTheSpout() throws Exception { - // spout emit, sink execute, sink fail, spout fail - List spans = runWithSink(SinkOutcome.FAIL, conf(true), 4); - - SpanData emit = named(spans, "spout emit").get(0); - SpanData execute = named(spans, "sink execute").get(0); - assertEquals(1, named(spans, "sink fail").size()); - SpanData sinkFail = named(spans, "sink fail").get(0); - SpanData spoutFail = named(spans, "spout fail").get(0); - assertEquals(execute.getSpanId(), sinkFail.getParentSpanId()); - assertEquals(emit.getSpanId(), spoutFail.getParentSpanId()); - assertEquals(StatusCode.ERROR, sinkFail.getStatus().getStatusCode()); - assertEquals(StatusCode.ERROR, spoutFail.getStatus().getStatusCode()); - } - - @Test - public void testBoltFailIsRecordedWithoutAckers() throws Exception { - Config conf = conf(true); - conf.put(Config.TOPOLOGY_ACKER_EXECUTORS, 0); - // spout emit, sink execute, sink fail; without ackers the spout records no outcome - List spans = runWithSink(SinkOutcome.FAIL, conf, 3); - - SpanData sinkFail = named(spans, "sink fail").get(0); - assertEquals(StatusCode.ERROR, sinkFail.getStatus().getStatusCode()); - assertTrue(named(spans, "spout ack").isEmpty()); - } - - @Test - public void testTimeoutRecordsAnErrorSpanAtTheSpout() throws Exception { - Config conf = conf(true); - conf.put(Config.TOPOLOGY_MESSAGE_TIMEOUT_SECS, 2); - // spout emit, sink execute, spout timeout - List spans = runWithSink(SinkOutcome.HOLD, conf, 3); - - SpanData emit = named(spans, "spout emit").get(0); - SpanData timeout = named(spans, "spout timeout").get(0); - assertEquals(emit.getSpanId(), timeout.getParentSpanId()); - assertEquals(StatusCode.ERROR, timeout.getStatus().getStatusCode()); - assertTrue(named(spans, "spout fail").isEmpty()); - } - - @Test - public void testAnchoredEmitContinuesTheTrace() throws Exception { - // per tuple: spout emit, middle execute, sink execute - List spans = runThroughMiddle(EmitMode.ANCHORED, 2, 6, 2); - - assertSinkExecutesAreChildrenOfMiddleExecutes(spans, 2); - } - - @Test - public void testAnchorsCarryingTheSameSpanAddNoMergeSpan() throws Exception { - // per tuple: spout emit, middle execute, sink execute; the emit anchors the input twice - List spans = runThroughMiddle(EmitMode.ANCHORED_TWICE, 2, 6, 2); - - assertTrue(named(spans, "middle emit").isEmpty()); - assertSinkExecutesAreChildrenOfMiddleExecutes(spans, 2); - } - - @Test - public void testEmitAnchoredToTwoTracedTuplesStartsARootWithTwoLinks() throws Exception { - // 2 spout emits, 2 middle executes, 1 merge span, 1 sink execute - List spans = runThroughMiddle(EmitMode.JOIN, 2, 6, 1); - - List merges = named(spans, "middle emit"); - assertEquals(1, merges.size()); - SpanData merge = merges.get(0); - assertFalse(merge.getParentSpanContext().isValid(), "a merge starts a new trace"); - Set linked = merge.getLinks().stream() - .map(link -> link.getSpanContext().getSpanId()).collect(Collectors.toSet()); - assertEquals(byId(named(spans, "middle execute")).keySet(), linked); - List sinks = named(spans, "sink execute"); - assertEquals(1, sinks.size()); - assertEquals(merge.getSpanId(), sinks.get(0).getParentSpanId()); - } - - @Test - public void testUnanchoredEmitCarriesNoContext() throws Exception { - // per tuple: spout emit, middle execute; the sink gets untraced tuples - List spans = runThroughMiddle(EmitMode.UNANCHORED, 2, 4, 2); - - assertEquals(2, named(spans, "middle execute").size()); - assertTrue(named(spans, "sink execute").isEmpty()); - assertTrue(RECEIVED_TRACE_IDS.isEmpty(), "the sink's tuples carry no context"); - } - - @Test - public void testDelayedEmitsFromAnotherThreadKeepTheirOwnParents() throws Exception { - // per tuple: spout emit, middle execute, sink execute - List spans = runThroughMiddle(EmitMode.ASYNC_REVERSED, 2, 6, 2); - - assertNull(EMITTER_THREAD_FAILURE.get()); - Map byId = byId(spans); - for (Object value : MIDDLE_SPAN_BY_VALUE.keySet()) { - SpanData sink = byId.get(SINK_SPAN_BY_VALUE.get(value)); - assertEquals(MIDDLE_SPAN_BY_VALUE.get(value), sink.getParentSpanId(), - "the sink span of " + value + " is a child of the middle span of " + value); - } - } - - @Test - public void testUnsampledContextsPropagateAndNothingIsExported() throws Exception { - // parent-based: a sampled flag flipped on the way would export the middle or sink span - InMemorySpanExporter exporter = InMemorySpanExporter.create(); - SdkTracerProvider tracerProvider = SdkTracerProvider.builder() - .setSampler(Sampler.parentBased(Sampler.alwaysOff())) - .addSpanProcessor(SimpleSpanProcessor.create(exporter)) - .build(); - try (OpenTelemetrySdk sdk = - OpenTelemetrySdk.builder().setTracerProvider(tracerProvider).build()) { - GlobalOpenTelemetry.resetForTest(); - GlobalOpenTelemetry.set(sdk); - // spans go to this SDK, not OTEL: wait for the sink only - runThroughMiddle(EmitMode.ANCHORED, 2, 0, 2); - } finally { - GlobalOpenTelemetry.resetForTest(); - GlobalOpenTelemetry.set(OTEL.getOpenTelemetry()); - } - - assertTrue(exporter.getFinishedSpanItems().isEmpty()); - assertEquals(2, UNSAMPLED_CONTEXTS_RECEIVED.get(), "the sink got unsampled contexts"); - assertEquals(MIDDLE_TRACE_IDS, RECEIVED_TRACE_IDS, "the traces continue to the sink"); - // different workers: the contexts went through the serializer - assertNotEquals(WORKER_PORT_BY_COMPONENT.get("middle"), - WORKER_PORT_BY_COMPONENT.get("sink")); - } - - private static void assertSinkExecutesAreChildrenOfMiddleExecutes(List spans, - int count) { - Map middles = byId(named(spans, "middle execute")); - List sinks = named(spans, "sink execute"); - assertEquals(count, middles.size()); - assertEquals(count, sinks.size()); - for (SpanData sink : sinks) { - SpanData middle = middles.get(sink.getParentSpanId()); - assertNotNull(middle, "the emit carries the middle execute span as parent"); - assertEquals(middle.getTraceId(), sink.getTraceId()); - } - } - - /** - * Spout to sink (all grouping). With {@code tickSecs} positive, also waits for two ticks. - */ - private List runSpoutToSink(boolean tracing, int count, int sinkTasks, int tickSecs) - throws Exception { - Config conf = conf(tracing); - if (tickSecs > 0) { - conf.put(Config.TOPOLOGY_TICK_TUPLE_FREQ_SECS, tickSecs); - } - // one emit span per tuple and one execute span per tuple and sink task - int expectedSpans = tracing ? count * (1 + sinkTasks) : 0; - return runTopology(conf, count, - builder -> builder.setBolt("sink", new SinkBolt(), sinkTasks).allGrouping("spout"), - () -> OTEL.getSpans().size() >= expectedSpans - && (tickSecs == 0 || TICK_TUPLES_RECEIVED.get() >= 2)); - } - - /** - * Spout to middle (one task, which JOIN and ASYNC_REVERSED need) to sink. - */ - private List runThroughMiddle(EmitMode mode, int count, int expectedSpans, - int sinkTuples) throws Exception { - return runTopology(conf(true), count, - builder -> { - builder.setBolt("middle", new MiddleBolt(mode)).shuffleGrouping("spout"); - builder.setBolt("sink", new SinkBolt()).shuffleGrouping("middle"); - }, - () -> OTEL.getSpans().size() >= expectedSpans - && SINK_TUPLES_RECEIVED.get() >= sinkTuples); - } - - /** One tuple from spout "spout" to a sink that acks, fails or holds it. */ - private List runWithSink(SinkOutcome outcome, Config conf, int expectedSpans) - throws Exception { - return runTopology(conf, 1, - builder -> builder.setBolt("sink", new SinkBolt(outcome)).shuffleGrouping("spout"), - () -> OTEL.getSpans().size() >= expectedSpans); - } - - private static Config conf(boolean tracing) { - Config conf = new Config(); - conf.setNumWorkers(2); - conf.put(Config.TOPOLOGY_TRACING_ENABLED, tracing); - return conf; - } - - /** - * Feeds {@code count} tuples to spout "spout", waits until each is acked or failed and - * {@code done} holds, and returns the exported spans. - */ - private List runTopology(Config conf, int count, Consumer bolts, - BooleanSupplier done) throws Exception { - FeederSpout spout = new FeederSpout(new Fields("value")); - AckFailMapTracker tracker = new AckFailMapTracker(); - spout.setAckFailDelegate(tracker); - TopologyBuilder builder = new TopologyBuilder(); - builder.setSpout("spout", spout); - bolts.accept(builder); - - OTEL.clearSpans(); - RECEIVED_TRACE_IDS.clear(); - CURRENT_IN_EXECUTE.clear(); - SINK_TUPLES_RECEIVED.set(0); - UNSAMPLED_CONTEXTS_RECEIVED.set(0); - MIDDLE_TRACE_IDS.clear(); - MIDDLE_SPAN_BY_VALUE.clear(); - SINK_SPAN_BY_VALUE.clear(); - WORKER_PORT_BY_COMPONENT.clear(); - EMITTER_THREAD_FAILURE.set(null); - TICK_TUPLES_RECEIVED.set(0); - SPAN_CURRENT_DURING_TICK.set(false); - topologyName = "tracing-" + topologyCount++; - StormTopology topology = builder.createTopology(); - try (ILocalTopology ignored = cluster.submitTopology(topologyName, conf, topology)) { - Object[] ids = new Object[count]; - for (int i = 0; i < count; i++) { - ids[i] = i; - spout.feed(new Values("v" + i), i); - } - AssertLoop.assertLoop(id -> tracker.isAcked(id) || tracker.isFailed(id), ids); - // spans end after the bolt acked, and unanchored tuples are not tracked by the acks - Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) - .until(done::getAsBoolean); - return OTEL.getSpans(); - } - } - - private static List named(List spans, String name) { - return spans.stream().filter(s -> s.getName().equals(name)).collect(Collectors.toList()); - } - - private static Map byId(List spans) { - return spans.stream().collect(Collectors.toMap(SpanData::getSpanId, Function.identity())); - } - - private enum EmitMode { - ANCHORED, - /** Anchored to the input twice: both anchors carry the same span. */ - ANCHORED_TWICE, - UNANCHORED, - /** Holds the first input, then emits anchored to both. */ - JOIN, - /** - * Holds the first input; on the second, another thread emits the second then the first, - * each anchored to itself, with the first one's span current. The reverse order rules out - * pairing emits with executes by arrival order. - */ - ASYNC_REVERSED - } - - private static class MiddleBolt extends BaseRichBolt { - private final EmitMode mode; - private transient OutputCollector collector; - private transient Tuple held; - - MiddleBolt(EmitMode mode) { - this.mode = mode; - } - - @Override - public void prepare(Map conf, TopologyContext context, - OutputCollector collector) { - this.collector = collector; - WORKER_PORT_BY_COMPONENT.put("middle", context.getThisWorkerPort()); - } - - @Override - public void execute(Tuple input) { - SpanContext current = Span.current().getSpanContext(); - MIDDLE_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); - MIDDLE_TRACE_IDS.add(current.getTraceId()); - if ((mode == EmitMode.JOIN || mode == EmitMode.ASYNC_REVERSED) && held == null) { - held = input; - return; - } - Values values = new Values(input.getValue(0)); - switch (mode) { - case ANCHORED: - collector.emit(input, values); - break; - case ANCHORED_TWICE: - collector.emit(Arrays.asList(input, input), values); - break; - case UNANCHORED: - collector.emit(values); - break; - case JOIN: - collector.emit(Arrays.asList(held, input), values); - collector.ack(held); - held = null; - break; - case ASYNC_REVERSED: - Tuple first = held; - held = null; - new Thread(() -> emitReversed(first, input)).start(); - return; - default: - throw new IllegalStateException("unknown mode " + mode); - } - collector.ack(input); - } - - private void emitReversed(Tuple first, Tuple second) { - try { - Context firstContext = TupleUtils.traceContext(first); - try (Scope ignored = firstContext.makeCurrent()) { - collector.emit(second, new Values(second.getValue(0))); - collector.emit(first, new Values(first.getValue(0))); - } - collector.ack(second); - collector.ack(first); - } catch (Throwable t) { - EMITTER_THREAD_FAILURE.set(t); - } - } - - @Override - public void declareOutputFields(OutputFieldsDeclarer declarer) { - declarer.declare(new Fields("value")); - } - } - - private enum SinkOutcome { - ACK, - FAIL, - /** Neither acks nor fails, so the tree times out. */ - HOLD - } - - private static class SinkBolt extends BaseRichBolt { - private final SinkOutcome outcome; - private OutputCollector collector; - - SinkBolt() { - this(SinkOutcome.ACK); - } - - SinkBolt(SinkOutcome outcome) { - this.outcome = outcome; - } - - @Override - public void prepare(Map conf, TopologyContext context, - OutputCollector collector) { - this.collector = collector; - WORKER_PORT_BY_COMPONENT.put("sink", context.getThisWorkerPort()); - sinkTaskId = context.getThisTaskId(); - } - - @Override - public void execute(Tuple input) { - if (TupleUtils.isTick(input)) { - if (Span.current().getSpanContext().isValid()) { - SPAN_CURRENT_DURING_TICK.set(true); - } - TICK_TUPLES_RECEIVED.incrementAndGet(); - return; - } - SpanContext received = Span.fromContext(TupleUtils.traceContext(input)).getSpanContext(); - if (received.isValid()) { - RECEIVED_TRACE_IDS.add(received.getTraceId()); - if (!received.isSampled()) { - UNSAMPLED_CONTEXTS_RECEIVED.incrementAndGet(); - } - } - SpanContext current = Span.current().getSpanContext(); - if (current.isValid()) { - CURRENT_IN_EXECUTE.add(current.getSpanId()); - SINK_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); - } - SINK_TUPLES_RECEIVED.incrementAndGet(); - if (outcome == SinkOutcome.ACK) { - collector.ack(input); - } else if (outcome == SinkOutcome.FAIL) { - collector.fail(input); - } - } - - @Override - public void declareOutputFields(OutputFieldsDeclarer declarer) { - } - } -} diff --git a/storm-server/src/test/java/org/apache/storm/TupleTracerTest.java b/storm-server/src/test/java/org/apache/storm/TupleTracerTest.java new file mode 100644 index 00000000000..03721688d0f --- /dev/null +++ b/storm-server/src/test/java/org/apache/storm/TupleTracerTest.java @@ -0,0 +1,372 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm; + +import java.nio.charset.StandardCharsets; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.List; +import java.util.Map; +import java.util.Queue; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.ConcurrentLinkedQueue; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.function.BooleanSupplier; +import java.util.function.Consumer; +import java.util.stream.Collectors; +import org.apache.storm.ILocalCluster.ILocalTopology; +import org.apache.storm.task.OutputCollector; +import org.apache.storm.task.TopologyContext; +import org.apache.storm.task.WorkerTopologyContext; +import org.apache.storm.testing.FeederSpout; +import org.apache.storm.topology.OutputFieldsDeclarer; +import org.apache.storm.topology.TopologyBuilder; +import org.apache.storm.topology.base.BaseRichBolt; +import org.apache.storm.tracing.TupleTracer; +import org.apache.storm.tuple.Fields; +import org.apache.storm.tuple.Tuple; +import org.apache.storm.tuple.TupleImpl; +import org.apache.storm.tuple.Values; +import org.awaitility.Awaitility; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNotEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * Runs topologies on a two-worker local cluster with a tracer that records the calls Storm makes to it. + */ +public class TupleTracerTest { + + /** Tracer calls and execute() calls, in the order they happened on each thread. */ + private static final Queue EVENTS = new ConcurrentLinkedQueue<>(); + private static final Map LATENCY_BY_CONTEXT = new ConcurrentHashMap<>(); + private static final AtomicInteger NEXT_TRACE = new AtomicInteger(); + private static final AtomicInteger DECODES = new AtomicInteger(); + private static final Map WORKER_PORT_BY_COMPONENT = new ConcurrentHashMap<>(); + + private static ILocalCluster cluster; + private static int topologyCount; + + @BeforeAll + public static void startCluster() throws Exception { + cluster = new LocalCluster(); + } + + @AfterAll + public static void stopCluster() throws Exception { + cluster.close(); + } + + @Test + public void testTracerCallsFollowTheTupleTree() throws Exception { + // close() runs after the sink acked, so the acks alone do not mean all scopes are closed + runThroughMiddle(EmitMode.ANCHORED, SinkOutcome.ACK, conf(), 2, + () -> count("ACK ") == 2 && count("close ") == 4); + + List events = new ArrayList<>(EVENTS); + List traces = contexts(events, "spoutEmit "); + assertEquals(2, traces.size()); + for (String trace : traces) { + String middle = trace + ">middle"; + String sink = middle + ">sink"; + assertInOrder(events, "start " + middle, "execute " + middle, "boltEmit middle [" + middle + "]", + "close " + middle); + assertInOrder(events, "start " + sink, "execute " + sink, "close " + sink); + assertInOrder(events, "spoutEmit " + trace, "ACK " + trace); + assertTrue(LATENCY_BY_CONTEXT.getOrDefault(trace, -1L) >= 0, "latency of " + trace); + } + assertNotEquals(WORKER_PORT_BY_COMPONENT.get("middle"), WORKER_PORT_BY_COMPONENT.get("sink")); + assertTrue(DECODES.get() > 0, "contexts crossed workers"); + } + + @Test + public void testFailIsReportedByTheBoltAndTheSpout() throws Exception { + runSpoutToSink(SinkOutcome.FAIL, conf(), () -> count("FAIL ") == 1); + + List events = new ArrayList<>(EVENTS); + String trace = contexts(events, "spoutEmit ").get(0); + assertInOrder(events, "start " + trace + ">sink", "boltFail " + trace + ">sink", "FAIL " + trace); + } + + @Test + public void testTimeoutIsReportedWithTheTimeSinceTheEmit() throws Exception { + Config conf = conf(); + conf.put(Config.TOPOLOGY_MESSAGE_TIMEOUT_SECS, 2); + runSpoutToSink(SinkOutcome.HOLD, conf, () -> count("TIMEOUT ") == 1); + + List events = new ArrayList<>(EVENTS); + String trace = contexts(events, "spoutEmit ").get(0); + assertInOrder(events, "spoutEmit " + trace, "TIMEOUT " + trace); + assertTrue(LATENCY_BY_CONTEXT.getOrDefault(trace, -1L) >= TimeUnit.SECONDS.toMillis(1)); + } + + @Test + public void testBoltFailIsReportedWithoutAckers() throws Exception { + Config conf = conf(); + conf.put(Config.TOPOLOGY_ACKER_EXECUTORS, 0); + runSpoutToSink(SinkOutcome.FAIL, conf, () -> count("boltFail ") == 1); + + String trace = contexts(new ArrayList<>(EVENTS), "spoutEmit ").get(0); + assertEquals(1, count("boltFail " + trace + ">sink")); + assertEquals(0, count("FAIL "), "without ackers the spout reports no outcome"); + } + + @Test + public void testEmitGetsTheContextsOfItsAnchorsInOrder() throws Exception { + runThroughMiddle(EmitMode.JOIN, SinkOutcome.ACK, conf(), 2, () -> count("close ") == 3); + + List events = new ArrayList<>(EVENTS); + List middles = contexts(events, "execute ").stream().filter(c -> c.endsWith(">middle")) + .collect(Collectors.toList()); + assertEquals(2, middles.size()); + String joined = middles.get(0) + "+" + middles.get(1); + assertInOrder(events, "boltEmit middle [" + middles.get(0) + ", " + middles.get(1) + "]", + "start " + joined + ">sink"); + } + + @Test + public void testUnanchoredEmitCarriesNoContext() throws Exception { + runThroughMiddle(EmitMode.UNANCHORED, SinkOutcome.ACK, conf(), 2, () -> count("execute null") == 2); + + assertEquals(2, count("boltEmit middle []")); + assertEquals(2, count("start "), "only the middle bolt gets traced tuples"); + } + + @Test + public void testTuplesAreNotTracedWithoutATracerClass() throws Exception { + runThroughMiddle(EmitMode.ANCHORED, SinkOutcome.ACK, new Config(), 2, () -> count("execute null") == 4); + + assertEquals(EVENTS.size(), count("execute null"), "only execute() calls, all without a context"); + } + + private static Config conf() { + Config conf = new Config(); + conf.put(Config.TOPOLOGY_TRACING_TRACER, RecordingTracer.class.getName()); + return conf; + } + + private void runSpoutToSink(SinkOutcome outcome, Config conf, BooleanSupplier done) throws Exception { + runTopology(conf, 1, builder -> builder.setBolt("sink", new SinkBolt(outcome)).shuffleGrouping("spout"), done); + } + + private void runThroughMiddle(EmitMode mode, SinkOutcome outcome, Config conf, int count, BooleanSupplier done) + throws Exception { + runTopology(conf, count, builder -> { + // one middle task, which JOIN needs + builder.setBolt("middle", new MiddleBolt(mode)).shuffleGrouping("spout"); + builder.setBolt("sink", new SinkBolt(outcome)).shuffleGrouping("middle"); + }, done); + } + + /** + * Feeds {@code count} tuples to spout "spout" and waits until {@code done} holds. + */ + private void runTopology(Config conf, int count, Consumer bolts, BooleanSupplier done) + throws Exception { + conf.setNumWorkers(2); + FeederSpout spout = new FeederSpout(new Fields("value")); + TopologyBuilder builder = new TopologyBuilder(); + builder.setSpout("spout", spout); + bolts.accept(builder); + + EVENTS.clear(); + LATENCY_BY_CONTEXT.clear(); + DECODES.set(0); + WORKER_PORT_BY_COMPONENT.clear(); + String name = "tracer-" + topologyCount++; + try (ILocalTopology ignored = cluster.submitTopology(name, conf, builder.createTopology())) { + for (int i = 0; i < count; i++) { + spout.feed(new Values("v" + i), i); + } + Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS).until(done::getAsBoolean); + } + } + + private static long count(String prefix) { + return EVENTS.stream().filter(e -> e.startsWith(prefix)).count(); + } + + private static List contexts(List events, String prefix) { + return events.stream().filter(e -> e.startsWith(prefix)).map(e -> e.substring(prefix.length())) + .collect(Collectors.toList()); + } + + private static void assertInOrder(List events, String... expected) { + int previous = -1; + for (String event : expected) { + int index = events.indexOf(event); + assertTrue(index > previous, event + " after " + String.join(", ", expected) + " in " + events); + previous = index; + } + } + + /** + * Spout contexts are "t1", "t2", ...; an execute appends ">component" to the context it gets; a bolt emit + * joins its anchor contexts with "+". + */ + public static class RecordingTracer implements TupleTracer { + private WorkerTopologyContext context; + + @Override + public void prepare(Map topoConf, WorkerTopologyContext context) { + this.context = context; + } + + @Override + public Object spoutEmit(int taskId, String streamId) { + String trace = "t" + NEXT_TRACE.incrementAndGet(); + EVENTS.add("spoutEmit " + trace); + return trace; + } + + @Override + public Object boltEmit(int taskId, String streamId, List anchorContexts) { + EVENTS.add("boltEmit " + context.getComponentId(taskId) + " " + anchorContexts); + return anchorContexts.isEmpty() ? null + : anchorContexts.stream().map(String::valueOf).collect(Collectors.joining("+")); + } + + @Override + public ExecuteScope startExecute(int taskId, Tuple tuple, Object received) { + String executeContext = received + ">" + context.getComponentId(taskId); + EVENTS.add("start " + executeContext); + return new ExecuteScope() { + @Override + public Object context() { + return executeContext; + } + + @Override + public void close() { + EVENTS.add("close " + executeContext); + } + }; + } + + @Override + public void spoutOutcome(int taskId, Object context, Outcome outcome, long latencyMs) { + LATENCY_BY_CONTEXT.put(context, latencyMs); + EVENTS.add(outcome + " " + context); + } + + @Override + public void boltFail(int taskId, Object context) { + EVENTS.add("boltFail " + context); + } + + @Override + public byte[] encode(Object context) { + return ((String) context).getBytes(StandardCharsets.UTF_8); + } + + @Override + public Object decode(byte[] bytes) { + DECODES.incrementAndGet(); + return new String(bytes, StandardCharsets.UTF_8); + } + } + + private enum EmitMode { + ANCHORED, + UNANCHORED, + /** Holds the first input, then emits anchored to both. */ + JOIN + } + + private static class MiddleBolt extends BaseRichBolt { + private final EmitMode mode; + private transient OutputCollector collector; + private transient Tuple held; + + MiddleBolt(EmitMode mode) { + this.mode = mode; + } + + @Override + public void prepare(Map conf, TopologyContext context, OutputCollector collector) { + this.collector = collector; + WORKER_PORT_BY_COMPONENT.put("middle", context.getThisWorkerPort()); + } + + @Override + public void execute(Tuple input) { + EVENTS.add("execute " + ((TupleImpl) input).getTraceContext()); + Values values = new Values(input.getValue(0)); + switch (mode) { + case ANCHORED: + collector.emit(input, values); + break; + case UNANCHORED: + collector.emit(values); + break; + case JOIN: + if (held == null) { + held = input; + return; + } + collector.emit(Arrays.asList(held, input), values); + collector.ack(held); + break; + default: + throw new IllegalStateException("unknown mode " + mode); + } + collector.ack(input); + } + + @Override + public void declareOutputFields(OutputFieldsDeclarer declarer) { + declarer.declare(new Fields("value")); + } + } + + private enum SinkOutcome { + ACK, + FAIL, + /** Neither acks nor fails, so the tree times out. */ + HOLD + } + + private static class SinkBolt extends BaseRichBolt { + private final SinkOutcome outcome; + private transient OutputCollector collector; + + SinkBolt(SinkOutcome outcome) { + this.outcome = outcome; + } + + @Override + public void prepare(Map conf, TopologyContext context, OutputCollector collector) { + this.collector = collector; + WORKER_PORT_BY_COMPONENT.put("sink", context.getThisWorkerPort()); + } + + @Override + public void execute(Tuple input) { + EVENTS.add("execute " + ((TupleImpl) input).getTraceContext()); + if (outcome == SinkOutcome.ACK) { + collector.ack(input); + } else if (outcome == SinkOutcome.FAIL) { + collector.fail(input); + } + } + + @Override + public void declareOutputFields(OutputFieldsDeclarer declarer) { + } + } +} From 0f396d950f4f861c9425a2eb96bac52736afc212 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Mon, 5 Oct 2026 16:09:06 +0200 Subject: [PATCH 10/12] feat: add the OpenTelemetry tracing module 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. --- external/pom.xml | 1 + external/storm-opentelemetry/pom.xml | 101 +++ .../OpenTelemetryTupleTracer.java | 269 ++++++++ .../storm/opentelemetry/StormTracing.java | 35 ++ .../opentelemetry/TraceContextCodec.java | 105 ++++ .../OpenTelemetryTupleTracerTest.java | 73 +++ .../opentelemetry/TopologyTracingTest.java | 576 ++++++++++++++++++ .../opentelemetry/TraceContextCodecTest.java | 114 ++++ 8 files changed, 1274 insertions(+) create mode 100644 external/storm-opentelemetry/pom.xml create mode 100644 external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java create mode 100644 external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/StormTracing.java create mode 100644 external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/TraceContextCodec.java create mode 100644 external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracerTest.java create mode 100644 external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java create mode 100644 external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TraceContextCodecTest.java diff --git a/external/pom.xml b/external/pom.xml index a7a50e4f4c4..1b8a845a7bc 100644 --- a/external/pom.xml +++ b/external/pom.xml @@ -43,6 +43,7 @@ storm-kafka-monitor storm-metrics storm-metrics-prometheus + storm-opentelemetry storm-redis diff --git a/external/storm-opentelemetry/pom.xml b/external/storm-opentelemetry/pom.xml new file mode 100644 index 00000000000..5a3c8f030dd --- /dev/null +++ b/external/storm-opentelemetry/pom.xml @@ -0,0 +1,101 @@ + + + + 4.0.0 + + storm-external + org.apache.storm + 3.1.1-SNAPSHOT + ../pom.xml + + + storm-opentelemetry + Storm OpenTelemetry + jar + Traces Storm tuple trees with OpenTelemetry. + + + 1.66.0 + + + + + + io.opentelemetry + opentelemetry-bom + ${opentelemetry.version} + pom + import + + + + + + + org.apache.storm + storm-client + ${project.version} + ${provided.scope} + + + + io.opentelemetry + opentelemetry-api + + + + org.apache.storm + storm-server + ${project.version} + test + + + io.opentelemetry + opentelemetry-sdk-testing + test + + + org.junit.jupiter + junit-jupiter + test + + + org.mockito + mockito-core + test + + + org.awaitility + awaitility + test + + + + + + + org.apache.maven.plugins + maven-checkstyle-plugin + + + org.apache.maven.plugins + maven-pmd-plugin + + + + diff --git a/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java new file mode 100644 index 00000000000..db5eeb63834 --- /dev/null +++ b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java @@ -0,0 +1,269 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm.opentelemetry; + +import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.api.common.AttributesBuilder; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanBuilder; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.StatusCode; +import io.opentelemetry.api.trace.Tracer; +import io.opentelemetry.context.Context; +import io.opentelemetry.context.Scope; +import java.net.UnknownHostException; +import java.util.Collection; +import java.util.Collections; +import java.util.LinkedHashSet; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicLong; +import org.apache.storm.Config; +import org.apache.storm.task.WorkerTopologyContext; +import org.apache.storm.tracing.TupleTracer; +import org.apache.storm.tuple.Tuple; +import org.apache.storm.utils.Time; +import org.apache.storm.utils.Utils; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +/** + * Traces tuple trees with OpenTelemetry. To use it, set {@link Config#TOPOLOGY_TRACING_TRACER} to this class name. Spans go to + * the SDK registered as the global OpenTelemetry instance, usually by the OpenTelemetry Java agent, version 2.23.0 or later. Until + * one is registered, tuples are not traced and one warning is logged. + * + *

Each spout emit starts a trace with a root span named "component emit", started and ended at once. Each bolt + * {@code execute()} of a traced tuple runs in a child span named "component execute", current while {@code execute()} runs. A bolt + * emit carries the context of its anchors: the anchor's context if they share one span, otherwise a new root span linked to each. + * The spout records the ack, fail or timeout of each traced tuple tree, and a bolt each {@code fail()}, as spans started and ended + * at once. Contexts with the sampled flag unset are propagated too. + */ +public class OpenTelemetryTupleTracer implements TupleTracer { + + private static final Logger LOG = LoggerFactory.getLogger(OpenTelemetryTupleTracer.class); + private static final String INSTRUMENTATION_SCOPE = "org.apache.storm"; + private static final long SDK_LOOKUP_INTERVAL_MS = 1000; + private static final long UNTRACED_EMIT_LOG_INTERVAL_MS = 60_000; + + private static final AttributeKey TOPOLOGY_NAME_KEY = AttributeKey.stringKey("storm.topology.name"); + private static final AttributeKey TOPOLOGY_ID_KEY = AttributeKey.stringKey("storm.topology.id"); + private static final AttributeKey COMPONENT_ID_KEY = AttributeKey.stringKey("storm.component.id"); + private static final AttributeKey TASK_ID_KEY = AttributeKey.longKey("storm.task.id"); + private static final AttributeKey SOURCE_COMPONENT_ID_KEY = AttributeKey.stringKey("storm.source.component.id"); + private static final AttributeKey SOURCE_STREAM_ID_KEY = AttributeKey.stringKey("storm.source.stream.id"); + private static final AttributeKey WORKER_HOST_KEY = AttributeKey.stringKey("storm.worker.host"); + private static final AttributeKey WORKER_PORT_KEY = AttributeKey.longKey("storm.worker.port"); + + private WorkerTopologyContext context; + private Attributes workerAttributes; + /** Indexed by task id; null for the tasks of other workers and for system tasks with a negative id. */ + private TaskSpans[] taskSpans; + private volatile Tracer tracer; + private volatile long nextSdkLookupMs; + private final AtomicBoolean warnedNoSdk = new AtomicBoolean(); + + @Override + public void prepare(Map topoConf, WorkerTopologyContext context) { + this.context = context; + AttributesBuilder attributes = Attributes.builder() + .put(TOPOLOGY_NAME_KEY, (String) topoConf.get(Config.TOPOLOGY_NAME)) + .put(TOPOLOGY_ID_KEY, context.getStormId()) + .put(WORKER_PORT_KEY, context.getThisWorkerPort().longValue()); + try { + attributes.put(WORKER_HOST_KEY, Utils.hostname()); + } catch (UnknownHostException e) { + LOG.warn("Execute spans get no {} attribute: the host name is unknown", WORKER_HOST_KEY, e); + } + this.workerAttributes = attributes.build(); + int maxTaskId = context.getThisWorkerTasks().stream().mapToInt(Integer::intValue).max().orElse(-1); + TaskSpans[] byTask = new TaskSpans[maxTaskId + 1]; + for (int taskId : context.getThisWorkerTasks()) { + if (taskId >= 0) { + byTask[taskId] = newTaskSpans(taskId); + } + } + this.taskSpans = byTask; + } + + @Override + public Object spoutEmit(int taskId, String streamId) { + Tracer current = tracer(); + return current == null ? null : newRootContext(current, spans(taskId).emitName(), Collections.emptyList()); + } + + @Override + public Object boltEmit(int taskId, String streamId, List anchorContexts) { + if (anchorContexts.isEmpty()) { + logUntracedEmitUnderSpan(taskId, streamId); + return null; + } + Context first = (Context) anchorContexts.get(0); + if (anchorContexts.size() == 1) { + return first; + } + Set linkedSpans = new LinkedHashSet<>(); + for (Object anchorContext : anchorContexts) { + linkedSpans.add(Span.fromContext((Context) anchorContext).getSpanContext()); + } + if (linkedSpans.size() == 1) { + return first; + } + // the SDK keeps up to 128 links by default + Tracer current = tracer(); + return current == null ? null : newRootContext(current, spans(taskId).emitName(), linkedSpans); + } + + @Override + public ExecuteScope startExecute(int taskId, Tuple tuple, Object context) { + Tracer current = tracer(); + if (current == null) { + return null; + } + Context received = (Context) context; + TaskSpans spans = spans(taskId); + Span span = current.spanBuilder(spans.executeName()).setParent(received).startSpan(); + if (span.isRecording()) { + span.setAllAttributes(spans.executeAttributes()); + span.setAttribute(SOURCE_COMPONENT_ID_KEY, tuple.getSourceComponent()); + span.setAttribute(SOURCE_STREAM_ID_KEY, tuple.getSourceStreamId()); + } + // the tuple keeps the span ids only: it may outlive the span + Context executeContext = received.with(Span.wrap(span.getSpanContext())); + return new ExecuteSpan(span, span.makeCurrent(), executeContext); + } + + @Override + public void spoutOutcome(int taskId, Object context, Outcome outcome, long latencyMs) { + TaskSpans spans = spans(taskId); + String spanName = switch (outcome) { + case ACK -> spans.ackName(); + case FAIL -> spans.failName(); + case TIMEOUT -> spans.timeoutName(); + }; + recordOutcome((Context) context, spanName, outcome != Outcome.ACK); + } + + @Override + public void boltFail(int taskId, Object context) { + recordOutcome((Context) context, spans(taskId).failName(), true); + } + + @Override + public byte[] encode(Object context) { + return TraceContextCodec.encode((Context) context); + } + + @Override + public Object decode(byte[] bytes) { + return TraceContextCodec.decode(bytes); + } + + /** + * Returns the tracer, or null until an SDK is registered as the global instance. Checks at most once a second, with isSet() + * rather than get() so that an SDK registered later is still used. + */ + private Tracer tracer() { + Tracer current = tracer; + if (current != null) { + return current; + } + long now = Time.currentTimeMillis(); + if (now < nextSdkLookupMs) { + return null; + } + nextSdkLookupMs = now + SDK_LOOKUP_INTERVAL_MS; + if (GlobalOpenTelemetry.isSet()) { + current = GlobalOpenTelemetry.get().getTracer(INSTRUMENTATION_SCOPE); + tracer = current; + return current; + } + if (warnedNoSdk.compareAndSet(false, true)) { + LOG.warn("{} is configured but no OpenTelemetry SDK is registered as the global instance, so tuples are not traced" + + " until one is. With the OpenTelemetry Java agent, this needs version 2.23.0 or later.", getClass().getName()); + } + return null; + } + + /** + * Starts and immediately ends a root span linked to {@code links}, and returns its context, or null when the span is not + * valid. The context keeps the span ids only: pending tuples hold it until their tree completes. + */ + private static Context newRootContext(Tracer tracer, String spanName, Collection links) { + SpanBuilder builder = tracer.spanBuilder(spanName).setNoParent(); + links.forEach(builder::addLink); + Span span = builder.startSpan(); + span.end(); + SpanContext ids = span.getSpanContext(); + return ids.isValid() ? Context.root().with(Span.wrap(ids)) : null; + } + + private void recordOutcome(Context parent, String spanName, boolean error) { + Tracer current = tracer(); + if (current == null) { + return; + } + Span span = current.spanBuilder(spanName).setParent(parent).startSpan(); + if (error) { + span.setStatus(StatusCode.ERROR); + } + span.end(); + } + + private void logUntracedEmitUnderSpan(int taskId, String streamId) { + if (!LOG.isDebugEnabled() || !Span.current().getSpanContext().isValid()) { + return; + } + TaskSpans spans = spans(taskId); + AtomicLong lastLogMs = spans.lastUntracedEmitLogMs(); + long last = lastLogMs.get(); + long now = Time.currentTimeMillis(); + if (now - last < UNTRACED_EMIT_LOG_INTERVAL_MS || !lastLogMs.compareAndSet(last, now)) { + return; + } + LOG.debug("{} emitted on stream {} without a traced anchor while a span was current; the emitted tuple carries no" + + " trace context", spans.component(), streamId); + } + + private TaskSpans spans(int taskId) { + TaskSpans[] byTask = taskSpans; + TaskSpans spans = taskId >= 0 && taskId < byTask.length ? byTask[taskId] : null; + return spans != null ? spans : newTaskSpans(taskId); + } + + private TaskSpans newTaskSpans(int taskId) { + String component = context.getComponentId(taskId); + Attributes executeAttributes = workerAttributes.toBuilder() + .put(COMPONENT_ID_KEY, component) + .put(TASK_ID_KEY, (long) taskId) + .build(); + return new TaskSpans(component, component + " emit", component + " execute", component + " ack", component + " fail", + component + " timeout", executeAttributes, new AtomicLong()); + } + + /** Span names, execute span attributes and the time of the last untraced emit log line of one task. */ + private record TaskSpans(String component, String emitName, String executeName, String ackName, String failName, + String timeoutName, Attributes executeAttributes, AtomicLong lastUntracedEmitLogMs) { + } + + private record ExecuteSpan(Span span, Scope scope, Context context) implements ExecuteScope { + @Override + public void close() { + scope.close(); + span.end(); + } + } +} diff --git a/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/StormTracing.java b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/StormTracing.java new file mode 100644 index 00000000000..d0d86d33e77 --- /dev/null +++ b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/StormTracing.java @@ -0,0 +1,35 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm.opentelemetry; + +import io.opentelemetry.context.Context; +import org.apache.storm.tuple.Tuple; +import org.apache.storm.tuple.TupleImpl; + +/** + * Gives bolts the trace context of the tuples they process, when {@link OpenTelemetryTupleTracer} traces the topology. + */ +public final class StormTracing { + + private StormTracing() { + } + + /** + * Returns the context to run work for this tuple under, so that spans created there join the tuple's trace, or + * {@link Context#root()} when the tuple carries none. Never null. The context holds span ids only: it parents new spans but + * gives no access to the execute span itself. Example: {@code pool.submit(StormTracing.context(input).wrap(task))}. + */ + public static Context context(Tuple tuple) { + return tuple instanceof TupleImpl impl && impl.getTraceContext() instanceof Context context ? context : Context.root(); + } +} diff --git a/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/TraceContextCodec.java b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/TraceContextCodec.java new file mode 100644 index 00000000000..db1e4a9d810 --- /dev/null +++ b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/TraceContextCodec.java @@ -0,0 +1,105 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm.opentelemetry; + +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.SpanId; +import io.opentelemetry.api.trace.TraceFlags; +import io.opentelemetry.api.trace.TraceId; +import io.opentelemetry.api.trace.TraceState; +import io.opentelemetry.api.trace.TraceStateBuilder; +import io.opentelemetry.context.Context; +import java.nio.charset.StandardCharsets; +import java.util.Arrays; +import java.util.StringJoiner; + +/** + * Binary form of a W3C trace context: a version byte, the 16-byte trace id, the 8-byte span id, the trace flags byte, then the + * tracestate in its W3C header form, if not empty. + */ +final class TraceContextCodec { + + /** Bump when the layout changes; readers return no context for other versions. */ + static final int VERSION = 1; + /** The tracestate length W3C asks vendors to propagate at least. Longer ones are not sent. */ + static final int MAX_TRACE_STATE_LENGTH = 512; + + private static final int TRACE_ID_BYTES = 16; + private static final int SPAN_ID_BYTES = 8; + private static final int TRACE_STATE_OFFSET = 1 + TRACE_ID_BYTES + SPAN_ID_BYTES + 1; + + private TraceContextCodec() { + } + + /** + * Returns the bytes of the span context in {@code context}, or null when it holds no valid span context. Unsampled span + * contexts are encoded too. + */ + static byte[] encode(Context context) { + SpanContext span = Span.fromContext(context).getSpanContext(); + if (!span.isValid()) { + return null; + } + byte[] traceState = traceState(span.getTraceState()); + byte[] bytes = new byte[TRACE_STATE_OFFSET + traceState.length]; + bytes[0] = VERSION; + System.arraycopy(span.getTraceIdBytes(), 0, bytes, 1, TRACE_ID_BYTES); + System.arraycopy(span.getSpanIdBytes(), 0, bytes, 1 + TRACE_ID_BYTES, SPAN_ID_BYTES); + bytes[TRACE_STATE_OFFSET - 1] = span.getTraceFlags().asByte(); + System.arraycopy(traceState, 0, bytes, TRACE_STATE_OFFSET, traceState.length); + return bytes; + } + + /** + * Returns a context with the remote span context in {@code bytes}, or null when they are too short, of another version, carry + * invalid ids or a tracestate over {@link #MAX_TRACE_STATE_LENGTH}. Invalid tracestate entries are dropped. + */ + static Context decode(byte[] bytes) { + int traceStateLength = bytes.length - TRACE_STATE_OFFSET; + if (traceStateLength < 0 || traceStateLength > MAX_TRACE_STATE_LENGTH || bytes[0] != VERSION) { + return null; + } + String traceId = TraceId.fromBytes(Arrays.copyOfRange(bytes, 1, 1 + TRACE_ID_BYTES)); + String spanId = SpanId.fromBytes(Arrays.copyOfRange(bytes, 1 + TRACE_ID_BYTES, TRACE_STATE_OFFSET - 1)); + TraceFlags flags = TraceFlags.fromByte(bytes[TRACE_STATE_OFFSET - 1]); + TraceState traceState = traceStateLength == 0 + ? TraceState.getDefault() + : parseTraceState(new String(bytes, TRACE_STATE_OFFSET, traceStateLength, StandardCharsets.US_ASCII)); + SpanContext span = SpanContext.createFromRemoteParent(traceId, spanId, flags, traceState); + return span.isValid() ? Context.root().with(Span.wrap(span)) : null; + } + + private static byte[] traceState(TraceState traceState) { + if (traceState.isEmpty()) { + return new byte[0]; + } + StringJoiner entries = new StringJoiner(","); + traceState.forEach((key, value) -> entries.add(key + '=' + value)); + byte[] bytes = entries.toString().getBytes(StandardCharsets.US_ASCII); + return bytes.length > MAX_TRACE_STATE_LENGTH ? new byte[0] : bytes; + } + + private static TraceState parseTraceState(String header) { + String[] entries = header.split(","); + TraceStateBuilder builder = TraceState.builder(); + // put() inserts in front of existing entries: add in reverse to keep the order + for (int i = entries.length - 1; i >= 0; i--) { + int separator = entries[i].indexOf('='); + if (separator > 0) { + builder.put(entries[i].substring(0, separator), entries[i].substring(separator + 1)); + } + } + return builder.build(); + } +} diff --git a/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracerTest.java b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracerTest.java new file mode 100644 index 00000000000..af5b7c16dd8 --- /dev/null +++ b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracerTest.java @@ -0,0 +1,73 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm.opentelemetry; + +import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.trace.SdkTracerProvider; +import java.util.List; +import java.util.Map; +import org.apache.storm.Config; +import org.apache.storm.task.WorkerTopologyContext; +import org.apache.storm.utils.Time; +import org.apache.storm.utils.Time.SimulatedTime; +import org.apache.storm.utils.Utils; +import org.junit.jupiter.api.Test; +import org.mockito.MockedStatic; + +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.mockStatic; +import static org.mockito.Mockito.times; +import static org.mockito.Mockito.when; + +public class OpenTelemetryTupleTracerTest { + + private static final int SPOUT_TASK = 1; + + @Test + public void testLooksForAnSdkAtMostOnceASecondUntilOneIsRegistered() { + OpenTelemetryTupleTracer tracer = preparedTracer(); + try (SimulatedTime ignored = new SimulatedTime(); + MockedStatic global = mockStatic(GlobalOpenTelemetry.class); + OpenTelemetrySdk sdk = OpenTelemetrySdk.builder().setTracerProvider(SdkTracerProvider.builder().build()).build()) { + global.when(GlobalOpenTelemetry::isSet).thenReturn(false); + + assertNull(tracer.spoutEmit(SPOUT_TASK, Utils.DEFAULT_STREAM_ID)); + assertNull(tracer.spoutEmit(SPOUT_TASK, Utils.DEFAULT_STREAM_ID)); + Time.advanceTime(999); + assertNull(tracer.spoutEmit(SPOUT_TASK, Utils.DEFAULT_STREAM_ID)); + global.verify(GlobalOpenTelemetry::isSet, times(1)); + + global.when(GlobalOpenTelemetry::isSet).thenReturn(true); + global.when(GlobalOpenTelemetry::get).thenReturn(sdk); + assertNull(tracer.spoutEmit(SPOUT_TASK, Utils.DEFAULT_STREAM_ID), "registered within the same second"); + Time.advanceTime(1); + assertNotNull(tracer.spoutEmit(SPOUT_TASK, Utils.DEFAULT_STREAM_ID)); + assertNotNull(tracer.spoutEmit(SPOUT_TASK, Utils.DEFAULT_STREAM_ID)); + global.verify(GlobalOpenTelemetry::isSet, times(2)); + } + } + + private static OpenTelemetryTupleTracer preparedTracer() { + WorkerTopologyContext context = mock(WorkerTopologyContext.class); + when(context.getStormId()).thenReturn("topology-1-0"); + when(context.getThisWorkerPort()).thenReturn(6700); + when(context.getThisWorkerTasks()).thenReturn(List.of(SPOUT_TASK)); + when(context.getComponentId(SPOUT_TASK)).thenReturn("spout"); + OpenTelemetryTupleTracer tracer = new OpenTelemetryTupleTracer(); + tracer.prepare(Map.of(Config.TOPOLOGY_NAME, "topology"), context); + return tracer; + } +} diff --git a/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java new file mode 100644 index 00000000000..1cdbdb7d984 --- /dev/null +++ b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java @@ -0,0 +1,576 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm.opentelemetry; + +import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.common.Attributes; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.StatusCode; +import io.opentelemetry.context.Context; +import io.opentelemetry.context.Scope; +import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter; +import io.opentelemetry.sdk.testing.junit5.OpenTelemetryExtension; +import io.opentelemetry.sdk.trace.SdkTracerProvider; +import io.opentelemetry.sdk.trace.data.SpanData; +import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; +import io.opentelemetry.sdk.trace.samplers.Sampler; +import java.util.Arrays; +import java.util.List; +import java.util.Map; +import java.util.Set; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicReference; +import java.util.function.BooleanSupplier; +import java.util.function.Consumer; +import java.util.function.Function; +import java.util.stream.Collectors; +import org.apache.storm.Config; +import org.apache.storm.ILocalCluster; +import org.apache.storm.ILocalCluster.ILocalTopology; +import org.apache.storm.LocalCluster; +import org.apache.storm.Testing; +import org.apache.storm.generated.StormTopology; +import org.apache.storm.task.OutputCollector; +import org.apache.storm.task.TopologyContext; +import org.apache.storm.testing.AckFailMapTracker; +import org.apache.storm.testing.FeederSpout; +import org.apache.storm.topology.OutputFieldsDeclarer; +import org.apache.storm.topology.TopologyBuilder; +import org.apache.storm.topology.base.BaseRichBolt; +import org.apache.storm.tuple.Fields; +import org.apache.storm.tuple.Tuple; +import org.apache.storm.tuple.Values; +import org.apache.storm.utils.TupleUtils; +import org.apache.storm.utils.Utils; +import org.awaitility.Awaitility; +import org.junit.jupiter.api.AfterAll; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.RegisterExtension; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNotEquals; +import static org.junit.jupiter.api.Assertions.assertNotNull; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** + * Runs topologies on a two-worker local cluster with tracing on or off and checks the spans + * Storm exports. + */ +public class TopologyTracingTest { + + @RegisterExtension + static final OpenTelemetryExtension OTEL = OpenTelemetryExtension.create(); + + private static final Set RECEIVED_TRACE_IDS = ConcurrentHashMap.newKeySet(); + /** Span ids that were current on the sink's thread while its execute() ran. */ + private static final Set CURRENT_IN_EXECUTE = ConcurrentHashMap.newKeySet(); + private static final AtomicInteger SINK_TUPLES_RECEIVED = new AtomicInteger(); + private static final AtomicInteger UNSAMPLED_CONTEXTS_RECEIVED = new AtomicInteger(); + private static final Set MIDDLE_TRACE_IDS = ConcurrentHashMap.newKeySet(); + /** Tuple value to the id of the span current while middle, then sink, handled it. */ + private static final Map MIDDLE_SPAN_BY_VALUE = new ConcurrentHashMap<>(); + private static final Map SINK_SPAN_BY_VALUE = new ConcurrentHashMap<>(); + private static final Map WORKER_PORT_BY_COMPONENT = new ConcurrentHashMap<>(); + private static final AtomicReference EMITTER_THREAD_FAILURE = + new AtomicReference<>(); + private static final AtomicInteger TICK_TUPLES_RECEIVED = new AtomicInteger(); + private static final AtomicBoolean SPAN_CURRENT_DURING_TICK = new AtomicBoolean(); + + private static ILocalCluster cluster; + private static int topologyCount; + private static String topologyName; + private static volatile int sinkTaskId; + + @BeforeAll + public static void startCluster() throws Exception { + cluster = new LocalCluster(); + } + + @AfterAll + public static void stopCluster() throws Exception { + cluster.close(); + } + + @Test + public void testEachSpoutEmitStartsARootSpan() throws Exception { + List spans = runSpoutToSink(true, 3, 1, 0); // 3 tuples, 1 sink task, no ticks + + List emits = named(spans, "spout emit"); + assertEquals(3, emits.size()); + for (SpanData emit : emits) { + assertFalse(emit.getParentSpanContext().isValid(), "a spout emit starts a new trace"); + } + Set emitTraceIds = + emits.stream().map(SpanData::getTraceId).collect(Collectors.toSet()); + assertEquals(3, emitTraceIds.size()); + assertEquals(emitTraceIds, RECEIVED_TRACE_IDS, "each tuple carries its emit context"); + } + + @Test + public void testNoSpansWhenTracingIsOff() throws Exception { + assertTrue(runSpoutToSink(false, 1, 1, 0).isEmpty()); // 1 tuple, 1 sink task, no ticks + assertTrue(RECEIVED_TRACE_IDS.isEmpty(), "tuples carry no context"); + } + + @Test + public void testExecuteSpanIsChildOfTheEmitAndCurrentDuringExecute() throws Exception { + // two sink tasks with all grouping: on two workers, a copy of each tuple crosses workers + List spans = runSpoutToSink(true, 2, 2, 0); // 2 tuples, 2 sink tasks, no ticks + + Map emits = byId(named(spans, "spout emit")); + List executes = named(spans, "sink execute"); + assertEquals(2, emits.size()); + assertEquals(4, executes.size()); + for (SpanData execute : executes) { + SpanData emit = emits.get(execute.getParentSpanId()); + assertNotNull(emit, "an execute span is a child of the emit that produced its tuple"); + assertEquals(emit.getTraceId(), execute.getTraceId()); + } + assertTrue(executes.stream().anyMatch(s -> s.getParentSpanContext().isRemote()), + "at least one tuple crossed workers, so its context went through the serializer"); + Set executeIds = + executes.stream().map(SpanData::getSpanId).collect(Collectors.toSet()); + assertEquals(executeIds, CURRENT_IN_EXECUTE, "the execute span is current in the bolt"); + } + + @Test + public void testTickTuplesGetNoSpanAndSeeNoLeftoverContext() throws Exception { + List spans = runSpoutToSink(true, 1, 1, 1); // 1 tuple, 1 sink task, 1 s ticks + + assertEquals(1, named(spans, "sink execute").size()); + assertFalse(SPAN_CURRENT_DURING_TICK.get(), "the execute span's scope was closed"); + } + + @Test + public void testExecuteSpanCarriesStormAttributes() throws Exception { + List spans = runSpoutToSink(true, 1, 1, 0); // 1 tuple, 1 sink task, no ticks + + Attributes attributes = named(spans, "sink execute").get(0).getAttributes(); + assertEquals(topologyName, attributes.get(AttributeKey.stringKey("storm.topology.name"))); + String topologyId = attributes.get(AttributeKey.stringKey("storm.topology.id")); + assertTrue(topologyId.startsWith(topologyName), topologyId); + assertEquals("sink", attributes.get(AttributeKey.stringKey("storm.component.id"))); + assertEquals(sinkTaskId, attributes.get(AttributeKey.longKey("storm.task.id"))); + assertEquals("spout", attributes.get(AttributeKey.stringKey("storm.source.component.id"))); + assertEquals("default", attributes.get(AttributeKey.stringKey("storm.source.stream.id"))); + assertEquals(Utils.hostname(), attributes.get(AttributeKey.stringKey("storm.worker.host"))); + assertEquals(WORKER_PORT_BY_COMPONENT.get("sink").longValue(), + attributes.get(AttributeKey.longKey("storm.worker.port"))); + } + + @Test + public void testAckRecordsAnOutcomeSpanUnderTheRoot() throws Exception { + // spout emit, sink execute, spout ack + List spans = runWithSink(SinkOutcome.ACK, conf(true), 3); + + SpanData emit = named(spans, "spout emit").get(0); + SpanData ack = named(spans, "spout ack").get(0); + assertEquals(emit.getSpanId(), ack.getParentSpanId()); + assertEquals(StatusCode.UNSET, ack.getStatus().getStatusCode()); + } + + @Test + public void testFailRecordsErrorSpansInTheBoltAndAtTheSpout() throws Exception { + // spout emit, sink execute, sink fail, spout fail + List spans = runWithSink(SinkOutcome.FAIL, conf(true), 4); + + SpanData emit = named(spans, "spout emit").get(0); + SpanData execute = named(spans, "sink execute").get(0); + assertEquals(1, named(spans, "sink fail").size()); + SpanData sinkFail = named(spans, "sink fail").get(0); + SpanData spoutFail = named(spans, "spout fail").get(0); + assertEquals(execute.getSpanId(), sinkFail.getParentSpanId()); + assertEquals(emit.getSpanId(), spoutFail.getParentSpanId()); + assertEquals(StatusCode.ERROR, sinkFail.getStatus().getStatusCode()); + assertEquals(StatusCode.ERROR, spoutFail.getStatus().getStatusCode()); + } + + @Test + public void testBoltFailIsRecordedWithoutAckers() throws Exception { + Config conf = conf(true); + conf.put(Config.TOPOLOGY_ACKER_EXECUTORS, 0); + // spout emit, sink execute, sink fail; without ackers the spout records no outcome + List spans = runWithSink(SinkOutcome.FAIL, conf, 3); + + SpanData sinkFail = named(spans, "sink fail").get(0); + assertEquals(StatusCode.ERROR, sinkFail.getStatus().getStatusCode()); + assertTrue(named(spans, "spout ack").isEmpty()); + } + + @Test + public void testTimeoutRecordsAnErrorSpanAtTheSpout() throws Exception { + Config conf = conf(true); + conf.put(Config.TOPOLOGY_MESSAGE_TIMEOUT_SECS, 2); + // spout emit, sink execute, spout timeout + List spans = runWithSink(SinkOutcome.HOLD, conf, 3); + + SpanData emit = named(spans, "spout emit").get(0); + SpanData timeout = named(spans, "spout timeout").get(0); + assertEquals(emit.getSpanId(), timeout.getParentSpanId()); + assertEquals(StatusCode.ERROR, timeout.getStatus().getStatusCode()); + assertTrue(named(spans, "spout fail").isEmpty()); + } + + @Test + public void testAnchoredEmitContinuesTheTrace() throws Exception { + // per tuple: spout emit, middle execute, sink execute, spout ack + List spans = runThroughMiddle(EmitMode.ANCHORED, 2, 8, 2); + + assertSinkExecutesAreChildrenOfMiddleExecutes(spans, 2); + } + + @Test + public void testAnchorsCarryingTheSameSpanAddNoMergeSpan() throws Exception { + // per tuple: spout emit, middle execute, sink execute, spout ack; the emit anchors the input twice + List spans = runThroughMiddle(EmitMode.ANCHORED_TWICE, 2, 8, 2); + + assertTrue(named(spans, "middle emit").isEmpty()); + assertSinkExecutesAreChildrenOfMiddleExecutes(spans, 2); + } + + @Test + public void testEmitAnchoredToTwoTracedTuplesStartsARootWithTwoLinks() throws Exception { + // 2 spout emits, 2 middle executes, 1 merge span, 1 sink execute, 2 spout acks + List spans = runThroughMiddle(EmitMode.JOIN, 2, 8, 1); + + List merges = named(spans, "middle emit"); + assertEquals(1, merges.size()); + SpanData merge = merges.get(0); + assertFalse(merge.getParentSpanContext().isValid(), "a merge starts a new trace"); + Set linked = merge.getLinks().stream() + .map(link -> link.getSpanContext().getSpanId()).collect(Collectors.toSet()); + assertEquals(byId(named(spans, "middle execute")).keySet(), linked); + List sinks = named(spans, "sink execute"); + assertEquals(1, sinks.size()); + assertEquals(merge.getSpanId(), sinks.get(0).getParentSpanId()); + } + + @Test + public void testUnanchoredEmitCarriesNoContext() throws Exception { + // per tuple: spout emit, middle execute, spout ack; the sink gets untraced tuples + List spans = runThroughMiddle(EmitMode.UNANCHORED, 2, 6, 2); + + assertEquals(2, named(spans, "middle execute").size()); + assertTrue(named(spans, "sink execute").isEmpty()); + assertTrue(RECEIVED_TRACE_IDS.isEmpty(), "the sink's tuples carry no context"); + } + + @Test + public void testDelayedEmitsFromAnotherThreadKeepTheirOwnParents() throws Exception { + // per tuple: spout emit, middle execute, sink execute, spout ack + List spans = runThroughMiddle(EmitMode.ASYNC_REVERSED, 2, 8, 2); + + assertNull(EMITTER_THREAD_FAILURE.get()); + Map byId = byId(spans); + for (Object value : MIDDLE_SPAN_BY_VALUE.keySet()) { + SpanData sink = byId.get(SINK_SPAN_BY_VALUE.get(value)); + assertEquals(MIDDLE_SPAN_BY_VALUE.get(value), sink.getParentSpanId(), + "the sink span of " + value + " is a child of the middle span of " + value); + } + } + + @Test + public void testUnsampledContextsPropagateAndNothingIsExported() throws Exception { + // parent-based: a sampled flag flipped on the way would export the middle or sink span + InMemorySpanExporter exporter = InMemorySpanExporter.create(); + SdkTracerProvider tracerProvider = SdkTracerProvider.builder() + .setSampler(Sampler.parentBased(Sampler.alwaysOff())) + .addSpanProcessor(SimpleSpanProcessor.create(exporter)) + .build(); + try (OpenTelemetrySdk sdk = + OpenTelemetrySdk.builder().setTracerProvider(tracerProvider).build()) { + GlobalOpenTelemetry.resetForTest(); + GlobalOpenTelemetry.set(sdk); + // spans go to this SDK, not OTEL: wait for the sink only + runThroughMiddle(EmitMode.ANCHORED, 2, 0, 2); + } finally { + GlobalOpenTelemetry.resetForTest(); + GlobalOpenTelemetry.set(OTEL.getOpenTelemetry()); + } + + assertTrue(exporter.getFinishedSpanItems().isEmpty()); + assertEquals(2, UNSAMPLED_CONTEXTS_RECEIVED.get(), "the sink got unsampled contexts"); + assertEquals(MIDDLE_TRACE_IDS, RECEIVED_TRACE_IDS, "the traces continue to the sink"); + // different workers: the contexts went through the serializer + assertNotEquals(WORKER_PORT_BY_COMPONENT.get("middle"), + WORKER_PORT_BY_COMPONENT.get("sink")); + } + + private static void assertSinkExecutesAreChildrenOfMiddleExecutes(List spans, + int count) { + Map middles = byId(named(spans, "middle execute")); + List sinks = named(spans, "sink execute"); + assertEquals(count, middles.size()); + assertEquals(count, sinks.size()); + for (SpanData sink : sinks) { + SpanData middle = middles.get(sink.getParentSpanId()); + assertNotNull(middle, "the emit carries the middle execute span as parent"); + assertEquals(middle.getTraceId(), sink.getTraceId()); + } + } + + /** + * Spout to sink (all grouping). With {@code tickSecs} positive, also waits for two ticks. + */ + private List runSpoutToSink(boolean tracing, int count, int sinkTasks, int tickSecs) + throws Exception { + Config conf = conf(tracing); + if (tickSecs > 0) { + conf.put(Config.TOPOLOGY_TICK_TUPLE_FREQ_SECS, tickSecs); + } + // per tuple: one emit span, one execute span per sink task and one spout ack span + int expectedSpans = tracing ? count * (2 + sinkTasks) : 0; + return runTopology(conf, count, + builder -> builder.setBolt("sink", new SinkBolt(), sinkTasks).allGrouping("spout"), + () -> OTEL.getSpans().size() >= expectedSpans + && (tickSecs == 0 || TICK_TUPLES_RECEIVED.get() >= 2)); + } + + /** + * Spout to middle (one task, which JOIN and ASYNC_REVERSED need) to sink. + */ + private List runThroughMiddle(EmitMode mode, int count, int expectedSpans, + int sinkTuples) throws Exception { + return runTopology(conf(true), count, + builder -> { + builder.setBolt("middle", new MiddleBolt(mode)).shuffleGrouping("spout"); + builder.setBolt("sink", new SinkBolt()).shuffleGrouping("middle"); + }, + () -> OTEL.getSpans().size() >= expectedSpans + && SINK_TUPLES_RECEIVED.get() >= sinkTuples); + } + + /** One tuple from spout "spout" to a sink that acks, fails or holds it. */ + private List runWithSink(SinkOutcome outcome, Config conf, int expectedSpans) + throws Exception { + return runTopology(conf, 1, + builder -> builder.setBolt("sink", new SinkBolt(outcome)).shuffleGrouping("spout"), + () -> OTEL.getSpans().size() >= expectedSpans); + } + + private static Config conf(boolean tracing) { + Config conf = new Config(); + conf.setNumWorkers(2); + if (tracing) { + conf.put(Config.TOPOLOGY_TRACING_TRACER, OpenTelemetryTupleTracer.class.getName()); + } + return conf; + } + + /** + * Feeds {@code count} tuples to spout "spout", waits until each is acked or failed and + * {@code done} holds, and returns the exported spans. + */ + private List runTopology(Config conf, int count, Consumer bolts, + BooleanSupplier done) throws Exception { + FeederSpout spout = new FeederSpout(new Fields("value")); + AckFailMapTracker tracker = new AckFailMapTracker(); + spout.setAckFailDelegate(tracker); + TopologyBuilder builder = new TopologyBuilder(); + builder.setSpout("spout", spout); + bolts.accept(builder); + + OTEL.clearSpans(); + RECEIVED_TRACE_IDS.clear(); + CURRENT_IN_EXECUTE.clear(); + SINK_TUPLES_RECEIVED.set(0); + UNSAMPLED_CONTEXTS_RECEIVED.set(0); + MIDDLE_TRACE_IDS.clear(); + MIDDLE_SPAN_BY_VALUE.clear(); + SINK_SPAN_BY_VALUE.clear(); + WORKER_PORT_BY_COMPONENT.clear(); + EMITTER_THREAD_FAILURE.set(null); + TICK_TUPLES_RECEIVED.set(0); + SPAN_CURRENT_DURING_TICK.set(false); + topologyName = "tracing-" + topologyCount++; + StormTopology topology = builder.createTopology(); + try (ILocalTopology ignored = cluster.submitTopology(topologyName, conf, topology)) { + Object[] ids = new Object[count]; + for (int i = 0; i < count; i++) { + ids[i] = i; + spout.feed(new Values("v" + i), i); + } + Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) + .until(() -> Arrays.stream(ids).allMatch(id -> tracker.isAcked(id) || tracker.isFailed(id))); + // execute spans end after the bolt acked: wait for every expected span + Awaitility.await().atMost(Testing.TEST_TIMEOUT_MS, TimeUnit.MILLISECONDS) + .until(done::getAsBoolean); + return OTEL.getSpans(); + } + } + + private static List named(List spans, String name) { + return spans.stream().filter(s -> s.getName().equals(name)).collect(Collectors.toList()); + } + + private static Map byId(List spans) { + return spans.stream().collect(Collectors.toMap(SpanData::getSpanId, Function.identity())); + } + + private enum EmitMode { + ANCHORED, + /** Anchored to the input twice: both anchors carry the same span. */ + ANCHORED_TWICE, + UNANCHORED, + /** Holds the first input, then emits anchored to both. */ + JOIN, + /** + * Holds the first input; on the second, another thread emits the second then the first, + * each anchored to itself, with the first one's span current. The reverse order rules out + * pairing emits with executes by arrival order. + */ + ASYNC_REVERSED + } + + private static class MiddleBolt extends BaseRichBolt { + private final EmitMode mode; + private transient OutputCollector collector; + private transient Tuple held; + + MiddleBolt(EmitMode mode) { + this.mode = mode; + } + + @Override + public void prepare(Map conf, TopologyContext context, + OutputCollector collector) { + this.collector = collector; + WORKER_PORT_BY_COMPONENT.put("middle", context.getThisWorkerPort()); + } + + @Override + public void execute(Tuple input) { + SpanContext current = Span.current().getSpanContext(); + MIDDLE_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); + MIDDLE_TRACE_IDS.add(current.getTraceId()); + if ((mode == EmitMode.JOIN || mode == EmitMode.ASYNC_REVERSED) && held == null) { + held = input; + return; + } + Values values = new Values(input.getValue(0)); + switch (mode) { + case ANCHORED: + collector.emit(input, values); + break; + case ANCHORED_TWICE: + collector.emit(Arrays.asList(input, input), values); + break; + case UNANCHORED: + collector.emit(values); + break; + case JOIN: + collector.emit(Arrays.asList(held, input), values); + collector.ack(held); + held = null; + break; + case ASYNC_REVERSED: + Tuple first = held; + held = null; + new Thread(() -> emitReversed(first, input)).start(); + return; + default: + throw new IllegalStateException("unknown mode " + mode); + } + collector.ack(input); + } + + private void emitReversed(Tuple first, Tuple second) { + try { + Context firstContext = StormTracing.context(first); + try (Scope ignored = firstContext.makeCurrent()) { + collector.emit(second, new Values(second.getValue(0))); + collector.emit(first, new Values(first.getValue(0))); + } + collector.ack(second); + collector.ack(first); + } catch (Throwable t) { + EMITTER_THREAD_FAILURE.set(t); + } + } + + @Override + public void declareOutputFields(OutputFieldsDeclarer declarer) { + declarer.declare(new Fields("value")); + } + } + + private enum SinkOutcome { + ACK, + FAIL, + /** Neither acks nor fails, so the tree times out. */ + HOLD + } + + private static class SinkBolt extends BaseRichBolt { + private final SinkOutcome outcome; + private OutputCollector collector; + + SinkBolt() { + this(SinkOutcome.ACK); + } + + SinkBolt(SinkOutcome outcome) { + this.outcome = outcome; + } + + @Override + public void prepare(Map conf, TopologyContext context, + OutputCollector collector) { + this.collector = collector; + WORKER_PORT_BY_COMPONENT.put("sink", context.getThisWorkerPort()); + sinkTaskId = context.getThisTaskId(); + } + + @Override + public void execute(Tuple input) { + if (TupleUtils.isTick(input)) { + if (Span.current().getSpanContext().isValid()) { + SPAN_CURRENT_DURING_TICK.set(true); + } + TICK_TUPLES_RECEIVED.incrementAndGet(); + return; + } + SpanContext received = Span.fromContext(StormTracing.context(input)).getSpanContext(); + if (received.isValid()) { + RECEIVED_TRACE_IDS.add(received.getTraceId()); + if (!received.isSampled()) { + UNSAMPLED_CONTEXTS_RECEIVED.incrementAndGet(); + } + } + SpanContext current = Span.current().getSpanContext(); + if (current.isValid()) { + CURRENT_IN_EXECUTE.add(current.getSpanId()); + SINK_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); + } + SINK_TUPLES_RECEIVED.incrementAndGet(); + if (outcome == SinkOutcome.ACK) { + collector.ack(input); + } else if (outcome == SinkOutcome.FAIL) { + collector.fail(input); + } + } + + @Override + public void declareOutputFields(OutputFieldsDeclarer declarer) { + } + } +} diff --git a/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TraceContextCodecTest.java b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TraceContextCodecTest.java new file mode 100644 index 00000000000..189a2ce92a0 --- /dev/null +++ b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TraceContextCodecTest.java @@ -0,0 +1,114 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. The ASF licenses this file to you under the Apache License, Version + * 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License for the specific language governing permissions + * and limitations under the License. + */ + +package org.apache.storm.opentelemetry; + +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.api.trace.SpanContext; +import io.opentelemetry.api.trace.TraceFlags; +import io.opentelemetry.api.trace.TraceState; +import io.opentelemetry.context.Context; +import java.nio.charset.StandardCharsets; +import java.util.Arrays; +import java.util.List; +import org.junit.jupiter.api.Test; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertTrue; + +public class TraceContextCodecTest { + + private static final String TRACE_ID = "0af7651916cd43dd8448eb211c80319c"; + private static final String SPAN_ID = "b7ad6b7169203331"; + + @Test + public void testRoundTrip() { + TraceState twoEntries = TraceState.builder().put("vendor", "v1").put("ot", "th:8;rv:0123456789abcd").build(); + // 0x03 = sampled plus the W3C random-trace-id bit; 0x00 = not sampled, which must propagate too + List sent = List.of( + spanContext((byte) 0x03, TraceState.getDefault()), + spanContext((byte) 0x03, twoEntries), + spanContext((byte) 0x00, TraceState.getDefault())); + + for (SpanContext span : sent) { + SpanContext received = Span.fromContext(TraceContextCodec.decode(TraceContextCodec.encode(context(span)))) + .getSpanContext(); + assertEquals(span.getTraceId(), received.getTraceId()); + assertEquals(span.getSpanId(), received.getSpanId()); + assertEquals(span.getTraceFlags(), received.getTraceFlags()); + assertEquals(span.getTraceState(), received.getTraceState()); + assertTrue(received.isRemote()); + } + } + + @Test + public void testContextWithoutValidSpanIsNotEncoded() { + assertNull(TraceContextCodec.encode(Context.root())); + } + + @Test + public void testTraceStateOverTheLimitIsNotSent() { + // a value holds at most 256 characters, so three entries are needed to pass 512 + TraceState large = TraceState.builder().put("a", "x".repeat(200)).put("b", "x".repeat(200)).put("c", "x".repeat(200)).build(); + assertEquals(3, large.size()); + + SpanContext received = Span.fromContext( + TraceContextCodec.decode(TraceContextCodec.encode(context(spanContext((byte) 0x01, large))))).getSpanContext(); + assertEquals(TRACE_ID, received.getTraceId()); + assertTrue(received.getTraceState().isEmpty()); + } + + @Test + public void testTraceStateOverTheLimitReadsAsAbsent() { + byte[] ids = TraceContextCodec.encode(context(spanContext((byte) 0x01, TraceState.getDefault()))); + String entry = "x".repeat(200); + byte[] state = ("a=" + entry + ",b=" + entry + ",c=" + entry).getBytes(StandardCharsets.US_ASCII); + byte[] bytes = Arrays.copyOf(ids, ids.length + state.length); + System.arraycopy(state, 0, bytes, ids.length, state.length); + + assertNull(TraceContextCodec.decode(bytes)); + } + + @Test + public void testShortPayloadReadsAsAbsent() { + byte[] bytes = TraceContextCodec.encode(context(spanContext((byte) 0x01, TraceState.getDefault()))); + + for (int length = 0; length < bytes.length; length++) { + assertNull(TraceContextCodec.decode(Arrays.copyOf(bytes, length)), "length " + length); + } + } + + @Test + public void testUnknownVersionReadsAsAbsent() { + byte[] bytes = TraceContextCodec.encode(context(spanContext((byte) 0x01, TraceState.getDefault()))); + bytes[0] = 2; + + assertNull(TraceContextCodec.decode(bytes)); + } + + @Test + public void testInvalidIdsReadAsAbsent() { + byte[] bytes = TraceContextCodec.encode(context(spanContext((byte) 0x01, TraceState.getDefault()))); + Arrays.fill(bytes, 1, 17, (byte) 0); // all-zero trace id + + assertNull(TraceContextCodec.decode(bytes)); + } + + private static SpanContext spanContext(byte flags, TraceState traceState) { + return SpanContext.create(TRACE_ID, SPAN_ID, TraceFlags.fromByte(flags), traceState); + } + + private static Context context(SpanContext span) { + return Context.root().with(Span.wrap(span)); + } +} From aa652cd21efcdee6364807a305375155732a4c81 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Mon, 5 Oct 2026 16:47:19 +0200 Subject: [PATCH 11/12] fix: preserve trace ancestry and record outcome duration 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. --- .../OpenTelemetryTupleTracer.java | 81 +++++++---- .../opentelemetry/TopologyTracingTest.java | 136 +++++++++++++++++- .../storm/executor/spout/SpoutExecutor.java | 12 +- .../org/apache/storm/tracing/TupleTracer.java | 7 +- 4 files changed, 190 insertions(+), 46 deletions(-) diff --git a/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java index db5eeb63834..5f308ff50ec 100644 --- a/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java +++ b/external/storm-opentelemetry/src/main/java/org/apache/storm/opentelemetry/OpenTelemetryTupleTracer.java @@ -24,8 +24,7 @@ import io.opentelemetry.context.Context; import io.opentelemetry.context.Scope; import java.net.UnknownHostException; -import java.util.Collection; -import java.util.Collections; +import java.time.Instant; import java.util.LinkedHashSet; import java.util.List; import java.util.Map; @@ -48,9 +47,13 @@ * *

Each spout emit starts a trace with a root span named "component emit", started and ended at once. Each bolt * {@code execute()} of a traced tuple runs in a child span named "component execute", current while {@code execute()} runs. A bolt - * emit carries the context of its anchors: the anchor's context if they share one span, otherwise a new root span linked to each. - * The spout records the ack, fail or timeout of each traced tuple tree, and a bolt each {@code fail()}, as spans started and ended - * at once. Contexts with the sampled flag unset are propagated too. + * emit carries the context of its anchors: the anchor's context if they share one span. Otherwise it carries the context of a span + * named "component emit", started and ended at once: a child of the first anchor's span linked to the others if all anchors belong + * to one trace, else a new root span linked to each. + * + *

The spout records the ack, fail or timeout of each traced tuple tree as a span whose duration, also set as the + * {@code storm.tuple.latency_ms} attribute, is the time from the emit to the outcome. A bolt records each {@code fail()} as a span + * started and ended at once. Contexts with the sampled flag unset are propagated too. */ public class OpenTelemetryTupleTracer implements TupleTracer { @@ -67,6 +70,7 @@ public class OpenTelemetryTupleTracer implements TupleTracer { private static final AttributeKey SOURCE_STREAM_ID_KEY = AttributeKey.stringKey("storm.source.stream.id"); private static final AttributeKey WORKER_HOST_KEY = AttributeKey.stringKey("storm.worker.host"); private static final AttributeKey WORKER_PORT_KEY = AttributeKey.longKey("storm.worker.port"); + private static final AttributeKey TUPLE_LATENCY_KEY = AttributeKey.longKey("storm.tuple.latency_ms"); private WorkerTopologyContext context; private Attributes workerAttributes; @@ -102,7 +106,7 @@ public void prepare(Map topoConf, WorkerTopologyContext context) @Override public Object spoutEmit(int taskId, String streamId) { Tracer current = tracer(); - return current == null ? null : newRootContext(current, spans(taskId).emitName(), Collections.emptyList()); + return current == null ? null : emitContext(current.spanBuilder(spans(taskId).emitName()).setNoParent()); } @Override @@ -115,16 +119,28 @@ public Object boltEmit(int taskId, String streamId, List anchorContexts) if (anchorContexts.size() == 1) { return first; } - Set linkedSpans = new LinkedHashSet<>(); + SpanContext firstSpan = Span.fromContext(first).getSpanContext(); + Set otherSpans = new LinkedHashSet<>(); for (Object anchorContext : anchorContexts) { - linkedSpans.add(Span.fromContext((Context) anchorContext).getSpanContext()); + otherSpans.add(Span.fromContext((Context) anchorContext).getSpanContext()); } - if (linkedSpans.size() == 1) { + otherSpans.remove(firstSpan); + if (otherSpans.isEmpty()) { return first; } - // the SDK keeps up to 128 links by default Tracer current = tracer(); - return current == null ? null : newRootContext(current, spans(taskId).emitName(), linkedSpans); + if (current == null) { + return null; + } + // the SDK keeps up to 128 links by default + SpanBuilder builder = current.spanBuilder(spans(taskId).emitName()); + if (otherSpans.stream().allMatch(span -> span.getTraceId().equals(firstSpan.getTraceId()))) { + builder.setParent(first); + } else { + builder.setNoParent().addLink(firstSpan); + } + otherSpans.forEach(builder::addLink); + return emitContext(builder); } @Override @@ -148,18 +164,37 @@ public ExecuteScope startExecute(int taskId, Tuple tuple, Object context) { @Override public void spoutOutcome(int taskId, Object context, Outcome outcome, long latencyMs) { + Tracer current = tracer(); + if (current == null) { + return; + } TaskSpans spans = spans(taskId); String spanName = switch (outcome) { case ACK -> spans.ackName(); case FAIL -> spans.failName(); case TIMEOUT -> spans.timeoutName(); }; - recordOutcome((Context) context, spanName, outcome != Outcome.ACK); + Instant end = Instant.now(); + Span span = current.spanBuilder(spanName) + .setParent((Context) context) + .setStartTimestamp(end.minusMillis(latencyMs)) + .setAttribute(TUPLE_LATENCY_KEY, latencyMs) + .startSpan(); + if (outcome != Outcome.ACK) { + span.setStatus(StatusCode.ERROR); + } + span.end(end); } @Override public void boltFail(int taskId, Object context) { - recordOutcome((Context) context, spans(taskId).failName(), true); + Tracer current = tracer(); + if (current == null) { + return; + } + current.spanBuilder(spans(taskId).failName()).setParent((Context) context).startSpan() + .setStatus(StatusCode.ERROR) + .end(); } @Override @@ -199,30 +234,16 @@ private Tracer tracer() { } /** - * Starts and immediately ends a root span linked to {@code links}, and returns its context, or null when the span is not - * valid. The context keeps the span ids only: pending tuples hold it until their tree completes. + * Starts and immediately ends the emit span, and returns its context, or null when the span is not valid. The context keeps the + * span ids only: pending tuples hold it until their tree completes. */ - private static Context newRootContext(Tracer tracer, String spanName, Collection links) { - SpanBuilder builder = tracer.spanBuilder(spanName).setNoParent(); - links.forEach(builder::addLink); + private static Context emitContext(SpanBuilder builder) { Span span = builder.startSpan(); span.end(); SpanContext ids = span.getSpanContext(); return ids.isValid() ? Context.root().with(Span.wrap(ids)) : null; } - private void recordOutcome(Context parent, String spanName, boolean error) { - Tracer current = tracer(); - if (current == null) { - return; - } - Span span = current.spanBuilder(spanName).setParent(parent).startSpan(); - if (error) { - span.setStatus(StatusCode.ERROR); - } - span.end(); - } - private void logUntracedEmitUnderSpan(int taskId, String streamId) { if (!LOG.isDebugEnabled() || !Span.current().getSpanContext().isValid()) { return; diff --git a/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java index 1cdbdb7d984..3f3555e0f6a 100644 --- a/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java +++ b/external/storm-opentelemetry/src/test/java/org/apache/storm/opentelemetry/TopologyTracingTest.java @@ -27,7 +27,9 @@ import io.opentelemetry.sdk.trace.data.SpanData; import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor; import io.opentelemetry.sdk.trace.samplers.Sampler; +import java.time.Instant; import java.util.Arrays; +import java.util.Comparator; import java.util.List; import java.util.Map; import java.util.Set; @@ -35,6 +37,7 @@ import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicInteger; +import java.util.concurrent.atomic.AtomicLong; import java.util.concurrent.atomic.AtomicReference; import java.util.function.BooleanSupplier; import java.util.function.Consumer; @@ -48,6 +51,7 @@ import org.apache.storm.generated.StormTopology; import org.apache.storm.task.OutputCollector; import org.apache.storm.task.TopologyContext; +import org.apache.storm.testing.AckFailDelegate; import org.apache.storm.testing.AckFailMapTracker; import org.apache.storm.testing.FeederSpout; import org.apache.storm.topology.OutputFieldsDeclarer; @@ -94,6 +98,15 @@ public class TopologyTracingTest { new AtomicReference<>(); private static final AtomicInteger TICK_TUPLES_RECEIVED = new AtomicInteger(); private static final AtomicBoolean SPAN_CURRENT_DURING_TICK = new AtomicBoolean(); + /** How long the sink of {@link #runWithSink} waits before it acks or fails. */ + private static final long SINK_DELAY_MS = 100; + /** + * Longer than {@link #SINK_DELAY_MS}, so an outcome span recorded after the spout's callback + * fails {@link #assertRunsFromEmitToOutcome}. + */ + private static final long SPOUT_CALLBACK_DELAY_MS = 500; + /** Epoch nanos at which the spout's last ack() or fail() started. */ + private static final AtomicLong SPOUT_CALLBACK_START_NANOS = new AtomicLong(); private static ILocalCluster cluster; private static int topologyCount; @@ -186,6 +199,7 @@ public void testAckRecordsAnOutcomeSpanUnderTheRoot() throws Exception { SpanData ack = named(spans, "spout ack").get(0); assertEquals(emit.getSpanId(), ack.getParentSpanId()); assertEquals(StatusCode.UNSET, ack.getStatus().getStatusCode()); + assertRunsFromEmitToOutcome(ack, emit); } @Test @@ -202,6 +216,7 @@ public void testFailRecordsErrorSpansInTheBoltAndAtTheSpout() throws Exception { assertEquals(emit.getSpanId(), spoutFail.getParentSpanId()); assertEquals(StatusCode.ERROR, sinkFail.getStatus().getStatusCode()); assertEquals(StatusCode.ERROR, spoutFail.getStatus().getStatusCode()); + assertRunsFromEmitToOutcome(spoutFail, emit); } @Test @@ -228,6 +243,7 @@ public void testTimeoutRecordsAnErrorSpanAtTheSpout() throws Exception { assertEquals(emit.getSpanId(), timeout.getParentSpanId()); assertEquals(StatusCode.ERROR, timeout.getStatus().getStatusCode()); assertTrue(named(spans, "spout fail").isEmpty()); + assertRunsFromEmitToOutcome(timeout, emit); } @Test @@ -264,6 +280,33 @@ public void testEmitAnchoredToTwoTracedTuplesStartsARootWithTwoLinks() throws Ex assertEquals(merge.getSpanId(), sinks.get(0).getParentSpanId()); } + @Test + public void testEmitAnchoredToTwoSpansOfOneTraceIsAChildOfOneLinkedToTheOther() throws Exception { + // spout emit, split execute, 2 middle executes, 1 middle emit, 1 sink execute, spout ack + List spans = runTopology(conf(true), 1, + builder -> { + builder.setBolt("split", new SplitBolt()).shuffleGrouping("spout"); + builder.setBolt("middle", new MiddleBolt(EmitMode.JOIN)).shuffleGrouping("split"); + builder.setBolt("sink", new SinkBolt()).shuffleGrouping("middle"); + }, + () -> OTEL.getSpans().size() >= 7 && SINK_TUPLES_RECEIVED.get() >= 1); + + List joins = named(spans, "middle emit"); + assertEquals(1, joins.size()); + SpanData join = joins.get(0); + assertEquals(named(spans, "spout emit").get(0).getTraceId(), join.getTraceId(), + "the join stays in the trace"); + // one middle task runs both executes in turn: the first started is the held anchor's + List middles = named(spans, "middle execute").stream() + .sorted(Comparator.comparingLong(SpanData::getStartEpochNanos)) + .collect(Collectors.toList()); + assertEquals(2, middles.size()); + assertEquals(middles.get(0).getSpanId(), join.getParentSpanId()); + assertEquals(1, join.getLinks().size()); + assertEquals(middles.get(1).getSpanId(), join.getLinks().get(0).getSpanContext().getSpanId()); + assertEquals(join.getSpanId(), named(spans, "sink execute").get(0).getParentSpanId()); + } + @Test public void testUnanchoredEmitCarriesNoContext() throws Exception { // per tuple: spout emit, middle execute, spout ack; the sink gets untraced tuples @@ -315,6 +358,23 @@ public void testUnsampledContextsPropagateAndNothingIsExported() throws Exceptio WORKER_PORT_BY_COMPONENT.get("sink")); } + /** + * The outcome span starts at the emit, ends before the spout's ack() or fail() runs, and lasts + * as long as its latency attribute, which covers the sink's delay. + */ + private static void assertRunsFromEmitToOutcome(SpanData outcome, SpanData emit) { + Long latencyMs = outcome.getAttributes().get(AttributeKey.longKey("storm.tuple.latency_ms")); + assertNotNull(latencyMs); + assertTrue(latencyMs >= SINK_DELAY_MS, latencyMs + " ms"); + assertEquals(TimeUnit.MILLISECONDS.toNanos(latencyMs), + outcome.getEndEpochNanos() - outcome.getStartEpochNanos()); + long startGapMs = TimeUnit.NANOSECONDS.toMillis( + Math.abs(outcome.getStartEpochNanos() - emit.getStartEpochNanos())); + assertTrue(startGapMs < SINK_DELAY_MS, "starts " + startGapMs + " ms away from the emit"); + assertTrue(outcome.getEndEpochNanos() <= SPOUT_CALLBACK_START_NANOS.get(), + "ends before the spout's callback"); + } + private static void assertSinkExecutesAreChildrenOfMiddleExecutes(List spans, int count) { Map middles = byId(named(spans, "middle execute")); @@ -359,12 +419,15 @@ private List runThroughMiddle(EmitMode mode, int count, int expectedSp && SINK_TUPLES_RECEIVED.get() >= sinkTuples); } - /** One tuple from spout "spout" to a sink that acks, fails or holds it. */ + /** + * One tuple from spout "spout" to a sink that acks or fails it after {@link #SINK_DELAY_MS}, + * or holds it. The spout's ack() and fail() take {@link #SPOUT_CALLBACK_DELAY_MS}. + */ private List runWithSink(SinkOutcome outcome, Config conf, int expectedSpans) throws Exception { return runTopology(conf, 1, - builder -> builder.setBolt("sink", new SinkBolt(outcome)).shuffleGrouping("spout"), - () -> OTEL.getSpans().size() >= expectedSpans); + builder -> builder.setBolt("sink", new SinkBolt(outcome, SINK_DELAY_MS)).shuffleGrouping("spout"), + () -> OTEL.getSpans().size() >= expectedSpans, SPOUT_CALLBACK_DELAY_MS); } private static Config conf(boolean tracing) { @@ -382,9 +445,14 @@ private static Config conf(boolean tracing) { */ private List runTopology(Config conf, int count, Consumer bolts, BooleanSupplier done) throws Exception { + return runTopology(conf, count, bolts, done, 0); + } + + private List runTopology(Config conf, int count, Consumer bolts, + BooleanSupplier done, long spoutCallbackDelayMs) throws Exception { FeederSpout spout = new FeederSpout(new Fields("value")); AckFailMapTracker tracker = new AckFailMapTracker(); - spout.setAckFailDelegate(tracker); + spout.setAckFailDelegate(new SlowAckFailDelegate(tracker, spoutCallbackDelayMs)); TopologyBuilder builder = new TopologyBuilder(); builder.setSpout("spout", spout); bolts.accept(builder); @@ -393,6 +461,7 @@ private List runTopology(Config conf, int count, Consumer conf, TopologyContext context, + OutputCollector collector) { + this.collector = collector; + } + + @Override + public void execute(Tuple input) { + collector.emit(input, new Values(input.getValue(0))); + collector.emit(input, new Values(input.getValue(0))); + collector.ack(input); + } + + @Override + public void declareOutputFields(OutputFieldsDeclarer declarer) { + declarer.declare(new Fields("value")); + } + } + + /** Records when each ack or fail starts, then passes it to the tracker after {@code delayMs}. */ + private static class SlowAckFailDelegate implements AckFailDelegate { + private final AckFailMapTracker tracker; + private final long delayMs; + + SlowAckFailDelegate(AckFailMapTracker tracker, long delayMs) { + this.tracker = tracker; + this.delayMs = delayMs; + } + + @Override + public void ack(Object id) { + recordStartAndSleep(); + tracker.ack(id); + } + + @Override + public void fail(Object id) { + recordStartAndSleep(); + tracker.fail(id); + } + + private void recordStartAndSleep() { + Instant now = Instant.now(); + SPOUT_CALLBACK_START_NANOS.set(TimeUnit.SECONDS.toNanos(now.getEpochSecond()) + now.getNano()); + Utils.sleep(delayMs); + } + } + private enum SinkOutcome { ACK, FAIL, @@ -522,14 +643,16 @@ private enum SinkOutcome { private static class SinkBolt extends BaseRichBolt { private final SinkOutcome outcome; + private final long delayMs; private OutputCollector collector; SinkBolt() { - this(SinkOutcome.ACK); + this(SinkOutcome.ACK, 0); } - SinkBolt(SinkOutcome outcome) { + SinkBolt(SinkOutcome outcome, long delayMs) { this.outcome = outcome; + this.delayMs = delayMs; } @Override @@ -562,6 +685,7 @@ public void execute(Tuple input) { SINK_SPAN_BY_VALUE.put(input.getValue(0), current.getSpanId()); } SINK_TUPLES_RECEIVED.incrementAndGet(); + Utils.sleep(delayMs); if (outcome == SinkOutcome.ACK) { collector.ack(input); } else if (outcome == SinkOutcome.FAIL) { diff --git a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java index 83ff32516d3..0cec64fe481 100644 --- a/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java +++ b/storm-client/src/jvm/org/apache/storm/executor/spout/SpoutExecutor.java @@ -361,11 +361,11 @@ public void ackSpoutMsg(SpoutExecutor executor, Task taskData, Long timeDelta, T LOG.info("SPOUT Acking message {} {}", tupleInfo.getRootId(), tupleInfo.getMessageId()); } Object traceContext = tupleInfo.getTraceContext(); - long traceLatencyMs = traceContext != null ? Time.deltaMs(tupleInfo.getTraceEmitTimeMs()) : 0; - spout.ack(tupleInfo.getMessageId()); if (traceContext != null) { - executor.getTupleTracer().spoutOutcome(taskId, traceContext, TupleTracer.Outcome.ACK, traceLatencyMs); + long latencyMs = Time.deltaMs(tupleInfo.getTraceEmitTimeMs()); + executor.getTupleTracer().spoutOutcome(taskId, traceContext, TupleTracer.Outcome.ACK, latencyMs); } + spout.ack(tupleInfo.getMessageId()); if (!taskData.getUserContext().getHooks().isEmpty()) { // avoid allocating SpoutAckInfo obj if not necessary new SpoutAckInfo(tupleInfo.getMessageId(), taskId, timeDelta).applyOn(taskData.getUserContext()); } @@ -386,12 +386,12 @@ public void failSpoutMsg(SpoutExecutor executor, Task taskData, Long timeDelta, LOG.info("SPOUT Failing {} : {} REASON: {}", tupleInfo.getRootId(), tupleInfo, reason); } Object traceContext = tupleInfo.getTraceContext(); - long traceLatencyMs = traceContext != null ? Time.deltaMs(tupleInfo.getTraceEmitTimeMs()) : 0; - spout.fail(tupleInfo.getMessageId()); if (traceContext != null) { TupleTracer.Outcome outcome = "TIMEOUT".equals(reason) ? TupleTracer.Outcome.TIMEOUT : TupleTracer.Outcome.FAIL; - executor.getTupleTracer().spoutOutcome(taskId, traceContext, outcome, traceLatencyMs); + long latencyMs = Time.deltaMs(tupleInfo.getTraceEmitTimeMs()); + executor.getTupleTracer().spoutOutcome(taskId, traceContext, outcome, latencyMs); } + spout.fail(tupleInfo.getMessageId()); new SpoutFailInfo(tupleInfo.getMessageId(), taskId, timeDelta).applyOn(taskData.getUserContext()); if (timeDelta != null) { executor.getStats().spoutFailedTuple(tupleInfo.getStream()); diff --git a/storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java b/storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java index 3b361c72e48..863737f8959 100644 --- a/storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java +++ b/storm-client/src/jvm/org/apache/storm/tracing/TupleTracer.java @@ -58,10 +58,9 @@ public interface TupleTracer { ExecuteScope startExecute(int taskId, Tuple tuple, Object context); /** - * Called on the executor thread of spout task {@code taskId} after the tuple tree of {@code context} was acked, failed or timed - * out, and the spout's {@code ack()} or {@code fail()} returned. {@code latencyMs} is the time from the emit of the tree to - * its outcome, measured before the spout's {@code ack()} or {@code fail()} runs. Not called for trees that no acker tracks, - * such as all trees of a topology without ackers. + * Called on the executor thread of spout task {@code taskId} when the tuple tree of {@code context} was acked, failed or timed + * out, before the spout's {@code ack()} or {@code fail()} runs. {@code latencyMs} is the time from the emit of the tree to + * this call. Not called for trees that no acker tracks, such as all trees of a topology without ackers. */ void spoutOutcome(int taskId, Object context, Outcome outcome, long latencyMs); From 42e1430cc56fa3866da8747e387b4d40f4f2a8c4 Mon Sep 17 00:00:00 2001 From: Davide Polato Date: Mon, 5 Oct 2026 17:23:01 +0200 Subject: [PATCH 12/12] docs: document pluggable tuple tracing 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. --- docs/Tracing.md | 114 ++++++++++++------ external/storm-opentelemetry/README.md | 24 ++++ .../src/main/assembly/common.xml | 7 ++ 3 files changed, 107 insertions(+), 38 deletions(-) create mode 100644 external/storm-opentelemetry/README.md diff --git a/docs/Tracing.md b/docs/Tracing.md index 6cc997ff633..f1a18d8392e 100644 --- a/docs/Tracing.md +++ b/docs/Tracing.md @@ -3,31 +3,54 @@ title: Tracing layout: documentation documentation: true --- -Storm can carry an [OpenTelemetry](https://opentelemetry.io/) trace context with every tuple. A trace then follows a +Storm can carry a trace context with every tuple. A trace then follows a [tuple tree](Guaranteeing-message-processing.html) across bolts and workers: the spout emit and each bolt `execute()` -it caused. For reliable spouts, the trace also shows how the tree ended. Spans that the application creates during -`execute()`, and spans of instrumented clients called there, join the same trace. +it caused. For reliable spouts, the trace also shows how the tree ended. -## Enabling tracing +The tracer is pluggable: the class named in `topology.tracing.tracer` decides what a context is, how it is encoded +for other workers and what is recorded. Storm provides one tracer, for [OpenTelemetry](https://opentelemetry.io/), in +the `storm-opentelemetry` module. With it, spans that the application creates during `execute()`, and spans of +instrumented clients called there, join the tuple's trace. The rest of this page describes that tracer. -Tracing is off by default; set `topology.tracing.enabled` to `true` to turn it on. Storm calls only the OpenTelemetry -API; the OpenTelemetry SDK registered as the global instance records the spans. The -[OpenTelemetry Java agent](https://opentelemetry.io/docs/zero-code/java/agent/) attached to the workers is one way to -register it: - -```yaml -topology.tracing.enabled: true -topology.worker.childopts: >- - -javaagent:/opt/otel/opentelemetry-javaagent.jar - -Dotel.service.name=my-topology - -Dotel.exporter.otlp.endpoint=http://collector:4318 - -Dotel.traces.sampler=parentbased_traceidratio - -Dotel.traces.sampler.arg=0.01 -``` +## Enabling tracing -The SDK exports the spans to the backend it is configured for, such as an OpenTelemetry Collector or any service that -accepts OTLP. An SDK that the application registers as the global instance works as well; Storm starts recording once -it is registered. A worker without an SDK records nothing. +Tracing is off by default. To turn it on: + +1. Put `storm-opentelemetry` and its dependencies (`opentelemetry-api`, `opentelemetry-context` and + `opentelemetry-common`) on the worker classpath: either in the `lib-worker` directory of each Storm installation, or + in the topology jar: + + ```xml + + org.apache.storm + storm-opentelemetry + ${storm.version} + + ``` + +2. Set `topology.tracing.tracer` to `org.apache.storm.opentelemetry.OpenTelemetryTupleTracer`. +3. Register an OpenTelemetry SDK as the global instance on the workers. The + [OpenTelemetry Java agent](https://opentelemetry.io/docs/zero-code/java/agent/), version 2.23.0 or later, is one + way to do it: + + ```yaml + topology.tracing.tracer: org.apache.storm.opentelemetry.OpenTelemetryTupleTracer + topology.worker.childopts: >- + -javaagent:/opt/otel/opentelemetry-javaagent.jar + -Dotel.service.name=my-topology + -Dotel.exporter.otlp.endpoint=http://collector:4318 + -Dotel.traces.sampler=parentbased_traceidratio + -Dotel.traces.sampler.arg=0.01 + ``` + +The tracer only calls the OpenTelemetry API; the SDK samples the spans and exports them to the backend it is +configured for, such as an OpenTelemetry Collector or any service that accepts OTLP. An SDK that the application +registers as the global instance works as well; the tracer starts recording once it is registered. Until then, the +tracer starts no traces and records no spans, and the worker logs one warning. + +Workers put `lib-worker` before the topology jar on one classpath, so when both carry `opentelemetry-api`, the copy in +`lib-worker` is the one loaded. The agent bridges the API from either place, but not a copy relocated to another +package: when shading the topology jar, do not relocate `io.opentelemetry`. ## What is recorded @@ -35,7 +58,7 @@ it is registered. A worker without an SDK records nothing. |------|--------|---------------| | ` emit` | none, it starts a trace | a spout emits a tuple, except checkpoint tuples of stateful bolts | | ` execute` | the context of the input tuple | `execute()` runs for a tuple that carries a context; the span is current on the executor thread during the call | -| ` emit` | none, linked to each anchor's span | a bolt emits a tuple whose anchors carry different spans | +| ` emit` | the first traced anchor's span when all traced anchors belong to one trace, linked to the others' spans; otherwise none, linked to each anchor's span | a bolt emits a tuple whose anchors carry different spans | | ` ack`, ` fail`, ` timeout` | the ` emit` span | the tuple tree is acked, fails or times out; only for emits with a message id when the topology has ackers; fail and timeout have status ERROR | | ` fail` | the execute span of the tuple | a bolt calls `fail()`; status ERROR | @@ -43,33 +66,41 @@ A recording execute span has these attributes: `storm.topology.name`, `storm.top `storm.task.id`, `storm.source.component.id`, `storm.source.stream.id`, `storm.worker.port` and, when the host name resolves, `storm.worker.host`. +The spout's ack, fail and timeout spans start at the emit and end when the spout executor handles the outcome, before +the spout's `ack()` or `fail()` runs; their `storm.tuple.latency_ms` attribute holds that duration in milliseconds. The +emit spans and the bolt fail span are started and ended at once. + ## How the context moves An emitted tuple takes its context from its [anchors](Guaranteeing-message-processing.html), on whatever thread the emit runs. When the traced anchors carry one span, the tuple carries that span as parent. When they carry different -spans, the tuple carries a new root span linked to each of them, so a tree with joins spans several linked traces. An -unanchored emit carries no context, and the work downstream of it is not traced. Tick and other system tuples carry no -context. +spans of one trace, the tuple carries a new span that is a child of the first traced anchor's span and linked to the +others, so the trace continues. When the anchors belong to different traces, the tuple carries a new root span linked +to each of them, so the spans of such a tree fall into several linked traces. An unanchored emit carries no context, +and the work downstream of it is not traced. Tick and other system tuples carry no context. Between workers, the context travels in the serialized tuple, after the values. Workers of one topology run the same -Storm version; a worker of an earlier version would read such a tuple and ignore the extra bytes. +Storm version; a worker of an earlier version would read such a tuple and ignore the extra bytes. Tuples that stateful +bolts save in their state do not keep their context. ## Sampling -The SDK's sampler decides whether the trace that a spout emit starts is sampled. Storm passes every context on, sampled -or not. With a parent-based sampler (the default), every span of a tuple tree therefore follows that decision. The root -sampler alone decides whether the new root of an emit with several anchors is sampled, because the built-in samplers -ignore links. +The SDK's sampler decides whether the trace that a spout emit starts is sampled. The tracer passes every context on, +sampled or not. With a parent-based sampler (the default), every span of a tuple tree therefore follows that decision, +including the emit span of an emit whose anchors belong to one trace. The root sampler alone decides whether the new +root of an emit with anchors from different traces is sampled, because the built-in samplers ignore links. ## Continuing a trace on other threads -`TupleUtils.traceContext(tuple)` returns the context to run work for a tuple under, or an empty context -(`Context.root()`) when the tuple carries none. Make it current where work for the tuple runs outside `execute()`: +`StormTracing.context(tuple)`, in `org.apache.storm.opentelemetry`, returns the context to run work for a tuple under, +or an empty context (`Context.root()`) when the tuple carries none. Make it current where work for the tuple runs +outside `execute()`: ```java import io.opentelemetry.context.Context; +import org.apache.storm.opentelemetry.StormTracing; -Context context = TupleUtils.traceContext(input); +Context context = StormTracing.context(input); pool.submit(context.wrap(() -> { Object page = fetch(input); // an instrumented HTTP client called here joins the input's trace collector.emit(input, new Values(page)); @@ -91,10 +122,17 @@ Emits themselves do not need this: an anchored emit takes its parent from the an logs how many it dropped. Lower the sampling ratio, or tune the processor with the `otel.bsp.*` settings. - Execute span attributes are set after the span starts, so a sampler cannot use them in its decision. - A span keeps up to 128 links by default, so an emit whose anchors carry more different spans keeps only part of them. -- On a worker without an SDK, a tuple with one traced anchor passes its context on, but an emit with several traced - anchors carries none. +- On a worker without an SDK, a tuple with one traced anchor passes its context on, but an emit whose anchors carry + different spans carries none. +- Each spout emit starts a new trace, so a spout cannot continue a trace that arrives with its messages, for example + in Kafka or JMS headers. Baggage does not travel with tuples. +- In Trident topologies, the master batch coordinator's emits on the `$batch`, `$commit` and `$success` streams are + spout emits, so each starts its own trace. - The trace shows how a tuple tree ended, not which bolt held a tuple that timed out. - An exception thrown by `execute()` is not recorded on the span. -- Workers put Storm's libraries before the topology jar on the classpath, so a topology runs against the - `opentelemetry-api` version Storm ships, not one bundled in its jar. Build the topology against that version and - declare the dependency as `provided`. + +## Writing another tracer + +`topology.tracing.tracer` accepts any implementation of `org.apache.storm.tracing.TupleTracer` with a zero-arg +constructor. Each worker creates one instance and shares it between its executors and the threads that serialize and +deserialize tuples. The interface's Javadoc says when Storm calls each method and what it expects back. diff --git a/external/storm-opentelemetry/README.md b/external/storm-opentelemetry/README.md new file mode 100644 index 00000000000..ddfb0505a5e --- /dev/null +++ b/external/storm-opentelemetry/README.md @@ -0,0 +1,24 @@ +# Storm OpenTelemetry + +This module traces Storm [tuple trees](https://storm.apache.org/releases/current/Guaranteeing-message-processing.html) +with [OpenTelemetry](https://opentelemetry.io/). Anchored tuples carry the trace context of their tree, so one trace +follows a tuple tree across bolts, threads and workers, and spans created during `execute()` join it. + +## Usage + +Add the module to the topology jar, or put it with its dependencies in the `lib-worker` directory of each Storm +installation: + +```xml + + org.apache.storm + storm-opentelemetry + ${storm.version} + +``` + +Then set `topology.tracing.tracer` to `org.apache.storm.opentelemetry.OpenTelemetryTupleTracer` and register an +OpenTelemetry SDK on the workers, for example with the OpenTelemetry Java agent. + +The [Tracing](https://storm.apache.org/releases/current/Tracing.html) page covers the setup, the spans and their +attributes, sampling, costs and limits. diff --git a/storm-dist/binary/final-package/src/main/assembly/common.xml b/storm-dist/binary/final-package/src/main/assembly/common.xml index 999a9a798b2..b813e79e443 100644 --- a/storm-dist/binary/final-package/src/main/assembly/common.xml +++ b/storm-dist/binary/final-package/src/main/assembly/common.xml @@ -190,6 +190,13 @@ README.* + + ${project.basedir}/../../../external/storm-opentelemetry + external/storm-opentelemetry + + README.* + + ${project.basedir}/../../../external/storm-opentsdb external/storm-opentsdb