From 545238e94da967c818fc422363d8e53b9152e61a Mon Sep 17 00:00:00 2001 From: David Schmitt Date: Tue, 3 Mar 2026 21:04:12 +0000 Subject: [PATCH 1/2] feat: remove pool.acquire and prepare spans, preserve metrics Remove span creation for pool.acquire and prepare operations to reduce trace noise. Metrics (db.client.operation.duration, error counts) are preserved for both operations. For prepare, the wall-clock duration is recorded as a pgx.prepare.duration attribute (Int64, milliseconds) on the parent query span instead of creating a separate child span. Pool acquire duration is better tracked through aggregate metrics (pgxpool.* from RecordStats) since contention is an environmental concern, not useful as individual trace spans. Made-with: Cursor --- tracer.go | 112 ++++++++------------------------------------ tracer_span_test.go | 96 +++++++++++++++++++++++++++++++++++++ 2 files changed, 116 insertions(+), 92 deletions(-) create mode 100644 tracer_span_test.go diff --git a/tracer.go b/tracer.go index ce1a130..85c91de 100644 --- a/tracer.go +++ b/tracer.go @@ -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 { diff --git a/tracer_span_test.go b/tracer_span_test.go new file mode 100644 index 0000000..017e73a --- /dev/null +++ b/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") + } +} From 65bf1016045eeebff687b3e5172e408959ee4f64 Mon Sep 17 00:00:00 2001 From: David Schmitt Date: Tue, 3 Mar 2026 21:04:27 +0000 Subject: [PATCH 2/2] chore: rename module to github.com/overmindtech/otelpgx Update module path, instrumentation scope names, benchmark import, and README references from exaring/otelpgx to overmindtech/otelpgx. Made-with: Cursor --- README.md | 4 ++-- go.mod | 2 +- tracer.go | 4 ++-- tracer_benchmark_test.go | 2 +- 4 files changed, 6 insertions(+), 6 deletions(-) diff --git a/README.md b/README.md index 0e8ec15..8960beb 100644 --- a/README.md +++ b/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: diff --git a/go.mod b/go.mod index 42c792a..ec173b1 100644 --- a/go.mod +++ b/go.mod @@ -1,4 +1,4 @@ -module github.com/exaring/otelpgx +module github.com/overmindtech/otelpgx go 1.22.0 diff --git a/tracer.go b/tracer.go index 85c91de..3fc44c3 100644 --- a/tracer.go +++ b/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 ( diff --git a/tracer_benchmark_test.go b/tracer_benchmark_test.go index 48fad83..adaac6d 100644 --- a/tracer_benchmark_test.go +++ b/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"