From 101f8826836cd869f108e9a958bce2f1d08dde94 Mon Sep 17 00:00:00 2001 From: Joshua Temple Date: Fri, 5 Jun 2026 10:08:02 -0400 Subject: [PATCH] fix(telemetry): correct doc.go adapter status, datadog SetStatus(OK) bug, and slog span context MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - telemetry/doc.go: replace stale "deferred" description for otel and datadog with accurate "shipped" wording mirroring the README adapter table - telemetry/datadog: SetStatus(StatusOK) now clears a previously recorded error so a span that recovers finishes without the Datadog error flag; add test asserting OK-after-error produces no error.message tag - telemetry/slog: store the span's own context (which carries the span id) in the span struct; use it in SetAttributes/RecordError/End instead of context.Background(), preserving trace/deadline propagation - telemetry/slog: NewMeter no longer calls resolve() (which allocates an unused atomic counter and clock func); apply only WithLogger - telemetry/otel: simplify stringify() to v.String() — the fmt.Sprintf fallback was unreachable because slog.Value.String always produces a non-empty representation; remove dead fmt import - telemetry/otel: add errMeterImpl test helper and TestMeter_InstrumentErrorFallback covering the no-op fallback path when the SDK returns an error building an instrument; add TestConvertAttr_KindAnyStringify covering the KindAny stringify branch - telemetry/datadog: add TestTracer_WithSpanStarter and TestAttrValue_Kinds covering the WithSpanStarter option and duration/time/uint64/any tag kinds Signed-off-by: Joshua Temple --- telemetry/datadog/datadog.go | 21 +++++++--- telemetry/datadog/datadog_test.go | 69 +++++++++++++++++++++++++++++++ telemetry/doc.go | 20 +++++---- telemetry/otel/otel.go | 9 ++-- telemetry/otel/otel_test.go | 66 ++++++++++++++++++++++++++++- telemetry/slog/slog.go | 23 ++++++++--- 6 files changed, 181 insertions(+), 27 deletions(-) diff --git a/telemetry/datadog/datadog.go b/telemetry/datadog/datadog.go index bd7da20..32556e4 100644 --- a/telemetry/datadog/datadog.go +++ b/telemetry/datadog/datadog.go @@ -123,13 +123,22 @@ func (s *span) SetStatus(code telemetry.StatusCode, msg string) { if s.ended { return } - if code == telemetry.StatusError && s.err == nil { - // SetStatus(Error) without a recorded error still marks the span errored; - // synthesize an error carrying the status message. - if msg == "" { - msg = "error" + switch code { + case telemetry.StatusError: + if s.err == nil { + // SetStatus(Error) without a recorded error still marks the span errored; + // synthesize an error carrying the status message. + if msg == "" { + msg = "error" + } + s.err = statusError(msg) } - s.err = statusError(msg) + case telemetry.StatusOK: + // An explicit OK overrides any previously recorded error so the span + // finishes clean. The error event was already appended by RecordError; + // clearing s.err only prevents End from finishing the span with + // tracer.WithError, which is what determines the error flag in Datadog. + s.err = nil } } diff --git a/telemetry/datadog/datadog_test.go b/telemetry/datadog/datadog_test.go index 2aa2570..cf3cf11 100644 --- a/telemetry/datadog/datadog_test.go +++ b/telemetry/datadog/datadog_test.go @@ -8,6 +8,7 @@ import ( "github.com/DataDog/datadog-go/v5/statsd" "github.com/DataDog/dd-trace-go/v2/ddtrace/mocktracer" + "github.com/DataDog/dd-trace-go/v2/ddtrace/tracer" "github.com/stablekernel/crucible/telemetry" ddadapter "github.com/stablekernel/crucible/telemetry/datadog" @@ -126,6 +127,74 @@ func TestTracer_StatusErrorWithoutRecordedError(t *testing.T) { } } +// TestTracer_StatusOKClearsPriorError asserts that SetStatus(StatusOK) after a +// RecordError clears the recorded error so the span finishes without the +// Datadog error flag. +func TestTracer_StatusOKClearsPriorError(t *testing.T) { + mt := mocktracer.Start() + defer mt.Stop() + + tr := ddadapter.NewTracer() + _, span := tr.Start(context.Background(), "op") + span.RecordError(errors.New("transient")) + // Caller decides the operation ultimately succeeded. + span.SetStatus(telemetry.StatusOK, "recovered") + span.End() + + s := mt.FinishedSpans()[0] + if s.Tag("error.message") != nil { + t.Errorf("expected no error tag after StatusOK, got %v", s.Tag("error.message")) + } +} + +// TestTracer_WithSpanStarter asserts the injected spanStarter is called and its +// span is used instead of the default global tracer. +func TestTracer_WithSpanStarter(t *testing.T) { + mt := mocktracer.Start() + defer mt.Stop() + + called := false + starter := func(ctx context.Context, name string, opts ...tracer.StartSpanOption) (*tracer.Span, context.Context) { + called = true + return tracer.StartSpanFromContext(ctx, name, opts...) + } + tr := ddadapter.NewTracer(ddadapter.WithSpanStarter(starter)) + _, span := tr.Start(context.Background(), "op") + span.End() + + if !called { + t.Error("WithSpanStarter: custom starter was not called") + } + if len(mt.FinishedSpans()) != 1 { + t.Fatalf("got %d finished spans, want 1", len(mt.FinishedSpans())) + } +} + +// TestAttrValue_Kinds exercises attrValue for duration, time, uint64, and any +// kinds so tag conversion is covered end to end via the span path. mocktracer +// normalizes many value types (duration → string, time → string, uint64 → +// float64), so assertions check that each tag is present and non-nil. +func TestAttrValue_Kinds(t *testing.T) { + mt := mocktracer.Start() + defer mt.Stop() + + tr := ddadapter.NewTracer() + _, span := tr.Start(context.Background(), "op", + telemetry.Duration("elapsed", 1500*time.Millisecond), + telemetry.Time("at", time.Unix(0, 0).UTC()), + telemetry.Any("obj", struct{ X int }{1}), + telemetry.Uint64("u", 42), + ) + span.End() + + s := mt.FinishedSpans()[0] + for _, key := range []string{"elapsed", "at", "obj", "u"} { + if s.Tag(key) == nil { + t.Errorf("tag %q missing from span", key) + } + } +} + // TestTracer_Parentage asserts a child span started from the returned context // parents under the first span. func TestTracer_Parentage(t *testing.T) { diff --git a/telemetry/doc.go b/telemetry/doc.go index 1d1a983..5547661 100644 --- a/telemetry/doc.go +++ b/telemetry/doc.go @@ -92,14 +92,18 @@ // deps) that emits spans and metrics as structured logs. Shipped here; it // proves the seam end to end. Because Attr is slog.Attr, this adapter is // conversion-free: attributes pass straight to the slog handler. -// - telemetry/otel, telemetry/datadog — deferred. Each would live in its own -// sub-module with its own go.mod that requires the vendor SDK, implement the -// same interfaces (Span.SetStatus -> otel status / dd error flag, -// ResolveInstrument -> instrument unit/description), and be wired by a -// consumer via WithTracer/WithMeter exactly like the slog adapter. They convert -// each attribute with a switch over Attr.Value.Kind (the slog.Value kind), -// reading the typed accessor for each scalar kind and Value.Any only for the -// KindAny escape hatch. +// - telemetry/otel — shipped. Lives in its own sub-module with its own go.mod +// that requires the OpenTelemetry SDK. Bridges Tracer/Meter onto an +// OpenTelemetry trace.Tracer and metric.Meter; Span.SetStatus maps to +// codes.Ok/Error/Unset; WithUnit/WithDescription are honored via the +// OpenTelemetry instrument options. Attributes are converted with a switch +// over Attr.Value.Kind. +// - telemetry/datadog — shipped. Lives in its own sub-module with its own +// go.mod that requires dd-trace-go / datadog-go. Bridges Tracer onto +// dd-trace-go spans and Meter onto DogStatsD; Span.SetStatus(StatusError) +// marks the span errored. Attributes are converted with a switch over +// Attr.Value.Kind, reading the typed accessor for each scalar kind and +// Value.Any only for the KindAny escape hatch. // // # Naming convention // diff --git a/telemetry/otel/otel.go b/telemetry/otel/otel.go index ea0d021..60e746c 100644 --- a/telemetry/otel/otel.go +++ b/telemetry/otel/otel.go @@ -32,7 +32,6 @@ package otel import ( "context" - "fmt" "log/slog" "go.opentelemetry.io/otel/attribute" @@ -194,11 +193,11 @@ func convertAttr(a telemetry.Attr) attribute.KeyValue { } } +// stringify renders v as a string for the default/KindAny case. +// slog.Value.String resolves LogValuers and formats the value via fmt.Sprintf +// for all kinds, so it is always a complete representation. func stringify(v slog.Value) string { - if s := v.String(); s != "" { - return s - } - return fmt.Sprintf("%v", v.Any()) + return v.String() } // Compile-time assertions that the adapter types satisfy the telemetry diff --git a/telemetry/otel/otel_test.go b/telemetry/otel/otel_test.go index 80604d8..88f19e8 100644 --- a/telemetry/otel/otel_test.go +++ b/telemetry/otel/otel_test.go @@ -3,11 +3,14 @@ package otel_test import ( "context" "errors" + "fmt" "testing" "time" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/codes" + otelmetric "go.opentelemetry.io/otel/metric" + noopmeter "go.opentelemetry.io/otel/metric/noop" "go.opentelemetry.io/otel/sdk/metric" "go.opentelemetry.io/otel/sdk/metric/metricdata" sdktrace "go.opentelemetry.io/otel/sdk/trace" @@ -17,6 +20,25 @@ import ( oteladapter "github.com/stablekernel/crucible/telemetry/otel" ) +// errMeterImpl embeds the OTel noop.Meter (which satisfies metric.Meter via +// embedded.Meter) and overrides the three instrument constructors to return +// errors, exercising the adapter's no-op fallback branches. +type errMeterImpl struct { + noopmeter.Meter +} + +func (errMeterImpl) Int64Counter(string, ...otelmetric.Int64CounterOption) (otelmetric.Int64Counter, error) { + return nil, fmt.Errorf("counter error") +} + +func (errMeterImpl) Float64Histogram(string, ...otelmetric.Float64HistogramOption) (otelmetric.Float64Histogram, error) { + return nil, fmt.Errorf("histogram error") +} + +func (errMeterImpl) Float64Gauge(string, ...otelmetric.Float64GaugeOption) (otelmetric.Float64Gauge, error) { + return nil, fmt.Errorf("gauge error") +} + // newTracer returns an adapter tracer plus the SpanRecorder capturing its spans. func newTracer() (*oteladapter.Tracer, *tracetest.SpanRecorder) { rec := tracetest.NewSpanRecorder() @@ -50,7 +72,8 @@ func findAttr(set attribute.Set, key string) (attribute.Value, bool) { func TestTracer_SpanLifecycle(t *testing.T) { tr, rec := newTracer() - ctx, span := tr.Start(context.Background(), "sink.Sink", + ctx, span := tr.Start( + context.Background(), "sink.Sink", telemetry.String("payload.type", "Order"), telemetry.Int64("count", 3), telemetry.Bool("flush", true), @@ -139,7 +162,8 @@ func TestTracer_Parentage(t *testing.T) { // TestTracer_AttrKinds exercises the duration/time/uint64/any conversions. func TestTracer_AttrKinds(t *testing.T) { tr, rec := newTracer() - _, span := tr.Start(context.Background(), "op", + _, span := tr.Start( + context.Background(), "op", telemetry.Duration("elapsed", 1500*time.Millisecond), telemetry.Uint64("u", 42), telemetry.Time("at", time.Unix(0, 0).UTC()), @@ -224,3 +248,41 @@ func TestSpan_NoErrorOnNil(t *testing.T) { t.Error("RecordError(nil) should record no event") } } + +// TestMeter_InstrumentErrorFallback asserts that when the OTel SDK returns an +// error building an instrument the adapter falls back to a no-op — the method +// never panics and the returned instrument is usable. +func TestMeter_InstrumentErrorFallback(t *testing.T) { + mt := oteladapter.NewMeter(errMeterImpl{}) + + // All three constructors must succeed (no panic) and the returned instruments + // must be callable without panicking. + counter := mt.Counter("c") + histo := mt.Histogram("h") + gauge := mt.Gauge("g") + + counter.Add(context.Background(), 1, telemetry.String("k", "v")) + histo.Record(context.Background(), 1.5) + gauge.Record(context.Background(), 42.0) +} + +// TestConvertAttr_KindAnyStringify asserts that KindAny values are stringified +// via slog.Value.String rather than falling through to a dead fmt.Sprintf branch. +func TestConvertAttr_KindAnyStringify(t *testing.T) { + tr, rec := newTracer() + type custom struct{ Label string } + _, span := tr.Start( + context.Background(), "op", + telemetry.Any("obj", custom{Label: "hello"}), + ) + span.End() + + attrs := attribute.NewSet(rec.Ended()[0].Attributes()...) + v, ok := findAttr(attrs, "obj") + if !ok { + t.Fatal("obj attribute missing") + } + if v.AsString() == "" { + t.Errorf("expected non-empty stringification of Any value, got %q", v.AsString()) + } +} diff --git a/telemetry/slog/slog.go b/telemetry/slog/slog.go index 959e592..3a6bfde 100644 --- a/telemetry/slog/slog.go +++ b/telemetry/slog/slog.go @@ -112,18 +112,21 @@ func (t *Tracer) Start(ctx context.Context, name string, attrs ...telemetry.Attr logAttrs = append(logAttrs, attrArgs(attrs)...) t.cfg.logger.LogAttrs(ctx, sl.LevelDebug, "span.start", sl.Group("span", logAttrs...)) + spanCtx := context.WithValue(ctx, spanIDKey{}, id) s := &span{ cfg: t.cfg, + ctx: spanCtx, name: name, id: id, start: t.cfg.now(), } - return context.WithValue(ctx, spanIDKey{}, id), s + return spanCtx, s } // span is a telemetry.Span backed by slog. type span struct { cfg config + ctx context.Context name string id uint64 start time.Time @@ -137,14 +140,14 @@ func (s *span) SetAttributes(attrs ...telemetry.Attr) { return } args := append([]any{sl.String("name", s.name), sl.Uint64("id", s.id)}, attrArgs(attrs)...) - s.cfg.logger.LogAttrs(context.Background(), sl.LevelDebug, "span.attributes", sl.Group("span", args...)) + s.cfg.logger.LogAttrs(s.ctx, sl.LevelDebug, "span.attributes", sl.Group("span", args...)) } func (s *span) RecordError(err error) { if s.ended || err == nil { return } - s.cfg.logger.LogAttrs(context.Background(), sl.LevelError, "span.error", + s.cfg.logger.LogAttrs(s.ctx, sl.LevelError, "span.error", sl.Group("span", sl.String("name", s.name), sl.Uint64("id", s.id), @@ -175,7 +178,7 @@ func (s *span) End() { if s.statusMsg != "" { args = append(args, sl.String("status_msg", s.statusMsg)) } - s.cfg.logger.LogAttrs(context.Background(), sl.LevelDebug, "span.end", sl.Group("span", args...)) + s.cfg.logger.LogAttrs(s.ctx, sl.LevelDebug, "span.end", sl.Group("span", args...)) } // Meter is a telemetry.Meter backed by slog. @@ -183,8 +186,16 @@ type Meter struct { logger *sl.Logger } -// NewMeter returns a slog-backed Meter. -func NewMeter(opts ...Option) *Meter { return &Meter{logger: resolve(opts...).logger} } +// NewMeter returns a slog-backed Meter. Only WithLogger is meaningful for a +// Meter; clock and ID options are accepted and ignored so callers can share an +// option slice with NewTracer without error. +func NewMeter(opts ...Option) *Meter { + c := config{logger: sl.New(sl.DiscardHandler)} + for _, opt := range opts { + opt(&c) + } + return &Meter{logger: c.logger} +} // Counter returns a counter instrument that logs a "metric" record per Add. func (m *Meter) Counter(name string, opts ...telemetry.InstrumentOption) telemetry.Counter {