feat: remove pool.acquire and prepare spans, preserve metrics

README.md

@@ -1,4 +1,4 @@
-[![Go Reference](https://pkg.go.dev/badge/github.com/exaring/otelpgx.svg)](https://pkg.go.dev/github.com/exaring/otelpgx)
+[![Go Reference](https://pkg.go.dev/badge/github.com/overmindtech/otelpgx.svg)](https://pkg.go.dev/github.com/overmindtech/otelpgx)
 
 # otelpgx
 
@@ -21,7 +21,7 @@ go get github.com/jackc/pgx/v5
 Install the library:
 
 ```go
-go get github.com/exaring/otelpgx
+go get github.com/overmindtech/otelpgx
 ```
 
 Create the tracer as part of your connection:

go.mod

@@ -1,4 +1,4 @@
-module github.com/exaring/otelpgx
+module github.com/overmindtech/otelpgx
 
 go 1.22.0
 

tracer.go

@@ -21,8 +21,8 @@ import (
 )
 
 const (
-	tracerName = "github.com/exaring/otelpgx"
-	meterName  = "github.com/exaring/otelpgx"
+	tracerName = "github.com/overmindtech/otelpgx"
+	meterName  = "github.com/overmindtech/otelpgx"
 )
 
 const (
@@ -52,6 +52,9 @@ const (
 	PGXOperationTypeKey = attribute.Key("pgx.operation.type")
 	// DBClientOperationErrorsKey represents the count of operation errors
 	DBClientOperationErrorsKey = attribute.Key("db.client.operation.errors")
+	// PrepareDurationKey records the wall-clock time of a prepared-statement
+	// round-trip, in milliseconds, as an attribute on the parent query span.
+	PrepareDurationKey = attribute.Key("pgx.prepare.duration")
 )
 
 type startTimeCtxKey struct{}
@@ -530,116 +533,41 @@ func (t *Tracer) TraceConnectEnd(ctx context.Context, data pgx.TraceConnectEndDa
 // TracePrepareStart is called at the beginning of Prepare calls. The returned
 // context is used for the rest of the call and will be passed to
 // TracePrepareEnd.
-func (t *Tracer) TracePrepareStart(ctx context.Context, conn *pgx.Conn, data pgx.TracePrepareStartData) context.Context {
-	ctx = context.WithValue(ctx, startTimeCtxKey{}, time.Now())
-
-	if !trace.SpanFromContext(ctx).IsRecording() {
-		return ctx
-	}
-
-	optsP := t.spanStartOptionsPool.Get().(*[]trace.SpanStartOption)
-	defer t.spanStartOptionsPool.Put(optsP)
-	attrsP := t.attributeSlicePool.Get().(*[]attribute.KeyValue)
-	defer t.attributeSlicePool.Put(attrsP)
-
-	// reslice to empty
-	opts := (*optsP)[:0]
-	attrs := (*attrsP)[:0]
-
-	attrs = append(attrs, t.tracerAttrs...)
-
-	if data.Name != "" {
-		attrs = append(attrs, PrepareStmtNameKey.String(data.Name))
-	}
-
-	if t.logConnectionDetails && conn != nil {
-		attrs = append(attrs, connectionAttributesFromConfig(conn.Config())...)
-	}
-
-	attrs = append(attrs, semconv.DBOperationName(t.spanNameCtxFunc(ctx, data.SQL)))
-
-	if t.logSQLStatement {
-		attrs = append(attrs, semconv.DBQueryText(data.SQL))
-	}
-
-	opts = append(opts,
-		trace.WithSpanKind(trace.SpanKindClient),
-		trace.WithAttributes(attrs...),
-	)
-
-	spanName := data.SQL
-	if t.trimQuerySpanName {
-		spanName = t.spanNameCtxFunc(ctx, data.SQL)
-	}
-	if t.prefixQuerySpanName {
-		spanName = "prepare " + spanName
-	}
-
-	ctx, _ = t.tracer.Start(ctx, spanName, opts...)
-
-	return ctx
+//
+// No span is created for prepare. Instead, the prepare duration is recorded as
+// the pgx.prepare.duration attribute (milliseconds) on the parent query span.
+func (t *Tracer) TracePrepareStart(ctx context.Context, _ *pgx.Conn, _ pgx.TracePrepareStartData) context.Context {
+	return context.WithValue(ctx, startTimeCtxKey{}, time.Now())
 }
 
 // TracePrepareEnd is called at the end of Prepare calls.
 func (t *Tracer) TracePrepareEnd(ctx context.Context, _ *pgx.Conn, data pgx.TracePrepareEndData) {
-	span := trace.SpanFromContext(ctx)
 	t.incrementOperationErrorCount(ctx, data.Err, pgxOperationPrepare)
 	t.recordOperationDuration(ctx, pgxOperationPrepare)
 
-	if !span.IsRecording() {
-		return
+	if startTime, ok := ctx.Value(startTimeCtxKey{}).(time.Time); ok {
+		span := trace.SpanFromContext(ctx)
+		if span.IsRecording() {
+			span.SetAttributes(PrepareDurationKey.Int64(time.Since(startTime).Milliseconds()))
+		}
 	}
-
-	recordSpanError(span, data.Err)
-	span.End()
 }
 
 // TraceAcquireStart is called at the beginning of Acquire.
 // The returned context is used for the rest of the call and will be passed to the TraceAcquireEnd.
-func (t *Tracer) TraceAcquireStart(ctx context.Context, pool *pgxpool.Pool, data pgxpool.TraceAcquireStartData) context.Context {
-	ctx = context.WithValue(ctx, startTimeCtxKey{}, time.Now())
-
-	if !trace.SpanFromContext(ctx).IsRecording() {
-		return ctx
-	}
-
-	optsP := t.spanStartOptionsPool.Get().(*[]trace.SpanStartOption)
-	defer t.spanStartOptionsPool.Put(optsP)
-	attrsP := t.attributeSlicePool.Get().(*[]attribute.KeyValue)
-	defer t.attributeSlicePool.Put(attrsP)
-
-	// reslice to empty
-	opts := (*optsP)[:0]
-	attrs := (*attrsP)[:0]
-
-	attrs = append(attrs, t.tracerAttrs...)
-
-	if t.logConnectionDetails && pool != nil && pool.Config() != nil && pool.Config().ConnConfig != nil {
-		attrs = append(attrs, connectionAttributesFromConfig(pool.Config().ConnConfig)...)
-	}
-
-	opts = append(opts,
-		trace.WithSpanKind(trace.SpanKindClient),
-		trace.WithAttributes(attrs...),
-	)
-
-	ctx, _ = t.tracer.Start(ctx, "pool.acquire", opts...)
-
-	return ctx
+//
+// No span is created for pool.acquire. Pool acquire duration is tracked via the
+// db.client.operation.duration metric (pgx.operation.type=acquire) and the pgxpool.*
+// metrics from RecordStats. As a span it adds noise without actionable signal; pool
+// contention is an environmental concern better diagnosed from aggregate metrics.
+func (t *Tracer) TraceAcquireStart(ctx context.Context, _ *pgxpool.Pool, _ pgxpool.TraceAcquireStartData) context.Context {
+	return context.WithValue(ctx, startTimeCtxKey{}, time.Now())
 }
 
 // TraceAcquireEnd is called when a connection has been acquired.
 func (t *Tracer) TraceAcquireEnd(ctx context.Context, _ *pgxpool.Pool, data pgxpool.TraceAcquireEndData) {
-	span := trace.SpanFromContext(ctx)
 	t.incrementOperationErrorCount(ctx, data.Err, pgxOperationAcquire)
 	t.recordOperationDuration(ctx, pgxOperationAcquire)
-
-	if !span.IsRecording() {
-		return
-	}
-
-	recordSpanError(span, data.Err)
-	span.End()
 }
 
 func makeParamsAttribute(args []any) attribute.KeyValue {

tracer_benchmark_test.go

@@ -8,7 +8,7 @@ import (
 	"os"
 	"testing"
 
-	"github.com/exaring/otelpgx"
+	"github.com/overmindtech/otelpgx"
 	"github.com/jackc/pgx/v5/pgxpool"
 	sdktrace "go.opentelemetry.io/otel/sdk/trace"
 	"go.opentelemetry.io/otel/sdk/trace/tracetest"

tracer_span_test.go

@@ -0,0 +1,96 @@
+package otelpgx
+
+import (
+	"context"
+	"testing"
+
+	"github.com/jackc/pgx/v5"
+	"github.com/jackc/pgx/v5/pgxpool"
+	sdktrace "go.opentelemetry.io/otel/sdk/trace"
+	"go.opentelemetry.io/otel/sdk/trace/tracetest"
+)
+
+func setupTestTracer(t *testing.T) (*Tracer, *tracetest.InMemoryExporter, sdktrace.TracerProvider) {
+	t.Helper()
+
+	exporter := tracetest.NewInMemoryExporter()
+	tp := *sdktrace.NewTracerProvider(
+		sdktrace.WithSyncer(exporter),
+		sdktrace.WithSampler(sdktrace.AlwaysSample()),
+	)
+
+	tracer := NewTracer(WithTracerProvider(&tp))
+	return tracer, exporter, tp
+}
+
+func TestTraceAcquire_NoSpan(t *testing.T) {
+	tracer, exporter, tp := setupTestTracer(t)
+
+	parentTracer := tp.Tracer("test")
+	ctx, parentSpan := parentTracer.Start(context.Background(), "parent")
+
+	ctx = tracer.TraceAcquireStart(ctx, nil, pgxpool.TraceAcquireStartData{})
+	tracer.TraceAcquireEnd(ctx, nil, pgxpool.TraceAcquireEndData{})
+
+	parentSpan.End()
+
+	spans := exporter.GetSpans()
+
+	for _, s := range spans {
+		if s.Name == "pool.acquire" {
+			t.Error("pool.acquire span should not be created")
+		}
+	}
+
+	if len(spans) != 1 {
+		t.Errorf("expected exactly 1 span (the parent), got %d", len(spans))
+	}
+	if spans[0].Name != "parent" {
+		t.Errorf("expected span name 'parent', got %q", spans[0].Name)
+	}
+}
+
+func TestTracePrepare_NoSpan_SetsAttribute(t *testing.T) {
+	tracer, exporter, tp := setupTestTracer(t)
+
+	parentTracer := tp.Tracer("test")
+	ctx, parentSpan := parentTracer.Start(context.Background(), "query SELECT 1")
+
+	ctx = tracer.TracePrepareStart(ctx, nil, pgx.TracePrepareStartData{
+		Name: "stmt1",
+		SQL:  "SELECT 1",
+	})
+	tracer.TracePrepareEnd(ctx, nil, pgx.TracePrepareEndData{})
+
+	parentSpan.End()
+
+	spans := exporter.GetSpans()
+
+	for _, s := range spans {
+		if s.Name == "prepare SELECT 1" || s.Name == "SELECT 1" {
+			t.Errorf("prepare span should not be created, found span %q", s.Name)
+		}
+	}
+
+	if len(spans) != 1 {
+		t.Errorf("expected exactly 1 span (the parent), got %d", len(spans))
+	}
+
+	parentAttrs := spans[0].Attributes
+	var found bool
+	for _, attr := range parentAttrs {
+		if attr.Key == PrepareDurationKey {
+			found = true
+			if attr.Value.Type().String() != "INT64" {
+				t.Errorf("expected pgx.prepare.duration to be INT64, got %s", attr.Value.Type())
+			}
+			if attr.Value.AsInt64() < 0 {
+				t.Errorf("expected pgx.prepare.duration >= 0, got %d", attr.Value.AsInt64())
+			}
+		}
+	}
+
+	if !found {
+		t.Error("expected pgx.prepare.duration attribute on parent span, but not found")
+	}
+}