Skip to content

Commit 67e18bd

Browse files
authored
chore: gather spans from both ev-node and ev-reth in spamoor test (#3099)
* wip: passing test, but hacky * chore: refactor test setup to allow for injection of docker client * chore: fix test compilation errors, removed useless comments * chore: addresing PR feedback * chore: create common trace printing code * chore: adding assertions on addtional spans * deps: tidy all * chore: address PR feedback * chore: removed unnessesdary test * chore: removed unused imports * chore: removed non-existant trace
1 parent 6a6c2a0 commit 67e18bd

5 files changed

Lines changed: 231 additions & 101 deletions

File tree

test/e2e/evm_contract_bench_test.go

Lines changed: 15 additions & 73 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,6 @@ import (
1111
"net"
1212
"net/http"
1313
"path/filepath"
14-
"sort"
1514
"sync"
1615
"testing"
1716
"time"
@@ -203,81 +202,24 @@ func (c *otlpCollector) getSpans() []*tracepb.Span {
203202
return cp
204203
}
205204

206-
// printCollectedTraceReport aggregates collected spans by operation name and
207-
// prints a timing breakdown.
208-
func printCollectedTraceReport(b testing.TB, collector *otlpCollector) {
209-
b.Helper()
210-
211-
spans := collector.getSpans()
212-
if len(spans) == 0 {
213-
b.Logf("WARNING: no spans collected from ev-node")
214-
return
215-
}
216-
217-
type stats struct {
218-
count int
219-
total time.Duration
220-
min time.Duration
221-
max time.Duration
222-
}
223-
m := make(map[string]*stats)
224-
225-
for _, span := range spans {
226-
// Duration: end - start in nanoseconds.
227-
d := time.Duration(span.GetEndTimeUnixNano()-span.GetStartTimeUnixNano()) * time.Nanosecond
228-
if d <= 0 {
229-
continue
230-
}
231-
name := span.GetName()
232-
s, ok := m[name]
233-
if !ok {
234-
s = &stats{min: d, max: d}
235-
m[name] = s
236-
}
237-
s.count++
238-
s.total += d
239-
if d < s.min {
240-
s.min = d
241-
}
242-
if d > s.max {
243-
s.max = d
244-
}
245-
}
246-
247-
// Sort by total time descending.
248-
names := make([]string, 0, len(m))
249-
for name := range m {
250-
names = append(names, name)
251-
}
252-
sort.Slice(names, func(i, j int) bool {
253-
return m[names[i]].total > m[names[j]].total
254-
})
255-
256-
// Calculate overall total for percentages.
257-
var overallTotal time.Duration
258-
for _, s := range m {
259-
overallTotal += s.total
260-
}
205+
// otlpSpanAdapter wraps an OTLP protobuf span to implement traceSpan.
206+
type otlpSpanAdapter struct {
207+
span *tracepb.Span
208+
}
261209

262-
b.Logf("\n--- ev-node Trace Breakdown (%d spans collected) ---", len(spans))
263-
b.Logf("%-40s %6s %12s %12s %12s %7s", "OPERATION", "COUNT", "AVG", "MIN", "MAX", "% TOTAL")
264-
for _, name := range names {
265-
s := m[name]
266-
avg := s.total / time.Duration(s.count)
267-
pct := float64(s.total) / float64(overallTotal) * 100
268-
b.Logf("%-40s %6d %12s %12s %12s %6.1f%%", name, s.count, avg, s.min, s.max, pct)
269-
}
210+
func (a otlpSpanAdapter) SpanName() string { return a.span.GetName() }
211+
func (a otlpSpanAdapter) SpanDuration() time.Duration {
212+
return time.Duration(a.span.GetEndTimeUnixNano()-a.span.GetStartTimeUnixNano()) * time.Nanosecond
213+
}
270214

271-
b.Logf("\n--- Time Distribution ---")
272-
for _, name := range names {
273-
s := m[name]
274-
pct := float64(s.total) / float64(overallTotal) * 100
275-
bar := ""
276-
for range int(pct / 2) {
277-
bar += "█"
278-
}
279-
b.Logf("%-40s %5.1f%% %s", name, pct, bar)
215+
func printCollectedTraceReport(b testing.TB, collector *otlpCollector) {
216+
b.Helper()
217+
raw := collector.getSpans()
218+
spans := make([]traceSpan, len(raw))
219+
for i, s := range raw {
220+
spans[i] = otlpSpanAdapter{span: s}
280221
}
222+
printTraceReport(b, "ev-node", spans)
281223
}
282224

283225
// waitForReceipt polls for a transaction receipt until it is available.

test/e2e/evm_spamoor_smoke_test.go

Lines changed: 125 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -11,9 +11,12 @@ import (
1111
"time"
1212

1313
tastoradocker "github.com/celestiaorg/tastora/framework/docker"
14+
reth "github.com/celestiaorg/tastora/framework/docker/evstack/reth"
1415
spamoor "github.com/celestiaorg/tastora/framework/docker/evstack/spamoor"
16+
jaeger "github.com/celestiaorg/tastora/framework/docker/jaeger"
1517
dto "github.com/prometheus/client_model/go"
1618
"github.com/stretchr/testify/require"
19+
"go.uber.org/zap/zaptest"
1720
)
1821

1922
// TestSpamoorSmoke spins up reth + sequencer and a Spamoor node, starts a few
@@ -22,28 +25,42 @@ func TestSpamoorSmoke(t *testing.T) {
2225
t.Parallel()
2326

2427
sut := NewSystemUnderTest(t)
25-
// Bring up reth + local DA and start sequencer with default settings.
28+
// Prepare a shared docker client and network for Jaeger and reth.
29+
ctx := t.Context()
2630
dcli, netID := tastoradocker.Setup(t)
27-
env := setupCommonEVMEnv(t, sut, dcli, netID)
31+
jcfg := jaeger.Config{Logger: zaptest.NewLogger(t), DockerClient: dcli, DockerNetworkID: netID}
32+
jg, err := jaeger.New(ctx, jcfg, t.Name(), 0)
33+
require.NoError(t, err, "failed to create jaeger node")
34+
t.Cleanup(func() { _ = jg.Remove(t.Context()) })
35+
require.NoError(t, jg.Start(ctx), "failed to start jaeger node")
36+
37+
// Bring up reth + local DA on the same docker network as Jaeger so reth can export traces.
38+
env := setupCommonEVMEnv(t, sut, dcli, netID,
39+
WithRethOpts(func(b *reth.NodeBuilder) {
40+
b.WithEnv(
41+
"OTEL_EXPORTER_OTLP_TRACES_ENDPOINT="+jg.Internal.IngestHTTPEndpoint()+"/v1/traces",
42+
"OTEL_EXPORTER_OTLP_TRACES_PROTOCOL=http",
43+
"RUST_LOG=info",
44+
"OTEL_SDK_DISABLED=false",
45+
)
46+
}),
47+
)
2848
sequencerHome := filepath.Join(t.TempDir(), "sequencer")
2949

30-
// In-process OTLP/HTTP collector to capture ev-node spans.
31-
collector := newOTLPCollector(t)
32-
t.Cleanup(func() {
33-
_ = collector.close()
34-
})
50+
// ev-node runs on the host, so use Jaeger's external OTLP/HTTP endpoint.
51+
otlpHTTP := jg.External.IngestHTTPEndpoint()
3552

36-
// Start sequencer with tracing to our collector.
53+
// Start sequencer with tracing to Jaeger collector.
3754
setupSequencerNode(t, sut, sequencerHome, env.SequencerJWT, env.GenesisHash, env.Endpoints,
3855
"--evnode.instrumentation.tracing=true",
39-
"--evnode.instrumentation.tracing_endpoint", collector.endpoint(),
56+
"--evnode.instrumentation.tracing_endpoint", otlpHTTP,
4057
"--evnode.instrumentation.tracing_sample_rate", "1.0",
4158
"--evnode.instrumentation.tracing_service_name", "ev-node-smoke",
4259
)
4360
t.Log("Sequencer node is up")
4461

4562
// Start Spamoor within the same Docker network, targeting reth internal RPC.
46-
ni, err := env.RethNode.GetNetworkInfo(context.Background())
63+
ni, err := env.RethNode.GetNetworkInfo(ctx)
4764
require.NoError(t, err, "failed to get network info")
4865

4966
internalRPC := "http://" + ni.Internal.RPCAddress()
@@ -55,7 +72,6 @@ func TestSpamoorSmoke(t *testing.T) {
5572
WithRPCHosts(internalRPC).
5673
WithPrivateKey(TestPrivateKey)
5774

58-
ctx := t.Context()
5975
spNode, err := spBuilder.Build(ctx)
6076
require.NoError(t, err, "failed to build sp node")
6177

@@ -113,7 +129,8 @@ func TestSpamoorSmoke(t *testing.T) {
113129
t.Cleanup(func() { _ = api.DeleteSpammer(idToDelete) })
114130
}
115131

116-
// Allow additional time to accumulate activity.
132+
// allow spamoor enough time to generate transaction throughput
133+
// so that the expected tracing spans appear in Jaeger.
117134
time.Sleep(60 * time.Second)
118135

119136
// Fetch parsed metrics and print a concise summary.
@@ -122,8 +139,61 @@ func TestSpamoorSmoke(t *testing.T) {
122139
sent := sumCounter(metrics["spamoor_transactions_sent_total"])
123140
fail := sumCounter(metrics["spamoor_transactions_failed_total"])
124141

125-
time.Sleep(2 * time.Second)
126-
printCollectedTraceReport(t, collector)
142+
// Verify Jaeger received traces from ev-node.
143+
// Service name is set above via --evnode.instrumentation.tracing_service_name "ev-node-smoke".
144+
traceCtx, cancel := context.WithTimeout(ctx, 3*time.Minute)
145+
defer cancel()
146+
ok, err := jg.External.WaitForTraces(traceCtx, "ev-node-smoke", 1, 2*time.Second)
147+
require.NoError(t, err, "error while waiting for Jaeger traces; UI: %s", jg.External.QueryURL())
148+
require.True(t, ok, "expected at least one trace in Jaeger; UI: %s", jg.External.QueryURL())
149+
150+
// Also wait for traces from ev-reth and print a small sample.
151+
ok, err = jg.External.WaitForTraces(traceCtx, "ev-reth", 1, 2*time.Second)
152+
require.NoError(t, err, "error while waiting for ev-reth traces; UI: %s", jg.External.QueryURL())
153+
require.True(t, ok, "expected at least one trace from ev-reth; UI: %s", jg.External.QueryURL())
154+
155+
// fetch traces and print reports for both services.
156+
// use a large limit to fetch all traces from the test run.
157+
evNodeTraces, err := jg.External.Traces(traceCtx, "ev-node-smoke", 10000)
158+
require.NoError(t, err, "failed to fetch ev-node-smoke traces from Jaeger")
159+
evNodeSpans := extractSpansFromTraces(evNodeTraces)
160+
printTraceReport(t, "ev-node-smoke", toTraceSpans(evNodeSpans))
161+
162+
evRethTraces, err := jg.External.Traces(traceCtx, "ev-reth", 10000)
163+
require.NoError(t, err, "failed to fetch ev-reth traces from Jaeger")
164+
evRethSpans := extractSpansFromTraces(evRethTraces)
165+
printTraceReport(t, "ev-reth", toTraceSpans(evRethSpans))
166+
167+
// assert expected ev-node span names are present.
168+
// these spans reliably appear during block production with transactions flowing.
169+
expectedSpans := []string{
170+
"BlockExecutor.ProduceBlock",
171+
"BlockExecutor.ApplyBlock",
172+
"BlockExecutor.CreateBlock",
173+
"BlockExecutor.RetrieveBatch",
174+
"Executor.ExecuteTxs",
175+
"Executor.SetFinal",
176+
"Engine.ForkchoiceUpdated",
177+
"Engine.NewPayload",
178+
"Engine.GetPayload",
179+
"Eth.GetBlockByNumber",
180+
"Sequencer.GetNextBatch",
181+
"DASubmitter.SubmitHeaders",
182+
"DASubmitter.SubmitData",
183+
"DA.Submit",
184+
}
185+
opNames := make(map[string]struct{}, len(evNodeSpans))
186+
for _, s := range evNodeSpans {
187+
opNames[s.operationName] = struct{}{}
188+
}
189+
for _, name := range expectedSpans {
190+
require.Contains(t, opNames, name, "expected span %q not found in ev-node-smoke traces", name)
191+
}
192+
193+
// ev-reth span names are internal to the Rust OTLP exporter and may change
194+
// across versions, so we only assert that spans were collected at all.
195+
// TODO: check for more specific spans once implemented.
196+
require.NotEmpty(t, evRethSpans, "expected at least one span from ev-reth")
127197

128198
require.Greater(t, sent, float64(0), "at least one transaction should have been sent")
129199
require.Zero(t, fail, "no transactions should have failed")
@@ -165,15 +235,47 @@ func sumCounter(f *dto.MetricFamily) float64 {
165235
}
166236
return sum
167237
}
168-
func sumGauge(f *dto.MetricFamily) float64 {
169-
if f == nil || f.GetType() != dto.MetricType_GAUGE {
170-
return 0
171-
}
172-
var sum float64
173-
for _, m := range f.GetMetric() {
174-
if m.GetGauge() != nil && m.GetGauge().Value != nil {
175-
sum += m.GetGauge().GetValue()
238+
239+
// jaegerSpan holds the fields we extract from Jaeger's untyped JSON response.
240+
type jaegerSpan struct {
241+
operationName string
242+
duration float64 // microseconds
243+
}
244+
245+
func (j jaegerSpan) SpanName() string { return j.operationName }
246+
func (j jaegerSpan) SpanDuration() time.Duration { return time.Duration(j.duration) * time.Microsecond }
247+
248+
// extractSpansFromTraces walks Jaeger's []any response and pulls out span operation names and durations.
249+
func extractSpansFromTraces(traces []any) []jaegerSpan {
250+
var out []jaegerSpan
251+
for _, t := range traces {
252+
traceMap, ok := t.(map[string]any)
253+
if !ok {
254+
continue
255+
}
256+
spans, ok := traceMap["spans"].([]any)
257+
if !ok {
258+
continue
259+
}
260+
for _, s := range spans {
261+
spanMap, ok := s.(map[string]any)
262+
if !ok {
263+
continue
264+
}
265+
name, _ := spanMap["operationName"].(string)
266+
dur, _ := spanMap["duration"].(float64)
267+
if name != "" {
268+
out = append(out, jaegerSpan{operationName: name, duration: dur})
269+
}
176270
}
177271
}
178-
return sum
272+
return out
273+
}
274+
275+
func toTraceSpans(spans []jaegerSpan) []traceSpan {
276+
out := make([]traceSpan, len(spans))
277+
for i, s := range spans {
278+
out[i] = s
279+
}
280+
return out
179281
}

0 commit comments

Comments
 (0)